Skip to main content

Confused by your error backtrace? Check the optimization level!

The DBMS_UTILITY.FORMAT_ERROR_BACKTRACE (and similar functionality in the UTL_CALL_STACK package) is a tremendously helpful function. It returns a formatted string that allows you to easily trace back to the line number on which an exception was raised.

You know what else is really helpful? The automatic optimization performed by the PL/SQL compiler. The default level is 2, which does an awful lot of optimizing for you. But if you want to get the most out of the optimizer, you can ratchet it up to level 3, which then added subprogram inlining.

Unfortunately, these two wonderful features don't mix all that well. Specifically, if you optimize at level 3, then the backtrace may not point all the way back to the line number in your "original" source code (without inlining, of course).

Run this LiveSQL script to see the following code below "in action."
ALTER SESSION SET plsql_optimize_level = 2
/

CREATE OR REPLACE PROCEDURE proc1
IS
   l_level   INTEGER;

   PROCEDURE inline_proc1
   IS
   BEGIN
      RAISE PROGRAM_ERROR;
   EXCEPTION
      WHEN OTHERS
      THEN
         DBMS_OUTPUT.put_line ('inline_proc1 handler');

         DBMS_OUTPUT.put_line (DBMS_UTILITY.format_error_backtrace);
         RAISE;
   END;
BEGIN
   SELECT plsql_optimize_level
     INTO l_level
     FROM user_plsql_object_settings
    WHERE name = 'PROC1';

   DBMS_OUTPUT.put_line ('Opt level = ' || l_level);

   inline_proc1;
EXCEPTION
   WHEN OTHERS
   THEN
      DBMS_OUTPUT.put_line ('inline handler');

      DBMS_OUTPUT.put_line (DBMS_UTILITY.format_error_backtrace);
      RAISE;
END;
/

BEGIN
   proc1;
END;
/

ALTER SESSION SET plsql_optimize_level = 3
/

ALTER PROCEDURE proc1
COMPILE
/

BEGIN
   proc1;
END;
/

Opt level = 2
inline_proc1 handler
ORA-06512: at "STEVEN.PROC1", line 8

inline handler
ORA-06512: at "STEVEN.PROC1", line 15
ORA-06512: at "STEVEN.PROC1", line 8
ORA-06512: at "STEVEN.PROC1", line 25


Opt level = 3
inline_proc1 handler
ORA-06512: at "STEVEN.PROC1", line 25

inline handler
ORA-06512: at "STEVEN.PROC1", line 25
ORA-06512: at "STEVEN.PROC1", line 25
I hope to have an update from the PL/SQL dev team on this topic soon, but I wanted to make you aware of this in case you get all confused and frustrated.

Check your optimization level! Oh, how do you do that? Here you go:
SELECT p.plsql_optimize_level
  FROM user_plsql_object_settings p
 WHERE name = 'PROC1'
/

