Wednesday, 28 February 2018

UTL_CALL_STACK : Get Detailed Information About the Currently Running Subprogram in Oracle Database 12c Release 1

Oracle database 12c introduced the UTL_CALL_STACK package to allow programmatic access to the call stack and error stack, giving much greater flexibility for debugging and error handling of PL/SQL code. This is only a replacement for the existing functionality if you need the extra level of control. The existing functionality in the DBMS_UTILITY package is still available and has not been deprecated.

◉ Call Stack


The call stack allows you to identify exactly where you are in the currently running code, which includes information about nesting of subprogram calls. In previous releases this information was displayed using the DBMS_UTILITY.FORMAT_CALL_STACK function, as shown below.


-- Procedure to display the call stack.
CREATE OR REPLACE PROCEDURE display_call_stack AS
BEGIN
  DBMS_OUTPUT.put_line('***** Call Stack Start *****');
  DBMS_OUTPUT.put_line(DBMS_UTILITY.format_call_stack);
  DBMS_OUTPUT.put_line('***** Call Stack End *****');
END;
/

-- Test package to show a nested call.
CREATE OR REPLACE PACKAGE test_pkg AS
  PROCEDURE proc_1;
  PROCEDURE proc_2;
  PROCEDURE proc_3;
END;
/

CREATE OR REPLACE PACKAGE BODY test_pkg AS

  PROCEDURE proc_1 AS
  BEGIN
    proc_2;
  END;

  PROCEDURE proc_2 AS
  BEGIN
    proc_3;
  END;

  PROCEDURE proc_3 AS
  BEGIN
    display_call_stack;
  END;

END;
/

-- Run the test.
SET SERVEROUTPUT ON
EXEC test_pkg.proc_1;
***** Call Stack Start *****
----- PL/SQL Call Stack -----
  object      line  object
  handle    number
name
0xb6d4ac18         4  procedure TEST.DISPLAY_CALL_STACK
0xb6d14298
15  package body TEST.TEST_PKG
0xb6d14298        10  package body
TEST.TEST_PKG
0xb6d14298         5  package body TEST.TEST_PKG
0xb99fe7c8
1  anonymous block

***** Call Stack End *****

PL/SQL procedure successfully completed.

SQL>

As you can see, the output from the DBMS_UTILITY.FORMAT_CALL_STACK function is rather ugly and we have no control over it, other than to manually parse it.

The UTL_CALL_STACK package contains APIs to display the contents of the call stack in a more readable form.

◈ DYNAMIC_DEPTH : The number of subprograms on the call stack, starting at the current position in the call stack, to the initial call.
◈ LEXICAL_DEPTH : Lexical depth of the subprogram within the current call.
◈ UNIT_LINE : Line number in the subprogram of the current call.
◈ SUBPROGRAM : Subprogram name associated with the current call.
◈ CONCATENATE_SUBPROGRAM : Returns the UNIT.SUBPROGRAM.LOCAL_SUBPROGRAM form of the subprogram name.
◈ OWNER : The owner of the subprogram associated with the current call.
◈ CURRENT_EDITION : The edition of the subprogram associated with the current call.

The following example recreates the DISPLAY_CALL_STACK procedure to use the UTL_CALL_STACK package, then re-runs the test.

-- Procedure to display the call stack.
CREATE OR REPLACE PROCEDURE display_call_stack AS
  l_depth PLS_INTEGER;
BEGIN
  l_depth := UTL_CALL_STACK.dynamic_depth;

  DBMS_OUTPUT.put_line('***** Call Stack Start *****');

  DBMS_OUTPUT.put_line('Depth     Lexical   Line      Owner     Edition   Name');
  DBMS_OUTPUT.put_line('.         Depth     Number');
  DBMS_OUTPUT.put_line('--------- --------- --------- --------- --------- --------------------');

  FOR i IN 1 .. l_depth LOOP
    DBMS_OUTPUT.put_line(
      RPAD(i, 10) ||
      RPAD(UTL_CALL_STACK.lexical_depth(i), 10) ||
      RPAD(TO_CHAR(UTL_CALL_STACK.unit_line(i),'99'), 10) ||
      RPAD(NVL(UTL_CALL_STACK.owner(i),' '), 10) ||
      RPAD(NVL(UTL_CALL_STACK.current_edition(i),' '), 10) ||
      UTL_CALL_STACK.concatenate_subprogram(UTL_CALL_STACK.subprogram(i))
    );
  END LOOP;

  DBMS_OUTPUT.put_line('***** Call Stack End *****');
