【深度】ArteryBase事务日志（4）– 事务日志误删怎么办

2022-03-29 15:09:07

【深度】ArteryBase事务日志（4）– 事务日志误删怎么办

@(arterybase)

概述

在实际使用中，由于各种各样等原因，可能会将事务日志删掉，这种情况如何处理，是不是就整个库就完全不能用了？

例子1

数据库启动后，连到数据库上，插入1千万条数据。然后关闭数据库

pg_ctl start -w
psql postgres sa -c "insert into test1 select generate_series(1, 10000000)"
pg_ctl stop

删除事务日志

cd $PGDATA/pg_xlog
rm 0000*

重启数据库，无法启动

pg_ctl start
 LOG:  database system was shut down at 2016-10-20 11:24:06 CST
LOG:  invalid primary checkpoint record
LOG:  invalid secondary checkpoint record
PANIC:  could not locate a valid checkpoint record
LOG:  startup process (PID 52721) was terminated by signal 6: Aborted
LOG:  aborting startup due to startup process failure

使用pg_controldata工具查看控制文件中的信息，得到后一个检查点的信息，如nextXID、nextOID。

$ pg_controldata | grep "Latest checkpoint's Next"
Latest checkpoint's NextXID:          0/1875
Latest chekpoint's NextOID:          40975
Latest checkpoint's NextMultiXactId:  1
Latest checkpoint's NextMultiOffset:

下一步，我们根据以上信息使用pg_resetxlog将事务日志初始化

注意： 我们一定只把它用作后的方法，就是说只有因为这样的崩溃导致服务器无法启动的时候才使用。

$ pg_resetxlog -o 40975 -x 1875 -f $PGDATA
Transaction log reset

启动数据库，可正常启动

$ pg_ctl start -w
waiting for server to start....LOG:  database system was shut down at 2016-10-20 11:28:14 CST
LOG:  MultiXact member wraparound protections are now enabled
LOG:  database system is ready to accept connections
LOG:  autovacuum launcher started
 done
server started

访问及导出所有的表，均没有错误

psql postgres sa -c "select count(*) from test1"
  count  
---------
 1000000
(1 row)
pg_dumpall -U sa >test.dmp

通过以上例子，说明在数据库正常关机情况下，删除事务日志文件，数据库是可以恢复正常的。根据前文《【深度】ArteryBase事务日志（2）--从关机中恢复》一文中，正常关机情况下（pg_ctl stop，不加-m immediate参数）会创建关机检查点，事务日志和数据文件保持一致。重新启动时，无需重做即可恢复。

例子2

数据库启动后，待psql连到数据库上后，杀掉数据库守护进程；

$ ps -ef | grep postgres
appuser  44913 25901   04:31 pts/2    00:00:00 psql postgres appuser
appuser  52758     1   11:28 pts/    00:00:00 /home/appuser/workspace/arterybase/bin/postgres
appuser  52760 52758   11:28 ?        00:00:00 postgres: checkpointer process                 
appuser  52761 52758   11:28 ?        00:00:00 postgres: writer process                       
appuser  52762 52758   11:28 ?        00:00:00 postgres: wal writer process                   
appuser  52763 52758   11:28 ?        00:00:00 postgres: autovacuum launcher process          
appuser  52764 52758   11:28 ?        00:00:00 postgres: stats collector process              
appuser  52834 52497   11:34 pts/    00:00:00 grep postgres
$ kill -9 52758

在psql窗口写sql插入一千万条数据后，杀掉psql对应的服务进程

psql postgres sa
#select pg_backend_pid();
 pg_backend_pid 
----------------
          52877
(1 row)
#insert into test1 select generate_series(1, 10000000);
Kill -9 52877

然后将pg_xlog下的事务日志都删除，然后启动数据库，数据库报错：

$ pg_ctl start
LOG:  database system was interrupted; last known up at 2016-10-20 13:36:28 CST
LOG:  invalid primary checkpoint record
LOG:  invalid secondary checkpoint record
PANIC:  could not locate a valid checkpoint record
LOG:  startup process (PID 53557) was terminated by signal 6: Aborted
LOG:  aborting startup due to startup process failure

跟踪源码：在读取xlog文件时，找不到文件，以下为报错堆栈：

(gdb) backtrace
#0  XLogFileRead (segno=3915, emode=13,    tli=1, source=2, notfoundOk=1 '\001') at xlog.c:3351
#1  0x0000000000521342 in XLogFileReadAnyTLI (segno=3915, emode=13, source=2) at xlog.c:3436
#2  0x000000000052fcc3 in WaitForWALToBecomeAvailable (RecPtr=65682808832, randAccess=1 '\001',    fetching_ckpt=1 '\001', tliRecPtr=65682920312) at xlog.c:11291
#3  0x000000000052f560 in XLogPageRead (xlogreader=0xe7af18, targetPagePtr=65682800640,    reqLen=8192, targetRecPtr=65682920312, readBuf=0xe7b838 "", readTLI=0xe7b7c0) at xlog.c:10956
#4  0x0000000000534a24 in ReadPageInternal (state=0xe7af18, pageptr=65682915328, reqLen=5008) at xlogreader.c:524
#5  0x0000000000534264 in XLogReadRecord (state=0xe7af18, RecPtr=65682920312, errormsg=0x7fffffffd2f8) at xlogreader.c:243
#6  0x00000000005221e1 in ReadRecord (xlogreader=0xe7af18, RecPtr=65682920312, emode=15, fetching_ckpt=1 '\001') at xlog.c:3922
#7  0x0000000000529632 in ReadCheckpointRecord (xlogreader=0xe7af18, RecPtr=65682920312, whichChkpt=1, report=1 '\001')    at xlog.c:7660
#8  0x000000000052717b in StartupXLOG () at xlog.c:6175
#9  0x000000000076e394 in StartupProcessMain ()    at startup.c:215
#10 0x000000000053af6f in AuxiliaryProcessMain (argc=2,    argv=0x7fffffffdf80) at bootstrap.c:418
#11 0x000000000076d557 in StartChildProcess (type=StartupProcess) at postmaster.c:5203
#12 0x00000000007683b3 in PostmasterMain (argc=1, argv=0xe50f90) at postmaster.c:1288
#13 0x00000000006c018a in main (argc=1,    argv=0xe50f90) at main.c:228

