Suivi de l’AUTOVACUUM

Impact, durée, bénéfice d’un AUTOVACUUM

Alerte !

      Sur un système de production une alerte Nagios est levée :


***** Notification Centreon ***** Type de notification : PROBLEM Service impacté : Postgres-Wal-Size Etat : WARNING Hôte associé : Serveur Linux Debian XXXXXX (Sauvegarde Postgres pour Moteur de Chiffrement XXXXXXX) [dmz] Adresse : XXXXXX.XXXXXX.XXX Date/Heure : 02-12-2016 13:47:22 Information sur le contrôle : Taille totale des WAL : 7.5 ( 7 GiB) Accès direct au service impacté : Centreon

Que se passe-t-il ?

      Cette alerte s’appuie sur les capacités de l’outil de sauvegarde Barman (commande "barman list-backup"). Elle est déclenchée lorsqu’un volume de WAL (write-ahead log, fichiers de journalisation) produit depuis la dernière sauvegarde est jugé anormal pour un cluster donné. Cela permet notamment de détecter rapidement des anomalies applicatives (flood) et de transmettre l’information à l’équipe concernée. Quelle est cette fois la raison de son déclenchement ? Le traqueur n’indique aucune activité applicative anormale mais il note la présence en continu d’AUTOVACUUM parmi les sessions actives comme le confirme un simple SELECT sur pg_stat_activity :

\x SELECT version(); -[ RECORD 1 ]------------------------------------------------------------------------------------------ version | PostgreSQL 9.4.8 on x86_64-unknown-linux-gnu, compiled by gcc (Debian 4.9.2-10) 4.9.2, 64-bit SELECT * FROM pg_stat_activity; -[ RECORD 1 ]----+--------------------------------------------- datid | 1175159 datname | coffre001 pid | 17372 usesysid | 10 usename | postgres application_name | client_addr | client_hostname | client_port | backend_start | 2016-12-02 13:03:52.98543+01 xact_start | 2016-12-02 13:03:53.006873+01 query_start | 2016-12-02 13:03:53.006873+01 state_change | 2016-12-02 13:03:53.006875+01 waiting | f state | active backend_xid | backend_xmin | 2587905 query | autovacuum: VACUUM pg_toast.pg_toast_1203372

Quelle table est concernée ?

      AUTOVACUUM s’est réveillé le 02/12 à 13h03 et travaille sur pg_toast_1203372. VACUUM est une opération constituant à répérer l’espace occupé par des lignes "mortes" après une mise à jour ou une suppression. Les lignes sont mortes quand elles ne sont plus nécessaires pour aucune transaction. Un VACUUM classique restitue logiquement l’espace tandis qu’un VACUUM FULL restitue véritablement cet espace au système de fichiers, mais au prix d’un verrouillage exclusif sur la table concernée. Les opérations effectuées par AUTOVACUUM sont des VACUUM classiques déclenchés automatiquement quand un seuil de lignes mortes a été atteint. Ici cela concerne une table pg_toast. Une table pg_toast est une table obtenue en complément d’une table principale lorsque les colonnes de type VARCHAR dépassent une taille limite (2000 octets). Il faut obtenir davantage d’informations :

