A restore that reported success and returned nothing

At 03:21 UTC this morning, the DuckDB leg of our nightly restore drill failed. Not the backup. Not the upload. The restore ran, reported success, and then the verification step went looking for the row it had written an hour earlier and found nothing at all:

text

Catalog Error: Table with name restore_drill_sentinel does not exist!

That is the failure mode you least want. A backup that errors is annoying and loud. A restore that fails outright is recoverable, because you still have the backup. A restore that returns exit code 0 and hands you an empty database is the one that hurts, because every system downstream of it believes the restore worked. Nobody re-checks a successful restore. That is the whole point of a success code.

No customer data was affected. The reason I can say that plainly is the same reason I am writing this post: the thing that hit the bug was a drill, on staging, at 3 in the morning, on a database that existed for four minutes and contained one row.

What the drill actually does

Every night at 02:30 UTC we run a full restore drill on staging. For each engine, in sequence, it:

Creates a throwaway database.
Writes a sentinel row with a known value.
Takes a real backup, the same code path a customer's backup uses, to the same R2 bucket.
Simulates data loss by dropping the data.
Restores from that backup.
Verifies the sentinel came back.
Runs a second export/import round trip on top, then tears everything down.

It runs against every engine we offer in Layerbase Cloud, with two deliberate exceptions. MongoDB is not creatable in Cloud for licensing reasons, so FerretDB gets drilled in its place. TigerBeetle needs a bigger staging box than the drill currently gets, and pretending otherwise with a skipped test would be worse than a documented gap.

The important word is verifies. Plenty of platforms monitor that backups were written: file exists, size is nonzero, job exited clean. Far fewer prove every night that those backups come back. Those are different claims, and only the second one is the one you actually care about at 4am during an incident.

The night before, the drill cried wolf

I want to tell this part first, because it is the reason the real alert got taken seriously.

The previous night's drill failed on InfluxDB with a message that amounted to fetch failed. The alert text said backups may not be recoverable. That is a sentence engineered to ruin your morning.

It was wrong. The backup was fine. What had actually happened was a transient network throw in the drill's own preamble: a bare fetch sitting outside the retry envelope, in the setup code that runs before any database is even created. One flaky connection and the leg died before it had done anything worth reporting on. The alarm had a bug. The thing it was watching was healthy.

An alarm that is wrong is worse than no alarm, because the next false positive teaches you to ignore the true one. So instead of shrugging at it, I spent the day fixing the alarm with the same rigor I would spend on the thing it watches. Every request in the drill now goes through one retry envelope with a bounded overall budget. Non-idempotent POSTs, meaning backup and deploy, are deliberately opted out of network retry: if the response is lost, we would rather fail the leg than risk running a second backup on a request we already sent. Around twenty deterministic tests now cover the retry policy itself.

Twenty-four hours later that hardened drill fired again, on a different engine, with a different shape of failure. Because the plumbing had just been audited, the first question was not "is the drill broken again". It was "what is broken".

It passed on retry, which was the useful part

I re-dispatched the DuckDB leg alone, forty-five minutes later, on identical code. It passed.

That is the most informative result I got all day. A green run on unchanged code eliminated every deterministic hypothesis in one stroke. Not a bad backup file. Not a version mismatch. Not a broken checkpoint. Not a bug in the restore logic that would fail the same way every time. Whatever this was, it depended on timing, which meant it depended on load, which meant it would keep hiding.

So I stopped reasoning about it and watched it instead. During another drill run I put a watcher on the working directory sampling at two-second resolution: file inodes, file hashes, and the command lines of every process holding them. Then I read the tape.

The race

DuckDB in Cloud does not run as a bare file that our tooling owns exclusively. It sits behind a small Postgres-wire proxy, so that clients can talk to it with ordinary Postgres tooling. That proxy holds the database file open.

The restore sequence, roughly, looked like this:

bash

# stop the proxy holding the database file
kill -TERM "$(pgrep -f duckgres)"   # async: returns immediately
sleep 2                             # "it should be gone by now"

cp "$restored" "$db_path"           # same inode, still referenced
rm -f "$db_path".wal                # blind cleanup at a fixed point

start_proxy

Read it with a hostile eye and it comes apart. kill -TERM is asynchronous. It does not wait, it asks. The sleep 2 is a guess dressed up as a synchronization primitive. And the thing being asked to die does real work on the way out: the proxy writes its write-ahead log during shutdown.

Under load, shutdown takes longer than the grace period. The sequence then runs like this:

The kill is sent. The proxy begins shutting down, flushing as it goes.
Two seconds pass. The script assumes death and proceeds.
The restored file is copied over the same inode the dying proxy still holds.
The WAL files are removed.
The proxy finally finishes shutting down and writes its final WAL, containing the transactions from the simulated data loss, including the DROP. This lands after the cleanup that was supposed to remove it.
The proxy is relaunched, finds a WAL, and does exactly what a correct database is supposed to do: it faithfully replays it.

The result is a valid database file with a clean catalog and no data. The restore genuinely succeeded. Then the drop replayed on top of it.

The race had been in the code since June 15. It survived more than sixty nightly drills without firing, because it needs a restore to happen while the proxy is busy enough that shutdown outruns two seconds. The same shape existed in the SQLite proxy path, for the same reason, and had never fired there either.

The fix

All of it landed the same night. Found to fixed was under six hours, and none of it is clever, which is the point:

Collect PIDs before the kill, not after, so we know exactly which processes we are waiting on.
Prove the stop. Poll for process death, and separately probe the port until it refuses connections. Two independent signals, because a process can linger after it stops listening and a port can be freed before the process is gone.
Escalate. SIGKILL at 8 seconds if SIGTERM has not taken.
Fail closed. If the proxy still will not die, the script exits nonzero and touches nothing. A restore that refuses to start is a support ticket. A restore that half-runs is a data loss event.
Delete the WAL only after confirmed death, never on a timer.
Swap the file, do not overwrite it. Copy to a temporary path and atomically rename onto a new inode. If some straggler flush still lands, it lands on an orphaned inode and harms nothing. This one change alone defuses the whole class.
Poll for readiness on restart instead of sleeping blind.

The regression tests execute the real generated shell under bash against a stub proxy that ignores SIGTERM and writes a WAL when it finally dies, which is precisely the adversary the old code lost to. Five of the nine cases fail against the pre-fix script. A targeted drill on the fixed build passed. The full nightly is the real proof, and it runs every night at 02:30 UTC.

Why this one mattered

The restore path this touched is not drill-only scaffolding. It is the same code behind customer-initiated restores, the day 90 archive rehydrate, wake-from-rebuild, and moving a database between servers. A silent empty restore in that path is not a test failure, it is the failure that quietly follows a real incident and turns a bad night into an unrecoverable one.

It never got there, because the drill went first. That is the entire argument for drilling restores nightly rather than watching backup jobs go green. A backup is a claim. A restore is the evidence. If you have never restored from your backups on a schedule, on real infrastructure, with a verification step that fails when the data is missing, then you do not know what you have, you know what you wrote.

And the humbling footnote: the drill that caught this had itself cried wolf twenty-four hours earlier. Fixing the alarm's own plumbing is what made the next firing credible enough to chase at 3am instead of dismissing. Both halves of that count.

Layerbase runs this drill every night, for every engine we host. Not because we expect it to fail, but because the one night it does is worth every night it does not.