Consistent error logging greatly simplifies PL/SQL debugging

참고 : http://blogs.techrepublic.com.com/programming-and-development/?p=400

I’ve been working with Oracle databases for a little over a year now, and the part I really
like best is PL/SQL. That’s their database programming language that lets you combine
procedural code with SQL code. What I like most is that it lets you build your entire app
in one place ? all the data selects and updates, all the HTTP and HTML output
interacting with LDAP, everything can be done in one place with the one language.

But the downside of that is really complex applications. Since a particular procedure or
function in your PL/SQL code might be doing any of those many tasks, when things
break it can be really difficult to debug the problem. Was it a database problem, was
there an HTTP issue with LDAP, just where was the problem? I like including a simple
error logging mechanism in any PL/SQL project, so that when things break, I have a simple
table I can look at to trace all the errors.

I start by building the logging table itself:

CREATE TABLE ERRORLOG
(
  ID              NUMBER               NOT NULL,
  TIME            DATE                 NOT NULL,
  CODE            VARCHAR2(9 BYTE)     NOT NULL,
  MESSAGE         VARCHAR2(2000 BYTE)  NOT NULL,
  PACKAGE_NAME    VARCHAR2(100 BYTE),
  PROCEDURE_NAME  VARCHAR2(100 BYTE)   NOT NULL,
  LOCATION        NUMBER,
  PARAMETERS      VARCHAR2(4000 BYTE)
);

Unlike most other databases, in Oracle you don’t get a built-in auto-increment field to
use for the ID. Instead, you have to create a sequence and then include some mechanism
for including the sequence numbers whenever a new value is inserted. Here’s the sequence:

CREATE SEQUENCE ERRORLOG_ID_SEQ
  MINVALUE 1
  MAXVALUE 999999999999999999999999999
  INCREMENT BY 1
  START WITH 1
  CACHE 20
  NOORDER
  NOCYCLE ;
 
I could use the trigger to insert the timestamp, but I’ll do that later in the package that
provides the logging interface. This trigger just handles incrementing the ID field with the
sequence we created above:

CREATE OR REPLACE TRIGGER T_ERRORLOG_BI
BEFORE INSERT
ON ERRORLOG
REFERENCING OLD AS OLD NEW AS NEW
FOR EACH ROW
begin
  if :new.id is null then
    select errorlog_id_seq.nextval
      into :new.id
      from dual;
  end if;
end t_errorlog_bi;

It’s always a good practice to provide a primary key. I know I could have done that when creating
the table itself, but I just like the formality of doing it separately. I don’t know why ?
it just feels more explicit that way:

ALTER TABLE ERRORLOG ADD (PRIMARY KEY (ID));

PL/SQL is based on the old Ada programming language, so when you create a package, you have to
provide a spec (the interface) and a body (the actual implementation of the interface).
For my simple error logging package, the spec exposes just a single procedure:

CREATE OR REPLACE package pkg_error is 

  procedure log (p_error_code errorlog.code%type,
                 p_error_message errorlog.message%type,
                 p_package errorlog.package_name%type default null,
                 p_procedure errorlog.procedure_name%type,
                 p_location errorlog.location%type default null,
                 p_parameters errorlog.parameters%type default null); 

end pkg_error;

In the body, you can have as many procedures and functions as you like. At the very least, it must
implement whatever’s in the spec. In this case, my package body only implements the one procedure
exposed in the spec:

CREATE OR REPLACE package body pkg_error is 

  procedure log (p_error_code errorlog.code%type,
                 p_error_message errorlog.message%type,
                 p_package errorlog.package_name%type default null,
                 p_procedure errorlog.procedure_name%type,
                 p_location errorlog.location%type default null,
                 p_parameters errorlog.parameters%type default null) is 

  pragma autonomous_transaction; 

   begin 

    insert
      into errorlog
           (time,
            code,
            message,
            package_name,
            procedure_name,
            location,
            parameters)
    values (sysdate,
            p_error_code,
            p_error_message,
            p_package,
            p_procedure,
            p_location,
            p_parameters);
    commit;
  end log; 

end pkg_error;

The pragma autonomous_transaction part is very important because you want the log method to be
able to commit the log data into the table, without also committing whatever changes have gone
on in the procedure that raised this error. That’s what this particular pragma does ? it tells
Oracle to treat this procedure as an atomic action that does not affect anything earlier in the call stack.

The last bit is of course incorporating this logging into your code. For example, say you’ve got
a simple little function, and whenever there’s an exception, you want to log that but not re-raise
the error. In other words, record but then let the app continue running. You might do something like this:

CREATE OR REPLACE FUNCTION hello_world RETURN VARCHAR2 IS
  v_procedure errorlog.procedure_name%TYPE default 'hello_world';
  v_location errorlog.location%TYPE;
BEGIN 

  v_location := 1000;
  return ('hello, world'); 

EXCEPTION 

  when others then
    pkg_error.log(p_error_code => substr(sqlerrm,1,9),
    p_error_message => substr(sqlerrm,12),
    p_package => 'FUNCTION',
    p_procedure => v_procedure,
    p_location => v_location); 

END;

Obviously, if this was inside a package, you’d create a package-level variable with the actual name
of your package and pass that to the p_package parameter instead of the string constant I used here.

That’s pretty much it. I’m not going to claim this is the best way to log errors in PL/SQL.
I’ve only been working in this thing a bit over a year, so I’m not an expert by any means.
But this kind of logging has made debugging my applications so much easier.
If something fails, I now have a record from all the procedures and functions that had problems,
so I can quickly track down the root cause.