PostgreSQL DELETE FROM schlägt mit `Fehler: Versuch, unsichtbares Tupel zu löschen` fehl

25

Der Fehler

Versuch, Tupel mit ungültigen Zeitstempeln mit zu löschen

DELETE FROM comments WHERE date > '1 Jan 9999' OR date < '1 Jan 2000' OR date_found > '1 Jan 9999' OR date_found < '1 Jan 2000';

endet in

ERROR:  attempted to delete invisible tuple

Es gibt eine Mailingliste aus dem Jahr 2009 , die genau dieselbe Fehlermeldung behandelt, bei der OP sie behoben hat, aber ich finde keine Erklärung dafür, wie er es getan hat oder was möglicherweise zu diesem Fehler geführt hat.

Ich bin hilflos wegen fehlender Zugriffe auf Google und wegen meiner begrenzten Kenntnisse von PostgreSQL.

Was zur Korruption geführt hat

Ich hatte einen PostgreSQL 9.5.5-Server ( ~ 4 TB Daten, alle Standardeinstellungen, mit Ausnahme von erhöhten Speichergrenzen ) unter Debian 8, als der Betriebssystemkern in Panik geriet - wahrscheinlich während der Neuerstellung von / dev / md1, auf dem sich Swap befand. Zuvor hatte PostgreSQL fast den gesamten Speicherplatz mit einer 400-GB-Protokolldatei belegt. Das Betriebssystem wurde nie wieder gestartet, die Festplattenüberprüfungen waren in Ordnung, daher habe ich von einer LiveCD gebootet und jedes Blockgerät auf Images gesichert, nur für den Fall. Ich habe / directory erfolgreich aus / dev / md2 wiederhergestellt, fsck hat ein sauberes Dateisystem angezeigt und ich habe den PGDATA-Ordner auf einer externen Festplatte gesichert.

Was ich getan habe, um die Genesung zu versuchen

Nachdem ich md-Geräte formatiert und das Betriebssystem zusammen mit einem neuen postgresql-9.5 neu installiert habe, habe ich den PostgreSQL-Server gestoppt, den PGDATA-Ordner an postgres-Benutzer verschoben und dort abgelegt und den Server gestartet - alles schien in Ordnung zu sein, es gab keine Fehler.

Sobald ich angefangen habe pg_dumpall, ist es mit gestorben

Error message from server: ERROR:  timestamp out of range

Ich habe natürlich versucht, die beleidigenden Tupel zu löschen, nur um dasselbe zu erhalten invisible tuple um immer wieder Fehler zu erhalten.

Dinge, die ich versucht habe

Zuallererst sind DELETE-Abfragen wegen beschädigter Seiten fehlgeschlagen, daher habe ich folgende Einstellungen vorgenommen:

zero_damaged_pages = on
ignore_system_indexes = on
enable_indexscan = off
enable_bitmapscan = off
enable_indexonlyscan = off

Jetzt ist mir aufgefallen, dass der Server beim erneuten Ausführen der gleichen Abfragen immer wieder die gleichen Seiten auf Null setzt und nicht sicher ist, was dies bedeutet:

invalid page in block 92800 of relation base/16385/16443; zeroing out page

Ich habe versucht, in einer undefinierten Reihenfolge zu folgen:

  • pg_resetxlog -D $PGDATA hat seine Arbeit ohne Fehler oder Meldungen erledigt
  • Löschte alle Indizes einschließlich pkey Einschränkungen

  • CREATE TABLE aaa AS (SELECT * FROM comments); führt zu Segmentation fault weiter

    heap_deform_tuple (tuple=tuple@entry=0x7f0d1be29b08, tupleDesc=tupleDesc@entry=0x7f0d1a35abe0, values=values@entry=0x7ffd57a5beb0, isnull=isnull@entry=0x7ffd57a65af0 "\001\001") Es ist reproduzierbar und hinterlässt einen Core-Dump von ~ 9 GB.

  • SELECT COUNT(*) from comments;darf VACUUM comments;abgeschlossen werden, der gleiche Trick funktioniert nicht für andere Tabellen.
  • SELECT COUNT(*) from photos;und VACUUM photos;jetzt stirbt mit ERROR: MultiXactId 302740528 has not been created yet -- apparent wraparound- dieser verfolgt jeden Tisch, an dem andere Fehler nicht mehr auftauchen.

