Friday 26 August 2011

Name of currently-executing program

Question:
When I trap an error in an exception section, I want to record as part of my error log the name of the subprogram currently being executed. I would rather not hard-code the name in a local variable. How can I do that in PL/SQL?
Answer:
When an error occurs, it certainly is very important to know which subprogram was currently being executed; even better, it would be truly wonderful to know the line which caused the error to be raised. (Oracle refers to PL/SQL procedures and functions, whether they be schema-level (stand-alone) or defined with packages and objects types, as "subprograms.")
Depending on the version of Oracle you are running, you should use one of the following two very handy built-in functions, each of which will give you almost all the information needed to answer your question.
With Oracle Database 10g Release 1 and later, call
DBMS_UTILITY.FORMAT_ERROR_BACKTRACE
With Oracle9i Database Release 2 and earlier, call
DBMS_UTILITY.FORMAT_CALL_STACK
DBMS_UTILITY.FORMAT_ERROR_BACKTRACE, which I will refer to as "backtrace" for the remainder of this answer, returns a formatted string that shows the trace of calls in the execution stack down to the point at which an error was raised. More to the point, the top of that stack shows the line number of the program unit in which the exception was raised.
DBMS_UTILITY.FORMAT_CALL_STACK, which I will refer to as "callstack" for the remainder of this answer, returns a formatted string that contains the execution call stack from the point at which the built-in function was called. In other words, callstack has nothing to do with error handling; it can be called anywhere and at any point in your code.
If the subprograms in these stacks are schema-level (a.k.a, "stand alone") functions or procedures, you can indeed see the actual name of that subprograms. If a subprogram is defined within a package, however, you will only see the name of that package. The name of the subprogram is lost once the package has been compiled. Examples further along in this answer demonstrate this fact.
For this reason alone, I suggest you concentrate on logging the entire callstack and backtrace when you encounter an error or want to preserve information about the current context. Don't worry so much about obtaining the specific subprogram name.
Let's take a look at each of the backtrace and callstack functions in more detail. Suppose I define a logging mechanism as follows:
First, I will create a very simple error log table; it only stores the stack information. Obviously it is not sufficient for an error or generic logging mechanism, but it does allow us to focus on the issue at hand!
CREATE TABLE my_log (
stack_info VARCHAR2(4000))
/
I then create an autonomous transaction log_error procedure that writes a string out to the my_log table and immediately saves it:
CREATE OR REPLACE PROCEDURE log_error (stack_in IN VARCHAR2)
IS
PRAGMA AUTONOMOUS_TRANSACTION;
BEGIN
INSERT INTO my_log
(stack_info
)
VALUES (stack_in
);

COMMIT;
EXCEPTION
WHEN OTHERS
THEN
ROLLBACK;
RAISE;
END log_error;
/
I will use this table and procedure to demonstrate the functionality of both the backtrace and callstack functions.
If you are using Oracle Database 10g...then you are fortunate enough to be able to use the backtrace function. Suppose I have defined three schema-level procedures in my application:
CREATE OR REPLACE PROCEDURE proc1
IS
BEGIN
RAISE NO_DATA_FOUND;
END proc1;
/

CREATE OR REPLACE PROCEDURE proc2
IS
BEGIN
proc1;
END proc2;
/

CREATE OR REPLACE PROCEDURE proc3
IS
BEGIN
proc2;
END proc3;
/
Notice that none of my procedures have exception sections. If I only want to identify the line number on which an error was originally raised, I can simply let that exception propagate out to the outermost block, and then call backtrace at that point, as I do in the following anonymous block:
BEGIN
proc3;
EXCEPTION
WHEN NO_DATA_FOUND
THEN
log_error (DBMS_UTILITY.format_error_backtrace);
RAISE;
END;
/
After running this code, I get an unhandled exception:
BEGIN
*
ERROR at line 1:
ORA-01403: no data found
ORA-06512: at line 7
In this case, however, my error log contains the full trace back to proc1 (note: in this demonstration, the log table is always empty when I execute proc3 so my SELECT statement can simply query "all rows"):
SELECT * FROM my_log
/

