Ближе к концу прошлого года стабильность работы Tailscale заметно просела — тренд был виден на странице статуса сервиса, и нестабильность продолжилась в начале нового года. Большинство простоев вызывала одна и та же проблема, скрытая глубоко в SQLite. Поиск занял месяцы интенсивной форензики.
К лету баг был найден, понят и, что важнее всего, исправлен.
Клиенты Tailscale вправе рассчитывать на надёжность сервиса, и несколько месяцев компания не соответствовала этому ожиданию. Ниже — рассказ о том, что пошло не так, как на это отреагировали, и как в итоге удалось вскрыть давнюю ошибку в самом сердце базы данных SQLite.
Архитектура баз данных Tailscale
Клиенты взаимодействуют с control plane Tailscale как с единой публичной точкой входа (controlplane.tailscale.com), но внутри control plane разделён на серию координационных серверов, или «шардов». Каждый tailnet в любой момент времени живёт на одном внутреннем шарде, но может бесшовно мигрировать на другой. Шарды — это деталь внутренней реализации: пользователь не знает и никогда не должен знать, на каком шарде находится его tailnet.
У каждого шарда есть своя база данных SQLite, хранящая всю информацию о находящихся на нём tailnet-ах. К базе эксклюзивно обращается один процесс на Go, который и обслуживает control plane для этих tailnet-ов. Такая модель с единственным писателем — это именно то, для чего и создавался SQLite.
SQLite используется в качестве основной базы данных с 2022 года — его выбрали как известное, надёжное и широко распространённое решение. SQLite — это «скучная технология» в хорошем смысле слова. Множество компаний используют SQLite в куда более крупных развёртываниях без проблем, и ожидалось точно такое же беспроблемное использование.
В текущем пайплайне резервного копирования каждые несколько минут снимается полный снапшот базы данных, после чего весь файл SQLite загружается в S3-бакет. Эта схема работала без нареканий с начала 2023 года.
В августе прошлого года пайплайн, читающий эти бэкапы из S3, сообщил об ошибке в одной из баз. Команда PRAGMA integrity_check, запущенная против бэкапа, подтвердила: база действительно повреждена. Повреждение SQLite в принципе возможно, но это крайне необычное явление, с которым не должны сталкиваться в нормальной эксплуатации. Повреждённую базу восстановили, причину попытались найти — безуспешно.
При работе в больших масштабах даже редкие события начинают происходить с некоторой регулярностью, так что не стоило удивляться, когда инцидент повторился — и ещё раз, и ещё. В общей сложности за полгода до устранения первопричины было зафиксировано 19 отдельных случаев повреждения баз данных.
При словах «повреждение базы данных» естественно беспокоиться о потере данных. Поскольку control plane обрабатывает только конфигурационные данные, эти базы содержат метаданные о tailnet-ах и устройствах, но никогда — приватные ключи шифрования или сетевой трафик. В самых ранних инцидентах восстановление означало, что горстка недавно добавленных устройств или изменений конфигурации не сохранялась, и небольшой объём метаданных приходилось вводить заново.
При каждом случае повреждения приходилось останавливать процесс control plane на шарде на время ремонта или восстановления базы. Это было болезненно для tailnet-ов на этом шарде — их control plane полностью пропадал на время восстановления. В ранних инцидентах простой превышал час, но с каждым следующим случаем процесс восстановления постепенно ускорялся.
Каждый tailnet — это mesh-сеть, где устройства устанавливают друг с другом прямые WireGuard®-соединения. Когда устройство присоединяется к tailnet, ему нужно получить от control plane список остальных устройств, прежде чем устанавливать новые соединения — так что если устройство выходило в онлайн во время простоя SQLite, подключиться оно не могло. Пока база чинилась, уже подключённые устройства оставались на связи друг с другом, но не могли узнавать об изменениях в сети. Такие tailnet-ы также временно теряли доступ к веб-консоли администрирования и API Tailscale.
Есть и более широкий эффект — на доверие. Глобальный инцидент публикуется на странице статуса, даже если затронуто лишь небольшое число tailnet-ов. Многие видели запись об инциденте на странице статуса, хотя их это никак не касалось. Более того, большинство шардов и tailnet-ов вообще ни разу не сталкивались с повреждением базы! Тем не менее повторяющиеся простои подрывают доверие независимо от того, затронут ты напрямую или нет.
С самого первого случая повреждения стало понятно, что это серьёзная угроза надёжности сервиса, и на проблему были брошены значительные инженерные ресурсы — но решение далось непросто.
Попытки найти причину
Баг сопротивлялся всем первоначальным попыткам его обнаружить.
Проверили недавние изменения в коде — ничего похожего на причину не нашлось. Никто давно не трогал низкоуровневый код взаимодействия с SQLite: он был написан много лет назад и до этого не вызывал никаких проблем. Весь этот код перепроверили с частым гребнем в поисках ранее пропущенных ошибок, но ничего, что могло бы вызвать наблюдаемое повреждение, обнаружено не было.
Искали общие факторы между инцидентами — безрезультатно. Проблема не была привязана ни к конкретному шарду, ни к клиенту, ни к какой-то функции tailnet, ни ко времени суток, ни к уровню нагрузки. Понять, что именно триггерит поведение, не удавалось.
Отсутствие надёжных условий воспроизведения означало, что баг нельзя было воссоздать синтетически. Пришлось полагаться на пассивную форензическую телеметрию в живом окружении, чтобы поймать повреждение «на месте преступления». Сбор диагностики на живой системе для проблемы с базой данных — последнее, чего хотелось бы, но выбора не было.
Дополнительно осложняло дело то, что повреждения возникали без регулярного расписания. Иногда инциденты разделяли часы, иногда — недели. Из-за этого было сложно планировать дальнейшую работу и предсказывать прогресс — никогда не было понятно, когда появится следующий диагностический дамп. Между октябрём и декабрём был шестинедельный период без единого инцидента, прежде чем они вернулись в виде незваного рождественского подарка.
Поскольку быстрого и лёгкого решения не предвиделось, команда Tailscale обратилась к разработчикам SQLite за профессиональной поддержкой по контракту. Решение оказалось удачным: оно дало прямой доступ к их глубокой экспертизе и опыту, состоялось множество детальных технических обсуждений архитектуры и инцидентов.
Совместно инженеры Tailscale и core-разработчики SQLite составили несколько теорий возможной причины повреждения — включая сломанные POSIX-локи при close(), некорректное управление памятью, принадлежащей SQLite, или случайное использование SQLite из нескольких потоков при отключённой потокобезопасности. После каждого инцидента собирались новые данные, добавлялись новые диагностики, и теории методично отсекались одна за другой. Постепенно происходило сближение с истинной причиной.
Транзакции, которые не залаяли
Пока шло расследование первопричины, платформу нужно было продолжать эксплуатировать. Были предприняты агрессивные шаги по автоматизации восстановления и минимизации простоя:
- Настройка шардов control plane на немедленную жёсткую остановку при обнаружении повреждения
- Развёртывание автоматического монитора бэкапов, непрерывно выполняющего
PRAGMA integrity_check - Улучшение runbook-ов и обучения дежурных инженеров
Эти меры сократили время реакции до менее часа — и тогда обнаружилась неожиданная зацепка.
Нужен был способ восстанавливать сервис, не откатываясь к последнему известному хорошему бэкапу (при этом терялось бы много данных) и не чиня заведомо повреждённую базу (потенциально рискованно).
Для этого построили пайплайн логирования транзакций: каждый SQL-запрос, изменяющий базу, стримился в отдельный лог-файл. Поскольку SQLite — это база данных с единственным писателем и сериализуемыми транзакциями, история транзакций получалась полностью линейной и детерминированной (в базе с множеством писателей вроде Postgres или MySQL это было бы не так). Повторное применение этих транзакций к последнему известному хорошему бэкапу должно было восстановить базу в её самое актуальное состояние, безопасно обойдя повреждение.
Пайплайн заработал, но затем случилось нечто ещё более полезное — он дал зацепку.
В двух инцидентах логи транзакций отказывались применяться корректно. При ближайшем рассмотрении выяснилось: данные, записанные и закоммиченные одной транзакцией, необъяснимым образом оказывались невидимыми для последующих транзакций. Запись исчезала в никуда, не выдавая никакой ошибки. Это должно было быть невозможно!
Надпись на WAL
Пока продолжались инциденты, разработчики SQLite создавали новый инструмент отладки. Уже некоторое время подозревали, что баг кроется где-то в процессе чекпоинтинга, и для лучшей видимости происходящего во время чекпоинтов создавался новый инструмент.
Чтобы понять, что этот инструмент обнаружил, стоит кратко объяснить, как устроены чекпоинты в SQLite.
База данных SQLite состоит из серии «страниц» — крошечных блоков информации. При обновлении базы часть страниц нужно заменить новыми, с обновлённой информацией.
Ради лучшей производительности и большей конкурентности SQLite здесь запускается с включённым Write-Ahead Logging — новые страницы записываются не напрямую в файл базы данных, а в «журнал упреждающей записи», или WAL-файл.
Новые страницы не могут бесконечно накапливаться в WAL-файле — в какой-то момент их нужно скопировать обратно в основной файл базы данных. Этот процесс называется «чекпоинтингом».
В большинстве развёртываний SQLite сам решает, когда делать чекпоинт, и процесс невидим для конечного пользователя и разработчика. В control plane Tailscale процесс чекпоинтинга берётся под ручной контроль, чтобы обеспечить быстрые и консистентные бэкапы. Этот нестандартный подход казался подозрительным по мере того, как исключались другие возможные причины.
Одной из зацепок стало то, что во время инцидентов метрики показывали: SQLite сообщал о копировании из WAL-файла большего числа страниц, чем в нём фактически было. Если в WAL-файле 10 страниц, а копируется 20 — что-то явно не так.
Чтобы понять, что происходит во время таких некорректных чекпоинтов, разработчики SQLite создали новый отладочный инструмент для уровня виртуальной файловой системы.
SQLite разделён на несколько слоёв. Верхний слой — парсер и генератор кода, преобразующий SQL-запросы во внутренние структуры данных SQLite. Эти структуры передаются в pager, который разбивает их на отдельные страницы для записи на диск. Собственно запись на диск обрабатывается интерфейсом ОС, или «виртуальной файловой системой». Сейчас у SQLite есть две основные реализации виртуальной файловой системы — для Unix и Windows.
Тем, кто интересуется более глубоким разбором этих внутренностей, стоит посмотреть лекцию Ричарда Хиппа, главного автора SQLite.
Такая слоистая архитектура позволяет заменять разные слои разными реализациями или оборачивать существующий слой для получения дополнительной информации. Чтобы диагностировать проблему, разработчики SQLite создали обёртку вокруг виртуальной файловой системы, которая пишет дополнительную трассировочную информацию и логи об изменениях в базе данных. Эта обёртка называется tmstmpvfs-шимом, исходный код доступен в публичном репозитории SQLite.
Шим развернули в живом окружении и стали ждать следующего случая повреждения. К счастью, ждать пришлось недолго.
Баг WAL-Reset
После следующего инцидента дополнительные логи от нового шима tmstmpvfs позволили разработчикам SQLite найти и исправить баг: редкое состояние гонки в исходном коде SQLite между чекпоинтом и write-транзакцией.
Если запись происходит в определённый момент во время чекпоинта, процесс чекпоинтинга «путается» — он думает, что часть страниц уже скопирована из WAL в основной файл базы данных, хотя на самом деле это не так. Эти страницы так и не записываются в файл базы данных, и данные теряются безвозвратно. Файл базы данных становится повреждённым, потому что другие страницы, ссылающиеся на них — например, индекс — всё равно записываются в базу.
Разработчики SQLite назвали это «багом WAL-Reset» и оценивают, что он присутствовал в SQLite не менее 16 лет. Столько времени баг мог существовать незамеченным именно из-за своей редкости — настолько редкой, что разработчикам SQLite пришлось специально добавлять код, принудительно вызывающий его в тестовых окружениях. Исправление добавляет дополнительную проверку в функцию чекпоинтинга, которая обнаруживает, что WAL был сброшен другим потоком.
Разработчики подтвердили, что именно этот баг вызывал всё наблюдавшееся странное поведение. Он объяснял и повреждение, и логи транзакций, отказывавшиеся корректно применяться, и несогласованную статистику чекпоинтов. Также стало понятно, почему вероятность столкнуться с этим багом была выше, чем у других пользователей SQLite: control plane берёт чекпоинтинг под ручной контроль и делает это очень агрессивно. Даже баг, срабатывающий при редком условии, рано или поздно должен был сработать.
Это был волнующий момент. После месяцев путаницы и неопределённости наконец появилась правдоподобная теория причины повреждения и исправление, которое можно было развернуть для его предотвращения.
Разработчики SQLite выпустили исправление как SQLite 3.52.0, и его сразу начали готовить к развёртыванию.
Исправлено, но с ложной тревогой
SQLite 3.52.0 выкатывали осторожно — сначала на несколько канареечных шардов, а когда убедились, что всё работает гладко, развернули на остальной control plane.
Монитор бэкапов немедленно загорелся красным, сообщив о повреждении в 13 разных базах данных. Это было крайне тревожно, но по отработанным процедурам восстановления все предполагаемые повреждения были устранены, и всё пришло в норму. Оказалось, что эти базы не пострадали от реального повреждения — сработала вторая проблема в новой версии SQLite.
Информацией об ошибках поделились с разработчиками SQLite, что помогло обнаружить баг, связанный со устаревшими индексами по вычисляемым выражениям. Если создать индекс по вычисляемому значению, а затем изменить сам расчёт, индекс будет содержать несовпадающие значения, что PRAGMA integrity_check отчитывается как повреждение.
В данном случае некоторые высокоточные временные метки хранились как текст и конвертировались в число с плавающей точкой в VIRTUAL-колонке-генераторе, а релиз SQLite 3.52.0, исправивший гонку данных, заодно внёс оптимизацию, слегка изменившую поведение округления при конвертации текста в число с плавающей точкой. На канареечных шардах не оказалось временных меток, вызывающих изменённое поведение округления, поэтому проблема была пропущена при поэтапном развёртывании.
Поскольку это изменение вызывало ложные предупреждения о повреждении, разработчики SQLite отозвали релиз 3.52.0 и вместо него опубликовали 3.51.3, содержащий только исправление бага WAL-Reset.
Проблему на своей стороне устранили, снизив точность временных меток до целых секунд — конвертация текста в целое число однозначна. Тем временем разработчики SQLite реализовали автоматическую функцию самовосстановления индексов в версии 3.53.0, которая предотвращает проблему устаревших индексов по выражениям.
Время праздновать!
После развёртывания исправления на весь control plane можно было бы объявить победу, но осторожность сохранялась: отсутствие инцидентов повреждения ещё не значит, что всё исправлено — уже был один шестинедельный период обманчивого затишья.
Требовалось прямое доказательство того, что эта гонка данных действительно происходит в продакшене. Теперь, когда причина бага была понятна — столкновение write-транзакции и сброса WAL, — драйвер SQLite был пропатчен, чтобы логировать предупреждение при пересечении этих двух операций. Если предупреждение срабатывало, а база оставалась неповреждённой — это было бы доказательством, что исправление спасло от потенциального инцидента.
Предупреждение развернули и стали ждать. И ждать. И ждать ещё. Недели шли, и начали закрадываться сомнения: почему предупреждение не срабатывает? Сломано ли оно? Ошибочна ли теория? Прячется ли настоящий баг где-то ещё во тьме?
Затем, спустя два месяца, долгожданный алерт наконец сработал:
Этот алерт доказал, что точные условия для бага WAL-Reset действительно возникают в продакшене, а значит, именно он был наиболее вероятной причиной полугодовой нестабильности сервиса.
С момента срабатывания этого странно радостного алерта прошло уже четыре месяца без единого инцидента с базами данных на момент написания. Наконец можно было вздохнуть спокойно.
В стороне от проторенной тропы
Никто не хотел тратить полгода на поиск ошибок в SQLite. Это было крайне утомительным испытанием и для клиентов, и для сотрудников, и все рады оставить эту нестабильность позади.
Это расследование — полезное напоминание: эксплуатация «скучной технологии» нестандартным способом — это риск. Общепринятые пути и стандартные конфигурации невероятно хорошо протестированы и надёжны. Большинство пользуется SQLite в стандартной конфигурации и никогда не сталкивается с подобными проблемами. Всё, что здесь делалось, было публичной, задокументированной, поддерживаемой конфигурацией — но, взяв под ручной контроль процесс чекпоинтинга и работая в собственном агрессивном темпе, команда сошла с проторенной операционной тропы.
Устранение этих инцидентов потребовало огромных совместных усилий десятков людей — включая инженерные и саппорт-команды Tailscale, а также core-мейнтейнеров SQLite. Именно благодаря их заслугам последствия этих инцидентов оказались не намного хуже.
Повторяющиеся простои подрывают доверие вне зависимости от того, сколько людей затронуто, и клиентам стоит быть благодарным за терпение и поддержку, проявленные во время этого расследования.
Каким бы утомительным ни был этот период, в итоге позиция оказалась крепче прежней. Давняя ошибка в SQLite исправлена, попутно устранены десятки других мелких проблем, замеченных в процессе поиска. Был профинансирован open-source VFS-шим для SQLite, который почти сразу помог изолировать состояние гонки и будет помогать находить похожие баги в будущем. Наконец, процессы резервного копирования и восстановления баз данных были доработаны и протестированы вживую больше десятка раз.
Есть надежда, что подобного инцидента с базами данных больше не повторится — но если это случится, к этому уже будут готовы.