Debugging PL/SQL with DBMS_OUTPUT, Exceptions & SQL Developer

-- Step 1: Enable DBMS_OUTPUT in the client
-- SQL*Plus:
SET SERVEROUTPUT ON SIZE UNLIMITED

-- SQL Developer: View > DBMS Output > click green (+) > select connection

-- Step 2: Basic debugging with DBMS_OUTPUT
CREATE OR REPLACE PROCEDURE app_schema.test_procedure IS
  v_count NUMBER;
  v_name  VARCHAR2(100);
BEGIN
  DBMS_OUTPUT.PUT_LINE('=== test_procedure started ===');
  DBMS_OUTPUT.PUT_LINE('Timestamp: ' || TO_CHAR(SYSTIMESTAMP, 'YYYY-MM-DD HH24:MI:SS.FF3'));

  SELECT COUNT(*) INTO v_count
  FROM data_owner.accounts
  WHERE status = 'ACTIVE';
  DBMS_OUTPUT.PUT_LINE('Active accounts: ' || v_count);

  SELECT customer_name INTO v_name
  FROM data_owner.customers
  WHERE customer_id = 1001;
  DBMS_OUTPUT.PUT_LINE('Customer name: ' || v_name);

  DBMS_OUTPUT.PUT_LINE('=== test_procedure completed ===');
EXCEPTION
  WHEN OTHERS THEN
    DBMS_OUTPUT.PUT_LINE('ERROR: ' || SQLERRM);
    DBMS_OUTPUT.PUT_LINE('Backtrace: ' || DBMS_UTILITY.FORMAT_ERROR_BACKTRACE);
    RAISE;
END test_procedure;
/

-- Step 3: Conditional debug output (avoids production overhead)
CREATE OR REPLACE PACKAGE app_schema.debug_pkg AS
  -- Session-level flag: FALSE in production, TRUE during debugging
  g_debug_enabled BOOLEAN := FALSE;

  PROCEDURE enable_debug;
  PROCEDURE disable_debug;
  PROCEDURE log(p_message IN VARCHAR2);
  PROCEDURE log(p_label IN VARCHAR2, p_value IN VARCHAR2);
  PROCEDURE log(p_label IN VARCHAR2, p_value IN NUMBER);
  PROCEDURE log(p_label IN VARCHAR2, p_value IN DATE);
END debug_pkg;
/

CREATE OR REPLACE PACKAGE BODY app_schema.debug_pkg AS

  PROCEDURE enable_debug IS
  BEGIN
    g_debug_enabled := TRUE;
    DBMS_OUTPUT.ENABLE(buffer_size => NULL);  -- Unlimited buffer
  END enable_debug;

  PROCEDURE disable_debug IS
  BEGIN
    g_debug_enabled := FALSE;
  END disable_debug;

  PROCEDURE log(p_message IN VARCHAR2) IS
  BEGIN
    IF g_debug_enabled THEN
      DBMS_OUTPUT.PUT_LINE(
        TO_CHAR(SYSTIMESTAMP, 'HH24:MI:SS.FF3') || ' | ' || p_message
      );
    END IF;
  END log;

  PROCEDURE log(p_label IN VARCHAR2, p_value IN VARCHAR2) IS
  BEGIN
    IF g_debug_enabled THEN
      DBMS_OUTPUT.PUT_LINE(
        TO_CHAR(SYSTIMESTAMP, 'HH24:MI:SS.FF3')
        || ' | ' || p_label || ' = ' || NVL(p_value, '<NULL>')
      );
    END IF;
  END log;

  PROCEDURE log(p_label IN VARCHAR2, p_value IN NUMBER) IS
  BEGIN
    log(p_label, TO_CHAR(p_value));
  END log;

  PROCEDURE log(p_label IN VARCHAR2, p_value IN DATE) IS
  BEGIN
    log(p_label, TO_CHAR(p_value, 'YYYY-MM-DD HH24:MI:SS'));
  END log;

