A simple, essential part of PL/SQL coding and debugging is logging. However, it seems to be one of the most overlooked parts of coding.  Below is a simple package body (the package is left out for brevity) and the DDL needed for it:

CREATE TABLE log_entry (
   log_entry_id      NUMBER (10),
   run_number        NUMBER,
   process_name      VARCHAR2 (50),
   description       VARCHAR2 (400),
   expected_result   VARCHAR2 (1),
   depth_level       NUMBER,
   log_date          DATE,
   time_entry        NUMBER,
   CONSTRAINT transform_log_pk 
      PRIMARY KEY (log_entry_id)
);

CREATE SEQUENCE seq_log_entry_pk
   START WITH 1;

CREATE OR REPLACE PACKAGE BODY log_entry_pkg
IS
   PROCEDURE insert_log_entry (p_run_number        IN NUMBER,
                               p_process_name      IN VARCHAR2,
                               p_description       IN VARCHAR2,
                               p_expected_result   IN VARCHAR2,
                               p_depth_level       IN NUMBER)
   IS
      PRAGMA AUTONOMOUS_TRANSACTION;
   BEGIN
      INSERT INTO log_entry (log_entry_id,
                             run_number,
                             process_name,
                             description,
                             expected_result,
                             depth_level,
                             log_date,
                             time_entry)
        VALUES   (seq_log_entry_pk.NEXTVAL,
                  p_run_number,
                  p_process_name,
                  p_description,
                  p_expected_result,
                  p_depth_level,
                  SYSDATE,
                  DBMS_UTILITY.get_time ());

      COMMIT;
   END insert_log_entry;

   PROCEDURE show_run_results (p_run_number     IN NUMBER,
                               p_process_name   IN VARCHAR2)
   IS
   BEGIN
      show_run_results (p_run_number,
                        p_process_name,
                        NULL,
                        NULL);
   END show_run_results;

   PROCEDURE show_run_results (p_run_number          IN NUMBER,
                               p_process_name        IN VARCHAR2,
                               p_start_description   IN VARCHAR2,
                               p_end_description     IN VARCHAR2)
   IS
      TYPE timing_rec IS RECORD
      (
         description   log_entry.description%TYPE,
         time_entry    log_entry.time_entry%TYPE
      );

      TYPE timing_tab IS TABLE OF timing_rec
                            INDEX BY BINARY_INTEGER;

      v_timing_tab   timing_tab;

      v_depth        NUMBER := 0;
   BEGIN
      FOR i
      IN (SELECT   *
            FROM   log_entry
           WHERE   run_number = p_run_number
                   AND process_name LIKE '%' || p_process_name || '%'
                   AND log_entry_id >=
                         (SELECT   NVL (MIN (log_entry_id), 0)
                            FROM   log_entry
                           WHERE   run_number = p_run_number
                                   AND process_name LIKE
                                         '%' || p_process_name || '%'
                                   AND description LIKE
                                         '%'
                                         || NVL2 (p_end_description,
                                                  p_start_description,
                                                  NULL)
                                         || '%')
                   AND log_entry_id <=
                         (SELECT   NVL (MAX (log_entry_id), 10E30)
                            FROM   log_entry
                           WHERE   run_number = p_run_number
                                   AND process_name LIKE
                                         '%' || p_process_name || '%'
                                   AND description LIKE
                                         '%'
                                         || NVL2 (p_end_description,
                                                  p_start_description,
                                                  NULL)
                                         || '%'))
      LOOP
         IF v_depth = i.depth_level
         THEN
            DBMS_OUTPUT.put_line(   LPAD (' ', 4 * (i.depth_level - 1))
                                 || v_timing_tab (i.depth_level).description
                                 || ' - '
                                 || i.description
                                 || ': '
                                 || TRUNC (
                                       (i.time_entry
                                        - v_timing_tab (
                                             i.depth_level
                                          ).time_entry)
                                       / 100
                                       / 60,
                                       3
                                    ));

            v_timing_tab (i.depth_level).time_entry := i.time_entry;
            v_timing_tab (i.depth_level).description := i.description;
         ELSE
            IF v_depth < i.depth_level
            THEN
               v_timing_tab (i.depth_level).time_entry := i.time_entry;
               v_timing_tab (i.depth_level).description := i.description;
            ELSE
               DBMS_OUTPUT.put_line(LPAD (' ', 4 * (i.depth_level - 1))
                                    || v_timing_tab (
                                          i.depth_level
                                       ).description
                                    || ' - '
                                    || i.description
                                    || ': '
                                    || TRUNC (
                                          (i.time_entry
                                           - v_timing_tab (
                                                i.depth_level
                                             ).time_entry)
                                          / 100
                                          / 60,
                                          3
                                       ));
            END IF;

            v_depth := i.depth_level;
         END IF;
      END LOOP;
   END show_run_results;
END log_entry_pkg;
/

One of the most important things to note is the first line in the insert_log_entry procedure that has PRAGMA AUTONOMOUS_TRANSACTION.  That line creates a new session for the logging work and allows the procedure to commit without committing the rest of the calling PL/SQL.  If the calling SQL fails immediately after the insert_log_entry call and rollback, the logging entry will exist and the calling PL/SQL will rollback as expected.  The show_run_results procedures simply display the output of a logging run in a nice format.

Comment