Analyse du VACUUM

Ce billet fait partie d'une série sur l'écriture de mon livre, « PostgreSQL - Architecture et notions avancées ».

Et voilà, deux nouveaux chapitres écrits, dont un sur le système transactionnel de PostgreSQL. Ce dernier m'a demandé d' étudier plus attentivement le travail de l'opération VACUUM. J'en connaissais le principe et son fonctionnement, à savoir un fonctionnement en trois phases : recherche des éléments à flagguer comme invisibles, suppression de ces éléments dans les index, puis suppression dans la table (pas physiquement). Cependant, je ne l'avais pas regardé plus précisément.

J'ai donc lu le code, puis écrit un petit patch pour mieux suivre cela (disponible en pièce jointe). J'ai exécuté un script SQL pour visualiser différents comportements. Par exemple, on ajoute dix lignes dans une nouvelle table, puis on met à jour une ligne sur trois, et enfin on exécute un VACUUM sur cette table :

CREATE TABLE t2(c1 integer);
ALTER TABLE t2 SET (autovacuum_enabled=off);
INSERT INTO t2 SELECT generate_series(1, 10);
UPDATE t2 SET c1=-c1 where c1%3=1;
SET client_min_messages to log;
VACUUM t2;

Voici le log fourni par le patch :

psql:script.sql:9: LOG:  patch - vacuum.c - vacuum[117] - VACUUM on 0, toast included, no wraparound
psql:script.sql:9: LOG:  patch - vacuum.c - vacuum[249] - vacuuming 82231
psql:script.sql:9: LOG:  patch - vacuum.c - vacuum_rel[1207] - relation t2 (82231) opened with lockmode 4
psql:script.sql:9: LOG:  patch - vacuumlazy.c - lazy_vacuum_rel[194] - vacuuming...
psql:script.sql:9: LOG:  patch - vacuumlazy.c - lazy_scan_heap[465] - relation has 1 blocks
psql:script.sql:9: LOG:  patch - vacuumlazy.c - lazy_scan_heap[534] - working on block 0
psql:script.sql:9: LOG:  patch - vacuumlazy.c - lazy_scan_heap[629] - reading block
psql:script.sql:9: LOG:  patch - vacuumlazy.c - lazy_scan_heap[762] - pruning HOT update chains...
psql:script.sql:9: LOG:  patch - pruneheap.c - heap_page_prune[220] - 4 deleted items found
psql:script.sql:9: LOG:  patch - pruneheap.c - heap_page_prune_execute[691] - item 1 is now REDIRECTed to item 11
psql:script.sql:9: LOG:  patch - pruneheap.c - heap_page_prune_execute[691] - item 4 is now REDIRECTed to item 12
psql:script.sql:9: LOG:  patch - pruneheap.c - heap_page_prune_execute[691] - item 7 is now REDIRECTed to item 13
psql:script.sql:9: LOG:  patch - pruneheap.c - heap_page_prune_execute[691] - item 10 is now REDIRECTed to item 14
psql:script.sql:9: LOG:  patch - bufpage.c - PageRepairFragmentation[489] - compacting page (10 have storage, 0 are unused)
psql:script.sql:9: LOG:  patch - bufpage.c - PageRepairFragmentation[514] - compacting page (totallen 320)

Il n'y a là qu'une seule étape exécutée. En effet, dû au très petit nombre de lignes dans la table, le seul bloc de 8 Ko n'a pas été entièrement occupé. Du coup, PostgreSQL place les nouvelles versions des lignes mises à jour dans le même bloc que les anciennes versions et utilise le Heap Over Tuple pour lier les enregistrements. De plus, comme il n'y a pas d'index, pas besoin de les mettre à jour.