END debug_pkg;
/

-- Usage: enable debug for a session, run the procedure, disable
BEGIN
  app_schema.debug_pkg.enable_debug;
  app_schema.test_procedure;
  app_schema.debug_pkg.disable_debug;
END;
/

-- Step 1: Grant debug privileges to the debugging user
-- Run as SYS or a DBA user
GRANT DEBUG CONNECT SESSION TO app_user;
GRANT DEBUG ANY PROCEDURE TO app_user;

-- Step 2: Compile the package body with debug symbols
ALTER PACKAGE app_schema.billing_pkg COMPILE DEBUG BODY;
-- Note: COMPILE DEBUG BODY compiles only the body with debug info
-- Use COMPILE DEBUG to compile both spec and body

-- Step 3: Verify the package is VALID after debug compilation
SELECT
  object_name,
  object_type,
  status,
  last_ddl_time
FROM user_objects
WHERE object_name = 'BILLING_PKG'
ORDER BY object_type;
-- Both PACKAGE and PACKAGE BODY should show VALID

-- Step 4: Verify debug info is present (Oracle 12c+)
SELECT
  owner,
  name,
  type,
  plsql_debug
FROM all_plsql_object_settings
WHERE name = 'BILLING_PKG'
  AND owner = 'APP_SCHEMA';
-- plsql_debug = TRUE indicates debug symbols are present

-- Step 5: SQL Developer debugger workflow
-- 1. Open the package body in SQL Developer's editor
-- 2. Click in the line number gutter to set a breakpoint (red dot appears)
-- 3. Right-click the procedure name and select "Debug" (or Ctrl+Shift+F10)
-- 4. Enter parameter values in the Debug PL/SQL dialog
-- 5. Click OK — execution starts and pauses at the first breakpoint
-- 6. Navigation controls:
--    Step Into  (F7) : enter the called procedure
--    Step Over  (F8) : execute the line without entering sub-calls
--    Step Out   (F9) : finish the current procedure and return to caller
--    Run to Cursor   : execute until the cursor position
--    Resume    (F9)  : continue to the next breakpoint
--    Terminate (Ctrl+F2) : stop debugging immediately
-- 7. Inspect variables in the Smart Data panel (auto-populated)
-- 8. Add watch expressions in the Watches panel for computed values
-- 9. View the call stack in the Stack panel to see the calling chain

-- Step 6: Recompile WITHOUT debug symbols after debugging
ALTER PACKAGE app_schema.billing_pkg COMPILE BODY;
-- Production code should never carry debug symbols

-- Step 7: Verify debug info is removed
SELECT
  owner,
  name,
  type,
  plsql_debug
FROM all_plsql_object_settings
WHERE name = 'BILLING_PKG'
  AND owner = 'APP_SCHEMA';
-- plsql_debug should now be FALSE

-- Logging table
CREATE TABLE app_schema.app_log (
  log_id        NUMBER         GENERATED ALWAYS AS IDENTITY PRIMARY KEY,
  log_level     VARCHAR2(10)   NOT NULL,
  module        VARCHAR2(128)  NOT NULL,
  message       VARCHAR2(4000),
  error_stack   VARCHAR2(4000),
  session_id    NUMBER         DEFAULT SYS_CONTEXT('USERENV', 'SESSIONID'),
  db_user       VARCHAR2(128)  DEFAULT SYS_CONTEXT('USERENV', 'SESSION_USER'),
  os_user       VARCHAR2(128)  DEFAULT SYS_CONTEXT('USERENV', 'OS_USER'),
  created_at    TIMESTAMP      DEFAULT SYSTIMESTAMP
) TABLESPACE app_data;

CREATE INDEX idx_app_log_module  ON app_schema.app_log(module, created_at);
CREATE INDEX idx_app_log_level   ON app_schema.app_log(log_level, created_at);
CREATE INDEX idx_app_log_created ON app_schema.app_log(created_at);

