PostgreSQL恢复系列:wal日志丢失恢复

联系:手机/微信(+86 17813235971) QQ(107644445)QQ咨询惜分飞

标题:PostgreSQL恢复系列:wal日志丢失恢复

作者:惜分飞©版权所有[未经本人同意,不得以任何形式转载,否则有进一步追究法律责任的权利.]

WAL是Write Ahead Log的简写,和oracle的redo日志类似,存放在$PGDATA/pg_xlog中,10版本以后在$PGDATA/pg_wal目录.在oracle数据库中,如果redo丢失,分为active/current和inactive的redo,分别有不同的处理方式,对于oracle需要实例恢复的redo丢失,需要屏蔽数据库一致性,强制打开数据库,对于PG数据库这部分日志丢失该如何恢复,主要是通过pg_resetwal/pg_resetxlog(10以前版本)命令来实现,这里通过一个测试来验证
创建测试表并强制kill数据库

-bash-4.2$ psql
psql (14.3)
Type "help" for help.

postgres=# create table t_xifenfei as select * from pg_database;
SELECT 4
postgres=# select count(1) from t_xifenfei;
 count 
-------
     4
(1 row)

postgres=# \q
-bash-4.2$ ps -ef|grep post
root       1819      1  0 May28 ?        00:00:00 /usr/libexec/postfix/master -w
postfix    1838   1819  0 May28 ?        00:00:00 qmgr -l -t unix -u
postgres  11102      1  0 05:49 ?        00:00:00 /usr/pgsql-14/bin/postgres -D /var/lib/pgsql/14/data
postgres  11103  11102  0 05:49 ?        00:00:00 postgres: logger 
postgres  11105  11102  0 05:49 ?        00:00:00 postgres: checkpointer 
postgres  11106  11102  0 05:49 ?        00:00:00 postgres: background writer 
postgres  11107  11102  0 05:49 ?        00:00:00 postgres: walwriter 
postgres  11108  11102  0 05:49 ?        00:00:00 postgres: autovacuum launcher 
postgres  11109  11102  0 05:49 ?        00:00:01 postgres: stats collector 
postgres  11110  11102  0 05:49 ?        00:00:00 postgres: logical replication launcher 
root      22743  22300  0 18:26 pts/3    00:00:00 su - postgres
postgres  22744  22743  0 18:26 pts/3    00:00:00 -bash
postgres  22937  22744  0 18:28 pts/3    00:00:00 psql
postgres  22938  11102  0 18:28 ?        00:00:00 postgres: postgres postgres [local] idle
postfix   32623   1819  0 21:10 ?        00:00:00 pickup -l -t unix -u
root      33032  32912  0 21:15 pts/2    00:00:00 su - postgres
postgres  33033  33032  0 21:15 pts/2    00:00:00 -bash
postgres  35210  33033  0 21:51 pts/2    00:00:00 ps -ef
postgres  35211  33033  0 21:51 pts/2    00:00:00 grep --color=auto post
-bash-4.2$ kill -9 11102

删除wal日志

-bash-4.2$ pwd
/var/lib/pgsql/14/data/pg_wal
-bash-4.2$ ls -ltr
total 311296
drwx------. 2 postgres postgres        6 May 24 02:20 archive_status
-rw-------. 1 postgres postgres 16777216 May 28 21:29 000000010000000000000014
-rw-------. 1 postgres postgres 16777216 May 28 21:29 000000010000000000000015
-rw-------. 1 postgres postgres 16777216 May 28 21:29 000000010000000000000016
-rw-------. 1 postgres postgres 16777216 May 28 21:29 000000010000000000000017
-rw-------. 1 postgres postgres 16777216 May 28 21:29 000000010000000000000018
-rw-------. 1 postgres postgres 16777216 May 28 21:29 000000010000000000000019
-rw-------. 1 postgres postgres 16777216 May 28 21:29 00000001000000000000001A
-rw-------. 1 postgres postgres 16777216 May 28 21:29 00000001000000000000001B
-rw-------. 1 postgres postgres 16777216 May 28 21:29 00000001000000000000001C
-rw-------. 1 postgres postgres 16777216 May 28 21:29 00000001000000000000001D
-rw-------. 1 postgres postgres 16777216 May 28 21:29 00000001000000000000001E
-rw-------. 1 postgres postgres 16777216 May 28 21:29 00000001000000000000001F
-rw-------. 1 postgres postgres 16777216 May 28 21:29 000000010000000000000020
-rw-------. 1 postgres postgres 16777216 May 28 21:29 000000010000000000000021
-rw-------. 1 postgres postgres 16777216 May 28 21:29 000000010000000000000022
-rw-------. 1 postgres postgres 16777216 May 28 21:30 000000010000000000000023
-rw-------. 1 postgres postgres 16777216 May 28 21:30 000000010000000000000024
-rw-------. 1 postgres postgres 16777216 May 28 21:30 000000010000000000000025
-rw-------. 1 postgres postgres 16777216 May 29 21:51 000000010000000000000013
-bash-4.2$ rm -rf 0000000100000000000000*
-bash-4.2$ ls
archive_status

