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:
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:
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
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.
posted by Thomas Kyte at 11:37 AM
6 Comments:
Thank you for giving so much of your personal time to the Oracle community. Would you be willing to blog about your personal study habits and learning methodology?
@Anonymous -
if you go back to the 2005-2007 blog entries, that is what many of them are all about... :)
Awesome. Now, I can tell our developers to not hardcode the subprogram names and hence have inherent bugs during copy-pasting.
Until now, I only championed using $$PLSQL_UNIT and $$PLSQL_LINE.
Now this feature is surely going to make your 'Who called me' code obsolete ;)
This comment has been removed by the author.
Had a good talk with Bryn Llewellyn today. Turns out my tests of utl_call_stack were flawed. I'm still left with a couple of wishes after putting utl_call_stack through its paces last night:
1. I imagine backtrace_unit was designed to return the same unit name as seen in the 10g backtrace, but I wish it would return the fantastic fully qualified routine name instead (like the one returned by utl_call_stack.concatenate_subprogram(utl_call_stack.subprogram()
2. Although I don't currently use it in my logging framework, the object type could be parsed out of the old call stack, but is not available in utl_call_stack routines.
Much appreciation to Bryn and Co. for utl_call_stack.subprogram. So nice to finally enable a proc to identify itself w/o jumping through parsing hoops!
POST A COMMENT
<< Home