打开相应的trace后。你会发现这类trace文件一般都是以“ksedmp:internal or fatal error"开头,"kesdmp"意味着Kernel Service Error Dump,这一行以下的内容就是errorstack记录的错误堆栈!
Errorstack dump也能够通过使用Oradebug errorstack 3手工调用,前提是先使用Oradebug setospid设定了目标进程之后。Oradebug Errorstack对于诊断一个session似乎Hang住(可是在v$session_wait里面并未出现合理的wait event)或者是比正常时消耗很多其它资源时。获取当前session运行sql、详细的变量值等等信息,从而帮助你找到问题根源!
二、跟踪级别和方法 ErrorStack主要有4个跟踪级别。例如以下
- 0 仅转储错误堆栈
- 1 转储错误堆栈和函数调用堆栈
- 2 Level 1 + ProcessState
- 3 Level 2 + Context area (一般我们诊断问题,都是使用这个级别的跟踪。)
- 实例级别:alter system set events=‘984 trace name errorstack forever,level 3‘ scope=spfile;
- 会话级别: alter session set events=‘984 trace name errorstack forever,level 3‘;
- oradebug: 1、oradebug
setospid xxxx; 2、oradebug dump errorstack 3 --当前session正在执行的语句
- 从Errorstack跟踪文件中发现当前正在运行SQL文本。
- 从Errorstack跟踪文件中发现当前正在运行PL/SQL包和PL/SQL source code line number。
- 从Errorstack跟踪文件中发现当前bind variable value。
- 从Errorstack跟踪文件中发现一个cursor正在使用多少private memory(UGA)。
这一部分的内容主要參考tanelpoder大牛的博客。
1、从Errorstack跟踪文件里发现当前正在运行SQL文本 这一部分很easy找到,当前sql语句的文本信息在跟踪文件的最前面部分(能够搜索Current SQL statement for this session)
Trace file /u01/oracle/diag/rdbms/cn100/cn100/trace/cn100_ora_10848.trcOracle Database 11g Enterprise Edition Release 11.2.0.1.0 - 64bit Production
With the Partitioning, Oracle Label Security, OLAP, Data Mining,
Oracle Database Vault and Real Application Testing options
ORACLE_HOME = /u01/oracle/product/11.2.0
System name: Linux
Node name: 192oracle.cn100.com
Release: 2.6.32-358.el6.x86_64
Version: #1 SMP Fri Feb 22 00:31:26 UTC 2013
Machine: x86_64
Instance name: cn100
Redo thread mounted by this instance: 1
Oracle process number: 26
Unix process pid: 10848, image: oracle@192oracle.cn100.com (TNS V1-V3)
*** 2014-07-01 11:16:36.260
*** SESSION ID:(61.13360) 2014-07-01 11:16:36.260
*** CLIENT ID:() 2014-07-01 11:16:36.260
*** SERVICE NAME:(SYS$USERS) 2014-07-01 11:16:36.260
*** MODULE NAME:(SQL*Plus) 2014-07-01 11:16:36.260
*** ACTION NAME:() 2014-07-01 11:16:36.260
dbkedDefDump(): Starting a non-incident diagnostic dump (flags=0x0, level=3, mask=0x0)
----- Error Stack Dump -----
ORA-01438: value larger than specified precision allowed for this column
----- Current SQL Statement for this session (sql_id=b8n03s73k7d39) ----- --能够看到,当前SQL就在这一行以下
INSERT INTO DH_T VALUES (:B2 ,:B1 )
----- PL/SQL Stack -----
----- PL/SQL Call Stack -----
object line object
handle number name
0x1075fcd10 6 procedure DBMON.P_DH1
0xfcfaebe8 7 procedure DBMON.P_DH2
0x10e7d6420 1 anonymous block
----- Call Stack Trace -----
calling call entry argument values in hex
location type point (? means dubious value)
-------------------- -------- -------------------- ----------------------------
skdstdst()+36 call kgdsdst() 000000000 ? 000000000 ?
7FFF332C8AD8 ?
000000001 ?
7FFF332CCFD8 ? 000000000 ?
......为了排版,兴许省略......
2、从Errorstack跟踪文件中发现当前正在运行PL/SQL包和PL/SQL source code line number Errorstack跟踪文件和前面一样,例如以下
Trace file /u01/oracle/diag/rdbms/cn100/cn100/trace/cn100_ora_10848.trcOracle Database 11g Enterprise Edition Release 11.2.0.1.0 - 64bit Production
With the Partitioning, Oracle Label Security, OLAP, Data Mining,
Oracle Database Vault and Real Application Testing options
ORACLE_HOME = /u01/oracle/product/11.2.0
System name: Linux
Node name: 192oracle.cn100.com
Release: 2.6.32-358.el6.x86_64
Version: #1 SMP Fri Feb 22 00:31:26 UTC 2013
Machine: x86_64
Instance name: cn100
Redo thread mounted by this instance: 1
Oracle process number: 26
Unix process pid: 10848, image: oracle@192oracle.cn100.com (TNS V1-V3)
*** 2014-07-01 11:16:36.260
*** SESSION ID:(61.13360) 2014-07-01 11:16:36.260
*** CLIENT ID:() 2014-07-01 11:16:36.260
*** SERVICE NAME:(SYS$USERS) 2014-07-01 11:16:36.260
*** MODULE NAME:(SQL*Plus) 2014-07-01 11:16:36.260
*** ACTION NAME:() 2014-07-01 11:16:36.260
dbkedDefDump(): Starting a non-incident diagnostic dump (flags=0x0, level=3, mask=0x0)
----- Error Stack Dump -----
ORA-01438: value larger than specified precision allowed for this column
----- Current SQL Statement for this session (sql_id=b8n03s73k7d39) ----- --能够看到,当前SQL就在这一行以下
INSERT INTO DH_T VALUES (:B2 ,:B1 )
----- PL/SQL Stack -----
----- PL/SQL Call Stack -----
object line object
handle number name
0x1075fcd10 6 procedure DBMON.P_DH1
0xfcfaebe8 7 procedure DBMON.P_DH2
0x10e7d6420 1 anonymous block
----- Call Stack Trace -----
calling call entry argument values in hex
location type point (?
means dubious value)
-------------------- -------- -------------------- ----------------------------
skdstdst()+36 call kgdsdst() 000000000 ?
000000000 ?
7FFF332C8AD8 ? 000000001 ?
7FFF332CCFD8 ? 000000000 ?
......为了排版,兴许省略......
这部分告诉你发生错误时Oracle在运行详细哪个PL/SQL过程(包or函数)以及errorstack跟踪过程中的详细哪个调用发生错误。这对我们诊断问题很有帮助
PL/SQL Call Stack包括三列,例如以下- object handle
- line number
- object name
以上的PL/SQL call stack只包括三行。 0x1075fcd10 6 procedure DBMON.P_DH1
0xfcfaebe8 7 procedure DBMON.P_DH2
0x10e7d6420 1 anonymous block
应该从下而上来阅读一个PL/SQL call stack,比如 1.底部的行能够告诉我们正在运行一个匿名块以及在这个匿名块的第一行。它在调用DBMON.P_DH2存储过程 2.第二行能够告诉我们DBMON.P_DH2存储过程在第7行调用了另外一个存储过程DBMON.P_DH1 3.DBMON.P_DH2存储过程中的第6行代码出现错误,errorstack信息被转储。
通过查询DBA_SOURCE,我们能够与errorstack跟踪文件里的PL/SQL call stack部分信息进行验证,例如以下。 SQL> select line, text from dba_source where owner = ‘DBMON‘ and name = ‘P_DH2‘ order by line asc; LINE TEXT ---------- ------------------------------------------------------------ 1 procedure p_dh2 as 2 v_cnt number; 3 begin 4 ----just for errorstack test 5 select count(*) into v_cnt from dh_t; 6 dbms_output.put_line(‘the dh_t count is ‘||v_cnt); 7 p_dh1; 8 end; 9 9 rows selected. SQL> select line, text from dba_source where owner = ‘DBMON‘ and name = ‘P_DH1‘ order by line asc; LINE TEXT ---------- ------------------------------------------------------------ 1 procedure p_dh1 as 2 v_id number :=1234335; 3 v_name varchar2(200) :=‘oradh‘; 4 begin 5 --just for errorstack test 6 insert into dh_t values (v_id,v_name); 7 commit; 8 end; 9 9 rows selected. 你能够发现会话正在运行的PL/SQL第6行(一个insert语句导致错误)。 通常,当error dump,crash,hang发生时(顶部的行是”parent" function递归调用的“child”function正在运行的代码),PL/SQL errorstack告诉我们精确的PL/SQL code。
3、从Errorstack跟踪文件中发现当前bind variable value 为什么找到详细的语句后,我们还须要寻找详细的绑定变量值??能够归纳为例如以下四种原因
- 一个会话可能以某种方式变的很消耗CPU,而且会话的wait等待时间没有不论什么意义.
- 你须要调查什么SQL正在被运行,而且你须要查看SQL带有的绑定变量
- SQL的运行计划是正常的,可是性能却很低下
- 能够如果当某些表或者行源变的大的时候,存在数据倾斜。CBO没有计算出正确的运行计划。
Oracle 11gR2中实时的SQL Monitoring特性可以达到此目的。在V$SQL_MONITOR中有一列BIND_XML,此列包括正在执行的足够长时间(默认占用CPU超过5s的SQL。都会出如今次视图中)的bind variable values.可是这个仅仅有在11gR2而且具有Diag+Tuning pack licenses时才有效。 注意:因为SQL语句的绑定变量值存在于进程的PGA中的私有内存中,因此不能轻易的跟踪还有一个进程私有内存。
errorstack跟踪文件里中包括CURSORDUMP,也就包括我们想要得到的bind variable value。
我们继续看開始的跟踪文件,例如以下 Trace file /u01/oracle/diag/rdbms/cn100/cn100/trace/cn100_ora_10848.trc
Oracle Database 11g Enterprise Edition Release 11.2.0.1.0 - 64bit Production
With the Partitioning, Oracle Label Security, OLAP, Data Mining,
Oracle Database Vault and Real Application Testing options
ORACLE_HOME = /u01/oracle/product/11.2.0
System name: Linux
Node name: 192oracle.cn100.com
Release: 2.6.32-358.el6.x86_64
Version: #1 SMP Fri Feb 22 00:31:26 UTC 2013
Machine: x86_64
Instance name: cn100
Redo thread mounted by this instance: 1
Oracle process number: 26
Unix process pid: 10848, image: oracle@192oracle.cn100.com (TNS V1-V3)
*** 2014-07-01 11:16:36.260
*** SESSION ID:(61.13360) 2014-07-01 11:16:36.260
*** CLIENT ID:() 2014-07-01 11:16:36.260
*** SERVICE NAME:(SYS$USERS) 2014-07-01 11:16:36.260
*** MODULE NAME:(SQL*Plus) 2014-07-01 11:16:36.260
*** ACTION NAME:() 2014-07-01 11:16:36.260
dbkedDefDump(): Starting a non-incident diagnostic dump (flags=0x0, level=3, mask=0x0)
----- Error Stack Dump -----
ORA-01438: value larger than specified precision allowed for this column
----- Current SQL Statement for this session (sql_id=b8n03s73k7d39) ----- --能够看到,当前SQL就在这一行以下
INSERT INTO DH_T VALUES (:B2 ,:B1 )
----- PL/SQL Stack -----
----- PL/SQL Call Stack -----
object line object
handle number name
0x1075fcd10 6 procedure DBMON.P_DH1
0xfcfaebe8 7 procedure DBMON.P_DH2
0x10e7d6420 1 anonymous block
----- Call Stack Trace -----
calling call entry argument values in hex
location type point (?
means dubious value)
-------------------- -------- -------------------- ----------------------------
skdstdst()+36 call kgdsdst() 000000000 ? 000000000 ?
7FFF332C8AD8 ?
000000001 ?
7FFF332CCFD8 ? 000000000 ?
......为了排版,兴许省略......
打开跟踪文件。通常第一步做的是搜索第一个"Session Cursor Dump",当搜索它的时候,将看到例如以下的输出
----- Session Cursor Dump -----Current cursor: 2, pgadep=1