Tracing Lines

Find and report your errors—by line number—in Oracle Database 10g.

March/April 2005

PL/SQL offers a powerful and flexible exception architecture. Of course, there is always room for improvement, and in Oracle Database 10g, exception handling takes a big step forward with the introduction of the DBMS_UTILITY.FORMAT_ERROR_BACKTRACE function. This article explores the problem that this function solves and how best to use it.

When an exception is raised, one of the most important pieces of information a programmer would like to uncover is the line of code that raised the exception. Prior to Oracle Database 10g, one could obtain this information only by allowing the exception to go unhandled.

Let's revisit the error-handling behavior available to programmers in Oracle9i Database. Consider this simple chain of program calls in Listing 1: procedure proc3 calls proc2 calls proc1 , at which point proc1 raises the NO_DATA_FOUND exception. Notice that there is no error handling in any of the procedures; it is most significantly lacking in the top-level proc3 procedure. If I run proc3 in SQL*Plus, I will see the following results:

ERROR at line 1:
ORA-01403: no data found
ORA-06512: at "SCOTT.PROC1", line 4
ORA-06512: at "SCOTT.PROC2", line 6
ORA-06512: at "SCOTT.PROC3", line 4
ORA-06512: at line 3

Code Listing 1: A stack of procedures

CREATE OR REPLACE PROCEDURE proc1 IS
BEGIN
   DBMS_OUTPUT.put_line ('running proc1');
   RAISE NO_DATA_FOUND;
END;
/
CREATE OR REPLACE PROCEDURE proc2 IS
   l_str VARCHAR2(30)
         := 'calling proc1';
BEGIN
   DBMS_OUTPUT.put_line (l_str);
   proc1;
END;
/
CREATE OR REPLACE PROCEDURE proc3 IS
BEGIN
   DBMS_OUTPUT.put_line ('calling proc2');
   proc2;
END;
/

This is the error trace dump of an unhandled exception, and it shows that the error was raised on line 4 of proc1. On the one hand, we should be very pleased with this behavior. Now that we have the line number, we can zoom right in on the problem code and fix it. On the other hand, we got this information by letting the exception go unhandled. In many applications, however, we work to avoid unhandled exceptions.

Let's see what happens when I add an exception section to the proc3 procedure and then display the error information (the simplest form of error logging). Here is the second version of proc3 :

CREATE OR REPLACE PROCEDURE proc3
IS
BEGIN
  DBMS_OUTPUT.put_line ('calling proc2');
  proc2;
EXCEPTION
  WHEN OTHERS THEN
    my_putline (
       DBMS_UTILITY.FORMAT_ERROR_STACK);
END;
/

Notice that I call DBMS_UTILITY.FORMAT_ERROR_STACK , because it will return the full error message. Of course, DBMS_OUTPUT.PUT_LINE will raise an exception if you pass it a string that is longer than 255 characters, so I will display the error message using my own enhanced version of DBMS_OUTPUT.PUT_LINE, my_putline (which is available here).

Having compiled the new proc3 , when I run it inside SQL*Plus I see the following output:

SQL> SET SERVEROUTPUT ON
SQL> exec proc3
calling proc2
calling proc1
running proc1
ORA-01403: no data found

In other words, DBMS_UTILITY.FORMAT_ERROR_STACK does not show the full error stack with line numbers; SQLERRM acts in the same manner.

In Oracle Database 10g, Oracle added DBMS_UTILITY.FORMAT_ERROR_BACKTRACE , which can and should be called in your exception handler. It displays the call stack at the point where an exception was raised, even if the function is called in a PL/SQL block in an outer scope from that where the exception was raised. Thus, you can call DBMS_UTILITY.FORMAT_ERROR_BACKTRACE within an exception section at the top level of your stack and still find out where the error was raised deep within the call stack.

Having upgraded to Oracle Database 10g, I can now revisit my proc3 procedure and replace the call to FORMAT_ERROR_STACK with FORMAT_ERROR_BACKTRACE , as shown in Listing 2. I will continue to use my_putline , since the backtrace could be very long if the call stack is deep (and your program names are long).

Code Listing 2: proc3 rewritten with FORMAT_ERROR_BACKTRACE

CREATE OR REPLACE PROCEDURE proc3
IS
BEGIN
  DBMS_OUTPUT.put_line ('calling proc2');
  proc2;
