Регистрация Войти
Рейтинг:2
avatar Server

Как отладить ошибку сегментации PostgreSQL?

флаг ng
Tombart

У меня есть экземпляр PostgreSQL 13, который постоянно падает:

LOG: серверный процесс (PID 10722) был прерван сигналом 11: Ошибка сегментации
ПОДРОБНО: Запускался сбойный процесс: COMMIT
LOG: завершение любых других активных серверных процессов
ВНИМАНИЕ: разрыв соединения из-за сбоя другого серверного процесса
ПОДРОБНЕЕ: администратор почты приказал этому серверному процессу откатить текущую транзакцию и завершить работу, поскольку другой серверный процесс аварийно завершил работу и, возможно, повредил разделяемую память.

я обновил /etc/postgresql/13/main/pg_ctl.conf включить дампы ядра

pg_ctl_options = '--core-файлы'

и перезапустил postgresql оказание услуг. Теперь, похоже, разрешены дампы ядра:

$ for f в `pgrep postgres`; сделать кот /proc/$f/limits | ядро grep; сделано
Максимальный размер основного файла неограниченный неограниченный байт

gdb backtrace дает следующий вывод

$ gdb /usr/lib/postgresql/13/bin/postgres 13/main/core.postgres.12264

Программа завершена с сигналом SIGSEGV, ошибка сегментации.
#0 slot_deform_heap_tuple (natts=5, offp=0x557cc2e60720, tuple=<оптимизировано>, slot=0x557cc2e606d8) в ./build/../src/backend/executor/execTuples.c:930
930 ./build/../src/backend/executor/execTuples.c: Нет такого файла или каталога.
(гдб) бт
#0 slot_deform_heap_tuple (natts=5, offp=0x557cc2e60720, tuple=<оптимизировано>, slot=0x557cc2e606d8) в ./build/../src/backend/executor/execTuples.c:930
#1 tts_buffer_heap_getsomeattrs (slot=0x557cc2e606d8, natts=5) в ./build/../src/backend/executor/execTuples.c:695
#2 0x0000557cc1d3998c в slot_getsomeattrs_int (slot=slot@entry=0x557cc2e606d8, attnum=5) в ./build/../src/backend/executor/execTuples.c:1912
#3 0x0000557cc1d28fba в slot_getsomeattrs (attnum=<оптимизировано>, slot=0x557cc2e606d8) в ./build/../src/include/executor/tuptable.h:344
#4 ExecInterpExpr (состояние=0x557cc2e620a8, econtext=0x557cc2ea1768, isnull=<оптимизировано>) в ./build/../src/backend/executor/execExprInterp.c:482
#5 0x0000557cc1d5548d в ExecEvalExprSwitchContext (isNull=0x7ffdd2599507, econtext=0x557cc2ea1768, state=0x557cc2e620a8) в ./build/../src/include/executor/executor.h:322
#6 ExecQual (econtext=0x557cc2ea1768, состояние=0x557cc2e620a8) в ./build/../src/include/executor/executor.h:391
# 7 MJFillInner (узел = 0x557cc2ea1558) в ./build/../src/backend/executor/nodeMergejoin.c:494
#8 0x0000557cc1d55ce8 в ExecMergeJoin (pstate=0x557cc2ea1558) в ./build/../src/backend/executor/nodeMergejoin.c:1353
#9 0x0000557cc1d2cc83 в ExecProcNode (node=0x557cc2ea1558) в ./build/../src/include/executor/executor.h:248
#10 ExecutePlan (execute_once=<оптимизированный вывод>, dest=0x557cc2e1a630, direction=<оптимизированный вывод>, numberTuples=0, sendTuples=<оптимизированный вывод>, operation=CMD_SELECT, use_parallel_mode=<оптимизированный вывод>, planstate=0x557cc2ea1558, 
    Estate=0x557cc2ea12f8) в ./build/../src/backend/executor/execMain.c:1632