WITH rel_set AS ( SELECT oid, CASE split_part(split_part(array_to_string(reloptions, ','), 'autovacuum_vacuum_threshold=', 2), ',', 1) WHEN '' THEN NULL ELSE split_part(split_part(array_to_string(reloptions, ','), 'autovacuum_vacuum_threshold=', 2), ',', 1)::BIGINT END AS rel_av_vac_threshold, CASE split_part(split_part(array_to_string(reloptions, ','), 'autovacuum_vacuum_scale_factor=', 2), ',', 1) WHEN '' THEN NULL ELSE split_part(split_part(array_to_string(reloptions, ','), 'autovacuum_vacuum_scale_factor=', 2), ',', 1)::NUMERIC END AS rel_av_vac_scale_factor FROM pg_class ) SELECT PSAT.schemaname, PSAT.relname, to_char(PSAT.last_vacuum, 'YYYY-MM-DD HH24:MI') AS last_vacuum, to_char(PSAT.last_autovacuum, 'YYYY-MM-DD HH24:MI') AS last_autovacuum, to_char(C.reltuples, '9G999G999G999') AS n_tup, to_char(PSAT.n_dead_tup, '9G999G999G999') AS dead_tup, to_char(coalesce(RS.rel_av_vac_threshold, current_setting('autovacuum_vacuum_threshold')::BIGINT) + coalesce(RS.rel_av_vac_scale_factor, current_setting('autovacuum_vacuum_scale_factor')::NUMERIC) * C.reltuples, '9G999G999G999') AS av_threshold, CASE WHEN (coalesce(RS.rel_av_vac_threshold, current_setting('autovacuum_vacuum_threshold')::BIGINT) + coalesce(RS.rel_av_vac_scale_factor, current_setting('autovacuum_vacuum_scale_factor')::NUMERIC) * C.reltuples) < PSAT.n_dead_tup THEN '*' ELSE '' END AS expect_av FROM pg_stat_all_tables PSAT JOIN pg_class C ON PSAT.relid = C.oid JOIN rel_set RS ON PSAT.relid = RS.oid ORDER BY PSAT.schemaname, C.reltuples DESC; ... -[ RECORD 62 ]--+------------------------ schemaname | pg_toast relname | pg_toast_1203372 last_vacuum | last_autovacuum | 2016-09-13 21:01 n_tup | 10 238 673 dead_tup | 2 055 047 av_threshold | 2 047 785 expect_av | * ... SELECT 1203372::regclass; regclass ----------------- xxxxxx.datas (1 ligne) SELECT * FROM pg_class WHERE relname = 'datas'; -[ RECORD 1 ]--+-------- relname | datas relnamespace | 1175165 reltype | 1203374 reloftype | 0 relowner | 1175161 relam | 0 relfilenode | 1203372 reltablespace | 0 relpages | 21972 reltuples | 419257 relallvisible | 0 reltoastrelid | 1203377 relhasindex | t relisshared | f relpersistence | p relkind | r relnatts | 8 relchecks | 0 relhasoids | f relhaspkey | t relhasrules | f relhastriggers | f relhassubclass | f relispopulated | t relreplident | d relfrozenxid | 404079 relminmxid | 1 relacl | reloptions | \dt+ datas Liste des relations Schéma | Nom | Type | Propriétaire | Taille | Description -----------+-------+-------+--------------+--------+------------- xxxxxx | datas | table | xxxxxx | 153 GB | (1 ligne)

      La "grosse" requête adaptée d’une requête présentée sur stackoverflow confirme que le seuil de déclenchement de l’AUTOVACUUM a été atteint pour pg_toast_1203372. Cette table est liée à datas, la table principale de l’application pesant 153Go. L’opération dans laquelle s’est lancée AUTOVACUUM est donc conséquente.

Quel impact et quelle durée ?

      Il importe de savoir si l’opération ne va pas saturer l’espace d’archivage des fichiers de journalisation (WAL) sur le serveur Barman et accessoirement combien de temps va durer l’opération. Les données cryptées de la table se compressent mal, la taille compressée représente 80% de la taille originale. Cependant les WAL archivés compressés par Barman résultant de l’AUTOVACUUM ne devraient pas occuper plus de 123Go puisque la table fait 154Go. Que constatons-nous directement au niveau OS ?

-- sur le serveur PostgreSQL ls -ltr 1203377 1203377.* -rw------- 1 postgres postgres 1073741824 déc. 2 13:05 1203377 -rw------- 1 postgres postgres 1073741824 déc. 2 13:05 1203377.1 -rw------- 1 postgres postgres 1073741824 déc. 2 13:05 1203377.2 -rw------- 1 postgres postgres 1073741824 déc. 2 13:05 1203377.3 ... -rw------- 1 postgres postgres 1073741824 déc. 2 17:23 1203377.55 -rw------- 1 postgres postgres 427671552 déc. 2 17:30 1203377.151 -rw------- 1 postgres postgres 1073741824 déc. 2 17:30 1203377.56 -rw------- 1 postgres postgres 1073741824 déc. 2 17:31 1203377.57 -- sur le serveur Barman barman list-backup xxxxxx_xx xxxxxx_xx 20161127T223001 - Sun Nov 27 22:50:19 2016 - Size: 149.7 GiB - WAL Size: 31.2 GiB (tablespaces: temp:/var/tmp/postgresql/9.4/xxxxxx) xxxxxx_xx 20161120T223002 - Sun Nov 20 23:02:48 2016 - Size: 145.5 GiB - WAL Size: 3.4 GiB (tablespaces: temp:/var/tmp/postgresql/9.4/xxxxxx) df -h Sys. de fichiers Taille Utilisé Dispo Uti% Monté sur ... /dev/mapper/vg01-barman 577G 229G 322G 42% /var/lib/barman ... -rw------- 1 barman barman 12460647 déc. 2 18:12 0000004700000240000000A2 -rw------- 1 barman barman 12461290 déc. 2 18:12 0000004700000240000000A3 ... -rw------- 1 barman barman 12455227 déc. 2 18:18 0000004700000240000000E2 -rw------- 1 barman barman 12461030 déc. 2 18:18 0000004700000240000000E3 -- 66 fichiers de 12,5Mo produits toutes les 7 minutes30

