【测试类型：工具功能】【测试版本：6.0.0】【可靠性】xstore场景，执行可靠性用例，会出现备机无法恢复的问题，第一次备机全量build到节点启动阶段失败，第二次全量build未到启动阶段失败

【标题描述】: xstore场景，第一次备机全量build到节点启动阶段失败，第二次全量build未到启动阶段失败
【测试类型：工具功能】【测试版本：6.0.0】xstore场景，执行可靠性用例，第一次备机全量build到节点启动阶段失败，第二次全量build未到启动阶段失败

【操作系统和硬件信息】(查询命令: cat /etc/system-release, uname -a):
CentOS Linux release 7.6.1908 (Core)

【测试环境】(单机/1主x备x级联备):
一主一备

【被测功能】:
ustore场景build功能

【测试类型】:
可靠性测试

【数据库版本】(查询命令: gaussdb -V):
gaussdb (openGauss 6.0.0 build 53bc767d) compiled at 2024-08-28 12:08:45 commit 0 last mr

【预置条件】:
1. 数据库功能正常
2. tpcc建仓，ustore表类型
 
【操作步骤】(请填写详细的操作步骤):
1. 执行可靠性用例
![输入图片说明](https://foruda.gitee.com/images/1725960355002566258/f85dbba7_8568116.png "屏幕截图")

【预期输出】:
1. 执行成功

【实际输出】:
1. 执行过程build备机出现问题

【原因分析】:
1. 这个问题的根因
2. 问题推断过程
3. 还有哪些原因可能造成类似现象
4. 该问题是否有临时规避措施
5. 问题解决方案
6. 预计修复问题时间

【日志信息】(请附上日志文件、截图、coredump信息):
第一次全量build失败，gs_ctl日志
```
[2024-09-04 11:18:49.322][46176][][gs_ctl]: gs_ctl full build ,datadir is /data/relia1137/cluster/dn1
[2024-09-04 11:18:49.325][46176][][gs_ctl]: fopen build pid file "/data/relia1137/cluster/dn1/gs_build.pid" success
[2024-09-04 11:18:49.325][46176][][gs_ctl]: fprintf build pid file "/data/relia1137/cluster/dn1/gs_build.pid" success
[2024-09-04 11:18:49.326][46176][][gs_ctl]: fsync build pid file "/data/relia1137/cluster/dn1/gs_build.pid" success
[2024-09-04 11:18:50.341][46176][][gs_ctl]: current workdir is (/home/relia1137).
[2024-09-04 11:18:50.342][46176][][gs_ctl]: set gaussdb state file when full build build:db state(BUILDING_STATE), server mode(STANDBY_MODE), build mode(FULL_BUILD).
[2024-09-04 11:18:50.343][46176][dn_6001_6002_6003][gs_ctl]: Get repl_auth_mode is  and repl_uuid is
[2024-09-04 11:18:50.376][46176][dn_6001_6002_6003][gs_ctl]: build try host(10.116.253.24) port(51138) success
[2024-09-04 11:18:50.376][46176][dn_6001_6002_6003][gs_ctl]: connected to server success, build started.
[2024-09-04 11:18:50.495][46176][dn_6001_6002_6003][gs_ctl]: clear old target dir success
[2024-09-04 11:18:50.495][46176][dn_6001_6002_6003][gs_ctl]: create build tag file success
[2024-09-04 11:18:50.495][46176][dn_6001_6002_6003][gs_ctl]: create build tag file again success
[2024-09-04 11:18:50.706][46176][dn_6001_6002_6003][gs_ctl]: get system identifier success
[2024-09-04 11:18:50.706][46176][dn_6001_6002_6003][gs_ctl]: create backup label success
INFO:  The starting position of the xlog copy of the full build is: 13/57FFD58. The slot minimum LSN is: 13/57FFD58. The disaster slot minimum LSN is: 0/0. The logical slot minimum LSN is: 0/0.
[2024-09-04 11:18:50.793][46176][dn_6001_6002_6003][gs_ctl]: xlog start point: 13/57FFD58
[2024-09-04 11:18:50.793][46176][dn_6001_6002_6003][gs_ctl]: begin build tablespace list
[2024-09-04 11:18:50.793][46176][dn_6001_6002_6003][gs_ctl]: finish build tablespace list
[2024-09-04 11:18:50.793][46176][dn_6001_6002_6003][gs_ctl]: begin get xlog by xlogstream
[2024-09-04 11:18:50.793][46176][dn_6001_6002_6003][gs_ctl]: starting background WAL receiver
[2024-09-04 11:18:50.793][46176][dn_6001_6002_6003][gs_ctl]: starting walreceiver
[2024-09-04 11:18:50.794][46176][dn_6001_6002_6003][gs_ctl]: begin receive tar files
[2024-09-04 11:18:50.818][46176][dn_6001_6002_6003][gs_ctl]: build try host(10.116.253.24) port(51138) success
[2024-09-04 11:18:50.821][46176][dn_6001_6002_6003][gs_ctl]: check identify system success
[2024-09-04 11:18:50.849][46176][dn_6001_6002_6003][gs_ctl]: send START_REPLICATION 13/5000000 success
[2024-09-04 11:30:36.149][46176][dn_6001_6002_6003][gs_ctl]: xlog end point: 13/13008D98
[2024-09-04 11:30:36.150][46176][dn_6001_6002_6003][gs_ctl]: fetching MOT checkpoint
gs_ctl: no mot checkpoint exists
[2024-09-04 11:30:36.154][46176][dn_6001_6002_6003][gs_ctl]: waiting for background process to finish streaming...
[2024-09-04 11:30:41.775][46176][dn_6001_6002_6003][gs_ctl]: starting fsync all files come from source.
[2024-09-04 11:30:43.893][46176][dn_6001_6002_6003][gs_ctl]: finish fsync all files.
[2024-09-04 11:30:43.895][46176][dn_6001_6002_6003][gs_ctl]: build dummy dw file success
[2024-09-04 11:30:43.895][46176][dn_6001_6002_6003][gs_ctl]: rename build status file success
[2024-09-04 11:30:43.901][46176][dn_6001_6002_6003][gs_ctl]: full build build completed(/data/relia1137/cluster/dn1).
[2024-09-04 11:30:43.949][46176][dn_6001_6002_6003][gs_ctl]: waiting for server to start...
....[2024-09-04 11:30:47.319][46176][dn_6001_6002_6003][gs_ctl]: waitpid 48160 failed, exitstatus is 256, ret is 2

[2024-09-04 11:30:47.319][46176][dn_6001_6002_6003][gs_ctl]: stopped waiting
[2024-09-04 11:30:47.319][46176][dn_6001_6002_6003][gs_ctl]: could not start server

```
第一次全量build start失败pg日志

```

2024-09-04 11:30:47.252 66d7d464.6126 [unknown] 139797198796544 dn_6003 0 dn_6001_6002_6003 00000  0 [DBL_WRT] LOG:  Double write single flush file created successfully
2024-09-04 11:30:47.253 66d7d464.6126 [unknown] 139797198796544 dn_6003 0 dn_6001_6002_6003 00000  0 [DBL_WRT] LOG:  Found a valid batch meta file info: dw_file_num [1], dw_file_size [256] MB, dw_version [92568]
2024-09-04 11:30:47.258 66d7d464.6126 [unknown] 139797198796544 dn_6003 0 dn_6001_6002_6003 00000  0 [DBL_WRT] LOG:  Found a valid batch file header: id 0, file_head[dwn 0, start 1]
2024-09-04 11:30:47.260 66d7d464.6126 [unknown] 139797198796544 dn_6003 0 dn_6001_6002_6003 00000  0 [DBL_WRT] LOG:  Found a valid single file header: id 0, file_head[dwn 0, start 0]
2024-09-04 11:30:47.261 66d7d464.6126 [unknown] 139797198796544 dn_6003 0 dn_6001_6002_6003 00000  0 [DBL_WRT] LOG:  Found a valid single file header: id 0, file_head[dwn 0, start 0]
2024-09-04 11:30:47.263 66d7d464.6126 [unknown] 139797198796544 dn_6003 0 dn_6001_6002_6003 00000  0 [DBL_WRT] LOG:  DW batch flush file recovery start.
2024-09-04 11:30:47.268 66d7d464.6126 [unknown] 139797198796544 dn_6003 0 dn_6001_6002_6003 00000  0 [DBL_WRT] LOG:  DW recovery state: "Empty", file start page[dwn 0, start 1], now access page 0, current [page_id 1, dwn 0, checksum verify res is 1, page_num orig 0, page_num fixed 0]
2024-09-04 11:30:47.268 66d7d464.6126 [unknown] 139797198796544 dn_6003 0 dn_6001_6002_6003 00000  0 [DBL_WRT] LOG:  DW recovery state: "Finish", file start page[dwn 0, start 1], now access page 0, current [page_id 1, dwn 0, checksum verify res is 1, page_num orig 0, page_num fixed 0]
2024-09-04 11:30:47.268 66d7d464.6126 [unknown] 139797198796544 dn_6003 0 dn_6001_6002_6003 00000  0 [DBL_WRT] LOG:  DW batch flush file recovery finish.
2024-09-04 11:30:47.268 66d7d464.6126 [unknown] 139797198796544 dn_6003 0 dn_6001_6002_6003 00000  0 [DBL_WRT] LOG:  DW single flush file recovery start.
2024-09-04 11:30:47.268 66d7d464.6126 [unknown] 139797198796544 dn_6003 0 dn_6001_6002_6003 00000  0 [DBL_WRT] LOG:  [single flush] recovery, [first version] dw page is new, break this recovery: buf_tag[rel 0/0/0 blk 0 fork 0], compress: 0
2024-09-04 11:30:47.269 66d7d464.6126 [unknown] 139797198796544 dn_6003 0 dn_6001_6002_6003 00000  0 [DBL_WRT] LOG:  [second version] DW single flush file valid item num is 0.
2024-09-04 11:30:47.269 66d7d464.6126 [unknown] 139797198796544 dn_6003 0 dn_6001_6002_6003 00000  0 [DBL_WRT] LOG:  DW single flush file recovery finish.
2024-09-04 11:30:47.270 66d7d464.6126 [unknown] 139797198796544 dn_6003 0 dn_6001_6002_6003 00000  0 [DBL_WRT] LOG:  DW single flush finish recovery, reset the file head[dwn 1, start 0].
2024-09-04 11:30:47.271 66d7d464.6126 [unknown] 139797198796544 dn_6003 0 dn_6001_6002_6003 00000  0 [DBL_WRT] LOG:  DW single flush finish recovery [second version], reset the file head[dwn 1, start 0].
2024-09-04 11:30:47.285 66d7d464.6126 [unknown] 139797198796544 dn_6003 0 dn_6001_6002_6003 42809  0 [BACKEND] FATAL:  [RecoveryUndoZone:749]Undo meta CRC calculated(1945039119) is different from CRC recorded(4120790587) in page.
2024-09-04 11:30:47.285 66d7d464.6126 [unknown] 139797198796544 dn_6003 0 dn_6001_6002_6003 42809  0 [BACKEND] BACKTRACELOG:  tid[48205]'s backtrace:
        /data/relia1137/cluster/app/bin/gaussdb(+0xdbda0b) [0x558843143a0b]
        /data/relia1137/cluster/app/bin/gaussdb(_Z9errfinishiz+0x59b) [0x55884313b12b]
        /data/relia1137/cluster/app/bin/gaussdb(_ZN4undo22RecoveryUndoSystemMetaEv+0x7e) [0x558843c8d83e]
        /data/relia1137/cluster/app/bin/gaussdb(_Z11StartupXLOGv+0x19d1) [0x558843bd2261]
        /data/relia1137/cluster/app/bin/gaussdb(_Z18StartupProcessMainv+0x299) [0x5588436f9289]
        /data/relia1137/cluster/app/bin/gaussdb(_Z17GaussDbThreadMainIL15knl_thread_role24EEiP14knl_thread_arg+0x3ca) [0x5588436e5c5a]
        /data/relia1137/cluster/app/bin/gaussdb(+0x133a805) [0x5588436c0805]
        /lib64/libpthread.so.0(+0x7e65) [0x7f2680e53e65]
        /lib64/libc.so.6(clone+0x6d) [0x7f2680b7c88d]
        Use addr2line to get pretty function name and line

2024-09-04 11:30:47.286  [postmaster][reaper][139803715513024] LOG: startupprocess exit
2024-09-04 11:30:47.286 66d7d463.1 [unknown] 139803715513024 [unknown] 0 dn_6001_6002_6003 00000  0 [BACKEND] LOG:  startup process (ThreadId 139797198796544) was terminated by signal 1: Hangup
2024-09-04 11:30:47.286  [postmaster][reaper][139803715513024] LOG: aborting startup due to startup process failure
2024-09-04 11:30:47.286 66d7d463.1 [unknown] 139803715513024 [unknown] 0 dn_6001_6002_6003 00000  0 [BACKEND] LOG:  startup process (ThreadId 139797198796544) was terminated by signal 1: Hangup
2024-09-04 11:30:47.286  [postmaster][reaper][139803715513024] LOG: terminating any other active server processes
2024-09-04 11:30:47.286  [postmaster][reaper][139803715513024] LOG: startup process (ThreadId 139797198796544) exited with exit code 0
2024-09-04 11:30:47.286  [postmaster][reaper][139803715513024] LOG: the server process exits
~

```
第二次全量build失败，gs_ctl日志

```
[2024-09-04 11:34:12.198][49696][][gs_ctl]: gs_ctl full build ,datadir is /data/relia1137/cluster/dn1
[2024-09-04 11:34:12.198][49696][][gs_ctl]: fopen build pid file "/data/relia1137/cluster/dn1/gs_build.pid" success
[2024-09-04 11:34:12.198][49696][][gs_ctl]: fprintf build pid file "/data/relia1137/cluster/dn1/gs_build.pid" success
[2024-09-04 11:34:12.201][49696][][gs_ctl]: fsync build pid file "/data/relia1137/cluster/dn1/gs_build.pid" success
[2024-09-04 11:34:12.201][49696][][gs_ctl]: stop failed, killing gaussdb by force ...
[2024-09-04 11:34:12.201][49696][][gs_ctl]: command [ps c -eo pid,euid,cmd | grep gaussdb | grep -v grep | awk '{if($2 == curuid && $1!="-n") print "/proc/"$1"/cwd"}' curuid=`id -u`| xargs ls -l | awk '{if ($NF=="/data/relia1137/cluster/dn1")  print $(NF-2)}' | awk -F/ '{print $3 }' | xargs kill -9 >/dev/null 2>&1 ] path: [/data/relia1137/cluster/dn1]
[2024-09-04 11:34:12.219][49696][][gs_ctl]: server stopped
[2024-09-04 11:34:12.219][49696][][gs_ctl]: current workdir is (/home/relia1137).
[2024-09-04 11:34:12.220][49696][][gs_ctl]: set gaussdb state file when full build build:db state(BUILDING_STATE), server mode(STANDBY_MODE), build mode(FULL_BUILD).
[2024-09-04 11:34:12.220][49696][dn_6001_6002_6003][gs_ctl]: Get repl_auth_mode is  and repl_uuid is
[2024-09-04 11:34:12.256][49696][dn_6001_6002_6003][gs_ctl]: build try host(10.116.253.24) port(51138) success
[2024-09-04 11:34:12.256][49696][dn_6001_6002_6003][gs_ctl]: connected to server success, build started.
[2024-09-04 11:34:12.383][49696][dn_6001_6002_6003][gs_ctl]: clear old target dir success
[2024-09-04 11:34:12.383][49696][dn_6001_6002_6003][gs_ctl]: create build tag file success
[2024-09-04 11:34:12.383][49696][dn_6001_6002_6003][gs_ctl]: create build tag file again success
[2024-09-04 11:34:12.384][49696][dn_6001_6002_6003][gs_ctl]: get system identifier success
[2024-09-04 11:34:12.385][49696][dn_6001_6002_6003][gs_ctl]: create backup label success
INFO:  The starting position of the xlog copy of the full build is: 13/57FFD58. The slot minimum LSN is: 13/57FFD58. The disaster slot minimum LSN is: 0/0. The logical slot minimum LSN is: 0/0.
[2024-09-04 11:34:12.492][49696][dn_6001_6002_6003][gs_ctl]: xlog start point: 13/57FFD58
[2024-09-04 11:34:12.492][49696][dn_6001_6002_6003][gs_ctl]: begin build tablespace list
[2024-09-04 11:34:12.492][49696][dn_6001_6002_6003][gs_ctl]: finish build tablespace list
[2024-09-04 11:34:12.492][49696][dn_6001_6002_6003][gs_ctl]: begin get xlog by xlogstream
[2024-09-04 11:34:12.492][49696][dn_6001_6002_6003][gs_ctl]: starting background WAL receiver
[2024-09-04 11:34:12.492][49696][dn_6001_6002_6003][gs_ctl]: starting walreceiver
[2024-09-04 11:34:12.492][49696][dn_6001_6002_6003][gs_ctl]: begin receive tar files
[2024-09-04 11:34:12.521][49696][dn_6001_6002_6003][gs_ctl]: build try host(10.116.253.24) port(51138) success
[2024-09-04 11:34:12.526][49696][dn_6001_6002_6003][gs_ctl]: check identify system success
[2024-09-04 11:34:12.530][49696][dn_6001_6002_6003][gs_ctl]: send START_REPLICATION 13/5000000 success
[2024-09-04 11:44:15.356][49696][dn_6001_6002_6003][gs_ctl]: could not get WAL end position from server: lost synchronization with server: got message type " ", length 538976288

[2024-09-04 11:44:15.381][49696][dn_6001_6002_6003][gs_ctl]: full build failed(/data/relia1137/cluster/dn1).
[2024-09-04 11:44:17]

```

【测试代码】:

GVP openGauss/openGauss-server

内容风险标识

评论 (4)

GVPopenGauss/openGauss-server

内容风险标识