Gedanken

  • DB wurde von vielen ( möglicherweise doppelten ) Schreibvorgängen mit ON CONFLICTKlauselVACUUM überhäuft. DB hat einen Fehler gemacht, als Kernel-Panik auftratnonexistent MultiXactIds undinvisible tuple
  • Daten wurden mit Crawler über einen Zeitraum von mehr als 2 Jahren gesammelt, und ich bin völlig in Ordnung, wenn ich etwas davon verliere
  • Jetzt mache ich Backups
  • Es gab keine relationalen Einschränkungen zwischen Tabellen oder Trigger

Hier ist die Ausgabe von pg_controldata:

pg_control version number:            942
Catalog version number:               201510051
Database system identifier:           6330224129664261958
Database cluster state:               in production
pg_control last modified:             Thu 08 Dec 2016 01:06:22 AM EET
Latest checkpoint location:           1562/8F9F8A8
Prior checkpoint location:            1562/8F7F460
Latest checkpoint's REDO location:    1562/8F9F8A8
Latest checkpoint's REDO WAL file:    000000010000156200000008
Latest checkpoint's TimeLineID:       1
Latest checkpoint's PrevTimeLineID:   1
Latest checkpoint's full_page_writes: on
Latest checkpoint's NextXID:          0/40781255
Latest checkpoint's NextOID:          67798231
Latest checkpoint's NextMultiXactId:  1
Latest checkpoint's NextMultiOffset:  0
Latest checkpoint's oldestXID:        615
Latest checkpoint's oldestXID's DB:   1
Latest checkpoint's oldestActiveXID:  0
Latest checkpoint's oldestMultiXid:   1
Latest checkpoint's oldestMulti's DB: 1
Latest checkpoint's oldestCommitTsXid:0
Latest checkpoint's newestCommitTsXid:0
Time of latest checkpoint:            Thu 08 Dec 2016 01:06:22 AM EET
Fake LSN counter for unlogged rels:   0/1
Minimum recovery ending location:     0/0
Min recovery ending loc's timeline:   0
Backup start location:                0/0
Backup end location:                  0/0
End-of-backup record required:        no
wal_level setting:                    minimal
wal_log_hints setting:                off
max_connections setting:              100
max_worker_processes setting:         8
max_prepared_xacts setting:           0
max_locks_per_xact setting:           64
track_commit_timestamp setting:       off
Maximum data alignment:               8
Database block size:                  8192
Blocks per segment of large relation: 131072
WAL block size:                       8192
Bytes per WAL segment:                16777216
Maximum length of identifiers:        64
Maximum columns in an index:          32
Maximum size of a TOAST chunk:        1996
Size of a large-object chunk:         2048
Date/time type storage:               64-bit integers
Float4 argument passing:              by value
Float8 argument passing:              by value
Data page checksum version:           0

Aktualisierung

  • ( 9. Dezember 2016 ) Beim Lesen der Informationen zu nicht vorhandenen MultiXactIds ist mir eingefallen , dass meine Datenbank zum Zeitpunkt des Absturzes nicht ausgelastet war, aber eine manuelle VACUUMAnforderung verarbeitet wurde. Ich habe die Webserver und Crawler offline geschaltet, nachdem ich festgestellt habe, dass nur noch 3% Speicherplatz auf den Festplatten vorhanden sind. Ich hätte /var/lognach großen Dateien VACUUM FULLsuchen sollen , aber ich habe versehentlich PostgreSQL beschuldigt und versucht , sie abzubrechen, da auf dem Gerät nur noch wenig Speicherplatz vorhanden ist. Also habe ich mit normalem VACUUM angefangen und es dabei belassen.
  • ( 14. Dezember 2016 ) Github hat einen 9.5-Zweig von PostgreSQL-Quellen heruntergeladen und Blöcke in heapam.c und multixact.c auskommentiert und mit der Hoffnung kompiliert, dass diese Fehler nicht werden. Der Server konnte jedoch nicht gestartet werden, da er mit denselben Flags konfiguriert werden musste, die in einem von APT verwendeten verwendet wurden. Es gab ungefähr 47 Flaggen, von denen jede eine Abhängigkeit mit einem nicht offensichtlichen Namen erforderte, also gab ich diese Idee auf.

  • ( 16. Dezember 2016 ) Ich habe einen Weg gefunden, um Tupel mit ungültigen Zeitstempeln loszuwerden, indem ich relevante Seiten auf Null gesetzt habe. Ich habe zuerst folgende Optionen eingestellt psql:

    \set FETCH_COUNT 1
