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.