SQL> /
STACK_INFO
------------------------------------------
ORA-06512: at "SCOTT.PROC1", line 4
ORA-06512: at "SCOTT.PROC2", line 4
ORA-06512: at "SCOTT.PROC3", line 4
ORA-06512: at line 2
I have previously explored the use of the backtrace function on the OTN Best Practice PL/SQL Q&A. I encourage you to search for "Exception, Exception, Where Did You Raise?" to read about it in more detail. The Download page also offers a package to help you parse the backtrace string and extract information like the program name. I will now devote the rest of this answer to exploring how to use the Callstack function.
If you are not yet on Oracle Database 10g...assuming you cannot yet take advantage of backtrace, you will have to use callstack to gather what information you can about the context in which the exception was raised (of course, you can also use callstack at any point in your application to determine the path your code followed to get to that point).
The following example should clarify how to put callstack to use.
I will first modify my definition of the proc1 procedure defined earlier; when I was relying on backtrace, I did not need to include an exception section at this low level in my execution stack. Without backtrace at my disposal, however, if I want to be able to record the call stack that points to the subprogram in which the error was raised, I need to include an error handler that invokes callstack in that.
If I do not invoke callstack at this level and instead let the exception propagate to enclosing blocks, the callstack information will be lost - a crucial difference from the way backtrace works. Here is my new proc1:
CREATE OR REPLACE PROCEDURE proc1
IS
BEGIN
RAISE NO_DATA_FOUND;
EXCEPTION
WHEN NO_DATA_FOUND
THEN
log_error (DBMS_UTILITY.format_call_stack);
RAISE;
END;
/
As before, proc1 is then called by proc2, which in turn is called by proc3. Now, when I call proc3, I get an unhandled NO_DATA_FOUND exception, as one would expect:
BEGIN
proc3;
END;
/

ORA-01403: no data found
ORA-06512: at "QNXO_DEMO.PROC1", line 9
ORA-06512: at "QNXO_DEMO.PROC2", line 4
ORA-06512: at "QNXO_DEMO.PROC3", line 4
ORA-06512: at line 2
Since I defined log_error subprogram as an autonomous transaction, I can still query the contents of my log to view the call stack:
SQL> SELECT stack_info FROM my_log
2 /

STACK_INFO
-------------------------------------------
----- PL/SQL Call Stack -----
object line object
handle number name
22490CCC 8 procedure SCOTT.PROC1
2272D4B0 4 procedure SCOTT.PROC2
2A9B38D0 4 procedure SCOTT.PROC3
2A8C21E0 2 anonymous block
A very nicely formatted and informative call stack, indeed! It provides the object handle (an internal ID for the object), the line number in the subprogram that was executed, the type of subprogram unit, and the name of the subprogram or package containing the subprogram (in the form schema.name, unless it is an anonymous block).
The above code provides an example of the call stack in which each subprogram in the stack is a procedure. Now let's take a look at the behavior of DBMS_UTILTY.FORMAT_CALL_STACK when I call a packaged procedure.
I will now put proc1 inside a package:
CREATE OR REPLACE PACKAGE pkg
IS
PROCEDURE proc1;
END pkg;
/

CREATE OR REPLACE PACKAGE BODY pkg
IS
PROCEDURE proc1
IS
BEGIN
RAISE NO_DATA_FOUND;
EXCEPTION
WHEN NO_DATA_FOUND
THEN
log_error (DBMS_UTILITY.format_call_stack);
RAISE;
END proc1;
END pkg;
/
And I will change proc2 to call the packaged version:
CREATE OR REPLACE PROCEDURE proc2
IS
BEGIN
pkg.proc1;
END proc2;
/
Now when I call proc3 and then look at my error log, I find this call stack:
----- PL/SQL Call Stack -----
object line object
handle number name
6A46A1AC 10 package body QNXO_DEMO.PKG
67C68C68 4 procedure QNXO_DEMO.PROC2
69AADC94 4 procedure QNXO_DEMO.PROC3
689C9FA8 2 anonymous block
Notice the difference? Rather than showing me that the QNXO_DEMO.PKG.PROC1 procedure was called, the formatted call stack only reveals, sadly enough, the name of the package. The reason for this is that once your code has been compiled, the names of the individual subprograms in a package are replaced by pointers; the PL/SQL runtime engine simply doesn't know the subprogram names, so it cannot put them into the call stack.
Fortunately, you are given the line number at which point the call stack subprogram was called. So if and when you are debugging your code and analyzing the error log, simply open up the package in your editor of choice, locate the code by line number, and then work your way back up to the subprogram header.
Alternatively, you could write a subprogram that accepts the name of a package and a line number, and parses the package definition so that it can return to you the name of the subprogram within the package. That is definitely a task I will leave to an industrious reader.
A cautionary note: if you are using a version of Oracle earlier than Oracle Database 10g Release 2, you should avoid using DBMS_OUTPUT.PUT_LINE to display the call stack, as doing so will likely raise an exception. Even with a very small execution stack, the value returned by DBMS_UTILITY.FORMAT_CALL_STACK is likely to exceed 255 characters in length. Oracle Database 10g Release 2 fixes this problem by expanding the maximum string length supported by DBMS_OUTPUT.PUT_LINE to 32K.
To sum up, it is definitely important to identify the program that you were running when an error occurred. Even more critical is to know the line number in that subprogram on which the error was raised. If you are running Oracle Database 10g, you can easily use tt>DBMS_UTILITY.FORMAT_ERROR_BACKTRACE to accomplish this task. Set as a rule that your exception logging code will call this function and save the formatted trace in your error log. If you are not yet running Oracle Database 10g, DBMS_UTILITY.FORMAT_CALL_STACK will help you identify the subprogram in which an error occurred, but you must call it within the same block in which the error was raised

No comments:

Post a Comment