Un peu de calculs

      La table est physiquement découpée en 152 fichiers de 1Go, ce qui constitue le défaut. Les 35 premiers fichiers ayant déjà fait l’objet d’un AUTOVACUUM ont été traités rapidement (110 minutes) mais chaque fichier suivant est traité en 7 minutes 30 environ. La durée de l’opération devrait donc être logiquement de 110 + 7,5 X 117 = 987,5 minutes donc 16h30 environ. L’opération débuté à 13h03 devrait donc se terminer vers 5h30 le lendemain matin.
      La durée est une information intéressante mais il est plus important de savoir si nous allons manquer d’espace sur le serveur Barman. L’AUTOVACUUM ne dérange pas l’activité des utilisateurs mais l’administrateur système doit-il étendre le filesystem pour éviter un incident ?
      Un calcul est nécessaire. L’espace est occupé par les sauvegardes et par les WAL compressés. Tout d’abord les sauvegardes. Chaque fichier de la table datas a été retouché, il ne faudra pas compter sur la déduplication Barman, basée sur rsync et réalisée au niveau fichier. La sauvegarde est planifiée de manière hebdomadaire et la fenêtre de recover est de 5 jours donc il y a 2 sauvegardes FULL en ligne au maximum. Elles occuperont environ 150 + 160 = 310Go. A présent les WAL. 825Mo de fichiers WAL compressés sont produits par fichier subissant l’AUTOVACUUM donc au maximum 122Go, ce qui rejoint l’estimation obtenue à partir de la taille de la table datas et du taux de compression de ses données. En fait les 35 premiers fichiers traité n’ont pas produit autant de WAL donc cette estimation est large, ce qui est préférable. L’espace de sauvegarde, pour l’instant affecté exclusivement à ce cluster, fait 577Go. 577Go c’est supérieur à 310 + 123 = 433Go donc l’opération pourra se terminer sans erreur. Comment s’est terminé l’AUTOVACUUM en pratique ?