END;
/

-- Run the test.
SET SERVEROUTPUT ON
EXEC test_pkg.proc_1;
***** Call Stack Start *****

Depth Lexical Depth Line Number Owner  Edition  Name 
1
2
3
4
5
0
1
1
1
0
13
15
10
5
1
TEST
TEST
TEST
TEST
DISPLAY_CALL_STACK
TEST_PKG.PROC_3
TEST_PKG.PROC_2
TEST_PKG.PROC_1
__anonymous_block

***** Call Stack End *****

PL/SQL procedure successfully completed.

SQL>

Starting with the call to DISPLAY_CALL_STACK, we can work back through all the nested calls to the original anonymous block. The output includes the procedure names in the package as well as the associated line numbers of the calls. If we wanted to, we could have displayed the output in reverse order, starting at the top-level call.

-- Procedure to display the call stack.
CREATE OR REPLACE PROCEDURE display_call_stack AS
  l_depth PLS_INTEGER;
BEGIN
  l_depth := UTL_CALL_STACK.dynamic_depth;

  DBMS_OUTPUT.put_line('***** Call Stack Start *****');

  DBMS_OUTPUT.put_line('Depth     Lexical   Line      Owner     Edition   Name');
  DBMS_OUTPUT.put_line('.         Depth     Number');
  DBMS_OUTPUT.put_line('--------- --------- --------- --------- --------- --------------------');

  FOR i IN REVERSE 1 .. l_depth LOOP
    DBMS_OUTPUT.put_line(
      RPAD(i, 10) ||
      RPAD(UTL_CALL_STACK.lexical_depth(i), 10) ||
      RPAD(TO_CHAR(UTL_CALL_STACK.unit_line(i),'99'), 10) ||
      RPAD(NVL(UTL_CALL_STACK.owner(i),' '), 10) ||
      RPAD(NVL(UTL_CALL_STACK.current_edition(i),' '), 10) ||
      UTL_CALL_STACK.concatenate_subprogram(UTL_CALL_STACK.subprogram(i))
    );
  END LOOP;

  DBMS_OUTPUT.put_line('***** Call Stack End *****');
END;
/

-- Run the test.
SET SERVEROUTPUT ON
EXEC test_pkg.proc_1;
***** Call Stack Start *****

Depth Lexical Depth Line Number Owner  Edition  Name 
5
4
3
2
1
0
1
1
1
0
1
5
10
15
13
TEST
TEST
TEST
TEST
__anonymous_block
TEST_PKG.PROC_1
TEST_PKG.PROC_2
TEST_PKG.PROC_3
DISPLAY_CALL_STACK

***** Call Stack End *****

PL/SQL procedure successfully completed.

SQL>

You now have programmatic control to interrogate and display the call stack if you need to.

◉ Error Stack


Exceptions are often handled by exception handlers and re-raised. In some cases, exceptions in nested calls result in different errors being produced by the error handler of the calling routine. The error stack allows you to display chains of errors, making it easier to determine the real cause of the issue. In previous releases this information was displayed using the DBMS_UTILITY.FORMAT_ERROR_STACK function, as shown below.

-- Procedure to display the call stack.
CREATE OR REPLACE PROCEDURE display_error_stack AS
BEGIN
  DBMS_OUTPUT.put_line('***** Error Stack Start *****');
  DBMS_OUTPUT.put_line(DBMS_UTILITY.format_error_stack);
  DBMS_OUTPUT.put_line('***** Error Stack End *****');
END;
/

-- Test package to show a nested call.
CREATE OR REPLACE PACKAGE test_pkg AS
  PROCEDURE proc_1;
  PROCEDURE proc_2;
  PROCEDURE proc_3;
END;
/

CREATE OR REPLACE PACKAGE BODY test_pkg AS

  PROCEDURE proc_1 AS
  BEGIN
    proc_2;
  EXCEPTION
    WHEN OTHERS THEN
      display_error_stack;
  END;

  PROCEDURE proc_2 AS
  BEGIN
    proc_3;
  EXCEPTION
    WHEN OTHERS THEN
      RAISE DUP_VAL_ON_INDEX;
  END;

  PROCEDURE proc_3 AS
  BEGIN
    RAISE NO_DATA_FOUND;
  EXCEPTION
    WHEN OTHERS THEN
      RAISE TOO_MANY_ROWS;
  END;

END;
/