-- Partition by day for easy cleanup (Oracle 12c+)
-- ALTER TABLE app_schema.app_log MODIFY PARTITION BY RANGE (created_at)
--   INTERVAL (NUMTODSINTERVAL(1, 'DAY'))
--   (PARTITION p_initial VALUES LESS THAN (TIMESTAMP '2026-01-01 00:00:00'));

-- Logging package
CREATE OR REPLACE PACKAGE app_schema.logger_pkg AS
  -- Log level constants
  c_debug CONSTANT VARCHAR2(10) := 'DEBUG';
  c_info  CONSTANT VARCHAR2(10) := 'INFO';
  c_warn  CONSTANT VARCHAR2(10) := 'WARN';
  c_error CONSTANT VARCHAR2(10) := 'ERROR';

  -- Convenience procedures
  PROCEDURE debug(p_module IN VARCHAR2, p_message IN VARCHAR2);
  PROCEDURE info (p_module IN VARCHAR2, p_message IN VARCHAR2);
  PROCEDURE warn (p_module IN VARCHAR2, p_message IN VARCHAR2);
  PROCEDURE error(p_module IN VARCHAR2, p_message IN VARCHAR2);
  PROCEDURE error(p_module IN VARCHAR2, p_message IN VARCHAR2, p_error_stack IN VARCHAR2);

  -- Runtime log level control (per session)
  PROCEDURE set_level(p_level IN VARCHAR2);
  FUNCTION  get_level RETURN VARCHAR2;
END logger_pkg;
/

CREATE OR REPLACE PACKAGE BODY app_schema.logger_pkg AS

  -- Session-level minimum log level — WARN by default in production
  g_min_level VARCHAR2(10) := c_warn;

  FUNCTION level_priority(p_level IN VARCHAR2) RETURN NUMBER IS
  BEGIN
    RETURN CASE UPPER(p_level)
      WHEN 'DEBUG' THEN 10
      WHEN 'INFO'  THEN 20
      WHEN 'WARN'  THEN 30
      WHEN 'ERROR' THEN 40
      ELSE 0
    END;
  END level_priority;

  -- Core writer — autonomous transaction, self-protecting
  PROCEDURE write_log(
    p_level       IN VARCHAR2,
    p_module      IN VARCHAR2,
    p_message     IN VARCHAR2,
    p_error_stack IN VARCHAR2 DEFAULT NULL
  ) IS
    PRAGMA AUTONOMOUS_TRANSACTION;
  BEGIN
    -- Skip if below session threshold
    IF level_priority(p_level) < level_priority(g_min_level) THEN
      RETURN;
    END IF;

    INSERT INTO app_schema.app_log (
      log_level, module, message, error_stack
    ) VALUES (
      p_level,
      SUBSTR(p_module, 1, 128),
      SUBSTR(p_message, 1, 4000),
      SUBSTR(p_error_stack, 1, 4000)
    );
    COMMIT;
  EXCEPTION
    WHEN OTHERS THEN
      -- Logging must NEVER crash the caller
      ROLLBACK;
  END write_log;

  PROCEDURE debug(p_module IN VARCHAR2, p_message IN VARCHAR2) IS
  BEGIN write_log(c_debug, p_module, p_message); END;

  PROCEDURE info(p_module IN VARCHAR2, p_message IN VARCHAR2) IS
  BEGIN write_log(c_info, p_module, p_message); END;

  PROCEDURE warn(p_module IN VARCHAR2, p_message IN VARCHAR2) IS
  BEGIN write_log(c_warn, p_module, p_message); END;

  PROCEDURE error(p_module IN VARCHAR2, p_message IN VARCHAR2) IS
  BEGIN write_log(c_error, p_module, p_message); END;

  PROCEDURE error(p_module IN VARCHAR2, p_message IN VARCHAR2, p_error_stack IN VARCHAR2) IS
  BEGIN write_log(c_error, p_module, p_message, p_error_stack); END;

  PROCEDURE set_level(p_level IN VARCHAR2) IS
  BEGIN
    g_min_level := UPPER(p_level);
  END set_level;

  FUNCTION get_level RETURN VARCHAR2 IS
  BEGIN
    RETURN g_min_level;
  END get_level;