-- sur le serveur PostgreSQL WITH rel_set AS ( SELECT oid, CASE split_part(split_part(array_to_string(reloptions, ','), 'autovacuum_vacuum_threshold=', 2), ',', 1) WHEN '' THEN NULL ELSE split_part(split_part(array_to_string(reloptions, ','), 'autovacuum_vacuum_threshold=', 2), ',', 1)::BIGINT END AS rel_av_vac_threshold, CASE split_part(split_part(array_to_string(reloptions, ','), 'autovacuum_vacuum_scale_factor=', 2), ',', 1) WHEN '' THEN NULL ELSE split_part(split_part(array_to_string(reloptions, ','), 'autovacuum_vacuum_scale_factor=', 2), ',', 1)::NUMERIC END AS rel_av_vac_scale_factor FROM pg_class ) SELECT PSAT.schemaname, PSAT.relname, to_char(PSAT.last_vacuum, 'YYYY-MM-DD HH24:MI') AS last_vacuum, to_char(PSAT.last_autovacuum, 'YYYY-MM-DD HH24:MI') AS last_autovacuum, to_char(C.reltuples, '9G999G999G999') AS n_tup, to_char(PSAT.n_dead_tup, '9G999G999G999') AS dead_tup, to_char(coalesce(RS.rel_av_vac_threshold, current_setting('autovacuum_vacuum_threshold')::BIGINT) + coalesce(RS.rel_av_vac_scale_factor, current_setting('autovacuum_vacuum_scale_factor')::NUMERIC) * C.reltuples, '9G999G999G999') AS av_threshold, CASE WHEN (coalesce(RS.rel_av_vac_threshold, current_setting('autovacuum_vacuum_threshold')::BIGINT) + coalesce(RS.rel_av_vac_scale_factor, current_setting('autovacuum_vacuum_scale_factor')::NUMERIC) * C.reltuples) < PSAT.n_dead_tup THEN '*' ELSE '' END AS expect_av FROM pg_stat_all_tables PSAT JOIN pg_class C ON PSAT.relid = C.oid JOIN rel_set RS ON PSAT.relid = RS.oid ORDER BY PSAT.schemaname, C.reltuples DESC; ... -[ RECORD 62 ]--+------------------------ schemaname | pg_toast relname | pg_toast_1203372 last_vacuum | last_autovacuum | 2016-12-03 05:20 n_tup | 76 521 016 dead_tup | 0 av_threshold | 15 304 253 expect_av | ... ls -ltr 1203377 1203377.* ... -rw------- 1 postgres postgres 1073741824 déc. 3 09:21 1203377 -rw------- 1 postgres postgres 1073741824 déc. 3 10:50 1203377.1 -rw------- 1 postgres postgres 1073741824 déc. 3 11:05 1203377.2 -rw------- 1 postgres postgres 1073741824 déc. 3 11:06 1203377.3 -rw------- 1 postgres postgres 1073741824 déc. 3 11:07 1203377.4 -rw------- 1 postgres postgres 1073741824 déc. 3 11:08 1203377.5 -rw------- 1 postgres postgres 1073741824 déc. 3 11:12 1203377.6 -rw------- 1 postgres postgres 1073741824 déc. 3 11:12 1203377.7 -rw------- 1 postgres postgres 1073741824 déc. 3 11:16 1203377.8 -rw------- 1 postgres postgres 1073741824 déc. 3 11:56 1203377.9 -rw------- 1 postgres postgres 1073741824 déc. 3 13:11 1203377.10 -rw------- 1 postgres postgres 643317760 déc. 3 14:05 1203377.151 -rw------- 1 postgres postgres 1073741824 déc. 3 14:41 1203377.11 -rw------- 1 postgres postgres 1073741824 déc. 3 15:40 1203377.12 -rw------- 1 postgres postgres 1073741824 déc. 3 16:35 1203377.13 -- sur le serveur Barman apres la 1ere sauvegarde suivant l’autovacuum barman list-backup xxxxxx_xx xxxxxx_xx 20161204T223001 - Mon Dec 5 00:49:22 2016 - Size: 154.3 GiB - WAL Size: 0 B (tablespaces: temp:/var/tmp/postgresql/9.4/xxxxxx) xxxxxx_xx 20161127T223001 - Sun Nov 27 22:50:19 2016 - Size: 149.7 GiB - WAL Size: 102.7 GiB (tablespaces: temp:/var/tmp/postgresql/9.4/xxxxxx) df -h Sys. de fichiers Taille Utilisé Dispo Uti% Monté sur ... /dev/mapper/vg01-barman 577G 407G 144G 74% /var/lib/barman ...

Conclusion

      L’AUTOVACUUM s’est achevé à 5h20 conformément à la prévision. Les WAL compressés occupent un peu moins de 103Go ce qui est également conforme à ce qui était attendu. PostgreSQL 9.4 est la version fournie avec Debian 8 "Jessie" qui est la version stable en décembre 2016 mais il faut noter que PostgreSQL 9.6, version fournie par défaut avec Debian 9 "Stretch", dispose d’une vue permettant de déterminer plus aisément l’avancement d’une opération d’AUTOVACUUM : pg_stat_progress_vacuum
      Je conseille évidemment de laisser AUTOVACUUM configuré par défaut dans la majeure partie des situations. Son action a été bénéfique puisque la taille de la base ne progresse plus, l’espace libéré logiquement étant réutilisé progressivement comme le montre le dernier "ls".
      AUTOVACUUM peut cependant ici être désactivé de manière ciblée en raison de la nature des données et de l’application. Dans quelques mois, lorsque le cluster actuel aura atteint un seuil au niveau stockage, un nouveau cluster PostgreSQL accueillera la base active. Une purge applicative aura lieu sur l’ancienne base et les données résiduelles seront intégrées dans le nouveau cluster : le travail effectué par AUTOVACUUM est donc ici prématuré mais c’est un cas très particulier. Afin de prendre en compte cette désactivation ciblée il suffit de passer :

ALTER TABLE xxxxx SET (autovacuum_enabled = true, toast.autovacuum_enabled = false); ALTER TABLE

      AUTOVACUUM ne s’occupera ainsi plus de la volumineuse table TOAST associée à la table xxxxx, laissant le DBA s’en occuper à sa convenance.

Mise à jour : 05/12/2016