gpaddmirrors & gprecoverseg issue

[adnanhamdussalam]

Hi,

I have started adding mirrors as 16 primary segments. After completing one mirror segment (100%) pg_basebackup removed the mirror segment folder started again from scratch and same behavior for the rest of the segments.

Then I used gprecoverseg with -F option against only 4 segments and again observed the same behavior.

PFB the snapshot:

sky-cbseg03 (dbid 19): 1034761642/1165354896 kB (88%), 0/1 tablespace (...rrors/gpseg0/base/17018/280446.1)
sky-cbseg03 (dbid 20): pg_basebackup: removing data directory "/data/cbdatabase/mirrors/gpseg1"
sky-cbseg03 (dbid 21): pg_basebackup: removing data directory "/data/cbdatabase/mirrors/gpseg2"
sky-cbseg03 (dbid 22): 1026698590/1162146943 kB (88%), 0/1 tablespace (...mirrors/gpseg3/base/17018/280677)

20260330:16:18:53:1407854 gpstate:sky-cbcoord:gpadmin-[INFO]:-local Cloudberry Version: 'postgres (Apache Cloudberry) 2.0.0-incubating build 1'
20260330:16:18:53:1407854 gpstate:sky-cbcoord:gpadmin-[INFO]:-coordinator Cloudberry Version: 'PostgreSQL 14.4 (Apache Cloudberry 2.0.0-incubating build 1) on x86_64-pc-linux-gnu, compiled by gcc (GCC) 11.5.0 20240719 (Red Hat 11.5.0-5.0.1), 64-bit compiled on Aug 28 2025 15:25:48'
20260330:16:18:53:1407854 gpstate:sky-cbcoord:gpadmin-[INFO]:-Obtaining Segment details from coordinator...
20260330:16:18:53:1407854 gpstate:sky-cbcoord:gpadmin-[INFO]:-Gathering data from segments...
..
20260330:16:18:55:1407854 gpstate:sky-cbcoord:gpadmin-[INFO]:-Cloudberry instance status summary
20260330:16:18:55:1407854 gpstate:sky-cbcoord:gpadmin-[INFO]:-----------------------------------------------------
20260330:16:18:55:1407854 gpstate:sky-cbcoord:gpadmin-[INFO]:- Coordinator instance = Active
20260330:16:18:55:1407854 gpstate:sky-cbcoord:gpadmin-[INFO]:- Coordinator standby = No coordinator standby configured
20260330:16:18:55:1407854 gpstate:sky-cbcoord:gpadmin-[INFO]:- Total segment instance count from metadata = 32
20260330:16:18:55:1407854 gpstate:sky-cbcoord:gpadmin-[INFO]:-----------------------------------------------------
20260330:16:18:55:1407854 gpstate:sky-cbcoord:gpadmin-[INFO]:- Primary Segment Status
20260330:16:18:55:1407854 gpstate:sky-cbcoord:gpadmin-[INFO]:-----------------------------------------------------
20260330:16:18:55:1407854 gpstate:sky-cbcoord:gpadmin-[INFO]:- Total primary segments = 16
20260330:16:18:55:1407854 gpstate:sky-cbcoord:gpadmin-[INFO]:- Total primary segment valid (at coordinator) = 16
20260330:16:18:55:1407854 gpstate:sky-cbcoord:gpadmin-[INFO]:- Total primary segment failures (at coordinator) = 0
20260330:16:18:55:1407854 gpstate:sky-cbcoord:gpadmin-[INFO]:- Total number of postmaster.pid files missing = 0
20260330:16:18:55:1407854 gpstate:sky-cbcoord:gpadmin-[INFO]:- Total number of postmaster.pid files found = 16
20260330:16:18:55:1407854 gpstate:sky-cbcoord:gpadmin-[INFO]:- Total number of postmaster.pid PIDs missing = 0
20260330:16:18:55:1407854 gpstate:sky-cbcoord:gpadmin-[INFO]:- Total number of postmaster.pid PIDs found = 16
20260330:16:18:55:1407854 gpstate:sky-cbcoord:gpadmin-[INFO]:- Total number of /tmp lock files missing = 0
20260330:16:18:55:1407854 gpstate:sky-cbcoord:gpadmin-[INFO]:- Total number of /tmp lock files found = 16
20260330:16:18:55:1407854 gpstate:sky-cbcoord:gpadmin-[INFO]:- Total number postmaster processes missing = 0
20260330:16:18:55:1407854 gpstate:sky-cbcoord:gpadmin-[INFO]:- Total number postmaster processes found = 16
20260330:16:18:55:1407854 gpstate:sky-cbcoord:gpadmin-[INFO]:-----------------------------------------------------
20260330:16:18:55:1407854 gpstate:sky-cbcoord:gpadmin-[INFO]:- Mirror Segment Status
20260330:16:18:55:1407854 gpstate:sky-cbcoord:gpadmin-[INFO]:-----------------------------------------------------
20260330:16:18:55:1407854 gpstate:sky-cbcoord:gpadmin-[INFO]:- Total mirror segments = 16
20260330:16:18:55:1407854 gpstate:sky-cbcoord:gpadmin-[INFO]:- Total mirror segment valid (at coordinator) = 0
20260330:16:18:55:1407854 gpstate:sky-cbcoord:gpadmin-[WARNING]:-Total mirror segment failures (at coordinator) = 16 <<<<<<<<
20260330:16:18:55:1407854 gpstate:sky-cbcoord:gpadmin-[WARNING]:-Total number of postmaster.pid files missing = 16 <<<<<<<<
20260330:16:18:55:1407854 gpstate:sky-cbcoord:gpadmin-[INFO]:- Total number of postmaster.pid files found = 0
20260330:16:18:55:1407854 gpstate:sky-cbcoord:gpadmin-[WARNING]:-Total number of postmaster.pid PIDs missing = 16 <<<<<<<<
20260330:16:18:55:1407854 gpstate:sky-cbcoord:gpadmin-[INFO]:- Total number of postmaster.pid PIDs found = 0
20260330:16:18:55:1407854 gpstate:sky-cbcoord:gpadmin-[WARNING]:-Total number of /tmp lock files missing = 16 <<<<<<<<
20260330:16:18:55:1407854 gpstate:sky-cbcoord:gpadmin-[INFO]:- Total number of /tmp lock files found = 0
20260330:16:18:55:1407854 gpstate:sky-cbcoord:gpadmin-[WARNING]:-Total number postmaster processes missing = 16 <<<<<<<<
20260330:16:18:55:1407854 gpstate:sky-cbcoord:gpadmin-[INFO]:- Total number postmaster processes found = 0
20260330:16:18:55:1407854 gpstate:sky-cbcoord:gpadmin-[INFO]:- Total number mirror segments acting as primary segments = 0
20260330:16:18:55:1407854 gpstate:sky-cbcoord:gpadmin-[INFO]:- Total number mirror segments acting as mirror segments = 16
20260330:16:18:55:1407854 gpstate:sky-cbcoord:gpadmin-[INFO]:-----------------------------------------------------

