Saturday, May 7, 2011

ORA-00054, ORA-04022 while gathering table statistics

Problem Description
The following errors are reprted when executing DBMS_STATS procedures simultaneously in order to collect database tables statistics.

ORA-00054: resource busy and acquire with NOWAIT specified
ORA-04022: nowait requested, but had to wait to lock dictionary object

DBMS_STATS procedures that collect statistics for more than one object sometimes reports ORA-00054 and ORA-04022. For example these error arised whenever we collect statistics through GATHER_SCHEMA_STATS.

Cause of the Problem
Statistics gathering procedures such as DBMS_STATS that operate on multiple objects using subprogram like GATHER_SCHEMA_STATS, GATHER_DATABASE_STATS, GATHER_DICTIONARY_STATS, component install etc raises error ORA-00054 and ORA-04022.

According to Oracle documentation this is expected behavior on Oracle 10g.

Solution of the Problem
These ORA-00054 and ORA-04022 errors are expected for GATHER_TABLE_STATS if another session is modifying statistics for the same table.

So, in order to avoid the errors ensure that there is no other statistics gathering activity on the system running simultaneously. It might happen that auto statistics gathering and manual statistics gather are performed at the same time and you hit above error.

Sunday, May 1, 2011

ORA-07445: exception encountered: core dump slaac_int unknown signal, unknown code

Today, I see from our production database alert log we see unknown signal, unknown code.
From Alert log we see,
Mon May 02 02:00:44 2011
******************************************************************
LGWR: Setting 'active' archival for destination LOG_ARCHIVE_DEST_2
******************************************************************
LNS: Standby redo logfile selected for thread 1 sequence 40020 for destination LOG_ARCHIVE_DEST_2
Mon May 02 03:44:22 2011
opidcl aborting process unknown ospid (29451) as a result of ORA-19624
Mon May 02 03:44:22 2011
opidcl aborting process unknown ospid (29410) as a result of ORA-19624
Mon May 02 03:44:22 2011
Exception [type: unknown signal, unknown code] [ADDR:0x4A23DCE9AA169] [PC:0x2321257, slaac_int()+237] [flags: 0x0, count: 1]
Errors in file /u01/app/oracle/diag/rdbms/bdafisdc/bdafisdc1/trace/bdafisdc1_ora_29360.trc:
ORA-07445: exception encountered: core dump [slaac_int()+237] [unknown signal] [ADDR:0x4A23DCE9AA169] [PC:0x2321257] [unknown code] []
ORA-00600: internal error code, arguments: [1884], [0x2B0F9A5E9F20], [2583909272], [3165375983], [1], [], [], [], [], [], [], []
Exception [type: SIGXCPU, unknown code] [ADDR:0x7FFF125EE480] [PC:0x2321257, slaac_int()+237] [flags: 0x0, count: 2]
Errors in file /u01/app/oracle/diag/rdbms/bdafisdc/bdafisdc1/trace/bdafisdc1_ora_29360.trc:
ORA-07445: exception encountered: core dump [slaac_int()+237] [SIGXCPU] [ADDR:0x7FFF125EE480] [PC:0x2321257] [unknown code] []
ORA-07445: exception encountered: core dump [slaac_int()+237] [unknown signal] [ADDR:0x4A23DCE9AA169] [PC:0x2321257] [unknown code] []
ORA-00600: internal error code, arguments: [1884], [0x2B0F9A5E9F20], [2583909272], [3165375983], [1], [], [], [], [], [], [], []
Exception [type: SIGXCPU, unknown code] [ADDR:0x7FFF125BF0E0] [PC:0x2321257, slaac_int()+237] [flags: 0x0, count: 3]
Errors in file /u01/app/oracle/diag/rdbms/bdafisdc/bdafisdc1/trace/bdafisdc1_ora_29360.trc:
ORA-07445: exception encountered: core dump [slaac_int()+237] [SIGXCPU] [ADDR:0x7FFF125BF0E0] [PC:0x2321257] [unknown code] []
ORA-07445: exception encountered: core dump [slaac_int()+237] [SIGXCPU] [ADDR:0x7FFF125EE480] [PC:0x2321257] [unknown code] []
ORA-07445: exception encountered: core dump [slaac_int()+237] [unknown signal] [ADDR:0x4A23DCE9AA169] [PC:0x2321257] [unknown code] []
ORA-00600: internal error code, arguments: [1884], [0x2B0F9A5E9F20], [2583909272], [3165375983], [1], [], [], [], [], [], [], []
From the trace logfile we see,
*** 2011-05-02 03:42:38.311
*** SESSION ID:(303.1267) 2011-05-02 03:42:38.311
*** CLIENT ID:() 2011-05-02 03:42:38.311
*** SERVICE NAME:(bdafisdc.world) 2011-05-02 03:42:38.311
*** MODULE NAME:(backup full datafile) 2011-05-02 03:42:38.311
*** ACTION NAME:(0000061 STARTED16) 2011-05-02 03:42:38.311