END logger_pkg;
/

-- Usage in application code
CREATE OR REPLACE PROCEDURE app_schema.process_batch(
  p_batch_id IN NUMBER
) IS
  v_count NUMBER;
BEGIN
  app_schema.logger_pkg.info('process_batch', 'Starting batch ' || p_batch_id);

  SELECT COUNT(*) INTO v_count
  FROM data_owner.orders
  WHERE batch_id = p_batch_id AND status = 'PENDING';

  app_schema.logger_pkg.debug('process_batch', 'Pending orders: ' || v_count);

  -- ... batch processing logic ...

  app_schema.logger_pkg.info('process_batch', 'Completed batch ' || p_batch_id || ', processed ' || v_count || ' orders');
EXCEPTION
  WHEN OTHERS THEN
    app_schema.logger_pkg.error(
      'process_batch',
      'Failed batch ' || p_batch_id,
      DBMS_UTILITY.FORMAT_ERROR_STACK || CHR(10) || DBMS_UTILITY.FORMAT_ERROR_BACKTRACE
    );
    RAISE;
END process_batch;
/

-- Enable DEBUG logging for incident investigation
BEGIN
  app_schema.logger_pkg.set_level('DEBUG');
END;
/

-- Query the log table during or after investigation
SELECT log_level, module, message, created_at
FROM app_schema.app_log
WHERE module = 'process_batch'
  AND created_at > SYSTIMESTAMP - INTERVAL '1' HOUR
ORDER BY created_at;

-- Restore WARN level after investigation
BEGIN
  app_schema.logger_pkg.set_level('WARN');
END;
/

-- Cleanup: purge old log entries (run daily via scheduler)
DELETE FROM app_schema.app_log
WHERE created_at < SYSTIMESTAMP - INTERVAL '30' DAY;
COMMIT;

-- Exception-driven debugging with strategic checkpoints
CREATE OR REPLACE PROCEDURE app_schema.process_payment(
  p_account_id IN NUMBER,
  p_amount     IN NUMBER
) IS
  v_balance   NUMBER;
  v_status    VARCHAR2(20);
  v_rowcount  NUMBER;
BEGIN
  -- Checkpoint 1: Input validation
  IF p_account_id IS NULL THEN
    RAISE_APPLICATION_ERROR(
      -20001,
      'CP1 FAILED: p_account_id is NULL'
    );
  END IF;

  IF p_amount IS NULL OR p_amount <= 0 THEN
    RAISE_APPLICATION_ERROR(
      -20001,
      'CP1 FAILED: p_amount=' || NVL(TO_CHAR(p_amount), 'NULL')
      || ' (expected positive number)'
    );
  END IF;

  -- Checkpoint 2: Account exists and is in the expected state
  BEGIN
    SELECT balance, status
    INTO v_balance, v_status
    FROM data_owner.accounts
    WHERE account_id = p_account_id;
  EXCEPTION
    WHEN NO_DATA_FOUND THEN
      RAISE_APPLICATION_ERROR(
        -20002,
        'CP2 FAILED: account_id=' || p_account_id || ' not found in accounts table'
      );
  END;

  IF v_status != 'ACTIVE' THEN
    RAISE_APPLICATION_ERROR(
      -20002,
      'CP2 FAILED: account ' || p_account_id
      || ' status=' || v_status || ' (expected ACTIVE)'
    );
  END IF;

  -- Checkpoint 3: Sufficient balance for the operation
  IF v_balance < p_amount THEN
    RAISE_APPLICATION_ERROR(
      -20003,
      'CP3 FAILED: account ' || p_account_id
      || ' balance=' || v_balance
      || ' < requested amount=' || p_amount
    );
  END IF;

  -- Checkpoint 4: DML affected exactly one row
  UPDATE data_owner.accounts
  SET balance = balance - p_amount,
      last_updated = SYSTIMESTAMP
  WHERE account_id = p_account_id
    AND status = 'ACTIVE';

  v_rowcount := SQL%ROWCOUNT;

  IF v_rowcount != 1 THEN
    RAISE_APPLICATION_ERROR(
      -20004,
      'CP4 FAILED: expected 1 row updated, got ' || v_rowcount
      || ' for account ' || p_account_id
      || ' (possible concurrent modification or status change between SELECT and UPDATE)'
    );
  END IF;

  -- Log success
  app_schema.logger_pkg.info(
    'process_payment',
    'Payment processed: account=' || p_account_id
    || ', amount=' || p_amount
    || ', new_balance=' || (v_balance - p_amount)
  );

