Skip to main content
RunBook Academy

← All break/fix scenarios in Backup & DR

advancedbdr-vm-consistency~50 min

The virtual machine restored, booted, and the application refused to start

Reported symptoms

  • ●The storage array holding rbdr-app-01 is lost at 02:14; the virtual machine is restored from the previous night image onto replacement storage and powers on normally
  • ●The guest reaches multi-user.target and answers SSH in under four minutes, so the on-call engineer records the restore as successful and moves to the application check
  • ●The postgresql unit enters failed state within two seconds of every start attempt, and restarting it produces the identical failure each time
  • ●The database log ends with a PANIC naming a checkpoint record the server cannot locate, followed by the startup process being terminated by signal 6
  • ●The same virtual machine had passed its monthly restore test three weeks earlier, and the test report shows every assertion green
  • ●The first hypothesis on the bridge is that the restore was truncated or incomplete, because a partially written disk image would also stop a database from starting
  • ●Nobody on the bridge can name a time when anything other than the guest boot was checked after a restore of this machine

Evidence

  • · The backup job definition for the guest records mode snapshot and agent 0, with no guest agent installed inside the guest, no filesystem freeze requested and no pre-backup hook configured, so nothing on either side of the hypervisor boundary knew a copy was being taken
  • · The guest has two virtual disks, scsi0 carrying the operating system and the PostgreSQL data directory and scsi1 carrying a separate volume mounted at the cluster pg_wal path, and the job captured both while the guest was serving traffic
  • · The course capture reproduces the failure signature exactly: invalid checkpoint record, then PANIC: could not locate a valid checkpoint record at 0/2F20158, then startup process (PID 132) was terminated by signal 6: Aborted, and pg_ctl exits 1
  • · The same capture shows the far more dangerous neighbouring case, in which a copy taken the same uncoordinated way started, completed automatic recovery and returned all 45000 rows at exit code 0
  • · The monthly restore test report for 2026-08-01 asserts four things - image restored, guest powered on, guest reached multi-user.target, SSH answered on port 22 - and asserts nothing about the database
  • · Comparing each restored disk against the size and SHA-256 digest the backup catalogue recorded when the image was written shows both disks matching on both properties, so the restore delivered exactly the bytes that were captured
  • · The capture of the application-consistent path on the same database recovers a base backup forward through archived WAL and reports rows recovered 50000 against an expected 50000 and sum(amount) 825025000 against an expected 825025000
Diagnosis and resolutionclick to reveal

Root cause

Two defects, and the second one is the reason the first survived to an incident. The immediate cause is that the machine-level copy was taken with no coordination of any kind. The job ran in snapshot mode against a running guest with the QEMU guest agent absent and `agent` set to 0, so the hypervisor never asked the guest to flush and freeze its filesystems, and nothing asked PostgreSQL to bracket the copy. The guest spans two virtual disks - the data directory on one, pg_wal on another - and without a freeze there is nothing that makes those two images correspond to a single instant of guest I/O. The control file restored from the data disk therefore names a checkpoint the WAL image cannot supply, which is precisely the `invalid checkpoint record` / `could not locate a valid checkpoint record` pair the capture reproduces. PostgreSQL documents the boundary directly: a file-system-level copy of a running cluster is a valid backup only when it is an atomic snapshot of the whole cluster, or when it is bracketed by pg_backup_start and pg_backup_stop and accompanied by every WAL segment written during the copy. This copy was neither. The control that should have caught it is the monthly restore test, and it was built to the wrong bar. It restored the image, powered the guest on, waited for multi-user.target and checked that SSH answered. Every one of those assertions is true of a guest whose database cannot start, so the test was incapable by construction of detecting this fault, and it reported that incapability as a pass. Raising the bar to "the unit is active" would not have been enough either: the capture shows an equally uncoordinated copy starting cleanly, completing automatic recovery and serving all 45000 rows at exit 0. A crash-consistent image usually appears to work, which is what makes a boot-level test worthless here. The plausible alternative - that the restore itself was incomplete or truncated - is eliminated by the catalogue comparison. Both restored disks match the size and the SHA-256 digest recorded when the image was written. The restore delivered exactly the bytes that were captured, so the fault lies in what was captured, not in what was delivered.

Remediation

