PostgreSQL跟踪checkpointer出现死锁
gdb跟踪checkpointer进程,出现死锁,Mark一下.
为金州等地区用户提供了全套网页设计制作服务,及金州网站建设行业解决方案。主营业务为成都网站设计、做网站、金州网站设计,以传统方式定制建设网站,并提供域名空间备案等一条龙服务,秉承以专业、用心的态度为用户提供真诚的服务。我们深信只要达到每一位用户的要求,就会得到认可,从而选择与我们长期合作。这样,我们也可以走得更远!
跟踪checkpointer进程,查看共享内存中的信(heckpointerShmem->requests)
(gdb) p CheckpointerShmem->requests[150] ... $16 = {rnode = {spcNode = 1663, dbNode = 16402, relNode = 26185}, forknum = MAIN_FORKNUM, segno = 0} (gdb) p CheckpointerShmem->requests[200] Cannot access memory at address 0xf9fb18 ...
然后,请求checkpoint的进程报错
testdb=# update t_wal_ckpt set c2 = 'C2#'||substr(c2,4,40); UPDATE 8192 testdb=# checkpoint; 2019-01-07 12:30:32.114 CST [1418] PANIC: stuck spinlock detected at RequestCheckpoint, checkpointer.c:1050 2019-01-07 12:30:32.114 CST [1418] STATEMENT: checkpoint; 2019-01-07 12:30:37.081 CST [1390] PANIC: stuck spinlock detected at FirstCallSinceLastCheckpoint, checkpointer.c:1376 2019-01-07 12:30:38.610 CST [1370] LOG: background writer process (PID 1390) was terminated by signal 6: Aborted 2019-01-07 12:30:38.610 CST [1370] LOG: terminating any other active server processes 2019-01-07 12:30:38.611 CST [1392] WARNING: terminating connection because of crash of another server process 2019-01-07 12:30:38.611 CST [1392] 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. 2019-01-07 12:30:38.611 CST [1392] HINT: In a moment you should be able to reconnect to the database and repeat your command. 2019-01-07 12:30:38.613 CST [1558] WARNING: terminating connection because of crash of another server process 2019-01-07 12:30:38.613 CST [1558] 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. 2019-01-07 12:30:38.613 CST [1558] HINT: In a moment you should be able to reconnect to the database and repeat your command. PANIC: stuck spinlock detected at RequestCheckpoint, checkpointer.c:1050 server closed the connection unexpectedly This probably means the server terminated abnormally before or while processing the request. The connection to the server was lost. Attempting reset: 2019-01-07 12:30:54.041 CST [1560] FATAL: the database system is in recovery mode Failed. !>
尝试重新连接,发现DB已coredump.
[xdb@localhost ~]$ [xdb@localhost ~]$ psql -d testdb 2019-01-07 14:10:16.114 CST [1629] FATAL: the database system is in recovery mode psql: FATAL: the database system is in recovery mode
执行恢复
[xdb@localhost ~]$ pg_ctl start pg_ctl: another server might be running; trying to start server anyway waiting for server to start....2019-01-07 14:11:50.821 CST [1632] FATAL: lock file "postmaster.pid" already exists 2019-01-07 14:11:50.821 CST [1632] HINT: Is another postmaster (PID 1370) running in data directory "/data/xdb/pg111db"? stopped waiting pg_ctl: could not start server Examine the log output. [xdb@localhost ~]$ find /data/xdb -name postmaster.pid /data/xdb/pg111db/postmaster.pid [xdb@localhost ~]$ rm -rf /data/xdb/pg111db/postmaster.pid [xdb@localhost ~]$ pg_ctl start waiting for server to start....2019-01-07 14:12:44.578 CST [1639] LOG: could not bind IPv6 address "::1": Address already in use [xdb@localhost ~]$ ps -ef|grep postgres xdb 1370 1 0 12:01 pts/0 00:00:02 /appdb/atlasdb/pg11.1/bin/postgres xdb 1389 1370 0 12:01 ? 00:00:00 [postgres] xdb 1641 1332 0 14:12 pts/0 00:00:00 grep --color=auto postgres [xdb@localhost ~]$ kill -9 1370 [xdb@localhost ~]$ pg_ctl start waiting for server to start....2019-01-07 14:13:33.125 CST [1648] LOG: listening on IPv6 address "::1", port 5432 2019-01-07 14:13:33.125 CST [1648] LOG: listening on IPv4 address "127.0.0.1", port 5432 2019-01-07 14:13:33.142 CST [1648] LOG: listening on Unix socket "/tmp/.s.PGSQL.5432" .2019-01-07 14:13:34.361 CST [1649] LOG: database system was interrupted; last known up at 2019-01-07 12:26:22 CST 2019-01-07 14:13:34.818 CST [1649] LOG: database system was not properly shut down; automatic recovery in progress 2019-01-07 14:13:34.863 CST [1649] LOG: redo starts at 1/48F9ED08 .2019-01-07 14:13:35.467 CST [1649] LOG: invalid record length at 1/4914FF58: wanted 24, got 0 2019-01-07 14:13:35.467 CST [1649] LOG: redo done at 1/4914FF30 2019-01-07 14:13:35.467 CST [1649] LOG: last completed transaction was at log time 2019-01-07 12:28:37.521542+08 2019-01-07 14:13:35.977 CST [1648] LOG: database system is ready to accept connections done server started
经分析,是因为共享内存结构中的CheckpointerShmem->ckpt_lck导致的.
在跟踪checkpointer进程时,执行
SpinLockRelease(&CheckpointerShmem->ckpt_lck);
释放lock后,不再出现上述问题.
网站名称:PostgreSQL跟踪checkpointer出现死锁
当前网址:http://myzitong.com/article/psojgd.html