查询当时数据库需要的最小wal记录

-bash-4.2$ pg_controldata 
pg_control version number:            1300
Catalog version number:               202107181
Database system identifier:           7100998319216817119
Database cluster state:               in production
pg_control last modified:             Sat 28 May 2022 09:36:11 PM CST
Latest checkpoint location:           0/13692F80
Latest checkpoint's REDO location:    0/13692F48
Latest checkpoint's REDO WAL file:    000000010000000000000013   <===需要的记录
Latest checkpoint's TimeLineID:       1
Latest checkpoint's PrevTimeLineID:   1
Latest checkpoint's full_page_writes: on
Latest checkpoint's NextXID:          0:17824
Latest checkpoint's NextOID:          32769
Latest checkpoint's NextMultiXactId:  1
Latest checkpoint's NextMultiOffset:  0
Latest checkpoint's oldestXID:        727
Latest checkpoint's oldestXID's DB:   1
Latest checkpoint's oldestActiveXID:  17824
Latest checkpoint's oldestMultiXid:   1
Latest checkpoint's oldestMulti's DB: 1
Latest checkpoint's oldestCommitTsXid:0
Latest checkpoint's newestCommitTsXid:0
Time of latest checkpoint:            Sat 28 May 2022 09:31:41 PM CST

尝试启动PG

-bash-4.2$ pg_ctl start
pg_ctl: another server might be running; trying to start server anyway
waiting for server to start....2022-05-29 21:52:22.926 CST [35270] LOG:  
redirecting log output to logging collector process
2022-05-29 21:52:22.926 CST [35270] HINT:  Future log output will appear in directory "log".
. stopped waiting
pg_ctl: could not start server
Examine the log output.

启动pg失败,查看日志记录

2022-05-29 21:52:22.926 CST [35270] LOG:  starting PostgreSQL 14.3 on x86_64-pc-linux-gnu, 
            compiled by gcc (GCC) 4.8.5 20150623 (Red Hat 4.8.5-44), 64-bit
2022-05-29 21:52:22.927 CST [35270] LOG:  listening on IPv6 address "::1", port 5432
2022-05-29 21:52:22.927 CST [35270] LOG:  listening on IPv4 address "127.0.0.1", port 5432
2022-05-29 21:52:22.929 CST [35270] LOG:  listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
2022-05-29 21:52:22.931 CST [35270] LOG:  listening on Unix socket "/tmp/.s.PGSQL.5432"
2022-05-29 21:52:22.936 CST [35272] LOG:  database system was interrupted; last known up at 2022-05-28 21:36:11 CST
2022-05-29 21:52:23.049 CST [35272] LOG:  invalid primary checkpoint record
2022-05-29 21:52:23.049 CST [35272] PANIC:  could not locate a valid checkpoint record
2022-05-29 21:52:24.211 CST [35270] LOG:  startup process (PID 35272) was terminated by signal 6: Aborted
2022-05-29 21:52:24.211 CST [35270] LOG:  aborting startup due to startup process failure
2022-05-29 21:52:24.218 CST [35270] LOG:  database system is shut down

错误比较明显,无法定位到有效的checkpoint记录,在oracle里面的意思可以理解为无法进行实例恢复,pg启动失败

重设wal
由于数据库为不一致状态,需要使用-f进行强制重设

-bash-4.2$ pg_resetwal $PGDATA
The database server was not shut down cleanly.
Resetting the write-ahead log might cause data to be lost.
If you want to proceed anyway, use -f to force reset.
-bash-4.2$ pg_resetwal -f $PGDATA
Write-ahead log reset