# 11 standard_ExecutorRun (queryDesc=0x557cc2e1a5a0, direction=<оптимизировано>, count=0, execute_once=<оптимизировано>) в ./build/../src/backend/executor/execMain.c:350
#12 0x00007f0ec05ae09d в pgss_ExecutorRun (queryDesc=0x557cc2e1a5a0, direction=ForwardScanDirection, count=0, execute_once=<оптимизировано>) в ./build/../contrib/pg_stat_statements/pg_stat_statements.c:1045
#13 0x0000557cc1cdbcd4 в PersistHoldablePortal (portal=portal@entry=0x557cc2d44b78) в ./build/../src/backend/commands/portalcmds.c:407
#14 0x0000557cc1ff95f9 в HoldPortal (portal=portal@entry=0x557cc2d44b78) в ./build/../src/backend/utils/mmgr/portalmem.c:642
#15 0x0000557cc1ff9e7d в PreCommit_Portals (isPrepare=isPrepare@entry=false) в ./build/../src/backend/utils/mmgr/portalmem.c:738
#16 0x0000557cc1c001c4 в CommitTransaction() в ./build/../src/backend/access/transam/xact.c:2087
#17 0x0000557cc1c015d5 в CommitTransactionCommand() в ./build/../src/backend/access/transam/xact.c:3085
#18 0x0000557cc1ea211d в finish_xact_command() в ./build/../src/backend/tcop/postgres.c:2662
#19 0x0000557cc1ea4703 в exec_simple_query (query_string=0x557cc2c9cd28 "COMMIT") в ./build/../src/backend/tcop/postgres.c:1264
#20 0x0000557cc1ea6143 в PostgresMain (argc=<оптимизировано>, argv=argv@entry=0x557cc2cf6c68, dbname=<оптимизировано>, username=<оптимизировано>) в ./build/../src/backend/tcop/postgres .с:4339
#21 0x0000557cc1e25bcd в BackendRun (порт=0x557cc2ce94d0, порт=0x557cc2ce94d0) в ./build/../src/backend/postmaster/postmaster.c:4526
# 22 BackendStartup (порт = 0x557cc2ce94d0) в ./build/../src/backend/postmaster/postmaster.c:4210
# 23 ServerLoop() в ./build/../src/backend/postmaster/postmaster.c:1739
#24 0x0000557cc1e26b41 в PostmasterMain (argc=5, argv=<оптимизировано>) в ./build/../src/backend/postmaster/postmaster.c:1412
#25 0x0000557cc1b70f4f в main (argc=5, argv=0x557cc2c96c30) в ./build/../src/backend/main/main.c:210

Добавление log_statement = 'все' к /etc/postgresql/13/main/postgresql.conf не очень помогает, т. почтмейстер немедленно завершает все процессы, и запрос не записывается в журналы.

вот стрейс вывод после запуска СОВЕРШИТЬ

[pid 20006] pwrite64(29, "COMMIT", 6, 15936) = 6
[pid 20006] pwrite64(29, "\0", 1, 15942) = 1
[pid 20006] закрыть (29) = 0
[pid 20006] --- SIGSEGV {si_signo=SIGSEGV, si_code=SEGV_MAPERR, si_addr=0x10} ---
[pid 20006] +++ убит SIGSEGV (дамп ядра) +++
<... выберите возобновление> ) = ? ERESTARTNOHAND (перезапустить, если нет обработчика)
--- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_DUMPED, si_pid=20006, si_uid=108, si_status=SIGSEGV, si_utime=0, si_stime=0} ---
wait4(-1, [{WIFSIGNALED(s) && WTERMSIG(s) == SIGSEGV && WCOREDUMP(s)}], WNOHANG, NULL) = 20006
write(2, "2021-09-08 13:38:51.853 UTC [299"..., 198) = 198
write(2, "2021-09-08 13:38:51.853 UTC [299"..., 88) = 88
убить (19324, SIGQUIT) = 0
убить (-19324, SIGQUIT) = 0
убить (19331, SIGQUIT) = 0
убить (-19331, SIGQUIT) = 0
убить (19320, SIGQUIT) = 0
убить (-19320, SIGQUIT) = 0
убить (19319, SIGQUIT) = 0
убить (-19319, SIGQUIT) = 0
убить (19321, SIGQUIT) = 0
убить (-19321, SIGQUIT) = 0
убить (19322, SIGQUIT) = 0
убить (-19322, SIGQUIT) = 0
убить (19323, SIGQUIT) = 0
убить (-19323, SIGQUIT) = 0
ожидание4(-1, 0x7ffe90814374, WNOHANG, NULL) = 0
rt_sigreturn({mask=[]}) = -1 EINTR (прерванный системный вызов)
rt_sigprocmask(SIG_SETMASK, ~[ILL TRAP ABRT BUS FPE SEGV CONT SYS RTMIN RT_1], NULL, 8) = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
select(7, [5 6], NULL, NULL, {tv_sec=5, tv_usec=0}) = ? ERESTARTNOHAND (перезапустить, если нет обработчика)
--- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=19320, si_uid=108, si_status=2, si_utime=14, si_stime=3} ---

Есть ли способ отследить точный SQL-запрос, который был выполнен?