Stop restarting the guest. Every start attempt is another automatic recovery attempt against the same image, and a recovery attempt writes. Take a copy of the restored disks before anything else touches them, so the evidence and the fallback both survive whatever comes next. Recover the database from a database-aware source rather than from the machine image. The capture shows what that path yields: a base backup rolled forward through archived WAL to a chosen point, validated on the data rather than on the process table. If the estate holds a base backup and a WAL archive for this cluster, that is the recovery source; the machine image is not. If no database-aware source exists for this cluster, say so on the bridge in those words rather than trying to force the image to start. The image can still return the operating system, the packages and the configuration, which shortens the rebuild, but the cluster data in it is not a recovery point for the database. Then close the capture defect before the next backup window: install and enable the guest agent so the hypervisor can freeze the guest filesystems for the moment of the snapshot, and add a database-native backup with WAL archiving so the database has a recovery path that does not depend on disk-image timing at all.

Verification

The recovered cluster reaches a consistent recovery state and accepts connections without an `invalid checkpoint record` line anywhere in its startup log. A start that succeeds after a crash-consistent copy is not the proof - the capture contains one of those - so the startup log is read for the absence of the fault, not merely for the presence of a running server. The recovered data is compared against an independently recorded property of the business data. In the capture this is a row count and a summed amount, both taken before the incident and both matched afterwards: 50000 rows and sum(amount) 825025000. Read the two together; a row count alone survives a great deal of damage. The rewritten restore test connects to the restored database over the network and runs a query whose result is diffed against a stored expectation. The test passes only when that diff is empty. The boot assertions stay, but they are now preconditions rather than the verdict. A subsequent backup taken with the guest agent enabled restores into an isolated target and starts with a clean recovery, proving the capture defect is closed rather than assuming it.

Prevention

**Make the restore test assert that the application served.** The bar is a query result compared against a recorded expectation, not a boot, not an SSH banner and not an active unit. That is the single change that would have surfaced this three weeks before the array failed. **Enable guest coordination and then prove it worked.** Installing the guest agent and setting the freeze option is the configuration change; a restore that starts without an `invalid checkpoint record` is the evidence. Configuration without a restore behind it is an intention. **Back databases up with database-aware tooling, and treat the machine image as operating-system and configuration recovery.** A base backup plus an archived WAL stream gives a recovery point the hypervisor cannot express, and it is the only path in this scenario that produced a verified result. **Record the size and digest of every image when it is written.** That is what let the bridge discard the incomplete-restore hypothesis in minutes instead of spending the incident on it. **Alert on the age of the last restore test that reached the application**, not on the age of the last restore test. The estate had a passing monthly test and a database it could not recover, and no dashboard could tell the difference. **Write down which guests hold databases.** Guest coordination matters most exactly where somebody has quietly put a stateful service inside a virtual machine that the backup schedule treats as a generic workload.

Reported symptoms

The array holding rbdr-app-01 is lost at 02:14. The guest is restored from the previous night’s hypervisor image onto replacement storage, powers on, reaches multi-user.target and answers SSH inside four minutes. The on-call engineer marks the restore successful and moves to the application.

The postgresql unit for that cluster then fails, within two seconds, every time. Its log ends with a PANIC naming a checkpoint record the server cannot locate, and the startup process being killed by signal 6. Three weeks earlier this same guest passed its monthly restore test with every assertion green.

The first hypothesis on the bridge is that the restore was truncated.

Evidence provided

Read-only / Safethe job that produced the image, as the estate stored it
$ grep -E '^(agent|name|scsi[0-9]|mode|script):' /etc/pve/qemu-server/141.conf /etc/vzdump.conf
/etc/pve/qemu-server/141.conf:agent: 0
/etc/pve/qemu-server/141.conf:name: rbdr-app-01
/etc/pve/qemu-server/141.conf:scsi0: rbdr-store:vm-141-disk-0,size=40G
/etc/pve/qemu-server/141.conf:scsi1: rbdr-store:vm-141-disk-1,size=20G
/etc/vzdump.conf:mode: snapshot

Illustrative output

Read what is there and what is not. agent: 0 means the hypervisor had nobody to ask for a filesystem freeze; the grep matched no script: line, so no pre-backup hook ran either; mode: snapshot means the guest kept serving traffic throughout. The guest is also not one disk.

