6 Replies Latest reply: Jul 27, 2012 7:15 AM by user13785220 RSS

    Trace files size increasing abnormally in the system only during sometime

    User448486
      Hi,

      Database :  Oracle Database 11g Enterprise Edition Release 11.1.0.7.0 - 64bit Production

      Last one week , the trace files are generating in huge size abnormally and occupying the Disk space in the Operating system.

      This  huge trace files are generating only some time  in a day during "gather statistics and RMAN Backup " running in the  database thru CRON JOB.

      *1. Could anyone please tell me why the trace files generating in huge size suddenly*

      *2. what is this trace files contains?*

      *3. What is this contents related to?*

      *4. Is it mandatory or we can disable this Trace files?*

      *4. Is it possible to check in v$session whether this files related to which Job/process/SQL running in the database?*

      When i checked the content of the trace file , i found the below contents:

      Trace file /opt/oracle/diag/rdbms/dws/DWS/trace/DWS_arc2_21382.trc
      Oracle Database 11g Enterprise Edition Release 11.1.0.7.0 - 64bit Production
      With the Partitioning, OLAP, Data Mining and Real Application Testing options
      ORACLE_HOME = /opt/oracle/product/11.1.0
      System name: SunOS
      Node name: crs42dws2
      Release: 5.10
      Version: Generic_142909-17
      Machine: sun4u
      Instance name: DWS
      Redo thread mounted by this instance: 1
      Oracle process number: 58
      Unix process pid: 21382, image: oracle@crs42dws2 (ARC2)


      *** 2012-05-21 15:16:42.370
      *** SESSION ID:(2248.19) 2012-05-21 15:16:42.370
      *** CLIENT ID:() 2012-05-21 15:16:42.370
      *** SERVICE NAME:(SYS$BACKGROUND) 2012-05-21 15:16:42.370
      *** MODULE NAME:() 2012-05-21 15:16:42.370
      *** ACTION NAME:() 2012-05-21 15:16:42.370

      *** 2012-05-21 15:16:42.294 3333 kcrr.c
      kcrroda: calling ksfdrcres to create AL or RL

      *** 2012-05-21 15:16:45.358
      *** 2012-05-21 15:16:45.357 3353 kcrr.c
      kcrroda: completed call to ksfdrcres

      *** 2012-05-21 15:27:14.776
      *** 2012-05-21 15:27:14.776 3333 kcrr.c
      kcrroda: calling ksfdrcres to create AL or RL

      *** 2012-05-21 15:27:15.864
      *** 2012-05-21 15:27:15.864 3353 kcrr.c
      kcrroda: completed call to ksfdrcres
      *** 2012-05-21 15:38:43.858 3333 kcrr.c

      *** 2012-05-21 15:38:43.858
      kcrroda: calling ksfdrcres to create AL or RL

      *** 2012-05-21 15:38:44.977
      *** 2012-05-21 15:38:44.977 3353 kcrr.c
      kcrroda: completed call to ksfdrcres
      *** 2012-05-21 15:58:25.144 3333 kcrr.c


      Thanks and Regards,
      C.DEEBAN
        • 1. Re: Trace files size increasing abnormally in the system only during sometime
          User448486
          Hi,

          I found another different trace file with the below content :

          [11:32pm] root@crs42dws2: # cat DWS_ora_7339.trc|pg
          Trace file /opt/oracle/diag/rdbms/dws/DWS/trace/DWS_ora_7339.trc
          Oracle Database 11g Enterprise Edition Release 11.1.0.7.0 - 64bit Production
          With the Partitioning, OLAP, Data Mining and Real Application Testing options
          ORACLE_HOME = /opt/oracle/product/11.1.0
          System name: SunOS
          Node name: crs42dws2
          Release: 5.10
          Version: Generic_142909-17
          Machine: sun4u
          Instance name: DWS
          Redo thread mounted by this instance: 1
          Oracle process number: 10
          Unix process pid: 7339, image: oracle@crs42dws2 (TNS V1-V3)


          *** 2012-05-23 20:00:12.323
          *** SESSION ID:(2111.11419) 2012-05-23 20:00:12.323
          *** CLIENT ID:() 2012-05-23 20:00:12.323
          *** SERVICE NAME:(SYS$USERS) 2012-05-23 20:00:12.323
          *** MODULE NAME:(rman@crs42dws2 (TNS V1-V3)) 2012-05-23 20:00:12.323
          *** ACTION NAME:() 2012-05-23 20:00:12.323

          Current KRB flags set for session
          =========================================================
          krbcsi=0, krbcss=0, krbcsr=0, krbcso=0
          krbpfn=0, krbtra=0x100, krbpfl=0x0
          krbdsd=0x0, krbbxp=0x0, krbrxp=0x0, krbnas=0
          krbbsbct=0, krbovac=0
          krbubsphi=0, krbubsphr=0, krbubspbi=0, krbubspbr=0
          krbubbsbi=0, krbubbsbr=0, krbubfl=0x0
          =========================================================
          Got krbitrc
          krbiwtrc : (bkrsmain - Action is NULL)
          Got krbitrc
          Got krbiovac
          *** ACTION NAME:(0000001 STARTED1) 2012-05-23 20:00:12.335

          krbiwtrc : (icdstart - Action set to 0000001 STARTED1)
          Got krbidvac
          allocated device type: "DISK", name: ""
          *** ACTION NAME:(0000001 FINISHED1) 2012-05-23 20:00:12.336

          krbiwtrc : (icdfinish - Action set to 0000001 FINISHED1)
          *** ACTION NAME:(0000002 STARTED3) 2012-05-23 20:00:12.336

          krbiwtrc : (icdstart - Action set to 0000002 STARTED3)
          Got krbidvq
          *** ACTION NAME:(0000002 FINISHED3) 2012-05-23 20:00:12.336

          krbiwtrc : (icdfinish - Action set to 0000002 FINISHED3)
          *** ACTION NAME:(0000003 STARTED3) 2012-05-23 20:00:12.336

          krbiwtrc : (icdstart - Action set to 0000003 STARTED3)
          Got krbidvq
          *** ACTION NAME:(0000003 FINISHED3) 2012-05-23 20:00:12.337

          krbiwtrc : (icdfinish - Action set to 0000003 FINISHED3)
          *** ACTION NAME:(0000004 STARTED3) 2012-05-23 20:00:12.337

          krbiwtrc : (icdstart - Action set to 0000004 STARTED3)
          Got krbidvq
          *** ACTION NAME:(0000004 FINISHED3) 2012-05-23 20:00:12.337

          krbiwtrc : (icdfinish - Action set to 0000004 FINISHED3)
          *** ACTION NAME:(0000005 STARTED3) 2012-05-23 20:00:12.341

          krbiwtrc : (icdstart - Action set to 0000005 STARTED3)
          Got krbidvq
          *** ACTION NAME:(0000005 FINISHED3) 2012-05-23 20:00:12.341

          krbiwtrc : (icdfinish - Action set to 0000005 FINISHED3)

          *** 2012-05-23 20:11:02.468
          *** ACTION NAME:(0000006 STARTED42) 2012-05-23 20:11:02.468

          krbiwtrc : (icdstart - Action set to 0000006 STARTED42)
          Got krbirsta
          *** ACTION NAME:(0000006 FINISHED42) 2012-05-23 20:11:02.468

          krbiwtrc : (icdfinish - Action set to 0000006 FINISHED42)
          Got krbitrc
          Got krbiovac
          *** ACTION NAME:(0000007 STARTED129) 2012-05-23 20:11:02.469

          krbiwtrc : (icdstart - Action set to 0000007 STARTED129)
          Got krbisrid
          *** ACTION NAME:(0000007 FINISHED129) 2012-05-23 20:11:02.469

          krbiwtrc : (icdfinish - Action set to 0000007 FINISHED129)
          Got krbitrc
          Got krbiovac
          *** ACTION NAME:(0000008 STARTED32) 2012-05-23 20:11:02.470

          krbiwtrc : (icdstart - Action set to 0000008 STARTED32)
          *** MODULE NAME:(restore incr datafile) 2012-05-23 20:11:02.470
          *** ACTION NAME:(0000008 STARTED32) 2012-05-23 20:11:02.470

          Got krbirsdf
          ++++++++++++++++++++++++++++++++++++++++++++++++++++++
          ++++ Restore conversation started +++
          ++++ type: 2 +++
          ++++++++++++++++++++++++++++++++++++++++++++++++++++++
          *** ACTION NAME:(0000008 FINISHED32) 2012-05-23 20:11:02.470

          krbiwtrc : (icdfinish - Action set to 0000008 FINISHED32)
          *** ACTION NAME:(0000009 STARTED36) 2012-05-23 20:11:02.472

          krbiwtrc : (icdstart - Action set to 0000009 STARTED36)
          Got krbiadft

          *** 2012-05-23 20:11:03.174
          *** ACTION NAME:(0000009 FINISHED36) 2012-05-23 20:11:03.174

          krbiwtrc : (icdfinish - Action set to 0000009 FINISHED36)
          *** ACTION NAME:(0000010 STARTED36) 2012-05-23 20:11:03.177

          krbiwtrc : (icdstart - Action set to 0000010 STARTED36)
          Got krbiadft
          *** ACTION NAME:(0000010 FINISHED36) 2012-05-23 20:11:03.729

          krbiwtrc : (icdfinish - Action set to 0000010 FINISHED36)
          *** ACTION NAME:(0000011 STARTED36) 2012-05-23 20:11:03.731

          krbiwtrc : (icdstart - Action set to 0000011 STARTED36)
          Got krbiadft
          • 2. Re: Trace files size increasing abnormally in the system only during sometime
            Srini Chavali-Oracle
            Pl see this MOS Doc - pl open an SR with Support to verify that the patch mentioned in the doc is applicable to your case

            Excessive Number Of Arc Trace Files Generated In 11g [ID 754289.1]     

            HTH
            Srini
            • 3. Re: Trace files size increasing abnormally in the system only during sometime
              jgarry
              Looks like MOS Bug 6910132: UNNECESSARY ARC TRACEFILE fixed with a patch. Contact support.

              I'd guess the same problem with the RMAN trace files, some goofball left debugging flag on in production release. Just like they have in various patch levels back to at least 7.x, that I know of.
              • 4. Re: Trace files size increasing abnormally in the system only during sometime
                User448486
                Hi ,

                Actually RMAN debug log was enabled , that is the reason we got excessive trace files with huge size and occupied the DIsk space in the operating system.

                We disabled the RMAN debug log and trace files become normal and its in KB and less MB.

                Problem solved and we are not applied the patch mentioned in the Thread.

                Regards,
                Deeban
                • 6. Re: Trace files size increasing abnormally in the system only during sometime
                  user13785220
                  Would you post more details on how to solve this issue.
                  We have tons of trace files like this:


                  Trace file /u01/app/oracle/diag/rdbms/itsmp/ITSMP1/trace/ITSMP1_ora_2277.trc
                  Oracle Database 11g Enterprise Edition Release 11.2.0.1.0 - 64bit Production
                  With the Partitioning, Real Application Clusters, Automatic Storage Management, OLAP,
                  Data Mining and Real Application Testing options
                  ORACLE_HOME = /u01/app/oracle/product/11.2.0/dbhome_1
                  System name: Linux
                  Node name: tryprorarac1a.searshc.com
                  Release: 2.6.18-194.26.1.el5
                  Version: #1 SMP Fri Oct 29 14:21:16 EDT 2010
                  Machine: x86_64
                  Instance name: ITSMP1
                  Redo thread mounted by this instance: 1
                  Oracle process number: 86
                  Unix process pid: 2277, image: oracle@tryprorarac1a.searshc.com


                  *** 2012-07-27 08:10:32.181
                  *** SESSION ID:(687.54939) 2012-07-27 08:10:32.181
                  *** CLIENT ID:() 2012-07-27 08:10:32.181
                  *** SERVICE NAME:(itsmp) 2012-07-27 08:10:32.181
                  *** MODULE NAME:() 2012-07-27 08:10:32.181
                  *** ACTION NAME:() 2012-07-27 08:10:32.181

                  Current KRB flags set for session
                  =========================================================
                  krbcsi=0, krbcss=0, krbcsr=0, krbcso=0
                  krbpfn=0, krbtra=0x0, krbpfl=0x800000
                  krbdsd=(nil), krbbxp=(nil), krbrxp=(nil), krbnas=0
                  krbbsbct=0, krbovac=0
                  krbubsphi=0, krbubsphr=0, krbubspbi=0, krbubspbr=0
                  krbubbsbi=0, krbubbsbr=0, krbubfl=0x0
                  =========================================================

                  Still looking for solution.
                  Thank you
                  vad.roytman@gmail.com