PL/SQL Error Logging and Quantum Theory

When I started writing this post, it was going to be about something else.
This happens occasionally, I have an idea in my head and set to work.
Then I do some research – don’t look so surprised, I do look at the docs occasionally – and, as in this case, I find out that there’s rather more to the topic at hand than I first thought.
What follows is a re-visiting of some of the tools available in Oracle to help with error logging.
It includes stuff that either I’d forgotten or had never considered about some fairly common functions.
Before I dive in, I’d just like to say thanks to William Robertson, who first pointed out to me the similarity between PL/SQL error logging and Quantum Theory. If you’re still unclear of the connection between the two then consider, if you will, the Schrodinger’s Cat Thought Experiment.
It involves locking a cat in a box and possibly poisoning it.
Schrodinger postulates that the cat is both alive and dead…until you open the box to check.
The conclusions we can draw from this experiment are :

  • According to Quantum Theory, the act of observation changes the nature of the thing being observed
  • Schrodinger wasn’t a Cat person

Before going any further, I should point out that most of the stuff I know about Physics comes from watching Star Trek.

Moving on, I now invite you to consider…

Mysteriously moving errors

As with cats – according to Shrodinger at least – the act of “observing”- well, handling – a PL/SQL exception changes the error ( or the location from which it originated at any rate).

For example…

declare
    l_cat number;
begin
    l_cat := 'GREEBO';
end;
/

declare
*
ERROR at line 1:
ORA-06502: PL/SQL: numeric or value error: character to number conversion error
ORA-06512: at line 4

No problem with this. It shows us that the error happened at line 4 in the code, which is correct.
However….

declare
    l_cat number;
begin
    l_cat := 'GREEBO';
exception
    when others then
        -- do some logging stuff....
        raise;
end;
/

declare
*
ERROR at line 1:
ORA-06502: PL/SQL: numeric or value error: character to number conversion error
ORA-06512: at line 8

Here, the exception originated on line 4. However, the error is reported at line 8 – inside the exception handler.

This then, is the problem with which we need to wrestle.
Time to take a closer look at the tools that Oracle provides us for the purpose of error handling, starting with the most venerable…

SQLCODE and SQLERRM

SQLCODE and SQLERRM have been around for as long as I can remember.
If you’ve worked on PL/SQL applications for any length of time, you will almost certainly seen a variation of one of the following in an exception handler :

    sqlerrm(sqlcode);
    
    sqlcode||' : '||sqlerrm;
    
    substr(sqlerrm(sqlcode),1,500));

If any of the above ring any bells then it illustrates the point that these functions ( for that is what they are), are not especially well understood.

SQLCODE

SQLCODE returns the number of the last error encountered. Not the message, just the error number :

set serveroutput on
declare
    l_cat_lives number;
begin
    l_cat_lives := 'If the cat belongs to Shrodinger the answer is uncertain. Otherwise 9';
exception 
    when others then
        dbms_output.put_line(sqlcode);
end;
/

-6502

PL/SQL procedure successfully completed.

SQLCODE returns 0 on successful completion…

declare
    l_cat_lives number;
begin
    l_cat_lives := 9;
    dbms_output.put_line(sqlcode);
end;
/
0

PL/SQL procedure successfully completed.

For user-defined errors, it returns 1 by default…

declare
    e_no_cat exception;
begin
    raise e_no_cat;
exception when e_no_cat then
    dbms_output.put_line(sqlcode);
end;
/

1

PL/SQL procedure successfully completed.

…unless you associate the exception with an error number using the EXCEPTION_INIT pragma…

declare
    e_no_cat exception;
    pragma exception_init( e_no_cat, -20000);
begin
    raise e_no_cat;
exception when e_no_cat then
    dbms_output.put_line(sqlcode);
end;
/
-20000

PL/SQL procedure successfully completed.

SQL> 

It will also return the relevant error code if you use RAISE_APPLICATION_ERROR…

begin
    raise_application_error(-20001, 'The cat has run off');