Read-only / Safetwo virtual disks, and what the guest puts on each
$ ssh rbdr-app-01 df -h /var/lib/postgresql/18/main /var/lib/postgresql/18/main/pg_wal
Filesystem      Size  Used Avail Use% Mounted on
/dev/sda1        39G   12G   26G  32% /
/dev/sdb1        20G  3.1G   16G  17% /var/lib/postgresql/18/main/pg_wal

Illustrative output

The data directory rides the root filesystem on scsi0; pg_wal is a separate volume on scsi1. Nothing on either side of the hypervisor boundary knew a copy was in progress, and nothing tied the two disk images to one instant. The course capture reproduces the resulting failure signature deliberately.

Service impact possiblerecovery stops at a checkpoint record the image cannot supply
$ pg_ctl -D /work/nowal start
  waiting for server to start.... stopped waiting
pg_ctl: could not start server
Examine the log output.
>>> exit code: 1

2026-08-28 13:34:37.879 UTC [132] LOG:  creating missing WAL directory "pg_wal/archive_status"
2026-08-28 13:34:37.879 UTC [132] LOG:  creating missing WAL directory "pg_wal/summaries"
2026-08-28 13:34:37.879 UTC [132] LOG:  invalid checkpoint record
2026-08-28 13:34:37.879 UTC [132] PANIC:  could not locate a valid checkpoint record at 0/2F20158
2026-08-28 13:34:37.941 UTC [126] LOG:  startup process (PID 132) was terminated by signal 6: Aborted
2026-08-28 13:34:37.941 UTC [126] LOG:  terminating any other active server processes
2026-08-28 13:34:37.942 UTC [126] LOG:  shutting down due to startup process failure
2026-08-28 13:34:37.943 UTC [126] LOG:  database system is shut down

The same capture records the neighbouring case, and it is the more dangerous one. In PART A the capture ran cp -a $PGDATA /work/naive-copy mid-workload, with no database involvement at all, and then started the copy. It ran automatic recovery to completion and served every row.

Data-loss riskthe same lack of coordination, this time appearing to work
$ pg_ctl -D /work/naive-copy start
  waiting for server to start.... done
server started
>>> exit code: 0

2026-08-28 13:34:37.611 UTC [94] LOG:  database system was interrupted; last known up at 2026-08-28 13:34:36 UTC
2026-08-28 13:34:37.613 UTC [94] LOG:  database system was not properly shut down; automatic recovery in progress
2026-08-28 13:34:37.613 UTC [94] LOG:  redo starts at 0/17615F8
2026-08-28 13:34:37.634 UTC [94] LOG:  invalid record length at 0/256A8D8: expected at least 24, got 0
2026-08-28 13:34:37.634 UTC [94] LOG:  redo done at 0/256A8B0 system usage: CPU: user: 0.01 s, system: 0.00 s, elapsed: 0.02 s
2026-08-28 13:34:37.639 UTC [88] LOG:  database system is ready to accept connections

rows readable from the naive copy : 45000
rows in the live database         : 45000

The monthly restore test report is short.

Read-only / Safefour assertions, none of them about the database
$ cat /srv/rbdr-restore-test/rbdr-app-01-2026-08-01.report
rbdr-restore-test  2026-08-01  vm 141  rbdr-app-01
image restored from rbdr-pbs        : ok   (18m41s)
guest powered on                    : ok
guest reached multi-user.target     : ok
ssh answered on port 22             : ok
RESULT: PASS

Illustrative output

Against that, the platform’s application-consistent path on the same database:

Read-only / Safea coordinated copy, validated on the data rather than on the process table
$ recover the base backup to the target time, then count and checksum the business data
  rows recovered  : 50000   (expected 50000)
sum(amount)     : 825025000   (expected 825025000)
RECOVERED - row count and business checksum both match the pre-DELETE state

Work the evidence before reading on

  1. The guest boots and the database does not. Which layer’s copy is under suspicion, and which layer’s restore is not?
  2. Two virtual disks, one running guest, no freeze. What has to be true for the control file on one disk and the WAL on the other to describe the same instant?
  3. The capture shows an uncoordinated copy failing and an uncoordinated copy succeeding. What does that pair tell you about systemctl is-active as a restore-test assertion?
  4. The bridge suspects a truncated restore. What single measurement settles that, and where does the number to compare against have to come from?
  5. Three weeks of a passing monthly test. What exactly was it measuring?

