The ticket said “backup server is missing the customer uploads.” It was filed by someone who had gone looking for a file, not by monitoring. Monitoring had been green every morning for eleven months. It was green that morning too.
I got the call because the guy who wrote the backup script had left, and the people who remained wanted someone who could read shell without flinching.
The script was fourteen lines. It was fine. That’s the part that bothers me.
#!/bin/sh
set -e
rsync -a --delete /srv/uploads/ backup01:/backup/uploads/
echo "backup ok $(date)" >> /var/log/backup.logTrailing slash on the source, correct. set -e, correct. -a, --delete, a mirror that actually mirrors instead of accumulating every file anyone ever removed. If you asked me to review this in a pull request I would have approved it with a nit about quoting.
What actually happened
/srv/uploads was a separate disk. In /etc/fstab it had nofail, because somebody once had a box hang at boot waiting for a data volume and decided that was worse than booting without it. Reasonable at the time. The box booted, the disk didn’t mount (a bad cable, as it turned out, because of course), and /srv/uploads was just a directory on the root filesystem. Empty. Mode 755, owned by root, exactly as the installer left it in 2019.
Then cron fired at 02:10.
rsync looked at the source: an existing, readable, empty directory. It looked at the destination: forty thousand files. The source is the truth. Anything in the destination that is not in the source gets removed. rsync removed forty thousand files, in order, quickly, and exited 0. There was no error to report. From rsync’s point of view someone had asked for an empty mirror and received one.
The script wrote “backup ok” to the log. The dashboard grepped the log for “backup ok” with today’s date. Green.
Why rsync didn’t save us
People assume rsync has a safety net here. It has a different one. If rsync hits an I/O error while scanning the source, it prints IO error encountered -- skipping file deletion and refuses to delete anything on the receiving side. That guard exists for a half-readable source. It does nothing for a source that is readable and simply empty, because an empty directory is not an error. It is a valid state.
There is a second guard, --max-delete=NUM, which stops rsync after NUM deletions and exits non-zero (code 25). Nobody had set it. If they had set it to a couple hundred, the run would have deleted a couple hundred files, failed loudly, and I’d be writing a shorter story.
Worth saying out loud: a mirror is not a backup. It’s a replica with a delay of one cron interval. A replica faithfully copies whatever the source becomes, including nothing. I wrote up the flags that matter in rsync flags that matter and the paragraph on --delete there says to run it with -n first, every time. That is advice for a human at a terminal. It does not help a cron job at 02:10.
The part where it got worse
The backup host ran ext4. No snapshots. No ZFS, no LVM thin pool, nothing that retained yesterday. The only second copy of the uploads was the primary, which was currently a directory with nothing in it, sitting on top of a disk that was physically fine and just not attached.
Fixing the cable and mounting the disk brought the primary back. That’s the only reason there’s no horror story here about customers. The data was on the data disk the whole time. The backup was the thing that was gone, and the next night’s run would have been a valid mirror again.
Think about that for a second. The system recovered because the failure was in the one place where we hadn’t put the real data. We got lucky in a direction that depended entirely on which of the two disks the cable fault hit. Had the backup host’s volume been the flaky one, or had the primary actually died the same week, we’d have had no copy at all and a green dashboard.
I’ve seen this movie before, in a different wrapper. The backup completed, the restore was fine, and the thing being backed up was wrong. Same failure family. The job succeeds against what it’s pointed at, and nobody asks whether what it’s pointed at is the thing you care about. The temporary NFS mount had the same smell from the other direction.
What I changed
Four things, none clever.
Refuse to run if the source isn’t a mount.
mountpoint -q /srv/uploads || { echo "uploads not mounted" >&2; exit 1; }mountpoint is in util-linux and checks that the path is a mount point, not merely a directory that exists. It’s one line and it would have prevented the entire incident. findmnt -rn /srv/uploads does the same job if you prefer it.
Put a sentinel file on the data volume. A file named .mounted that lives on the disk and nowhere else. The script tests for it. This covers the case where something else got mounted at the path, or a bind mount papered over it, which mountpoint alone would happily accept.
Cap the damage. --max-delete=500. A legitimate nightly run on that dataset deletes tens of files. If it wants to delete thousands, a human should look, and exit code 25 gets a human to look.
Keep history on the receiving side. The backup host got ZFS. A snapshot before each run, zfs snapshot backup/uploads@$(date +%F), thirty days retained. Now the mirror can lie and we can still go back a day. Replication details are in zfs send/recv if you want to push that offsite too.
Also changed: the monitor no longer greps for the string “backup ok”. It checks the file count and byte total on the destination against the previous night and complains about a drop of more than a few percent. A heartbeat that only proves the script ran proves the script ran.
And nofail stays, for the record. It was never the bug. The bug was that the script treated “path exists” as “data exists.”
The takeaway, such as it is
A backup script has three jobs: verify the source is what you think it is, copy it, and verify the destination. The original did the middle one. Most of them do. The two verification steps are the ones that cost a line each and the ones that are always missing, because on the day you write the script, the source is always mounted.
Exit 0 means the command did what you asked. It was never a statement about whether you asked for the right thing.