Dear Tom,
it's documented and generally well understood (and you demonstrated it numerous times) that a BEFORE trigger can fire more than once due to concurrent update conflicts, in which case transactions rollback to a savepoint and restart the DML, executing triggers again.
Today I was given a test case where a FOR EACH ROW trigger can fire several thousand times during single row update in single transaction (no concurrent activity on the table being updated.) How many times the trigger will fire seems to be unpredictable and rather random. I couldn't find an explanation for this behavior anywhere, maybe you can shed some light.
First we create a really small undo tablespace:
CREATE UNDO TABLESPACE UNDO_5M DATAFILE SIZE 5M AUTOEXTEND OFF;
ALTER SYSTEM SET UNDO_TABLESPACE=UNDO_5M;
And then we run the following:
SQL> SELECT BANNER FROM V$VERSION;
BANNER
--------------------------------------------------------------------------------
Oracle Database 11g Enterprise Edition Release 11.2.0.2.0 - 64bit Production
PL/SQL Release 11.2.0.2.0 - Production
CORE 11.2.0.2.0 Production
TNS for Linux: Version 11.2.0.2.0 - Production
NLSRTL Version 11.2.0.2.0 - Production
SQL> CREATE OR REPLACE PACKAGE trg_pkg AS
2
3 cnt_r PLS_INTEGER := 0;
4 cnt_s PLS_INTEGER := 0;
5
6 END;
7 /
Package created.
SQL> CREATE TABLE T0 AS SELECT 0 N FROM DUAL
2 /
Table created.
SQL> CREATE TABLE T1 AS SELECT LEVEL IX, RPAD('x',4000,'x') X FROM DUAL CONNECT BY LEVEL < 3
2 /
Table created.
SQL> CREATE OR REPLACE TRIGGER s_bu_trg_t1
2 BEFORE UPDATE
3 ON t1
4 BEGIN
5 trg_pkg.cnt_s := trg_pkg.cnt_s + 1;
6 dbms_output.put_line('Before statement: '||trg_pkg.cnt_s);
7 END;
8 /
Trigger created.
SQL> CREATE OR REPLACE TRIGGER r_bu_trg_t1
2 BEFORE UPDATE
3 ON t1
4 FOR EACH ROW
5 DECLARE
6 PRAGMA AUTONOMOUS_TRANSACTION;
7 BEGIN
8 trg_pkg.cnt_r := trg_pkg.cnt_r+ 1;
9 dbms_output.put_line('FEaR fired for ix '||:new.ix||', '||trg_pkg.cnt_r);
10 UPDATE t0 SET n=n+1;
11 COMMIT;
12 END;
13 /
Trigger created.
SQL> SET SERVEROUTPUT ON
SQL> BEGIN
2 trg_pkg.cnt_r := 0;
3 FOR j IN 1..10 LOOP
4 trg_pkg.cnt_s := 0;
5 FOR i IN 1..100 LOOP
6 UPDATE t1 SET x = x;
7 END LOOP;
8 COMMIT;
9 END LOOP;
10 dbms_output.put_line('FEaR trigger executed '||trg_pkg.cnt_r||' times.');
11 END;
12 /
Before statement: 1
FEaR fired for ix 1, 1
FEaR fired for ix 2, 2
Before statement: 2
FEaR fired for ix 1, 3
FEaR fired for ix 1, 4
FEaR fired for ix 2, 5
FEaR fired for ix 2, 6
Before statement: 3
FEaR fired for ix 1, 7
FEaR fired for ix 1, 8
FEaR fired for ix 2, 9
FEaR fired for ix 2, 10
<...skip...>
Before statement: 1
FEaR fired for ix 1, 229
FEaR fired for ix 2, 230
Before statement: 2
FEaR fired for ix 1, 231
FEaR fired for ix 1, 232
FEaR fired for ix 2, 233
FEaR fired for ix 2, 234
Before statement: 3
FEaR fired for ix 1, 235
FEaR fired for ix 1, 236
FEaR fired for ix 2, 237
FEaR fired for ix 2, 238
Before statement: 4
FEaR fired for ix 1, 239
FEaR fired for ix 2, 240
Before statement: 5
FEaR fired for ix 1, 241
FEaR fired for ix 2, 242
<------------------------- here it starts
Before statement: 6
FEaR fired for ix 1, 243
FEaR fired for ix 1, 244
<...skip 5000+ executions for the same row in the same update...>
FEaR fired for ix 1, 5911
FEaR fired for ix 1, 5912
FEaR fired for ix 1, 5913
FEaR fired for ix 1, 5914
FEaR fired for ix 2, 5915
FEaR fired for ix 2, 5916
<------------------------- up to here
Before statement: 7
FEaR fired for ix 1, 5917
FEaR fired for ix 1, 5918
FEaR fired for ix 1, 5919
FEaR fired for ix 2, 5920
FEaR fired for ix 2, 5921
Before statement: 8
FEaR fired for ix 1, 5922
FEaR fired for ix 2, 5923
<...skip remaining iterations...>
Before statement: 100
FEaR fired for ix 1, 8489
FEaR fired for ix 1, 8490
FEaR fired for ix 2, 8491
FEaR fired for ix 2, 8492
FEaR trigger executed 8492 times.
PL/SQL procedure successfully completed.
Most of the output is skipped, I left just relevant portion. So for 2000 row updates, the FOR EACH ROW trigger fired almost 8,500 times.
I had to try several times before getting this particular result (almost 6000 trigger executions for single row update.) Each time I run this test I get different results, but trigger is always fired more than 2000 times. If you add a COMMIT immediately after UPDATE, this doesn't happen. Limited undo space just exaggerates the result, with any undo space available the trigger sometimes fires twice or more for the same row. I monitored statistics and "commit cleanouts" and "deferred (CURRENT) block cleanout applications" seemed to be relevant, and "table scans (short tables)" was unusually high, even higher than the number of trigger executions, so it looks like updates were indeed restarted several thousand times, but no rollbacks were taking place as far as I can tell (at least all '%rollback%' stats came out zero.)
Can you please explain what happens in this particular case and why the update is being restarted so many times without any rollbacks or errors? And how could I further diagnose what's going on under the hood? (I was thinking about taking a block dump from the trigger each time it fires to see what's inside and how the block changes over time, but this seems to be an overkill, maybe there is a simpler and more straightforward way.)
And while we're at it, can you clarify what "deferred (CURRENT) block cleanout applications" really counts as I find it a bit ambiguously defined. Some people refer to it in conjunction with deferred block cleanout mechanism. For instance, Jonathan Lewis gave his interpretation here:
https://forums.oracle.com/forums/thread.jspa?threadID=580691 "A "deferred (CURRENT)" cleanout occurs when a DML statement wants to modify the contents of a block and all the available ITLs are showing recent commit cleanouts. The process cleans out the block (incrementing the statistic once) and then uses the ITL slot with the lowest commit SCN."
However, the documentation suggests that this statistic shows the number of cleanouts deferred for later rather than the number of deferred block cleanouts performed, as opposed to "immediate (CURRENT) block cleanout applications," which is the count of current mode block cleanouts performed. So which interpretation is correct? Both?
Thanks in advance,
Vladimir
we've already demonstrated this once before on this site:
http://asktom.oracle.com/pls/asktom/f?p=100:11:0::::P11_QUESTION_ID:2599480800346313755#2600827300346401245 It will have to do with all of your micro transactions (lots of commits), very small undo, and consistent read.
It really goes back to a mantra of mine which is:
NEVER EVER DO ANYTHING NON-TRANSACTIONAL in a trigger, autonomous transaction is a horrible feature I wished we never introduced (it has ONE use and only one use - to log errors - we should have provided a general purpose error logging facility instead of autonomous transactions).
Jonathan's description is better than the one liner in the reference guide, which I think is awkwardly phrased.
The doc says:
Number of times cleanout records are deferred, piggyback with changes, always current get
but probably should say something more like:
Number of times cleanout records are performed in a deferred fashion, piggyback with changes, always current get
Moral to this story however is:
o avoid triggers unless you absolutely need them (and you hardly ever do)
o do nothing that doesn't rollback in them - ever - unless you can live with the side effects (triggers can always fire more than once!)
o autonomous transactions in triggers are pure evil.
http://www.oracle.com/technetwork/issue-archive/2008/08-sep/o58asktom-101055.html