启动PG成功

-bash-4.2$ pg_ctl start -D $PGDATA
waiting for server to start....2022-05-29 22:01:02.647 CST [37178] LOG:  
redirecting log output to logging collector process
2022-05-29 22:01:02.647 CST [37178] HINT:  Future log output will appear in directory "log".
 done
server started

日志记录

2022-05-29 22:01:02.647 CST [37178] LOG:  starting PostgreSQL 14.3 on x86_64-pc-linux-gnu, 
                    compiled by gcc (GCC) 4.8.5 20150623 (Red Hat 4.8.5-44), 64-bit
2022-05-29 22:01:02.648 CST [37178] LOG:  listening on IPv6 address "::1", port 5432
2022-05-29 22:01:02.648 CST [37178] LOG:  listening on IPv4 address "127.0.0.1", port 5432
2022-05-29 22:01:02.649 CST [37178] LOG:  listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
2022-05-29 22:01:02.651 CST [37178] LOG:  listening on Unix socket "/tmp/.s.PGSQL.5432"
2022-05-29 22:01:02.653 CST [37180] LOG:  database system was shut down at 2022-05-29 22:00:47 CST
2022-05-29 22:01:02.661 CST [37178] LOG:  database system is ready to accept connections

查看wal日志,产生新记录

-bash-4.2$ pwd
/var/lib/pgsql/14/data/pg_wal
-bash-4.2$ ls -ltr
total 16384
drwx------. 2 postgres postgres        6 May 24 02:20 archive_status
-rw-------. 1 postgres postgres 16777216 May 29 22:01 000000010000000000000014

验证刚刚创建测试表

-bash-4.2$ psql
psql (14.3)
Type "help" for help.

postgres=# select count(1) from t_xifenfei;
ERROR:  relation "t_xifenfei" does not exist
LINE 1: select count(1) from t_xifenfei;
                             ^

由于需要进行实例恢复的wal日志丢失导致这表记录也丢失.由此可见这类操作可能导致数据丢失风险,对于生产环境,需要慎重,

pvcreate asm disk导致asm磁盘组异常恢复

联系:手机/微信(+86 17813235971) QQ(107644445)QQ咨询惜分飞

标题:pvcreate asm disk导致asm磁盘组异常恢复

作者:惜分飞©版权所有[未经本人同意,不得以任何形式转载,否则有进一步追究法律责任的权利.]

一客户asm磁盘组异常,无法正常mount

SQL> alter diskgroup datadg mount 
2022-05-28T19:08:55.114960+08:00
NOTE: cache registered group DATADG 1/0x2B504997
NOTE: cache began mount (first) of group DATADG 1/0x2B504997
NOTE: Assigning number (1,3) to disk (/dev/oracleasm/disks/DATA05)
NOTE: Assigning number (1,2) to disk (/dev/oracleasm/disks/DATA03)
NOTE: Assigning number (1,1) to disk (/dev/oracleasm/disks/DATA02)
2022-05-28T19:08:55.150062+08:00
ERROR: no read quorum in group: required 1, found 0 disks
2022-05-28T19:08:55.150684+08:00
NOTE: cache dismounting (clean) group 1/0x2B504997 (DATADG)
NOTE: messaging CKPT to quiesce pins Unix process pid: 15103, image: oracle@XFF01 (TNS V1-V3)
NOTE: dbwr not being msg'd to dismount
NOTE: LGWR not being messaged to dismount
NOTE: cache dismounted group 1/0x2B504997 (DATADG)
NOTE: cache ending mount (fail) of group DATADG number=1 incarn=0x2b504997
NOTE: cache deleting context for group DATADG 1/0x2b504997
2022-05-28T19:08:55.191073+08:00
GMON dismounting group 1 at 36 for pid 37, osid 15103
2022-05-28T19:08:55.191258+08:00
NOTE: Disk DATA02 in mode 0x8 marked for de-assignment
NOTE: Disk DATA03 in mode 0x8 marked for de-assignment
NOTE: Disk DATA05 in mode 0x8 marked for de-assignment
ERROR: diskgroup DATADG was not mounted
ORA-15032: not all alterations performed
ORA-15017: diskgroup "DATADG" cannot be mounted
ORA-15040: diskgroup is incomplete