pg_basebackup: error: connection to server at "sky-cbseg04" (10.247.224.64), port 50002 failed: Connection refused
Is the server running on that host and accepting TCP/IP connections?

Can you guide why it is behaving like this ?

[my-ship-it]

Hi, thanks for reporting this issue.

Based on the logs you shared, the key clue is the Connection refused error on sky-cbseg04:50002. This means a primary segment went down while pg_basebackup was still streaming data from it. When pg_basebackup loses its connection mid-transfer, it automatically removes the partially-copied data directory to avoid leaving behind an incomplete/corrupt copy — that's the "removing data directory" behavior you're seeing.

With 16 primary segments (~1TB each based on the progress output), running all pg_basebackup processes simultaneously puts enormous pressure on the system — heavy I/O, WAL generation, and network traffic across all hosts at once. This likely caused one or more primary segments to crash, which then cascaded into failures for the mirrors being built from them.

Suggested troubleshooting steps:

1. Check primary segment logs on sky-cbseg04 (port 50002) for crash/OOM/restart entries around the time of the failure.
2. Check dmesg on all segment hosts for OOM killer activity.
3. Verify max_wal_senders — run gpconfig -s max_wal_senders and ensure the value is sufficient (at least 2 per segment).
4. Check disk space — during pg_basebackup, WAL files accumulate and can fill up disks.