exception when others then
    dbms_output.put_line(sqlcode);
end;
/
-20001

PL/SQL procedure successfully completed.

SQL> 

On it’s own then, SQLCODE is not much help in terms of working out what went wrong unless you happen to have memorized all of the Oracle error messages.

Fortunately we also have…

SQLERRM

This function takes in an error number and returns the relevant message :

begin
    dbms_output.put_line(sqlerrm(-6502));
end;
/
ORA-06502: PL/SQL: numeric or value error

PL/SQL procedure successfully completed.

Because of this SQLERRM can be used to create the equivalent of the oerr utility in PL/SQL.
Better still, it takes SQLCODE as it’s default parameter…

declare
    l_cat_lives number;
begin
    l_cat_lives := 'If the cat belongs to Shrodinger the answer is uncertain. Otherwise 9';
exception
    when others then
        dbms_output.put_line(sqlerrm);
end;
/

ORA-06502: PL/SQL: numeric or value error: character to number conversion error

PL/SQL procedure successfully completed.

The maximum length of a varchar returned by SQLERRM is, according to the documentation, “the maximum length of an Oracle Database error message” – 512.

Whilst we’re on the subject, the 11gR2 documentationincludes a note recommending that, generally, DBMS_UTILITY.FORMAT_ERROR_STACK be used instead…

DBMS_UTILITY.FORMAT_ERROR_STACK

So, let’s see what this function gives us when used as a drop-in replacement for SQLERRM….

declare
    l_cat_lives number;
begin
    l_cat_lives := 'If the cat belongs to Shrodinger the answer is uncertain. Otherwise 9';
exception
    when others then
        dbms_output.put_line(dbms_utility.format_error_stack);
end;
/
ORA-06502: PL/SQL: numeric or value error: character to number conversion error


PL/SQL procedure successfully completed.

SQL> 

Not much then based on this example. However, there are a couple of differences.
The first is that this function returns up to 2000 characters of the error stack.
The second is that it does not take any arguments. Fair enough I suppose. From the name you’d infer that this function returns the entire error stack rather than the single message that SQLERRM does.
Let’s put that to the test…

create or replace package transporter as
    function find_target return varchar2;
    procedure beam_me_up_scotty;
end transporter;
/

create or replace package body transporter as
    function find_target 
        return varchar2
    is
    begin
        raise_application_error(-20003, 'Location or velocity unknown');
    end find_target;

    procedure beam_me_up_scotty is
        l_target varchar2(30);
    begin
        -- engage the heisenburg compensator...
        l_target := find_target;
        dbms_output.put_line('Energize !');
    end beam_me_up_scotty;
end transporter;
/

This package is an analog of what Star Fleet Engineers would have been working with before they came up with the Heisenburg Compensator.

If we call this without any error handling, we’ll get a “stack” of errors…

begin
    transporter.beam_me_up_scotty;
end;
/

*
ERROR at line 1:
ORA-20003: Location or velocity unknown
ORA-06512: at "MIKE.TRANSPORTER", line 6 
ORA-06512: at "MIKE.TRANSPORTER", line 13
ORA-06512: at line 1

You’d expect something fairly similar if you used the FORMAT_ERROR_STACK function…

set serveroutput on size unlimited
begin
    transporter.beam_me_up_scotty;
exception
    when others then
        dbms_output.put_line(dbms_utility.format_error_stack);
end;
/

ORA-20003: Location or velocity unknown



PL/SQL procedure successfully completed.

SQL> 

So, not similar at all then.
NOTE – if you’ve already spotted the deliberate mistake here. Bear with me for a bit.
If we change the package body so that errors are raised at multiple levels…

create or replace package body transporter as
    function find_target 
        return varchar2
    is
    begin
        raise_application_error(-20003, 'Location or velocity unknown');
    end find_target;

    procedure beam_me_up_scotty is
        l_target varchar2(30);
    begin
        -- engage the heisenburg compensator...
        l_target := find_target;
        dbms_output.put_line('Energize !');
    exception when others then
        raise_application_error(-20004, 'I canna change the laws o physics!');
    end beam_me_up_scotty;