-- Run the test.
SET SERVEROUTPUT ON
EXEC test_pkg.proc_1;
***** Error Stack Start *****
ORA-00001: unique constraint (.) violated
ORA-06512: at "TEST.TEST_PKG", line
16
ORA-01422: exact fetch returns more than requested number of rows
ORA-06512:
at "TEST.TEST_PKG", line 24
ORA-01403: no data found

***** Error Stack End *****

PL/SQL procedure successfully completed.

SQL>

The output from DBMS_UTILITY.FORMAT_ERROR_STACK function is fine, but there are occasional formatting errors and we can't order the output to suit our taste.

The UTL_CALL_STACK package contains APIs to display the contents of the error stack.

◈ ERROR_DEPTH : The number of errors on the error stack.
◈ ERROR_MSG : The error message associated with the current line in the error stack.
◈ ERROR_NUMBER : The error number associated with the current line in the error stack.

The following example recreates the DISPLAY_ERROR_STACK procedure to use the UTL_CALL_STACK package, then re-runs the test.

-- Procedure to display the call stack.
CREATE OR REPLACE PROCEDURE display_error_stack AS
  l_depth PLS_INTEGER;
BEGIN
  l_depth := UTL_CALL_STACK.error_depth;

  DBMS_OUTPUT.put_line('***** Error Stack Start *****');

  DBMS_OUTPUT.put_line('Depth     Error     Error');
  DBMS_OUTPUT.put_line('.         Code      Message');
  DBMS_OUTPUT.put_line('--------- --------- --------------------');

  FOR i IN 1 .. l_depth LOOP
    DBMS_OUTPUT.put_line(
      RPAD(i, 10) ||
      RPAD('ORA-' || LPAD(UTL_CALL_STACK.error_number(i), 5, '0'), 10) ||
      UTL_CALL_STACK.error_msg(i)
    );
  END LOOP; 

  DBMS_OUTPUT.put_line('***** Error Stack End *****');
END;
/

-- Run the test.
SET SERVEROUTPUT ON
EXEC test_pkg.proc_1;
***** Error Stack Start *****

Depth Error Code  Error Message
1
2
3
4
5
ORA-00001
ORA-06512
ORA-01422
ORA-06512
ORA-01403
unique constraint (.) violated
at "TEST.TEST_PKG", line 16
exact fetch returns more than requested number of rows
at "TEST.TEST_PKG", line 24
no data found

***** Error Stack End *****

PL/SQL procedure successfully completed.

SQL>

In the previous example, the display order matches the DBMS_UTILITY.FORMAT_ERROR_STACK output, which reports last to first in the chain. We could easily reverse it to display first to last.

-- Procedure to display the call stack.
CREATE OR REPLACE PROCEDURE display_error_stack AS
  l_depth PLS_INTEGER;
BEGIN
  l_depth := UTL_CALL_STACK.error_depth;

  DBMS_OUTPUT.put_line('***** Error Stack Start *****');

  DBMS_OUTPUT.put_line('Depth     Error     Error');
  DBMS_OUTPUT.put_line('.         Code      Message');
  DBMS_OUTPUT.put_line('--------- --------- --------------------');

  FOR i IN REVERSE 1 .. l_depth LOOP
    DBMS_OUTPUT.put_line(
      RPAD(i, 10) ||
      RPAD('ORA-' || LPAD(UTL_CALL_STACK.error_number(i), 5, '0'), 10) ||
      UTL_CALL_STACK.error_msg(i)
    );
  END LOOP; 

  DBMS_OUTPUT.put_line('***** Error Stack End *****');
END;
/

-- Run the test.
SET SERVEROUTPUT ON
EXEC test_pkg.proc_1;
***** Error Stack Start *****

Depth Error Code  Error Message
5
4
3
2
1
ORA-01403
ORA-06512
ORA-01422
ORA-06512
ORA-00001
no data found
at "TEST.TEST_PKG", line 24
exact fetch returns more than requested number of rows
at "TEST.TEST_PKG", line 16
unique constraint (.) violated

***** Error Stack End *****

PL/SQL procedure successfully completed.

SQL>

◉ Backtrace


Backtrace shows a walk through the call stack from the line where the exception was raised, to the last call before the exception was trapped. This shows the propagation of the exception, which allows you to identify the actual line that caused the problem. In previous releases this information was displayed using the DBMS_UTILITY.FORMAT_ERROR_BACKTRACE function, as shown below.

-- Procedure to display the call stack.
CREATE OR REPLACE PROCEDURE display_backtrace AS
BEGIN
  DBMS_OUTPUT.put_line('***** Backtrace Start *****');
  DBMS_OUTPUT.put_line(DBMS_UTILITY.format_error_backtrace);
  DBMS_OUTPUT.put_line('***** Backtrace End *****');