EXCEPTION
  WHEN OTHERS THEN
    -- Log the error with full stack, then re-raise
    app_schema.logger_pkg.error(
      'process_payment',
      'Failed: account=' || p_account_id || ', amount=' || p_amount
      || ' | ' || SQLERRM,
      DBMS_UTILITY.FORMAT_ERROR_STACK || CHR(10) || DBMS_UTILITY.FORMAT_ERROR_BACKTRACE
    );
    RAISE;  -- Preserve the original error for the caller
END process_payment;
/

-- Prerequisites: run the trace table setup script (once per database)
-- @$ORACLE_HOME/rdbms/admin/tracetab.sql

-- Step 1: Compile the target package with debug symbols (required for line-level trace)
ALTER PACKAGE app_schema.billing_pkg COMPILE DEBUG BODY;

-- Step 2: Enable trace — all lines executed
BEGIN
  DBMS_TRACE.SET_PLSQL_TRACE(DBMS_TRACE.trace_all_lines);
END;
/

-- Step 3: Execute the procedure to trace
BEGIN
  app_schema.billing_pkg.process_invoice(1001);
END;
/

-- Step 4: Disable tracing
BEGIN
  DBMS_TRACE.CLEAR_PLSQL_TRACE;
END;
/

-- Step 5: Query the trace results
SELECT
  event_seq,
  event_unit_owner,
  event_unit,
  event_line,
  event_kind,
  event_time
FROM sys.plsql_trace_events
WHERE runid = (SELECT MAX(runid) FROM sys.plsql_trace_runs)
ORDER BY event_seq;
-- event_kind: 38 = line executed, 54 = exception raised, 51 = call, 52 = return

-- Step 6: Trace exceptions only (lighter weight)
BEGIN
  DBMS_TRACE.SET_PLSQL_TRACE(DBMS_TRACE.trace_all_exceptions);
END;
/

BEGIN
  app_schema.billing_pkg.process_invoice(1001);
END;
/

BEGIN
  DBMS_TRACE.CLEAR_PLSQL_TRACE;
END;
/

-- Query only exception events
SELECT
  event_seq,
  event_unit_owner || '.' || event_unit AS unit,
  event_line,
  event_kind
FROM sys.plsql_trace_events
WHERE runid = (SELECT MAX(runid) FROM sys.plsql_trace_runs)
  AND event_kind = 54  -- Exception raised
ORDER BY event_seq;

-- Step 7: DBMS_HPROF — Hierarchical Profiler (Oracle 11g+)
-- Profile a procedure to find performance hotspots
DECLARE
  v_runid NUMBER;
BEGIN
  DBMS_HPROF.START_PROFILING('PLSHPROF_DIR', 'billing_profile.trc');
  app_schema.billing_pkg.process_invoice(1001);
  DBMS_HPROF.STOP_PROFILING;

  -- Analyze the profile data into reporting tables
  v_runid := DBMS_HPROF.ANALYZE(
    location => 'PLSHPROF_DIR',
    filename => 'billing_profile.trc'
  );

  DBMS_OUTPUT.PUT_LINE('Profile run ID: ' || v_runid);
END;
/

-- Query the profiler results
SELECT
  owner,
  module,
  function AS subprogram,
  line#,
  subtree_elapsed_time AS total_us,
  function_elapsed_time AS self_us,
  calls
FROM dbmshp_function_info
WHERE runid = (SELECT MAX(runid) FROM dbmshp_runs)
ORDER BY function_elapsed_time DESC;
-- Shows which subprograms consume the most time

-- Step 8: Recompile without debug symbols after tracing
ALTER PACKAGE app_schema.billing_pkg COMPILE BODY;

-- Step 9: Clean up old trace data
DELETE FROM sys.plsql_trace_events WHERE runid < (SELECT MAX(runid) - 5 FROM sys.plsql_trace_runs);
DELETE FROM sys.plsql_trace_runs WHERE runid < (SELECT MAX(runid) - 5 FROM sys.plsql_trace_runs);
COMMIT;

-- Decision Tree: Which debugging tool to use
--
-- Q1: Is the issue reproducible interactively in SQL Developer?
--   YES -> Use SQL Developer interactive debugger (breakpoints + variable inspection)
--   NO  -> Go to Q2
--
-- Q2: Is the issue in production or triggered by a trigger/job/external app?
--   YES -> Use structured logging (logger_pkg) + checkpoint assertions
--   NO  -> Go to Q3
--
-- Q3: Do you need to understand the execution path through branches?
--   YES -> Use DBMS_TRACE (trace_all_lines in dev, trace_all_exceptions in staging)
--   NO  -> Go to Q4
--
-- Q4: Is the problem performance (slow) rather than correctness (wrong/error)?
--   YES -> Use DBMS_HPROF for subprogram-level time profiling
--   NO  -> Go to Q5
--
-- Q5: Quick check during development with a connected client?
--   YES -> DBMS_OUTPUT with conditional debug flag
--   NO  -> Use structured logging (it works everywhere)

-- Example: combining tools for a complex debugging session

-- 1. Enable structured logging at DEBUG level for the session
BEGIN
  app_schema.logger_pkg.set_level('DEBUG');
END;
/

-- 2. Enable DBMS_OUTPUT for interactive visibility
SET SERVEROUTPUT ON SIZE UNLIMITED

-- 3. Run the failing procedure
BEGIN
  app_schema.debug_pkg.enable_debug;  -- Conditional DBMS_OUTPUT
  app_schema.process_payment(1001, 500);
  app_schema.debug_pkg.disable_debug;
END;
/

-- 4. If the error is not clear, check the structured log
SELECT log_level, module, message, error_stack, created_at
FROM app_schema.app_log
WHERE module LIKE 'process_payment%'
  AND created_at > SYSTIMESTAMP - INTERVAL '5' MINUTE
ORDER BY created_at;

-- 5. If execution path is unclear, enable DBMS_TRACE
BEGIN
  DBMS_TRACE.SET_PLSQL_TRACE(DBMS_TRACE.trace_all_exceptions);
END;
/

BEGIN
  app_schema.process_payment(1001, 500);
END;
/

BEGIN
  DBMS_TRACE.CLEAR_PLSQL_TRACE;
END;
/

-- 6. Query trace results for exception events
SELECT event_seq, event_unit, event_line, event_kind
FROM sys.plsql_trace_events
WHERE runid = (SELECT MAX(runid) FROM sys.plsql_trace_runs)
  AND event_kind = 54
ORDER BY event_seq;

-- 7. Restore production log level
BEGIN
  app_schema.logger_pkg.set_level('WARN');
END;
/