EXCEPTION
  WHEN OTHERS
  THEN
    DBMS_OUTPUT.put_line ('Error stack at top level:');
    my_putline (DBMS_UTILITY.FORMAT_ERROR_BACKTRACE);
END;
/

And now when I run proc3 , I will see the following output:

SQL> SET SERVEROUTPUT ON
SQL> exec proc3
calling proc2
calling proc1
running proc1
Error stack at top level:
ORA-06512: at "SCOTT.PROC1", line 4
ORA-06512: at "SCOTT.PROC2", line 6
ORA-06512: at "SCOTT.PROC3", line 4

In other words, the information that had previously been available only through an unhandled exception is now retrievable from within the PL/SQL code.

An exception often occurs deep within the execution stack. If you want that exception to propagate all the way to the outermost PL/SQL block, it will have to be re-raised within each exception handler in the stack of blocks. Listing 3 shows an example of such an occurrence.

Code Listing 3: Re-raising exceptions to the outermost block in the stack

CREATE OR REPLACE PROCEDURE proc1 IS
BEGIN
   DBMS_OUTPUT.put_line ('running proc1');
   RAISE NO_DATA_FOUND;
EXCEPTION
   WHEN OTHERS THEN
      DBMS_OUTPUT.put_line (
         'Error stack in block where raised:');
      my_putline (
         DBMS_UTILITY.format_error_backtrace);
      RAISE;
END;
/
CREATE OR REPLACE PROCEDURE proc2
IS
   l_str VARCHAR2 (30) := 'calling proc1';
BEGIN
   DBMS_OUTPUT.put_line (l_str);
   proc1;
END;
/
CREATE OR REPLACE PROCEDURE proc3 IS
BEGIN
   DBMS_OUTPUT.put_line ('calling proc2');
   proc2;
EXCEPTION
   WHEN OTHERS
   THEN
      DBMS_OUTPUT.put_line ('Error stack at top level:');
      my_putline (DBMS_UTILITY.format_error_backtrace);
      bt.show_info (DBMS_UTILITY.format_error_backtrace);
END;
/

When I run the code in Listing 3, I see the following output:

SQL> exec proc3
calling proc2
calling proc1
running proc1
Error stack in block where raised:
ORA-06512: at "SCOTT.PROC1", line 4
Error stack at top level:
ORA-06512: at "SCOTT.PROC1", line 11
ORA-06512: at "SCOTT.PROC2", line 6
ORA-06512: at "SCOTT.PROC3", line 4
Program owner = SCOTT
Program name = PROC1
Line number = 11

When I call the backtrace function within the lowest-level program, it correctly identifies line 4 of proc1 as the line in which the error is first raised. I then re-raise the same exception using the RAISE statement. When the exception propagates to the outermost block, I call the backtrace function again, and this time it shows that the error was raised on line 11 of proc1.

From this behavior, we can conclude that DBMS_UTILITY.FORMAT_ERROR_BACKTRACE shows the trace of execution back to the last RAISE in one's session. As soon as you issue a RAISE of a particular exception or re-raise the current exception, you restart the stack that the backtrace function produces. This means that if you want to take advantage of DBMS_UTILITY.FORMAT_ERROR_BACKTRACE , take one of the following two approaches:

• Call the backtrace function in the exception section of the block in which the error was raised. This way you have (and can log) that critical line number, even if the exception is re-raised further up in the stack.

• Avoid exception handlers in intermediate programs in your stack, and call the backtrace function in the exception section of the outermost program in your stack.

In a real-world application, the error backtrace could be very long. Generally, debuggers and support people don't really want to have to deal with the entire stack; they are mostly going to be interested in that top-most entry. The developer of the application might even like to display that critical information to the users so that they can immediately and accurately report the problem to the support staff.

In this case, it is necessary to parse the backtrace string and retrieve just the top-most entry. I built a utility to do this called the BT package. In this package, I provide a simple, clean interface as follows:

CREATE OR REPLACE PACKAGE bt
IS
  TYPE error_rt IS RECORD (
    program_owner all_objects.owner%TYPE
  , program_name all_objects.object_name%TYPE
  , line_number PLS_INTEGER
  );
  FUNCTION info (backtrace_in  IN VARCHAR2)
    RETURN error_rt;
  PROCEDURE show_info (backtrace_in  IN VARCHAR2);
