Oracle12c R2注意事项： 因BUG生成大量的trace file 包含KRB: (rman module)

升级了Oracle 12cR2的同学，尤其是安装了2018 4月RU的版本（12.2.0.1.180417）, 遇好检查下你的trace目录下是否生成了超大量的trace file,或单个超大的trace file文件，因为在这个版本下有两个原因很可能生成这些trace:

1. Trace files generation with message “AUTO SGA: kmgs_parameter_update_timeout gen0 0 mmon alive 1”.

2. Trace files generated from RMAN module with KRB messages.

第一个原因是因为Bug 25415713, 安装one-off patch可以解决；

第二个原因很可能就是几个bug了，而且目前看最终修复还是在20.1版本

Bug 28174827 RMAN Unconditional KRB Trace File After Installing Fix Of Bug 22700845

修复了上面，还可以出现下面新BUG

Bug 28390273 : RMAN: UNCONDITIONAL KRB TRACE FILE AFTER PATCH 27674384

DEMO

oracle@anbob01:/oracle/app/oracle/diag/rdbms/anbob/anbob1/trace> find . -size +50000k -exec ls -lh {} \;  
-rw-r--r-- 1 oracle asmadmin 110M Dec 18 15:48 ./anbob1_ora_69448.trm
-rw-r--r-- 1 oracle asmadmin 110M Dec 18 15:48 ./anbob1_ora_69426.trm
-rw-r--r-- 1 oracle asmadmin 110M Dec 18 15:48 ./anbob1_ora_71413.trm
-rw-r--r-- 1 oracle asmadmin 110M Dec 18 15:48 ./anbob1_ora_72634.trm
-rw-r--r-- 1 oracle asmadmin 123M Dec 19 10:40 ./anbob1_ora_67514.trm
-rw-r--r-- 1 oracle asmadmin 123M Dec 19 10:40 ./anbob1_ora_67523.trm
-rw-r--r-- 1 oracle asmadmin 123M Dec 19 10:40 ./anbob1_ora_67529.trm
-rw-r--r-- 1 oracle asmadmin 123M Dec 19 10:40 ./anbob1_ora_67537.trm
-rw-r--r-- 1 oracle asmadmin 1022M Dec 24 21:51 ./anbob1_ora_34780.trc
-rw-r--r-- 1 oracle asmadmin 341M Dec 24 21:51 ./anbob1_ora_34780.trm
-rw-r--r-- 1 oracle asmadmin 1019M Dec 24 21:51 ./anbob1_ora_34796.trc
-rw-r--r-- 1 oracle asmadmin 345M Dec 24 21:51 ./anbob1_ora_34796.trm
-rw-r--r-- 1 oracle asmadmin 1017M Dec 24 21:51 ./anbob1_ora_34878.trc
-rw-r--r-- 1 oracle asmadmin 348M Dec 24 21:51 ./anbob1_ora_34878.trm
-rw-r--r-- 1 oracle asmadmin 1015M Dec 24 21:51 ./anbob1_ora_34951.trc
-rw-r--r-- 1 oracle asmadmin 349M Dec 24 21:51 ./anbob1_ora_34951.trm

oracle@anbob01:/oracle/app/oracle/diag/rdbms/anbob/anbob1/trace> more anbob1_ora_34780.trc