Root cause

The copy was taken while the guest ran, with nothing coordinating it

With agent: 0 and no guest agent, the hypervisor could not ask the guest to flush and freeze its filesystems, and nothing asked PostgreSQL to bracket the copy. Without a freeze, nothing makes the scsi0 and scsi1 images correspond to a single instant of guest I/O.

The restored control file therefore names a checkpoint the restored WAL cannot supply, which is the invalid checkpoint record and could not locate a valid checkpoint record pair above. PostgreSQL states the boundary plainly: a file-system-level copy of a running cluster is a valid backup only when it is an atomic snapshot of the entire cluster, or when it is bracketed by pg_backup_start and pg_backup_stop and accompanied by every WAL segment written during the copy. This copy was neither.

The restore test was built to a bar a broken image usually clears

The monthly test restored the image, powered the guest on, waited for multi-user.target and checked SSH. All four assertions are true of a guest whose database cannot start, so the test could not detect this fault and reported that incapability as a pass.

Raising the bar to “the unit is active” would not have been enough. The capture shows an equally uncoordinated copy that started, completed automatic recovery and returned all 45000 rows at exit 0. As the capture puts it: a practice that usually appears to work, and has no defined failure signal when it does not, is more dangerous than one that fails loudly.

Resolution

Stop restarting the guest. Each attempt is another automatic recovery pass against the same image, and recovery writes. Copy the restored disks first, so the evidence and the fallback both survive what follows.

Recover the database from a database-aware source, not from the machine image. The capture shows what that path returns: a base backup rolled forward through archived WAL, checked against a recorded property of the business data. If this cluster has no base backup and no WAL archive, say so on the bridge in those words. The image still returns the operating system, the packages and the configuration, which shortens a rebuild - but the cluster data inside it is not a recovery point.

Then close the capture defect before the next window: install and enable the guest agent so the hypervisor can freeze the guest filesystems for the moment of the snapshot, and add a database-native backup with WAL archiving so the database has a recovery path that does not depend on disk-image timing.

Verification

The recovered cluster reaches a consistent recovery state and accepts connections with no invalid checkpoint record line in its startup log. Read the log for the absence of the fault, not merely for a running server - the capture contains a start that succeeded on a copy nobody should trust.

Copy the check the capture performs: not that the server started, but that the data it holds matches an independently recorded property of the business data. Row count and summed amount are read together; a row count alone survives a great deal of damage.

The rewritten restore test connects over the network and diffs a query result against a stored expectation:

RESTORE_HOST=rbdr-restore-app-01
EXPECTED=/srv/rbdr-restore-proof/rbdr-expected.txt
psql -h "$RESTORE_HOST" -U rbdr_check -d orders -Atc \
  'select count(*), sum(amount) from orders' > /srv/rbdr-restore-proof/rbdr-actual.txt
diff -u "$EXPECTED" /srv/rbdr-restore-proof/rbdr-actual.txt

The test passes on an empty diff. The boot assertions stay, as preconditions rather than as the verdict. Finally, a backup taken with the guest agent enabled is restored into an isolated target and started, so the capture defect is shown closed rather than assumed closed.

Prevention

Make the restore test assert that the application served. A query result compared against a recorded expectation - not a boot, not an SSH banner, not an active unit. That one change would have surfaced this three weeks before the array failed.

Enable guest coordination, then prove it. Installing the guest agent is the configuration change; a restore that starts without an invalid checkpoint record is the evidence. Configuration with no restore behind it is an intention.

Back databases up with database-aware tooling and treat the machine image as operating-system and configuration recovery. A base backup plus an archived WAL stream expresses a recovery point the hypervisor cannot.

Record the size and digest of every image as it is written, and alert on the age of the last restore test that reached the application rather than on the age of the last restore test. The first is what let the bridge discard the truncated-restore hypothesis in minutes; the second is what stopped a green monthly test and an unrecoverable database from looking identical for three weeks.

Write down which guests hold databases. Coordination matters most where somebody has put a stateful service inside a machine the backup schedule treats as generic.