Tools make life easier for developers. One of these tools that I find indispensible is a logging package. This post is not about that package though but one that is built on top of it; an error logging package.
Exception handling is one area that I have frequently found to be poor with PL/SQL applications. In particular identifying the specific place in the code where an exception is thrown can be a difficult task if any routine in the call stack has an exception handler that is simply:
EXCEPTION
WHEN OTHERS THEN
RAISE;
(I actually worked at a place where the above was part of the standard for any PL/SQL routine!)
The package I’ll introduce here exposes two very simple routines:
- A function that returns the last SQL error message, complete with a error stack trace
- A procedure that logs the last error message to the, as yet unspecified, logging package. This routine permits the user to include a customised message at the start of the error message text.
The package specification (or header) is:
CREATE OR REPLACE PACKAGE pkg_err AS -------------------------------------------------------------------------------- -- Package : pkg_err -- Author : Mark Hoxey -- Creation Date : 17/11/2009 -- -- Overview : Error handling routines -- -------------------------------------------------------------------------------- -- Source Control: $Id$ -------------------------------------------------------------------------------- -- Modification History : -- -- Initials Date Description -- -------- ---------- --------------------------------------- -- M Hoxey 17/11/2009 Initial version -- M Hoxey 02/12/2009 Added p_custom_message parameter to -- log_last_err -------------------------------------------------------------------------------- -------------------------------------------------------------------------------- -- Function : full_err_msg -- -- Description : Returns the full error message stack -------------------------------------------------------------------------------- FUNCTION full_err_msg RETURN pkg_log.t_log_msg; -------------------------------------------------------------------------------- -- Procedure : log_last_err -- -- Description : Logs the last error details -------------------------------------------------------------------------------- PROCEDURE log_last_err (p_custom_message IN pkg_db_type.t_big_string DEFAULT NULL); END pkg_err; /
The package body is:
CREATE OR REPLACE PACKAGE BODY pkg_err
AS
--------------------------------------------------------------------------------
-- Package : pkg_err
-- Author : Mark Hoxey
-- Creation Date : 17/11/2009
--
-- Overview : Error handling routines
--
--------------------------------------------------------------------------------
-- Source Control: $Id$
--------------------------------------------------------------------------------
-- Modification History :
--
-- Initials Date Description
-- -------- ---------- ---------------------------------------
-- M Hoxey 17/11/2009 Initial version
-- M Hoxey 02/12/2009 Added p_custom_message parameter to
-- log_last_err
-- M Hoxey 09/12/2009 Added the NULLIF function to log_last_err_msg
--------------------------------------------------------------------------------
--------------------------------------------------------------------------------
-- Function : full_err_msg
--
-- Description : Returns the full error message stack
--------------------------------------------------------------------------------
FUNCTION full_err_msg
RETURN pkg_log.t_log_msg
AS
BEGIN
RETURN dbms_utility.format_error_stack ||
pkg_gen_const.c_new_line ||
dbms_utility.format_error_backtrace;
END full_err_msg;
--------------------------------------------------------------------------------
-- Procedure : log_last_err
--
-- Description : Logs the last error details
--------------------------------------------------------------------------------
PROCEDURE log_last_err (p_custom_message IN pkg_db_type.t_big_string DEFAULT NULL)
AS
BEGIN
pkg_log.err (NULLIF(p_custom_message || pkg_gen_const.c_new_line, pkg_gen_const.c_new_line) ||
full_err_msg(),SQLCODE);
END log_last_err;
END pkg_err;
/
You’ll note the dependencies to the pkg_db_type package described in a previous post. With the pkg_err package deployed any time I want to log an exception I can simply include the following in my code:
EXCEPTION
WHEN OTHERS THEN
pkg_err.log_last_error;
RAISE;
My logging package will log the error message using an autonomous transaction so I’m free to rollback or do whatever other action I may like to do inside the exception handler. You will need to replace the call to pkg_log.err with whatever logging routine you use.
Let’s look at an example of how we would use these routines. The following code consists of an anonymous with 3 local procedures; proc_a, proc_b and proc_c (hey, I work with database systems so don’t expect imaginative names!). Proc_a, calls proc_b, which in turn calls proc_c. Initially we have no exception handling:
DECLARE
PROCEDURE proc_c
AS
BEGIN
dbms_output.put_line ('Start of proc_c');
RAISE NO_DATA_FOUND;
dbms_output.put_line ('Start of proc_c');
END proc_c;
PROCEDURE proc_b
AS
BEGIN
dbms_output.put_line ('Start of proc_b');
proc_c;
dbms_output.put_line ('End of proc_b');
END proc_b;
PROCEDURE proc_a
AS
BEGIN
dbms_output.put_line ('Start of proc_a');
proc_b;
dbms_output.put_line ('End of proc_a');
END proc_a;
BEGIN
dbms_output.put_line ('Start of test');
proc_a;
dbms_output.put_line ('End of test');
END;
/
The execution of this code gives us:
Start of test Start of proc_a Start of proc_b Start of proc_c DECLARE * ERROR at line 1: ORA-01403: no data found ORA-06512: at line 6 ORA-06512: at line 13 ORA-06512: at line 20 ORA-06512: at line 25
All appears as we want; we can see the error and the line in the code where it originated. Now, let’s put an exception handler in proc_a. Inside the exception handler we’ll simply report the error and re-raise it:
DECLARE
PROCEDURE proc_c
AS
BEGIN
dbms_output.put_line ('Start of proc_c');
RAISE NO_DATA_FOUND;
dbms_output.put_line ('Start of proc_c');
END proc_c;
PROCEDURE proc_b
AS
BEGIN
dbms_output.put_line ('Start of proc_b');
proc_c;
dbms_output.put_line ('End of proc_b');
END proc_b;
PROCEDURE proc_a
AS
BEGIN
dbms_output.put_line ('Start of proc_a');
proc_b;
dbms_output.put_line ('End of proc_a');
EXCEPTION
WHEN OTHERS THEN
dbms_output.put_line (SQLERRM);
dbms_output.put_line ('-------------');
RAISE;
END proc_a;
BEGIN
dbms_output.put_line ('Start of test');
proc_a;
dbms_output.put_line ('End of test');
END;
/
The output we get is:
Start of test Start of proc_a Start of proc_b Start of proc_c ORA-01403: no data foun ------------- DECLARE * ERROR at line 1: ORA-01403: no data foun ORA-06512: at line 26 ORA-06512: at line 30
Hmmm… while we can still see the type of exception we have lost the details as to where it originated. We know that the proc_a exception handler caught it but that’s as specific as we can get. Let’s try again and this time use a combination of dbms_utility.format_error_stack and dbms_utility.format_error_backtrace.
DECLARE
PROCEDURE proc_c
AS
BEGIN
dbms_output.put_line ('Start of proc_c');
RAISE NO_DATA_FOUND;
dbms_output.put_line ('Start of proc_c');
END proc_c;
PROCEDURE proc_b
AS
BEGIN
dbms_output.put_line ('Start of proc_b');
proc_c;
dbms_output.put_line ('End of proc_b');
END proc_b;
PROCEDURE proc_a
AS
BEGIN
dbms_output.put_line ('Start of proc_a');
proc_b;
dbms_output.put_line ('End of proc_a');
EXCEPTION
WHEN OTHERS THEN
dbms_output.put_line (dbms_utility.format_error_stack);
dbms_output.put_line ('-------------');
dbms_output.put_line (dbms_utility.format_error_backtrace);
dbms_output.put_line ('-------------');
RAISE;
END proc_a;
BEGIN
dbms_output.put_line ('Start of test');
proc_a;
dbms_output.put_line ('End of test');
END;
/
The output we get is:
Start of test Start of proc_a Start of proc_b Start of proc_c ORA-01403: no data found ------------- ORA-06512: at line 6 ORA-06512: at line 13 ORA-06512: at line 20 ------------- DECLARE * ERROR at line 1: ORA-01403: no data found ORA-06512: at line 28 ORA-06512: at line 32
Ah, so now we’ve got the full error message, thanks to dbms_utility.format_error_stack, and the location of where it originated, thanks to dbms_utility.format_error_backtrace. This is exactly what the routine pkg_err.full_err_msg does. Note, dbms_utility.format_error_backtrace was introduced in Oracle 10g. Prior to this version, trapping exceptions and working out exactly where they originated was rather hard.
Once we’ve intercepted an exception we will often want to log it to our standard logging facility. This is the purpose of the other routine in pkg_err, log_last_err. As an option, the routine will accept a string that will prefix the standard Oracle error message. The idea behind this to provide some scenario specifc information that may help interpretation of the error at a later stage. For example, lets say I do a SELECT…INTO looking for details on a specific widget as shown below:
BEGIN
SELECT ...
INTO ...
FROM widgets w
WHERE w.widget_id = l_widget_id;
EXCEPTION
WHEN NO_DATA_FOUND THEN
pkg_err.log_last_err ('Cannot locate widget with ID of ' || l_widget_id);
RAISE;
END;
Then my logged exception not only tells me what exception was thrown and where it occurred but also specifically the widget ID that the code was looking for. All this makes for speedy problem resolution.
Once we’ve trapped the exception and logged it then we can do whatever we want; continue as if nothing has happened, re-raise the exception (as shown above) or throw some other sort of exception. I plan on discussing the latter strategy in a future post.
Download scripts shown in this post.
Mark Hoxey 