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."
Check your optimization level! Oh, how do you do that? Here you go:
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
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'
/
Hello Steven,
ReplyDeleteIt 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
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.
DeleteI 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.
Hello Steven,
ReplyDeleteJust 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