2018-12-24 19:02:40.597*:KRB:krbb.c@7963:krbbtgb(): reading file; t->pkrbbf_krbbt->name_krbbf=+DATADG/anbob/DATAFILE/rpt_result.1296.990810375
2018-12-24 19:02:40.597*:KRB:krbb.c@16076:krbbnbf(): entering; fno=1026 *bno=436480 *bct=4294967295 fd->gnb_bno_krbbfd=0 fd->gnb_bct_krbbfd=0 firstblk=0 lastblk=3932160
2018-12-24 19:02:40.597*:KRB:krbb.c@7094:krbbTraceWriteBuf(): Writing 128 blocks, begin: 0x0x7f9af178c000, end: 0x0x7f9af188c000
2018-12-24 19:02:40.597*:KRB:krbb.c@7963:krbbtgb(): reading file; t->pkrbbf_krbbt->name_krbbf=+DATADG/anbob/DATAFILE/rpt_result.1296.990810375
2018-12-24 19:02:40.597*:KRB:krbb.c@16076:krbbnbf(): entering; fno=1026 *bno=436608 *bct=4294967295 fd->gnb_bno_krbbfd=0 fd->gnb_bct_krbbfd=0 firstblk=0 lastblk=3932160
2018-12-24 19:02:40.598*:KRB:krbb.c@7094:krbbTraceWriteBuf(): Writing 128 blocks, begin: 0x0x7f9af15ac000, end: 0x0x7f9af16ac000
2018-12-24 19:02:40.604*:KRB:krbb.c@7963:krbbtgb(): reading file; t->pkrbbf_krbbt->name_krbbf=+DATADG/anbob/DATAFILE/rpt_result.1296.990810375
2018-12-24 19:02:40.604*:KRB:krbb.c@16076:krbbnbf(): entering; fno=1026 *bno=436736 *bct=4294967295 fd->gnb_bno_krbbfd=0 fd->gnb_bct_krbbfd=0 firstblk=0 lastblk=3932160
2018-12-24 19:02:40.605*:KRB:krbb.c@7094:krbbTraceWriteBuf(): Writing 128 blocks, begin: 0x0x7f9af149c000, end: 0x0x7f9af159c000
2018-12-24 19:02:40.610*:KRB:krbb.c@7963:krbbtgb(): reading file; t->pkrbbf_krbbt->name_krbbf=+DATADG/anbob/DATAFILE/rpt_result.1296.990810375
2018-12-24 19:02:40.610*:KRB:krbb.c@16076:krbbnbf(): entering; fno=1026 *bno=436864 *bct=4294967295 fd->gnb_bno_krbbfd=0 fd->gnb_bct_krbbfd=0 firstblk=0 lastblk=3932160
2018-12-24 19:02:40.610*:KRB:krbb.c@7094:krbbTraceWriteBuf(): Writing 128 blocks, begin: 0x0x7f9af138c000, end: 0x0x7f9af148c000

Note:

KRBB ==>> Kernel Recovery Backup Restore Creation Of A Backuppiece

SQL> select USED_CHANGE_TRACKING from  v$backup_datafile;

USE
---
NO
NO

QL> set serveroutput on
SQL> exec dbms_qopatch.get_sqlpatch_status;

Patch Id : 27674384
        Action : APPLY
        Action Time : 26-OCT-2018 18:11:23
        Description : DATABASE APR 2018 RELEASE UPDATE 12.2.0.1.180417
        Logfile : /oracle/app/oracle/cfgtoollogs/sqlpatch/27674384/22098633/27674384_apply_anbob_2018Oct26_18_10_54.log
        Status : SUCCESS

Patch Id : 24554937
        Action : APPLY
        Action Time : 26-OCT-2018 18:11:23
        Description : ORA-12850 WHILE MMON SLAVE AUTOMATIC REPORT FLUSH ACTION
        Logfile : /oracle/app/oracle/cfgtoollogs/sqlpatch/24554937/22382646/24554937_apply_anbob_2018Oct26_18_11_21.log
        Status : SUCCESS

PL/SQL procedure successfully completed.

oracle@anbob01:/oracle/app/oracle/product/12.2.0/db_1/OPatch> ./opatch lsinv|grep -n 22700845
216:     26256131, 23019710, 24308349, 22700845, 27169796, 25975723, 26797591


# bug 28390273 每个RMAN 命令都会生成trace

oracle@anbob01:/oracle/app/oracle/product/12.2.0/db_1/OPatch> rman target /
Recovery Manager: Release 12.2.0.1.0 - Production on Wed Dec 26 15:42:11 2018
Copyright (c) 1982, 2017, Oracle and/or its affiliates.  All rights reserved.
connected to target database: anbob (DBID=2595938058)
RMAN> report schema;

Trace file /oracle/app/oracle/diag/rdbms/anbob/anbob1/trace/anbob1_ora_11617.trc
Oracle Database 12c Enterprise Edition Release 12.2.0.1.0 - 64bit Production
Build label:    RDBMS_12.2.0.1.0_LINUX.X64_170125
ORACLE_HOME:    /oracle/app/oracle/product/12.2.0/db_1
System name:    Linux
Node name:      anbob01
Release:        4.4.21-69-default
Version:        #1 SMP Tue Oct 25 10:58:20 UTC 2016 (9464f67)
Machine:        x86_64
Instance name: anbob1
Redo thread mounted by this instance: 1
Oracle process number: 147
Unix process pid: 11617, image: oracle@anbob01 (TNS V1-V3)