Comments

  1. Hello Steven,

    It looks to me that even for PLSQL_OPTIMIZE_LEVEL = 2 the output that we see is not exactly as it was supposed to be
    by definition.

    As far as I know the "line 8" was only supposed to be "remembered" by the backtrace value displayed
    in the handler of "inline_proc1", and "forgotten" after re-raising the exception.

    However, we see "line 8" twice in the output.

    Wasn't the output supposed to be as follows ?

    Opt level = 2
    inline_proc1 handler
    ORA-06512: at "STEVEN.PROC1", line 8

    inline handler
    ORA-06512: at "STEVEN.PROC1", line 15
    ORA-06512: at "STEVEN.PROC1", line 25



    Thanks a lot & Best Regards,
    Iudith

    ReplyDelete
    Replies
    1. Huh. Interesting. I am not certain of all the details of how backtrace constructs its stack. I generally focus like a laser on the very top: the line number on which the current exception was raised.

      I can see an argument for including line 8, in the sense that the error stack did "go through" that line. But I do not know if that is an accurate explanation.

      Delete
  2. Hello Steven,

    Just out of curiosity, I performed some tests to compare the
    output of DBMS_UTILITY.FORMAT_ERROR_BACKTRACE with that of
    the UTL_CALL_STACK backtrace functions, and their results
    are the same.

    But, surprisingly enough, the output of DBMS_UTILITY.FORMAT_ERROR_BACKTRACE in 12c contains more lines than its value in 11gR2.

    Specifically, in 12c it shows BOTH the line where the original exception was raised AND the line where it was re-raised,
    so, the same unit name may appear twice in the backtrace output.

    Similarly, the DBMS_UTILITY.FORMAT_ERROR_STACK also contains more lines than its 11gR2 counterpart, looks like in 12c it "repeats" part of the DBMS_UTILITY.FORMAT_ERROR_BACKTRACE info.


    At least, this is the behavior I experienced when testing with
    LiveSQL.

    So, when using a new version, one should not only learn new things,
    but also forget things already considered as known ...

    Anyway, it could be interesting to know whether the changed
    content of the DBMS_UTILITY error functions for 12c
    was deliberate or not.

    Below is the test code I used, if anybody is interested.

    One thing to be mentioned is that trying to call UTL_CALL_STACK.backtrace_unit from an anonymous block
    raises error "ORA-64610: bad depth indicator", so that is why I added the last procedure named test_plch_proc3.


    CREATE OR REPLACE PROCEDURE show_backtrace
    AS
    BEGIN
    DBMS_OUTPUT.put_line('--------------------------');
    DBMS_OUTPUT.put_line('backtrace - depth='||UTL_CALL_STACK.backtrace_depth);
    DBMS_OUTPUT.put_line('--------------------------');

    FOR i IN 1 .. UTL_CALL_STACK.backtrace_depth
    LOOP
    DBMS_OUTPUT.put_line('BACKTRACE_DEPTH=['||i||'] --> '||
    'UNIT=' ||UTL_CALL_STACK.backtrace_unit(i)||
    ' -- LINE='||UTL_CALL_STACK.backtrace_line(i) );
    END LOOP;
    END;
    /

    CREATE OR REPLACE PROCEDURE plch_proc1
    IS
    BEGIN
    RAISE NO_DATA_FOUND;
    END plch_proc1;
    /


    CREATE OR REPLACE PROCEDURE plch_proc2
    IS
    BEGIN
    plch_proc1;
    EXCEPTION
    WHEN OTHERS
    THEN
    RAISE VALUE_ERROR;
    END plch_proc2;
    /

    CREATE OR REPLACE PROCEDURE plch_proc3
    IS
    BEGIN
    plch_proc2;
    EXCEPTION
    WHEN OTHERS
    THEN
    DBMS_OUTPUT.put_line('----- BEFORE RAISE; -----');
    DBMS_OUTPUT.put_line('----- ERROR -----');
    DBMS_OUTPUT.put_line(DBMS_UTILITY.format_error_stack);
    DBMS_OUTPUT.put_line('----- BACKTRACE -----');
    DBMS_OUTPUT.put_line(DBMS_UTILITY.format_error_backtrace);
    -- 12c
    DBMS_OUTPUT.put_line('----- UTL BACKTRACE -----');
    show_backtrace;

    RAISE;
    END plch_proc3;
    /


    CREATE OR REPLACE PROCEDURE test_plch_proc3
    AS
    BEGIN
    plch_proc3;
    EXCEPTION
    WHEN OTHERS
    THEN
    DBMS_OUTPUT.put_line('----- AFTER RAISE; -----');
    DBMS_OUTPUT.put_line('----- ERROR -----');
    DBMS_OUTPUT.put_line(DBMS_UTILITY.format_error_stack);
    DBMS_OUTPUT.put_line('----- BACKTRACE -----');
    DBMS_OUTPUT.put_line(DBMS_UTILITY.format_error_backtrace);
    -- 12c
    DBMS_OUTPUT.put_line('----- UTL BACKTRACE -----');
    show_backtrace;
    END;
    /


    BEGIN
    test_plch_proc3;
    END;
    /


    Thanks a lot & Best Regards,
    Iudith

    ReplyDelete

Post a Comment

Popular posts from this blog

Quick Guide to User-Defined Types in Oracle PL/SQL

A Twitter follower recently asked for more information on user-defined types in the PL/SQL language, and I figured the best way to answer is to offer up this blog post. PL/SQL is a strongly-typed language . Before you can work with a variable or constant, it must be declared with a type (yes, PL/SQL also supports lots of implicit conversions from one type to another, but still, everything must be declared with a type). PL/SQL offers a wide array of pre-defined data types , both in the language natively (such as VARCHAR2, PLS_INTEGER, BOOLEAN, etc.) and in a variety of supplied packages (e.g., the NUMBER_TABLE collection type in the DBMS_SQL package). Data types in PL/SQL can be scalars, such as strings and numbers, or composite (consisting of one or more scalars), such as record types, collection types and object types. You can't really declare your own "user-defined" scalars, though you can define subtypes  from those scalars, which can be very helpful from the p

The differences between deterministic and result cache features

 EVERY once in a while, a developer gets in touch with a question like this: I am confused about the exact difference between deterministic and result_cache. Do they have different application use cases? I have used deterministic feature in many functions which retrieve data from some lookup tables. Is it essential to replace these 'deterministic' key words with 'result_cache'?  So I thought I'd write a post about the differences between these two features. But first, let's make sure we all understand what it means for a function to be  deterministic. From Wikipedia : In computer science, a deterministic algorithm is an algorithm which, given a particular input, will always produce the same output, with the underlying machine always passing through the same sequence of states.  Another way of putting this is that a deterministic subprogram (procedure or function) has no side-effects. If you pass a certain set of arguments for the parameters, you will always get

My two favorite APEX 5 features: Regional Display Selector and Cards

We (the over-sized development team for the PL/SQL Challenge - myself and my son, Eli) have been busy creating a new website on top of the PLCH platform (tables and packages): The Oracle Dev Gym! In a few short months (and just a part time involvement by yours truly), we have leveraged Oracle Application Express 5 to create what I think is an elegant, easy-to-use site that our users will absolutely love.  We plan to initially make the Dev Gym available only for current users of PL/SQL Challenge, so we can get feedback from our loyal user base. We will make the necessary adjustments and then offer it for general availability later this year. Anyway, more on that as the date approaches (the date being June 27, the APEX Open Mic Night at Kscope16 , where I will present it to a packed room of APEX experts). What I want to talk about today are two features of APEX that are making me so happy these days: Regional Display Selector and Cards. Regional Display Sel