通过报错信息,初步判断是由于少了asm disk导致(依据:1. ORA-15040,2.asmlib中的DATA01丢失),初步判断由于某种原因导致asmlib的磁盘异常,从而使得asm磁盘组无法正常mount,通过对dd 到本地的asm磁盘进行分析

C:\Users\XFF>kfed read H:\TEMP\asmdd\sdb6-o.dd
kfbh.endian:                          0 ; 0x000: 0x00
kfbh.hard:                            0 ; 0x001: 0x00
kfbh.type:                            0 ; 0x002: KFBTYP_INVALID
kfbh.datfmt:                          0 ; 0x003: 0x00
kfbh.block.blk:                       0 ; 0x004: blk=0
kfbh.block.obj:                       0 ; 0x008: file=0
kfbh.check:                           0 ; 0x00c: 0x00000000
kfbh.fcn.base:                        0 ; 0x010: 0x00000000
kfbh.fcn.wrap:                        0 ; 0x014: 0x00000000
kfbh.spare1:                          0 ; 0x018: 0x00000000
kfbh.spare2:                          0 ; 0x01c: 0x00000000
0066E8200 00000000 00000000 00000000 00000000  [................]
        Repeat 31 times
0066E8400 4542414C 454E4F4C 00000001 00000000  [LABELONE........]
0066E8410 4E06D490 00000020 324D564C 31303020  [...N ...LVM2 001]
0066E8420 34535542 476A7667 42546C48 6D384675  [BUS4gvjGHlTBuF8m]
0066E8430 7A385273 4B495777 73336242 33637449  [sR8zwWIKBb3sItc3]
0066E8440 48001000 000001E8 00100000 00000000  [...H............]
0066E8450 00000000 00000000 00000000 00000000  [................]
0066E8460 00000000 00000000 00001000 00000000  [................]
0066E8470 000FF000 00000000 00000000 00000000  [................]
0066E8480 00000000 00000000 00000002 00000000  [................]
0066E8490 00000000 00000000 00000000 00000000  [................]
  Repeat 214 times
KFED-00322: Invalid content encountered during block traversal: [kfbtTraverseBlock][Invalid OSM block type][][0]

通过这部分信息可以确认,一个asm disk被创建了pv,进一步分析pv信息
pv


对于这样的情况,表示asm disk被创建了pv但是pv没有加入到任何vg中,也就意味着该disk没有太大破坏,通过信息确认
20220529124428
20220529124734

主要是这两个部分信息被损坏,可以通过一些方法对这两个block信息进行重构

C:\Users\XFF>kfed read H:\TEMP\asmdd\sdb6.dd|more
kfbh.endian:                          1 ; 0x000: 0x01
kfbh.hard:                          130 ; 0x001: 0x82
kfbh.type:                            1 ; 0x002: KFBTYP_DISKHEAD
kfbh.datfmt:                          1 ; 0x003: 0x01
kfbh.block.blk:                       0 ; 0x004: blk=0
kfbh.block.obj:              2147483648 ; 0x008: disk=0
kfbh.check:                  3196491921 ; 0x00c: 0xbe869891
kfbh.fcn.base:                        0 ; 0x010: 0x00000000
kfbh.fcn.wrap:                        0 ; 0x014: 0x00000000
kfbh.spare1:                          0 ; 0x018: 0x00000000
kfbh.spare2:                          0 ; 0x01c: 0x00000000
kfdhdb.driver.provstr:   ORCLDISKDATA01 ; 0x000: length=14
kfdhdb.driver.reserved[0]:   1096040772 ; 0x008: 0x41544144
kfdhdb.driver.reserved[1]:        12592 ; 0x00c: 0x00003130
kfdhdb.driver.reserved[2]:            0 ; 0x010: 0x00000000
kfdhdb.driver.reserved[3]:            0 ; 0x014: 0x00000000
kfdhdb.driver.reserved[4]:            0 ; 0x018: 0x00000000
kfdhdb.driver.reserved[5]:            0 ; 0x01c: 0x00000000
kfdhdb.compat:                203424000 ; 0x020: 0x0c200100
kfdhdb.dsknum:                        0 ; 0x024: 0x0000
kfdhdb.grptyp:                        1 ; 0x026: KFDGTP_EXTERNAL
kfdhdb.hdrsts:                        3 ; 0x027: KFDHDR_MEMBER
kfdhdb.dskname:                  DATA01 ; 0x028: length=6
kfdhdb.grpname:                  DATADG ; 0x048: length=6
kfdhdb.fgname:                   DATA01 ; 0x068: length=6
kfdhdb.capname:                         ; 0x088: length=0
kfdhdb.crestmp.hi:             33083792 ; 0x0a8: HOUR=0x10 DAYS=0xc MNTH=0x4 YEAR=0x7e3
kfdhdb.crestmp.lo:           2268043264 ; 0x0ac: USEC=0x0 MSEC=0x3e6 SECS=0x32 MINS=0x21
kfdhdb.mntstmp.hi:             33134479 ; 0x0b0: HOUR=0xf DAYS=0x1c MNTH=0x5 YEAR=0x7e6
-- More  --

