Oracle DML (and other) Logging

During my last migration project I have used the following technique to keep logs of the progress of migration as well as keep track of failed records. The whole idea was based on this article. I have extended somehow the idea to use the DML log table for general purpose logging as well. These were the steps: 1. Created the DML logging table:

CREATE TABLE MIG_LOG (
   ORA_ERR_NUMBER$ NUMBER,
   ORA_ERR_MESG$ VARCHAR2(2000 BYTE),
   ORA_ERR_ROWID$ ROWID,
   ORA_ERR_OPTYP$ VARCHAR2(2 BYTE),
   ORA_ERR_TAG$ VARCHAR2(4000 BYTE),
   LOG_ID NUMBER,
   RUN_ID NUMBER,
   LOG_DT TIMESTAMP(6),
   LOG_LVL NUMBER(1) );

The fields UP TO ORA_ERR_TAG$ are required (in this order) by the native Oracle DML logging implementation. The fields AFTER ORA_ERR_TAG$ were added in order to keep additional information. 2. Created a table to hold runs of data loading batches:

CREATE TABLE MIG_RUN (
   RUN_ID NUMBER(20),
   RUN_AREA VARCHAR2(32 BYTE),
   START_TM TIMESTAMP(6),
   END_TM TIMESTAMP(6),
   RUN_INFO VARCHAR2(256 BYTE) );

CREATE UNIQUE INDEX PK_MIG_RUN ON MIG_RUN(RUN_ID);

ALTER TABLE MIG_RUN ADD (
   CONSTRAINT PK_MIG_RUN
   PRIMARY KEY (RUN_ID) USING INDEX);

