Vous n'êtes pas identifié(e).
Pages : 1
Bonjour à tous
Je suis perplexe face au comportement de Postgres.
Nous avons eu récemment une corruption de 2 de nos databases (PG9.6.21) suite à un incident réseau et une coupure électrique de nos noeuds sur les 3 DC que nous possédons.
La corruption semblait être du même type sur les 2:
ERROR: could not access status of transaction xxxxxx
DETAIL: Could not open file "pg_clog/yyyy": file not foundSur notre 1er cluster:
La corruption a pu être réduite à un unique enregistrement, plus particulièrement à 2 colonnes de cette ligne.
1.
select * from mytable => ERROR sur master, OK sur slave
2.
select * from mytable where id<>corrupted_record_id => ok sur master et slave
3.
select * from mytable where id=corrupted_record_id => ERROR sur master, OK sur slave
4.
select all_but_2_columns from mytable where id=corrupted_record_id => ok sur master et slave
5.
select identified_2_colums from mytable where id=corrupted_record_id => ERROR sur master, OK sur slave
6.
vacuum full mytable => ERROR
7.
pg_dump -t mytable => ERROR sur master, OK sur slave
8.
pg_dumpall => ERROR sur master, OK sur slave
9.
delete from mytable where id=corrupted_record_id => ERROR
10.
update mytable set corrupted_col_1=<its_value_on_slave>, corrupted_col_2=<its_value_on_slave> where id=corrupted_record_id=> ERROR
Nous en avons conclu qu'il n'y avait pas de perte de données mais uniquement un problème d'accès aux données de cette ligne.
Nous avons donc décidé de promote le slave en master.
Cela dit, une fois fait, le problème est apparu / persiste sur le nouveau master et a disparu sur l'ancien master devenu slave.
1ère question : pourquoi ? En quoi le rôle du noeud peut-il impacter la map de visibilité ? Ou qu'avons-nous raté ici ?
Le fix appliqué (pour ceux qui auraient la même situation):
. stop applications on that database only (1 db = 1 customer, multiple db per instance in our case, live 24/7 critical db)
. check slave is 100% sync
. dump data from table on slave
. truncate table on master
. restore data into that table on master
. reindexdb + vacuum analyze
. restart apps
Sur la 2e cluster:
Après la 1ère corruption (apparue immédiatement suite à l'incident), nous avons décidé de faire un dumpall sur l'ensemble de nos clusters et avons identifié un 2e avec le même message d'erreur.
Contrairement au 1er cluster, pas de plainte client ou de blocage fonctionnel à ce moment.
Du coup, nous n'avons pas fixé, nous avons relancé un dumpall 4 fois.
Pour 4 ? parce qu'un dumpall sur ce cluster dure entre 3 et 4h, et que le résultat a varié d'une exécution à l'autre :
1st iteration: corruption detected, error on database X, objID Y
2nd iteration: corruption detected, error on database U, objID V
3rd iteration: ok
4th iteration: ok
5th iteration: ok
Comment une telle évolution est-elle possible ?
Ma théorie:
* je comprends qu'une page est marqué comme obsolète à partir du moment ou toutes les lignes auxquelles elle fait référence sont également marquées comme obsolètes
* la page était marquée obsolète mais l'une de ses lignes ne l'était pas => corruption de la page. Vérifié avec l'extension pg_visibility et la requête suivante:
SELECT oid::regclass AS relname FROM pg_class WHERE relkind IN ('r', 'm') AND (EXISTS (SELECT * FROM pg_check_visible(oid)) OR EXISTS (SELECT * FROM pg_check_frozen(oid))); * à un moment, qqch se passe et la ligne en question devient marquée comme obsolète => la page n'est plus corrompue puisque toutes ses lignes sont effectivement obsolètes
Mais:
Je suis vraiment perplexe sur cette étape "qqch se passe" (en assumant que ma théorie soit techniquement correcte). Comment Postgres parvient-il a marqué une ligne obsolète alors qu'il n'arrive pas à y accéder et que manuellement, nous n'avons pas réussi non plus à l'altérer ?
Surtout, si une corruption peut disparaitre de la sorte, peut-elle également (re)apparaître de la même sorte ?
Finallement:
==> comment détecter avec fiabilité une telle corruption (en cours ou à venir) ?
==> comment prévenir qu'elle ne se reproduise sur une DB où elle s'est déjà produite ? (un restore est-il vraiment fiable ou peut-il embarquer le problème)
Dernière modification par asphator (30/04/2021 15:12:29)
Hors ligne
This is a french forum. If you need help in english, you should better go to PostgreSQL mailing lists. See https://www.postgresql.org/list/
If you speak french, we can resume in french.
Guillaume.
Hors ligne
Oups.
J'ai tout traduit, merci d'avoir précisé.
Hors ligne
6.
vacuum full mytable=> ERROR sur master, OK sur slave
Je ne suis pas certain de comprendre cette étape. Avez-vous effectué un VACUUM FULL mytable sur les 2 serveurs (ce qui implique donc une réplication logique), ou uniquement sur le primaire et suite à ça l'erreur lors du SELECT n'apparait plus sur le secondaire mais toujours sur le primaire ?
Julien.
https://rjuju.github.io/
Hors ligne
Bonjour,
Je ne suis pas certain de comprendre la relation que vous faites entre l'erreur suivante et la visilibty map:
ERROR: could not access status of transaction xxxxxx
DETAIL: Could not open file "pg_clog/yyyy": file not foundDe plus, la visibility map ne consigne pas les "pages obsolètes", mais les blocs où toutes les lignes sont visibles (voir freeze). Les espace disponibles dans les blocs sont consignés dans le FSM associé à la table.
Je suppose donc que vos corruptions ont affecté plusieurs mécaniques distinctes, et entre autre la cohérence entre certains fichiers de données et la VM associée.
Concernant les clog, une ligne fait manifestement référence à une transaction plus ancienne que l'actuel horizon connu. Cet horizon bouge entre autre lors des vacuum. Il se peut que l'action d'un vacuum qui aura supprimé le clog en question suite à son travail de freeze ait été perdu. Reste à savoir comment cela est possible. Corruption matériel ? fysnc=off ? perte d'un cache sans BBU au fond d'une baie SAN ?
Concernant la détection des corruptions des VM, votre requête semble suffisante. La correction quand à elle peut se faire avec un appel à pg_truncate_visibility_map() suivit d'un vacuum sur la table.
Cependant, si vous arrivez à trouver de telles corruptions, la première action consiste probablement à faire une sauvegarde physique de l'instance, puis identifier les composant matériel ou de configuration à l'origine de cette corruption.
Hors ligne
Concernant les clog, une ligne fait manifestement référence à une transaction plus ancienne que l'actuel horizon connu. Cet horizon bouge entre autre lors des vacuum. Il se peut que l'action d'un vacuum qui aura supprimé le clog en question suite à son travail de freeze ait été perdu. Reste à savoir comment cela est possible. Corruption matériel ? fysnc=off ? perte d'un cache sans BBU au fond d'une baie SAN ?
Ou plus simplement corruption d'un xmin/xmax, soit d'une ligne de la table soit de la table TOAST associée.
Julien.
https://rjuju.github.io/
Hors ligne
@rjuju:
pardon, j'ai corrigé pour le vacuum full. Non, il n'a été fait que sur le master. La replication est du streaming.
nous sommes sur du full ssd + serveurs physiques + lien 10G + iscsi + rhel6 côté infra.
@ioguix:
fsync à on.
le lien que je fais est que les pg_clog contiennent les historiques de commits/transactions qui permet ensuite à la map de visibilité de savoir quelles sont les lignes à afficher ou non, or, s'il lui manque un fichier clog, il n'est plus capable d'assurer l'intégrité de sa map de visibilité (ou si j'ai mal compris, je veux bien qu'on me corrige svp 
). J'aurais bien rejoué WAL par WAL depuis mon dernier backup jusqu'à l'apparition de ce fichier pour le réintégrer, mais avec 2T de wal par jour, ce n'est pas la 1ère option qui a été envisagée.
Pour le pg_truncate_visibility_map, il me semble que cela permet effectivement que la ligne s'affiche à nouveau mais au risque/prix d'en voir d'autres qui étaient freeze ou delete réapparaitre également. Or, comme on avait la ligne sur le slave, on n'a pas choisi cette option.
Dernière modification par asphator (30/04/2021 15:29:25)
Hors ligne
le lien que je fais est que les pg_clog contiennent les historiques de commits/transactions qui permet ensuite à la map de visibilité de savoir quelles sont les lignes à afficher ou non, or, s'il lui manque un fichier clog, il n'est plus capable d'assurer l'intégrité de sa map de visibilité (ou si j'ai mal compris, je veux bien qu'on me corrige svp
Effectivement, mais uniquement pour les lignes non "freezées", sinon vous auriez un problème passé quelques milliards de transactions (en plus de devoir conserver un historique de l'intégralité des transactions exécutées, ce qui serait très volumineux).
Donc soit le fichier clog était le bon et il n'était pas accessible (à priori peu plausible), soit le xmin/xmax des lignes en question était corrompu et pointait vers un numéro de transaction invalide, ce qui fait que le fichier clog manquant est tout à fait normal.
Le seul moyen de savoir serait de regarder le numéro de transaction et de le comparer au numéro de transaction courant et du datfrozenxid, pour savoir s'il est valide ou non.
Au passage il est possible que la coupure électrique soit totalement sans rapport avec le problème, outre le fait que cela ait entrainé un redémarrage du serveur et donc la suppression du cache postgres et du cache OS ce qui aurait pu tout simplement révéler une corruption survenue des jours ou des mois plus tôt. S'il s'agit de lignes utilisées en permanence dans l'application, cela serait très probable.
Julien.
https://rjuju.github.io/
Hors ligne
Le fichier était vraiment physiquement absent.
Du coup, la méthode du dumpall pour détecter la corruption est-elle suffisante ?
Faudrait-il (dans l'idéal) reboot l'ensemble de nos noeuds avant de refaire un dumpall pour mettre en évidence une corruption ?
Faire un script pour check chaque transaction vs le courant et son datfrozenxid me parait un peu compliqué (sauf si une extension fait déjà cela) ?
Egalement, nous avions essayé de delete / update la ligne, mais peut-être que la forcer/marquer comme frozen pourrait suffir (si cela est possible manuellement) ?
Hors ligne
le lien que je fais est que les pg_clog contiennent les historiques de commits/transactions qui permet ensuite à la map de visibilité de savoir quelles sont les lignes à afficher ou non, or, s'il lui manque un fichier clog, il n'est plus capable d'assurer l'intégrité de sa map de visibilité (ou si j'ai mal compris, je veux bien qu'on me corrige svp smile )
les clog contiennent l'état des transactions et ont donc un impact sur la visibiblités des lignes en fonction que la transaction soit en cours, annulée ou validée. Mais quand vous parlez de visibility map, on parle d'une autre mécanique, dont la partie visible sont les fichiers "_vm" et les fonctions de l'extension pgvisibility que vous utilisez ici. Ces visibility map n'ont rien à voir avec les clog. Comme je l'écrivais, ce n'est qu'une optimisation du moteur lui permettant de déterminer rapidement si l'ensemble des lignes d'un bloc sont visibles, voir même freezées.
Faire appel à pg_truncate_visibility_map() ne pose aucun risque de corruption, il ne fait que remettre à zéro la visibility map associée aux fichiers de la table concernée, forçant le vacuum et vos requêtes à parcourir TOUS les blocs de la table et à valider la visibilité (dans les clog notamment) ligne à ligne.
J'aurais bien rejoué WAL par WAL depuis mon dernier backup jusqu'à l'apparition de ce fichier pour le réintégrer, mais avec 2T de wal par jour, ce n'est pas la 1ère option qui a été envisagée.
Je pense qu'on approche du problème. En théorie, votre instance aurait dû rejouer les WAL créés depuis son dernier checkpoint (et non depuis son dernier backup) automatiquement. Vous pouvez par ailleurs lui indiquer où trouver les WAL archivés grâce à l'"archive_command" si les WAL locaux sont considérés comme corrompus ou incomplets.
Le rejeu des WAL aurait dû remettre d'équerre et en cohérence, clog, VM et données. Ce qui n'est manifestement pas le cas ici. Je m'intérroge donc sur la méthode avec laquelle l'instance a été démarrée.
Si la rejeu des WAL "n'est pas la 1ère option qui a été envisagée", comment avez vous démarré vos instances ? Ces dernières ont-elles pu rejouer les WAL produits depuis leur dernier checkpoint valide connu ?
Hors ligne
Du coup, la méthode du dumpall pour détecter la corruption est-elle suffisante ?
Faudrait-il (dans l'idéal) reboot l'ensemble de nos noeuds avant de refaire un dumpall pour mettre en évidence une corruption ?
Faire un script pour check chaque transaction vs le courant et son datfrozenxid me parait un peu compliqué (sauf si une extension fait déjà cela) ?Egalement, nous avions essayé de delete / update la ligne, mais peut-être que la forcer/marquer comme frozen pourrait suffir (si cela est possible manuellement) ?
J'insiste, avant de se poser ces questions et y trouver des réponses, il faut comprendre comment ces corruptions ont pu apparaître. Et au risque de paraître désagréable, rien pour le moment ne nous indique que la méthode employée pour démarrer les instances ait été fiable ou n'ait pas provoqué ces corruptions justement...
Comment les instances ont démarrés ? Avez vous des erreurs dans vos log ? Ont-elles bien démarré en mode recovery ? Ont-elles rejoués tous les WAL présents dans leur pg_wal ? Ceux-ci étaient ils complets ? ...
Hors ligne
Aucun désagrément tant que c'est constructif donc je prends. Désolé si l'urgence ma facette prod ressort parfois ^^
Les instances ont été redémarrées avec pg_ctl -D et aucune autre option particulière. Il n'y a eu aucun problème pour le rejeu des WAL ou la réouverture de l'instance. Les seules erreurs dans les logs concernent les tentatives d'accès à la table en question - une fois la base déjà up - lorsque la requête tente de remonter la ligne défectueuse. Je n'ai aucun WAL perdu ou problème d'archivage (qui se fait sur un serveur tiers). Et ma "restore_command" est également bien configuré. Mon master et mes slaves ont bien retrouvés leurs petits. Consistent recovery state reached.
Je crois qu'il y a confusion pour le backup. Je voulais dire que j'ai envisagé de restore un backup full sur un serveur tiers puis de lui faire rejouer les WAL un par un jusqu'à ce que ce fichier pg_clog manquant resurgisse pour ensuite aller le copier sur la vraie prod où il est marqué comme not found. Je n'ai pas pour autant fait de restore de ma base de prod, j'ai juste redémarré les instances et grep les erreurs (il n'y en a pas eu au démarrage).
J'ai remarqué que les fichiers dans pg_clog s'incrémentent dans le temps, manque de bol, mon dernier backup (datant d'avant l'incident) ne possède déjà plus ce fichier avant même de commencer à rejouer les WAL. Cela semble donc rejoindre la piste d'un problème latent depuis un moment et effectivement peut-être pas lié à l'incident réseau.
Hors ligne
Les instances ont été redémarrées avec pg_ctl -D et aucune autre option particulière. Il n'y a eu aucun problème pour le rejeu des WAL ou la réouverture de l'instance. Les seules erreurs dans les logs concernent les tentatives d'accès à la table en question - une fois la base déjà up - lorsque la requête tente de remonter la ligne défectueuse. Je n'ai aucun WAL perdu ou problème d'archivage (qui se fait sur un serveur tiers). Et ma "restore_command" est également bien configuré. Mon master et mes slaves ont bien retrouvés leurs petits. Consistent recovery state reached.
OK, la phase de rejeu semble donc s'être déroulée convenablement. Par acquis de conscience, pourriez-vous retrouver les messages avant et après la fin de la période de recovery sur l'instance principale ?
Je voulais dire que j'ai envisagé de restore un backup full sur un serveur tiers puis de lui faire rejouer les WAL un par un jusqu'à ce que ce fichier pg_clog manquant resurgisse pour ensuite aller le copier sur la vraie prod où il est marqué comme not found.
Ce n'est jamais trop une bonne idée de manipuler soit même ces fichiers à la main.
Mais ce fichier n'a peut-être pas lieu d'exister. Le problème peut venir d'une corruption dans les entêtes des lignes. Vous pouvez vérifier cela en comparant l'age de vos bases (datfrozenxid dans pg_database) avec le premier clog disponible (dans pg_xact ou pg_clog). Pensez bien que chaque transaction utilise 2 bits et que chaque fichier clog a une taille maximale de 256k, ce qui nous fait 1048576 de transaction par fichier clog (0x100000 en hexa, pratique). N'hésitez pas à coller ici ces informations.
Aussi, il pourrait être intéressant de récupérer les valeurs de xmin/xmax pour la ligne "corrompue" (mais accessible) sur le standby. Coté primaire, vous pouvez peut-être essayer de lire les entête de la ligne fautive grace à l'extension pageinspect et la fonction heap_page_items(). Voir pour un exemple de requête: https://www.postgresql.org/docs/current … spect.html
Comparer toutes ces valeurs entre elles (xmin/xmax, relfrozenxid, datfrozenxid, fichiers clog disponibles, denrière transaction connue, etc ) pourrait nous permettre de détecter où se trouve l'anomalie.
J'ai remarqué que les fichiers dans pg_clog s'incrémentent dans le temps, manque de bol, mon dernier backup (datant d'avant l'incident) ne possède déjà plus ce fichier avant même de commencer à rejouer les WAL. Cela semble donc rejoindre la piste d'un problème latent depuis un moment et effectivement peut-être pas lié à l'incident réseau.
Je doute qu'un problème réseau puisse corrompre une instance. Quel type de scénario imaginez vous ?
Hors ligne
Pages : 1