Recommended workaround:

Reduce the parallelism to avoid overwhelming the cluster. Instead of recovering all segments at once, try:

gprecoverseg -B 4 -b 2

• -B 4: only process 4 hosts in parallel at the coordinator level (default is 16)
• -b 2: only run 2 pg_basebackup processes per host (default is 64)

This will take longer but should prevent the resource exhaustion that causes primaries to crash mid-backup.

For gpaddmirrors, the same flags (-B and -b) are available to control parallelism.

Hope this helps! Let us know what you find in the primary segment logs.

[adnanhamdussalam]

Thank you for the update @my-ship-it :

I executed below command:

gprecoverseg -aF -B 4 -b 2 -i recovery_failed_30MAR2026

but it still it removed the folder:

in Primary segment log file:

2026-03-31 15:31:14.580776 BST,,,p2731950,th-1214003008,,,,0,,,seg10,,,,,"LOG","00000","activeWeight underflow!",,,,,,,0,,"backoff.c",912,
2026-03-31 15:31:20.888968 BST,"gpadmin",,p3176052,th-1214003008,"10.247.224.59","36372",2026-03-31 14:33:46 BST,0,,,seg10,,,,,"LOG","00000","Basebackup stop point is at 281/E0CCFE58.",,,,,,"BASE_BACKUP LABEL 'pg_basebackup base backup' PROGRESS FAST NOWAIT NOVERIFY_CHECKSUMS MANIFEST 'yes' EXCLUDE './db_dumps' EXCLUDE './promote'",0,,"xlog.c",12394,

2026-03-31 15:31:31.598655 BST,,,p2731950,th-1214003008,,,,0,,,seg10,,,,,"LOG","00000","activeWeight underflow!",,,,,,,0,,"backoff.c",912,

2026-03-31 15:31:34.602018 BST,,,p2731950,th-1214003008,,,,0,,,seg10,,,,,"LOG","00000","activeWeight underflow!",,,,,,,0,,"backoff.c",912,
2026-03-31 15:31:38.606651 BST,,,p2731950,th-1214003008,,,,0,,,seg10,,,,,"LOG","00000","activeWeight underflow!",,,,,,,0,,"backoff.c",912,
2026-03-31 15:31:43.612473 BST,,,p2731950,th-1214003008,,,,0,,,seg10,,,,,"LOG","00000","activeWeight underflow!",,,,,,,0,,"backoff.c",912,
2026-03-31 15:31:48.617557 BST,,,p2731950,th-1214003008,,,,0,,,seg10,,,,,"LOG","00000","activeWeight underflow!",,,,,,,0,,"backoff.c",912,
2026-03-31 15:31:49.618700 BST,,,p2731950,th-1214003008,,,,0,,,seg10,,,,,"LOG","00000","activeWeight underflow!",,,,,,,0,,"backoff.c",912,
2026-03-31 15:31:57.626500 BST,,,p2731950,th-1214003008,,,,0,,,seg10,,,,,"LOG","00000","activeWeight underflow!",,,,,,,0,,"backoff.c",912,
2026-03-31 15:32:00.629941 BST,,,p2731950,th-1214003008,,,,0,,,seg10,,,,,"LOG","00000","activeWeight underflow!",,,,,,,0,,"backoff.c",912,
2026-03-31 15:32:00.664789 BST,,,p2731944,th-1214003008,,,,0,,,seg10,,,,,"LOG","00000","checkpoint starting: immediate force wait",,,,,,,0,,"xlog.c",9239,
2026-03-31 15:32:01.547952 BST,,,p2731944,th-1214003008,,,,0,,,seg10,,,,,"LOG","00000","checkpoint complete: wrote 7520 buffers (2.9%); 0 WAL file(s) added, 0 removed, 7 recycled; write=0.652 s, sync=0.218 s, total=0.884 s; sync files=124, longest=0.033 s, average=0.002 s; distance=401269 kB, estimate=401269 kB",,,,,,,0,,"xlog.c",9320,
2026-03-31 15:32:01.558522 BST,"gpadmin",,p3182237,th-1214003008,"10.247.224.59","38690",2026-03-31 15:32:00 BST,0,,,seg10,,,,,"LOG","00000","basebackup perform -- Basebackup start xlog location = 281/F00014E0",,,,,,"BASE_BACKUP LABEL 'pg_basebackup base backup' PROGRESS FAST NOWAIT NOVERIFY_CHECKSUMS MANIFEST 'yes' EXCLUDE './db_dumps' EXCLUDE './promote'",0,,"basebackup.c",340,