\pset pager off

    Ich mache es dann SELECT ctid, * FROM comments;. Auf diese Weise wird ctidein fehlerhaftes Tupel ausgespuckt, bevor die Abfrage stirbt. Dann fülle ich diese Seite mit Nullen: dd if=/dev/zero of=/var/lib/postgresql/9.5/main/base/16385/16443 bs=8K seek=92803 count=1 conv=notruncAber jede Seite, die auf diese Weise auf Null gesetzt wurde, bricht die vorherige Seite auf, was dazu führt, dass die Seite 16442jetzt ein Tupel mit einem ungültigen Zeitstempel enthält. Ich bin mir nicht sicher, was ich hier falsch mache.

  • ( 16. Dezember 2016 ) Der Versuch pg_dump -Fc --table photos vw > photos.bakführt zu einem Segmentierungsfehler, nachdem 1,3 GB ( von wahrscheinlich 800 GB ) geschrieben wurden. Hier ist das Serverprotokoll:

    2016-12-16 18:48:05 EET [19337-2] LOG:  server process (PID 29088) was terminated by signal 11: Segmentation fault
2016-12-16 18:48:05 EET [19337-3] DETAIL:  Failed process was running: COPY public.photos (id, owner_id, width, height, text, date, link, thumb, album_id, time_found, user_id, lat, long) TO stdout;
2016-12-16 18:48:05 EET [19337-4] LOG:  terminating any other active server processes
2016-12-16 18:48:05 EET [19342-2] WARNING:  terminating connection because of crash of another server process
2016-12-16 18:48:05 EET [19342-3] DETAIL:  The postmaster has commanded this server process to roll back the current transaction and exit, because another server process exited abnormally and possibly corrupted shared memory.
2016-12-16 18:48:05 EET [19342-4] HINT:  In a moment you should be able to reconnect to the database and repeat your command.
2016-12-16 18:48:05 EET [19337-5] LOG:  all server processes terminated; reinitializing
2016-12-16 18:48:06 EET [29135-1] LOG:  database system was interrupted; last known up at 2016-12-14 22:58:59 EET
2016-12-16 18:48:07 EET [29135-2] LOG:  database system was not properly shut down; automatic recovery in progress
2016-12-16 18:48:07 EET [29135-3] LOG:  invalid record length at 1562/A302F878
2016-12-16 18:48:07 EET [29135-4] LOG:  redo is not required
2016-12-16 18:48:07 EET [29135-5] LOG:  MultiXact member wraparound protections are now enabled
2016-12-16 18:48:07 EET [19337-6] LOG:  database system is ready to accept connections
2016-12-16 18:48:07 EET [29139-1] LOG:  autovacuum launcher started

    Hier ist ein kurzer Stacktrace:

    #0  pglz_decompress (source=source@entry=0x7fbfb6b99b13 "32;00/0ag4d/Jnz\027QI\003Jh3A.jpg", slen=<optimized out>,
    dest=dest@entry=0x7fbf74a0b044 "", rawsize=926905132)
#1  0x00007fc1bf120c12 in toast_decompress_datum (attr=0x7fbfb6b99b0b)
#2  0x00007fc1bf423c83 in text_to_cstring (t=0x7fbfb6b99b0b)

    Ich habe keine Ahnung, wie ich das umgehen soll.

  • ( 29. Dezember 2016 ) Ich habe ein Hilfsprogramm geschrieben SELECT * FROM tablename LIMIT 10000 OFFSET 0, das den Versatz erhöht und die Anzahl der toten Tupel einschränkt. Es hat erfolgreich Daten auf meinem lokalen Computer dupliziert, mit Ausnahme der Tupel ( ich hoffe die einzigen ), die ich manuell beschädigt habe. Es soll auch warten, wenn der Server neu gestartet wird. Ich hatte jedoch nicht genügend Speicherplatz auf meinem RAID und habe einen Tablespace slowdiskauf einer 8-TB-Festplatte erstellt. Wenn ich es versuche CREATE DATABASE vwslow WITH TABLESPACE slowdisk, geht das nicht mit Fehlern:

    2016-12-29 02:34:13 EET [29983-1] LOG:  request to flush past end of generated WAL; request 950412DE/114D59, currpos 1562/A3030C70