end transporter;
/

… we simply get the last error passed…

begin
    transporter.beam_me_up_scotty;
exception
    when others then
        dbms_output.put_line(dbms_utility.format_error_stack);
end;
/

ORA-20004: I canna change the laws o physics!



PL/SQL procedure successfully completed.

SQL> 

From all of this, it would appear that DBMS_UTILITY.FORMAT_ERROR_STACK doesn’t really give us much (if anything) over SQLERRM. This is especially true if the documentation is correct and no single Oracle Error Message will exceed 512 bytes.
All of which is rather odd, until you consider…

RAISE_APPLICATION_ERROR

RAISE_APPLICATION_ERROR is usually invoked as in the above example. However, it actually accepts three arguments :

  • NUM – an error code in the range -20000 to -20999
  • MSG – an error message up to 1024 characters ( including the error code)
  • KEEPERRORSTACK – if TRUE then the error code is placed at the top of the error stack. Otherwise it replaces the error stack.
    Default is FALSE

The first point to note here is that, unlike SQLERRM, FORMAT_ERROR_STACK can accomodate the full length of a message from RAISE_APPLICATION_ERROR.
More relevant to the issue at hand however, it the KEEPERRORSTACK parameter. If we tweak the package once more to set this parameter to true…

create or replace package body transporter as
    function find_target 
        return varchar2
    is
    begin
        raise_application_error(-20003, 'Location or velocity unknown', true);
    end find_target;

    procedure beam_me_up_scotty is
        l_target varchar2(30);
    begin
        -- engage the heisenburg compensator...
        l_target := find_target;
        dbms_output.put_line('Energize !');
    exception when others then
        raise_application_error(-20004, 'I canna change the laws o physics!', true);
    end beam_me_up_scotty;
end transporter;
/

…and re-run our test…

begin
    transporter.beam_me_up_scotty;
exception
    when others then
        dbms_output.put_line(dbms_utility.format_error_stack);
end;
/
ORA-20004: I canna change the laws o physics!
ORA-06512: at "MIKE.TRANSPORTER", line 16
ORA-20003: Location or velocity unknown

PL/SQL procedure successfully completed.

…we now get a stack. However, we’re still stuck without the line number from where the error originated.
Fortunately, they’ve been burning the candle at both ends over at Star Fleet, or possibly at Redwood Shores…

DBMS_UTILITY.FORMAT_ERROR_BACKTRACE

Let’s try re-executing our package, this time using FORMAT_ERROR_BACKTRACE…

begin
    transporter.beam_me_up_scotty;
exception
    when others then
        dbms_output.put_line(dbms_utility.format_error_backtrace);
end;
/

ORA-06512: at "MIKE.TRANSPORTER", line 7
ORA-06512: at "MIKE.TRANSPORTER", line 14
ORA-06512: at line 2



PL/SQL procedure successfully completed.

SQL> 

Well, that’s different. We get a stack, together with the line number at which the error originated. Unfortunately it doesn’t include the originating error message itself. Let’s try that again, but this time in combination with SQLERRM…

 
begin
    transporter.beam_me_up_scotty;
exception
    when others then
        dbms_output.put_line(sqlerrm);
        dbms_output.put_line(dbms_utility.format_error_backtrace);
end;
/
ORA-06502: PL/SQL: numeric or value error: character to number conversion error
ORA-06512: at "MIKE.TRANSPORTER", line 7
ORA-06512: at "MIKE.TRANSPORTER", line 14
ORA-06512: at line 2



PL/SQL procedure successfully completed.

SQL> 

Now we have the original error. We also have the line at which it happened. At last, we have our Heisenburg compensator.
Well, in most circumstances. Just before we test it on Admiral Archer’s prize beagle …

