Friday, June 28, 2013

12c - Utl_Call_Stack...

Over the next couple of months, I'll be writing about some cool new little features of Oracle Database 12c - things that might not make the front page of Oracle.com.  I'm going to start with a new package - UTL_CALL_STACK.

In the past, developers have had access to three functions to try to figure out "where the heck am I in my code", they were:




Now these routines, while useful, were of somewhat limited use.  Let's look at the format_call_stack routine for a reason why.  Here is a procedure that will just print out the current call stack for us:

ops$tkyte%ORA12CR1> create or replace
  2  procedure Print_Call_Stack
  3  is
  4  begin
  5    DBMS_Output.Put_Line(DBMS_Utility.Format_Call_Stack());
  6  end;
  7  /
Procedure created.


Now, if we have a package - with nested functions and even duplicated function names:

ops$tkyte%ORA12CR1> create or replace
  2  package body Pkg is
  3    procedure p
  4    is
  5      procedure q
  6      is
  7        procedure r
  8        is
  9          procedure p is
 10          begin
 11            Print_Call_Stack();
 12            raise program_error;
 13          end p;
 14        begin
 15          p();
 16        end r;
 17      begin
 18        r();
 19      end q;
 20    begin
 21      q();
 22    end p;
 23  end Pkg;
 24  /

Package body created.

When we execute the procedure PKG.P - we'll see as a result:

ops$tkyte%ORA12CR1> exec pkg.p
----- PL/SQL Call Stack -----
  object      line  object
  handle    number  name
0x6e891528         4  procedure OPS$TKYTE.PRINT_CALL_STACK
0x6ec4a7c0        10  package body OPS$TKYTE.PKG
0x6ec4a7c0        14  package body OPS$TKYTE.PKG
0x6ec4a7c0        17  package body OPS$TKYTE.PKG
0x6ec4a7c0        20  package body OPS$TKYTE.PKG
0x76439070         1  anonymous block

BEGIN pkg.p; END;

*
ERROR at line 1:
ORA-06501: PL/SQL: program error
ORA-06512: at "OPS$TKYTE.PKG", line 11
ORA-06512: at "OPS$TKYTE.PKG", line 14
ORA-06512: at "OPS$TKYTE.PKG", line 17
ORA-06512: at "OPS$TKYTE.PKG", line 20
ORA-06512: at line 1

The bit in red above is the output from format_call_stack whereas the bit in black is the error message returned to the client application (it would also be available to you via the format_error_backtrace API call). As you can see - it contains useful information but to use it you would need to parse it - and that can be trickier than it seems.  The format of those strings is not set in stone, they have changed over the years (I wrote the "who_am_i", "who_called_me" functions, I did that by parsing these strings - trust me, they change over time!).

Starting in 12c - we'll have structured access to the call stack and a series of API calls to interrogate this structure.  I'm going to rewrite the print_call_stack function as follows:

ops$tkyte%ORA12CR1> create or replace
 2  procedure Print_Call_Stack
  3  as
  4    Depth pls_integer := UTL_Call_Stack.Dynamic_Depth();
  5  
  6    procedure headers
  7    is
  8    begin
  9        dbms_output.put_line( 'Lexical   Depth   Line    Name' );
 10        dbms_output.put_line( 'Depth             Number      ' );
 11        dbms_output.put_line( '-------   -----   ----    ----' );
 12    end headers;
 13    procedure print
 14    is
 15    begin
 16        headers;
 17        for j in reverse 1..Depth loop
 18          DBMS_Output.Put_Line(
 19            rpad( utl_call_stack.lexical_depth(j), 10 ) ||
 20                    rpad( j, 7) ||
 21            rpad( To_Char(UTL_Call_Stack.Unit_Line(j), '99'), 9 ) ||
 22            UTL_Call_Stack.Concatenate_Subprogram
 23                       (UTL_Call_Stack.Subprogram(j)));
 24        end loop;
 25    end;
 26  begin
 27    print;
 28  end;
 29  /

Here we are able to figure out what 'depth' we are in the code (utl_call_stack.dynamic_depth) and then walk up the stack using a loop.  We will print out the lexical_depth, along with the line number within the unit we were executing plus - the unit name.  And not just any unit name, but the fully qualified, all of the way down to the subprogram name within a package.  Not only that - but down to the subprogram name within a subprogram name within a subprogram name.  For example - running the PKG.P procedure again results in:

ops$tkyte%ORA12CR1> exec pkg.p
Lexical   Depth   Line    Name
Depth             Number
-------   -----   ----    ----
1         6       20      PKG.P
2         5       17      PKG.P.Q
3         4       14      PKG.P.Q.R
4         3       10      PKG.P.Q.R.P
0         2       26      PRINT_CALL_STACK
1         1       17      PRINT_CALL_STACK.PRINT
BEGIN pkg.p; END;

*
ERROR at line 1:
ORA-06501: PL/SQL: program error
ORA-06512: at "OPS$TKYTE.PKG", line 11
ORA-06512: at "OPS$TKYTE.PKG", line 14
ORA-06512: at "OPS$TKYTE.PKG", line 17
ORA-06512: at "OPS$TKYTE.PKG", line 20
ORA-06512: at line 1


This time - we get much more than just a line number and a package name as we did previously with format_call_stack.  We not only got the line number and package (unit) name - we got the names of the subprograms - we can see that P called Q called R called P as nested subprograms.  Also note that we can see a 'truer' calling level with the lexical depth, we can see we "stepped" out of the package to call print_call_stack and that in turn called another nested subprogram.

This new package will be a nice addition to everyone's error logging packages.  Of course there are other functions in there to get owner names, the edition in effect when the code was executed and more. See UTL_CALL_STACK for all of the details.