3. Created two sequences for the log_id and run_id fields. 4. Created a package to implement logging (let's name it pkg_mig_utils - more details after a few paragraphs). 5. Created a context to keep the current RUN_ID.

CREATE OR REPLACE CONTEXT MIG_CTX USING PKG_MIG_UTILS;

6. Created the code to

• Start and stop logging
• Log info or errors (other than those produced by DML statements)

7. Added this trigger on the mig_log table to obtain values for the log_id, run_id, log_dt fields

CREATE OR REPLACE TRIGGER TRG_MIG_LOG_BI
BEFORE INSERT
ON MIG_LOG
REFERENCING NEW AS New OLD AS Old
FOR EACH ROW
DECLARE
BEGIN
  IF :NEW.run_id IS NULL THEN
      :NEW.run_id := SYS_CONTEXT ('mig_ctx', 'current_run_id');
  END IF;

  IF :NEW.log_id IS NULL THEN
      select log_id_seq.nextval
      into :NEW.log_id
      from dual;
  END IF;

  IF :new.log_lvl is null THEN
      :new.log_lvl := 3;
  END IF;

  :NEW.log_dt := SYSTIMESTAMP;

END;
/

This is some code from the package mentioned above:

CREATE OR REPLACE PACKAGE pkg_mig_utils AS
c_log_lvl_info CONSTANT PLS_INTEGER := 1;
c_log_lvl_warn CONSTANT PLS_INTEGER := 2;
c_log_lvl_error CONSTANT PLS_INTEGER := 3;

-- General funcs/procs

PROCEDURE start_log (v_area VARCHAR2, v_run_info VARCHAR2);
PROCEDURE end_log;
PROCEDURE log_msg (v_app_txt VARCHAR2, v_ora_txt VARCHAR2, v_log_lvl NUMBER DEFAULT 3);
PROCEDURE log_info (v_app_txt VARCHAR2);
END;
/

CREATE OR REPLACE PACKAGE BODY pkg_mig_utils AS

...............

PROCEDURE start_log (v_area VARCHAR2, v_run_info VARCHAR2) AS
PRAGMA AUTONOMOUS_TRANSACTION;
new_run_id mig_run.run_id%TYPE;
BEGIN
INSERT INTO mig_run(run_id, run_area, start_tm, run_info)
VALUES (mig_run_id_seq.NEXTVAL, v_area, SYSTIMESTAMP, v_run_info)
RETURNING run_id INTO new_run_id;

DBMS_SESSION.set_context ('mig_ctx', 'current_run_id', new_run_id);

COMMIT;
END;

PROCEDURE end_log AS
PRAGMA AUTONOMOUS_TRANSACTION;
BEGIN
UPDATE mig_run
SET end_tm = SYSTIMESTAMP
WHERE run_id = SYS_CONTEXT ('mig_ctx', 'current_run_id');

COMMIT;
END;

--
PROCEDURE log_info (v_app_txt VARCHAR2) AS
PRAGMA AUTONOMOUS_TRANSACTION;
BEGIN
INSERT INTO mig_log(ora_err_tag$, log_lvl)
VALUES (v_app_txt, 1);

COMMIT;
END;

PROCEDURE log_msg (v_app_txt VARCHAR2, v_ora_txt VARCHAR2, v_log_lvl NUMBER DEFAULT 3) AS
PRAGMA AUTONOMOUS_TRANSACTION;
BEGIN
INSERT INTO mig_log(ora_err_tag$, ora_err_mesg$, log_lvl)
VALUES (v_app_txt, v_ora_txt, v_log_lvl);

COMMIT;
END;

END;
/

Notes on the code above: 1. Procedure start_log :

• Gets a new run_id from the corresponding sequence
• Inserts a record for the run in the mig_run table
• Puts the current run_id in the session context so that the trigger can use it to update the corresponding fields in the mig_log table.

2. Procedure end_log just updates the end time of the run. Now that the necessary pieces are in place, let's use it in actual migration code: These were some of the requirements for this code: 1. In my case I was loading data per calendar year. So I wanted to keep this info (associate runs with years). 2. The same code had to be used for multiple cases. Therefore I had to use DYNAMIC SQL to perform the necessary INSERTS. 3. Since we had to migrate millions of rows, we had to use BULK operations (BULK COLLECT and FORALL statements). However, we did not want the whole process to be interrupted when a single record failed. In summary, the whole procedure was implemented like in the following SAMPLE package. The main procedure start_mig.

CREATE OR REPLACE PACKAGE BODY pkg_mig_exec AS
-- Error handling aids;
sentence                     VARCHAR2 (4000);
max_ora_message_length       NUMBER          := 512;

g_app_error_code             PLS_INTEGER     := -20002;
app_error_detected           EXCEPTION;
PRAGMA EXCEPTION_INIT (app_error_detected, -20002);
                                                                 --
TYPE ntable IS TABLE OF NUMBER;

TYPE oranametable IS TABLE OF VARCHAR2 (32);

TYPE sqltable IS TABLE OF VARCHAR2 (4000)
INDEX BY VARCHAR2 (30);

-- A map to hold dynamic sql statements   
area_sql_table               sqltable;

PROCEDURE mig_rows (ids ntable, v_tbls oranametable, v_id_fld VARCHAR2 DEFAULT 'ID') AS
PRAGMA AUTONOMOUS_TRANSACTION;
ins_stmnt    VARCHAR2 (4000);
tot_errors   PLS_INTEGER;
BEGIN
FOR j IN 1 .. v_tbls.COUNT () LOOP

   pkg_mig_utils.LOG_INFO('Inserting into table ' || v_tbls (j));
   ins_stmnt := area_sql_table (v_tbls (j)) || ' where ' || v_id_fld || ' = :b1';
   ins_stmnt := ins_stmnt || ' LOG ERRORS INTO MIG_LOG (''' || v_id_fld || '= ''|| :b1 ) REJECT LIMIT UNLIMITED';

   FORALL i IN 1 .. ids.COUNT
      EXECUTE IMMEDIATE ins_stmnt
      USING             ids (i), ids (i);

END LOOP;

COMMIT;

END;

PROCEDURE mig_data (
v_src_tbl_nm   VARCHAR2,
v_tbls         oranametable,
v_id_fld       VARCHAR2 DEFAULT 'ID'
) AS
ids               ntable;

TYPE idcurtyp IS REF CURSOR;

c_ids             idcurtyp;
id_stmnt          VARCHAR2 (128) := 'SELECT ' || v_id_fld || ' FROM ' || v_src_tbl_nm;
tot_rows_so_far   PLS_INTEGER    := 0;
BEGIN

id_stmnt := id_stmnt || ' ORDER BY ' || v_id_fld;
sentence := 'Failed to open cursor for ids of part key: ' || v_part_key;

OPEN c_ids FOR id_stmnt;

LOOP
   sentence := 'Failed to get ids for part key: ' || v_part_key;

   FETCH c_ids
   BULK COLLECT INTO ids LIMIT 100;

   EXIT WHEN ids.COUNT = 0;

   sentence := 'Failed to migrate rows from table ' || v_src_tbl_nm;
   mig_rows (ids, v_tbls, v_id_fld);
   EXIT WHEN c_ids%NOTFOUND;
END LOOP;

CLOSE c_ids;

COMMIT;

pkg_mig_utils.log_info ('Completed migration from table ' || v_src_tbl_nm);
EXCEPTION
WHEN OTHERS THEN
   pkg_mig_utils.log_msg (sentence, SUBSTR (SQLERRM, 1, max_ora_message_length));
   raise_application_error (g_app_error_code, sentence || '-' || SUBSTR (SQLERRM, 1, max_ora_message_length));
END;

/*
    Sample procedure to init migration using dynamic statements

    In this example all data come from a single source table where all
    legacy (COBOL) data have been aggregated into a single table
*/
PROCEDURE start_mig(v_year varchar2) AS
my_tbls          oranametable    := NEW oranametable ('TABLE1', 'TABLE2');

tot_rows         NUMBER;
tot_rows_stmnt   VARCHAR2 (256);
copy_stmnt       VARCHAR2 (4000);
BEGIN
pkg_mig_utils.start_log ('MY_MIG_AREA', v_year);
pkg_mig_utils.log_info ('Starting migration ....');

-- Sample dynamic insert statements

area_sql_table('TABLE1') := 'INSERT INTO TABLE1 SELECT * FROM SRC_TABLE WHERE MIG_YEAR = ' || v_year;
area_sql_table('TABLE2') := 'INSERT INTO TABLE2 SELECT * FROM SRC_TABLE WHERE MIG_YEAR = ' || v_year;

-- Perform migration for all tables

mig_data ('SRC_TABLE', my_tbls);

pkg_mig_utils.log_info ('Completed migration ...');
pkg_mig_utils.end_log;
END;

END;
/