C:\Users\XFF>kfed read H:\TEMP\asmdd\sdb6.dd blkn=1|more
kfbh.endian:                          1 ; 0x000: 0x01
kfbh.hard:                          130 ; 0x001: 0x82
kfbh.type:                            2 ; 0x002: KFBTYP_FREESPC
kfbh.datfmt:                          2 ; 0x003: 0x02
kfbh.block.blk:                       1 ; 0x004: blk=1
kfbh.block.obj:              2147483648 ; 0x008: disk=0
kfbh.check:                  2177715180 ; 0x00c: 0x81cd4bec
kfbh.fcn.base:                  3721754 ; 0x010: 0x0038ca1a
kfbh.fcn.wrap:                        0 ; 0x014: 0x00000000
kfbh.spare1:                          0 ; 0x018: 0x00000000
kfbh.spare2:                          0 ; 0x01c: 0x00000000
kfdfsb.aunum:                         0 ; 0x000: 0x00000000
kfdfsb.max:                        1014 ; 0x004: 0x03f6
kfdfsb.cnt:                        1014 ; 0x006: 0x03f6
kfdfsb.bound:                         0 ; 0x008: 0x0000
kfdfsb.flag:                          1 ; 0x00a: B=1
kfdfsb.ub1spare:                      0 ; 0x00b: 0x00
kfdfsb.spare[0]:                      0 ; 0x00c: 0x00000000
kfdfsb.spare[1]:                      0 ; 0x010: 0x00000000
kfdfsb.spare[2]:                      0 ; 0x014: 0x00000000
kfdfse[0].fse:                        0 ; 0x018: FREE=0x0 FRAG=0x0
kfdfse[1].fse:                        0 ; 0x019: FREE=0x0 FRAG=0x0
kfdfse[2].fse:                        0 ; 0x01a: FREE=0x0 FRAG=0x0
kfdfse[3].fse:                        0 ; 0x01b: FREE=0x0 FRAG=0x0
kfdfse[4].fse:                        0 ; 0x01c: FREE=0x0 FRAG=0x0
kfdfse[5].fse:                        0 ; 0x01d: FREE=0x0 FRAG=0x0
kfdfse[6].fse:                        0 ; 0x01e: FREE=0x0 FRAG=0x0
kfdfse[7].fse:                        0 ; 0x01f: FREE=0x0 FRAG=0x0
kfdfse[8].fse:                        0 ; 0x020: FREE=0x0 FRAG=0x0

通过dd写入到原磁盘,通过oracleasm scandisks扫描磁盘
scandisks


磁盘组mount成功
mount

数据库顺利open
20220529140558

20220529140813


这个案例能够完美恢复,主要是客户没有做进一步破坏,没有把这个pv加入到vg中并且写入数据,以前有过类似案例因为写入了数据,恢复比这个难多了,效果也没有这个好asm disk被加入vg恢复
如果不幸有类似oracle asm disk被破坏(格式化,dd部分,做成lv等),需要进行恢复支持,可以联系我们,做专业的恢复评估,最大限度,最快速度抢救数据,减少损失
Phone:17813235971    Q Q:107644445QQ咨询惜分飞    E-Mail:dba@xifenfei.com
恢复过部分asm异常案例:
删除分区 oracle asm disk 恢复
asm disk 磁盘部分被清空恢复
又一例asm格式化文件系统恢复
一次完美的asm disk被格式化ntfs恢复
oracle asm disk格式化恢复—格式化为ext4文件系统
oracle asm disk格式化恢复—格式化为ntfs文件系统
分享oracleasm createdisk重新创建asm disk后数据0丢失恢复案例