4 Replies Latest reply: Jun 24, 2013 2:02 AM by onkar.nath RSS

    ORA-445 error

    onkar.nath

      Hi all,

      I am getting below error very frequently on some of the targets:

       Incident (ORA-445) detected in /u01/app/oracle/diag/rdbms/devrdb2/DEVRDB2/alert/log.xml at time/line number

      When contacted Oracle support, they say that its an OS issue. I am not sure where to start debugging it from. I checked the trace file generated by the respective incident also but could not make out anything. I got the trace file name from adrci command

       show tracefile -i 240122 

      Below is first few lines from the tracefile:

      ORACLE_HOME = /u01/app/oracle/product/11.2.0/dbhome_2 System name:    Linux Node name:      devdb3.XXXX.com Release:        2.6.18-194.el5 Version:        #1 SMP Tue Mar 16 21:52:39 EDT 2010 Machine:        x86_64 VM name:        VMWare Version: 6 Instance name: DEVRDB2 Redo thread mounted by this instance: 1 Oracle process number: 15 Unix process pid: 30053, image: oracle@devdb3.XXX.com (MMON) *** 2013-06-02 00:21:48.751 *** SESSION ID:(15.1) 2013-06-02 00:21:48.751 *** CLIENT ID:() 2013-06-02 00:21:48.751 *** SERVICE NAME:(SYS$BACKGROUND) 2013-06-02 00:21:48.751 *** MODULE NAME:() 2013-06-02 00:21:48.751 *** ACTION NAME:() 2013-06-02 00:21:48.751 Dump continued from file: /u01/app/oracle/diag/rdbms/devrdb2/DEVRDB2/trace/DEVRDB2_mmon_30053.trc ORA-00445: background process "m003" did not start after 120 seconds ========= Dump for incident 240122 (ORA 445) ======== ----- Beginning of Customized Incident Dump(s) ----- ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 15 (osid: 30053, MMON) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2013-06-02 00:16:47.050476 :84A66ABC:db_trace:ksb.c@1809:ksbcti(): [10254:15:15] KSBCTI: (MMON) : (infrequent action) : acnum=[41] comment=[reload failed KSPD callbacks] 2013-06-02 00:16:47.050501 :84A66ABD:db_trace:ksb.c@1818:ksbcti(): [10254:15:15] KSBCTI: (MMON) : (timeout action)  : acnum=[42] comment=[reconfiguration MMON action] 2013-06-02 00:16:47.050505 :84A66ABE:db_trace:ksb.c@1818:ksbcti(): [10254:15:15] KSBCTI: (MMON) : (timeout action)  : acnum=[63] comment=[SGA memory tuning parameter update] 2013-06-02 00:16:47.050507 :84A66ABF:db_trace:ksb.c@1818:ksbcti(): [10254:15:15] KSBCTI: (MMON) : (timeout action)  : acnum=[69] comment=[SGA memory tuning] 2013-06-02 00:17:27.422622 :84A6767D:db_trace:ksb.c@1809:ksbcti(): [10254:15:15] KSBCTI: (MMON) : (infrequent action) : acnum=[131] comment=[deferred controlfile autobackup action] 2013-06-02 00:17:27.422634 :84A6767E:db_trace:ksb.c@1818:ksbcti(): [10254:15:15] KSBCTI: (MMON) : (timeout action)  : acnum=[152] comment=[Flashback Marker] 2013-06-02 00:17:27.422639 :84A6767F:db_trace:ksb.c@1809:ksbcti(): [10254:15:15] KSBCTI: (MMON) : (infrequent action) : acnum=[169] comment=[Block Cleanout Optim, Undo Segment Scan] 2013-06-02 00:17:27.462717 :84A67685:db_trace:ksb.c@1818:ksbcti(): [10254:15:15] KSBCTI: (MMON) : (timeout action)  : acnum=[170] comment=[Block Cleanout Optim, Rac specific code] 2013-06-02 00:17:27.422639 :84A6767F:db_trace:ksb.c@1809:ksbcti(): [10254:15:15] KSBCTI: (MMON) : (infrequent action) : acnum=[169] comment=[Block Cleanout Optim, Undo Segment Scan] 2013-06-02 00:17:27.462717 :84A67685:db_trace:ksb.c@1818:ksbcti(): [10254:15:15] KSBCTI: (MMON) : (timeout action)  : acnum=[170] comment=[Block Cleanout Optim, Rac specific code] 2013-06-02 00:17:27.462801 :84A67686:db_trace:ksb.c@1818:ksbcti(): [10254:15:15] KSBCTI: (MMON) : (timeout action)  : acnum=[171] comment=[BCO:] 2013-06-02 00:17:27.462807 :84A67687:db_trace:ksb.c@1809:ksbcti(): [10254:15:15] KSBCTI: (MMON) : (infrequent action) : acnum=[173] comment=[Flashback Archive RAC Health Check] 2013-06-02 00:17:27.463889 :84A67688:db_trace:ksb.c@1809:ksbcti(): [10254:15:15] KSBCTI: (MMON) : (infrequent action) : acnum=[176] comment=[tune undo retention lob] 2013-06-02 00:17:27.463893 :84A67689:db_trace:ksb.c@1809:ksbcti(): [10254:15:15] KSBCTI: (MMON) : (infrequent action) : acnum=[177] comment=[MMON Periodic LOB  MQL Selector] 2013-06-02 00:17:27.463895 :84A6768A:db_trace:ksb.c@1809:ksbcti(): [10254:15:15] KSBCTI: (MMON) : (infrequent action) : acnum=[178] comment=[MMON Periodic LOB Spc Analyze ] 2013-06-02 00:17:27.463897 :84A6768B:db_trace:ksb.c@1809:ksbcti(): [10254:15:15] KSBCTI: (MMON) : (infrequent action) : acnum=[203] comment=[Sample Shared Server Activity] 2013-06-02 00:17:27.463910 :84A6768C:db_trace:ksb.c@1809:ksbcti(): [10254:15:15] KSBCTI: (MMON) : (infrequent action) : acnum=[210] comment=[Compute cache stats in background] 2013-06-02 00:17:27.463914 :84A6768D:db_trace:ksb.c@1809:ksbcti(): [10254:15:15] KSBCTI: (MMON) : (infrequent action) : acnum=[217] comment=[KSXM Advance DML Frequencies] 2013-06-02 00:17:27.463916 :84A6768E:db_trace:ksb.c@1809:ksbcti(): [10254:15:15] KSBCTI: (MMON) : (infrequent action) : acnum=[218] comment=[KSXM Broadcast DML Frequencies] 2013-06-02 00:17:27.463918 :84A6768F:db_trace:ksb.c@1809:ksbcti(): [10254:15:15] KSBCTI: (MMON) : (infrequent action) : acnum=[293] comment=[alert message cleanup] 2013-06-02 00:17:27.548067 :84A676DD:db_trace:ksb.c@1809:ksbcti(): [10254:15:15] KSBCTI: (MMON) : (infrequent action) : acnum=[295] comment=[AWR Auto Flush Task] 2013-06-02 00:17:27.548106 :84A676DE:db_trace:ksb.c@1809:ksbcti(): [10254:15:15] KSBCTI: (MMON) : (infrequent action) : acnum=[296] comment=[AWR Auto Purge Task] 2013-06-02 00:17:28.350235 :84A6774C:db_trace:ksb.c@1809:ksbcti(): [10254:15:15] KSBCTI: (MMON) : (infrequent action) : acnum=[310] comment=[run-once action driver] 2013-06-02 00:17:28.350248 :84A6774D:db_trace:ksb.c@1809:ksbcti(): [10254:15:15] KSBCTI: (MMON) : (infrequent action) : acnum=[316] comment=[metrics monitoring] 2013-06-02 00:17:28.350429 :84A6774E:db_trace:ksb.c@1809:ksbcti(): [10254:15:15] KSBCTI: (MMON) : (infrequent action) : acnum=[319] comment=[sql tuning hard kill defense] 2013-06-02 00:17:28.350607 :84A6774F:db_trace:ksb.c@1809:ksbcti(): [10254:15:15] KSBCTI: (MMON) : (infrequent action) : acnum=[321] comment=[Maintain AWR Baseline Thresholds Task] 2013-06-02 00:17:28.350625 :84A67750:db_trace:ksb.c@1809:ksbcti(): [10254:15:15] KSBCTI: (MMON) : (infrequent action) : acnum=[322] comment=[WCR: Record Action Switcher] 2013-06-02 00:17:28.350627 :84A67751:db_trace:ksb.c@1809:ksbcti(): [10254:15:15] KSBCTI: (MMON) : (infrequent action) : acnum=[328] comment=[WCR: Replay Action Switcher] 2013-06-02 00:17:28.350628 :84A67752:db_trace:ksb.c@1809:ksbcti(): [10254:15:15] KSBCTI: (MMON) : (infrequent action) : acnum=[335] comment=[SQL Monitoring Garbage Collector] 2013-06-02 00:17:28.350642 :84A67753:db_trace:ksb.c@1809:ksbcti(): [10254:15:15] KSBCTI: (MMON) : (infrequent action) : acnum=[341] comment=[Coordinator autostart timeout] 2013-06-02 00:17:28.400566 :84A6776D:db_trace:ksb.c@1792:ksbcti(): [10254:15:15] KSBCTI: (MMON) : (interrupt action) : acnum=[2] comment=[KSB action for X-instance calls] 2013-06-02 00:17:28.400568 :84A6776E:db_trace:ksb.c@1792:ksbcti(): [10254:15:15] KSBCTI: (MMON) : (interrupt action) : acnum=[20] comment=[KSB action for ksbxic() calls] 2013-06-02 00:17:28.400569 :84A6776F:db_trace:ksb.c@1792:ksbcti(): [10254:15:15] KSBCTI: (MMON) : (interrupt action) : acnum=[39] comment=[MMON request for RLB metrics] 2013-06-02 00:17:28.400574 :84A67770:db_trace:ksb.c@1792:ksbcti(): [10254:15:15] KSBCTI: (MMON) : (interrupt action) : acnum=[106] comment=[Scumnt mount lock] 2013-06-02 00:17:28.400575 :84A67771:db_trace:ksb.c@1792:ksbcti(): [10254:15:15] KSBCTI: (MMON) : (interrupt action) : acnum=[107] comment=[Poll system events broadcast channel] 2013-06-02 00:17:28.400576 :84A67772:db_trace:ksb.c@1792:ksbcti(): [10254:15:15] KSBCTI: (MMON) : (interrupt action) : acnum=[303] comment=[MMON Remote action Listener] 2013-06-02 00:17:28.400582 :84A67773:db_trace:ksb.c@1792:ksbcti(): [10254:15:15] KSBCTI: (MMON) : (interrupt action) : acnum=[304] comment=[MMON Local action Listener] 2013-06-02 00:17:28.400584 :84A67774:db_trace:ksb.c@1792:ksbcti(): [10254:15:15] KSBCTI: (MMON) : (interrupt action) : acnum=[305] comment=[MMON Completion Callback Dispatcher]

      Tracefile is really huge. Please advise.

      -Onkar

        • 1. Re: ORA-445 error
          EricvdS
          Did you check MOS-note: ORA-00445 Is Reported While Waiting Too Long To Spawn A Process [ID 1382349.1]     

          Eric
          • 2. Re: ORA-445 error
            onkar.nath

            EricvdS,

             

            thanks for the link. I checked the link. It only lists unpublished bugs. It also recommends to run this:

            alter system set events '10281 trace name context forever, level xxxxxx';

            but I don't see any other solution.

             

            -Onkar

            • 3. Re: ORA-445 error
              EricvdS

              Hi Onkar,

               

              You say you have this error on some targets (databases?). So I think it is not a database issue but it is VM/Hardware thing. The underlaying hardware could be extremely busy or could it be the errors occur during the making of a VM backup/snapshot?

              btw: you did replace the xxxxxx by 240 or something like that?

               

              Eric

              • 4. Re: ORA-445 error
                onkar.nath

                Thanks Eric. I have replaced default timeout from 120 to 240. I am not expecting any more error but if I do, I will post here.

                 

                -Onkar