SKGFQ OSD: Error in function sbtwrite2 on line 1097
SKGFQ OSD: Look for SBT Trace messages in file /u01/app/oracle/diag/rdbms/bdafisdc/bdafisdc1/trace/sbtio.log
SKGFQ OSD: Error in function sbtwrite2 on line 1097
SKGFQ OSD: Look for SBT Trace messages in file /u01/app/oracle/diag/rdbms/bdafisdc/bdafisdc1/trace/sbtio.log
SKGFQ OSD: Error in function sbtwrite2 on line 1097
SKGFQ OSD: Look for SBT Trace messages in file /u01/app/oracle/diag/rdbms/bdafisdc/bdafisdc1/trace/sbtio.log
SKGFQ OSD: Error in function sbtclose2 on line 1586
SKGFQ OSD: Look for SBT Trace messages in file /u01/app/oracle/diag/rdbms/bdafisdc/bdafisdc1/trace/sbtio.log

*** 2011-05-02 03:44:09.787
*** ACTION NAME:(0000072 STARTED4) 2011-05-02 03:44:09.787

SKGFQ OSD: Error in function sbtend on line 704
SKGFQ OSD: Look for SBT Trace messages in file /u01/app/oracle/diag/rdbms/bdafisdc/bdafisdc1/trace/sbtio.log
*** ACTION NAME:() 2011-05-02 03:44:22.088


*** 2011-05-02 03:44:22.088
Exception [type: unknown signal, unknown code] [ADDR:0x4A23DCE9AA169] [PC:0x2321257, slaac_int()+237] [flags: 0x0, count: 1]
DDE previous invocation failed before phase II
DDE was called in a 'No Invocation Mode'
----- Start Diag Diagnostic Dump -----
Diag diagnostic dump is performed due to an error in the diagfw code during error handling.
DDE is switched to protected mode during the diagnostic dump to prevent recursive errors in the error hadnling code.
Dump error and call stack for the diagnostic dump:

*** 2011-05-02 03:44:22.099
dbkedDefDump(): Starting a non-incident diagnostic dump (flags=0x0, level=1, mask=0x0)
----- Error Stack Dump -----
ORA-07445: exception encountered: core dump [slaac_int()+237] [unknown signal] [ADDR:0x4A23DCE9AA169] [PC:0x2321257] [unknown code] []
ORA-00600: internal error code, arguments: [1884], [0x2B0F9A5E9F20], [2583909272], [3165375983], [1], [], [], [], [], [], [], []
----- SQL Statement (None) -----
Current SQL information unavailable - no cursor.


From the sbt trace file, we see the problem happened during backup operation to sbt. From sbt logfile we see following message,

SBT-29451 (?) 05/02/11 03:26:09 [Critical] From: OB2BAR_SBT_CHANNEL@dc-db-01 "bdafisdc"  Time: 05/02/2011 03:26:09 AM
        Unexpected close reading NET message => aborting.



SBT-29410 (?) 05/02/11 03:29:55 [Critical] From: OB2BAR_SBT_CHANNEL@dc-db-01 "bdafisdc"  Time: 05/02/2011 03:29:55 AM
        Unexpected close reading NET message => aborting.

In conclusion, it is revealed that the message arrived because backup operation was failed initially but later no longer we got this warning. And backup went successfully. From sbt trace file immediately we hit unexpected close message we get backup successful message like below,

SBT-29360 (?) 05/02/11 03:34:11 [Normal] From: OB2BAR_SBT_CHANNEL@dc-db-01 "bdafisdc"  Time: 05/02/2011 03:34:11 AM
        Completed OB2BAR Backup: dc-db-cluster.passport.gov.bd:BDAFISDC_23122010.dbf "Oracle8"



SBT-29360 (?) 05/02/11 03:34:15 [Normal] From: OB2BAR_SBT_CHANNEL@dc-db-01 "bdafisdc"  Time: 05/02/2011 03:34:15 AM
        Starting OB2BAR Backup: dc-db-cluster.passport.gov.bd:BDAFISDC_23122010.dbf "Oracle8"