ITPub博客

首页 > Linux操作系统 > Linux操作系统 > [from metalink]How to find the offending SQL from a trace file

[from metalink]How to find the offending SQL from a trace file

原创 Linux操作系统 作者:txt1124 时间:2010-10-28 15:09:49 0 删除 编辑

 

How to find the offending SQL from a trace file [ID 154170.1]

 


 

Modified 21-APR-2010     Type BULLETIN     Status PUBLISHED

 

In this Document
  Purpose
  Scope and Application
  How to find the offending SQL from a trace file
     Step 1: Find the SQL
     Step 2: Find values of the bind variables
     Examples
  References


Applies to:

Oracle Server - Enterprise Edition - Version: 8.1.7.0 to 11.1.0.6 - Release: 8.1.7 to 11.1
Information in this document applies to any platform.
Checked for relevance on 04-JAN-2007
Appearance updated, no changes to technical content 16-FEB-2007
Corrected a formatting error 21-FEB-07

Checked for relevance on 21-Apr-2010

Purpose

This article describes how to find the SQL statement that was active at the time an internal (ORA-600) error or ORA-7445 error was reported.

Scope and Application

This note is intended as an aid to database administrators when diagnosing the cause of Oracle errors.

How to find the offending SQL from a trace file

Extracting the SQL statement from a trace file is a two-step process.

First you must find the SQL itself, then you must identify the values of any bind variables that the SQL may be referencing.

The following text assumes that you have located the trace file associated with the reported error.

Step 1: Find the SQL

Locate the line "Current cursor:" (this should be right at the beginning of the "*** Cursor Dump ***" section). Note the number associated with the current cursor. (See the examples below for more details)

If the current cursor number is 0 then no current SQL is available. Under these conditions, the Call Stack Trace displayed near the top of the trace file gives the best indication of what was happening at the time of the error. Normally, Oracle Support Services will need to see this trace file in order to progress the issue.

If the Current cursor number is non-zero, search the remainder of the trace file for the line beginning with "Cursor n" where n is the cursor number just found. From 10.2 and onwards, search for "Cursor#n". On the next line you should see "cursor name:" which will be followed by the SQL statement.

Note: You will quite often be able to locate the SQL by searching for the line "Current SQL statement for this session:". Normally this is displayed near the beginning of the trace file.

If the SQL statement does not reference any bind variables (ie. ":b1", ":b2", etc.) then Step 2 can be ignored.

Step 2: Find values of the bind variables

If the SQL statement does reference bind variables, then following the SQL statement shown in the cursor, you should in most cases be able to locate a section of text associated with each bind variable. Each section of text will begin "bind x:" where x ranges from 0 to n-1 where n is the number of bind variables used in the SQL statement.

There may be a large memory dump between the SQL statement and the binds - it should just be ignored at this stage.

For each bind variable there are a number of attributes listed. The following are the ones we are interested in here:

 

  • dty the datatype. Typical values are:

1 VARCHAR2 or NVARCHAR2
2 NUMBER
8 LONG
11 ROWID
12 DATE
23 RAW
24 LONG RAW
96 CHAR
112 CLOB or NCLOB
113 BLOB
114 BFILE

  • mxl the maximum length - ie. the maximum number of bytes occupied by the variable. Eg. dty=2 and mxl=22 denotes a NUMBER(22) column.
  • scl the scale (for NUMBER columns)
  • pre the precision (for NUMBER columns)
  • value the value of the bind variable



Mapping the bind variables from the cursor dump with the bind variables in the SQL statement
is straight-forward:

:b1 ~ bind 0
:b2 ~ bind 1
:b3 ~ bind 2
etc.

The binds can also be called :1, :2, etc. or :a1, :a2, etc. the important thing is that the *order* in which they are used in the SQL statement matches the order of the variable dumps.

So for a statement like:

 

SELECT * FROM MYTAB WHERE A = :1 AND B = :2 AND C = :3

 

bind variables should be mapped like:

:1 ~ bind 0
:2 ~ bind 1
:3 ~ bind 2

Note that it is possible for the same bind variable to occur multiple times in the SQL statement, but that does not change anything for the mapping, eg. if you have a statement like:

 

SELECT * FROM MYTAB WHERE A = :B1 OR B BETWEEN :B2 AND :B1

 

the mapping will be:

:b1 ~ bind 0
:b2 ~ bind 1
:b1 ~ bind 2    <-- the value for bind 2 should be the same as for bind 0

 

You should now be able to find the datatype of the bind variable (including length, scale, and precision if applicable) and the value.In some (rare) cases, there is no "value=..." included in the dump, and then the method described in step 2 cannot be used to identify the values of the bind variables.