END bt;
/

The record type, error_rt , contains a separate field for each element of the backtrace that I want to retrieve (owner of the program unit, name of the program unit, and the line number within that program). Instead of calling and parsing the backtrace function in each exception section, I can call the bt.info function and report on the specifics of the error.

For example, using the bt.info function, the exception section of proc3 now looks like the procedure in Listing 4.

Code Listing 4: Revised proc3 calling bt.info

CREATE OR REPLACE PROCEDURE proc3
IS
BEGIN
   DBMS_OUTPUT.put_line ('calling proc2');
   proc2;
EXCEPTION
   WHEN OTHERS
   THEN
      DECLARE
         l_trace   bt.error_rt;
      BEGIN
         l_trace := bt.info (DBMS_UTILITY.format_error_backtrace);
         raise_application_error (-20000
                                 ,    'Error '
                                   || SQLCODE
                                   || ' encountered on line '
                                   || l_trace.line_number
                                   || ' in program '
                                   || l_trace.program_owner
                                   || '.'
                                   || l_trace.program_name
                                 );
      END;
END proc3;
/

The error message now offers some very focused information for the recipient. The implementation of this function is straightforward; the most important thing to keep in mind when writing utilities like this is to keep the code flexible and clearly structured. The basic task is to parse a string with this format:

ORA-NNNNN: at "OWNER.PROGRAM_NAME",
line NNN

Here are the steps I took:

1. Recognizing that I will be needing to parse the contents of a string based on various delimiters, I define a number of constants to hold these delimiter values. That way, I can avoid hard-coding these values later in my program (and possibly more than once).

c_name_delim  CONSTANT CHAR (1)  := '"';
c_dot_delim   CONSTANT CHAR (1)  := '.';
c_line_delim  CONSTANT CHAR (4)  := 'line';
c_eol_delim   CONSTANT CHAR (1)  := CHR (10);

2. The very first step in my info function is to perform a set of INSTR calls to identify the starting and ending locations of the various elements of the string that I want to isolate and return individually. I have placed all of this code into a separate initialization procedure in Listing 5.

Code Listing 5: Initialization procedure in bt.info

PROCEDURE initialize_values
IS
BEGIN
   l_name_start_loc := INSTR (backtrace_in, c_name_delim, 1, 1);
   l_dot_loc := INSTR (backtrace_in, c_dot_delim);
   l_name_end_loc := INSTR (backtrace_in, c_name_delim, 1, 2);
   l_line_loc := INSTR (backtrace_in, c_line_delim);
   l_eol_loc := INSTR (backtrace_in, c_eol_delim);
END initialize_values;

3. With these locations established, I can now use SUBSTR to extract the desired portions and assign them to the fields in my record to be returned to the calling program, as shown in Listing 6.

Code Listing 6: Executable section of the bt.info function

BEGIN
      initialize_values;
      retval.program_owner :=
         SUBSTR (backtrace_in
                , l_name_start_loc  + 1
                , l_dot_loc - l_name_start_loc - 1
                );
      retval.program_name :=
          SUBSTR (backtrace_in, l_dot_loc + 1, l_name_end_loc - l_dot_loc - 1);
      retval.line_number :=
             SUBSTR (backtrace_in, l_line_loc + 5, l_eol_loc - l_line_loc - 5);
      RETURN retval;
   END info;

Whether you call DBMS_UTILITY.FORMAT_ERROR_BACKTRACE directly or use a utility like bt.info to parse that string, the information is very useful. Error handling and resolution have gotten much easier in Oracle Database 10g.

READ more Feuerstein
oracle.com/technetwork/articles
www.oreillynet.com/cs/catalog/view/au/344

DOWNLOAD
my_putline and bt package

CREATE OR REPLACE PROCEDURE my_putline (
   str         IN   VARCHAR2
 , len         IN   INTEGER := 80
 , expand_in   IN   BOOLEAN := TRUE
)
IS
   v_len     PLS_INTEGER     := LEAST (len, 255);
   v_len2    PLS_INTEGER;
   v_chr10   PLS_INTEGER;
   v_str     VARCHAR2 (2000);
