PostgreSQL DELETE FROM завершается с ошибкой `Ошибка: попытка удалить невидимый кортеж`

Ошибка

Попытка удалить кортежи, содержащие недопустимые метки времени с

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';

заканчивается в

ERROR:  attempted to delete invisible tuple

Существует список рассылки 2009 года, в котором обсуждается точно такое же сообщение об ошибке, где OP исправил его, но я не вижу объяснения того, как он это сделал или что могло привести к этой ошибке.

Я беспомощен из-за отсутствия хитов в Google и из-за моего ограниченного знания PostgreSQL.

Что привело к коррупции

У меня был сервер PostgreSQL 9.5.5 ( данные ~ 4 ТБ, все настройки по умолчанию, за исключением увеличенного объема памяти ), работающий в Debian 8, когда ядро ​​ОС запаниковало - возможно, при перекомпоновке / dev / md1, где находился swap. До этого PostgreSQL израсходовал почти все дисковое пространство с файлом журнала 400 ГБ. ОС никогда больше не загружалась, проверки диска были в порядке, поэтому я загрузился с LiveCD и на всякий случай сделал резервную копию каждого блочного устройства для образов. Я успешно перестроил каталог / из / dev / md2, fsck показал чистую файловую систему, и я сделал резервную копию папки PGDATA на внешнем жестком диске.

Что я сделал, чтобы попытаться восстановить

После того, как я отформатировал устройства md и переустановил ОС вместе со свежим postgresql-9.5, я остановил сервер PostgreSQL, переместил и сжал папку PGDATA для пользователя postgres и запустил сервер - все было хорошо, ошибок не было.

Как только я начал pg_dumpall, он умер с

Error message from server: ERROR:  timestamp out of range

Естественно, я пытался удалить обидные кортежи, только чтобы invisible tupleснова и снова сталкиваться с одной и той же ошибкой.

Вещи, которые я пытался

Прежде всего, DELETE запросы не выполнялись из-за поврежденных страниц, поэтому я установил следующие настройки:

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

Теперь я заметил, что когда я снова запускаю одни и те же запросы, сервер снова и снова обнуляет одни и те же страницы, не зная, что это значит:

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

Я пробовал следовать в неопределенном порядке:

• pg_resetxlog -D $PGDATA сделал свою работу без каких-либо ошибок или сообщений
• Удалил все индексы, включая ограничения pkey

• CREATE TABLE aaa AS (SELECT * FROM comments);приводит к Segmentation faultпо

  heap_deform_tuple (tuple=tuple@entry=0x7f0d1be29b08, tupleDesc=tupleDesc@entry=0x7f0d1a35abe0, values=values@entry=0x7ffd57a5beb0, isnull=isnull@entry=0x7ffd57a65af0 "\001\001") Он воспроизводим и оставляет дамп ядра ~ 9 ГБ.

• SELECT COUNT(*) from comments;разрешено VACUUM comments;завершать, тот же трюк не работает на других таблицах.
• SELECT COUNT(*) from photos;и VACUUM photos;теперь умирает ERROR: MultiXactId 302740528 has not been created yet -- apparent wraparound- этот часто посещает каждую таблицу, где другие ошибки больше не появляются.

мысли

• БД сталкивался с большим количеством ( возможно, повторяющихся ) записей с ON CONFLICTпредложением,VACUUM когда ББ делал панику в ядре, и я считаю, что это то, что от него осталось, вызывает проблемы nonexistent MultiXactIdsиinvisible tuple
• Данные собирались с помощью crawler в течение 2+ лет, и я полностью согласен с их потерей.
• Теперь я делаю резервные копии
• Не было никаких реляционных ограничений между таблицами или каких-либо триггеров

Вот вывод 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

Обновления

• ( 9 декабря 2016 г. ) Читая о несуществующих MultiXactIds , я вспомнил, что в момент сбоя моя база данных не была загружена, но обрабатывал VACUUMзапрос вручную . Я перевел веб-серверы и сканеры в автономный режим после того, как понял, что на дисках осталось только 3% пространства. Я должен был проверить /var/logбольшие файлы, но я ошибочно обвинил PostgreSQL и попытался VACUUM FULL, только чтобы найти его прерванным из-за небольшого свободного места на устройстве. Итак, я запустил обычный VACUUM и оставил все как есть.
• ( 14 декабря 2016 г. ) Загрузил ветку 9.5 исходных текстов PostgreSQL с Github, закомментировал блоки в heapam.c и multixact.c и скомпилировал его с надеждой, что он не выдаст эти ошибки. Но сервер не запустился, потому что он должен был быть настроен с теми же флагами, которые использовались у меня из APT. Было около 47 флагов, каждый из которых требовал зависимости с неочевидным именем, поэтому я отказался от этой идеи.

• ( 16 декабря 2016 г. ) Я нашел способ избавиться от кортежей с неправильными временными метками, обнулив соответствующие страницы. Сначала я установил следующие параметры в psql:

  \set FETCH_COUNT 1
  \pset pager off
  

  Я тогда делаю SELECT ctid, * FROM comments;. Таким образом, он выплевывает ctidплохой кортеж до того, как запрос умирает. Затем я перехожу к заполнению этой страницы нулями: dd if=/dev/zero of=/var/lib/postgresql/9.5/main/base/16385/16443 bs=8K seek=92803 count=1 conv=notruncно каждая страница, обнуленная таким образом, разбивает предыдущую страницу, в результате чего страница 16442теперь имеет кортеж с недопустимой отметкой времени. Не уверен, что я здесь делаю не так.

• ( 16 декабря 2016 г. ) Попытка pg_dump -Fc --table photos vw > photos.bakпривести к ошибке сегментации после записи 1,3 ГБ ( из, вероятно, 800 ГБ ). Вот журнал сервера:

  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
  

  Вот короткая трассировка стека:

  #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)
  

  Я понятия не имею, как обойти это.

• ( 29 декабря 2016 г. ) Я написал утилиту, которая SELECT * FROM tablename LIMIT 10000 OFFSET 0увеличивает инкремент смещения и сужает мертвые кортежи и успешно дублирует данные на моем локальном компьютере, за исключением кортежей ( надеюсь, единственных ), которые я испортил вручную. Также предполагается, что сервер перезапустится. Однако у меня не было достаточно места на моем RAID, и я создал табличное пространство slowdiskна жестком диске 8 ТБ. Когда я попытаюсь CREATE DATABASE vwslow WITH TABLESPACE slowdisk, это не будет сделано с ошибками:

  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;
  

  Руководство CHECKPOINTвылилось в те же ошибки.

  После перезапуска сервера ошибка контрольной точки исчезла, и я запустил свой инструмент. Ответит на мой вопрос и опубликует код, если он работает.

Что ж, мне удалось автоматизировать процесс восстановления SELECTи INSERT INTO, пропуская диапазоны и ждать, если сервер выйдет из строя. Сначала я закодировал его в Node - он извлек неповрежденные данные commentsи продолжает работать.

Вчера я решил попробовать Golang, и вот репо с кодом Go: https://github.com/kaivi/pg_ripper Я скоро обновлю его, чтобы он действительно работал с плохими кортежами, а не просто сдавался в целом диапазон, содержащий один.