Поиск неисправностей
Метод, инструменты и разбор инцидентов распределённой системы
Вячеслав Федоров
Лекция 20
Разработка и применение ПО
в физических исследованиях
Изложение. Двадцатая лекция продолжает девятнадцатую. Лекция «Наблюдаемость» рассматривала, как заранее сделать систему наблюдаемой с помощью журналов, метрик, трассировок и оповещений; эта лекция посвящена тому, как действовать, когда оповещение уже пришло. Поиск неисправностей представляет собой процесс выявления и устранения причины, по которой система ведёт себя не так, как ожидается. Его нередко считают врождённым талантом, однако книга Google SRE рассматривает его как навык, которому можно научиться и научить, и выделяет две его составляющие: общий метод выдвижения и проверки гипотез и знание устройства конкретной системы. К ним добавляются инструменты, позволяющие проверить гипотезу на работающей системе. В рамках лекции рассматриваются особенности отказов распределённых систем, метод поиска, инструменты для работающего процесса на Python и Linux, управление инцидентом и разбор его причин, а в завершение — три учебных случая. Надпись на титуле — 500, код ответа HTTP «внутренняя ошибка сервера»: с него начинаются хронология первой части и первый учебный случай шестой.
Демонстрации. Слайды с розовым выделением слова «Демонстрация» отмечают места, где изложение прерывается для работы в терминале виртуальной машины lab с Ubuntu 24.04, Python 3.12, py-spy, strace, perf, git и systemd, далее называемой стендом: на слайде проигрывается запись тех же команд. Службы демонстраций слушают петлевой интерфейс 127.0.0.1, а данные учебных случаев порождаются моделями без случайности или с фиксированным зерном. Поэтому порядок событий, коды возврата, номера строк в стеках и числа событий повторяются на любой машине с Linux и Python 3.12, а времена, номера процессов и дескрипторов зависят от машины и запуска.
Содержание
От симптома к причине и к уроку для системы
Изложение. Лекция состоит из шести частей. Первая рассматривает особенности отказов распределённой системы: частичные отказы, расхождение часов машин и заблуждения о сети, оставляющие следы в коде. Вторая посвящена методу: знанию системы, циклу «гипотеза — проверка — вывод», типичным ошибкам рассуждения, поиску последнего изменения и проверке системы по уровням. Третья вводит инструменты для работающего процесса: профили, стеки потоков, снимки памяти, ожидание в ядре и журнал службы. Четвёртая рассматривает управление инцидентом — первые минуты, масштаб последствий, роли участников и документ инцидента, — пятая — безобвинительный разбор инцидента и его шаблон. Шестая часть разбирает три учебных случая в формате упражнения «колесо неудачи»: пул потоков, деградирующий диск и отравленное сообщение в очереди.
Цель лекции
Действовать при отказе по методу: восстановить работу, найти причину проверяемыми гипотезами и извлечь урок
Распределённая система отказывает частично, а часы её машин расходятся. Метод «гипотеза — проверка — вывод», вопросы к работающему процессу без перезапуска, явные роли участников и безобвинительный разбор позволяют сократить простой и не допустить повторения отказа.
Изложение. Цель лекции состоит в том, чтобы при отказе действовать по методу, а не наугад. Отказ распределённой системы редко бывает полным: один экземпляр отвечает медленно, одна зона недоступна, одна реплика базы отстала, а часы машин расходятся настолько, что сортировка журналов по времени переставляет причину и следствие. Перебор случайных действий — перезапусков, увеличения пулов, смены параметров — в таких условиях лишь добавляет изменений, которые потом приходится отличать от исходной причины. Метод опирается на три умения. Первое — знать, что спросить у системы и у отдельного процесса: какая часть отвечает ошибками, что менялось последним, где процесс тратит процессорное время, чего он ждёт и что удерживает его память. Второе — восстановить работу раньше, чем найдена причина: откатить выпуск, вывести зону из балансировки, отключить функцию. Третье — извлекать из каждого инцидента уроки для системы, а не для людей, и отрабатывать порядок действий на учениях до настоящего отказа. Таким образом, лекция переходит от вопроса о том, что наблюдать, рассмотренного в лекции 19, к вопросу о том, что делать с наблюдаемым.
Пять вопросов
при отказе
Вопрос Чем отвечают Часть
Что видит пользователь? оповещение по симптому, сообщение пользователя 1, 6
Где отказ? графики по зонам и экземплярам, запрос к каждому уровню 2
С какого момента? хронология по журналам, трассам и графикам 1
Что менялось последним? выкатка, конфигурация, нагрузка; git bisect 2
Кто нужен? командир, исполнители, коммуникации 4
Пояснение
Ответы записываются в документ инцидента по мере получения: они нужны и сменщику, и разбору.
Для физика
Те же вопросы задаёт начальник смены установки: что не работает, на каком участке, с какого момента, что меняли.
Изложение. Пять вопросов задают порядок первых действий при любом отказе и одновременно служат картой лекции. Первый вопрос — что видит пользователь: ошибки, задержку, устаревшие данные. Ответ дают оповещение по симптому или сообщение пользователя, и именно симптом определяет срочность. Второй — где отказ: какой компонент, какая зона, какой экземпляр; графики, разбитые по зонам и экземплярам, и запрос к каждому уровню системы позволяют сузить поиск быстрее любого другого приёма. Третий — с какого момента: хронологию собирают по журналам, трассам и графикам, и первая часть покажет, почему меток времени разных машин для этого недостаточно. Четвёртый — что менялось последним: выкатка, конфигурация, характер нагрузки; большинство отказов вызвано изменениями, и вторая часть рассматривает поиск изменения делением пополам. Пятый — кто нужен: отказ, который не устраняется одним человеком, требует распределения ролей, рассмотренного в четвёртой части. Отметим, что ответы на эти вопросы записываются по мере получения: документ инцидента позволяет сменщику продолжить работу без повторных проверок и служит основой последующего разбора.
Отказы
Частичные отказы, расхождение часов и заблуждения о сети
01
Отказы
Метод
Инструменты
Инцидент
Постмортем
Колесо неудачи
Изложение. Первая часть рассматривает, чем отказ распределённой системы отличается от отказа одной программы: отказы частичны, общего состояния нет, а часы машин расходятся. Первая демонстрация показывает, как смещение часов переставляет события инцидента, вторая — как запрос без тайм-аута останавливает пул потоков клиента.
Частичные отказы
и разные часы
01
Много экземпляров
отказывают по отдельности, не все сразу
02
Нет общего состояния
картину собирают из журналов и метрик разных машин
03
Часы расходятся
NTP: десятки мс через интернет, доли мс в локальной сети
04
Порядок событий
по идентификатору запроса и связям спанов
метка в журнале = время + смещение часов gw смещение 0.000 с archive смещение -1.500 с # отстают db смещение +0.012 с # спешат
Важно
Записи разных машин, разделённые миллисекундами, по меткам времени не упорядочить.
Для физика
Синхронизация ускорителя, например White Rabbit, даёт доли наносекунды; серверы архива обычно синхронизированы по NTP.
Изложение. Программа на одной машине либо работает, либо нет. Распределённая система, то есть система из многих процессов на разных машинах, обменивающихся сообщениями ради общей цели, отказывает частично: один экземпляр службы отвечает медленно, одна зона недоступна, одна реплика базы отстала, а остальные части работают. Части отказывают по отдельности, хотя и не всегда независимо — общая конфигурация или перенос нагрузки с отказавшей части связывают отказы, как в первом учебном случае, — а общего состояния, которое можно было бы рассмотреть целиком, у системы нет: картину отказа собирают из журналов и метрик разных машин. Сборку осложняют часы. Протокол NTP обычно поддерживает время машин с точностью порядка десятков миллисекунд при синхронизации через интернет и лучше миллисекунды в локальной сети при благоприятных условиях, а асимметричные маршруты и перегрузка сети дают ошибку в 100 мс и более; протокол PTP (IEEE 1588) с аппаратными метками времени обеспечивает в локальной сети точность лучше микросекунды, а основанная на нём система синхронизации ускорителей White Rabbit — доли наносекунды. Машина с неисправной синхронизацией может разойтись с остальными на секунды. Следовательно, записи разных машин, разделённые миллисекундами, по меткам времени упорядочить нельзя, а при неисправной синхронизации нельзя упорядочить и события, разделённые секундами. Чтобы сравнивать метки разных машин, необходимо знать смещение их часов; его показывают команды chronyc tracking (служба chrony) и timedatectl timesync-status (служба systemd-timesyncd). Надёжный порядок дают не часы, а причинные связи: идентификатор запроса, который передаётся от службы к службе, и связи «родитель — потомок» между спанами трассировки, рассмотренные в лекции 19. Рассмотрим, как смещение часов проявляется на одном запросе.
Демонстрация:
хронология
01
Запрос rid=7f3a: шлюз, архив, база — шесть событий
02
Часы архива отстают на 1,5 с, базы спешат на 12 мс
03
Сортировка по меткам журналов и с поправкой
04
Порядок по связям спанов, без часов
Что наблюдается
По меткам архив обращается к базе за 1,496 с до запроса, а ответ 500 оказывается раньше ошибки базы; с поправкой и по спанам — gw → archive → db → db → archive → gw.
root@lab — запись со стенда
Демонстрация. Сценарий timeline.py моделирует запрос rid=7f3a, который проходит шлюз gw, архив и базу метаданных db. Настоящий ход событий таков: база не дождалась блокировки и через секунду ответила ошибкой, архив передал ошибку дальше ответом 500, шлюз вернул 500 пользователю. Часы архива отстают на 1,5 с, часы базы спешат на 12 мс. При сортировке по меткам журналов первыми оказываются записи архива: запрос метаданных с меткой −1,496 с и ошибка базы с ответом 500 с меткой −0,487 с, то есть раньше прихода запроса на шлюз в 0,000 с. Причиной отказа кажется архив, обратившийся к базе до запроса. Небольшое смещение часов базы даёт вторую перестановку: ответ 500 пользователю с меткой 1,016 с оказывается раньше сообщения базы lock timeout с меткой 1,022 с, хотя на самом деле база ответила ошибкой на 6 мс раньше шлюза. Вторая таблица вычитает из меток смещение часов каждой машины и восстанавливает настоящий порядок: шлюз в 0,000 с, архив в 0,004 с, база в 0,010 с, превышение времени ожидания блокировки в 1,010 с, ошибка архива в 1,013 с и ответ шлюза в 1,016 с. Последняя строка упорядочивает события по связям спанов, не используя часов вовсе: gw → archive → db → db → archive → gw. Таким образом, причиной отказа является блокировка в базе, а архив и шлюз лишь передали ошибку дальше. Поправка на смещение требует знать смещение каждой машины в момент события, тогда как связи спанов и идентификатор запроса от часов не зависят и позволяют упорядочить события без них; поэтому хронологию инцидента строят по ним.
Заблуждения
о сети
Заблуждение След в коде или в эксплуатации
сеть надёжна запрос без тайм-аута, исчерпанный пул соединений
задержка нулевая сотни последовательных запросов вместо одного
полоса бесконечна передача файла целиком ради его метаданных
сеть безопасна служба без аутентификации «за межсетевым экраном»
топология неизменна адрес службы в программе без учёта TTL записи DNS
администратор один работы на сети сужают полосу без предупреждения
передача бесплатна трафик между зонами оплачивается, сериализация занимает процессор
сеть однородна разные версии протоколов и оборудования на пути
Первые семь сформулировал П. Дойч (Sun Microsystems, 1994), восьмое добавил Дж. Гослинг (около 1997)
Изложение. Многие ошибки проектирования распределённых систем сводятся к восьми заблуждениям о сети. Первые семь сформулировал П. Дойч в Sun Microsystems в 1994 году, восьмое около 1997 года добавил Дж. Гослинг. Каждое заблуждение оставляет след в коде, который на стенде работает, а в эксплуатации отказывает. Заблуждение «сеть надёжна» порождает запросы без тайм-аута: потерянный ответ заставляет клиента ждать бесконечно, пул соединений исчерпывается и не освобождается, и работу восстанавливает лишь перезапуск приложения; демонстрация после этого слайда воспроизводит такой отказ. Заблуждения «задержка нулевая» и «полоса бесконечна» проявляются в сотнях последовательных запросов там, где достаточно одного, и в передаче целого файла ради изменения его метаданных; договорённость о полосе между площадками перестаёт действовать, когда на сети начинаются работы, о которых служба не знает, — это уже заблуждение «администратор один». Заблуждение «сеть безопасна» порождает службы без аутентификации и авторизации в расчёте на межсетевой экран: после изменения его правил такая служба принимает запросы, в том числе на удаление данных, от любой программы в сети. Заблуждение «топология не меняется» проявляется в адресе службы, сохранённом в программе без учёта времени жизни записи DNS: после перестроения кластера тот же адрес может получить другая служба, и запросы начнут получать её ответы. Таким образом, тайм-аут на каждый сетевой вызов, аутентификация между службами, передача только нужных данных и повторное разрешение имён являются не улучшениями, а условиями работы распределённой системы.
Демонстрация:
пул без тайм-аута
01
Архив на 127.0.0.1:8501: ответ за 50 мс
02
Запуск 13: ответ через 3 с — модель зависшей базы
03
Пул из 4 потоков: 12 запросов, 4 из них к запуску 13
04
Без тайм-аута и с тайм-аутом 0,5 с
Что наблюдается
Без тайм-аута за первую секунду завершено 4 из 12 запросов, все — за 3,2 с; с тайм-аутом 0,5 с — 12 из 12: 8 успешно и 4 с ошибкой, всё за 0,7 с.
root@lab — запись со стенда
Демонстрация. Сценарий pool.py запускает в одном процессе модель службы архива на 127.0.0.1:8501: обычный запрос она обслуживает за 50 мс, а запросы к запуску 13 — за 3 с, как служба, которая ждёт недоступную базу. Клиент отправляет 12 запросов через пул из четырёх потоков, и четыре из них — второй, четвёртый, шестой и восьмой — обращаются к запуску 13. Первый прогон выполняется без тайм-аута: за первую секунду завершены лишь 4 запроса из 12, все успешно, а обработка всех двенадцати занимает 3,2 с. Причина в том, что четыре медленных запроса заняли все четыре потока пула, и быстрые запросы, поставленные в очередь после них, ждут 3 с, хотя сами обслуживаются за 50 мс. Во втором прогоне каждый запрос ограничен тайм-аутом 0,5 с: за первую секунду завершены все 12, из них 8 успешно и 4 — ошибкой тайм-аута, и прогон занимает 0,7 с. В службе, которая обращается к архиву по запросам пользователей, первый вариант означает, что отказ одной зависимости останавливает обслуживание всех пользователей; второй позволяет превратить зависание в быструю ошибку, которую можно обработать: повторить запрос с паузой, вернуть частичный ответ, сообщить пользователю. Отметим, что функция urllib.request.urlopen, как и библиотека requests, по умолчанию ждёт ответа без ограничения, поэтому тайм-аут необходимо задавать явно в каждом сетевом вызове. Согласование тайм-аутов по цепочке служб и повторы с бюджетом рассмотрены в лекции 14, на слайдах «Тайм-ауты и дедлайн» и «Повторы с бюджетом».
Метод
Знание системы, гипотеза и проверка, ловушки рассуждения, последнее изменение, деление пополам
02
Отказы
Метод
Инструменты
Инцидент
Постмортем
Колесо неудачи
Изложение. Вторая часть посвящена методу поиска. Рассматриваются подготовка к отказу — знание устройства системы и её нормального поведения, — цикл «гипотеза — проверка — вывод», типичные ошибки рассуждения, поиск последнего изменения, в том числе делением пополам с помощью git bisect, и проверка системы по уровням сверху вниз.
Знание
системы
база данных
ведущая и две реплики
01
Схема
все части и интерфейсы между ними
02
Норма
графики «как обычно» для каждой части
03
Гипотезы отказов
что увидит пользователь при отказе реплики
04
Учения
проверка гипотез на стенде, пока отказа нет
Для физика
Перед сеансом установки известно, какие показания нормальны и как выглядит отказ каждого узла.
Изложение. Неисправность в системе, устройство которой неизвестно, приходится искать перебором, поэтому подготовка к отказу начинается задолго до него. Первым её элементом является схема системы, на которой показаны все части и интерфейсы между ними. Служба, которая на схеме разработчика выглядит одним прямоугольником, в эксплуатации представляет собой цепочку: запросы пользователей принимает балансировщик уровня L4, распределяющий соединения TCP, за ним — балансировщик уровня L7, распределяющий запросы HTTP, причём оба сами являются кластерами. Экземпляры службы работают в трёх зонах доступности, а база данных — на трёх машинах: ведущая и две реплики. Каждая стрелка схемы является местом возможного отказа и интерфейсом, который можно проверить отдельно. Второй элемент — нормальное поведение: графики «как обычно» позволяют сразу заметить, что изменилось. Третий — гипотезы отказов, полученные мысленным экспериментом: что увидит пользователь, если откажет реплика базы, какие метрики при этом изменятся, ответит ли балансировщик ошибкой 500. Каждую такую гипотезу необходимо проверить на стенде или, если архитектура это допускает, на учениях в рабочей системе, пока отказа нет. Для физика это знакомая практика: перед сеансом установки известно, какие показания нормальны и как выглядит отказ каждого узла, а схема установки с интерфейсами между подсистемами висит на пульте.
Гипотеза → проверка →
вывод
отчёт
ожидаемое и фактическое
сортировка
восстановить или искать
исследование
метрики, журналы, трассы
диагностика
гипотеза о причине
проверка
подтвердить или отвергнуть
повтор, пока гипотеза не подтверждена; затем устранение
гипотеза: обработка медленная из-за диска проверка: time python3 slow.py ожидание: user заметно меньше real результат: user ≈ real — гипотеза отвергнута
01
Метод
из гипотезы — следствие, следствие — в опыт
02
До проверки
инструмент и ожидаемый результат
03
Отрицательный результат
тоже результат: поиск сужается
Изложение. Книга Google SRE описывает поиск неисправности как цикл. Он начинается с отчёта о проблеме — оповещения или сообщения пользователя, в котором указаны ожидаемое и фактическое поведение. Сортировка (triage) оценивает серьёзность и решает, что делать в первую очередь: восстанавливать работу или искать причину. Исследование собирает сведения о состоянии системы по метрикам, журналам и трассировкам. Диагностика выдвигает гипотезу о причине, а проверка подтверждает или опровергает её; цикл повторяется, пока причина не найдена, после чего наступает этап устранения. По существу это гипотетико-дедуктивный метод, знакомый каждому экспериментатору: из наблюдений выводится гипотеза, из гипотезы — проверяемое следствие, а опыт либо подтверждает следствие, либо отвергает гипотезу. Гипотезу необходимо формулировать вместе со способом проверки и ожидаемым результатом, как в примере на слайде: если обработка замедлилась из-за диска, то процессорное время программы заметно меньше реального, и это покажет команда time. Без ожидаемого результата любое вмешательство — перезапуск, увеличение пула, смена параметра — превращается в попытку наугад, исход которой ничего не доказывает; первый учебный случай шестой части содержит именно такой шаг. Отрицательный результат проверки также является результатом: опровергнутая гипотеза сужает область поиска. Каждая гипотеза и результат её проверки записываются в документ инцидента, чтобы ни дежурный, ни его сменщик не проверяли одно и то же дважды.
Ловушки
рассуждения
01
Несущественные симптомы
необычный график не обязательно связан с отказом
02
Негодная проверка
изменение, которое опасно или ничего не доказывает
03
Невероятные теории
и привязка к причине прошлого отказа
04
Ложные корреляции
совпадение во времени, общая третья причина
05
Два вмешательства
нельзя установить, какое подействовало
06
Без записей
те же гипотезы проверяются повторно
Пояснение
Те же ловушки применительно к графикам дашбордов рассмотрены в лекции 19 на слайде «Ловушки восприятия».
Изложение. Книга Google SRE перечисляет типичные ошибки рассуждения, замедляющие поиск. Первая — внимание к несущественным симптомам и неверное понимание смысла метрик: график, выглядящий необычно, не обязательно связан с отказом, и его исследование уводит в сторону. Вторая — непонимание того, как изменить систему, её входные данные или окружение, чтобы проверка была безопасной и действительно что-то доказывала. Третья — невероятные теории и привязка к причинам прошлых отказов: однажды случившееся вспоминается первым, но повторяется не всегда. Четвёртая — поиск ложных корреляций: совпадение двух событий во времени ещё не означает причинной связи, и оба события могут быть следствиями третьего. К перечню книги добавляется пятая ошибка — одновременные вмешательства: если два человека одновременно меняют систему или один меняет два параметра сразу, установить, какое изменение подействовало, нельзя, и наблюдаемый результат представляет собой интерференцию двух вмешательств. Шестая карточка напоминает, что без записей те же гипотезы проверяются повторно, особенно при смене дежурных. Те же ловушки применительно к графикам дашбордов рассмотрены в лекции 19 на слайде «Ловушки восприятия». Для экспериментатора они знакомы: правило «менять один параметр за раз» выработано физикой задолго до эксплуатации программ.
Последнее
изменение
01
Инерция
система работает, пока её не изменят: выпуск, конфигурация, нагрузка
02
Около 70 % отказов
вызваны изменениями в работающей системе
03
Первое действие
откат последнего изменения
04
Много изменений
деление пополам: около log₂ N проверок
git bisect start ПЛОХАЯ ХОРОШАЯ git bisect run ./check.sh # код 0 — версия исправна # 1…127, кроме 125, — неисправна # 125 — пропустить версию git bisect reset
Для физика
Журнал изменений установки — уставки, прошивки, версии программ — служит тем же списком кандидатов.
Изложение. Работающая система обладает инерцией: она продолжает работать, пока на неё не подействует внешнее изменение — новая версия программы, изменённая конфигурация, иной характер нагрузки. По оценке книги Google SRE, около 70 % отказов вызваны изменениями в работающей системе. Отсюда два следствия. Первое действие при отказе, последовавшем за выкаткой, — откат: он восстанавливает работу, не дожидаясь понимания причины, а причину затем ищут без спешки. Если же последнее изменение неизвестно или изменений много, виновное находят делением пополам. Команда git bisect получает заведомо неисправную и заведомо исправную версии, переключает рабочую копию на середину интервала и после каждой проверки отбрасывает половину кандидатов, поэтому N изменений требуют около log₂ N проверок. Команда git bisect run позволяет выполнить этот цикл автоматически: она запускает переданную программу на каждой версии и считает код возврата 0 признаком исправной версии, коды от 1 до 127, кроме 125, — признаком неисправной, а код 125 — указанием пропустить версию, которую нельзя проверить. Достаточно, следовательно, записать проверку в виде программы с кодом возврата. Отметим, что деление пополам применимо не только к истории git: тем же приёмом находят виновный пакет среди обновлённых, виновную часть конфигурации или виновный участок входных данных. Для физика списком кандидатов служит журнал изменений установки — уставки, прошивки, версии программ.
Демонстрация:
git bisect
01
mkrepo.sh: 32 выпуска конфигурации reco.toml
02
check_config.py: workers от 1 до 64, код 0 или 1
03
git bisect start: 1.32 неисправен, 1.1 исправен
04
git bisect run и последние 11 строк вывода
Что наблюдается
Последний выпуск отклонён: workers = 4000, код 1; осталось 15 версий, около 4 шагов; первый неисправный коммит — 641fd25 «Better», найден за 5 запусков проверки вместо 30.
root@lab — запись со стенда
Демонстрация. Скрипт mkrepo.sh создаёт репозиторий конфигурации службы реконструкции событий: 32 выпуска файла reco.toml с фиксированными датами коммитов, поэтому хеши одинаковы при каждом запуске, и последний коммит всегда 00f1569 «Release 1.32». В выпуске 1.19 коммит с сообщением «Better» по ошибке изменил число рабочих потоков с 40 на 4000. Скрипт check_config.py, лежащий уровнем выше, проверяет число потоков: служба выполняет вычисления на 16-ядерных машинах, и больше четырёх потоков на ядро, то есть больше 64, считается ошибкой. На последнем выпуске он печатает «workers = 4000, допустимо 1…64 — конфигурация отклонена» и возвращает код 1; для команды git bisect run такого кода достаточно. Команда git bisect start HEAD HEAD~31 объявляет текущую версию неисправной, а первую — исправной; git переключает рабочую копию на выпуск 1.16 и сообщает, что после его проверки останется 15 версий, примерно на 4 шага. Команда git bisect run python3 ../check_config.py выполняет весь поиск сама, а последние 11 строк её вывода показывают последнюю проверку и результат: первым неисправным является коммит 641fd25 с сообщением «Better», изменивший две строки файла reco.toml. Всего проверка запускается пять раз — на выпусках 1.16, 1.24, 1.20, 1.18 и на коммите «Better», — тогда как перебор подряд тридцати одного кандидата, выпусков 1.2–1.32, потребовал бы в худшем случае тридцати запусков: последний выпуск заведомо неисправен и проверки не требует. Команда git bisect reset возвращает рабочую копию на ветку main. Тот же скрипт, включённый в проверку перед выкаткой, не пропустил бы ошибочную конфигурацию вовсе; к этому выводу вернёмся при разборе первого учебного случая.
Сверху вниз
и пополам
01
Части и интерфейсы
HTTP, вызов процедуры, запрос к базе, библиотека
02
Ожидаемое поведение
цель уровня обслуживания интерфейса
03
Сверху вниз или пополам
середина цепочки отбрасывает половину частей
04
По зонам и экземплярам
разбивка графиков сужает поиск быстрее всего
curl -sS -o /dev/null \ -w '%{http_code} %{time_total}\n' URL 200 0.004133 уровень работает 404 0.000965 служба работает, объекта нет 000 0.000224 соединения нет: искать ниже
Важно
ping показывает лишь ответ узла на ICMP: балансировщик, отдающий 500, на ping отвечает исправно.
Изложение. Если последнее изменение не найдено, систему делят на части с чёткими интерфейсами — HTTP, вызов удалённой процедуры, запрос к базе, вызов библиотеки — и для каждого интерфейса определяют ожидаемое поведение, например цель уровня обслуживания: долю успешных ответов и время ответа. Поиск идёт сверху вниз, от того, что видит пользователь, к компонентам, или делением пополам: проверка середины цепочки сразу отбрасывает половину частей. Для конвейера данных удобнее двигаться по потоку данных, от источника к потребителю. Каждый уровень проверяют запросом его собственного протокола. Ответ на ping показывает лишь то, что машина отвечает на пакеты ICMP: балансировщик, возвращающий ошибку 500, на ping отвечает исправно. Состояние уровня HTTP показывает запрос curl, печатающий код ответа и время: код 200 и несколько миллисекунд означают, что уровень работает; код 404 — что служба работает, но запрошенного объекта нет; код 000 с ошибкой соединения — что на порту никто не принимает соединений, и поиск продолжается уровнем ниже: запущена ли служба, слушает ли она нужный адрес. Если ошибки идут из одной зоны или с одного экземпляра, разбиение графиков по зонам и экземплярам позволяет сузить поиск быстрее любого другого приёма; оба первых учебных случая шестой части начинаются именно с него. Запросы curl с кодом ответа и временем рассматривались в лекции 2 на слайде «curl из командной строки».
Вопросы
к процессу
Симптом Гипотеза Инструмент
медленная работа при занятом процессоре алгоритм, лишняя работа time, cProfile, py-spy , perf
зависание при свободном процессоре блокировка, ожидание сети или диска faulthandler, py-spy dump, /proc/PID/wchan, strace
рост памяти удержание объектов ссылками tracemalloc, VmRSS в /proc/PID/status
отказ при запуске конфигурация, окружение, права код возврата, systemctl, journalctl
Пояснение
Перезапуск уничтожает состояние, которое исследуется: сначала вопросы к работающему процессу.
Для физика
Расчёт, зависший на третьи сутки, исследуют теми же средствами: стеки, /proc, strace.
Изложение. Инструмент выбирают по симптому, а симптом формулируют двумя наблюдениями: что происходит с работой и что происходит с ресурсами. Если обработка медленная, а процессор занят, вероятные гипотезы — неудачный алгоритм или лишняя работа; проверкой служат команда time, сравнивающая процессорное и реальное время, детерминированный профилировщик cProfile и сэмплирующие профилировщики py-spy и perf. Если процесс не отвечает, а процессор свободен, он чего-то ждёт: блокировки, сети или диска; проверкой служат стеки потоков, которые печатают модуль faulthandler и команда py-spy dump, и сведения ядра о том, где процесс спит, — файлы /proc/PID/wchan и /proc/PID/syscall и трассировщик strace. Если растёт память, гипотеза состоит в том, что объекты удерживаются ссылками, например кешем без ограничения размера; проверкой служат снимки tracemalloc и строка VmRSS файла /proc/PID/status. Если служба не запускается, причину обычно сообщает она сама — кодом возврата и последними строками журнала, которые выводят systemctl и journalctl. Во всех случаях предпочтительны инструменты, не требующие перезапуска: перезапуск уничтожает именно то состояние процесса, которое необходимо исследовать. Для других языков набор аналогичен: для C++ — perf, gdb и профилировщик gperftools, для Go — встроенный pprof, для Java — VisualVM, для Node.js — профилировщик V8. В лекции используются инструменты Python и Linux, а профилировщики как средство ускорения расчётов рассматривались в лекции 9.
Демонстрация:
медленный скрипт
01
Гипотеза 1, медленный диск: time
02
Гипотеза 2, алгоритм: cProfile по tottime
03
Исправление: множество вместо списка
Что наблюдается
user 0,903 с при real 0,916 с — программа вычисляет, а не ждёт; профиль: 0,868 с из 0,891 — в dedup_slow; с множеством — 0,006 с.
root@lab — запись со стенда
Демонстрация. Сценарий slow.py моделирует ночную обработку, которая склеивает события двух файлов детектора и выбрасывает повторы по номеру события; по жалобам обработка стала заметно медленнее. Первая гипотеза — медленный диск. Если программа ждёт ввода-вывода, её процессорное время заметно меньше реального, и проверку выполняет команда time. На стенде реальное время составляет 0,916 с, время в пользовательском режиме — 0,903 с, в режиме ядра — 0,012 с: процессор занят всё время работы, программа вычисляет, а не ждёт, и гипотеза о диске отвергнута. Вторая гипотеза — неудачный алгоритм; профиль cProfile, отсортированный по собственному времени функций (tottime), показывает, где проходит время. Из 0,891 с работы 0,868 с, то есть 97 %, приходятся на функцию dedup_slow, объявленную в строке 22: для каждого из 24 000 событий она проверяет, нет ли его в списке уже встреченных, а поиск в списке требует времени, пропорционального его длине, поэтому обработка квадратична по числу событий. Отдельной функции, которую профиль мог бы назвать, у этого поиска нет: оператор in над списком выполняется кодом интерпретатора на C, и cProfile относит его время к вызывающей функции. Перенаправление 2>/dev/null убирает сообщение интерпретатора о закрытом канале, которое появляется, когда команда head завершается раньше профилировщика. Множество обеспечивает проверку принадлежности за время, в среднем не зависящее от его размера, и с функцией dedup_fast та же обработка, включая получение 24 000 событий, занимает 0,006 с — примерно в 150 раз меньше — с тем же результатом: 18 822 уникальных события; сценарий отсчитывает время от начала программы, поэтому в эти 6 мс входит и получение событий. Две гипотезы проверены двумя командами, и каждая проверка имела заранее известный ожидаемый результат.
py-spy и perf:
профиль снаружи
py-spy top --pid PID # функции, как в toppy-spy dump --pid PID # стеки всех потоковpy-spy record -o p.svg --pid PID python3 -m sysconfig | grep PERF_TRAMPOLINE python3 -X perf app.py # или PYTHONPERFSUPPORT=1 perf record -g -p PID perf report --stdio
01
py-spy
стеки из памяти процесса, без перезапуска и правки кода
02
Права
root или разрешение ptrace, в контейнере — SYS_PTRACE
03
perf
функции Python — с версии 3.12 при -X perf
04
Python 3.15
встроенный profiling.sampling, PEP 799
Важно
Без поддержки в интерпретаторе perf видит только функции на C, но не функции Python.
Изложение. Службу, которую нельзя перезапустить под профилировщиком, профилируют снаружи. Сэмплирующий профилировщик py-spy читает стеки интерпретатора из памяти работающего процесса, не останавливая его и не требуя изменения кода. Команда py-spy top --pid показывает функции, в которых процесс проводит время, в виде постоянно обновляемой таблицы, py-spy record записывает выборки стека в файл flame graph, а py-spy dump --pid печатает текущие стеки всех потоков — это основной способ увидеть, в каком месте ожидает зависший процесс. Для подключения достаточно номера процесса, но к уже работающему процессу в Linux py-spy обычно подключается только с правами root или при ослабленном ограничении ptrace (параметр ядра kernel.yama.ptrace_scope), а в контейнере, кроме того, с возможностью SYS_PTRACE; процесс, запущенный самим py-spy командой вида py-spy record -- python3 app.py, профилируется и без них. Системный профилировщик perf видит функции машинного кода, и для программы на Python без дополнительной поддержки он покажет лишь функции на C — интерпретатора, выполняющего байт-код, расширений и библиотек, — но не функции Python. Начиная с версии 3.12 интерпретатор умеет сообщать perf имена функций Python через так называемые трамплины, однако по умолчанию эта поддержка выключена: её включают ключом -X perf, переменной окружения PYTHONPERFSUPPORT=1 или вызовом sys.activate_stack_trampoline("perf"). Поддержка доступна только в Linux и не для всех архитектур, а её наличие показывает переменная HAVE_PERF_TRAMPOLINE в выводе python3 -m sysconfig. В Python 3.15 появляется встроенный сэмплирующий профилировщик profiling.sampling (PEP 799), способный подключаться к работающему процессу. Отметим, что py-spy применялся в лекции 9 для ускорения расчётов; здесь он служит инструментом диагностики службы.
Демонстрация:
py-spy снаружи
01
py-spy dump: стек slow.py через 0,3 с после запуска
02
py-spy record: 200 выборок в секунду, flame graph
03
perf record: python3 с ключом -X perf
04
perf report: строки py:: с функциями Python
Что наблюдается
dump: dedup_slow, строка 25 — проверка e not in seen; record: 171 выборка без ошибок, файл slow.svg; perf: py::dedup_slow и py::<module>.
root@lab — запись со стенда
Демонстрация. Демонстрация повторяет профиль slow.py снаружи, без cProfile и без изменения кода. Первая команда запускает обработку в фоне, через 0,3 с вызывает py-spy dump с номером фонового процесса $!, а команда wait дожидается завершения обработки, поэтому её итоговая строка, 0,893 с, и сообщение Done выводятся в том же шаге. Вывод содержит версию интерпретатора и стек единственного потока с пометкой active+gil — поток выполняется и удерживает глобальную блокировку интерпретатора: функция dedup_slow, строка 25, вызвана из модуля в строке 42. Строка 25 — проверка e not in seen, то есть py-spy указывает не только функцию, но и строку, на которой проходит время. Вторая команда py-spy record запускает обработку заново под профилировщиком с частотой 200 выборок в секунду и записывает flame graph в файл slow.svg; для работающей службы вместо команды после -- указывается ключ --pid. За 0,89 с работы снята 171 выборка без ошибок; в flame graph вошли 170 из них, и все 170 приходятся на ту же строку 25. Третья команда запускает обработку под perf record с ключом -X perf, включающим трамплины perf в интерпретаторе, а четвёртая выбирает из отчёта perf report первые пять строк с префиксом py::. Они содержат функции Python с именем файла — py::dedup_slow и py::<module> из /tmp/l20rec/slow.py, — то есть perf видит функции Python в одном профиле с функциями интерпретатора и ядра. Поддержка трамплинов в Python 3.12 из пакетов Ubuntu собрана, что и подтверждают эти строки. Профиль работающего процесса, следовательно, снимается без его перезапуска и без правки кода.
Демонстрация:
взаимная блокировка
01
deadlock.py в фоне, через 1 с — сигнал USR1
02
Стеки faulthandler в файле stacks.txt
03
py-spy dump: имена потоков и их состояние
04
Исправление: единый порядок захвата
Что наблюдается
archiver ждёт в строке 30, calibrator — в строке 39, главный поток — в join, строка 48; все три idle. С единым порядком — «обе задачи завершены».
root@lab — запись со стенда
Демонстрация. Сценарий deadlock.py моделирует службу, которая перестала отвечать, не загружая процессор. Поток archiver берёт блокировку журнала запусков, а затем блокировку калибровок, поток calibrator — те же блокировки в обратном порядке; через несколько итераций каждый удерживает блокировку, которую ждёт другой. Гипотеза — взаимная блокировка; проверкой служат стеки всех потоков. Обработчик faulthandler необходимо зарегистрировать заранее, поэтому при запуске сценарий вызывает faulthandler.register(signal.SIGUSR1, all_threads=True): по сигналу SIGUSR1 обработчик печатает стеки всех потоков в поток ошибок. Кроме того, сценарий заводит сторожевой таймер signal.alarm(30), завершающий процесс через 30 с. Первая команда запускает сценарий в фоне с потоком ошибок в файле stacks.txt и через секунду посылает сигнал. Вторая выбирает из файла строки, относящиеся к deadlock.py, вместе с предшествующими: один поток ожидает в строке 39 функции calibrator — захвате второй блокировки, — другой в строке 30 функции archiver — захвате блокировки калибровок, а главный поток находится в строке 48, в вызове join, ожидая завершения обоих. Потоки faulthandler обозначает адресами, а не именами. Третья команда, py-spy dump, показывает те же стеки снаружи, без заранее зарегистрированного обработчика, причём с именами потоков MainThread, archiver и calibrator, их номерами в системе и пометкой idle: ни один поток не выполняется. Гипотеза подтверждена: потоки захватывают две блокировки в разном порядке. Исправленный вариант fixed берёт блокировки в одном порядке во всех потоках и печатает «обе задачи завершены»; сообщение Terminated относится к зависшему процессу, остановленному командой kill. Отметим, что захват с тайм-аутом, lock.acquire(timeout=…), ошибку не устраняет, но превращает зависание в обнаружимую ошибку, а функция faulthandler.dump_traceback_later позволяет устроить сторожевой таймер, печатающий стеки, если операция не завершилась за заданное время.
Демонстрация:
утечка памяти
01
Служба графиков: кеш-словарь без ограничения
02
tracemalloc: снимок, 8000 запросов, второй снимок
03
compare_to по стекам глубиной 3
04
Исправление: lru_cache(maxsize=1024)
Что наблюдается
6,9 → 10,3 → 13,7 → 17,0 МиБ; прирост +12,6 МиБ в 412 100 блоках: render, строка 23 ← кеш, строка 29. С lru_cache — 1,9 МиБ во всех раундах.
root@lab — запись со стенда
Демонстрация. Сценарий leak.py моделирует службу выдачи графиков, память которой растёт с каждым часом работы. Служба кеширует построенные графики в словаре по ключу «запуск, канал, окно» и ничего из кеша не удаляет, а различных ключей неограниченно много. Гипотеза — объекты удерживаются ссылками из кода службы; проверкой служит модуль tracemalloc, запоминающий место каждого выделения памяти интерпретатором. Модуль необходимо запустить до выделений, которые требуется отследить, поэтому сценарий запускает tracemalloc с глубиной стека 3 в самом начале, обслуживает 2000 запросов и делает первый снимок, затем выполняет ещё четыре раунда по 2000 запросов и делает второй снимок, а метод compare_to с группировкой по стекам находит наибольшее изменение между снимками. Объём выделенной памяти растёт без насыщения: 6,9, 10,3, 13,7 и 17,0 МиБ, примерно по 3,4 МиБ на каждые 2000 запросов. Наибольшее изменение составляют +12,6 МиБ в 412 100 блоках — около 52 блоков на каждый из почти 8000 графиков, построенных между снимками: объект списка, массив его ссылок и 50 чисел float. Эти блоки выделены в строке 23 функции render. Цепочка вызовов показывает, при каком обращении выделены эти блоки: функцию render вызывает присваивание в словарь _cache в строке 29, а функцию plot_unbounded с этим присваиванием — функция serve в строке 38. Сам tracemalloc показывает только место выделения, но не ссылки на объект; то, что блоки удерживает кеш, видно из того, что они выделены при заполнении словаря _cache и между снимками не освобождаются. Исправленный вариант fixed заменяет словарь кешем functools.lru_cache с ограничением в 1024 записи: выделено 1,9 МиБ во всех четырёх раундах. Наибольшее изменение в этом прогоне отрицательно, −1,6 МиБ в 53 279 блоках: это графики, построенные до первого снимка, — их стек оканчивается строкой 42, вызовом serve перед снимком, — и вытесненные из кеша новыми, а метод compare_to упорядочивает изменения по абсолютной величине. Отметим, что tracemalloc учитывает только выделения интерпретатора Python: память расширений на C, выделенная без его участия, видна лишь в полном объёме памяти процесса — строке VmRSS файла /proc/PID/status.
Ожидание:
/proc и strace
grep State /proc/PID/status # S — событие, D — ввод-вывод cat /proc/PID/wchan; echo # функция ядра, где спит cat /proc/PID/syscall # номер вызова, аргументы ls -l /proc/PID/fd # файлы и сокеты ss -tnp # соединения TCP процессов strace -p PID # текущий системный вызовpy-spy dump --pid PID # строка Python
01
S и D
прерываемое ожидание события и непрерываемое — ввода-вывода
02
load average
в Linux учитывает и процессы в состоянии D
03
Лекции 2 и 3
strace, /proc, состояния процесса, состояние D
Пояснение
Рост load average при свободном процессоре указывает на непрерываемые ожидания: дисков, сетевых файловых систем, части блокировок ядра.
Изложение. Если стеки показывают, что поток ожидает завершения чтения из сокета или файла, следующий вопрос задают ядру. В Linux состояние процесса и место ожидания видны без какой-либо подготовки. Строка State файла /proc/PID/status показывает состояние: S означает прерываемое ожидание события — ответа по сети, сигнала, освобождения блокировки, — а D представляет собой непрерываемое ожидание, обычно ввода-вывода диска или сетевой файловой системы; процесс в состоянии D не реагирует на сигналы, пока ожидание не закончится, кроме ожиданий, которые ядро разрешает прервать сигналом SIGKILL, — так устроено большинство ожиданий клиента NFS. Файл wchan содержит имя функции ядра, в которой процесс спит, а файл syscall — номер выполняемого системного вызова и его аргументы. Каталог /proc/PID/fd показывает открытые файлы и сокеты, команда ss -tnp — соединения TCP с номерами процессов и дескрипторов, а strace -p — системные вызовы процесса с момента подключения, начиная с незавершённого вызова, в котором он ждёт. Строку Python, из которой сделан вызов, позволяет найти py-spy dump. Средняя загрузка (load average) в Linux учитывает не только процессы, готовые к выполнению, но и процессы в состоянии D, поэтому её рост при свободном процессоре указывает на непрерываемые ожидания — дисков, сетевых файловых систем, а также некоторых блокировок в ядре (Б. Грегг, 2017); процесс в состоянии S, ожидающий ответа по сети, её не увеличивает. Состояния процессов, файловая система /proc и strace рассматривались в лекциях 2 и 3, включая демонстрацию состояния D; здесь те же средства применяются к службе на Python.
Демонстрация:
ожидание recv
01
blocked.py в фоне: запрос отправлен, ответа нет
02
/proc: состояние, wchan, системный вызов, сокеты
03
ss -tnp: соединения с портом 8502
04
strace -p на 2 с и py-spy dump
Что наблюдается
S (sleeping), wait_woken; вызов 207 — recvfrom на дескрипторе 5, клиентском сокете к 8502; strace: recvfrom(5, без завершения; py-spy : строка 32.
root@lab — запись со стенда
Демонстрация. Сценарий blocked.py моделирует клиента, который отправил запрос архиву и ждёт ответа без тайм-аута. Архив представлен потоком того же процесса на 127.0.0.1:8502: он принимает соединение, читает запрос и 20 с не отвечает, как служба, ожидающая зависшую базу. Гипотеза — процесс ждёт ответа по сети; проверка выполняется средствами Linux без отладчика. Первая команда запускает сценарий в фоне и запоминает номер процесса в переменной P. Файл status показывает состояние S (sleeping), а wchan — функцию ядра wait_woken, в которой спит поток, ожидающий данных из сокета. Файл syscall начинается с числа 207 — номера вызова recvfrom в таблице системных вызовов arm64; следующие шесть чисел являются его аргументами — дескриптор 5, адрес буфера, длина 0x400, то есть 1024 байта, как в вызове sock.recv(1024), и три нуля, — а последние два содержат указатель стека и счётчик команд. Каталог fd содержит три сокета, 3, 4 и 5, а ss -tnp сопоставляет их с соединениями: дескриптор 5 принадлежит клиентскому концу соединения с локального порта 42790 на 127.0.0.1:8502, дескриптор 4 — концу, принятому потоком архива; слушающий сокет 3 команда ss без ключа -l не показывает. Нулевые очереди Recv-Q и Send-Q означают, что запрос доставлен и прочитан архивом, а ответных данных нет. Команда strace -p, ограниченная двумя секундами командой timeout, показывает незавершённый вызов recvfrom(5, и сообщение об отключении. Наконец, py-spy dump позволяет найти строку Python: главный поток ожидает в строке 32, data = sock.recv(1024), а поток архива — в строке 23, в вызове time.sleep. Гипотеза подтверждена: процесс ждёт ответа на дескрипторе 5 без ограничения времени. Исправление состоит в тайм-ауте на каждую сетевую операцию — методе sock.settimeout() или параметре timeout функции socket.create_connection — и в обработке его истечения; последняя команда останавливает процесс.
Демонстрация:
служба не стартует
01
svc.sh archve: юнит l20-archive с опечаткой
02
systemctl show: состояние, результат, код
03
journalctl -u: три последние строки
04
svc.sh archive и запрос /runs
Что наблюдается
ActiveState=failed, Result=exit-code , ExecMainStatus=78; в журнале — «каталог не найден» и status=78/CONFIG; с верным каталогом — два запуска.
root@lab — запись со стенда
Демонстрация. Служба архива archive_svc.py читает каталог данных из переменной окружения ARCHIVE_DIR и проверяет его при старте, а не при первом запросе: если каталога нет, она пишет в журнал понятную ошибку и завершается с кодом 78 — константой EX_CONFIG из заголовочного файла sysexits.h, обозначающей ошибку конфигурации. Обёртка svc.sh, входящая в подготовку стенда, сбрасывает прежнее состояние юнита и запускает службу командой systemd-run как временный юнит l20-archive с ARCHIVE_DIR=/tmp/l20rec/ и именем каталога из аргумента. Первая команда передаёт каталог с опечаткой, archve; systemd-run запускает юнит и сразу возвращает управление, ничего не печатая, поэтому отказ виден только по состоянию юнита. Команда systemctl show выводит три свойства: ActiveState=failed, Result=exit-code — главный процесс завершился с ненулевым кодом — и ExecMainStatus=78. Журнал юнита, выведенный journalctl без меток времени и ограниченный последней минутой, содержит строку службы «ERROR ARCHIVE_DIR=/tmp/l20rec/archve: каталог не найден, служба не запущена» и две строки systemd: главный процесс завершился с кодом 78/CONFIG — systemd знает имена кодов sysexits, — и юнит перешёл в состояние отказа. Причина названа самой службой, и её поиск занимает две команды. После запуска с правильным каталогом archive служба работает, и запрос curl к 127.0.0.1:8404/runs возвращает список из двух запусков, run0041.h5 и run0042.h5. Принцип немедленного отказа (fail fast) позволяет превратить отказ при первом запросе пользователя, часы спустя после выкатки, в отказ при запуске, который виден сразу и указывает на причину. Те же сведения в развёрнутом виде показывает systemctl status: строки Active: failed (Result: exit-code) и status=78/CONFIG.
Инцидент
Первые минуты, масштаб последствий, роли участников, документ инцидента
04
Отказы
Метод
Инструменты
Инцидент
Постмортем
Колесо неудачи
Изложение. Четвёртая часть посвящена управлению инцидентом — отказом, устранение которого требует согласованных действий нескольких человек. Метод и инструменты предыдущих частей остаются прежними, но добавляются вопросы организации: что делать в первые минуты, как оценить масштаб последствий, кто принимает решения, кто сообщает о ходе работ и где записываются действия.
Первые минуты:
восстановление
01
Спокойные действия
поспешные решения в тревоге порождают новые ошибки
02
Сначала работа системы
причина — потом: поиск может занять часы
03
Откат
первое действие после выкатки
04
Необратимое
удаление данных — только после создания копии
горячая фаза
восстановить работу, снять последствия
холодная фаза
найти причину, исправить, разобрать
Важно
Откат невозможен, если выпуск необратимо изменил данные: схему базы меняют в два этапа — расширение, совместимое с обеими версиями, затем удаление старого.
Изложение. Первое побуждение при крупном отказе — сразу начать искать причину. Книга Google SRE рекомендует этому побуждению не следовать и сначала восстановить работу системы настолько, насколько это возможно в сложившихся обстоятельствах: перевести запросы с отказавшего кластера на исправные, сбросить часть нагрузки, чтобы не допустить каскадного отказа, или отключить отдельные подсистемы. Поиск причины может занять часы, а пользователи всё это время остаются без обслуживания; кроме того, поспешные решения, принятые в тревоге, порождают новые ошибки и новые изменения, которые затем приходится отличать от исходной причины. Восстановление, как отмечает та же книга, не отменяет сохранения свидетельств: журналы и стеки потоков снимают до перезапуска, иначе причину придётся устанавливать по памяти участников. Поэтому инцидент удобно разделить на две фазы. В горячей фазе восстанавливают работу и снимают последствия, не заботясь о красоте решения; в холодной находят причину, исправляют её и разбирают инцидент. Если отказ последовал за выкаткой, первым действием является откат: для него достаточно самого факта выкатки, понимание причины не требуется, и лучше, если его выполняет автоматика или дежурный без долгих колебаний. Откат невозможен, если новая версия необратимо изменила данные, например схему базы. Поэтому изменения схемы проводят в два этапа: сначала расширение, совместимое и со старой, и с новой версиями программы, а после выкатки — удаление старого; этот шаблон называют расширением и сужением (expand/contract), и он обеспечивает безопасный откат программы. Необратимые действия во время инцидента требуют осторожности: данные удаляют только после создания копии, а внешние побочные эффекты — письма, команды оборудованию — отменить нельзя, поэтому там, где откат невозможен, его заменяют исправлением вперёд.
Масштаб
последствий
01
Кто затронут
сколько пользователей, какие функции
02
Где
все зоны или одна, все экземпляры или часть
03
Ранжирование
последствия задают срочность и необходимость разбора
Для физика
На установке аналог — перевести участок в безопасное состояние и продолжить сеанс на остальных.
Мера Что снимает Цена
откат выпуска отказ после выкатки новые функции недоступны
вывод зоны отказ одной зоны ёмкость меньше на треть
отключение функции отказ одной функции функция недоступна
переключение площадки отказ площадки задержка, холодные кеши
новые экземпляры перегрузка время запуска, стоимость
Изложение. Вторым вопросом после восстановления является масштаб: сколько пользователей и какие функции затронуты, все ли зоны отказали или одна, отказала ли функция целиком или работает медленнее обычного. Масштаб определяет срочность: отказ выдачи данных во время сеанса установки и задержка ночного отчёта требуют разной реакции. Он же подсказывает меры, которые снимают последствия до того, как найдена причина. Отказ одной зоны снимается выводом её из балансировки, если оставшиеся зоны выдерживают нагрузку; отказ функции — её отключением, если остальная система от неё не зависит; отказ площадки — переключением запросов на резервную ценой большей задержки и холодных кешей; перегрузка — добавлением экземпляров. Каждая мера имеет цену, и таблица позволяет сравнить её с ценой отказа. Отметим, что вывод зоны из балансировки снимает последствия, но не заканчивает инцидент: причина остаётся, а нагрузка выведенной зоны переходит на остальные. В первом учебном случае шестой части именно этот перенос нагрузки вызвал отказ и в двух других зонах. Последствия, оценённые числом пользователей, потерянными данными или деньгами, позволяют также ранжировать инциденты: при ограниченных силах команда исправляет то, что важнее, а разбор обязателен для инцидентов с последствиями выше установленного порога.
Роли
при инциденте
01
Командир
общая картина, решения, задачи, документ; командование передаётся явно
02
Операционная работа
изменения в системе вносит только эта группа
03
Коммуникации
регулярные сообщения участникам и заинтересованным лицам
04
Планирование
заявки, смена дежурных, учёт отклонений системы
Пояснение
Инцидент объявляют, если нужна вторая команда, отказ виден пользователям или не решён за час анализа.
Важно
В группе из трёх человек роли совмещаются явно: известно, кто решает и кто сообщает.
Изложение. Один человек не может одновременно искать причину, принимать решения, отвечать на вопросы пользователей и вести записи. Книга Google SRE выделяет при инциденте четыре роли. Командир инцидента владеет общей картиной, принимает решения, распределяет задачи и ведёт документ инцидента; роли, которые он никому не передал, исполняет сам. Обычно командиром становится дежурный, получивший оповещение. Полномочия командира делегирует организация, и на время инцидента его решения — отключить часть функций, поручить обходное решение вместо долгого исправления — исполняются без обсуждения; командование передаётся явно, с подтверждением принявшего. Операционная работа представляет собой изменения в системе, и во время инцидента систему изменяет только эта группа: так исключаются одновременные вмешательства, о которых шла речь во второй части. Коммуникации обеспечивают регулярные сообщения о ходе работ участникам и заинтересованным лицам — в книге обычно по электронной почте, — а при отказе, заметном пользователям, и самим пользователям, например на странице состояния; отказ не замалчивают, даже если он затянулся. Эта же роль может поддерживать документ инцидента в актуальном состоянии. Планирование поддерживает остальных: заводит заявки на последующие задачи, организует смену дежурных и учитывает, чем система отклонилась от обычного состояния, чтобы после инцидента вернуть её обратно. Объявлять инцидент та же книга рекомендует, если для устранения требуется вторая команда, если отказ виден пользователям или если проблема не решена после часа сосредоточенного анализа. В группе из трёх человек роли совмещаются, но совмещаются явно: должно быть известно, кто принимает решения и кто сообщает о ходе работ.
Документ
инцидента
Инцидент: архив отвечает 500 на выдачу запусков Командир: А. Изменения: Б. Сообщения: В. Начало 02:00 по графику, объявлен в 02:43 Последствия: 2 % запросов с ошибкой Критерий завершения: ошибок < 0,1 % 30 мин подряд Хронология: 02:43 ArchiveErrorBudgetBurnFast, принят 02:47 ошибки только в зоне B; гипотеза: отказ экземпляров зоны B 03:00 зона B выведена, ошибок нет 03:01 оповещение снято Гипотезы: реплика зоны B отстала — проверяется
01
Записи
время, кто, что сделал, что увидел
02
Гипотезы
и результаты их проверки
03
Зачем
сменщик входит без вопросов, проверки не повторяются
04
Форма
документ, канал, доска: любая запись лучше никакой
Изложение. Все действия записываются по ходу работы в общий документ, доступный участникам: время, кто, что сделал и что увидел, выдвинутые гипотезы и результаты их проверки. В книге Google SRE такой документ называется живым документом состояния инцидента, и его ведение является главной обязанностью командира. Документ решает три задачи. Он позволяет новому участнику или сменщику войти в работу без вопросов к остальным, которые в этот момент заняты. Он предотвращает повторные проверки и одновременные вмешательства: если два человека одновременно меняют систему, каждый видит результат обоих изменений и делает неверный вывод. Наконец, он служит основой постмортема: хронологию инцидента восстанавливают по записям, сделанным в момент событий, а не по памяти. Форма документа вторична — общий текстовый документ, канал в мессенджере, маркерная доска; любая запись лучше её отсутствия. Пример на слайде продолжает учебный отказ архива из демонстрации burnrate.py лекции 19: ошибки идут с 02:00, оповещение о быстром расходовании бюджета ошибок срабатывает в 02:43, через четыре минуты отказ локализован в зоне B, в 03:00 зона выведена из балансировки, и в 03:01 правило снимает оповещение: скорость расходования в окне 5 мин опускается ниже порога сразу после прекращения ошибок. Строка «Критерий завершения», как в образце документа из книги Google SRE, задаёт, когда инцидент считается законченным: снятое оповещение этого ещё не означает. Отметим последнюю строку: проверка отставания реплики ещё идёт, и запись об этом не позволит сменщику начать её заново.
Инцидент
на установке
Роль при инциденте На установке
командир инцидента начальник смены
операционная работа дежурные специалисты систем
коммуникации сообщения экспериментаторам
документ инцидента электронный журнал смены
постмортем разбор отказа после сеанса
Для физика
Правила установок — сначала безопасное состояние, не менять два параметра одновременно, записывать каждое действие со временем — совпадают с правилами SRE.
Пояснение
Отказ программной службы во время сеанса разбирается теми же людьми и по тому же журналу, что и отказ оборудования.
Изложение. Смена ускорительного комплекса или крупной экспериментальной установки действует по тем же правилам, что и дежурные программных систем, причём эти правила сложились в эксплуатации установок значительно раньше. Роль командира исполняет начальник смены: он принимает решения и распределяет задачи между дежурными специалистами систем — вакуума, питания, радиационного контроля, — которые выполняют операционную работу. Сообщения экспериментаторам о ходе работ и ожидаемом времени восстановления соответствуют роли коммуникаций, а документом инцидента служит электронный журнал смены, где каждое действие записано с временем. Правила эксплуатации установок — сначала перевести установку в безопасное состояние, затем искать причину; не менять два параметра одновременно; записывать каждое действие — совпадают с правилами восстановления работы, одиночного вмешательства и документа инцидента, рассмотренными выше. Отказ программной службы установки во время сеанса — архива, системы сбора данных, интерфейса управления — разбирается теми же людьми и по тому же журналу, что и отказ оборудования. Таким образом, физику, работавшему на смене, методы этой части знакомы, и задача состоит в том, чтобы применять их и к программам установки.
Постмортем
Безобвинительный разбор, шаблон отчёта, измерение инцидентов
05
Отказы
Метод
Инструменты
Инцидент
Постмортем
Колесо неудачи
Изложение. Пятая часть посвящена разбору инцидента, или постмортему, — письменному отчёту, который превращает инцидент в задачи, исправляющие систему. Рассматриваются принцип безобвинительного разбора, случаи, в которых разбор обязателен, шаблон отчёта с различием корневой причины и триггера и измерение инцидентов.
Безобвинительный
разбор
01
Постмортем
отчёт: последствия, действия, причины, задачи
02
Без виноватых
способствующие причины, а не человек или команда
03
Ошибка человека
следствие устройства системы: нет проверки, неудобный интерфейс
Важно
Наказание за ошибку ведёт к сокрытию подробностей, и организация теряет сведения для исправления системы.
Поводы для разбора:
01
простой или ухудшение сверх порога
02
потеря данных любого объёма
03
вмешательство дежурного: откат, переключение
04
время устранения сверх порога
05
отказ мониторинга: обнаружено вручную
Изложение. Постмортем, или разбор инцидента, представляет собой письменный отчёт об инциденте: его последствиях, действиях по их смягчению и устранению, причинах и задачах, предотвращающих повторение. Главным результатом инцидента является не восстановленная работа, а этот отчёт: он позволяет исправить систему так, чтобы отказ не повторился или обнаруживался быстрее. Книга Google SRE называет безобвинительный разбор основой культуры SRE: он выявляет способствующие причины, не обвиняя человека или команду, и исходит из того, что каждый участник действовал с добрыми намерениями и правильно в меру тех сведений, которые у него были. Обоснование практическое: если за ошибку наказывают, участники скрывают подробности, и организация лишается сведений, необходимых для исправления системы. Ошибка человека в таком подходе рассматривается как следствие устройства системы: опечатка в конфигурации прошла в эксплуатацию потому, что конфигурацию никто не проверял, а не потому, что инженер невнимателен. Случаи, в которых разбор обязателен, та же книга советует определить заранее и приводит типичные поводы: простой или ухудшение обслуживания, заметные пользователям, сверх установленного порога; потеря данных любого объёма; вмешательство дежурного — откат, переключение запросов; время устранения сверх порога; отказ мониторинга, когда проблема обнаружена вручную. Кроме того, разбор может запросить любой заинтересованный участник. Отметим последний пункт: инцидент, о котором сообщили пользователи, а не оповещение, требует разбора, даже если устранён быстро, поскольку он указывает на пробел в наблюдаемости.
Шаблон
постмортема
Раздел Содержание
Описание что произошло, одним абзацем
Последствия пользователи, функции, потери
Корневые причины дефекты, существовавшие до инцидента
Триггер событие, которое их проявило
Устранение как восстановлена работа
Обнаружение кто и как обнаружил отказ
Задачи тип, владелец, номер заявки
Уроки что хорошо, что плохо, где повезло
Хронология по документу инцидента
Триггер: рост трафика в 88 раз Причина: утечка ресурса при неудачных запросах, существовавшая до инцидента Задачи: исправить утечку; оповещение по ресурсу; у каждой — владелец и заявка
Пояснение
Устранение триггера ничего не исправляет: следующий рост нагрузки приведёт к тому же отказу.
Изложение. Шаблон разбора, приведённый в книге Google SRE в приложении «Example Postmortem», содержит краткое описание (Summary), последствия (Impact), корневые причины (Root Causes), триггер (Trigger), способ устранения (Resolution), способ обнаружения (Detection), задачи (Action Items), уроки (Lessons Learned) и хронологию (Timeline). Различие корневой причины и триггера существенно. Корневая причина является дефектом, существовавшим до инцидента, а триггер — событием, которое его проявило. В примере книги служба поиска по корпусу текстов отказала после того, как трафик вырос в 88 раз, но причиной была утечка ресурса при неудачных запросах, а рост трафика лишь проявил её. Та же ошибка встречается в практике постоянно: в записи «база не выдержала десятикратного трафика» триггер назван причиной, а вопрос, почему десятикратный рост запросов пользователей превратился в пятидесятикратный рост запросов к базе, остаётся без ответа. Устранение триггера ничего не исправляет: следующий рост нагрузки приведёт к тому же отказу. У каждой задачи в шаблоне указаны тип — смягчение, предотвращение, процесс, — владелец и номер заявки: задача без владельца и заявки, как правило, остаётся невыполненной. Уроки делят на три раздела: что прошло хорошо, что прошло плохо и где повезло; последний раздел предназначен для случаев, когда худшего исхода удалось избежать лишь благодаря случайности, на которую в следующий раз рассчитывать нельзя. Хронологию составляют по документу инцидента, рассмотренному в четвёртой части.
Измерение
инцидентов
01
Обнаружение
от начала отказа до первого сигнала
02
Локализация
до найденного компонента
03
Источник
оповещение или сообщение пользователя
04
Разбор каждого случая
вместо средних по кварталу
Случай Обнаружен Задача разбора
1. ответы 500 оповещение проверка конфигурации
2. ответы 403 сообщения пользователей сквозная проверка сценария
3. поиск событий сообщение смены оповещение об отставании
Важно
Среднее время восстановления при десятке инцидентов в квартал — шум: демонстрация incidents.py в лекции 19.
Изложение. По каждому инциденту записывают время обнаружения — от начала отказа до первого сигнала — и время локализации — до найденного компонента, — а также источник обнаружения: оповещение или сообщение пользователя. Эти величины позволяют увидеть, где система наблюдения слаба: отказ, о котором первыми сообщили пользователи, указывает на отсутствующее оповещение по симптому. Соблазнительно сравнивать средние значения этих отрезков между кварталами, однако при малом числе инцидентов среднее является шумом: распределение длительностей инцидентов широкое, и один долгий случай меняет среднее сильнее, чем любое улучшение процесса. Этот вывод работы Ш. Давидовича «Incident Metrics in SRE» показан в демонстрации incidents.py лекции 19: даже при реальном сокращении всех инцидентов среднее за квартал при десятке случаев часто не уменьшается. Поэтому каждый случай разбирают отдельно и следят, чтобы отказы обнаруживались мониторингом, а не пользователями. Таблица на слайде заранее подводит этот итог для трёх учебных случаев шестой части: оповещением обнаружен только первый, два других — сообщениями пользователей и смены, и в обоих разбор добавил новое оповещение или проверку.
Колесо неудачи
Упражнение и три учебных случая: пул потоков, деградирующий диск, отравленное сообщение
06
Отказы
Метод
Инструменты
Инцидент
Постмортем
Колесо неудачи
Изложение. Шестая часть посвящена тренировке. Навык поиска неисправностей отрабатывают до настоящего отказа в упражнении «колесо неудачи», и три учебных случая части разобраны в его формате: служба, которой увеличили пул потоков, реплика базы с деградирующим диском и потребитель очереди, остановленный одним сообщением. Каждый случай сопровождается демонстрацией на модели и уроками для системы.
Колесо неудачи:
правила
01
Ведущий
сценарий прошлого отказа, ответы на запросы
02
Основной дежурный
действует, как при настоящем отказе
03
Запасной дежурный
ищет причину вместе с основным
04
30–60 минут
проверяется порядок действий, а не ответ
дежурный: доля ответов 500 по зонам? ведущий: зона A — 12 %, B и C — 0,1 % дежурный: что выкатывалось в зону A? ведущий: выпуск 2.4, два часа назад дежурный: откат; ожидаю в A меньше 0,1 % ведущий: после отката в A — 3 %
Пояснение
Упражнение для группы: каждый готовит сценарий отказа своей установки или программы.
Изложение. Навык поиска неисправностей тренируют до настоящего отказа. Книга Google SRE описывает упражнение «колесо неудачи» (Wheel of Misfortune), относящееся к ролевым учениям по отказам. Ведущий заранее готовит сценарий — часто по прошлому отказу, иногда по возможному отказу новой функции — и назначает двух участников основным и запасным дежурными. Дежурные действуют так, как действовали бы при настоящем отказе: запрашивают графики, журналы и результаты команд, выдвигают гипотезы и принимают меры. Ведущий сообщает, что показали бы запрошенные графики, или отвечает, что такого графика нет, — отсутствие нужного графика тоже является результатом упражнения и становится задачей. Остальные участники наблюдают, а ведущий при необходимости возвращает дежурных от ложных следов к существу дела. Упражнение занимает 30–60 минут и позволяет проверить не знание правильного ответа, а порядок действий: восстановление, сужение поиска, гипотезы с ожидаемым результатом. Фрагмент на слайде показывает этот порядок: дежурный запрашивает долю ошибок по зонам, находит последнее изменение и, прежде чем откатить выпуск, называет ожидаемый результат, а ответ ведущего показывает, что гипотеза подтвердилась лишь частично и поиск продолжается. Для группы физиков сценарием служит отказ собственной установки или её программ; три случая этой части разобраны в том же формате.
Случай 1:
ответы 500
Служба реконструкции событий: вычисления по запросам, поток на запрос, 16 ядер на машину, три зоны
01
Симптом
ответы 500 от балансировщика L7, оповещение
02
Где
ошибки отдают экземпляры зоны A
03
Что менялось
выпуск в зоне A: откат — ошибок меньше, но выше SLO
04
Пул потоков
заняты все 4000; зона A закрыта — ошибки в B и C
Действие Результат
пул 4000 → 16 000 хуже: растут load average и время ядра
пул → 8000 лучше, но выше SLO
пул → 16, по числу ядер доля ошибок ниже SLO
Важно
Пул увеличен вчетверо без ожидаемого результата: шаг сделан наугад, а не как проверка гипотезы.
Изложение. Первый случай разбирает отказ службы реконструкции событий. Служба выполняет вычисления по запросам, работает на 16-ядерных виртуальных машинах в трёх зонах и обслуживает каждый запрос отдельным потоком из пула — по модели «поток на запрос». Оповещение сообщает, что пользователи получают ответ 500 от балансировщика уровня L7. Журнал балансировщика показывает, что успешные и ошибочные ответы перемежаются, а ошибки отдают в основном экземпляры одной зоны. На эту зону недавно выкатился новый выпуск, и его откатывают; ошибок становится меньше, но их доля остаётся выше цели уровня обслуживания. Зону закрывают от пользователей, её запросы переходят в две другие зоны, и после этого ошибки появляются и там. Метрики пула показывают, что заняты все 4000 потоков. Следующее действие — увеличить пул до 16 000 потоков — делает только хуже: средняя загрузка растёт, все 16 процессорных ядер заняты, причём в основном системным временем, то есть работой ядра операционной системы, а не пользовательским кодом, и растёт число переключений контекста. Повторов со стороны клиентов при этом почти нет: их политика повторов ограничена, и лавины повторных запросов не возникло. Уменьшение пула до 8000 улучшает положение, а до 16, по числу ядер, снижает долю ошибок ниже цели. Отметим, что решение увеличить пул вчетверо было принято без формулировки ожидаемого результата и без указания, на какие графики смотреть, — то есть без гипотезы; к этому уроку вернёмся после демонстрации.
Почему больше потоков —
хуже
01
Ядра те же
16 ядер делят тысячи готовых к работе потоков
02
Запрос дольше
каждый получает долю процессора, задержка растёт
03
Время ядра
планировщик, переключения, блокировки futex, промахи кешей
04
load average
в Linux — задачи в состояниях R и D, а не только очередь к процессору
работа ограничена процессором: потоков ≈ ядер работа ждёт сеть или диск, закон Литтла: потоков ≈ λ · W λ — запросов в секунду W — время запроса вместе с ожиданием 200 запросов/с · 0.05 с = 10 потоков
Пояснение
Измерение: vmstat 1 — столбцы r, cs, sy; pidstat -w; nonvoluntary_ctxt_switches в /proc/PID/status.
Изложение. Объяснение поведения пула опирается на простой факт: ядер не прибавилось. Работа службы ограничена процессором, и 16 ядер одновременно выполняют не больше 16 потоков; остальные готовы к выполнению и ждут очереди. Лишние потоки не ускоряют обработку, а делят те же ядра: каждый запрос получает долю процессорного времени и выполняется дольше, поэтому задержка отдельного запроса растёт, а пропускная способность остаётся прежней. Кроме того, ядро операционной системы тратит всё больше времени на обслуживание тысяч потоков: планирование, вынужденные переключения контекста, обработку блокировок в ядре (вызовы futex) и промахи страниц, а частые переключения вдобавок вытесняют данные из кешей процессора и замедляют любой код. Само переключение дешёвое, но десятки тысяч переключений в секунду становятся заметной долей времени, и доля системного времени растёт. Средняя загрузка (load average) в Linux учитывает задачи, готовые к выполнению, и задачи в состоянии D, поэтому является мерой нагрузки системы, а не только очереди к процессору; насыщение процессора точнее показывают столбец r команды vmstat и файл /proc/pressure/cpu. Среднюю загрузку оценивают в динамике: её рост после увеличения пула и был сигналом. Для работы, ограниченной процессором, достаточно числа потоков, близкого к числу ядер. Для службы, которая в основном ждёт сеть или диск, число одновременно выполняемых запросов оценивают по закону Литтла как произведение потока запросов λ на время пребывания запроса W вместе с ожиданием: 200 запросов в секунду по 50 мс требуют около 10 исполнителей. Закон Литтла рассматривался в лекции 14 на слайде «Нагрузка и задержка». Таким образом, правило «потоков по числу ядер» верно для вычислений и неверно для службы, которая по нескольку секунд ждёт ответа базы.
Демонстрация:
размер пула
01
Запрос — 16 хешей SHA-256 по 4 МиБ, около 20 мс
02
Пачка из 40 запросов на 2 ядрах стенда
03
Пулы из 2, 8 и 40 потоков
04
p50, p99 и переключения контекста
Что наблюдается
Пачка — 0,41–0,42 с при любом пуле; p50 растёт 218 → 252 → 365 мс, p99 — 415–424 мс; вынужденных переключений 146 → 506 → 537.
root@lab — запись со стенда
Демонстрация. Сценарий threads.py воспроизводит первый случай в малом масштабе. Каждый запрос вычисляет 16 хешей SHA-256 буфера размером 4 МиБ — около 20 мс процессора; функции hashlib отпускают глобальную блокировку интерпретатора на время хеширования больших буферов, поэтому потоки вычисляют параллельно, как в программе на C++. Пачка из 20 запросов на ядро — на двух ядрах стенда 40 запросов — приходит разом, и сравниваются три пула: по числу ядер, 2 потока, вчетверо больший, 8 потоков, и по потоку на запрос, 40. Задержка запроса измеряется от прихода пачки до его завершения, а переключения контекста процесса — функцией resource.getrusage: добровольные происходят, когда поток сам уходит ждать, вынужденные — когда планировщик снимает его с процессора. Вся пачка во всех трёх случаях обработана за 0,41–0,42 с: ядер два, и больше работы за это время они не выполнят. Медиана задержки растёт с числом потоков, 218, 252 и 365 мс, а 99-й перцентиль почти не меняется, 415, 424 и 423 мс. Объяснение даёт порядок обслуживания: при двух потоках запросы выполняются по два и в среднем ждут половину пачки, а при сорока все запросы делят процессор и почти все завершаются к концу пачки, поэтому медиана приближается к максимуму. Вынужденных переключений 146, 506 и 537 — в 3,7 раза больше при 40 потоках, чем при 2, добровольных — 84, 121 и 267. Системное время во всех трёх прогонах меньше 0,01 с: при сорока потоках на двух ядрах затраты ядра ещё незаметны, тогда как в учебном случае тысячи потоков на 16 ядрах сделали их основной долей времени. Лишние потоки, следовательно, не увеличили пропускную способность, но увеличили задержку большинства запросов и работу планировщика.
Результат:
задержка и размер пула
Что наблюдается
Пачка обработана за то же время, медиана задержки выросла с 218 до 365 мс, а вынужденных переключений стало в 3,7 раза больше: ядер два, и лишние потоки только делят их.
Демонстрация. Рисунок построен по числам записи threads.py на стенде. Слева — задержка запроса от прихода пачки до ответа против числа потоков в пуле по логарифмической оси с делениями 2, 8 и 40: синяя линия медианы поднимается с 218 до 252 и 365 мс, оранжевая линия 99-го перцентиля остаётся на уровне 415–424 мс. Справа — столбцы вынужденных переключений контекста: 146, 506 и 537. Пачка во всех трёх случаях обработана за 0,41–0,42 с, поэтому рисунок показывает только потери: та же работа выполняется за то же время, но большинство запросов ждут ответа дольше, а планировщик выполняет в 3,5–3,7 раза больше вынужденных переключений. Отметим, что между 8 и 40 потоками число переключений растёт мало: уже при 8 потоках на каждое из двух ядер приходится по четыре готовых к выполнению потока, и планировщик снимает их с процессора почти так же часто.
Уроки
случая 1
Триггер: небольшой рост нагрузки Причина: workers = 4000 вместо 40 в конфигурации двухнедельной давности, «Better», без ревью Последствия: ответы 500 в зоне A, затем в зонах B и C Обнаружение: оповещение по ответам 500
Пояснение
Откат выпуска в зоне A отказа не устранил: выпуск совпал с отказом по времени, но не был его причиной.
01
Проверка конфигурации
пределы перед выкаткой: check_config.py
02
Ревью
изменение одобряет не автор
03
Постепенная выкатка
канарейка: рост времени ядра виден на одной машине
04
Оповещения и графики
вызов — по доле 500, время ядра — на дашборд, всё по зонам
Изложение. Разбор показал, что две недели назад в конфигурацию службы вместо 40 рабочих потоков попало число 4000: при правке в текстовом редакторе была случайно повторена цифра. Автор изменения сам одобрил свой запрос на слияние с сообщением «Better» и сам выкатил его. На тестовом окружении всё работало, в эксплуатации служба две недели справлялась с нагрузкой, пока небольшой её рост не превратил избыток потоков в отказ. Триггером, таким образом, стал рост нагрузки, корневой причиной — непроверенная конфигурация, а свежий выпуск в зоне A с отказом лишь совпал по времени; это пример ложной корреляции из второй части. Уроки случая представляют собой задачи для системы, а не для людей. Первая — проверка конфигурации с пределами перед выкаткой, как check_config.py из демонстрации git bisect; проверка «число потоков равно числу ядер» перестала бы работать при первой замене машин, а предел «не больше четырёх потоков на ядро» достаточно пересчитать для новых машин; в check_config.py число ядер для простоты задано константой 16, а в рабочей проверке его берут из описания целевых машин. Вторая — обязательное ревью: изменение одобряет не автор. Третья — постепенная выкатка с канареечной машиной, на которой рост времени ядра заметен за минуты, и сравнение её метрик с базовой линией. Четвёртая касается наблюдения: дежурного вызывает оповещение по симптому — доле ответов 500 и расходованию бюджета ошибок, — а время ядра и заполненность пула выводятся на дашборд, и все графики строятся по зонам. Наконец, автоматический откат по ошибкам после выкатки сокращает время реакции, но требует ограничений: автоматика выполняет один откат и останавливается до прихода человека.
Случай 2:
ответы 403
Выдача доступа к данным эксперимента: короткоживущие токены в базе с репликами
01
Симптом
403 у части пользователей; выпусков нет, сеть исправна
02
Где
по зонам: 403 растут в одной, зона выведена
03
Реплика
отставание WAL растёт линейно, у соседней — около нуля
04
Диск
чтение быстрое, запись медленная; w_await 800 мс против 5–10
RAID 10 из четырёх дисков: две зеркальные пары запись — на оба диска пары, ждёт медленного чтение — с любого диска пары iostat -x 1: w_await — время записи с ожиданием в очереди, мс
Важно
Столбец %util для RAID-массива и SSD, обслуживающих запросы параллельно, предела не показывает.
Изложение. Второй случай разбирает отказ службы выдачи доступа к данным эксперимента. Служба проверяет короткоживущие токены пользователей, которые хранятся в базе с ведущим сервером и репликами. Пользователи получают ответ 403. Выпусков за неделю не было, и откатывать нечего; сеть исправна; гипотеза о новых правилах доступа отпадает, поскольку отказ получают и давние пользователи. Графики по зонам, построенные после первого случая, показывают, что в двух зонах доля ответов 403 прежняя, а в третьей растёт, и эту зону выводят из балансировки: последствия сняты, хотя причина не найдена. В базе этой зоны отставание воспроизведения журнала WAL на реплике растёт линейно, а на соседней реплике близко к нулю: реплика выдаёт устаревшие данные, и обновлённых токенов пользователей в ней ещё нет. На сервере реплики процессор и память свободны, места на диске достаточно, чтение быстрое, а запись идёт медленно. Массив RAID 10 из четырёх дисков пишет каждый блок на оба диска зеркальной пары и ждёт медленного из них, а чтение обслуживает любой исправный диск пары; поэтому деградирующий диск проявился именно при записи. Команда iostat с расширенной статистикой показывает для каждого устройства среднее время запроса с ожиданием в очереди: у трёх дисков w_await составляет 5–10 мс, обычные для шпиндельных дисков, у четвёртого — 800 мс. Столбец %util для самого массива предела не показывает: по документации iostat для устройств, обслуживающих запросы параллельно, таких как массивы RAID и современные SSD, он не отражает предела производительности, поэтому смотрят время записи каждого диска массива. Диск выводят из массива и заменяют горячим резервом, и реплика начинает догонять ведущий сервер.
Демонстрация:
аномалия диска
01
Сутки w_await четырёх дисков, раз в минуту
02
Правило 1: больше 20 мс пять минут подряд
03
Правило 2: больше трёх медиан соседей
04
Пересечения порога на исправных дисках
Что наблюдается
Порог срабатывает на всех дисках с 12:46 до 13:50, на исправных — 262 пересечения за сутки; правило соседей — только sdc в 15:02; в 15:00 у него 80,9 мс против 17–21 мс.
root@lab — запись со стенда
Демонстрация. Сценарий peers.py моделирует сутки среднего времени записи w_await четырёх шпиндельных дисков одного массива, раз в минуту, с фиксированным зерном: ночью около 6 мс, днём, с пиком нагрузки в 15:00, до 15–25 мс у всех дисков; с 13:00 диск sdc деградирует, и его время записи растёт до сотен миллисекунд. Сравниваются два правила оповещения, каждое из которых требует выполнения условия пять минут подряд. Абсолютный порог 20 мс срабатывает днём на всех четырёх дисках: на sdc в 12:46, на sdd в 13:08, на sdb в 13:37, на sda в 13:50, а пересечений порога снизу вверх на трёх исправных дисках за сутки 262 — оповещение, которое каждый день срабатывает на исправных дисках, быстро перестают читать. Правило «время записи диска больше трёх медиан его соседей по массиву» на исправных дисках за сутки не срабатывает ни разу, а на sdc срабатывает в 15:02, когда условие выполнено пятую минуту подряд; в 15:00, по таблице, w_await sdc составляет 80,9 мс против 17,2–21,1 мс у соседей. Ночью, в 03:00, все четыре диска близки: от 5,0 до 6,5 мс. Таким образом, сравнение с соседями отделяет отказ одного диска от общей дневной нагрузки, которую абсолютный порог не различает. Физический аналог — одинаковые вакуумметры одного участка: показание, отличающееся от соседних в несколько раз, подозрительнее показания, превысившего абсолютный порог вместе со всеми.
Результат:
await четырёх дисков
Что наблюдается
Днём все диски пересекают порог 20 мс; sdc отклоняется от соседей после 13:00, правило «три медианы» срабатывает в 15:02, к концу суток — сотни миллисекунд.
Демонстрация. Рисунок построен по той же модели peers.py. По горизонтали — время суток, по вертикали — w_await в логарифмической шкале; тонкие линии — исправные диски sda, sdb и sdd, толстая оранжевая — sdc, штриховая — порог 20 мс, точечная вертикаль — срабатывание относительного правила в 15:02. Днём все четыре диска поднимаются к порогу и многократно пересекают его, а sdc после 13:00 отклоняется от соседей и к концу суток доходит до сотен миллисекунд. Логарифмическая шкала показывает, что относительное правило по существу является порогом на отношение: оно реагирует на расстояние между линией sdc и пучком соседей, а не на высоту самого пучка, которая меняется в течение суток втрое. Отметим, что к моменту срабатывания относительного правила время записи sdc уже в несколько раз выше нормы; правило с меньшим множителем сработало бы раньше ценой большего числа ложных срабатываний.
Уроки
случая 2
01
Отставание реплики
оповещение о главном симптоме этой базы
02
Соседи по массиву
аномалия относительно медианы, а не абсолютный порог
03
Сквозная проверка
вход и получение данных, как у пользователя
04
Чтение реплик
приложение не читает из отставшей реплики
Важно
SMART часто не предупреждает: у более чем 36 % отказавших дисков все показатели, кроме температуры, были нулевыми (Google, 2007).
Для физика
Одинаковые вакуумметры участка: показание, отличающееся от соседних в несколько раз, подозрительнее превышения порога вместе со всеми.
Изложение. Разбор второго случая начинается с того, что сработало: графики по зонам, построенные после первого инцидента, позволили локализовать отказ за минуты. Затем — с того, чего не хватило. Оповещения на ответы 403 не было: после первого случая его завели только на ответы 500, а время ответа базы оставалось нормальным — данные лишь устарели. Поэтому первой задачей является оповещение об отставании реплики, главном симптоме этой базы. Оповещение по абсолютному порогу времени записи будет шумным: шпиндельный диск под дневной нагрузкой медленнее, и демонстрация показала 262 пересечения порога за сутки на исправных дисках. Оповещение по скорости записи бесполезно: она меняется в течение суток. Для дисков работает правило аномалии относительно соседей по массиву; сравнение между зонами затруднено, если оборудование в них разное. Показатели SMART такой отказ могут и не выдать: в исследовании Google, охватившем более ста тысяч дисков, более чем у 36 % отказавших дисков все показатели SMART, кроме температуры, оставались нулевыми, и авторы заключили, что предсказать по одним показателям SMART отказ отдельного диска вряд ли удастся. Третья задача — сквозная проверка пользовательского сценария: программа, периодически выполняющая вход и получение данных, позволила бы обнаружить ответы 403 раньше пользователей и показала бы, какой сценарий нарушен. Четвёртая — архитектурная: приложение опрашивает отставание реплик и не читает из отставших. Перенос токенов в другое хранилище с асинхронными репликами эту задачу не решает: его реплики отстают так же.
Случай 3:
отравленное сообщение
очередь
шарды, смещение offset
потребитель
разбор заголовка
запись
чтение
запись
01
Симптом
новые события не находятся в индексе
02
Где
запись в индекс — почти ноль, в очередь — идёт
03
Потребитель
занят на 100 %: аварийное завершение и перезапуск
04
Журнал
ошибка разбора поля заголовка новой прошивки
05
Мера
событие сохранить, смещение сдвинуть вручную
while True: event = read(offset) parse(event) # ValueError index(event) offset += 1 commit(offset) # перезапуск — с последней # зафиксированного смещения
Изложение. Третий случай разбирает конвейер обработки событий. Оцифровщики пишут события в очередь, разделённую на шарды, например в Kafka; потребитель читает события, разбирает заголовок каждого, записывает событие в поисковый индекс и фиксирует смещение (offset) прочитанного. Очередь сама ничего не отправляет: потребитель вычитывает события и фиксирует смещение, поэтому после перезапуска он продолжает с последнего зафиксированного. Смена сообщает, что новые события в индексе не находятся, причём только за последний день и почти во всех шардах. Проверка по потоку данных показывает, что запись в индекс снизилась почти до нуля, а запись в очередь продолжается, — проблема находится между ними, в потребителе. Потребитель загружает процессор: он аварийно завершается при разборе, перезапускается с последнего зафиксированного смещения и снова завершается на том же событии. Откат и перевод нагрузки на другой экземпляр потребителя не помогают: другой экземпляр получает то же событие и завершается так же. Журнал потребителя содержит ошибку разбора незнакомого поля заголовка: оцифровщик с новой прошивкой прислал событие нового формата. Исправить разбор может только разработчик, который недоступен, поэтому проблемное событие сохраняют для последующего разбора, а смещение потребителя сдвигают вручную на одно сообщение, как если бы оно было обработано, и очередь начинает разбираться. Сообщение, которое потребитель не может обработать и на котором останавливается весь конвейер, называют отравленным.
Демонстрация:
очередь и DLQ
01
Очередь: 100 событий/с, разбор до 150 событий/с
02
20-я секунда: событие прошивки fw=3.1
03
Без защиты: перезапуск через 2 с с того же смещения
04
DLQ: событие отложено после трёх попыток
Что наблюдается
Без защиты — обработано 2000 событий до конца прогона, отставание 4000 к 60-й секунде, 20 перезапусков; с DLQ — 2 перезапуска, 1 событие в DLQ, к 40-й секунде отставание 0.
root@lab — запись со стенда
Демонстрация. Сценарий poison.py моделирует конвейер в модельном времени с шагом 0,1 с, без случайности. Оцифровщики пишут в очередь 100 событий в секунду, потребитель разбирает до 150 событий в секунду и фиксирует смещение после каждой пачки. На 20-й секунде приходит событие 2000 от оцифровщика с прошивкой 3.1, заголовок которого содержит незнакомое поле, и разбор завершается исключением. В первом режиме защиты нет: потребитель аварийно завершается, через 2 с перезапускается с последнего зафиксированного смещения и снова завершается на том же событии. Таблица по десятисекундным отрезкам показывает, что после 20-й секунды обработано 2000 событий и больше не обрабатывается ни одного, отставание растёт на 1000 событий каждые 10 с и к 60-й секунде достигает 4000, а перезапусков 20 — по пять за каждые 10 с. Во втором режиме событие после трёх неудачных попыток откладывается в очередь недоставленных сообщений, dead letter queue, смещение фиксируется, и потребитель продолжает работу: два перезапуска, одно событие в DLQ, на 30-й секунде отставание 130 событий, а к 40-й — ноль, поскольку потребитель разбирает в полтора раза быстрее, чем пишут оцифровщики. Без защиты, следовательно, одно событие останавливает весь конвейер, а с защитой обходится двумя перезапусками и одной записью в DLQ.
Результат:
отставание потребителя
Что наблюдается
Без защиты отставание растёт линейно с 20-й секунды до 4000 событий; с dead letter queue оно достигает 420 событий на 24-й секунде и обнуляется к 33-й.
Демонстрация. Рисунок построен по той же модели poison.py: отставание потребителя от очереди в событиях по времени от 0 до 60 с, линии — модель с шагом 0,1 с, точки — значения таблицы демонстрации через каждые 10 с, штриховая вертикаль — 20-я секунда, когда приходит событие новой прошивки. Оранжевая линия без защиты растёт линейно от нуля до 4000 событий: потребитель не продвигается, а оцифровщики продолжают писать по 100 событий в секунду. Синяя линия с dead letter queue после трёх попыток поднимается до 420 событий на 24,2 с, пока потребитель тратит время на три попытки и два перезапуска, проходит через 130 событий на 30-й секунде, отмеченные точкой таблицы, и к 32,6 с обнуляется. Наклон оранжевой линии равен скорости записи в очередь, поэтому оповещение об отставании с порогом в 1000 событий сработало бы через 10 с после остановки потребителя.
Уроки
случая 3
01
Dead letter queue
после N попыток — в отдельную очередь, оповещение о её росте
02
Отставание потребителя
длина необработанной части очереди
03
Свежесть
время последней записи в индекс по шардам
04
План Б
проверяется учениями, иначе не сработает
Пояснение
Amazon SQS переносит сообщение в DLQ после заданного числа получений; в Kafka её реализует код потребителя или Kafka Connect, а share groups в Kafka 4.2 сами считают доставки.
Для физика
Событие с новым заголовком от одного оцифровщика не должно останавливать запись всех остальных.
Изложение. Оповещений в третьем случае не было: о проблеме сообщила смена. Первая задача — ограничить число попыток обработки, для чего необходима очередь недоставленных сообщений, dead letter queue: событие, которое не удалось обработать за несколько попыток, откладывается в отдельную очередь для разбора человеком, а потребитель продолжает работу; рост этой очереди сам по себе является сигналом — возможно, выкатился неудачный выпуск, возможно, изменилось что-то во внешнем мире, например прошивка оцифровщиков. В Amazon SQS такая очередь настраивается политикой повторной доставки: сообщение переносится в неё после заданного числа получений. В Kafka для обычных групп потребителей её реализует код потребителя, коннекторы-приёмники Kafka Connect или, начиная с версии 4.2, обработчики исключений Kafka Streams, а группы с разделяемым чтением (share groups), готовые к промышленному использованию с той же версии, сами ведут счётчик доставок записи и после пяти неудачных попыток по умолчанию перестают её выдавать. Вторая задача — оповещение об отставании потребителя, то есть о длине необработанной части очереди. Третья — индикатор свежести: время последней записи в индекс по каждому шарду; шардов тысячи, а не миллионы, как пользователей, поэтому оповещение по шардам остаётся обозримым. Четвёртая касается запасного плана: перевод нагрузки на резервные потребители не помог бы, поскольку они получили бы то же событие, а план, который не проверялся на учениях, в момент отказа не срабатывает. Для физика ситуация знакома по системе сбора данных: событие с испорченным или новым заголовком от одного оцифровщика не должно останавливать запись всех остальных.
Итоги
лекции
01
Сначала восстановить работу, затем искать причину.
02
Гипотеза — вместе с проверкой и ожидаемым результатом.
03
Хронология — по запросам и спанам, а не по часам машин.
04
Около 70 % отказов вызваны изменениями: откат и git bisect.
05
Профиль, стеки, снимки памяти, /proc — без перезапуска.
06
Явные роли, документ инцидента, разбор без виноватых.
07
Порядок действий отрабатывается на учениях.
Изложение. Подведём итоги. При отказе сначала восстанавливают работу — откатом, выводом зоны, отключением функции — и лишь затем ищут причину. Каждая гипотеза о причине формулируется вместе со способом проверки и ожидаемым результатом, отрицательный результат сужает поиск, а одновременно меняется только один параметр. Отказ распределённой системы частичен, и хронологию собирают по идентификаторам запросов и связям спанов, а не по часам разных машин. Большинство отказов вызваны изменениями, поэтому первым действием служит откат, а среди многих изменений виновное находит деление пополам — git bisect с проверкой в виде программы. Работающий процесс отвечает на вопросы без перезапуска: профиль показывает, где тратится процессорное время, стеки потоков — где процесс ждёт, снимки tracemalloc — где выделена растущая память, /proc и strace — чего процесс ждёт от ядра, а код возврата и журнал — почему служба не запустилась. Роли командира, исполнителей и коммуникаций распределяются явно, действия записываются в общий документ, а безобвинительный постмортем отделяет корневую причину от триггера и превращает инцидент в задачи для системы. Наконец, порядок действий отрабатывается на учениях «колесо неудачи» до настоящего отказа.
Упражнения
и задание
01
Колесо неудачи
сценарий своей установки: ведущий, два дежурных, 30 минут
02
Три ошибки
deadlock.py, leak.py, blocked.py: гипотеза, проверка, исправление
03
Постмортем
по шаблону для хронологии timeline.py
04
Своя служба
faulthandler по SIGUSR1, проверка конфигурации, код 78
Пояснение
Исправление проверяется той же командой, что и гипотеза: после правки ожидаемый результат меняется.
Для физика
Сценарий для колеса неудачи — последний отказ своей установки из журнала смены.
Изложение. Упражнения служат самопроверке. Первое — провести в группе упражнение «колесо неудачи» по сценарию отказа своей установки или программы: ведущий готовит сценарий и ответы на возможные запросы, основной и запасной дежурные действуют, остальные наблюдают; на всё отводится 30 минут, после чего ход поиска разбирается вместе. Второе — найти и исправить взаимную блокировку, утечку памяти и ожидание без тайм-аута в сценариях deadlock.py, leak.py и blocked.py, сформулировав для каждой ошибки гипотезу, способ проверки и ожидаемый результат, а после исправления убедиться, что та же проверка даёт другой результат. Третье — написать постмортем по шаблону книги Google SRE для учебного инцидента из демонстрации timeline.py: последствия, корневая причина и триггер, хронология с поправкой на смещение часов, задачи с владельцами. Четвёртое — добавить в собственную службу обработчик faulthandler по сигналу SIGUSR1 и проверку конфигурации при старте с кодом завершения 78, а затем проверить оба механизма запуском службы.
Источники
1
Книга курса: главы «Поиск неисправностей», «Наблюдаемость», «Инструменты Linux», «Внутреннее устройство Linux», «Причины низкой скорости Python»
phys-dev.github.io/soft-dev-book
2
Beyer B., Jones C., Petoff J., Murphy N. R. Site Reliability Engineering. – O'Reilly, 2016: главы «Effective Troubleshooting», «Managing Incidents», «Postmortem Culture», «Accelerating SREs to On-Call and Beyond»
sre.google/sre-book
3
Beyer B. et al. The Site Reliability Workbook. – O'Reilly, 2018; Davidovič Š. Incident Metrics in SRE. – O'Reilly, 2021
5
Pinheiro E., Weber W.-D., Barroso L. A. Failure Trends in a Large Disk Drive Population // FAST'07. – USENIX, 2007; Gregg B. Linux Load Averages: Solving the Mystery. – 2017
6
Справочные страницы iostat(1), mdadm(8), strace(1), proc(5); заблуждения о распределённых вычислениях (П. Дойч, 1994; Дж. Гослинг, около 1997)
man7.org/linux/man-pages
Изложение. Лекции соответствует глава книги «Поиск неисправностей» части «Инженерные практики», продолжающая главу «Наблюдаемость»; инструменты Linux и состояния процессов подробно рассмотрены в главах «Инструменты Linux» и «Внутреннее устройство Linux», профилировщики — в главе «Причины низкой скорости Python». Метод поиска, управление инцидентами, постмортемы и упражнение «колесо неудачи» изложены в книге Google SRE, практические шаблоны — в SRE Workbook, а критика средних метрик инцидентов — в работе Ш. Давидовича. Справочником по faulthandler, tracemalloc, профилировщикам и поддержке perf служит документация Python, по iostat, mdadm, strace и /proc — справочные страницы Linux. Работа Пинейро, Вебера и Баррозу содержит статистику отказов дисков и показателей SMART, статья Б. Грегга — объяснение средней загрузки в Linux.
Спасибо за внимание
Вопросы
phys-dev.github.io/soft-dev-book
Изложение. Лекция завершена. Вопросы по материалу удобно задавать, опираясь на главу «Поиск неисправностей» и на демонстрации: все сценарии работают на модельных данных и петлевом интерфейсе, поэтому любой учебный отказ можно воспроизвести, исследовать теми же инструментами и исправить.