20260331:14:33:46:2844565 gpsegrecovery.py:sky-cbseg01:gpadmin-[INFO]:-Running pg_basebackup with progress output temporarily in /home/gpadmin/gpAdminLogs/pg_basebackup.20260331_143345.dbid29.out
20260331:15:32:00:2844565 gpsegrecovery.py:sky-cbseg01:gpadmin-[INFO]:-Running pg_basebackup failed: ExecutionError: 'non-zero rc: 1' occurred. Details: 'pg_basebackup -c fast -D /data/cbdatabase/mirrors/gpseg10 -h sky-cbseg03 -p 50002 --slot internal_wal_replication_slot --wal-method stream --no-verify-checksums --force-overwrite --write-recovery-conf --target-gp-dbid 29 -E ./db_dumps -E ./promote --progress --verbose > /home/gpadmin/gpAdminLogs/pg_basebackup.20260331_143345.dbid29.out 2>&1' cmd had rc=1 completed=True halted=False
stdout=''
stderr=''
20260331:15:32:00:2844565 gpsegrecovery.py:sky-cbseg01:gpadmin-[INFO]:-Re-running pg_basebackup, creating the slot this time

Kindly can you look into it

how can I check internal_wal_replication_slot is created or not as you can see it saying in above message " creating the slot this time" ?

0.008 s, total=0.025 s; sync files=24, longest=0.002 s, average=0.001 s; distance=55079 kB, estimate=337347 kB",,,,,,,0,,"xlog.c",9320,
2026-03-31 14:33:46.613355 BST,"gpadmin",,p3176052,th-1214003008,"10.247.224.59","36372",2026-03-31 14:33:46 BST,0,,,seg10,,,,,"LOG","00000","basebackup perform -- Basebackup start xlog location = 281/A400E9B8",,,,,,"BASE_BACKUP LABEL 'pg_basebackup base backup' PROGRESS FAST NOWAIT NOVERIFY_CHECKSUMS MANIFEST 'yes' EXCLUDE './db_dumps' EXCLUDE './promote'",0,,"basebackup.c",340,
2026-03-31 14:33:48.145930 BST,"gpadmin",,p3176053,th-1214003008,"10.247.224.59","36698",2026-03-31 14:33:48 BST,0,,,seg10,,,,,"ERROR","42704","replication slot ""internal_wal_replication_slot"" does not exist",,,,,,"START_REPLICATION SLOT ""internal_wal_replication_slot"" 281/A4000000 TIMELINE 1",0,,"slot.c",401,
2026-03-31 14:33:48.145999 BST,"gpadmin",,p3176053,th-1214003008,"10.247.224.59","36698",2026-03-31 14:33:48 BST,0,,,seg10,,,,,"LOG","00000","An exception was encountered during the execution of statement: START_REPLICATION SLOT ""internal_wal_replication_slot"" 281/A4000000 TIMELINE 1",,,,,,"START_REPLICATION SLOT ""internal_wal_replication_slot"" 281/A4000000 TIMELINE 1",0,,"elog.c",2129,

