Зависание pg_probackup 2.1.5 во время выполнения бэкапа

[ykurenkov]

pg_probackup завис во время выполнения полного бэкапа, с максимальной загрузкой всех доступных ядер. Статус текущего бэкапа "DONE". Бэкап производится на CIFS. Однако при попытке провалидировать бэкап выдаётся вот такое сообщение:

D:\IBIS_ADM\AdminDB>pg_backup.bat validate -i PWG203
WARNING: Process 6864 which used backup PWG203 no longer exists
INFO: Validating backup PWG203

Хотя процесс pg_probackup с таким PID существует. Вот список открытых файлов, который не поменялся при повторном получении через 10 минут:

pg_probackup.exe pid: 6864 IBIS\MIS
   38: File  (RW-)   C:\Program Files (x86)\nnCron
   80: File  (R--)   D:\IBIS_ADM\AdminDB\logs\pg_backup.log
   84: File  (R--)   D:\IBIS_ADM\AdminDB\logs\pg_backup.err.log
  124: File  (R--)   D:\IBIS_ADM\AdminDB\lock\pg_backup-full.lock
  188: File  (RW-)   \Device\Mup\10.20.9.240\Ibis\IBIS_BACKUPS\PGBACKUPS\log\pg_probackup-Sun.log
  1FC: File  (RW-)   \Device\Mup\10.20.9.240\Ibis\IBIS_BACKUPS\PGBACKUPS\backups\ny1-10\PWG203\database\base\15326499\15326555.348
  29C: File  (RW-)   \Device\Mup\10.20.9.240\Ibis\IBIS_BACKUPS\PGBACKUPS\backups\ny1-10\PWG203\database\base\15326499\15326555.298
  2B0: File  (RW-)   \Device\Mup\10.20.9.240\Ibis\IBIS_BACKUPS\PGBACKUPS\backups\ny1-10\PWG203\database\base\15326499\15326555.3
  2E0: File  (RW-)   \Device\Mup\10.20.9.240\Ibis\IBIS_BACKUPS\PGBACKUPS\backups\ny1-10\PWG203\database\base\15326499\15326555.155
  2F8: File  (RW-)   \Device\Mup\10.20.9.240\Ibis\IBIS_BACKUPS\PGBACKUPS\backups\ny1-10\PWG203\database\base\15520165\15527116.4
  310: File  (RW-)   \Device\Mup\10.20.9.240\Ibis\IBIS_BACKUPS\PGBACKUPS\backups\ny1-10\PWG203\database\base\15520165\15527116.6
  348: File  (RW-)   \Device\Mup\10.20.9.240\Ibis\IBIS_BACKUPS\PGBACKUPS\backups\ny1-10\PWG203\database\base\15326499\15326555.79
  354: File  (RW-)   \Device\Mup\10.20.9.240\Ibis\IBIS_BACKUPS\PGBACKUPS\backups\ny1-10\PWG203\database\base\15520165\15527116.5
  360: File  (RW-)   \Device\Mup\10.20.9.240\Ibis\IBIS_BACKUPS\PGBACKUPS\backups\ny1-10\PWG203\database\base\15326499\15326555.296
  374: File  (RW-)   \Device\Mup\10.20.9.240\Ibis\IBIS_BACKUPS\PGBACKUPS\backups\ny1-10\PWG203\database\base\15326499\15326555.299
  380: File  (RW-)   \Device\Mup\10.20.9.240\Ibis\IBIS_BACKUPS\PGBACKUPS\backups\ny1-10\PWG203\database\base\15326499\15326555.238
  3BC: File  (RW-)   \Device\Mup\10.20.9.240\Ibis\IBIS_BACKUPS\PGBACKUPS\backups\ny1-10\PWG203\database\base\15326499\15326555.295
  3C4: File  (RW-)   \Device\Mup\10.20.9.240\Ibis\IBIS_BACKUPS\PGBACKUPS\backups\ny1-10\PWG203\database\base\15326499\15326555.246
  3D8: File  (RW-)   \Device\Mup\10.20.9.240\Ibis\IBIS_BACKUPS\PGBACKUPS\backups\ny1-10\PWG203\database\base\15326499\15326555.241
  3F4: File  (RW-)   \Device\Mup\10.20.9.240\Ibis\IBIS_BACKUPS\PGBACKUPS\backups\ny1-10\PWG203\database\base\15326499\15326555.297

Сервер тормозит безбожно. Попробую его придержать в таком состоянии для получения дополнительной информации, пока не поступят жалобы пользователей.

[knizhnik]

ESRCH на Windows прооисходит из-за невозможности открыть процесс, т.е. когда OpenProcess возвращает ошибку. Почему это происходит - мне не ясно. Истинный код ошибки к сожалению посгресовая реализация pgkill прячет.

А отладчиком к pgprobackup-у нельзя приконнектится?

[ykurenkov]

Что есть отладчик? Что-то поставить надо на сервер?

[knizhnik]

Попробуйте так: https://superuser.com/questions/462989/how-can-i-view-the-call-stack-of-a-running-process-thread

[ykurenkov]

[gsmolk]

@knizhnik, а почему pgkill не зовет GetLastError, чтобы убедиться в том, что процесса действительно нет?

[knizhnik]

Это глвный поток ждёт завершения запущенных пробэкапом потоков. А если кликнуть на любой другой поток? Какой будет стэк?

[knizhnik]

@gsmol это же не наш код. А Постгресе видимо предполагается, что если процесс не открылся, то его нет. Но, возможно, там просто каких-то ресурсов не хватает чтобы открыть процесс.

[gsmolk]

@knizhnik, да постгресовый, но это же не означает автоматически что он правильный.

[ykurenkov]

[knizhnik]

Читает. Видимо это верификация бэкапа. Там вроде у нас ключик был, что не верифицировать?

[knizhnik]

Почему он не может процесс открыть - для меня всё равно загадка. Но, видимо, без вставки в это место лога мы отгадки не узнаем.

[ykurenkov]

Я могу прибить процесс?

[ykurenkov]

Прибил процесс, запустил валидацию вручную. Пока всё живенько бежит.

[ykurenkov]

INFO: Backup PWG203 data files are valid INFO: Backup PWG203 WAL segments are valid INFO: Backup PWG203 is valid. INFO: Validate of backup PWG203 completed.

[knizhnik]

Я всё таки не понял, что это было? Пробэкап каким-то образом зациклился на вилидации? Или вскрытие показало что больной спал? Ручная валидация заняла меньше вреемни, чем прошло до дого момента, когда процесс был убит? Может как-то неправильно распределилась работа между потоками? В логах никаких сообщений об ошибках не было?

[ykurenkov]

Он зациклился ночью, прогрузив ве доступные ему ядра по полной. Проблему я обнаружил утром. Процесс был, что-то делал, максимум использовав процессор. Потом я снял процесс, запустил валидацию вручную, которая заняла около 1 часа 40 минут. Пока не был снят процесс, новый не мог достучаться до "зависшего" (см. первое сообщение).

[gsmolk]

По-моему там интеррапт прилетел и треды не смогли его переварить.

[gsmolk]

Не могу воспроизвести.

[ykurenkov]

Пока тоже все работает. Не могло сказаться временное пропадание связи с NAS (на CIFS бекапим по UNC)?

[gsmolk]

Сложно сказать, может быть и такое.

[ykurenkov]

Закрываем?

[gsmolk]

Пусть пока повисит, я потом сделаю отдельную задачу запатчить pgkill