最近一个客户的生产环境遇到这样的一个问题。背景大致说明下,就是机房断电,所有的服务器都异常关机,在电力恢复之后,重启服务器发现数据库服务不能正常启动。由于这个节点的数据库很多,而且定时备份很久之前都坏了,有效的备份都是几个月之前的,并且备份还不是全备,只有部分做了备份,很多边缘的数据库都没有备份,甚至有很多都是与业务紧密相关的,不能说重新初始化一个实例,然后根据备份直接去解压还原。下面是数据库启动的日志信息
2023-07-11 16:11:02.991 CST [1046] 0 LOG: starting PostgreSQL 14.2 on x86_64-pc-linux-gnu, compiled by gcc (GCC) 4.8.5 20150623 (Red Hat 4.8.5-44), 64-bit
2023-07-11 16:11:02.991 CST [1046] 0 LOG: listening on IPv4 address "0.0.0.0", port 5432
2023-07-11 16:11:02.992 CST [1046] 0 LOG: listening on IPv6 address "::", port 5432
2023-07-11 16:11:02.993 CST [1046] 0 LOG: listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
2023-07-11 16:11:02.995 CST [1046] 0 LOG: listening on Unix socket "/tmp/.s.PGSQL.5432"
2023-07-11 16:11:03.016 CST [1279] 0 LOG: database system was interrupted; last known up at 2023-07-10 18:26:58 CST
2023-07-11 16:11:03.884 CST [1279] 0 LOG: invalid record length at 7/B5F401B8: wanted 24, got 0
2023-07-11 16:11:03.884 CST [1279] 0 LOG: invalid primary checkpoint record
2023-07-11 16:11:03.884 CST [1279] 0 PANIC: could not locate a valid checkpoint record
2023-07-11 16:11:03.887 CST [1046] 0 LOG: startup process (PID 1279) was terminated by signal 6: Aborted
2023-07-11 16:11:03.887 CST [1046] 0 LOG: aborting startup due to startup process failure
2023-07-11 16:11:03.913 CST [1046] 0 LOG: database system is shut down
2023-07-11 16:21:01.627 CST [20792] 0 LOG: starting PostgreSQL 14.2 on x86_64-pc-linux-gnu, compiled by gcc (GCC) 4.8.5 20150623 (Red Hat 4.8.5-44), 64-bit
2023-07-11 16:21:01.627 CST [20792] 0 LOG: listening on IPv4 address "0.0.0.0", port 5432
2023-07-11 16:21:01.627 CST [20792] 0 LOG: listening on IPv6 address "::", port 5432
2023-07-11 16:21:01.628 CST [20792] 0 LOG: listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
2023-07-11 16:21:01.630 CST [20792] 0 LOG: listening on Unix socket "/tmp/.s.PGSQL.5432"
2023-07-11 16:21:01.645 CST [20794] 0 LOG: database system was interrupted; last known up at 2023-07-10 18:26:58 CST
2023-07-11 16:21:01.850 CST [20794] 0 LOG: invalid record length at 7/B5F401B8: wanted 24, got 0
2023-07-11 16:21:01.850 CST [20794] 0 LOG: invalid primary checkpoint record
2023-07-11 16:21:01.850 CST [20794] 0 PANIC: could not locate a valid checkpoint record
2023-07-11 16:21:01.851 CST [20792] 0 LOG: startup process (PID 20794) was terminated by signal 6: Aborted
2023-07-11 16:21:01.851 CST [20792] 0 LOG: aborting startup due to startup process failure
2023-07-11 16:21:01.884 CST [20792] 0 LOG: database system is shut down
从上面的日志信息中我们可以找到关键的几个信息:
LOG: invalid record length at 7/B5F401B8: wanted 24, got 0
LOG: invalid primary checkpoint record
PANIC: could not locate a valid checkpoint record
从上面的信息中我们可以了解到是找不到有效的检查点记录。网上搜索给出的解释是 WAL 日志文件损坏,这种一般是操作系统故障或者是硬件损坏会引起这个问题。服务器直接关机这种情况我们说实战演练用的也比较多,因为经常需要进行演练断电或者高可用测试都需要进行系统关机,但是关机之后重启系统服务还是可以正常启动的,但是这里直接启动不了了,再者我们知道服务器就算关机后,数据库也会进行启动恢复的。这一点不论是 PostgreSQL 还是别的什么数据库都是有这种机制在底层实现的。
下面我们简单描述下数据库异常关闭后恢复的过程:
当数据库异常关闭时,数据库的共享缓冲区中的数据还没有来得及刷到磁盘中,必然是会丢失,这个时候启动数据库便是从不正常的状态去启动,也就是我们要研究的崩溃恢复。我们说几乎任意一个数据库都有类似检查点这种操作,当 PostgreSQL 数据库崩溃恢复时,会以最近的 checkpoint 为基础,不断应用这之后的重做日志。为了更好地理解 PostgreSQL 数据库从崩溃中恢复的过程,我们需要弄清楚以下几个问题:
数据库操作系统如何识别到自己是非正常状态崩溃状态?
数据库如何找到合适的 checkpoint 作为基础?
为什么应用重做日志可以恢复数据库数据?
数据库如何应用重做日志?
PostgreSQL 数据库的状态有如下几种
DB_STARTUP = 0 /*数据库启动*/
DB_SHUTDOWNED /*数据库正常关闭*/
DB_SHUTDOWNED_IN_RECOVERY /*数据库在恢复时关闭*/
DB_SHUTDOWNING /*数据库启动到正常关闭过程中崩溃*/
DB_IN_CRASH_RECOVERY /*数据库在恢复过程中崩溃*/
DB_IN_ARCHIVE_RECOVERY /*数据库处于归档恢复*/
DB_IN_PRODUCTION /*数据库处于正常工作状态,等待接受事务处理*/
当数据库正常关闭时,数据库状态便是 shut down,如果是异常关闭,可能会如下所示:
Database cluster state: in production 而每次当 PostgreSQL 数据库启动时,会首先读取控制文件获取数据库的状态,如果为非正常关闭状态,则会执行崩溃恢复逻辑。
Chekpoint 相关结构:当数据库进行崩溃恢复时,因为需要恢复异常关闭时丢失的共享内存中的相关数据,所以需要通过 checkpoint 检查点来作为基础,不断的应用重做日志即 wal 日志来恢复。而 checkpoint 相关的信息在 PostgreSQL 中是存放在控制文件中的。
XLogRecPtr checkPoint /*指向最近一次的检查点位置*/
XLogRecPtr prevCheckPoint /*指向最近一次检查点的前一次检查点的位置*/
CheckPoint checkPointCopy /*最近一次检查点控制信息的副本*/
XLogRecPtr minRecoveryPoint /*归档恢复时必须恢复到的最小 LSN*/
XLogRecPtr backupStartPoint /*在线备份时进行的检查点开始 LSN*/
XLogRecPtr backupEndPoint /*在线备份时进行的检查点结束 LSN*/
bool backupEndRequired /* 用于判断是否基于正确的在线备份集恢复*/
TimeLineID minRecoveryPointTLI /* 必须恢复到的最小时间线 */
/usr/pgsql-14/bin/pg_controldata -D /home/postgres/pgsql-14/data/ | grep checkpoint
一般来说都会选取最近一次的 checkpoint 作为恢复点,但是会存在这样的一种特殊情况:在执行最近一次的 checkpoint 时数据库异常关闭了,那么这个检查点可能是不完整的。因此一般还会多存储一个检查点的位置,即 prevCheckPoint。在数据库崩溃恢复过程中,PostgreSQL 规定了三个在启动之前必须恢复到的最小位点:
minRecoveryPoint:数据库在归档恢复过程中,minRecoveryPoint 会被更新为最新被刷新到磁盘的最近一次检查点 LSN。每次数据库启动时必须已经 replay 该位置的重做日志记录。
backupStartPoint:数据库在线备份开始时,会调用 pg_start_backup 函数执行一次 checkpoint,并生成 backup_label 文件。当使用在线备份集进行恢复时,backupStartPoint 就是上述 checkpoint 记录对应的 LSN,当达到了该 LSN,该值置为 0,在置为 0 之前,数据库不能启动。该值被记录在 backup_label 文件中如下,直到在线备份结束,pg_stop_backup 将该文件删除。这样就保证了在备份过程中,数据库崩溃了,可以默认从备份开始时的日志检查点开始恢复。
backupEndPoint:当数据库从一个备库做的在线备份集进行恢复时,backupEndPoint 表示备份结束的 LSN,当达到该 LSN,该值置为 0,在置为 0 之前,数据库不能启动。
崩溃恢复具体过程:每次 postmaster 进程启动时,都会调用 StartupXLOG 函数对数据库崩溃进行恢复。其恢复过程大致为:
初始化内存,启动后台进程。
PostgreSQL 在启动时读取 pg_control 文件内容。如果 state 为 ’in production’,PostgreSQL 将进入恢复模式,因为这意味着数据库没有正常停止;如果为 ’shutdown’,将进入正常启动模式。PostgreSQL 从相应的 WAL 段文件中读取最新的检查点记录,该位置位于 pg_control 文件中,并从记录中获取重做点。如果最新的检查点记录无效 invalid,PostgreSQL 将读取前一个检查点的记录。如果两个记录都不可读,将放弃恢复。
那么既然我们已经大致了解了是什么原因之后,如何恢复呢?
1、首先我们需要备份当前数据目录到一个新的位置。
2、强制重置 WAL 日志,/usr/pgsql-14/bin/pg_resetwal -f -D /home/postgres/pgsql-14/data/
3、再次去启动数据库 /usr/pgsql-14/bin/pg_ctl restart -D /home/postgres/pgsql-14/data/