Examples

In the following we will work through some examples of how to extract the SQL statement from trace files.

IMPORTANT:
Replacing bind variables with literals can result in the optimizer choosing a different query path and thus the problem may not reproduce!

Example 1:


You should now be able to find the datatype of the bind variable (including length, scale, and precision if applicable) and the value.

The cursor dump starts with:

******************** Cursor Dump ************************
Current cursor: 2, pgadep: 1
Cursor Dump:
----------------------------------------

so we are looking for cursor 2:

----------------------------------------
Cursor 2 (20139ad0): CURFETCH curiob: 2013bca4
curflg: 7 curpar: 20139ab0 curusr: 0 curses 587a250c
cursor name: select text from view$ where rowid=:1
child pin: 50a5b650, child lock: 50a5a628, parent lock: 50a5a844
xscflg: 20141466, parent handle: 4f348490, xscfl2: 400
nxt: 2.0x0000006c nxt: 1.0x000001d8
Cursor frame. allocation dump:
frm: -------- Comment -------- Size Seg Off
bhp size: 52/560
bind 0: dty=11 mxl=16(16) mal=00 scl=00 pre=00 acflg=18 oacfl2=1 size=16
offset=0
bfp=2013e9f4 bln=16 avl=16 flg=05
value=0000138C.0046.0004

The current SQL is:

select text from view$ where rowid=:1

and the bind variable translates into:

:1 ~ bind 0 - ROWID (dty=11), value = 0000138C.0046.0004

so we can eg. reconstruct the original SQL statement as:

SQL> variable a1 varchar2(20)
SQL> exec :a1 := '0000138C.0046.0004';
SQL> select text from view$ where rowid=:a1;

Note that we construct the statement using a SQL*Plus bind variable in order to prevent the optimizer from choosing a different plan (not that it would make any difference for this particular example).

Example 2:
The cursor dump starts with:

******************** Cursor Dump ************************
Current cursor: 11, pgadep: 1
Cursor Dump:
----------------------------------------

ie. we should look for cursor 11:

----------------------------------------
Cursor 11 (202cb9f0): CURBOUND curiob: 202f8b04
curflg: dd curpar: 0 curusr: 0 curses 30047c7c
cursor name: SELECT LOCKID FROM DBMS_LOCK_ALLOCATED WHERE NAME =
:b1 FOR UPDATE
child pin: 0, child lock: 300dc9b4, parent lock: 301730b8
xscflg: 1151421, parent handle: 3025b4dc
bind 0: dty=1 mxl=32(00) mal=00 scl=00 pre=00 acflg=01
No bind buffers allocated
----------------------------------------

The current SQL statement is then:

SELECT LOCKID FROM DBMS_LOCK_ALLOCATED WHERE NAME = :b1 FOR UPDATE

The bind variable :b1 is of type VARCHAR2(32) (dty=1, mxl=32), but no value has been assigned to it at the time of the dump ("No bind buffers allocated").


Example 3:

******************** Cursor Dump ************************
Current cursor: 2, pgadep: 0
Cursor Dump:
----------------------------------------
...
----------------------------------------
Cursor 2 (20140444): CURNULL curiob: 0
curflg: 44 curpar: 0 curusr: 0 curses 701dc94c
----------------------------------------

In this case there is no SQL being executed at the time of the dump.

Example 4:

******************** Cursor Dump ************************
Current cursor: 1, pgadep: 0
pgactx: ccf361c0 ctxcbk: 0 ctxqbc: 0 ctxrws: 0
Cursor Dump:
----------------------------------------
Cursor 1 (400d9478): CURBOUND curiob: 400e43d8
curflg: 4c curpar: 0 curusr: 0 curses d5348f80
cursor name: BEGIN myparser.convert('/tmp','workflow000_2.log',2); END;
child pin: d14a4d70, child lock: d1589968, parent lock: d14c64a0
xscflg: 100064, parent handle: d083f1c0, xscfl2: 4040408
nxt: 1.0x000000a8
Cursor frame. allocation dump:
frm: -------- Comment -------- Size Seg Off
----------------------------------------

No binds included, so the SQL statement is the PL/SQL block:

BEGIN myparser.convert('/tmp','workflow000_2.log',2); END;

来自 “ ITPUB博客 ” ,链接:https://blog.itpub.net/14730395/viewspace-676985/ ,如需转载,请注明出处,否则将追究法律责任。

请登录后发表评论 登录
全部评论

注册时间:2008-12-15

  • 博文量
    91
  • 访问量
    162488