create or replace package body transporter as
    function find_target 
        return varchar2
    is
        l_silly number;
    begin
        l_silly :=  'Location or velocity unknown';
        exception when others then
            -- do some logging and...
            raise;
    end find_target;

    procedure beam_me_up_scotty is
        l_target varchar2(30);
    begin
        -- engage the heisenburg compensator...
        l_target := find_target;
        dbms_output.put_line('Energize !');
    end beam_me_up_scotty;
end transporter;
/

Now we’ve added an error handler to the innermost package member…

begin
    transporter.beam_me_up_scotty;
exception
    when others then
        dbms_output.put_line(sqlerrm);
        dbms_output.put_line(dbms_utility.format_error_backtrace);
end;
/

ORA-06502: PL/SQL: numeric or value error: character to number conversion error
ORA-06512: at "MIKE.TRANSPORTER", line 10
ORA-06512: at "MIKE.TRANSPORTER", line 17
ORA-06512: at line 2



PL/SQL procedure successfully completed.

…once again the handled error has “moved” to the exception block of the function.

In terms of retrieving the error stack, it would appear that a combination of SQLERRM and DBMS_UTILITY.FORMAT_ERROR_BACKTRACE offer the most comprehensive and reliable information.
However, in order to further pin down where those pesky errors are originating we may need to turn to a time-honoured technique – albeit with a comparatively modern twist…

Location Markers with $$PLSQL_LINE

The $$PLSQL_LINE variable simply returns the line number of the stored program unit or anonymous block you’re currently in…

begin
    dbms_output.put_line('At line : '||$$plsql_line);
end;
/

At line : 2

PL/SQL procedure successfully completed.

SQL> 

By sprinkling a few dollars through our code, we should get a better (although still not necessarily exact) idea of where our error is originating.

I’m going to persevere with this transporter code. After all, they managed to get it working in the original Star Trek and that was way back in the 60’s…

create or replace package body transporter as
    function find_target 
        return varchar2
    is
        l_loc pls_integer;
        l_silly number;
    begin
        l_loc := $$plsql_line;
        l_silly :=  'Location or velocity unknown';
        exception when others then
            dbms_output.put_line('Error originating after line '||l_loc);
            raise;
    end find_target;

    procedure beam_me_up_scotty is
        l_target varchar2(30);
    begin
        -- engage the heisenburg compensator...
        l_target := find_target;
        dbms_output.put_line('Energize !');
    end beam_me_up_scotty;
end transporter;
/

Now, we should get a bit more information…

begin
    transporter.beam_me_up_scotty;
exception
    when others then
        dbms_output.put_line(sqlerrm);
        dbms_output.put_line(dbms_utility.format_error_backtrace); 
end;
/
Error originating after line 8
ORA-06502: PL/SQL: numeric or value error: character to number conversion error
ORA-06512: at "MIKE.TRANSPORTER", line 12
ORA-06512: at "MIKE.TRANSPORTER", line 19
ORA-06512: at line 2



PL/SQL procedure successfully completed.

SQL> 

The error actually originates from line 9 so that’s a pretty good approximation.
The downside is the aforementionned sprinkling of the assignment of $$PLSQL_LINE to a variable immediately before you perform any action.

Well, I’ve probably managed to annoy an Physics experts and Star Trek fans that happen to be reading. That’s before you even start thinking about PL/SQL Developers.
On the plus side I can say, hand-on-heart, that no cats were harmed in the writing of this post.

Advertisements

6 thoughts on “PL/SQL Error Logging and Quantum Theory

  1. Nice article on navigating PL/SQL’s myriad of error stack solutions.

    Personally, I put DBMS_UTILITY.FORMAT_ERROR_BACKTRACE in every exception block.

    Do you know if UTL_CALL_STACK is more predictable?

    • Kevan,

      I’m still on 11gR2 in my day-job ( not to mention on the train when I’m writing this stuff) so I haven’t had a play
      with UTL_CALL_STACK as yet. However, if the docs are anything to go by, it certainly looks like an improvement 🙂

      Mike

  2. Pingback: utPLSQL – We’re building the…Unit Tests! | The Anti-Kyte

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s