У меня есть рабочий форум, и я хочу восстановить состояние, которое было несколько дней назад, когда всё работало корректно. Я работаю на AWS, поэтому создал AMI-образ рабочего форума, запустил новый экземпляр и попытался восстановить резервную копию от нескольких дней назад. Это не удалось, и я получил сообщения об ошибках, приведённые ниже.
Это не может быть связано с несовпадением версий или схемы, так как сервер создан из свежего образа рабочего форума.
Я пробовал пересоздать окружение.
Я пробовал восстановить из другой резервной копии от одного дня назад — результат тот же.
Единственное необычное действие, которое я предпринял, — это удаление файлов PDF из каталога загрузки (…/uploads/original/1X/*.pdf) для освобождения места. Я попробую снова, пропустив этот шаг, но маловероятно, что это стало причиной проблемы.
> [2019-11-30 01:17:44] 'admin' начал восстановление!
> [2019-11-30 01:17:44] Пометка восстановления как выполняющегося...
> [2019-11-30 01:17:44] Проверка существования /var/www/discourse/tmp/restores/default/2019-11-30-011744...
> [2019-11-30 01:17:44] Загрузка архива во временный каталог...
> [2019-11-30 01:23:24] Распаковка архива, это может занять время...
> [2019-11-30 01:27:52] Файл метаданных для извлечения отсутствует.
> [2019-11-30 01:27:52] Проверка метаданных...
> [2019-11-30 01:27:52] Текущая версия: 20191129144706
> [2019-11-30 01:27:52] Версия для восстановления: 20191120015344
> [2019-11-30 01:27:52] Извлечение файла дампа...
> [2019-11-30 01:50:57] недопустимая команда \N
> [2019-11-30 01:50:57] недопустимая команда \N
>
> < повторяется около 100 раз >
>
> [2019-11-30 01:51:07] недопустимая команда \N
> [2019-11-30 01:54:13] недопустимая команда \N
> [2019-11-30 01:54:13] ИСКЛЮЧЕНИЕ: psql завершился с ошибкой
> [2019-11-30 01:54:14] /var/www/discourse/lib/backup_restore/restorer.rb:331:in `restore_dump'
> /var/www/discourse/lib/backup_restore/restorer.rb:75:in `run'
> /var/www/discourse/lib/backup_restore.rb:166:in `block in start!'
> /var/www/discourse/lib/backup_restore.rb:163:in `fork'
> /var/www/discourse/lib/backup_restore.rb:163:in `start!'
> /var/www/discourse/lib/backup_restore.rb:22:in `restore!'
> /var/www/discourse/app/controllers/admin/backups_controller.rb:119:in `restore'
> и т. д...
Я склонен связывать эти ошибки с несовпадением версий PostgreSQL, но я видел подобные ошибки с \N на днях на системе, у которой закончилось место на диске (я восстанавливал данные на ту же систему, с которой была сделана резервная копия). Я не закончил диагностику проблемы (это была ещё одна странная проблема, с которой я столкнулся, и восстановление резервной копии на другой сервер решило её; я задумался, решило бы восстановление на тот же сервер проблему).
Вы упомянули, что у вас закончилось место. Я подозреваю, что именно в этом причина. Процесс восстановления требует много места, так как он распаковывает резервную копию, и, следовательно, одновременно хранит две её полные копии, плюс место, необходимое для самого восстановления и для возможности отката в случае сбоя.
Становится ещё хуже, но, возможно, это ближе к истинной проблеме… Исходя из гипотезы, что мне нужно больше места на диске, я создал новый экземпляр из своего образа, на этот раз с 100 ГБ вместо предыдущих 50 ГБ. (Резервные копии занимают по 5 ГБ каждая и хранятся в S3.) На этот раз я получил явную ошибку: «No space left on device» (Место на устройстве закончилось). Однако команда df показывает огромное количество свободного места.
> [2019-11-29 22:42:58] Убедимся, что каталог /var/www/discourse/tmp/restores/default/2019-11-29-224258 существует...
> [2019-11-29 22:42:58] Загрузка архива во временный каталог...
> [2019-11-29 22:45:46] Распаковка архива, это может занять некоторое время...
> [2019-11-29 22:51:46] Файл метаданных для извлечения отсутствует.
> [2019-11-29 22:51:46] Проверка метаданных...
> [2019-11-29 22:51:46] Текущая версия: 20191129144706
> [2019-11-29 22:51:46] Восстанавливаемая версия: 20191108000414
> [2019-11-29 22:51:46] Извлечение файла дампа...
> [2019-11-29 22:53:47] ИСКЛЮЧЕНИЕ: No space left on device @ io_write - /shared/tmp/restores/default/2019-11-29-224258/dump.sql
> [ec2-user@ip-172-31-47-237 discourse]$ df / -h
> Файловая система Размер Использовано Доступно Использ. Точка монтирования
> /dev/xvda1 99G 28G 71G 28% /
Неужели это проблема с файлом подкачки? Экземпляр EC2 имеет тип t2.small с 2 ГБ оперативной памяти, поэтому я давно создал файл подкачки на рабочем форуме. Предполагаю, что файл подкачки был скопирован на новый экземпляр. Я не эксперт, но считаю, что файл подкачки существует, так как система не позволила мне создать новый, и потому что:
> /var/www/discourse# swapon -s
> Имя файла Тип Размер Использовано Приоритет
> /swapfile файл 2097148 1024 -2
Ошибка «No space left on device» возникает не только тогда, когда на устройстве заканчиваются гигабайты, но и когда файловая система исчерпывает inode. Однако в данном случае это явно не проблема (иначе iUse% был бы равен 100%).
Всё ещё безрезультатно. Я подумал, что попробую восстановить на новом экземпляре Lightsail, вместо запуска AMI моего рабочего экземпляра EC2. Ошибка всё ещё возникает, но сообщения немного отличаются.
Оба экземпляра, старый и новый, обновлены, оба установлены как стандартные Docker-инсталляции, и оба используют одну и ту же версию PostgreSQL:
Создание отсутствующих функций в схеме discourse_functions
Невозможно восстановить в другую схему, восстановление выполняется на месте
Может ли это быть связано с плагинами? На «исходном» сайте установлено несколько плагинов, как поддерживаемых, так и кастомных. Некоторые из них используют пользовательские поля. Я пробовал восстанавливать на чистые «целевые» сайты как с плагинами, так и без них.
Есть ли какие-либо рекомендации, как начать сравнение схем?
> [2019-12-07 04:51:36] 'admin' начал восстановление!
> [2019-12-07 04:51:36] Пометка восстановления как запущенного...
> [2019-12-07 04:51:36] Проверка существования /var/www/discourse/tmp/restores/default/2019-12-07-045136...
> [2019-12-07 04:51:36] Загрузка архива во временную директорию...
> [2019-12-07 04:53:49] Распаковка архива, это может занять время...
> [2019-12-07 04:57:12] Файл метаданных для извлечения отсутствует.
> [2019-12-07 04:57:12] Проверка метаданных...
> [2019-12-07 04:57:12] Текущая версия: 20191129144706
> [2019-12-07 04:57:12] Восстанавливаемая версия: 20191120015344
> [2019-12-07 04:57:12] Извлечение файла дампа...
> [2019-12-07 04:59:10] Создание отсутствующих функций в схеме discourse_functions
> [2019-12-07 04:59:11] Невозможно восстановить в другую схему, восстановление выполняется на месте
> [2019-12-07 05:05:02] ОШИБКА: текущая транзакция прервана, команды игнорируются до конца блока транзакции
> [2019-12-07 05:05:03] ОШИБКА: текущая транзакция прервана, команды игнорируются до конца блока транзакции
> < повторяется около 100 раз >
> [2019-12-07 05:05:03] ОШИБКА: текущая транзакция прервана, команды игнорируются до конца блока транзакции
> [2019-12-07 05:05:03] ИСКЛЮЧЕНИЕ: psql не удался
> [2019-12-07 05:05:03] /var/www/discourse/lib/backup_restore/restorer.rb:331:in `restore_dump'
> /var/www/discourse/lib/backup_restore/restorer.rb:75:in `run'
> /var/www/discourse/lib/backup_restore.rb:166:in `block in start!'
> /var/www/discourse/lib/backup_restore.rb:163:in `fork'
> /var/www/discourse/lib/backup_restore.rb:163:in `start!'
> /var/www/discourse/lib/backup_restore.rb:22:in `restore!'
> /var/www/discourse/app/controllers/admin/backups_controller.rb:119:in `restore'
> < остальная часть трассировки стека >
Внутри PostgreSQL явно что-то идёт не так. Вы смотрели её логи?
Маловероятно, но возможно: это может быть связано с памятью? Попробуйте отслеживать вывод команды free -m во время восстановления и посмотрите, не закончится ли у вас (виртуальная) память.
Я понимаю, что это сложный вопрос, так как мы не знаем, в чём именно проблема, но в целом: нужно ли устанавливать плагины на целевом сайте перед попыткой восстановления? Или же процесс восстановления сам подтягивает и собирает плагины?
Да, это необходимо — процесс восстановления этого за вас не сделает.
С другой стороны, я не думаю, что это ваша проблема, так как восстановление всё же обеспечит правильную структуру базы данных (включая специфичные для плагинов элементы).
Я создал новый экземпляр Lightsail за $20 с 4 ГБ памяти. Я наблюдал за выводом free -m во время восстановления. Памяти всегда было достаточно свободной и доступной.
Конкретные ошибки варьируются в зависимости от того, установлены ли плагины, но, вероятно, они вызваны одной и той же корневой причиной. В данном случае я не устанавливал плагины перед созданием резервной копии. Существует два класса ошибок:
В логах PostgreSQL я получаю много таких сообщений, иногда на символе 34, а иногда на символе 41.
discourse@discourse ERROR: relation “user_auth_tokens” does not exist at character 34
Эти сообщения не имеют соответствующего вывода на странице администратора > резервное копирование > лог, и восстановление продолжается в течение нескольких минут, несмотря на эти ошибки.
Вторая ошибка зависит от того, установлены ли плагины. В данном случае я их не устанавливал, поэтому получаю ошибку, связанную с Data Explorer, и именно в этот момент всё идёт наперекосяк.
В логах администратора > резервное копирование > лог:
[2019-12-07 07:38:34] CREATE INDEX
[2019-12-07 07:38:34] CREATE INDEX
[2019-12-07 07:38:34] ERROR: could not create unique index “index_plugin_store_rows_on_plugin_name_and_key”
[2019-12-07 07:38:34] DETAIL: Key (plugin_name, key)=(discourse-data-explorer, q:-6) is duplicated.
[2019-12-07 07:38:34] ERROR: current transaction is aborted, commands ignored until end of transaction block
[2019-12-07 07:38:34] ERROR: current transaction is aborted, commands ignored until end of transaction block
< повторяется 1000 раз и завершается >
А соответствующий вывод в логе PostgreSQL:
2019-12-07 07:38:34.718 UTC [8991] discourse@discourse LOG: duration: 165.427 ms statement: CREATE INDEX index_notifications_on_user_
id_and_topic_id_and_post_number ON public.notifications USING btree (user_id, topic_id, post_number);
2019-12-07 07:38:34.767 UTC [8991] discourse@discourse ERROR: could not create unique index “index_plugin_store_rows_on_plugin_name_an
d_key”
2019-12-07 07:38:34.767 UTC [8991] discourse@discourse DETAIL: Key (plugin_name, key)=(discourse-data-explorer, q:-6) is duplicated.
2019-12-07 07:38:34.767 UTC [8991] discourse@discourse STATEMENT: CREATE UNIQUE INDEX index_plugin_store_rows_on_plugin_name_and_key O
N public.plugin_store_rows USING btree (plugin_name, key);
2019-12-07 07:38:34.984 UTC [8991] discourse@discourse ERROR: current transaction is aborted, commands ignored until end of transactio
n block
2019-12-07 07:38:34.984 UTC [8991] discourse@discourse STATEMENT: CREATE INDEX index_policy_users_on_post_policy_id_and_user_id ON pub
lic.policy_users USING btree (post_policy_id, user_id);
Я думаю, что проблема #1 не является критической и является лишь побочным эффектом восстановления в том же месте.
Вы можете рассмотреть возможность (экспорта и) удаления всех запросов из Data Explorer и отключения плагина Data Explorer перед созданием резервной копии.
Или, возможно, вы могли бы опубликовать соответствующее содержимое таблицы plugin_store_rows?
Действительно, есть дублирующиеся запросы с одинаковыми парами (plugin_name, key), например q:-11 и q:-2, но с уникальными идентификаторами. Я не вижу никакой закономерности среди дубликатов — например, это не мои любимые запросы или что-то подобное.
Поэтому следующим шагом будет удаление дубликатов, создание резервной копии и попытка восстановления из неё.
Я не могу воспроизвести это на чистом тестовом сайте, но на моём продакшн-сайте проблема возникает стабильно. Я установил все плагины с продакшна на тестовый сайт, но всё равно не могу воспроизвести ошибку.
Как мне найти, что не так с моим продакшн-сайтом?
Как удалить дублирующиеся запросы, если они принадлежат системе? Мне нужно выполнить sudo -u postgres psql discourse...? Звучит страшно.