由于无法读取到xlog文件，系统返回NULL，在xlog.c文件中的ReadCheckpointRecord方法，输出错误日志后退出。(处理过程中，后一个检查点对应的xlog未找到，又往前找前一个检查点的xlog，如果都未找到，才退出)

record = ReadCheckpointRecord(xlogreader, checkPointLoc, 1, true);
        if (record != NULL)
        {
            ...
        }
        /* 从库模式 */
        else if (StandbyMode)
        {
            ...
        }
        /* 未找到继续找前一个检查点 */
        else
        {
            checkPointLoc = ControlFile->prevCheckPoint;
            record = ReadCheckpointRecord(xlogreader, checkPointLoc, 2, true);
            if (record != NULL)
            {
                ...
            }
            else
                ereport(PANIC,
                     (errmsg("could not locate a valid checkpoint record")));
        }

守护进程检测到startup process非正常退出，输出无法启动数据库，退出。

while ((pid = waitpid(-1, &exitstatus, WNOHANG)) > )
{
    if (pid == StartupPID)
    {
        ......
        /* 状态不为0，退出 */
        if (pmState == PM_STARTUP && !EXIT_STATUS_0(exitstatus))
        {
            LogChildExit(LOG, _("startup process"),
                         pid, exitstatus);
            ereport(LOG,
            (errmsg("aborting startup due to startup process failure")));
            ExitPostmaster(1);
        }
        ......

使用pg_controldata工具查看控制文件$PGDATA/global/pg_control中的信息，得到后一个检查点的信息，如nextXID、nextOID。

$ pg_controldata | grep "Latest checkpoint's Next"
Latest checkpoint's NextXID:          0/1864
Latest checkpoint's NextOID:          40971
Latest checkpoint's NextMultiXactId:  1
Latest checkpoint's NextMultiOffset:

下一步，我们将系统从后一个检查点接起来，忽略在检查点之间产生的信息
使用pg_resetxlog恢复

注意： 我们一定只把它用作后的方法，就是说只有因为这样的崩溃导致服务器无法启动的时候才使用。

$ pg_resetxlog -o 40971 -x 1864 -f $PGDATA
Transaction log reset

启动数据库

$ pg_ctl start -w
waiting for server to start....LOG:  database system was shut down at 2016-10-19 14:04:37 CST
LOG:  MultiXact member wraparound protections are now enabled
LOG:  database system is ready to accept connections
LOG:  autovacuum launcher started
 done
server started

数据库虽然已经启动，但启动后一段时间，查看后台日志，频繁报错：

CONTEXT:  writing block 625696 of relation base/13241/40970
ERROR:  xlog flush request E/DA06ED78 is not satisfied --- flushed only to E/DA014238
DETAIL:  Multiple failures --- write error might be permanent.

根据日志查看是哪个表出了问题，是被杀掉的进程对应的表test1出问题了。

select relname from pg_class where relfilenode = 40970;
relname 
---------
 test1
(1 row)

此时，其他操作均无法进行，重启数据库，访问该表部分数据ok，访问全部数据报错，报错后系统无法使用。

select * from test1 limit 10;
---ok
select count(*) from test1;
--报错
LOG:  request to flush past end of generated WAL; request E/DB0D7368, currpos E/DB0AD130
CONTEXT:  writing block 626882 of relation base/13241/40970
FATAL:  xlog flush request E/DB0D7368 is not satisfied --- flushed only to E/DB0AD130

重启后将该表的数据导出。

pg_dump -d postgres -U sa -t test1 >test1.dmp

导出过程中也报上述错误，但该数据确实可以导出。

清空test1表，并导入备份数据。

psql postgres sa -c "truncate table test1"
psql postgres sa -f test1.dmp

成功导入，但数据不完整。因为在杀进程时，部分脏页写回磁盘，部分未写，又没有事务日志来redo。因此，应该从业务上校正这些数据。

注意：以上报错情形只是可能出现的一种情形，如果脏页完全未写入磁盘，也有可能数据完全未插入。总之，可能出现各种奇怪的数据。
后续处理
虽然进行了恢复，但数据完整性得不到保证。应该将实例A作为保留实例，新建一个数据库实例B，并将实例A中的数据导入到实例B，并进行数据校正，校正后方可使用。

总结

事务日志系列文章4篇，详细介绍了事务日志原理、事务日志文件为什么不能通过直接删除文件的方式删除、事务日志膨胀原因解决办法以及事务日志误删的处理方法，希望能够了解事务日志的运行机理，避免因为不了解导致严重问题，当出现严重问题时，能够迅速想到解决办法，提高数据库的可用性。

来自：https://mp.weixin.qq.com/s/nwV0gSANAysRCKif3mx0nQ

分享好友

分享这个小栈给你的朋友们，一起进步吧。

ArteryBase

创建时间：2022-03-29 14:58:09

ArteryBase

展开

订阅须知

• 所有用户可根据关注领域订阅专区或所有专区

• 付费订阅：虚拟交易，一经交易不退款；若特殊情况，可3日内客服咨询

• 专区发布评论属默认订阅所评论专区（除付费小栈外）

技术专家

查看更多

gaokeke123
专家