Восстановление из снапшота откатило сервер на две недели назад

MAATRIX

Ночью деплой сломал прод, дежурный поднял панель, увидел «последний снапшот: сегодня, 03:00» и восстановил из него — а сервер откатился на две недели назад. Две недели заказов, правок конфигурации и переписки с клиентами исчезли за десять минут работы lvconvert --merge. Ниже — как это выяснилось, какие версии отбросили по пути и что на самом деле сломалось за две недели до того, как кто-то это заметил.

Что случилось

Инфраструктура — обычная связка: KVM-гипервизор, тома под виртуалки на LVM thin-pool, ежедневные снапшоты по cron с ротацией на 14 дней. Раз в сутки скрипт создавал снапшот боевого тома, удалял тот, что старше двух недель, и писал строчку в каталог /var/lib/snapshots/catalog.json, который читала внутренняя панель мониторинга.

В ночь инцидента релиз с багом в миграции испортил часть данных в проде. Дежурный принял решение откатиться снапшотом, а не чинить миграцию руками — стандартная практика, когда цена ошибки при ручном фиксе выше, чем потеря нескольких минут работы. Панель показывала свежий снапшот с сегодняшней датой создания — как обычно. Слили изменения последних минут, где могли, смёржили снапшот, подняли том.

После загрузки счётчики заказов, последние правки nginx-конфига и записи в базе оказались такими, какими были две недели назад. Часть данных, накопленных за это время, восстановить было уже нечем — снапшот, из которого делали merge, оказался единственным «живым» слепком тома, и он был двухнедельной давности.

Что видели в логах и на панели

Первая реакция — паника с оттенком «панель нам соврала». Разбор начали с того, что реально показывали инструменты в момент инцидента:

• панель мониторинга: «Последний бэкап: сегодня, 03:14» — зелёная плашка, как и каждый день последние две недели;
• catalog.json на диске: mtime файла — сегодняшняя ночь, тело файла — валидный JSON без ошибок парсинга;
• лог cron-скрипта /var/log/snap.log: за последние 14 дней — строки Rotation script already running, exiting каждую ночь, без единой строки об успешном создании снапшота;
• lvs -a -o+lv_time vg_data: у снапшота, который панель называла «последним», реальная дата создания — две недели назад, а не сегодняшняя ночь;
• список LV в thin-pool: ровно один снапшот боевого тома вместо ожидаемых 14 — то есть ротация не только не создавала новые снапшоты, но и не удаляла старые.

Именно расхождение между mtime каталога и lv_time тома дало первую зацепку: панель была права насчёт файла, но не насчёт данных внутри него.

Версии, которые отбросили

Прежде чем добраться до причины, проверили и закрыли несколько версий — каждая была правдоподобной и заняла время:

• Восстановили не тот том. Сверили UUID и serial LV с тем, что указан в инвентаре виртуалки — совпадает, ошибки выбора не было.
• Баг гипервизора или API снапшотов. На соседних VM с той же схемой снапшотов проверили создание тестового снапшота вручную — lvcreate -s отработал штатно, значит, дело не в самом LVM или ядре.
• Рассинхронизация времени на хосте. timedatectl status показал синхронизацию с NTP без дрейфа — версия с «сервер думал, что сейчас другая дата» не подтвердилась.
• Ручное вмешательство или компрометация. Проверили auth.log и историю sudo за две недели — посторонних сессий и подозрительных команд нет, том никто руками не трогал.
• Просто выбрали не тот снапшот в интерфейсе. Пересчитали шаги дежурного по истории команд — он выбрал ровно тот LV, который система пометила «последним». Ошибка была не в выборе, а в том, что показывала система.

После того как «человеческий фактор» и «внешнее вмешательство» отпали, разбор сместился туда, где и должен был начаться — в сам cron-скрипт ротации.

Настоящая причина: мёртвый lock-файл, который тихо остановил и создание, и очистку

Скрипт ротации использовал классическую защиту от параллельного запуска — файл-флаг:

#!/bin/bash
# /usr/local/bin/snap-rotate.sh
LOCK=/var/run/snap-rotate.lock

if [ -f "$LOCK" ]; then
  echo "$(date): Rotation script already running, exiting" >> /var/log/snap.log
  exit 0
fi
touch "$LOCK"

DATE=$(date +%F)
lvcreate -s -L 5G -n "snap-vmdisk-$DATE" vg_data/vmdisk >> /var/log/snap.log 2>&1
# ... удаление снапшотов старше 14 дней ...

rm -f "$LOCK"

Проверка [ -f "$LOCK" ] смотрит только на существование файла, а не на то, жив ли процесс, который его создал. Две недели назад один из запусков скрипта был убит по OOM во время особенно тяжёлой ночной джобы бэкапа базы — файл snap-rotate.lock остался лежать навсегда. С этого момента каждый следующий запуск видел лок, писал одну и ту же строку в лог и выходил с кодом 0 — то есть cron формально отрабатывал успешно, никакой алерт по неудачному exit code не срабатывал, потому что срабатывать было не на что.