1762
1 + 4
Michael Hampton avatar
флаг cz
Michael Hampton
Если это продолжает происходить в одном и том же месте, вы, скорее всего, столкнулись с какой-то ошибкой и должны подать отчет об ошибке.
0
Ответить
флаг cn
Nasir Riley
В дополнение к вышесказанному вы смотрели логи?
0
Ответить
флаг ng
Tombart
@MichaelHampton Да, я попытаюсь это сделать, а пока мне нужно найти обходной путь, чтобы избежать сбоя всего postgres.
0
Ответить
флаг ng
Tombart
@NasirRiley В журналах нет ничего интересного, кроме уже показанных строк.
0
Ответить
Рейтинг:2
avatar Server
флаг ng
Tombart

Сначала установите символы отладки для вашего дистрибутива, для дистрибутивов Debian:

apt установить gdb postgresql-13-dbgsym

Перейти к кадру, содержащему некоторые описание запроса переменная, например 12:

(ГДБ) кадр 12
#12 0x00007f0ec05ae09d в pgss_ExecutorRun (queryDesc=0x557cc302b7d0, direction=ForwardScanDirection, count=0, execute_once=<оптимизировано>) в ./build/../contrib/pg_stat_statements/pg_stat_statements.c:1045
1045 в ./build/../contrib/pg_stat_statements/pg_stat_statements.c

распечатать эту переменную:

(gdb) p запросDesc
$1 = (ОписаниеЗапроса *) 0x557cc302b7d0

теперь скопируйте строку выше после знака равенства и разыменуйте ее, используя *

(gdb) p *(QueryDesc *) 0x557cc302b7d0
$6 = {операция = CMD_SELECT, planstmt = 0x557cc300e218, 
  sourceText = 0x557cc302b370 "\n", ' ' <повторяется 12 раз>, "DECLARE \"categoryPagePhotoUrl_image_urls\" КУРСОР С УДЕРЖИВАНИЕМ ДЛЯ\n", ' ' <повторяется 12 раз>, "SELECT di.itemId, image_number, filename FROM ( SELECT *\n", ' ' <повторяется 12 раз>, "FROM downl"..., snapshot = 0x557cc2e9b188, crosscheck_snapshot = 0x0, dest = 0x557cc302b860, params = 0x0, queryEnv = 0x0, Instrument_options = 0, tupDesc ​​= 0x557cc2f7bff8, 
  Estate = 0x557cc2cf8d08, planstate = 0x557cc2cf8f68, уже_исполнено = true, totaltime = 0x0}

Это не дает вам всего запроса, но, по крайней мере, дает представление о том, в какой таблице выполняется запрос.

На основе gdb вывод Мне удалось изолировать клиентов, которые выполняли такой запрос.

я пробовал бегать ПОЛНЫЙ ВАКУУМ на затронутой таблице, перестроение таблицы и индексов, переключение на реплику, копирование всей базы данных с использованием pg_dump. Тем не менее, проблема по-прежнему сохраняется и на копиях базы данных.

Наконец мне удалось изолировать минимальный код SQL для воспроизведения проблемы.

$ pg_createcluster 13 основной
$ созданная тестовая база данных
$ psql -d testdb -f postgresql-segfault.sql
СОЗДАТЬ СХЕМУ
СОЗДАТЬ ТАБЛИЦУ
КОПИРОВАТЬ 1
ИЗМЕНИТЬ ТАБЛИЦУ
НАЧИНАТЬ
СОЗДАТЬ ТАБЛИЦУ
ОБЪЯВИТЬ КУРСОР
 идентификатор товара  
---------
 1190300
(1 ряд)

psql:postgresql-segfault:34: сервер неожиданно закрыл соединение
        Вероятно, это означает, что сервер аварийно завершил работу.
        до или во время обработки запроса.
psql: postgresql-segfault: 34: фатальный: соединение с сервером было потеряно

С кодом для воспроизведения этого было достаточно, чтобы сообщить об ошибке к pgsql-ошибки список рассылки (также есть веб-форма). Оказался баг с перевыполнением плана, который уже дошел до завершения на нестабильный курсор, который был включен в PostgreSQL 13.4, 12.8 (и, возможно, другие версии).

0 + 0
Miles avatar
флаг kr
Miles
Вы избавили меня от многих проблем с отладкой этого, спасибо.
1
Ответить
флаг Moldova
Admin
Этот вопрос на других языках:

Ответить или комментировать

Большинство людей не понимают, что склонность к познанию нового открывает путь к обучению и улучшает межличностные связи. В исследованиях Элисон, например, хотя люди могли точно вспомнить, сколько вопросов было задано в их разговорах, они не чувствовали интуитивно связи между вопросами и симпатиями. В четырех исследованиях, в которых участники сами участвовали в разговорах или читали стенограммы чужих разговоров, люди, как правило, не осознавали, что задаваемый вопрос повлияет — или повлиял — на уровень дружбы между собеседниками.