Oracle Troubleshooting: How to read Oracle ERRORSTACK output?!

I have written the first article to the troubleshooting section of my new website

It’s about a very valuable Oracle troubleshooting tool -> ERRORSTACK trace.

I cover 4 frequently asked questions there:

  1. Reading the current executing SQL statement text from errorstack trace
  2. Reading the current executing PL/SQL package and PL/SQL source code line number from errorstack trace
  3. Reading the current bind variable values from errostack trace
  4. Identifying how much private (UGA) memory a cursor is using

You can read it here:

By the way, if you like my new website, feel free to link to it !!! ;-)

This entry was posted in Cool stuff, Oracle and tagged , , , . Bookmark the permalink.

18 Responses to Oracle Troubleshooting: How to read Oracle ERRORSTACK output?!

  1. Hi Tanel,

    great article. Just a small typo: it´s v$sql_bind_capture instead of v$sql_plan_capture.

    Looking forward to reading more great stuff on e2sn…


  2. Tanel Poder says:

    @Martin Decker
    Hi Martin,

    Thanks, the typo is fixed now.

  3. Chris Neumueller says:

    Hi Tanel!

    Thanks for a very interesting read. I found another typo: x$klgob should be replaced with x$kglob.


  4. Maxx says:

    Hi Tanel, Do you have a RSS feed setup for the new website ??

  5. Tanel Poder says:

    Hi Maxx,

    I’m still working on the best solution, I need to test out few things before I can publish this. Basically people need to join the site with their google account… stay tuned!:)

  6. Giridhar Kodakalla says:

    Are there any occassions where the “Current SQL Statement for this Session” in the trace file will be different than whatever is being found from the PL/SQL code (if the sql is from a pl/sql program) which you demonstrated in “Reading the current executing PL/SQL package and PL/SQL source code line number from errorstack trace” by querying DBA_SOURCE?

    If yes, would you please let us know.

    Giridhar Kodakalla.

  7. Tanel Poder says:

    @Giridhar Kodakalla
    Well, if the SQL you fire from your PL/SQL causes some other SQL to fire recursively (triggers, auditing, recursive data dictionary queries) then you may see other SQL pop up there if you take the errorstack dump when the recursive SQL happens to be executing.

  8. Dave Hays says:

    I am a great fan of your posts, this is the first time I’ve communicated with you directly – I have what a simple question -I am trying to reproduce the
    examples in


    in which you are able to obtain bind information using oradebug dump errorstack 3

    I am following the progression in your article, but I’m unable to reproduce the same when I try it at home. What I always see instead of “value=” in my trace dumps is:

    No bind buffers allocated

    Can you shed some light on this ? I’m not expecting that I need to tinker with the hidden parameter _optim_peek_user_binds (believe thats the name).

    I thank you greatly in advance for any feedback you can provide –

    Dave Hays
    Caterpillar, Inc.

  9. Tanel Poder says:

    @Dave Hays
    Can you post the full testcase here, e.g. which SQL are you running and when exactly are you running the dump command.

  10. Dave Hays says:

    @Tanel Poder
    sure –

    I have a table called BINDTEST :
    SQL> desc bindtest;
    Name Null? Type
    —————————————– ——– —————————-

    SQL> select * from bindtest;



    The simplest test I could think of was an anonymous block of PL/SQL with the following delete statement:

    script name delete.sql:

    variable B1 number;
    exec :B1 := 10;

    delete bindtest where v1 = :B1;

    And here’s the test:
    I setospid to my current session:
    Terminal 1:
    SQL> !ps -ef | grep 32191
    haysdj 467 32191 0 14:43 pts/3 00:00:00 grep 32191
    haysdj 32191 21417 0 14:40 pts/3 00:00:00 sqlplus
    oracle 32220 32191 0 14:40 ? 00:00:00 oraclez1tr (DESCRIPTION=(LOCAL=YES)(ADDRESS=(PROTOCOL=beq)))

    Terminal 2:
    SQL> oradebug setospid 32220
    Oracle pid: 27, Unix process pid: 32220, image: ( TNS V1-V3)

    I run my simple delete script:


    SQL> @delete

    PL/SQL procedure successfully completed.

    PL/SQL procedure successfully completed.


    I dump errorstack (level 3)
    Terminal 2
    SQL> oradebug dump errorstack 3
    Statement processed.

    My trace output is as follows:

    Unix process pid: 32220, image: (TNS V1-V3)

    *** 2011-05-20 14:44:25.821
    *** ACTION NAME:() 2011-05-20 14:44:25.810
    *** MODULE NAME:(SQL*Plus) 2011-05-20 14:44:25.810
    *** SERVICE NAME:(SYS$USERS) 2011-05-20 14:44:25.810
    *** SESSION ID:(305.915) 2011-05-20 14:44:25.810
    Received ORADEBUG command ‘dump errorstack 3′ from process Unix process pid: 364, image:
    *** 2011-05-20 14:44:25.821
    ksedmp: internal or fatal error
    Current SQL statement for this session:
    delete bindtest where v1 = :B1;

    Cursor#1(0x2b9b42321768) state=BOUND curiob=0x2b9b4233ce40
    curflg=cd fl2=0 par=(nil) ses=0x8f64ed70
    sqltxt(0x883fe0f0)=DELETE BINDTEST WHERE V1 = :B1
    parent=0x8779afc8 maxchild=01 plk=0x8c35b8e8 ppn=n
    cursor instantiation=0x2b9b4233ce40 used=1305920648
    child#0(0x883fdec8) pcs=0x8779abd8
    clk=0x8c2d9c90 ci=0x83f9d2e0 pn=(nil) ctx=0x840ba8a8
    kgsccflg=0 llk[0x2b9b4233ce48,0x2b9b4233ce48] idx=0
    xscflg=80110436 fl2=15000000 fl3=208218c fl4=0
    Bind bytecodes
    Opcode = 6 Bind Rpi Scalar Sql In(may be out) Nocopy NoSkip
    Offsi = 48, Offsi = 0
    oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
    oacflg=13 fl2=202001 frm=00 csi=00 siz=24 off=0
    No bind buffers allocated

  11. Tanel Poder says:

    This is likely because you’re not running the query anymore. Run something which takes longer time so you could run the oradebug command when the query is still running.

    What I use for demos is:

    SELECT COUNT(*) FROM some_table a, sometable b, sometable c WHERE a.some_col != :bind1 and b.some_col != :bind2

    Btw, you don’t need PL/SQL anonymous block to use bind variables…

  12. Dave Hays says:

    OH my goodness, I totally missed the point :)
    also, correct, I think I took my test as far as to begin using the pl/sql block just in attempt to obtain the desired result.
    Tanel, thank you very much!


  13. Filippo says:

    I generate a trace file when arise errors with code ORA-01461 in order to analyze them.
    To enable the event i do the following:

    alter system set events ‘1461 trace name errorstack level 3′;

    To check:

    oradebug setmypid
    oradebug eventdump system

    1461 trace name CONTEXT level 4, forever

    In order to examine the error a wanna check the bind variable passed.
    But in the bind variables section is showed only the value of the first bind variable “Bind#0.. value=”etl””.. and also the siz is only showed for the first variable.
    Just a snipped in the following

    ******************** Session Cursor Dump **********************
    Current cursor: 4, pgadep: 0
    Open cursors(pls, sys, hwm, max): 4(0, 0, 64, 800)
    Cached frame pages(total, free):
    4k(6, 2), 8k(0, 0), 16k(0, 0), 32k(0, 0)
    pgactx: 468bb7168 ctxcbk: 468bb5fb0 ctxqbc: 0 ctxrws: 468bb2968
    Explain plan:
    Cursor#4(ffffffff7b7319a8) state=BOUND curiob=ffffffff7b76f2a0
    curflg=4c fl2=400 par=0 ses=47a2d87d0
    ARITY = :v13 WHERE NOAT_ID = :v14
    parent=471237880 maxchild=15 plk=472c68910 ppn=n
    cursor instantiation=ffffffff7b76f2a0 used=1437430900
    child#3(47b8857f8) pcs=4715ddf38
    oacdty=96 mxl=32(03) mxlc=00 mal=00 scl=00 pre=00
    oacflg=01 fl2=1000000 frm=01 csi=871 siz=392 off=0
    kxsbbbfp=ffffffff7b76e8d0 bln=32 avl=03 flg=05
    oacdty=96 mxl=32(58) mxlc=00 mal=00 scl=00 pre=00
    oacflg=01 fl2=1000000 frm=01 csi=871 siz=0 off=32
    kxsbbbfp=ffffffff7b76e8f0 bln=32 avl=00 flg=01
    oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
    oacflg=01 fl2=1000000 frm=00 csi=00 siz=0 off=64
    kxsbbbfp=ffffffff7b76e910 bln=22 avl=00 flg=01
    oacdty=96 mxl=32(07) mxlc=00 mal=00 scl=00 pre=00
    oacflg=01 fl2=1000000 frm=01 csi=871 siz=0 off=88
    kxsbbbfp=ffffffff7b76e928 bln=32 avl=00 flg=01

    oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
    oacflg=01 fl2=1000000 frm=00 csi=00 siz=0 off=368
    kxsbbbfp=ffffffff7b76ea40 bln=22 avl=00 flg=01
    Frames pfr ffffffff7b76edd0 siz=10848 efr ffffffff7b76ece8 siz=10816
    Cursor frame dump
    enxt: 5.0x000004a8 enxt: 4.0x000007c0 enxt: 3.0x00000c78 enxt: 2.0x000001e0
    enxt: 1.0x00000f80
    pnxt: 2.0×00000008 pnxt: 1.0×00000018
    kxscphp ffffffff7b740658 siz=1992 inu=736 nps=464
    kxscbhp ffffffff7b740388 siz=984 inu=984 nps=416
    Session cached cursors
    ————– Generic Session Cached Cursors Dump ——–

    The value is only showed for the bind #0. Why Oracle does not show values for all binds?
    The problem is that there are only these types in all 14 bv: 96 (CHAR/NCHAR), 02 (NUMBER), 101 (BINARY_DOUBLE). So I cannot identify which bv was passed as LONG.
    Thank you

    Database version: Oracle Database 10g Enterprise Edition Release – 64bit Production

    • Tanel Poder says:

      The actual value length (avl=00) is zero for all binds after #1, so looks no binds after #1 have been put in place. So I would say the bind #2 is the problematic one where this exception is raised (unless your app code somehow binds values in a different order)

      • Filippo says:

        Hi Tanel,
        thank you for your reply.
        I have done some tests. I generate an error 01461 in this way:
        create table test5 (d number, c clob, v varchar2(10), a number);

        shortStr varchar2(10) := ‘0123456789’;
        longStr1 varchar2(10000) := shortStr;
        longStr2 varchar2(10000);
        num1 number := 1;
        num2 number := 41;
        for i in 1 .. 10000
        longStr2 := longStr2 || ‘X';
        end loop;
        insert into test5(d, c, v, a) values(num2, shortStr, longStr2, num1);

        the tracefile contains this info:

        sqltxt(3b1fba470)=INSERT INTO TEST5(D, C, V, A) VALUES(:B4 , :B3 , :B2 , :B1 )
        parent=3ac0f1fd0 maxchild=01 plk=3bb73c6f8 ppn=n
        cursor instantiation=ffffffff7dfdf4b8 used=1437934757
        child#0(3b99ef498) pcs=3ac0f15a0
        clk=3bbb1aaf0 ci=3ac0f12c8 pn=3b3d00ec8 ctx=3b0663af0
        kgsccflg=0 llk[ffffffff7dfdf4c0,ffffffff7dfdf4c0] idx=0
        xscflg=1304f2 fl2=11120000 fl3=22a2184 fl4=100
        Bind bytecodes
        Opcode = 6 Bind Rpi Scalar Sql In(may be out) Nocopy NoSkip
        Offsi = 48, Offsi = 0
        Opcode = 6 Bind Rpi Scalar Sql In(may be out) Nocopy NoSkip
        Offsi = 48, Offsi = 32
        Opcode = 1 Unoptimized
        Null Offset
        Opcode = 6 Bind Rpi Scalar Sql In(may be out) Nocopy NoSkip
        Offsi = 48, Offsi = 96
        oacdty=02 mxl=22(21) mxlc=00 mal=00 scl=00 pre=00
        oacflg=13 fl2=206001 frm=00 csi=00 siz=24 off=0
        kxsbbbfp=ffffffff7b669130 bln=22 avl=02 flg=09
        oacdty=01 mxl=32(10) mxlc=00 mal=00 scl=00 pre=00
        oacflg=13 fl2=206001 frm=01 csi=873 siz=32 off=0
        kxsbbbfp=ffffffff7b6690a8 bln=32 avl=10 flg=09
        oacdty=01 mxl=4001(10000) mxlc=00 mal=00 scl=00 pre=00
        oacflg=13 fl2=206001 frm=01 csi=873 siz=4000 off=0
        kxsbbbfp=ffffffff7b651cf8 bln=4000 avl=00 flg=09
        oacdty=02 mxl=22(21) mxlc=00 mal=00 scl=00 pre=00
        oacflg=13 fl2=206001 frm=00 csi=00 siz=24 off=0
        kxsbbbfp=00000000 bln=22 avl=00 flg=09
        Frames pfr 0 siz=0 efr 0 siz=0

        So it seems that the bind variables have been put in place only up till the the problematic one, which has not been putted, as the successive ones.
        So it seems that I cannot get back all the bind variables and their values in this manner (using tracefiles)..
        So, there is another way to retrieve this type of information from Oracle (db-side)? Even if an error arises, like in this example?
        Thank you

        • Tanel Poder says:

          If this particular SQL request comes in via SQL*Net, you could use SQL*Net trace (the sqlnet.ora settings or event 10079: trace data sent/received via SQL*Net). But you’d need to manually interpret the trace contents and find where/what the binds are. Probably too low level. The other option would be some client side tracing (JDBC tracing if using JDBC etc)

        • Tanel Poder says:

          And when navigating the SQLNet trace file, you could search for (binary representation, if needed) of the last bind variable value successfully bound, and search for it in the SQLNet trace, to see the other bind variable memory regions that are likely close in the stream. Even tcpdump+Wireshark might be enough if you’re just gonna search for a known (successfully bound) bind variable value.

Leave a Reply

Your email address will not be published. Required fields are marked *

You may use these HTML tags and attributes: <a href="" title=""> <abbr title=""> <acronym title=""> <b> <blockquote cite=""> <cite> <code> <del datetime=""> <em> <i> <q cite=""> <s> <strike> <strong>