Maintenant, faisons la même chose avec 400 lignes (en fait, suffisamment pour remplir plus d'un bloc). Les logs sont beaucoup plus importants.

psql:script.sql:9: LOG:  patch - vacuum.c - vacuum[117] - VACUUM on 0, toast included, no wraparound
psql:script.sql:9: LOG:  patch - vacuum.c - vacuum[249] - vacuuming 82234
psql:script.sql:9: LOG:  patch - vacuum.c - vacuum_rel[1207] - relation t2 (82234) opened with lockmode 4
psql:script.sql:9: LOG:  patch - vacuumlazy.c - lazy_vacuum_rel[194] - vacuuming...
psql:script.sql:9: LOG:  patch - vacuumlazy.c - lazy_scan_heap[465] - relation has 3 blocks
psql:script.sql:9: LOG:  patch - vacuumlazy.c - lazy_scan_heap[534] - working on block 0
psql:script.sql:9: LOG:  patch - vacuumlazy.c - lazy_scan_heap[629] - reading block
psql:script.sql:9: LOG:  patch - vacuumlazy.c - lazy_scan_heap[762] - pruning HOT update chains...
psql:script.sql:9: LOG:  patch - pruneheap.c - heap_page_prune[220] - 76 deleted items found
psql:script.sql:9: LOG:  patch - pruneheap.c - heap_page_prune_execute[702] - item 1 is now DEAD
psql:script.sql:9: LOG:  patch - pruneheap.c - heap_page_prune_execute[702] - item 4 is now DEAD
[...]
psql:script.sql:9: LOG:  patch - pruneheap.c - heap_page_prune_execute[702] - item 223 is now DEAD
psql:script.sql:9: LOG:  patch - pruneheap.c - heap_page_prune_execute[702] - item 226 is now DEAD
psql:script.sql:9: LOG:  patch - bufpage.c - PageRepairFragmentation[489] - compacting page (150 have storage, 0 are unused)
psql:script.sql:9: LOG:  patch - bufpage.c - PageRepairFragmentation[514] - compacting page (totallen 4800)
psql:script.sql:9: LOG:  patch - vacuumlazy.c - lazy_scan_heap[817] - item 1 DEAD
psql:script.sql:9: LOG:  patch - vacuumlazy.c - lazy_scan_heap[817] - item 4 DEAD
[...]
psql:script.sql:9: LOG:  patch - vacuumlazy.c - lazy_scan_heap[817] - item 223 DEAD
psql:script.sql:9: LOG:  patch - vacuumlazy.c - lazy_scan_heap[817] - item 226 DEAD
psql:script.sql:9: LOG:  patch - vacuumlazy.c - lazy_vacuum_page[1237] - block 0
psql:script.sql:9: LOG:  patch - vacuumlazy.c - lazy_vacuum_page[1250] - item 1 is now UNUSED
psql:script.sql:9: LOG:  patch - vacuumlazy.c - lazy_vacuum_page[1250] - item 4 is now UNUSED
[...]
psql:script.sql:9: LOG:  patch - vacuumlazy.c - lazy_vacuum_page[1250] - item 223 is now UNUSED
psql:script.sql:9: LOG:  patch - vacuumlazy.c - lazy_vacuum_page[1250] - item 226 is now UNUSED
psql:script.sql:9: LOG:  patch - bufpage.c - PageRepairFragmentation[489] - compacting page (150 have storage, 76 are unused)
psql:script.sql:9: LOG:  patch - bufpage.c - PageRepairFragmentation[514] - compacting page (totallen 4800)
psql:script.sql:9: LOG:  patch - vacuumlazy.c - lazy_scan_heap[534] - working on block 1
psql:script.sql:9: LOG:  patch - vacuumlazy.c - lazy_scan_heap[629] - reading block
psql:script.sql:9: LOG:  patch - vacuumlazy.c - lazy_scan_heap[762] - pruning HOT update chains...
psql:script.sql:9: LOG:  patch - pruneheap.c - heap_page_prune[220] - 58 deleted items found
psql:script.sql:9: LOG:  patch - pruneheap.c - heap_page_prune_execute[702] - item 3 is now DEAD
psql:script.sql:9: LOG:  patch - pruneheap.c - heap_page_prune_execute[702] - item 6 is now DEAD
[...]
psql:script.sql:9: LOG:  patch - pruneheap.c - heap_page_prune_execute[702] - item 171 is now DEAD
psql:script.sql:9: LOG:  patch - pruneheap.c - heap_page_prune_execute[702] - item 174 is now DEAD
psql:script.sql:9: LOG:  patch - bufpage.c - PageRepairFragmentation[489] - compacting page (168 have storage, 0 are unused)
psql:script.sql:9: LOG:  patch - bufpage.c - PageRepairFragmentation[514] - compacting page (totallen 5376)
psql:script.sql:9: LOG:  patch - vacuumlazy.c - lazy_scan_heap[817] - item 3 DEAD
psql:script.sql:9: LOG:  patch - vacuumlazy.c - lazy_scan_heap[817] - item 6 DEAD
psql:script.sql:9: LOG:  patch - vacuumlazy.c - lazy_scan_heap[817] - item 9 DEAD
[...]
psql:script.sql:9: LOG:  patch - vacuumlazy.c - lazy_scan_heap[817] - item 171 DEAD
psql:script.sql:9: LOG:  patch - vacuumlazy.c - lazy_scan_heap[817] - item 174 DEAD
psql:script.sql:9: LOG:  patch - vacuumlazy.c - lazy_vacuum_page[1237] - block 1
psql:script.sql:9: LOG:  patch - vacuumlazy.c - lazy_vacuum_page[1250] - item 3 is now UNUSED
psql:script.sql:9: LOG:  patch - vacuumlazy.c - lazy_vacuum_page[1250] - item 6 is now UNUSED
[...]
psql:script.sql:9: LOG:  patch - vacuumlazy.c - lazy_vacuum_page[1250] - item 171 is now UNUSED
psql:script.sql:9: LOG:  patch - vacuumlazy.c - lazy_vacuum_page[1250] - item 174 is now UNUSED
psql:script.sql:9: LOG:  patch - bufpage.c - PageRepairFragmentation[489] - compacting page (168 have storage, 58 are unused)
psql:script.sql:9: LOG:  patch - bufpage.c - PageRepairFragmentation[514] - compacting page (totallen 5376)
psql:script.sql:9: LOG:  patch - vacuumlazy.c - lazy_scan_heap[534] - working on block 2
psql:script.sql:9: LOG:  patch - vacuumlazy.c - lazy_scan_heap[629] - reading block
psql:script.sql:9: LOG:  patch - vacuumlazy.c - lazy_scan_heap[762] - pruning HOT update chains...
psql:script.sql:9: LOG:  patch - pruneheap.c - heap_page_prune[220] - 0 deleted items found

Chaque élément devenu invisible est déclaré DEAD lors de la première étape, puis UNUSED à la troisième étape.

Il est dit que le fillfactor permet d'augmenter l'utilisation du Heap Over Tuple. Voici ce que cela donne avec un fillfactor à 90% :

psql:script.sql:9: LOG:  patch - vacuum.c - vacuum[117] - VACUUM on 0, toast included, no wraparound
psql:script.sql:9: LOG:  patch - vacuum.c - vacuum[249] - vacuuming 82237
psql:script.sql:9: LOG:  patch - vacuum.c - vacuum_rel[1207] - relation t2 (82237) opened with lockmode 4
psql:script.sql:9: LOG:  patch - vacuumlazy.c - lazy_vacuum_rel[194] - vacuuming...
psql:script.sql:9: LOG:  patch - vacuumlazy.c - lazy_scan_heap[465] - relation has 3 blocks
psql:script.sql:9: LOG:  patch - vacuumlazy.c - lazy_scan_heap[534] - working on block 0
psql:script.sql:9: LOG:  patch - vacuumlazy.c - lazy_scan_heap[629] - reading block
psql:script.sql:9: LOG:  patch - vacuumlazy.c - lazy_scan_heap[762] - pruning HOT update chains...
psql:script.sql:9: LOG:  patch - pruneheap.c - heap_page_prune[220] - 68 deleted items found
psql:script.sql:9: LOG:  patch - pruneheap.c - heap_page_prune_execute[691] - item 1 is now REDIRECTed to item 205
psql:script.sql:9: LOG:  patch - pruneheap.c - heap_page_prune_execute[691] - item 4 is now REDIRECTed to item 206
[...]
psql:script.sql:9: LOG:  patch - pruneheap.c - heap_page_prune_execute[691] - item 61 is now REDIRECTed to item 225
psql:script.sql:9: LOG:  patch - pruneheap.c - heap_page_prune_execute[691] - item 64 is now REDIRECTed to item 226
psql:script.sql:9: LOG:  patch - pruneheap.c - heap_page_prune_execute[702] - item 67 is now DEAD
psql:script.sql:9: LOG:  patch - pruneheap.c - heap_page_prune_execute[702] - item 70 is now DEAD
[...]
psql:script.sql:9: LOG:  patch - pruneheap.c - heap_page_prune_execute[702] - item 199 is now DEAD
psql:script.sql:9: LOG:  patch - pruneheap.c - heap_page_prune_execute[702] - item 202 is now DEAD
psql:script.sql:9: LOG:  patch - bufpage.c - PageRepairFragmentation[489] - compacting page (158 have storage, 0 are unused)
psql:script.sql:9: LOG:  patch - bufpage.c - PageRepairFragmentation[514] - compacting page (totallen 5056)
psql:script.sql:9: LOG:  patch - vacuumlazy.c - lazy_scan_heap[817] - item 67 DEAD
psql:script.sql:9: LOG:  patch - vacuumlazy.c - lazy_scan_heap[817] - item 70 DEAD
[...]
psql:script.sql:9: LOG:  patch - vacuumlazy.c - lazy_scan_heap[817] - item 199 DEAD
psql:script.sql:9: LOG:  patch - vacuumlazy.c - lazy_scan_heap[817] - item 202 DEAD
psql:script.sql:9: LOG:  patch - vacuumlazy.c - lazy_vacuum_page[1237] - block 0
psql:script.sql:9: LOG:  patch - vacuumlazy.c - lazy_vacuum_page[1250] - item 67 is now UNUSED
psql:script.sql:9: LOG:  patch - vacuumlazy.c - lazy_vacuum_page[1250] - item 70 is now UNUSED
[...]
psql:script.sql:9: LOG:  patch - vacuumlazy.c - lazy_vacuum_page[1250] - item 199 is now UNUSED
psql:script.sql:9: LOG:  patch - vacuumlazy.c - lazy_vacuum_page[1250] - item 202 is now UNUSED
psql:script.sql:9: LOG:  patch - bufpage.c - PageRepairFragmentation[489] - compacting page (158 have storage, 46 are unused)
psql:script.sql:9: LOG:  patch - bufpage.c - PageRepairFragmentation[514] - compacting page (totallen 5056)
psql:script.sql:9: LOG:  patch - vacuumlazy.c - lazy_scan_heap[534] - working on block 1
psql:script.sql:9: LOG:  patch - vacuumlazy.c - lazy_scan_heap[629] - reading block
psql:script.sql:9: LOG:  patch - vacuumlazy.c - lazy_scan_heap[762] - pruning HOT update chains...
psql:script.sql:9: LOG:  patch - pruneheap.c - heap_page_prune[220] - 66 deleted items found
psql:script.sql:9: LOG:  patch - pruneheap.c - heap_page_prune_execute[691] - item 1 is now REDIRECTed to item 205
psql:script.sql:9: LOG:  patch - pruneheap.c - heap_page_prune_execute[691] - item 4 is now REDIRECTed to item 206
[...]
psql:script.sql:9: LOG:  patch - pruneheap.c - heap_page_prune_execute[691] - item 61 is now REDIRECTed to item 225
psql:script.sql:9: LOG:  patch - pruneheap.c - heap_page_prune_execute[691] - item 64 is now REDIRECTed to item 226
psql:script.sql:9: LOG:  patch - pruneheap.c - heap_page_prune_execute[702] - item 67 is now DEAD
psql:script.sql:9: LOG:  patch - pruneheap.c - heap_page_prune_execute[702] - item 70 is now DEAD
[...]
psql:script.sql:9: LOG:  patch - pruneheap.c - heap_page_prune_execute[702] - item 193 is now DEAD
psql:script.sql:9: LOG:  patch - pruneheap.c - heap_page_prune_execute[702] - item 196 is now DEAD
psql:script.sql:9: LOG:  patch - bufpage.c - PageRepairFragmentation[489] - compacting page (160 have storage, 0 are unused)
psql:script.sql:9: LOG:  patch - bufpage.c - PageRepairFragmentation[514] - compacting page (totallen 5120)
psql:script.sql:9: LOG:  patch - vacuumlazy.c - lazy_scan_heap[817] - item 67 DEAD
psql:script.sql:9: LOG:  patch - vacuumlazy.c - lazy_scan_heap[817] - item 70 DEAD
[...]
psql:script.sql:9: LOG:  patch - vacuumlazy.c - lazy_scan_heap[817] - item 193 DEAD
psql:script.sql:9: LOG:  patch - vacuumlazy.c - lazy_scan_heap[817] - item 196 DEAD
psql:script.sql:9: LOG:  patch - vacuumlazy.c - lazy_vacuum_page[1237] - block 1
psql:script.sql:9: LOG:  patch - vacuumlazy.c - lazy_vacuum_page[1250] - item 67 is now UNUSED
psql:script.sql:9: LOG:  patch - vacuumlazy.c - lazy_vacuum_page[1250] - item 70 is now UNUSED
[...]
psql:script.sql:9: LOG:  patch - vacuumlazy.c - lazy_vacuum_page[1250] - item 193 is now UNUSED
psql:script.sql:9: LOG:  patch - vacuumlazy.c - lazy_vacuum_page[1250] - item 196 is now UNUSED
psql:script.sql:9: LOG:  patch - bufpage.c - PageRepairFragmentation[489] - compacting page (160 have storage, 44 are unused)
psql:script.sql:9: LOG:  patch - bufpage.c - PageRepairFragmentation[514] - compacting page (totallen 5120)
psql:script.sql:9: LOG:  patch - vacuumlazy.c - lazy_scan_heap[534] - working on block 2
psql:script.sql:9: LOG:  patch - vacuumlazy.c - lazy_scan_heap[629] - reading block
psql:script.sql:9: LOG:  patch - vacuumlazy.c - lazy_scan_heap[762] - pruning HOT update chains...
psql:script.sql:9: LOG:  patch - pruneheap.c - heap_page_prune[220] - 0 deleted items found

Certains enregistrements bénéficient de HOT, mais la majorité deviennent UNUSED. Essayons avec un fillfactor de 50% :

psql:script.sql:9: LOG:  patch - vacuum.c - vacuum[117] - VACUUM on 0, toast included, no wraparound
psql:script.sql:9: LOG:  patch - vacuum.c - vacuum[249] - vacuuming 82240
psql:script.sql:9: LOG:  patch - vacuum.c - vacuum_rel[1207] - relation t2 (82240) opened with lockmode 4
psql:script.sql:9: LOG:  patch - vacuumlazy.c - lazy_vacuum_rel[194] - vacuuming...
psql:script.sql:9: LOG:  patch - vacuumlazy.c - lazy_scan_heap[465] - relation has 4 blocks
psql:script.sql:9: LOG:  patch - vacuumlazy.c - lazy_scan_heap[534] - working on block 0
psql:script.sql:9: LOG:  patch - vacuumlazy.c - lazy_scan_heap[629] - reading block
psql:script.sql:9: LOG:  patch - vacuumlazy.c - lazy_scan_heap[762] - pruning HOT update chains...
psql:script.sql:9: LOG:  patch - pruneheap.c - heap_page_prune[220] - 38 deleted items found
psql:script.sql:9: LOG:  patch - pruneheap.c - heap_page_prune_execute[691] - item 1 is now REDIRECTed to item 114
psql:script.sql:9: LOG:  patch - pruneheap.c - heap_page_prune_execute[691] - item 4 is now REDIRECTed to item 115
[...]
psql:script.sql:9: LOG:  patch - pruneheap.c - heap_page_prune_execute[691] - item 109 is now REDIRECTed to item 150
psql:script.sql:9: LOG:  patch - pruneheap.c - heap_page_prune_execute[691] - item 112 is now REDIRECTed to item 151
psql:script.sql:9: LOG:  patch - bufpage.c - PageRepairFragmentation[489] - compacting page (113 have storage, 0 are unused)
psql:script.sql:9: LOG:  patch - bufpage.c - PageRepairFragmentation[514] - compacting page (totallen 3616)
psql:script.sql:9: LOG:  patch - vacuumlazy.c - lazy_scan_heap[534] - working on block 1
psql:script.sql:9: LOG:  patch - vacuumlazy.c - lazy_scan_heap[629] - reading block
psql:script.sql:9: LOG:  patch - vacuumlazy.c - lazy_scan_heap[762] - pruning HOT update chains...
psql:script.sql:9: LOG:  patch - pruneheap.c - heap_page_prune[220] - 38 deleted items found
psql:script.sql:9: LOG:  patch - pruneheap.c - heap_page_prune_execute[691] - item 2 is now REDIRECTed to item 114
psql:script.sql:9: LOG:  patch - pruneheap.c - heap_page_prune_execute[691] - item 5 is now REDIRECTed to item 115
[...]
psql:script.sql:9: LOG:  patch - pruneheap.c - heap_page_prune_execute[691] - item 110 is now REDIRECTed to item 150
psql:script.sql:9: LOG:  patch - pruneheap.c - heap_page_prune_execute[691] - item 113 is now REDIRECTed to item 151
psql:script.sql:9: LOG:  patch - bufpage.c - PageRepairFragmentation[489] - compacting page (113 have storage, 0 are unused)
psql:script.sql:9: LOG:  patch - bufpage.c - PageRepairFragmentation[514] - compacting page (totallen 3616)
psql:script.sql:9: LOG:  patch - vacuumlazy.c - lazy_scan_heap[534] - working on block 2
psql:script.sql:9: LOG:  patch - vacuumlazy.c - lazy_scan_heap[629] - reading block
psql:script.sql:9: LOG:  patch - vacuumlazy.c - lazy_scan_heap[762] - pruning HOT update chains...
psql:script.sql:9: LOG:  patch - pruneheap.c - heap_page_prune[220] - 37 deleted items found
psql:script.sql:9: LOG:  patch - pruneheap.c - heap_page_prune_execute[691] - item 3 is now REDIRECTed to item 114
psql:script.sql:9: LOG:  patch - pruneheap.c - heap_page_prune_execute[691] - item 6 is now REDIRECTed to item 115
[...]
psql:script.sql:9: LOG:  patch - pruneheap.c - heap_page_prune_execute[691] - item 108 is now REDIRECTed to item 149
psql:script.sql:9: LOG:  patch - pruneheap.c - heap_page_prune_execute[691] - item 111 is now REDIRECTed to item 150
psql:script.sql:9: LOG:  patch - bufpage.c - PageRepairFragmentation[489] - compacting page (113 have storage, 0 are unused)
psql:script.sql:9: LOG:  patch - bufpage.c - PageRepairFragmentation[514] - compacting page (totallen 3616)
psql:script.sql:9: LOG:  patch - vacuumlazy.c - lazy_scan_heap[534] - working on block 3
psql:script.sql:9: LOG:  patch - vacuumlazy.c - lazy_scan_heap[629] - reading block
psql:script.sql:9: LOG:  patch - vacuumlazy.c - lazy_scan_heap[762] - pruning HOT update chains...
psql:script.sql:9: LOG:  patch - pruneheap.c - heap_page_prune[220] - 21 deleted items found
psql:script.sql:9: LOG:  patch - pruneheap.c - heap_page_prune_execute[691] - item 1 is now REDIRECTed to item 62
psql:script.sql:9: LOG:  patch - pruneheap.c - heap_page_prune_execute[691] - item 4 is now REDIRECTed to item 63
[...]
psql:script.sql:9: LOG:  patch - pruneheap.c - heap_page_prune_execute[691] - item 58 is now REDIRECTed to item 81
psql:script.sql:9: LOG:  patch - pruneheap.c - heap_page_prune_execute[691] - item 61 is now REDIRECTed to item 82
psql:script.sql:9: LOG:  patch - bufpage.c - PageRepairFragmentation[489] - compacting page (61 have storage, 0 are unused)
psql:script.sql:9: LOG:  patch - bufpage.c - PageRepairFragmentation[514] - compacting page (totallen 1952)

Dans ce cas, tous les enregistrements bénéficient de HOT, aucun n'est UNUSED. Cela permet des mises à jour et une maintenance plus rapides, mais c'est au prix d'une table plus volumineuse (sur disque et dans le cache des relations de PostgreSQL).

Et du coup, vous vous demandez peut-être quand va sortir la version beta 0.3 du livre ? D'ici peu a priori. Un peu de relecture, quelques ajustements de dernières minutes, et ça devrait être prêt :)

Annexes

Ajouter un commentaire

Les commentaires peuvent être formatés en utilisant une syntaxe wiki simplifiée.

La discussion continue ailleurs

1. Le vendredi, avril 24 2015, 08:45 par Anonymous blog

LdS S17-2015 | Anayrat.info

(…) Postgres : Analyse du VACUUM (…)

Fil des commentaires de ce billet