在Oracle数据库执行过程中,我们常常会遇到这样或那样的错误。可是错误的提示并不详细,加大了我们在诊断问题时的难度。
ErrorStack是Oracle提供的一种对于错误堆栈进行跟踪的方法,通过设置跟踪能够将一些指定错误的后台信息具体的转储出来,写入跟踪文件,帮助我们诊断问题。
备注:
1、当oracle发生关键的错误诸如:ora-600,Errorstack是自己主动被oracle dump写入trace文件里。
2、当你在alert.log里面看见这类错误,并提示已经产生trace文件。打开相应的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 (一般我们诊断问题,都是使用这个级别的跟踪。)
ErrorStack设置方法,例如以下(仅指定特定的错误代码,仅仅有这个特定的错误出现时才干被触发。)
- 实例级别: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跟踪文件里的内容
Errorstack跟踪文件有非常多信息,这里我们主要解说对我们诊断问题最实用的四个部分的内容(其他非常多内容我们无法看懂),例如以下
- 从Errorstack跟踪文件中发现当前正在运行SQL文本。
- 从Errorstack跟踪文件中发现当前正在运行PL/SQL包和PL/SQL source code line number。
- 从Errorstack跟踪文件中发现当前bind variable value。
- 从Errorstack跟踪文件中发现一个cursor正在使用多少private memory(UGA)。
针对上面的四个部分,我将通过一个详细的errorstack跟踪文件演示样例来展示盒加深理解,errorstack的跟踪文件例如以下(详细生成方式代码,放在最后了)。
这一部分的内容主要參考tanelpoder大牛的博客。
1、从Errorstack跟踪文件里发现当前正在运行SQL文本
这一部分很easy找到,当前sql
语句的文本信息在跟踪文件的最前面部分(能够搜索Current SQL statement for this session)
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 ?
......为了排版,兴许省略......
2、从Errorstack跟踪文件中发现当前正在运行PL/SQL包和PL/SQL source code line number
Errorstack跟踪文件和前面一样,例如以下
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 ?
......为了排版,兴许省略......
注意上面跟踪文件里PL/SQL标红那一部分,就是我们关注的部分。
假设进行errorstack跟踪式,跟踪进程运行的是一个PL/SQL调用。那么PL/SQL调用堆也将被跟踪下来(在PL/SQL Call Stack部分)。这部分告诉你发生错误时Oracle在运行详细哪个PL/SQL过程(包or函数)以及errorstack跟踪过程中的详细哪个调用发生错误。这对我们诊断问题很有帮助
PL/SQL Call Stack包括三列,例如以下
- object handle
- line number
- object name
以下我们一一介绍这三列的含义:
1、object handle
object handle是这个对象(PL/SQL过程、包、函数、匿名块)被load进library cache中的内存地址,能够通过这个映射地址和X$KGLOB.KGLHDADR表列关联起来以发现那个对象是正在被处理。例如以下
SQL> select kglnaown,kglnaobj,kglhdadr from X$KGLOB a where KGLHDADR=‘00000001075FCD10‘;
KGLNAOWN KGLNAOBJ KGLHDADR
---------- ---------- ----------------
DBMON P_DH1 00000001075FCD10
2、line number
这个是很重要的信息,它将告诉你当errorstack调用发生时正在运行的PL/SQL代码(能够定位到代码中的详细行)。比如,在如上的输出中。在这个匿名块的第1行调用了DBMON.P_DH2存储过程,而DBMON.P_DH2存储过程在第7行调用了另外一个存储过程DBMON.P_DH1,当errorstack跟踪发生时正在运行DBMON.P_DH2存储过程中的第6行代码。
3、object name
PL/SQL存储的对象名(或者匿名块,当对象并没有存储在一个过程中),假设是匿名块(匿名块的文本能够通过V$SQL发现),你能够关联这个地址和V$SQL.ADDRESS来发现匿名块的文本信息。
以上的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没有计算出正确的运行计划。
因此。你须要知道当问题发生时SQL使用的绑定变量是什么。不幸的是Oracle中并没有一个V$视图让我们去查看某个session的当前绑定变量值。V$SQL_BIND_CAPTURE视图只随机的採样绑定变量值。并不存储全部的被使用的绑定变量值。而dbms_xplan.display_cursor中显示的也不过第一次窥探的绑定变量值.
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