END;
/

-- Test package to show a nested call.
CREATE OR REPLACE PACKAGE test_pkg AS
  PROCEDURE proc_1;
  PROCEDURE proc_2;
  PROCEDURE proc_3;
END;
/

CREATE OR REPLACE PACKAGE BODY test_pkg AS

  PROCEDURE proc_1 AS
  BEGIN
    proc_2;
  EXCEPTION
    WHEN OTHERS THEN
      display_backtrace;
  END;

  PROCEDURE proc_2 AS
  BEGIN
    proc_3;
  END;

  PROCEDURE proc_3 AS
  BEGIN
    RAISE NO_DATA_FOUND;
  END;

END;
/

-- Run the test.
SET SERVEROUTPUT ON
EXEC test_pkg.proc_1;
***** Backtrace Start *****
ORA-06512: at "TEST.TEST_PKG", line 18
ORA-06512: at "TEST.TEST_PKG", line
13
ORA-06512: at "TEST.TEST_PKG", line 5

***** Backtrace End *****

PL/SQL procedure successfully completed.

SQL>

With the exception of some minor formatting issues, this output is fine and will probably be OK for most situations.

The UTL_CALL_STACK package contains APIs to display the backtrace.

◈ BACKTRACE_DEPTH : The number of backtrace messages on the error stack.
◈ BACKTRACE_LINE : Line number in the subprogram of the current call.
◈ BACKTRACE_UNIT : Subprogram name associated with the current call.

The following example recreates the DISPLAY_BACKTRACE procedure to use the UTL_CALL_STACK package, then re-runs the test.

-- Procedure to display the call stack.
CREATE OR REPLACE PROCEDURE display_backtrace AS
  l_depth PLS_INTEGER;
BEGIN
  l_depth := UTL_CALL_STACK.backtrace_depth;

  DBMS_OUTPUT.put_line('***** Backtrace Start *****');

  DBMS_OUTPUT.put_line('Depth     BTrace     BTrace');
  DBMS_OUTPUT.put_line('.         Line       Unit');
  DBMS_OUTPUT.put_line('--------- --------- --------------------');

  FOR i IN 1 .. l_depth LOOP
    DBMS_OUTPUT.put_line(
      RPAD(i, 10) ||
      RPAD(TO_CHAR(UTL_CALL_STACK.backtrace_line(i),'99'), 10) ||
      UTL_CALL_STACK.backtrace_unit(i)
    );
  END LOOP;

  DBMS_OUTPUT.put_line('***** Backtrace End *****');
END;
/

-- Run the test.
SET SERVEROUTPUT ON
EXEC test_pkg.proc_1;
***** Backtrace Start *****

Depth BTrace Live BTrace Unit
1
2
3
5
13
18
TEST.TEST_PKG
TEST.TEST_PKG
TEST.TEST_PKG

***** Backtrace End *****

PL/SQL procedure successfully completed.

SQL>

There is very little you can do with the backtrace, other than reordering it. The "ORA-06512" error is not included, but this is implied because it is a backtrace message. The following example shows the backtrace in reverse order.

-- Procedure to display the call stack.
CREATE OR REPLACE PROCEDURE display_backtrace AS
  l_depth PLS_INTEGER;
BEGIN
  l_depth := UTL_CALL_STACK.backtrace_depth;

  DBMS_OUTPUT.put_line('***** Backtrace Start *****');

  DBMS_OUTPUT.put_line('Depth     BTrace     BTrace');
  DBMS_OUTPUT.put_line('.         Line       Unit');
  DBMS_OUTPUT.put_line('--------- --------- --------------------');

  FOR i IN REVERSE 1 .. l_depth LOOP
    DBMS_OUTPUT.put_line(
      RPAD(i, 10) ||
      RPAD(TO_CHAR(UTL_CALL_STACK.backtrace_line(i),'99'), 10) ||
      UTL_CALL_STACK.backtrace_unit(i)
    );
  END LOOP; 

  DBMS_OUTPUT.put_line('***** Backtrace End *****');
END;
/

-- Run the test.
SET SERVEROUTPUT ON
EXEC test_pkg.proc_1;
***** Backtrace Start *****

Depth BTrace Live BTrace Unit
3
2
1
18
13
5
TEST.TEST_PKG
TEST.TEST_PKG
TEST.TEST_PKG

***** Backtrace End *****

PL/SQL procedure successfully completed.

SQL>