Tracefile information in Oracle 11.2

I’ve just been working on a bug, and needed to get some information on an (unhandled) exception which was caused by the operating system. Typically, these are ORA-07445’s. (If the exception is caused by the database server code itself, it’s typically an ORA-00600, and the code location is the first argument within the square brackets)

This is the relevant part about the exception in the alert.log file:

Exception [type: SIGSEGV, Address not mapped to object] [ADDR:0x71] [PC:0x1CCD521, kkqstcrf()+1355] [flags: 0x0, count: 1]
Errors in file /oracle/diag/rdbms/iris/iris/trace/iris_ora_5127.trc (incident=32602):
ORA-07445: exception encountered: core dump [kkqstcrf()+1355] [SIGSEGV] [ADDR:0x71] [PC:0x1CCD521] [Address not mapped to obj
ect] []
Incident details in: /oracle/diag/rdbms/iris/iris/incident/incdir_32602/iris_ora_5127_i32602.trc

What we see here is the notification of the SIGSEGV exception, which in older versions would be preceded by the database failure code (ORA-07445), details about the exception (PC address, and code location), and a line describing in which tracefile we can find more details: /oracle/diag/rdbms/iris/iris/trace/iris_ora_5127.trc, followed by again something new: the incident number.

There are two things to say about the first two lines: the tracefile will not contain anything usefull for diagnosing this error (as we will see in a short while) and: the database groups errors into “incidents”. This is connected with the OCM (Oracle Configuration Manager), which can bundle and upload details about problems as incidents.

Let’s see what is in: /oracle/diag/rdbms/iris/iris/trace/iris_ora_5127.trc

Trace file /oracle/diag/rdbms/iris/iris/trace/iris_ora_5127.trc
Oracle Database 11g Enterprise Edition Release 11.2.0.1.0 - 64bit Production
With the Partitioning, OLAP, Data Mining and Real Application Testing options
ORACLE_HOME = /oracle/db/11.2.0.1
System name: Linux
Node name: iris.local
Release: 2.6.18-194.el5
Version: #1 SMP Mon Mar 29 22:10:29 EDT 2010
Machine: x86_64
Instance name: iris
Redo thread mounted by this instance: 1
Oracle process number: 25
Unix process pid: 5127, image: oracle@iris.local (TNS V1-V3)
.
.
*** 2010-07-01 14:11:09.270
*** SESSION ID:(17.9) 2010-07-01 14:11:09.270
*** CLIENT ID:() 2010-07-01 14:11:09.270
*** SERVICE NAME:(SYS$USERS) 2010-07-01 14:11:09.270
*** MODULE NAME:(SQL*Plus) 2010-07-01 14:11:09.270
*** ACTION NAME:() 2010-07-01 14:11:09.270
.
Exception [type: SIGSEGV, Address not mapped to object] [ADDR:0x71] [PC:0x1CCD521, kkqstcrf()+1355] [flags: 0x0, count: 1]
.
*** 2010-07-01 14:11:10.182
Incident 32602 created, dump file: /oracle/diag/rdbms/iris/iris/incident/incdir_32602/iris_ora_5127_i32602.trc
ORA-07445: exception encountered: core dump [kkqstcrf()+1355] [SIGSEGV] [ADDR:0x71] [PC:0x1CCD521] [Address not mapped to object] []
.
ssexhd: crashing the process...
Shadow_Core_Dump = partial

Mmmh, there is NO additional information in the “normal” tracefile! It only re-displays the error, and points to the “incident tracefile”: /oracle/diag/rdbms/iris/iris/incident/incdir_32602/iris_ora_5127_i32602.trc!!

Let’s have a look in that file! Is that the file we need?

