Skip to Main Content

Breadcrumb

Question and Answer

Chris Saxon

Thanks for the question, Anastasia.

Asked: November 22, 2016 - 1:42 pm UTC

Last updated: November 29, 2016 - 11:06 am UTC

Version: 12c

Viewed 1000+ times

You Asked

Hello, Tom.
I my project we have a package with a pretty standard structure, I think. It has public procedures calling in turn private procedures, calling innermost procedures eventually. Simplifying, something like this:
-----------------------------------------------------
create or replace PACKAGE body pck_proccess is
-----------------------------------------------------
procedure prc_lvl_3(p_in_par) as
-- operations
end prc_lvl_3;
-----------------------------------------------------
procedure prc_lvl_2(p_in_par) as
prc_lvl_3(oper_params);
-- operations
end prc_lvl_2;
-----------------------------------------------------
procedure prc_lvl_1(p_in_par) as
prc_lvl_2(oper_params);
-- operations
end prc_lvl_1;
-----------------------------------------------------
end pck_proccess;
-----------------------------------------------------
This package must call a logging procedure at specific stages of processing and in case of foreseen and unforeseen (like ORA-XXXX exceptions) errors.
The last might, of course, occur, during the 'innermost' procedures/functions execution.
An exception in the procedure prc_lvl_3 should stop the flow of prc_lvl_2, the one in prc_lvl_2 - stops prc_lvl_1.
Besides, in case of ORA-exception (unforeseen, having occurred whilst one of innermost procedures), the log message must consist of SQLERRM and the string of all input parameters of the procedure which triggered an exception.
Taking it all into account, I found a solution that is as follows:

-----------------------------------------------------
create or replace PACKAGE body pck_proccess is
-----------------------------------------------------
e_internal_error EXCEPTION;
pragma exception_init(e_internal_error,-20001);

procedure prc_lvl_3(p_in_par) as
-- operations
exception when others then
pck_logging.prc_log_msg(log_param1, log_param2);
raise_application_error(-20001, sqlerrm);
end prc_lvl_3;
-----------------------------------------------------
procedure prc_lvl_2(p_in_par) as
prc_lvl_3(oper_params);
-- operations
-----------------------------------------------------
exception when e_internal_error then
raise_application_error(-20001, sqlerrm);
-----------------------------------------------------
exception when others then
pck_logging.prc_log_msg(log_param1, log_param2);
raise_application_error(-20001, sqlerrm);
-----------------------------------------------------
end prc_lvl_2;
-----------------------------------------------------
procedure prc_lvl_1(p_in_par) as
prc_lvl_2(oper_params);
-- operations
-----------------------------------------------------
exception when e_internal_error then
raise_application_error(-20001, sqlerrm);
-----------------------------------------------------
exception when others then
pck_logging.prc_log_msg(log_param1, log_param2);
raise_application_error(-20001, sqlerrm);
-----------------------------------------------------
end prc_lvl_1;
end pck_proccess;

-----------------------------------------------------
Basically, if we have already handle the exception, we pass it upper - so the rest procedures 'know' that the processing must be stopped, but log message has already be written.


Now to the question.
1) Can you advise me a better way to do this handling and logging?
2) My boss considers this way too heavy and ‘expensive’; because we pass an exception to the ‘top’ up to 3 times (there are 4 levels of 'nesting'). He suggests that we use a global variable (something like v_error_count) to be used as a flag pointing, whether something went wrong... I don't like global vars, so I am thinking of an out parameter p_out_status for every procedure, acting like a flag as well, but I like this idea neither.
So the question is, are exceptions really so hard to raise (in terms of performance), so that we need to search for some ways (seeming tricky enough) to handle them without passing it to the top?


Thank you very much in advance.

and Chris said...

Personally I'd only handle exceptions at the first point you're able to deal with the error. So you only have "when others" handlers at the top level. Not each stage along the way.

You can then get the full stack trace by using dbms_utility.format_error_backtrace. No need for flags or other gimmicks!

create or replace procedure show_trace is
begin
  dbms_output.put_line( dbms_utility.format_error_backtrace );  
end show_trace;
/
      
create or replace package pkg as
  procedure p1;
  procedure p2;
  procedure p3;
end pkg;
/

create or replace package body pkg as
  procedure p1 as
    n number;
  begin
    n := 1/0;
  end p1;
  
  procedure p2 as
  begin
    p1;
  end p2;
  
  procedure p3 as
  begin
    p2;
  exception
    when others then 
      show_trace;
      raise;
  end p3;
end pkg;
/

exec pkg.p3;

Error report -
ORA-01476: divisor is equal to zero
ORA-06512: at "CHRIS.PKG", line 19
ORA-06512: at line 1
01476. 00000 -  "divisor is equal to zero"
*Cause:    
*Action:
ORA-06512: at "CHRIS.PKG", line 5
ORA-06512: at "CHRIS.PKG", line 10
ORA-06512: at "CHRIS.PKG", line 15


Or, as you're on 12c, you could use the utl_call_stack package. This provides more power over format_error_backtrace:

create or replace procedure show_trace is
begin
  for i in reverse 1 .. utl_call_stack.backtrace_depth loop
    dbms_output.put_line (
      'Line: ' || utl_call_stack.backtrace_line(i) || ', ' || 
      'Subprogram: ' || utl_call_stack.backtrace_unit(i)
    );
  end loop;
end show_trace;
/

exec pkg.p3;

Error report -
ORA-01476: divisor is equal to zero
ORA-06512: at "CHRIS.PKG", line 19
ORA-06512: at line 1
01476. 00000 -  "divisor is equal to zero"
*Cause:    
*Action:
Line: 5, Subprogram: CHRIS.PKG
Line: 10, Subprogram: CHRIS.PKG
Line: 15, Subprogram: CHRIS.PKG


For further details on this, read this article by Steven Feuerstein:

http://www.oracle.com/technetwork/issue-archive/2014/14-jan/o14plsql-2045346.html

Note: If you set the PL/SQL optimization level to 3, the compiler can do some aggressive rewriting of your code. This can lead to unexpected line numbers in your error stack!

alter session set plsql_optimize_level = 3;

alter package pkg compile body;

exec pkg.p3;

Error report -
ORA-01476: divisor is equal to zero
ORA-06512: at "CHRIS.PKG", line 19
ORA-06512: at line 1
01476. 00000 -  "divisor is equal to zero"
*Cause:    
*Action:
Line: 13, Subprogram: CHRIS.PKG

Rating

  (2 ratings)

Is this answer out of date? If it is, please let us know via a Comment

Comments

Thanks, but how about inputs?

Anastasia, November 29, 2016 - 8:28 am UTC

Thank you very much.
UTL_CALL_STACK looks fine - there is just one little thing:
I see, it gives an opportunity to display the subprogram's name, but not the input parameters it was run with.
Perhaps, it is not good practice at all - to write the input parameters of the failed subroutine in the log message?

Chris Saxon
November 29, 2016 - 11:06 am UTC

Capturing the input parameters can certainly help with debugging. But if you're trapping and re-raising the exception multiple times it can be hard to see where the error really started.

In any case, I'd look at using a framework like logger to help you store parameters and errors:

https://github.com/OraOpenSource/Logger

More to Explore

PL/SQL demos

Check out more PL/SQL tutorials on our LiveSQL tool.

PL/SQL docs

PL/SQL reference manual from the Oracle documentation library