“PostgreSQL 日志里 database system was not properly shut down; automatic recovery in progress 是什么意思、崩溃之后数据会丢吗、要恢复多久” 都可以用 kill -9 直接复现。这篇在本机自己起一个 PostgreSQL 16.15,杀后端、杀主进程,看日志、pg_controldata、恢复耗时和 unlogged 表的结局。
kill -9 一个后端之后,0.06 s 实例又能连上了;日志:
LOG: server process (PID <pid>) was terminated by signal 9: Killed: 9
DETAIL: Failed process was running: select pg_backend_pid()
LOG: terminating any other active server processes
LOG: all server processes terminated; reinitializing
LOG: database system was not properly shut down; automatic recovery in progress
LOG: redo starts at 0/<lsn>
LOG: redo done at 0/<lsn> system usage: CPU: user: 0.00 s, system: 0.00 s, elapsed: 0.00 s
LOG: database system is ready to accept connections
另一个连接(正在事务里)之后的报错: OperationalError: consuming input failed: server closed the connection unexpectedly
崩溃前没提交的 insert(id = 5000)还在不在: 0 行;已提交的 1000 行: 1000 行kill -9 一个后端会让所有连接断开、实例重新初始化并做崩溃恢复,没提交的事务消失。
崩溃前的 pg_controldata: in production
postmaster 被杀之后,pg_controldata: in production ;postmaster.pid 还在: True
pg_ctl start 的输出: waiting for server to start.... done | server started | pg_ctl: another server might be running; trying to start server anyway
LOG: database system was not properly shut down; automatic recovery in progress
LOG: redo starts at 0/<lsn>
LOG: invalid record length at 0/<lsn>: expected at least 24, got 0
LOG: redo done at 0/<lsn> system usage: CPU: user: 0.00 s, system: 0.00 s, elapsed: 0.00 s
LOG: checkpoint starting: end-of-recovery immediate wait
LOG: checkpoint complete: wrote 11 buffers (0.1%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.001 s, sync=0.001 s, total=0.001 s; sync files=5, longest=0.001 s,
LOG: database system is ready to accept connections
恢复之后 2500 以内的已提交行数: 1500 (1000 + 500 条是崩溃前提交的)postmaster 被杀后 pg_controldata 仍是 in production,再启动时做恢复;pg_ctl 会提示 another server might be running。
崩溃前的 WAL 量 启动到可连接 s 日志里 redo 耗时 s
8 MB 0.13 0.01
61 MB 0.26 0.08
230 MB 0.56 0.36大致随上次检查点后的 WAL 量线性增长,是检查点间隔的权衡。
崩溃前:unlogged 表 1000 行,普通表 id=9999: 1 行 崩溃恢复后:unlogged 表 0 行,普通表 id=9999: 1 行
不写 WAL,崩溃恢复后被清空。
fast 关闭之后,pg_controldata: shut down 再启动用了 0.13 s;日志里 not properly shut down:没有,redo starts:没有
fast 关闭做关闭检查点,再启动不需要 redo。