As you can see in the above message when gprecoverseg started at first time it gives error ""ERROR","42704","replication slot ""int" due to which after completing the pg_basebackup gprecoverseg unable to find the internal replication slot due to which it removes the directory and in log it gives message ""creating the slot this time" and start again the pg_basebackup with internal replication slot and now it is in executing state will update you in a while if it get successful or fail.
If it gets successful it seems like to be bug.

[adnanhamdussalam]

@my-ship-it
This time it was successful now I proceed with next segment if the behaves is same then it seems to be a bug.

Will update you shortly.

[adnanhamdussalam]

2026-03-31 16:46:46.523484 BST,,,p2731959,th-2084910912,,,,0,,,seg11,,,,,"LOG","00000","activeWeight underflow!",,,,,,,0,,"backoff.c",912,
2026-03-31 16:46:47.524673 BST,,,p2731959,th-2084910912,,,,0,,,seg11,,,,,"LOG","00000","activeWeight underflow!",,,,,,,0,,"backoff.c",912,
2026-03-31 16:46:47.950725 BST,,,p2731953,th-2084910912,,,,0,,,seg11,,,,,"LOG","00000","checkpoint complete: wrote 10347 buffers (4.0%); 0 WAL file(s) added, 0 removed, 1 recycled; write=102.727 s,
sync=0.094 s, total=102.848 s; sync files=47, longest=0.050 s, average=0.002 s; distance=335050 kB, estimate=514332 kB",,,,,,,0,,"xlog.c",9320,
2026-03-31 16:46:47.964413 BST,,,p2731953,th-2084910912,,,,0,,,seg11,,,,,"LOG","00000","checkpoint starting: immediate force wait",,,,,,,0,,"xlog.c",9239,
2026-03-31 16:46:47.992625 BST,,,p2731953,th-2084910912,,,,0,,,seg11,,,,,"LOG","00000","checkpoint complete: wrote 78 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.012 s, sync=0.012 s, total=0.029 s; sync files=27, longest=0.001 s, average=0.001 s; distance=57799 kB, estimate=468679 kB",,,,,,,0,,"xlog.c",9320,
2026-03-31 16:46:47.993483 BST,"gpadmin",,p3193514,th-2084910912,"10.247.224.59","43576",2026-03-31 16:46:47 BST,0,,,seg11,,,,,"LOG","00000","basebackup perform -- Basebackup start xlog location = 287/18004560",,,,,,"BASE_BACKUP LABEL 'pg_basebackup base backup' PROGRESS FAST NOWAIT NOVERIFY_CHECKSUMS MANIFEST 'yes' EXCLUDE './db_dumps' EXCLUDE './promote'",0,,"basebackup.c",340,
2026-03-31 16:46:48.525866 BST,,,p2731959,th-2084910912,,,,0,,,seg11,,,,,"LOG","00000","activeWeight underflow!",,,,,,,0,,"backoff.c",912,
2026-03-31 16:46:49.376145 BST,"gpadmin",,p3193515,th-2084910912,"10.247.224.59","43590",2026-03-31 16:46:49 BST,0,,,seg11,,,,,"ERROR","42704","replication slot ""internal_wal_replication_slot"" does not exist",,,,,,"START_REPLICATION SLOT ""internal_wal_replication_slot"" 287/18000000 TIMELINE 1",0,,"slot.c",401,
2026-03-31 16:46:49.376251 BST,"gpadmin",,p3193515,th-2084910912,"10.247.224.59","43590",2026-03-31 16:46:49 BST,0,,,seg11,,,,,"LOG","00000","An exception was encountered during the execution of statement: START_REPLICATION SLOT ""internal_wal_replication_slot"" 287/18000000 TIMELINE 1",,,,,,"START_REPLICATION SLOT ""internal_wal_replication_slot"" 287/18000000 TIMELINE 1",0,,"elog.c",2129,
2026-03-31 16:46:51.529207 BST,,,p2731959,th-2084910912,,,,0,,,seg11,,,,,"LOG","00000","activeWeight underflow!",,,,,,,0,,"backoff.c",912,
2026-03-31 16:46:52.530455 BST,,,p2731959,th-2084910912,,,,0,,,seg11,,,,,"LOG","00000","activeWeight underflow!",,,,,,,0,,"backoff.c",912,
2026-03-31 16:46:53.531635 BST,,,p2731959,th-2084910912,,,,0,,,seg11,,,,,"LOG","00000","activeWeight underflow!",,,,,,,0,,"backoff.c",912,
2026-03-31 16:46:56.534786 BST,,,p2731959,th-2084910912,,,,0,,,seg11,,,,,"LOG","00000","activeWeight underflow!",,,,,,,0,,"backoff.c",912,
2026-03-31 16:46:58.536936 BST,,,p2731959,th-2084910912,,,,0,,,seg11,,,,,"LOG","00000","activeWeight underflow!",,,,,,,0,,"backoff.c",912,
2026-03-31 16:46:59.538138 BST,,,p2731959,th-2084910912,,,,0,,,seg11,,,,,"LOG","00000","activeWeight underflow!",,,,,,,0,,"backoff.c",912,
2026-03-31 16:47:01.540489 BST,,,p2731959,th-2084910912,,,,0,,,seg11,,,,,"LOG","00000","activeWeight underflow!",,,,,,,0,,"backoff.c",912,