*** 2018-12-26T15:42:11.808308+08:00
*** SESSION ID:(2552.28612) 2018-12-26T15:42:11.808332+08:00
*** CLIENT ID:() 2018-12-26T15:42:11.808338+08:00
*** SERVICE NAME:(SYS$USERS) 2018-12-26T15:42:11.808344+08:00
*** MODULE NAME:(rman@anbob01 (TNS V1-V3)) 2018-12-26T15:42:11.808350+08:00
*** ACTION NAME:() 2018-12-26T15:42:11.808356+08:00
*** CLIENT DRIVER:() 2018-12-26T15:42:11.808362+08:00
 
2018-12-26 15:42:11.807*:KRB:krbi.c@8857:krbitrc(): Got krbitrc
2018-12-26 15:42:11.808*:KRB:krbi.c@8887:krbiwtrc(): (bkrsmain - Action is NULL)
*** ACTION NAME:(0000001 STARTED70) 2018-12-26T15:42:11.808499+08:00
 
2018-12-26 15:42:11.808*:KRB:krbi.c@8887:krbiwtrc(): (icdstart - Action set to 0000001 STARTED70)
*** ACTION NAME:(0000001 FINISHED70) 2018-12-26T15:42:11.808675+08:00
 
2018-12-26 15:42:11.808*:KRB:krbi.c@8887:krbiwtrc(): (icdfinish - Action set to 0000001 FINISHED70)
2018-12-26 15:42:12.168*:KRB:krbi.c@7583:krbicrsr(): Got krbicrsr
2018-12-26 15:42:12.182*:KRB:krbm.c@6132:krbmcrsr(): created; recid=1439
2018-12-26 15:42:12.203*:KRB:krbi.c@7775:krbicror(): Got krbicror
2018-12-26 15:42:12.204*:KRB:krbm.c@6435:krbmcror(): ; sameline=0
2018-12-26 15:42:12.204*:KRB:krbm.c@6591:krbmcror(): ; rowset->used_krbmror=0 rowset->sameline_krbmror=0
2018-12-26 15:42:12.204*:KRB:krbm.c@6629:krbmcror(): update rowset output; rowset->used_krbmror=0
2018-12-26 15:42:12.204*:KRB:krbi.c@7775:krbicror(): Got krbicror
2018-12-26 15:42:12.204*:KRB:krbm.c@6435:krbmcror(): ; sameline=0
2018-12-26 15:42:12.204*:KRB:krbm.c@6591:krbmcror(): ; rowset->used_krbmror=1 rowset->sameline_krbmror=0
2018-12-26 15:42:12.204*:KRB:krbm.c@6629:krbmcror(): update rowset output; rowset->used_krbmror=1

解决方案:

禁用krb trace

SQL> oradebug setmypid
Statement processed.
SQL> oradebug eventdump system
Statement processed.

SQL> alter system set events 'trace[krb.*] disk disable, memory disable';
System altered.

SQL> oradebug eventdump system
trace [RDBMS.KRB_OPTIM] disk disable, memory disable
trace [RDBMS.KRB_FLWUSAGE] disk disable, memory disable
trace [RDBMS.KRB_FLWBCK] disk disable, memory disable
trace [RDBMS.KRB_FLWCPY] disk disable, memory disable
trace [RDBMS.KRB_FLWRES] disk disable, memory disable
trace [RDBMS.KRB_BPVAL] disk disable, memory disable
trace [RDBMS.KRB_BPOUTPUT] disk disable, memory disable
trace [RDBMS.KRB_PERF] disk disable, memory disable
trace [RDBMS.KRB_INCR] disk disable, memory disable
trace [RDBMS.KRB_IO] disk disable, memory disable
trace [RDBMS.KRB_THREAD] disk disable, memory disable
trace [RDBMS.KRB] disk disable, memory disable

SQL>  alter system set event='trace[krb.*] disk disable, memory disable' scope=spfile;

禁用当前内存和修改spfile重启同样生效。