2016-12-29 02:34:13 EET [29983-2] CONTEXT:  writing block 58368001 of relation base/16385/16473
2016-12-29 02:34:13 EET [29983-3] ERROR:  xlog flush request 950412DE/114D59 is not satisfied --- flushed only to 1562/A3030C70
2016-12-29 02:34:13 EET [29983-4] CONTEXT:  writing block 58368001 of relation base/16385/16473
2016-12-29 02:34:13 EET [30005-44212] postgres@vw ERROR:  checkpoint request failed
2016-12-29 02:34:13 EET [30005-44213] postgres@vw HINT:  Consult recent messages in the server log for details.
2016-12-29 02:34:13 EET [30005-44214] postgres@vw STATEMENT:  CREATE DATABASE vwslow WITH TABLESPACE slowdisk;

    Handbuch CHECKPOINTführte zu den gleichen Fehlern.

    Ein Server-Neustart hat den Checkpoint-Fehler behoben und mich mein Tool ausführen lassen. Beantwortet meine Frage und veröffentlicht den Code, wenn es funktioniert.

postgresql recovery corruption postgresql-9.5 disaster-recovery Kai
quelle
Lesen Sie dies und handeln Sie danach, bevor Sie etwas anderes unternehmen: wiki.postgresql.org/wiki/Corruption . Obwohl es so aussieht, als wäre es etwas spät. Ich vermute sehr, dass Festplattenprobleme / RAID-Neuerstellungen die Hauptursache sind.
Craig Ringer
Haben Sie eine Kopie des Datenverzeichnisses aufbewahrt, bevor Sie ein resetxlog usw. erstellt haben?
Craig Ringer
Nicht der Datadir selbst, aber ich habe Raw-Disk-Images an einen anderen Ort verschoben, an dem sie sicherer sind. Sie sind in Ordnung, weil ich mein RAID von ihnen neu aufgebaut habe.
Kai
1
@CraigRinger wirst du eine Antwort dazu schreiben? Sie sind wahrscheinlich einer der wenigen Benutzer, die im Postgres-Tag antworten und zu diesem Thema etwas Nützliches sagen können. Es scheint, als könne sehr wenig getan werden.
Ypercubeᵀᴹ
4
Sie werden die Antwort auf diese Frage nicht finden. Erwin kann Ihnen vielleicht weiterhelfen. Schüchtern, suchen Sie nach David Fetter oder AndrewSW / RhodiumToad auf irc.freenode.net/#postgresql. Sagen Sie uns (dba.se), was sie finden. Ich habe das Gefühl, dass dies ein bezahlter Beratungsjob sein wird, der vollständigen Zugriff auf Ihre Datenbank erfordert. developer.postgresql.org/~adunstan linkedin.com/in/davidfetter Ich habe keine Beziehung zu diesen Leuten oder ihren Firmen. Aber sie sind die einzigen, denen ich persönlich vertrauen würde, um aus diesem Haken herauszukommen.
Evan Carroll

Antworten:

2

Nun, ich habe es geschafft, den Wiederherstellungsprozess von zu automatisieren SELECT undINSERT INTO , Bereiche zu überspringen und darauf zu warten, dass der Server abstürzt. Ich habe es zuerst in Node codiert - es riss unbeschädigte Daten von commentsund wird immer noch verwendet.

Gestern habe ich beschlossen, Golang auszuprobieren, und hier ist ein Repo mit Go-Code: https://github.com/kaivi/pg_ripper Ich werde es bald aktualisieren, damit es wirklich gegen schlechte Tupel funktioniert und nicht nur aufgibt Bereich mit einem.

Kai
quelle