Now I have started the gprecoverseg -aF -B 4 -b 2 -i recovery_failed_30MAR2026 for segment gpseg11 and found the replication slot error as above primary log at the start pg_basebackup.

Will observe if it removes the directory and get message creating the slot this time and after start over again if it gets completed then it seems to be confirmed bug.

Will update you in a while.

[adnanhamdussalam]

Hi @my-ship-it
After reaching 100% it again removed the directory and started again, ps_basebackup and I have found message in logs "creating the slot this time" and it get successful in second time, it seems to be bug.

Kindly can you share your expert opinion.

[my-ship-it]

Hi @adnanhamdussalam,

Thanks for the thorough investigation and detailed logs — they were very helpful in pinpointing the issue.

What's Happening

You're right, this is a confirmed bug. The problem is that every mirror recovery via gprecoverseg -F (or gpaddmirrors) ends up running pg_basebackup twice per segment:

1. The first attempt copies all the data (~1TB in your case) and reaches 100%, but then fails at the WAL streaming phase because internal_wal_replication_slot doesn't exist on the primary.
2. pg_basebackup then removes the entire data directory it just copied.
3. A second attempt is launched with --create-slot, which starts the full copy all over again from scratch — and this one succeeds.

So for your 16 segments, you're effectively doing 32 full base backups instead of 16, doubling the time and I/O required.

Root Cause

The recovery code in gpsegrecovery.py assumes the first attempt without --create-slot will "fail quickly" if the slot doesn't exist. However, the slot check only happens during the WAL streaming phase — after the full data copy has already completed. This makes the retry extremely expensive for large segments.

There is actually a GPDB_12_MERGE_FIXME comment in the code acknowledging this needs to be fixed.

Workaround

Until we get a proper fix, you can avoid the double-copy by manually creating the replication slot on each primary before running gprecoverseg. Note that you need to connect in utility mode since direct connections to primary segments are not allowed by default:

PGOPTIONS='-c gp_role=utility' psql -h sky-cbseg03 -p 50002 -d postgres -c \
  "SELECT pg_create_physical_replication_slot('internal_wal_replication_slot');"

To check which primaries already have the slot (this can be run from the coordinator):

SELECT gp_segment_id, slot_name
FROM gp_dist_random('pg_replication_slots')
WHERE slot_name = 'internal_wal_replication_slot';

Next Steps

I've created #1654 to track the fix. The plan is to check whether the replication slot exists on the primary before running pg_basebackup, and create it if needed — so the first attempt always succeeds.

Thanks again for reporting this!