Dump file /oracle/diag/rdbms/iris/iris/incident/incdir_32602/iris_ora_5127_i32602.trc
Oracle Database 11g Enterprise Edition Release 11.2.0.1.0 - 64bit Production
With the Partitioning, OLAP, Data Mining and Real Application Testing options
ORACLE_HOME = /oracle/db/11.2.0.1
System name: Linux
Node name: iris.local
Release: 2.6.18-194.el5
Version: #1 SMP Mon Mar 29 22:10:29 EDT 2010
Machine: x86_64
Instance name: iris
Redo thread mounted by this instance: 1
Oracle process number: 25
Unix process pid: 5127, image: oracle@iris.local (TNS V1-V3)
.
.
*** 2010-07-01 14:11:10.183
*** SESSION ID:(17.9) 2010-07-01 14:11:10.183
*** CLIENT ID:() 2010-07-01 14:11:10.183
*** SERVICE NAME:(SYS$USERS) 2010-07-01 14:11:10.183
*** MODULE NAME:(SQL*Plus) 2010-07-01 14:11:10.183
*** ACTION NAME:() 2010-07-01 14:11:10.183
.
Dump continued from file: /oracle/diag/rdbms/iris/iris/trace/iris_ora_5127.trc
ORA-07445: exception encountered: core dump [kkqstcrf()+1355] [SIGSEGV] [ADDR:0x71] [PC:0x1CCD521] [Address not mapped to object] []
.
========= Dump for incident 32602 (ORA 7445 [kkqstcrf()+1355]) ========
----- Beginning of Customized Incident Dump(s) -----
Exception [type: SIGSEGV, Address not mapped to object] [ADDR:0x71] [PC:0x1CCD521, kkqstcrf()+1355] [flags: 0x0, count: 1]
Registers:
%rax: 0x00002af3795b7848 %rbx: 0x00002af3744dfa98 %rcx: 0x0000000000000002
%rdx: 0x0000000000000000 %rdi: 0x000000000a99d540 %rsi: 0x00000000733477f8
%rsp: 0x00007fffc86bec40 %rbp: 0x00007fffc86bed40 %r8: 0x0000000000000001
%r9: 0x0000000000002000 %r10: 0x00000000087f74c0 %r11: 0x0000000000000168
%r12: 0x0000000000000001 %r13: 0x00002af370d27988 %r14: 0x00002af3744cd6a8
%r15: 0x0000000000000001 %rip: 0x0000000001ccd521 %efl: 0x0000000000010202
> (0x1ccd521) mov 0x70(%r8),%rdx
(0x1ccd525) test %rdx,%rdx
(0x1ccd528) je 0x1ccd59b
(0x1ccd52a) mov 0x70(%r14),%rcx
(0x1ccd52e) test %rcx,%rcx
.
*** 2010-07-01 14:11:10.340
dbkedDefDump(): Starting a non-incident diagnostic dump (flags=0x3, level=3, mask=0x0)
----- Current SQL Statement for this session (sql_id=d6kswm1p11r93) -----
select
......SQL......
.
----- Call Stack Trace -----
calling call entry argument values in hex
location type point (? means dubious value)
-------------------- -------- -------------------- ----------------------------
skdstdst()+36 call kgdsdst() 000000000 ? 000000000 ?
2AF370989118 ? 000000001 ?
2AF37098D618 ? 000000000 ?
ksedst1()+98 call skdstdst() 000000000 ? 000000000 ?
2AF370989118 ? 000000001 ?
000000000 ? 000000000 ?
ksedst()+34 call ksedst1() 000000001 ? 000000001 ?
2AF370989118 ? 000000001 ?
000000000 ? 000000000 ?
dbkedDefDump()+2736 call ksedst() 000000001 ? 000000001 ?
2AF370989118 ? 000000001 ?
000000000 ? 000000000 ?
ksedmp()+36 call dbkedDefDump() 000000003 ? 000000003 ?
2AF370989118 ? 000000001 ?
000000000 ? 000000000 ?
ssexhd()+2326 call ksedmp() 000000003 ? 000000003 ?
2AF370989118 ? 000000001 ?
000000000 ? 000000000 ?
__restore_rt() call ssexhd() 00000000B ? 2AF370991D70 ?
2AF370991C68 ? 000000001 ?
000000000 ? 000000000 ?
kkqstcrf()+1355 signal __restore_rt() 00A99
.....etc.

Yes! This is the file we need! The heading is the same as a “normal” or “non-incident” tracefile. The first line after the heading tells us it is a “continuated tracefile”: “Dump continued from file: /oracle/diag/rdbms/iris/iris/trace/iris_ora_5127.trc”. In fact, at least for this type of error, there isn’t any real information in the “normal” tracefile.

My current understanding is, that if an “incident tracefile” is mentioned in the alert.log, it’s quicker to directly go to the “incident tracefile”, and skip the “normal tracefile”. Other information still is in the “normal tracefile”, like SQL/10046 or CBO/10053 traces.

About these ads
4 comments
  1. kavitasanjay said:

    Did you get a fix? I am currently working with oracle and we seem to run into same issue. Ours is 11.1.0.7 with Oracle ASO. So far we have not reached any conclusion.

    • The purpose of the post was to point out the new ‘incident’ system, where a tracefile in the diag dest only contains a small portion of the information if there’s an incident in adrci, the tracefile is continued in the incident.

      This error was caused by a huge amount of ansi-joins, made by Hibernate, a java persistence layer. The way to resolve this issue was to eliminate un-necessary joins (I believe this can be done setting lazy=true in Hibernate).

      • kavitasanjay said:

        Thanks! We will look at our queries as well.

  2. The function in which the error occurs is kkqstcrf() (as can be seen in the alert.log excerpt in this blog article), which is a function which has to do with query rewrite operations, which turned out to be due to a huge amount of ANSI joins.

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s

Follow

Get every new post delivered to your Inbox.

Join 2,060 other followers

%d bloggers like this: