CODEWITHSUNDEEP
sqloracle-databasetriggerstrace
Juan Ortega
Juan Ortega

Reputation: 69

How to trace a SQL trigger?

I'd like to trace the execution of a trigger but I don't know really how to do it. With the autotrace set on, the first idea that came to my mind was force the trigger but it still doesn't work. How am I supposed to view the execution tracer of a trigger?

Upvotes: 0

Views: 3436

Answers (2)

Matthew McPeak
Matthew McPeak

Reputation: 17924

Oracle gives you two good ways to trace PL/SQL. The preferred way is using the DBMS_HPROF package. Less good (it's older) is DBMS_PROFILER.

Since DBMS_PROFILER is simpler and your requirements are simple, I'll demonstrate that.

First, let's create a table with a trigger on it:

CREATE TABLE matt_test1 ( a number );

CREATE TRIGGER matt_trg1 BEFORE INSERT ON matt_test1 FOR EACH ROW
BEGIN
  NULL;
END;

Next, we start the profiler, run an INSERT (which should fire our trigger), and then stop the profiler:

EXEC DBMS_PROFILER.START_PROFILER;

INSERT INTO matt_test1 (a) values (1);

EXEC DBMS_PROFILER.STOP_PROFILER;

Now, there are better ways to start and stop the profiler. Those ways will return the run ID that was used, which you will need in order to query the results. In our quick-and-dirty example, we will just look the most recent profiler results that are out there:

SELECT * FROM plsql_profiler_runs order by runid desc;

On my system, that was runid 2.

Next, we query the PLSQL_PROFILER* tables to get all the information about PL/SQL that was executed during the run. This won't list just triggers -- it'll be a lot more: pretty much any SQL statement called from PL/SQL and pretty much any other PL/SQL block (procedure or function) called from PL/SQL.

Here is the query I used to use for this (before I switched to using DBMS_HPROF for this:

SELECT   d.runid,
         u.unit_type,
         u.unit_owner,
         u.unit_name,
         d.line#,
         d.total_occur,
         d.total_time / POWER (10, 9) total_seconds,
         d.min_time / POWER (10, 9) min_seconds,
         d.max_time / POWER (10, 9) max_seconds,
         ss.source line_text,
         SUM (d.total_time / POWER (10, 9)) OVER (PARTITION BY NULL ORDER BY d.total_time DESC ROWS BETWEEN UNBOUNDED PRECEDING AND CURRENT ROW)
                                                                                                               cumulative_seconds,
         SUM (d.total_time / POWER (10, 9)) OVER (PARTITION BY NULL) elapsed_seconds_for_run
FROM     plsql_profiler_data d INNER JOIN plsql_profiler_units u ON u.runid = d.runid
         AND                                                       u.unit_number = d.unit_number
         LEFT JOIN SYS.user$ su ON su.NAME = u.unit_owner
         LEFT JOIN SYS.obj$ so
         ON  so.NAME = u.unit_name
         AND so.owner# = su.user#
         AND DECODE (so.type#,
                     7, 'PROCEDURE',
                     8, 'FUNCTION',
                     9, 'PACKAGE',
                     11, 'PACKAGE BODY',
                     12, 'TRIGGER',
                     13, 'TYPE',
                     14, 'TYPE BODY',
                     'UNDEFINED') = u.unit_type
         LEFT JOIN SYS.source$ ss ON ss.obj# = so.obj#
         AND                        ss.line = d.line#
WHERE    1=1
and d.runid = 2
AND      d.total_occur > 0
ORDER BY d.total_time DESC;

Finally, the results:

+-------+-----------------+-------------+-------------+-------+-------------+---------------+-------------+-------------+-----------+--------------------+-------------------------+
| RUNID |    UNIT_TYPE    | UNIT_OWNER  |  UNIT_NAME  | LINE# | TOTAL_OCCUR | TOTAL_SECONDS | MIN_SECONDS | MAX_SECONDS | LINE_TEXT | CUMULATIVE_SECONDS | ELAPSED_SECONDS_FOR_RUN |
+-------+-----------------+-------------+-------------+-------+-------------+---------------+-------------+-------------+-----------+--------------------+-------------------------+
|     2 | ANONYMOUS BLOCK | <anonymous> | <anonymous> |     1 |           2 |   0.000010001 |    0.000001 | 0.000008001 |           |        0.000010001 |             0.000013001 |
|     2 | TRIGGER         | APPS        | MATT_TRG1   |     2 |           1 |      0.000002 |    0.000002 |    0.000002 | BEGIN     |        0.000012001 |             0.000013001 |
|     2 | ANONYMOUS BLOCK | <anonymous> | <anonymous> |     1 |           1 |      0.000001 |    0.000001 |    0.000001 |           |        0.000013001 |             0.000013001 |
+-------+-----------------+-------------+-------------+-------+-------------+---------------+-------------+-------------+-----------+--------------------+-------------------------+

You can see our trigger being fired in row #2, above.

Upvotes: 2

wolφi
wolφi

Reputation: 8361

Two way come to mind:

If you can change the trigger code, create a log table and write debug messages to it from the trigger body:

CREATE TABLE trigger_log (t TIMESTAMP, m VARCHAR2(4000));

CREATE OR REPLACE my_trigger BEFORE INSERT ...
BEGIN 
  INSERT INTO trigger_log(t, m)
  VALUES (systimestamp,'my_trigger fired :new_id is='||:new_id);

  ... rest of trigger body ...
END;
/

Secondly, if you can change the audit settings, switch on audit for the relevant table.

Upvotes: 1

Related Questions