The backup job had run every night for four years, reported success every night, and had never been restored. The first deliberate restore took ninety minutes and produced a database that was missing a table — which is the outcome that makes the case for doing this, and it is a case nobody makes until it has happened.
The symptom
$ zcat /backups/2023-04-24.sql.gz | grep -c '^CREATE TABLE'
41
$ mysql -e 'SELECT COUNT(*) FROM information_schema.tables
WHERE table_schema="app"'
42
$ diff <(zcat /backups/2023-04-24.sql.gz | grep -oP '^CREATE TABLE `K[^`]+' | sort)
<(mysql -N -e 'SHOW TABLES' app | sort)
> sessions
$ grep ignore-table /usr/local/bin/backup.sh
--ignore-table=app.sessions # large, not importantThe exclusion was added in 2021 when the table was large and held PHP session data. It now holds OAuth refresh tokens, because a library was swapped in 2022 and reused the table. Nobody revisited the backup script, because nobody reads a backup script that is working.
Why it happens
A backup job reports on writing a file. Whether that file can be restored, and whether the restored database is the database you needed, are different questions that only a restore can answer.
The fix
The drill, as a job
#!/usr/bin/env bash
set -euo pipefail
latest=$(aws s3 ls s3://backups/db/ | sort | tail -1 | awk '{print $4}')
aws s3 cp "s3://backups/db/$latest" /tmp/restore.sql.age
age -d -i /etc/backup/restore.key /tmp/restore.sql.age
| gunzip > /tmp/restore.sql
docker run -d --name drill -e MARIADB_ROOT_PASSWORD=drill
-p 3399:3306 mariadb:10.11
./bin/wait-for-mysql 3399
mysql -h127.0.0.1 -P3399 -uroot -pdrill -e 'CREATE DATABASE app'
mysql -h127.0.0.1 -P3399 -uroot -pdrill app < /tmp/restore.sqlThe assertions that matter
q() { mysql -h127.0.0.1 -P3399 -uroot -pdrill -N -B app -e "$1"; }
# 1. every table the production schema has
[ "$(q 'SELECT COUNT(*) FROM information_schema.tables
WHERE table_schema="app"')" -eq "$EXPECTED_TABLES" ]
# 2. the newest row is from last night, not last year
newest=$(q 'SELECT MAX(created_at) FROM orders')
[ "$newest" > "$(date -d yesterday +%F)" ]
# 3. row counts within 5% of production
# 4. a checksum on one small, stable table
[ "$(q 'CHECKSUM TABLE currencies' | cut -f2)" = "$EXPECTED_SUM" ]
# 5. the application boots against it
docker run --rm --network drill-net app:latest
php artisan migrate:statusThe last assertion is the one that catches a restore that is technically complete and functionally broken — a schema at the wrong migration version, or a table that restored with an unexpected collation. Booting the application against the restored database is the only check that covers the whole surface.
Timing it, because the number is the objective
measured, four months:
month download decrypt import assert total
Apr 4m 10s 1m 20s 78m 6m 89m 30s
May 4m 10s 1m 20s 22m 2m 29m 30s
Jun 4m 20s 1m 20s 21m 2m 28m 40s
Jul 4m 40s 1m 30s 24m 2m 32m 10s
April was slow because the drill container had 512 MB.
May onward: 4 GB, and innodb_flush_log_at_trx_commit=2
for the import only.
the recovery objective was "about an hour". it is 30
minutes, and now that is a measured number.The key, and where it must not live
questions asked during the first drill:
where is the key? a password manager
who has access? two people, one of whom
left in 2022
is it in the runbook? the runbook says "the
backup key"
what if the password
manager is unavailable? unanswered
after:
primary the password manager, two current people
secondary a sealed envelope, offsite, with the
recovery procedure printed alongside
the drill alternates between them, so both are
known to workAlternating the drill between key sources is the part that is easy to skip and is the whole point of the secondary — a copy that has never been used is a copy that might be a photograph of the wrong screen. Two of the four drills used the envelope.
Verifying it worked
$ cat /var/log/restore-drill/2023-07.log | tail -8
tables: 42/42 OK
newest order: 2023-07-24 OK
row counts: within 1.2% OK
checksum: match OK
app boots: yes OK
total: 32m 10s
# and the deliberate failure test, in May
$ ./bin/restore-drill --backup=2023-05-01-corrupted.sql.age
import: ERROR 1064 at line 41208
DRILL FAILED — alerted #opsDeliberately feeding it a truncated backup once confirms the drill can fail, which is not obvious from four successful runs. A check that has never failed is indistinguishable from a check that cannot fail.
What this costs
A scheduled job that will fail on a Sunday, usually for a reason unrelated to the backup — a runner without disk, a rotated key, an image tag that moved. Each of those is a false alarm that erodes the response, and the answer is that the drill alerts to a channel rather than to a person.
Thirty minutes of compute a month is nothing; the ongoing cost is that the assertions need maintaining. A new table changes the expected count, and a drill that fails because the schema legitimately changed is the failure mode that eventually gets it disabled. Deriving the expected values from the production schema rather than hard-coding them is what we should have done first and did in June.