Freitag, November 09, 2012

Notizen zur Performance von DELETE-Operationen

Gute Erklärungen für die folgenden Beobachtungen könnte ich mit hoher Wahrscheinlichkeit aus der einschlägigen Literatur bekommen, aber bekanntlich ist solide Recherche der Tod der Kreativität. Daher notiere ich einfach mal ein paar Punkte, die mir dieser Tage aufgefallen sind.

Seit Jahren warne ich die Entwickler in meiner Umgebung regelmäßig vor DELETE- und UPDATE-Operationen auf großen Datenmengen, da man daran in aller Regel keine Freude hat. Sofern es möglich ist, wandele ich solche Operationen gerne in INSERTs in neue Tabellen um, die ich dann anschließend gegen die Ursprungsobjekte austausche. Aber erst in den letzten Tagen ist mir klar geworden, wie viel Arbeit DELETE tatsächlich hervorruft. Dazu ein kleines Beispiel (11.1.0.7, ASSM, 8K Blockgröße, Noarchivelog auf einem nicht ganz neuen Windows-Desktop-PC):

drop table test_delete;
create table test_delete
as
select rownum id
  from dual
connect by level <= 1000000;

--> Abgelaufen: 00:00:00.89

exec dbms_stats.gather_table_stats(user, 'TEST_DELETE')

alter system flush buffer_cache;

-- Statistikerfassung über Snapshots aus v$sesstat 
-- vor und nach dem delete (erzeugt in einer anderen Session)
delete from test_delete;
--> Abgelaufen: 00:00:12.51

Während die Anlage der einspaltigen Tabelle mit 1M rows also weniger als 1 sec. benötigt, läuft das DELETE-Kommando über 12 sec. Ein Blick auf die Statistiken (bzw. die Deltas) in v$sesstat zeigt dabei ein paar interessante Werte, zu denen ich im Folgenden behutsame Interpretationen anschließe und dabei die Erläuterungen der Dokumentation berücksichtige:

-- Zeitangaben
NAME                                               DIFF
-------------------------------------------- ----------
DB time                                            1250
CPU used by this session                            761
redo log space wait time                            383
change write time                                   165
user I/O wait time                                   61

Demnach ist der eigentliche I/O-Anteil an der Laufzeit sehr bescheiden. Hoch sind hingegen die CPU-Nutzung und die Wartezeiten auf Platz im Log-Buffer (in meiner Test-Datenbank sind die Größe von log buffer und online redo logs nicht optimiert). Dass hier Wartezeiten entstehen, liegt nicht zuletzt an den Datenmengen, die in diesem Zusammenhang bewegt werden:

NAME                                               DIFF
-------------------------------------------- ----------
redo size                                     237244384 -- ca. 226 MB
undo change vector size                       103994836 -- ca.  99 MB
physical read bytes                            12804096 -- ca.  12 MB

Dabei entsprechen die 12 MB physical read bytes nahezu exakt der tatsächlichen Größe des Segments, das laut USER_TABLES 1557 Blocks umfasst (1557 * 8192 = 12754944). Das Löschen einer Tabelle von 12 MB führt demnach zur Erzeugung von über 200 MB redo und fast 100 MB undo! Dabei ist das Verhältnis von redo zu undo erst einmal keine besondere Überraschung, da auch zu jedem undo record redo-Informationen erzeugt werden müssen (in einem früheren Test-Lauf hatte ich auch noch IMU(also in-memory-undo)-Angaben, die anzeigen, dass das DELETE zunächst den in-memory-undo-Mechanismus verwendete, aber beim Erreichen eines gewissen Volumens davon wieder Abstand nahm - so jedenfalls deute ich den Wert IMU undo allocation size: 63996; habe aber gerade Jonathan Lewis' Oracle Core nicht zur Hand, wo das Verhalten im Detail geschrieben wird. Ein paar grundlegende Aussagen zu diesem Thema hat Jonathan Lewis auch gelegentlich in einem OTN-Thread gemacht. Im aktuellen Test-Lauf spielte IMU dann aber keine Rolle). Aber das Verhältnis der Netto-Datenmenge in der Tabelle zu undo und redo ist doch deutlich extremer als ich es erwartet hätte. Interessant sind auch die Statistiken zu den Block-Zugriffen, hier kombiniert mit allen Angaben, deren Wert im Umkreis von 1M liegt:

NAME                                               DIFF
-------------------------------------------- ----------
db block changes                                2019636
session logical reads                           1039698
db block gets                                   1037897
db block gets from cache                        1037897
redo entries                                    1006269
HSC Heap Segment Block Changes                  1000000
table scan rows gotten                          1000000
buffer is pinned count                           998477
free buffer requested                             16246
consistent gets                                    1801
consistent gets from cache                         1801
consistent gets from cache (fastpath)              1701
no work - consistent read gets                     1658
physical reads                                     1563
physical reads cache                               1563
switch current to new buffer                       1523
table scan blocks gotten                           1523
physical reads cache prefetch                      1495
buffer is not pinned count                          271
db block gets from cache (fastpath)                 200

Keine Überraschungen sind die table scan rows gotten. Ansonsten sehe ich diverse Werte, die im Bereich der Anzahl der Tabellenblocks (1557) liegen und andere, die eher der Satzanzahl entsprechen. Eine Ausnahme sind die db block changes, die die Dokumentation folgendermaßen erklärt: "the total number of changes that were part of an update or delete operation that were made to all blocks in the SGA. Such changes generate redo log entries and hence become permanent changes to the database if the transaction is committed." Blocks in der SGA sind natürlich auch die undo Blöcke, so dass die Verdopplung des Werts gegenüber 1M verständlich wird. Festzustellen ist in jedem Fall, dass die Anzahl der db block gets ("Number of times a CURRENT block was requested") in der Nähe der Satzanzahl liegt: offenbar ist hier keine BULK-artige Zusammenfassung mehrerer Änderungen eines Blocks möglich - und tatsächlich ändern sich redo size und undo change vector size nicht, wenn man die Löschung der Daten satzweise durchführt:

-- basierend auf dem ersten Test
create index ix_test_delete on test_delete(id);

-- Fall 1:
delete from test_delete;
--> Abgelaufen: 00:00:28.60
-- die Laufzeit ist also gegenüber dem ursprünglichen Test
-- ohne Index mehr als verdoppelt

-- Fall 2:
begin
for i in 1..1000000 loop
delete from TEST_DELETE where id = i;
end loop;
end;
/
--> Abgelaufen: 00:01:23.49

In beiden Fällen kommt man auf > 400MB redo und > 200MB undo, was angesichts des zusätzlichen Index in der Relation plausibel erscheint. Davon abgesehen ist das DELETE über alle Sätze natürlich schneller als die Löschung über Einzelkommandos: unter anderem steigt die Anzahl der consistent gets (1954 -> 3002599), da für jedes einzelne DELETE noch einmal ein für den Start der Transaktion konsistenter Zustand des Blocks, der geändert werden soll, erzeugt werden muss.

Viel weiter komme ich an dieser Stelle heute nicht mehr, aber zumindest die Beobachtung, dass die Performance von DELETE-Operationen weniger vom Datenvolumen als von der Anzahl geänderter Sätze abhängt, ist etwas, das ich mir merken sollte.

Keine Kommentare:

Kommentar veröffentlichen