Mittwoch, April 20, 2011

Trigger und Ladeoperationen

Wahrscheinlich liegt's daran, dass ich in diesem - wie in vielen anderen Punkten - ein Jünger Tom Kytes bin, jedenfalls halte ich Trigger für Teufelswerk und empfehle regelmäßig, sie zu vermeiden, wo immer das möglich ist. Gerade im Hinblick auf die Performance von Ladeprozessen behaupte ich gerne, dass Trigger ein massives Problem darstellen können. Um diese Aussage mal ein wenig zu fundieren, habe ich einen recht harmlosen Test gebastelt, der ein SQL-Script ausführt und dabei SQL-Trace mitlaufen lässt. Der Test erfolgt auf 11.2.0.1 unter Windows7, aber ich vermute, dass die Ergebnisse davon nicht besonders stark abhängen.

Zunächst das Script:

-- SQL-Trace aktivieren
EXEC DBMS_MONITOR.session_trace_enable(waits=>TRUE)

-- Anlage einer ersten Testtabelle 
-- für ein Insert ohne Trigger
drop table test1;
create table test1
( rn number
, insert_date date);

insert into test1
select rownum rn
     , sysdate insert_date
  from dual
connect by level <= 1000000;

-- Anlage einer zweiten Testtabelle 
-- für ein Insert mit Trigger
drop table test2;
create table test2
( rn number
, insert_date date);

-- der Trigger leistet für das zweite Insert das,
-- was das erste Insert ohne Hilfe schaffte:
-- er ergänzt das Datum für die Spalte insert_date
create or replace trigger test2_trigger
before insert
on test2
for each row

begin
  select sysdate
  into :new.insert_date
  from dual;

end test2_trigger;
/

insert into test2 (rn)
select rownum rn
  from dual
connect by level <= 1000000;

EXEC DBMS_MONITOR.session_trace_disable
Im (über tkprof) formatierten Trace für test1 (ohne Trigger) sieht man nun Folgendes:
********************************************************************************
insert into test1
select rownum rn
     , sysdate insert_date
  from dual
connect by level <= 1000000

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute      1      1.15       1.26          1       4748      26400     1000000
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        2      1.15       1.26          1       4748      26400     1000000

Misses in library cache during parse: 1
Misses in library cache during execute: 1
Optimizer mode: ALL_ROWS
Parsing user id: 75  

Rows     Row Source Operation
-------  ---------------------------------------------------
      0  LOAD TABLE CONVENTIONAL  (cr=0 pr=0 pw=0 time=0 us)
      1   COUNT  (cr=0 pr=0 pw=0 time=0 us)
      1    CONNECT BY WITHOUT FILTERING (cr=0 pr=0 pw=0 time=0 us)
      1     FAST DUAL  (cr=0 pr=0 pw=0 time=0 us cost=2 size=0 card=1)


Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  Disk file operations I/O                        2        0.00          0.00
  db file sequential read                         1        0.00          0.00
  reliable message                                1        0.00          0.00
  enq: CR - block range reuse ckpt                1        0.00          0.00
  log file switch completion                      2        0.05          0.09
  log file sync                                   1        0.02          0.02
  SQL*Net message to client                       1        0.00          0.00
  SQL*Net message from client                     1        0.00          0.00
********************************************************************************
Und hier das Ergebnis für die Variante test2 (mit Trigger):
********************************************************************************
insert into test2 (rn)
select rownum rn
  from dual
connect by level <= 1000000

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute      1     96.72      96.41          1       4757      26387     1000000
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        2     96.72      96.41          1       4757      26387     1000000

Misses in library cache during parse: 1
Misses in library cache during execute: 1
Optimizer mode: ALL_ROWS
Parsing user id: 75  

Rows     Row Source Operation
-------  ---------------------------------------------------
      0  LOAD TABLE CONVENTIONAL  (cr=0 pr=0 pw=0 time=0 us)
      1   COUNT  (cr=0 pr=0 pw=0 time=0 us)
      1    CONNECT BY WITHOUT FILTERING (cr=0 pr=0 pw=0 time=0 us)
      1     FAST DUAL  (cr=0 pr=0 pw=0 time=0 us cost=2 size=0 card=1)


Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  db file sequential read                         1        0.00          0.00
  reliable message                                1        0.00          0.00
  enq: CR - block range reuse ckpt                1        0.00          0.00
  SQL*Net message to client                       1        0.00          0.00
  SQL*Net message from client                     1        0.00          0.00
********************************************************************************

SQL ID: c749bc43qqfz3
Plan Hash: 1388734953
SELECT SYSDATE 
FROM
 DUAL


call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        2      0.00       0.00          0          0          0           0
Execute 999992      9.40      10.12          0          0          0           0
Fetch   999992      2.65       3.12          0          0          0      999992
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total  1999986     12.05      13.24          0          0          0      999992

Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: 75     (recursive depth: 1)

Rows     Row Source Operation
-------  ---------------------------------------------------
      1  FAST DUAL  (cr=0 pr=0 pw=0 time=0 us cost=2 size=0 card=1)

********************************************************************************
Also 1,26 sec. Laufzeit für die Variante ohne Trigger gegenüber fast 2 Minuten für die Variante mit dem before insert Trigger; laut sqlplus benötigte das insert für test2 1:49.72 min, was sich offenbar aus den 96.41 sec. für das insert und den 13.24 sec. für die dual-Zugriffe zusammensetzt. Zusätzlich erschreckend ist dabei, dass das insert für test2 nicht wartet, sondern massiv CPU konsumiert. Interessant ist noch, dass der dual-Zugriff nur 999992 mal erfolgt; wieso man ihn 8 mal sparen konnte, ist mir ein Rätsel (aber keines, dem ich heute noch nachgehen mag). Das Beispiel ist, ich geb's zu, ein wenig an den Haaren herbeigezogen. Außerdem liefert es auch nicht das gleiche Ergebnis, da alle Sätze in test1 mit dem gleichen Zeitstempel belegt werden, während in test2 viele unterschiedliche Werte ankommen - was im gegebenen Fall aber keine inhaltliche Bedeutung hätte:
select count(distinct insert_date) date_count from test1;

DATE_COUNT
----------
         1

select count(distinct insert_date) date_count from test2;

DATE_COUNT
----------
       111
Ein zweiter relevanterer Einwand gegen des Test wäre, dass die Trace-Erstellung massive Auswirkungen auf Fall2 hat: in einem weiteren Lauf ohne SQL-Trace benötigt das Insert "nur" 36,91 sec. Grundsätzlich sehe ich meine Abneigung gegen Trigger allerdings bestätigt. Natürlich gibt es Fälle, in denen sie benötigt werden, aber dort, wo man auch mit anderen Mitteln arbeiten kann, werde ich weiterhin dankend auf sie verzichten. Gerade hat übrigens Tim Hall eine schöne Einführung zum Thema geschrieben (und darin noch ein paar weitere Argumente gegen den Einsatz von Triggern aufgeführt).

Keine Kommentare:

Kommentar veröffentlichen