DbaaS/ExaCS filesystem filing up with KRB tracing

KRB tracing and background

On our Exadata Cloud Service system running 18c GI and DB, we have been running into issues with /u02 filesystem filling up.  This was primarily imposed and generated by one component – RMAN.  As it turns out we had just enabled ExaCS automated backups via the tooling (bkup_api) .

Firstly, krb.c code refers to RMAN code layer, and tracing is generally produced when user specifies krbitrc via the event tracing.  Note this is not the same as rman debugging ( debug=all).

Starting in DB 18.3 , the event tracing is generating tracing regardless of event being set or not, and worse, its gen’ing trace files for every command.  This why the the /u02 is getting filled up

Here’s a sample of the trace data:

2019-06-02 18:17:16.933*:KRB:krbr.c@15486:krbr2b1(): ; f->krfil_krbrf=0 op1=2 lbno=1165134 f->seq_krbrf=11981

2019-06-02 18:17:16.933*:KRB:krbr.c@15908:krbr9b2(): Entering; f->seq_krbrf=11981 f->thread_krbrf=2 bno=1165134

2019-06-02 18:17:16.933*:KRB:krbr.c@15486:krbr2b1(): ; f->krfil_krbrf=0 op1=2 lbno=1165135 f->seq_krbrf=11981

2019-06-02 18:17:16.933*:KRB:krbr.c@15908:krbr9b2(): Entering; f->seq_krbrf=11981 f->thread_krbrf=2 bno=1165135

2019-06-02 18:17:16.933*:KRB:krbr.c@15486:krbr2b1(): ; f->krfil_krbrf=0 op1=2 lbno=1165136 f->seq_krbrf=11981

2019-06-02 18:17:16.933*:KRB:krbr.c@15908:krbr9b2(): Entering; f->seq_krbrf=11981 f->thread_krbrf=2 bno=1165136

2019-06-02 18:17:16.933*:KRB:krbr.c@15486:krbr2b1(): ; f->krfil_krbrf=0 op1=2 lbno=1165137 f->seq_krbrf=11981

2019-06-02 18:17:16.933*:KRB:krbr.c@15908:krbr9b2(): Entering; f->seq_krbrf=11981 f->thread_krbrf=2 bno=1165137

2019-06-02 18:17:16.933*:KRB:krbr.c@15486:krbr2b1(): ; f->krfil_krbrf=0 op1=2 lbno=1165138 f->seq_krbrf=11981

2019-06-02 18:17:16.933*:KRB:krbr.c@15908:krbr9b2(): Entering; f->seq_krbrf=11981 f->thread_krbrf=2 bno=1165138

2019-06-02 18:17:16.933*:KRB:krbr.c@15486:krbr2b1(): ; f->krfil_krbrf=0 op1=2 lbno=1165139 f->seq_krbrf=11981

2019-06-02 18:17:16.933*:KRB:krbr.c@15908:krbr9b2(): Entering; f->seq_krbrf=11981 f->thread_krbrf=2 bno=1165139

2019-06-02 18:17:16.933*:KRB:krbr.c@15486:krbr2b1(): ; f->krfil_krbrf=0 op1=2 lbno=1165140 f->seq_krbrf=11981

2019-06-02 18:17:16.933*:KRB:krbr.c@15908:krbr9b2(): Entering; f->seq_krbrf=11981 f->thread_krbrf=2 bno=1165140

And

…………

Redo thread mounted by this instance: 1

Oracle process number: 284

Unix process pid: 8448, image: oracle@***** (TNS V1-V3)

*** 2019-06-02T19:00:03.444793+00:00 (CDB$ROOT(1))

*** SESSION ID:(1723.45910) 2019-06-19T19:00:03.444828+00:00

*** CLIENT ID:() 2019-06-02T19:00:03.444835+00:00

*** SERVICE NAME:(SYS$USERS) 2019-06-02T19:00:03.444841+00:00

*** MODULE NAME:(rman@***** (TNS V1-V3)) 2019-06-02T19:00:03.444848+00:00

*** ACTION NAME:() 2019-06-02T19:00:03.444855+00:00

*** CLIENT DRIVER:() 2019-06-02T19:00:03.444861+00:00

*** CONTAINER ID:(1) 2019-06-02T19:00:03.444868+00:00

2019-06-02 19:00:03.444*:KRB:krbi.c@8857:krbitrc(): Got krbitrc

2019-06-02 19:00:03.444*:KRB:krbi.c@8887:krbiwtrc(): (bkrsmain - Action is NULL)

*** ACTION NAME:(0000001 STARTED70) 2019-06-02T19:00:03.444998+00:00

2019-06-02 19:00:03.444*:KRB:krbi.c@8887:krbiwtrc(): (icdstart - Action set to 0000001 STARTED70)

*** ACTION NAME:(0000001 FINISHED70) 2019-06-02T19:00:03.445209+00:00

2019-06-02 19:00:03.445*:KRB:krbi.c@8887:krbiwtrc(): (icdfinish - Action set to 0000001 FINISHED70)

Doc ID 28390273.8 mentions that the fix is included in “18.4.0.0.181016 (Oct 2018) Database Release Update (DB RU)” but issue is still seen in latest RU.

You can either wait for the fix, or manually disable kbr tracing.

To fix this issue permanently set below parameter at DB level

if using spfile

Alter system set events ‘trace[krb.*] disk disable, memory disable’;  

If using pfile

event=’trace[krb.*] disk disable, memory disable’

MOS Note – Excessive MMON, KRB Traces Causing Trace File Location (/u01) Overflow in DBaaS (Doc ID 2442656.1) does a decent job describing this issue