BEGIN
   IF LENGTH (str) > v_len
   THEN
      v_chr10 := INSTR (str, CHR (10));

      IF v_chr10 > 0 AND v_len >= v_chr10
      THEN
         v_len := v_chr10 - 1;
         v_len2 := v_chr10 + 1;
      ELSE
         v_len2 := v_len + 1;
      END IF;

      v_str := SUBSTR (str, 1, v_len);
      DBMS_OUTPUT.put_line (v_str);
      my_putline (SUBSTR (str, v_len2), len, expand_in);
   ELSE
      -- Save the string in case we hit an error and need to recover.
      v_str := str;
      DBMS_OUTPUT.put_line (str);
   END IF;
EXCEPTION
   WHEN OTHERS
   THEN
      /* TVP 9/99: Might want to use buffer size to STOP program */
      IF expand_in
      THEN
         DBMS_OUTPUT.ENABLE (1000000);
         DBMS_OUTPUT.put_line (v_str);
      ELSE
         RAISE;
      END IF;
END my_putline;
/

CREATE OR REPLACE PACKAGE bt
IS
/*
| Overview: bt provides structured access to the information
|           returned by DBMS_UTILITY.format_error_backtrace.
|
| Author: Steven Feuerstein
| Repository: www.qnxo.com
| Contact: steven@stevenfeuerstein.com
| Copyright 2004 Steven Feuerstein, all rights reserved
|
| You are welcome to copy and use this program, but please
| include attribution of the source of the code.


*/
   TYPE error_rt IS RECORD (
      program_owner   all_objects.owner%TYPE
    , program_name    all_objects.object_name%TYPE
    , line_number     PLS_INTEGER
   );

--
-- Parse a line with this format:
-- ORA-NNNNN: at "SCHEMA.PROGRAM", line NNN
--
   FUNCTION info (backtrace_in IN VARCHAR2)
      RETURN error_rt;

   PROCEDURE show_info (backtrace_in IN VARCHAR2);
END bt;
/

CREATE OR REPLACE PACKAGE BODY bt
IS
   -- Strings that delimit different parts of line in stack.
   c_name_delim   CONSTANT CHAR (1) := '"';
   c_dot_delim    CONSTANT CHAR (1) := '.';
   c_line_delim   CONSTANT CHAR (4) := 'line';
   c_eol_delim    CONSTANT CHAR (1) := CHR (10);

   --
   FUNCTION info (backtrace_in IN VARCHAR2)
      RETURN error_rt
   IS
      -- Lots of INSTRs to come; these variables keep track
      -- of the start and end points of various portions of the string.
      l_at_loc           PLS_INTEGER;
      l_dot_loc          PLS_INTEGER;
      l_name_start_loc   PLS_INTEGER;
      l_name_end_loc     PLS_INTEGER;
      l_line_loc         PLS_INTEGER;
      l_eol_loc          PLS_INTEGER;
      --
      retval             error_rt;

      PROCEDURE initialize_values
      IS
      BEGIN
         l_name_start_loc := INSTR (backtrace_in, c_name_delim, 1, 1);
         l_dot_loc := INSTR (backtrace_in, c_dot_delim);
         l_name_end_loc := INSTR (backtrace_in, c_name_delim, 1, 2);
         l_line_loc := INSTR (backtrace_in, c_line_delim);
         l_eol_loc := INSTR (backtrace_in, c_eol_delim);

         IF l_eol_loc = 0
         THEN
            l_eol_loc := LENGTH (backtrace_in) + 1;
         END IF;
      END initialize_values;
   BEGIN
      initialize_values;
      --
      retval.program_owner :=
         SUBSTR (backtrace_in
               , l_name_start_loc + 1
               , l_dot_loc - l_name_start_loc - 1
                );
      --
      retval.program_name :=
          SUBSTR (backtrace_in, l_dot_loc + 1, l_name_end_loc - l_dot_loc - 1);
      --
      retval.line_number :=
             SUBSTR (backtrace_in, l_line_loc + 5, l_eol_loc - l_line_loc - 5);
      RETURN retval;
   END info;

   PROCEDURE show_info (backtrace_in IN VARCHAR2)
   IS
      l_line   error_rt;
   BEGIN
      l_line := info (backtrace_in);
      DBMS_OUTPUT.put_line ('Program owner = ' || l_line.program_owner);
      DBMS_OUTPUT.put_line ('Program name = ' || l_line.program_name);
      DBMS_OUTPUT.put_line ('Line number = ' || l_line.line_number);
   END show_info;
END bt;
/