How to read Oracle Errorstack Output
the
Wirte By tanelpoder, translation by me.
When a critical error occurs in oracle such as: ora-600, the Errorstack dump is automatically dumped by oracle. When you see an error in the alert.log, a trace file will be generated, and the trace will start with “ksedmp: internal or fatal
error”, errors such as this (ORA-7445 or ORA-600 with some parameters). “kesdmp” means Kernel Service Error Dump, so the following line is the errorstack dump.
the
Errorstack dump can also be invoked manually using Oradebug errorstack 3 (after setting the target process with Oradebug setospid). Oradebug Errorstack for when a session seems Hang(
But there is no reasonable wait event in v$session_wait) or it consumes more resources than normal and you want to know the specific variable value of the current sql.
the
The Errorstack trace file has a lot of information, which is more or less useful for our troubleshooting. But the large amount of data and binary dumps may confuse you, here I will show you some structures that you can understand.
In this article we will explore the following topics:
1. From the errorstack trace file, it is found that the SQL text is currently being executed.
2. From the errorstack trace file, it is found that the PL/SQL package and PL/SQL source code line number are currently being executed.
3. Find the current bind variable value from the errorstack trace file.
4. Find out how much private memory (UGA) a cursor is using from the errorstack trace file.
www.2cto.com
I’ll paste the relevant part of an errorstack dump in the elaboration below.
1. From the errorstack trace file, it is found that the SQL text is currently being executed.
You will be very easy to find the text information of the current SQL, this statement is in the front part of the tracefile (“Current SQL statement for this session”):
[html]
*** 2010-02-14 15:30:32.830
*** SERVICE NAME:(SOL102) 2010-02-14 15:30:32.829
*** SESSION ID: (156.974) 2010-02-14 15:30:32.829
Received ORADEBUG command ‘dump errorstack 3’ from process Unix process pid: 8556, image:
the
*** 2010-02-14 15:30:32.830
ksedmp: internal or fatal error
Current SQL statement for this session:
DELETE FROM MYTAB WHERE OWNER = :B1
the
—– PL/SQL Call Stack —–
object object line object
handle number name
38d172270 8 function SYS.DELETE_FUNC
38d1518f0 1 anonymous block
—– Call Stack Trace —– www.2cto.com
calling
location type point (? means dubious value)
——————– ——– ——————– — ————————–
ksedst()+23 ? 0000000000000001 0017B342C 000000000 0FFDF2420
ksedmp()+636 ? 0000000000000001 0017B1EC1 000000000 00601C7E0
ksdxfdmp()+1062 ? 0000000000000001 0018A3F03 000000000 00601C7E0
ksdxcb()+1238 ? 0000000000000001 0018A22D3 000000000 0FF2DCC80
….
2. From the errorstack trace file, it is found that the PL/SQL package and PL/SQL source code line number are currently being executed.
[html]
*** 2010-02-14 15:30:32.830
ksedmp: internal or fatal error
Current SQL statement for this session:
DELETE FROM MYTAB WHERE OWNER = :B1
the
—– PL/SQL Call Stack —–
object object line object
handle number name
38d172270 8 function SYS.DELETE_FUNC
38d1518f0 1 anonymous block
www.2cto.com
—–Call Stack Trace—–
calling
location type9 24 144 100 133 8……..t.&..V…d.
0080: 81 193 219 234 223 154 138 3 1 2 192 214 188 3 2 14 142 Q………. www.2cto.com
=============
Plan Table
=============
————————————–+———– ————————+
| Id | Operation | Name | Rows | Bytes | Cost |
————————————–+———– ————————+
| 0 | DELETE STATEMENT | | | | 1366 |
| 1 | DELETE | MYTAB | | |
| 2 | TABLE ACCESS FULL | MYTAB | 119K | 2023K | 1366 | 00:00:17 |
————————————–+———– ————————+
the
We can find Current cursor: 6, which tells us that Cursor#6 is being executed in the cursor opened in UGA of this session.
The pgadep: 1 variable tells us the PGA depth, which is the depth of recursion executed by this query. If pgadep is 0, it means that the query is a top-level query being executed by the user or application through the OCI interface. A value of 1 for pgadep means that it is a recursive query, executed through the Recursive Programming Interface (RPI), which may be a data dictionary query or just SQL to be executed through PL/SQL.
Therefore, to be able to find the bind variable value of the current query currently being executed, what we need to do is to search for Cursor6# forward in the trace file, remember: this is case sensitive.
[html]
Cursor#6(fffffd7ffddb1918) state=BOUND curiob=fffffd7ffdd0f380
curflg=cd fl2=0 par=0 ses=398f72fe8
sqltxt(38d15d0f8)=DELETE FROM MYTAB WHERE OWNER = :B1
hash=332a8a504bccd7f1a4a726a2879e71d9
parent=38ca516d0 maxchild=01 plk=395bf4dd8 ppn=n
cursor instantiation=fffffd7ffdd0f380 used=1266132628
child#0(38d151620) pcs=38ca512e0
clk=395b767b8 ci=38ca509c8 pn=38d179e58 ctx=38cc705e0
kgsccflg=0 llk[fffffd7ffdd0f388,fffffd7ffdd0f388] idx=0
xscflg=c0110676 fl2=1d120000 fl3=4228218c fl4=100
Bind bytecodes
Opcode = 6 Bind Rpi Scalar Sql In(may be out) Nocopy NoSkip
Offsi = 48, Offsi = 0
kkscoacd
the
Bind#0 www.2cto.com
oacdty=01 mxl=32(32) mxlc=00 mal=00 scl=00 pre=00
oacflg=13 fl2=206001 frm=01 csi=31 siz=32 off=0
kxsbbbfp=fffffd7ffdd31808 bln=32 avl=03 flg=09
value=”SYS”
Frames pfr fffffd7ffdd3f8c0 siz=4488 efr fffffd7ffdd3f800 siz=4464
enxt: 3.0x000004b0 enxt: 2.0×00000020 enxt: 1.0x00000ca0
pnxt: 2.0×00000008 pnxt: 1.0×00000010
kxscphp fffffd7ffddc0388 siz=984 inu=472 nps=344
kxscbhp fffffd7ffdcef1a8 siz=1008 inu=120 nps=0
kxscwhp fffffd7ffddc0748 siz=10496 inu=6608 nps=6608
1. We have found that Cursor#6 has state=BOUND from the trace file, which means that the bound variable value has been assigned.
2. The SQL text is what we have found out earlier, we can see only one bind variable value (it is automatically placed by the PL/SQL execution engine).
the
3. Bind variable numbering starts from 0, so if we want to go to the first bound value of the card, we need to search for Bind#0.
This is where we can systematically and reliably find the bind variable values being used.
4. Find out how much private memory (UGA) a cursor is using from the errorstack trace file
Finally, continuing our previous example, we can measure how much UGA private memory is used by certain cursors of a session.
[html]
Cursor frame dump
enxt: 3.0x000004b0 enxt: 2.0×00000020 enxt: 1.0x00000ca0
pnxt: 2.0×00000008 pnxt: 1.0×00000010
kxscphp fffffd7ffddc0388 siz=984 inu=472 nps=344
kxscbhp fffffd7ffdcef1a8 siz=1008 inu=120 nps=0
kxscwhp fffffd7ffddc0748 siz=10496 inu=6608 nps=6608
In the cursor frame dump section, we can see some information about the start of kxsc, which means Kernel eXECUTION Shared Cursor. The siz of each line tells us the size of the private memory currently allocated. Of course, we need to summarize all siz, this value is the memory usage of this cursor.
the
Here is a summary of some of my guesses: www.2cto.com
[html]
Heap description Meaning
kxscphp Cursor permanent heap. Allocated when cursor is opened
kxscdfhp Cursor default heap – default duration allocations
kxscehp Cursor ephemeral heap – short lived duration allocations
kxscwhp Cursor Work heap – used when actually executing the cursor (workareas etc)
kxscbhp Cursor Bind heap – this is where bind variable values and their metadata are kept.
the
the
Author Coast_lichao
nbsp;
kxscdfhp Cursor default heap – default duration allocations
kxscehp Cursor ephemeral heap – short lived duration allocations
kxscwhp Cursor Work heap – used when actually executing the cursor (workareas etc)
kxscbhp Cursor Bind heap – this is where bind variable values and their metadata are kept.
the
the
Author Coast_lichao
How to read OracleErrorstackOutput
This article is from the internet and does not represent1024programmerPosition, please indicate the source when reprinting:https://www.1024programmer.com/how-to-read-oracleerrorstackoutput/