Второй кусок головоломки — почему панель всё равно показывала «сегодня». Отдельная, не связанная с ротацией задача раз в сутки прогоняла catalog.json через валидатор: дописывала поле checked_at, приводила форматирование к единому виду и перезаписывала файл целиком — даже если новых записей не появилось. Панель брала дату из mtime файла каталога, а не из поля created_at внутри самих записей. Валидатор исправно «освежал» файл каждую ночь, и индикатор оставался зелёным ровно 14 дней подряд, пока за кулисами не создавалось и не удалялось ни одного снапшота.

Два независимых, безобидных по отдельности механизма — мёртвый лок и валидатор, трогающий файл целиком, — вместе дали ложную картину полностью рабочей системы бэкапов. Здесь стоит на секунду отвлечься от конкретно этого случая: любой слепок тома через LVM thin-pool — это снапшот со своими рисками, и если механизм их ротации не проверяется независимо от собственных логов, он может замолчать и никто не узнает.

Как проверить, что ваши снапшоты реально свежие

Вывод из этого разбора простой: нельзя доверять индикатору, который читает файл, а не данные. Практический чек-лист, который стоит прогнать на своей инфраструктуре:

# Реальная дата создания LV-снапшота, а не mtime каталога
lvs -o+lv_time vg_data

# Для ZFS — то же самое через свойство creation
zfs list -t snapshot -o name,creation -s creation

# Сколько живых снапшотов сейчас, а не сколько должно быть по расписанию
lvs vg_data | grep snap- | wc -l

Дальше — три вещи, которые превращают «мониторинг бэкапов» из театра в рабочий инструмент:

1. Источник правды — метаданные объекта, а не файл-каталог рядом с ним. Если у вас есть панель или дашборд, пусть она берёт дату создания из lv_time/creation/эквивалента у бэкенда хранения, а не из времени модификации служебного файла. Как именно проверять свежесть и целостность копии — отдельная тема, разобранная в статье как проверить, что бэкап рабочий.
2. Heartbeat вместо «скрипт написал строку в лог». Cron, который тихо завершается с кодом 0 из-за протухшего лока, ничем не отличается для системы алертинга от cron, который отработал штатно. Решается это внешним «мёртвым человеком» — задача обязана дойти до конца и отправить пинг наружу, иначе алерт сработает по таймауту. Настройка такого подхода описана в статье про мониторинг cron-задач через healthchecks.io.
3. Периодический тестовый restore, а не только создание снапшота. Снапшот, который никогда не разворачивали в тестовую среду, — это гипотеза о бэкапе, а не бэкап. Раз в одну-две недели стоит поднимать последнюю копию на отдельном scratch-томе и проверять, что данные там актуальны и целостны — а заодно сверять фактическое число хранимых копий с политикой ротации, которая описана в статье сколько хранить бэкапы и какая ротация нужна.

Что изменили после инцидента

По итогам разбора поменяли не один скрипт, а сам подход к тому, что считается «бэкап работает»:

• Lock-файл заменили на flock -n внутри самого скрипта. Блокировка теперь привязана к файловому дескриптору процесса и снимается автоматически, если процесс убит — мёртвый лок больше физически не может остаться висеть после OOM или kill -9.
• Панель переписали на чтение lv_time напрямую, без промежуточного каталога. Если данных нет или команда lvs вернула ошибку — панель честно показывает «нет данных», а не последнее закэшированное значение.
• Добавили heartbeat-пинг в конце скрипта ротации. Если снапшот не создался и не удалился старый — пинг не уходит, и внешний сервис поднимает алерт по таймауту через час, а не «когда-нибудь заметит дежурный».
• Мониторинг thin-pool разделили на data% и metadata%. Раньше следили только за процентом занятого места в пуле данных; отдельный, куда меньший по размеру пул метаданных thin-provisioning не мониторили вовсе, хотя именно его переполнение способно молча остановить создание новых снапшотов даже при наличии свободного места под сами данные.
• Ввели еженедельный автоматический test-restore на изолированный scratch-том с проверкой контрольных сумм ключевых файлов и таблиц — теперь несвежий бэкап обнаруживается тестом, а не следующим реальным инцидентом.
• Аудит ротации сделали регулярным, а не разовым. Раз в квартал кто-то из команды вручную сверяет фактическое число и возраст хранимых снапшотов с задокументированной политикой — простая процедура, которая один раз уже стоила бы двух недель данных, если бы существовала раньше.

Отдельно пересмотрели общий подход к резервному копированию виртуалок: одного механизма снапшотов на том же хранилище оказалось мало, и часть копий вынесли на отдельный сервер, чтобы сбой конкретного thin-pool не оставлял без вариантов восстановления вообще.

Частые вопросы