Skip to Main Content
  • Questions
  • BEFORE FOR EACH ROW trigger firing thousands times - why?

Breadcrumb

Question and Answer

Tom Kyte

Thanks for the question, Vladimir.

Asked: October 11, 2011 - 5:55 pm UTC

Last updated: October 12, 2011 - 3:41 pm UTC

Version: 11.2.0

Viewed 1000+ times

You Asked

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

and Tom said...

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


Rating

  (1 rating)

Is this answer out of date? If it is, please let us know via a Comment

Comments

Vladimir Zakharychev, October 12, 2011 - 1:35 pm UTC

Tom,

thanks for the response. Autonomous transaction is there to exaggerate the effect, I saw it without autonomous transactions as well, just the number of restarts for single row update was not that high.

I think I found a reasonable explanation why these restarts actually happen. First of all, I was wrong stating that no rollbacks were taking place when row updates were restarted. 10014 trace clearly shows there is a rollback to save point every time the row update is restarted. My impression is that restart itself happens because Oracle is unable to create the before image (no space in undo,) so undo tablespace is treated as if it's temporarily offline and a save undo segment in SYSTEM is created, which takes time. Meanwhile, the row update keeps failing and restarting until some undo space is available to store the before image. Insufficient undo space in this case is probably not considered a fatal failure, hence restart of row update instead of complete statement restart or an exception.

What puzzled me for some time is why I do see rollback to save point activity in 10014 trace, but it's not accounted for in any '%rollback%' statistics. Then I realized that probably this is because formally the rollback takes place to undo the failed row update operation and gets logged in the trace, but physically it doesn't happen as there's nothing to rollback - we couldn't even create the before image - so no counters are incremented.

Not sure I am completely correct here, but hope it's close to reality.

Regards,
Vladimir
Tom Kyte
October 12, 2011 - 3:41 pm UTC

because Oracle is unable to create the before image (no space in
undo,) so undo tablespace is treated as if it's temporarily offline and a save
undo segment in SYSTEM is created,


no, that would not be happening. If we ran out of undo, you'd get an error. We don't start spilling over into system.

It has to do with advancing through the undo rapidly like that. In the example I linked to, we had as much undo as you would like - still happens.

More to Explore

PL/SQL demos

Check out more PL/SQL tutorials on our LiveSQL tool.

PL/SQL docs

PL/SQL reference manual from the Oracle documentation library