Ошибки — это интересная штука, потому что даже в названии самого доклада есть двойное дно. Это работа над ошибками, которые мы допускаем в своем софте, в программах, сервисах. А также работа над ошибками – это создание pipeline, чтобы все это обработать, чтобы все в конце было хорошо.
Sentry — инструмент мониторинга исключений (exception), ошибок в ваших приложениях.
Работа над ошибками – это длинная история про то, как мы большой компанией переходили на Sentry. Этот переход у нас занял порядка двух лет. И маленький спойлер: этот переход еще не во всех местах завершен, но мы делаем работу над ошибками и вроде у нас все хорошо получается.
Давайте посмотрим ретроспективно на эти истории 2019-2020-года.
Начнем с того, как устроен у нас pipeline доставки логов и как он менялся во времени.
Если в прошлом году у нас было порядка 60 000 логов записей в секунду и суммарно 3 ТБ данных в сутки, то в этом году мы пробили потолок в 150 000 логов записей в секунду, а объем данных превышает порядка 6 ТБ за сутки.
В целом pipeline устроен довольно просто. У нас есть некое приложение, есть микросервис, в котором есть компонент, который должен отправить лог записи куда-то дальше. Этим куда-то дальше на другом конце у нас является Elastic. Он является индустриальным стандартом. Многие его используют. Многие представляют, как его готовить.
Вопрос в том, как сделать передачу до Elastic. Это можно делать разными способами. Мы пошли своим путем. Мы сделали систему, которая занимается доставкой логов. Назвали ее Hercules. Эта штука в open source, поэтому можно будет пройти по ссылочке на GitHub и попробовать там потыкаться.
В правом верхнем углу – это то, как выглядит созвездие Hercules в нашем звездном небе.
Pipeline внутри устроен следующим образом. Из приложения в специальный Elastic Adapter отправляется лог записи в том формате, в котором привык получать Elastic.
Дальше они перекладываются в специальный шлюз, который работает с Kafka. Kafka – это такая система, через которую можно очень много прокидывать событий. Дальше есть специальный daemon, который забирает логи из Kafka и складывает в Elastic.
Понятно, что Elastic мы используем не голый. Там рядом есть Kibana, которая позволяет эти логи ??? читать??? (наверное показывать).
В целом pipeline устроен таким образом. Почему столько компонентов и зачем так делать?
В действительности это не просто pipeline доставки логов, это целая система для надежной доставки телеметрии. У нас есть очень много различных daemons, которые умеют в разные типы телеметрии, т. е. это и логи, и метрики, и распределенные трассировки, и еще другие типы телеметрии. Всего там порядка 15 приложений.
Где здесь обработка ошибок? И зачем она нужна?
Обработка ошибок – это, по сути, способ как-то понять, насколько хорошо наш сервис работает, какие ошибки у него возникают, как часто и т. д.
Раз у нас уже есть Elastic, то ничего не мешает нам эти данные забирать непосредственно из него. В Kibana нет удобных способов для агрегации, поэтому у нас когда-то был написан небольшой наколеночный Web, который позволял, используя данные Elastic, их вытаскивать и показывать в удобном для пользователя виде, т. е. конкретным индексом.
Какими фичами он обладал?
- Во-первых, он был не по всем ошибкам, а только там, где есть Exception с каким-то stacktrace.
- Чтобы группировать событие, там вычислялось специальное поле exc_stacktrace_hash, по которому можно было эти ошибки группировать.
- И в этом Web можно было еще отфильтровать ошибки, т. е. те, которые нам не очень интересны. Например, это какая-то незначимая ошибка в компоненте, который вообще не влияет на работу системы. И чтобы не видеть в общем списке эти ошибки, они отфильтровывались.
Оставалось только на клиентах доработать и вычислять hash, чтобы правильным образом их группировать.
Но у такого подхода есть существенный недостаток. Поскольку у нас единственное место, где мы группируем ошибки – это Web, т. е. serverless-приложение, то мы никакой статистики не имеем по ошибкам и не имеем никакого алертинга. А как мы узнаем чуть позже, эти вещи очень полезны.
Что в таком pipeline сделать, чтобы это можно было завести?
Первое логичное место, куда можно было эту штуку вставить, это Elastic Adapter. И там это дело собирать.
Конкретно там можно сделать сбор метрик на какое-то общее количество, т. е. как часто они проявляются. Эту вещь можно там собрать.
При этом нам ничего не мешает настроить примитивный алертинг.
Например, мы можем отфильтровать ошибки по некоторым полям, т. е. по тем, которые действительно важны и по которым нужно уведомить пользователей.
А в качестве алертинга использовался email. Там раз в час можно было получить такой отчет.
Настройки фильтрации, а также что именно и как агрегировать – это тоже мы сделали в Web, чуть расширив его.
Как с этой штукой работали инженеры?
- Во-первых, дежурный мог зайти в почту и получить алерт об ошибках. И потом мог с ними разбираться. Это, может быть, не очень оперативный способ. Но это возможность в течение часа найти какую-то проблему и ее начинать исправлять.
- Во-вторых, чтобы не ждать этого часа, пока придет ошибка, использовался активный мониторинг.
В чем он заключался? Дежурный инженер, допустим, в момент релиза или в ближайшее время после него, или в течение дня смотрел глазками Web. Он смотрел, какие ошибки приходят. И если видел там какую-то аномалию, то начинал с этим что-то делать.
Такой активный мониторинг оказался хорошо применим для тестировщиков. Почему? Потому что у нас есть staging-окружение, на котором мы развернули нашу систему, погоняли какие-то тесты. И вроде бы все работает, но эти компоненты могут давать сбой. И как раз тестировщики могли просто зайти в такой мониторинг для staging-окружения, чтобы посмотреть, какие ошибки появились. И дальше они могли заводить дефекты, а потом улучшать софт.
Но в действительности не все так просто. И тут нам поможет аналитика факапов.
Есть у нас такая практика, когда мы собираем post mortem, и по ним делаем какие-то выводы. Для примера рассмотрим парочку факапов. Это реальные факапы, которые у нас были в компании в прошлом году в разных командах. В этом примере взят период времени – 2 суток. Каждый столбец – это ошибки в час. Видно, что потолок – 1 300 ошибок в час. И утверждается, что на этом графике есть период, когда произошел некий факап. Давайте попробуем понять, где все началось. Где-то с начала этого первого пика, потому что сложно не заметить вот этот всплеск. Но если присмотреться, то есть маленькая подозрительная пипка. И эта подозрительная пипка, может быть, тоже как-то относится к нашей проблеме. И если мы возьмем все наши логи и отфильтруем только по тем, которые действительно касались факапа, то мы получим такую картину:
Вот этот маленький всплеск под цифрой 2 в действительности был связан с этим факапом. И это как раз первые ошибки, с которыми столкнулись наши пользователи. Это было вечером 24 февраля. Уже ближе к ночи начались массовые ошибки. И только уже под утро были обращения пользователей в техническую поддержку. И видно, что тут достаточно быстро все пофиксили путем отката и все стало хорошо.
В таком факапе можно было сказать, что когда вы что-то делаете, посмотрите на количество ошибок. Мониторьте активно и проблему решите. Вроде бы аргумент разумный и так можно сделать.
Но давайте посмотрим на другой пример. Это уже другая команда. У них произошел какой-то факап. Каждый столбик – это количество ошибок в час. Временной промежуток тоже 2 суток. И здесь потолок уже больше. Здесь до 8 000 ошибок в час доходило. Давайте попробуем понять, где все началось. Можно предположить, что перед вот этим вторым всплеском факап произошел. Но с другой стороны где-то вот здесь слева тоже ошибки в большом количестве возникали, стали столбики появляться. Может быть, ошибка тут. Кто-то, возможно, заподозрит, что что-то тут неладно. И на самом деле где-то в прошлом у ребят начались проблемы. Но если сейчас взять и попытаться посмотреть только те ошибки, которые относятся непосредственно к факапу, то можно заметить, что на несколько пикселей изменились какие-то столбики. Тут совсем не разглядеть. Но на самом деле первые ошибки начались вот здесь. В середине дня они начались. На следующий день были обращения в техническую поддержку. Там стали разбирались, в чем проблема. Через пару часов начали фиксить проблему. Быстро ее починили и все стало хорошо. Но в целом важно понимать, что примерно сутки какая-то часть сервиса была недоступна для пользователя.
https://habr.com/ru/company/ru_mts/blog/308044/
Что в этой ситуации делать? Я говорил про активный мониторинг. Можно обратиться к интернету и посмотреть, как такую проблему решают в других местах.
Вот это реальная фотография с блога одной крупной российской компании на Habr. Что мы здесь видим? Здесь достаточно много инженеров за мониторами. Они сидят и смотрят графики.
Но нужно понимать, что масштаб может измениться. Задач стало много. Много проектов, трафик большой, нагрузка большая. Логов, графиков, событий много. Что делать?
Наверное, нужно увеличивать количество инженеров и давать им еще больше мониторов. Если приглядеться, то можно посчитать количество мониторов. И можно заметить, что у одного инженера аж целых 12 мониторов.
И те, кто внимательно посмотрели первую картинку, заметили, что тот большой экран находится в конце этого open space. Т. е. огромное количество инженеров, которые только и делают, что сутками смотрят графики.
Вроде бы это решение.
Но если проанализировать факапы, которые мы собирали в течение года, то можно сделать вывод, что лишь имея алертинг по новым ошибкам, которые мы не видели раньше, можно избегать порядка 10-15 % инцидентов. Это не то, чтобы быстро локализовать факап, а просто его избегать, т. е. он не случился бы вообще.
Понятно, что такая практика не возникнет сама по себе. Нужно использовать различные окружения типа staging, канареечный деплой и прочее. Но самое главное, что это действительно может помогать.
Подробней про то, какую аналитику факапов мы делаем и про культуру заполнения post mortem – это отсылка к докладу моего коллеги Леши Кирпичникова. Там он рассказывает, как мы к этому пришли и почему мы стали делать аналитики по факапам.
Миграция на Sentry
Давайте вернемся к нашей действительности, т. е. к тому, что нужно что-то менять. Тут, казалось бы, и должен появиться Sentry, который должен нас спасти.
Давайте для начала разберемся, почему именно Sentry, а не что-то другое. Самое главное, что Sentry – это тот инструмент, в котором есть алертинг по новым ошибкам. Эта та фича, которая нам была нужна. Вторая по списку, но не по значимости, вещь – это то, что можно делать инсталляцию Sentry на своем железе и не использовать cloud’ный Sentry. Почему это для нас важно? Об этом я расскажу чуть попозже.
Поскольку у нас компания очень большая, проектов очень много, их несколько десятков, некоторые команды идут в ногу со временем и находят свои инструменты. Были примеры в компании, когда отдельная команда начала использовать Sentry. Был положительный опыт. И вроде бы казалось, что у них меньше факапов происходит, что работа с ошибками действительно организовывается. И становится лучше жить не только инженеров, но и команде в целом. Поэтому мы решили взять Sentry и попробовать его на масштабах компании.
Но стоит понимать, что если мы берем какой-то инструмент, нужно его в плане инфраструктуры, которую мы хотим предлагать другим разработчикам, другим командам, суметь продать.
Для этого я как раз готовил демо.
Это демо показывается на примере реального факапа. Это один из факапов, который мы с вами сейчас разбирали. И нужно было закинуть все логи в наш pipeline и довести до Sentry и посмотреть, как все будет.
Давайте посмотрим коротенькое видео, как все работает. Видео начинается в 13.51
Получается, что есть какие-то ошибки, которые не относятся к текущему релизу. У нас релиз безошибочный. Здесь все хорошо. В целом у нас есть какие-то ошибки, которые трекались с предыдущих релизов, которые когда-то давно возникали. Их здесь можно смотреть.
Сейчас стало видно, что ошибок стало чуть-чуть побольше. Эти ошибки, которые мы закидываем, они как бы в реальном времени начинают наполняться-наполняться. И сейчас нам пришло уведомление от Sentry, что что-то пошло не так. На почту пришло сообщение, что вот такая-то у нас ошибка произошла. Даже можно посмотреть какой-то stacktrace. Но самое главное в том, что можно сразу из почты перейти в Sentry и увидеть эту ошибку. Можно увидеть контекст этой ошибки, т. е. что произошло.
Мы видим, что появился новый релиз. Пошли логи по новому релизу. И мы увидели ошибочку, которая в этот релиз попала. Эта та самая, которая здесь появилась. Ее можно с разных сторон найти. Это как раз та ошибка, которая самая последняя пришла.
В принципе, алерт получили. Это означает, что инженер уже не через сутки узнает о проблеме, а достаточно оперативно. Это будет зависеть от того, как мы настроим алерт в нашем инструменте. В данном случае он был настроен на 5 минут.
Мы решили использовать Sentry. Я уже говорил, что мы решили построить свой pipeline для логов. Но давайте поймем, почему бы не использовать Sentry SDK.
Есть библиотека, которую можно включить в приложение и с помощью нее сразу отправлять exception в Sentry. У такого подхода есть существенный недостаток. Самый первый – это то, что такой Sentry-клиент работает по модели fire-and-forget. Что это означает? Это означает, что он пытается отправить ошибку в Sentry. Если получилось, то она будет доставлена. Если что-то пошло где-то не по плану и где-то произошла ошибка, неважно на каком уровне, то мы эту информацию об ошибке потеряем.
Это звучит довольно неприятно, особенно, когда у нас инцидент или, например, вдруг Sentry не работает. Такой подход достаточно хрупкий.
Второй момент – это vendor lock. Если мы выбираем использование Sentry SDK, то это означает, что в каждый микросервис, в каждое наше приложение мы должны встроить библиотеку Sentry и ею пользоваться. Если вдруг нам что-то не понравится, а мы это делаем в масштабах компании, то это будет довольно неприятно. И заставлять разработчиков делать что-то другое – это плохо.
Почему это плохо? Заставлять людей что-то потом переделывать – это само по себе не очень. Кроме того, у нас таких микросервисов тысячи. У нас десятки команд. У каждой команды десятки микросервисов. В сумме накапливается в тысячу. И поменять для тысячи сервисов вот это не хотелось бы.
И самое главное, у нас есть под рукой труба, которая позволяет надежно доставку сделать. И вот эта вещь, которую надо сюда добавить. Эту проблему мы увидели не сразу, но она потом оказалась для нас очень существенной.
Когда команда использует SDK, то они напрямую отправляют в Sentry. И тогда мы не имеем никакого контроля со стороны инфраструктуры о том, что, кто и как отправляет в Sentry. А это очень важно.
И тут глядя на эти причины понятно, зачем использовать ту трубу, которая у нас уже есть. И получить эти данные довольно просто. У нас уже есть pipeline, который отправляет данные в Elastic.
Нам просто нужно эти же самые данные перенаправить в другое русло и направить в Sentry.
Но, как вы понимаете, не все так просто, иначе этого доклада не было бы. С какими проблемами мы при этом сталкивались? Сталкивались с большим количеством проблем. Давайте разберем самые основные.
Первая – это группировка ошибок. Оказалось, что не все так просто с ней. Если в целом посмотреть, как устроена группировка ошибок в Sentry, то там есть несколько типов событий, которые туда попадают.
Если очень грубо, то есть 3 набора данных, по которым можно их группировать. Это:
- Stacktrace,
- Exception, т. е. тип exception, который возник,
- Message, т. е. тот message, который мы записали вместе с ошибкой.
Если со stacktrace все более-менее понятно, т. е. если 2 stacktraces совпадают, то, скорее всего, ошибка одна и ее можно сгруппировать. Тут вопросов нет.
Интересно, когда у нас есть message. Понятно, одинаковые messages будут группироваться в одну ошибку; messages разные, соответственно, группироваться не будут.
Давайте посмотрим пример реального лога записи. Этот message, который у нас слогировался в качестве ошибки. Что мы здесь видим? Здесь виден какой-то идентификатор. Сразу спойлер – это на самом деле префикс межсервисной трассировки. Здесь есть еще какое-то число, которое довольно уникальное между отдельными запросами. Есть еще какой-то идентификатор. Я понятия не имею, что это такое. Это взято из логов одной из команд.
Что с этим делать? В действительности эта строка будет всегда уникальной, потому что идентификатор трассировки меняется, внутренние идентификаторы добавляют команды к своим логам, тоже меняются.
На помощь нам приходит fingerprint. Это специальная технология, которая позволяет нам сказать, что у данной ошибки будет вот такой-то отпечаток и все ошибки, которые имеют такой же отпечаток, нужно сгруппировать.
Как его формировать? Достаточно взять и посчитать какой-нибудь hash, например, от шаблона нашего сообщения.
Если в лог записи вставлены все нужны значения, но поскольку мы используем структурированное логирование, то у нас есть шаблон, в который в какой-то момент подставляются нужные значения. А здесь мы сразу будем считать fingerprint целого шаблона. Это в целом решает эту проблему.
Вторая вещь, с которой мы столкнулись, это то, что ошибок в проектах может возникать внезапно довольно много.
И тут оказалось, что полезно сделать троттлинг и таким образом снизить пиковую нагрузку от проектов. А также изолировать таким образом влияние других проектов. А также влияние одних команд, которые пишут свои ошибки, от ошибок других команд.
Допустим, решили, что 500 ошибок – это мягкий троттлинг, который позволит срезать какие-то пики.
Но мы поняли, что мы ошиблись и этого недостаточно, потому что бывают «команды-плохиши», которым какой бы ты троттлинг не устанавливал, какую бы норму не делал, они все всегда будут в нее упираться. И это означает, что в Sentry будет приходить очень и очень много ошибок.
И 1 000 ошибок мы можем выдать в Sentry, а это не шутка, это реальность, с которой мы столкнулись. И это слишком много. Да, можно попотеть и попытаться домасштабировать Sentry до такой нагрузки, но, кажется, что здесь что-то не так и нужно фундаментально менять подход.
Ошибки: Хорошие, плохие, бесполезные
Поэтому здесь мы как раз поговорим о том, какие ошибки идут к нам.
Что такое ошибка в нашем pipeline? Это лог-запись с уровнем логирования ERROR или FATAL.
Но если хорошенько подумать, то окажется, что этот тезис, хоть он фактически соответствует действительности, но фундаментально он ошибочный.
И ошибка – это не то, что мы залогировали с каким-то уровнем, а это то событие, которое требует реакции инженера. Т. е. должен человек включиться, посмотреть, в чем проблема и начинать ее исправлять. В противном случае, это ошибкой считать не надо. Давайте посмотрим некоторые примеры, с которыми мы сталкивались.
Примеров таких уже довольно много. Самый типовой – это ошибка + успешный retry.
https://github.com/vostok/clusterclient.core/issues/7
В чем она заключается? Давайте попробуем посмотреть логи, которые у нас были в сервисе. Тут все логи, не только ошибки. Здесь сервис пытался сделать запрос по какому-то URL. А за этим URLстоит несколько сервисов. Он выбрал какую-то реплику. Сделал какой-то запрос и что-то не получилось. Закончился ошибкой. Но самое главное, сервис на этом не закончил свою работу. Он попытался отправить запрос на следующую реплику. И эта реплика вернула уже успешный ответ.
С одной стороны, ошибка у нас возникла, но мы сделали retry и все стало хорошо. Но тем не менее ошибка в лог упала. Соответственно, счетчик в Sentry сработал. И прилетит алерт разработчику. И он будет вынужден ночью просыпаться и разбираться с тем, что на самом деле и не нужно было делать.
Давайте посмотрим другой пример. Это реальные логи, которые вытащены из разных сервисов, из разных приложений у разных команд.
Отсутствуют необходимые права. Здесь сервис пытался сделать запрос на получение некоторого уведомления, но для конкретного пользователя он не смог этого сделать, потому что ему их нельзя показывать. У него 403 код ошибки.
Казалось бы, зачем здесь делать ошибку. У пользователя нет прав – это нормально. Почему бы нет?
Вот еще один пример из похожей серии – «протухла» сессия. В браузере сессия может «протухнуть». Например, пользователь может открыть ее в новой вкладке. Самое главное, что это вполне естественная ситуация для нашего приложения, когда вдруг token пользователя перестал быть действительным. Но тем не менее эта штука логировалась с уровнем error.
Давайте еще посмотрим пример. Это тоже довольно частая штука, когда что-то мы не нашли в каком-то кэше. В данном случае здесь был кэш организации. И в нем мы не смогли найти нужного абонента с каким-то идентификатором.
Что значит, что данные не нашли в кэше? Это значит, что мы в какой-то момент пойдем в другое хранилище. Из него, может быть, помедленней прочитаем данные, но в целом мы сможем эту ситуацию разрулить.
Каких ошибок может быть много? Например, ошибки валидации. Это ошибки пользовательских данных. Нам отправили что-то нехорошее. Мы поняли, что это что-то нехорошее, но зачем-то залогировали с уровней error.
Вот еще пример довольно хитрой ошибки. Не очень очевидно, почему не нужно логировать как error.
Давайте представим, что это у нас не один сервис, а некая цепочка сервисов. У нас есть API-сервис, куда приходят пользовательские запросы. Далее запрос направляется в backend. Из этого backend запрос идет, например, в storage service.
Предположим в storage-сервисе произошел отказ. Все, этот сервис не работает.
Соответственно, в цепочке, перед которым стоял сервис, он тоже не может адекватно обработать запрос пользователя. И тоже запрос завершается ошибкой.
Здесь целые 3 ошибки, хотя, казалось бы, что то, что есть проблема можно было понять по одному сервису.
И таких примеров разнообразных очень много.
Классификация (не)ошибок
И если попытаться их все классифицировать, то можно выделить следующие.
Первое – сервис самостоятельно «поборол» ошибку. Это то, что мы видели на примере непопадания в кэш, когда данные выпали из него, а также когда мы сделали успешный retry, т. е. это те вещи, когда сервис столкнулся с какой-то проблемой и сам с ней справился. Зачем будить разработчика, зачем его трогать, когда сервис самостоятельно может это разрулить?
Дальше – это часть сценария. Когда ошибка в сценарии – это нормальная ситуация. Например, то, что у пользователя нет прав или то, что валидация не проходит. Это нормальная ситуация. И в этой ситуации тоже нет смысла логировать это как ошибку.
И то, что чаще всего любят использовать инженеры, это то, что проблема не на нашей стороне. Например, два сервиса. Наш сервис работает. Мы делаем запрос к тому, который не работает и находится в зоне ответственности другой команды. У них проблема возникла, зачем нам просыпаться и реагировать на проблему, когда это должен делать кто-то другой? Это логично.
Но что в этой ситуации нужно делать? Если ошибки такие возникают, то понятно, что мы промахиваемся в кэш очень часто и об этом было бы неплохо узнать. Помогают в этом нам метрики.
Я бы сделал отсылку к двум методологиям. Это USE-методология и RED-методология. Обе эти методологии содержат метрики по ошибкам, которые позволяют нам понять по типам ошибок, по их частоте возникновения, по количеству. Эти метрики позволят нам как-то ретроспективно (не обязательно ночью вставать и чинить) посмотреть, в чем у нас конкретно проблемы, какие настройки надо потюнить и, может быть, исправить какие-то баги.
Возможно, когда у пользователя не оказалось прав – это просто баг в коде. Мы не должны были делать запрос, когда уже понятно, что у пользователя нет соответствующих прав. Это вопрос уже к тому, как написан код.
Хороший пример для цепочки микросервисов – это использование трассировок.
Трассировками у нас инструментированы все наши микросервисы. Они позволяют по идентификатору трассировки построить дерево запросов и понять, где проблема возникла.
Если у нас в каком-то месте есть ошибка, то мы информацию о ней можем потом собрать вместе и полный контекст построить. Этого будет достаточно.
Но как с такими не ошибками надо бороться?
Рефакторинг логирования
Бороться можно рефакторингом логирования. В чем он заключается?
Мы открываем наш репозиторий, ищем по нему вхождения, когда мы логировали с уровнем ERROR и меняем на WARNING там, где действительно есть смысл это сделать. Плюс такого подхода в том, что это очень быстро. Вы открыли кодовую базу, нашли все использования вашего логирования. Быстро пробежались. По контексту поняли – делать или нет.
Но здесь есть подводный камень. Качество кода при этом не изменится. Если у вас действительно был в коде баг, а вы его просто замаскировали под WARNING, то ничего не поменяется. Да, ошибок у вас будет меньше. Да, у вас меньше будут просыпаться инженеры по ночам, что хорошо, но качество кода не изменится, что несомненно плохо.
Поэтому есть более продвинутый способ. Я бы его назвал итеративным подходом. Он уже более нацелен на работу дежурного. Когда дежурный вступает на дежурство, ему на первое время доверяем такую задачу, как брать топ ошибок, смотреть, в чем их суть. Если это баги, то, соответственно, их исправлять. Если еще остались какие-то ошибки, то возвращаться в начало и продолжать-продолжать по этому циклу идти, пока не станет совсем хорошо. Плюс очевидный – это улучшение качества кода. Закрываем баги. Это здорово. Но есть существенный минус. Баги бывают сложными, баги бывают непростыми. И это очень медленный процесс, очень долгий путь нужно пройти. При этом надо понимать, что софт при этом продолжает у нас развиваться. С добавлением новых фич мы естественным путем добавляем новые баги. И нужно понимать, что такой путь может продолжаться до бесконечности. Особенно, когда есть хитрые баги, которые вроде и баги, а вроде и нет. И тут важно руководствоваться принципом Парето. Т. е. не пытаться сделать нулевой фон ошибок, но сделать его таким, чтобы жить стало комфортно.
Проблемы
Какие у таких подходов есть проблемы? На самом деле не все так просто, как может в начале показаться.
Проблемы: Ошибки в общих библиотеках и клиентах
Ошибки, которые возникают в нашем коде. Понятно, что поправили баги, поменяли уровень логирования. Все как бы здорово. Но что делать, если код находится в общих библиотеках и в общих клиентах?
Например, вы пользуетесь такой библиотекой и там залогировалась какая-то запись с уровнем error, но вставать ночью на алерт, который пришел, придется вам, а не автору этой библиотеки. И здесь вам нужно привести все свои доводы, чтобы разработчик сменил уровень логирования или что-то поправил. Каждый пытается решить эту проблему по своему.
Давайте посмотрим на примере, как это проявляется и почему, в некоторых ситуациях эти errors для прикладных разработчиков какого-то нашего продукта могут оказаться бесполезными. Это конкретный пример лога. Вот здесь у нас залогировалось как error. Подчеркиваю, что это код из общей библиотеки. И мы видим, то не смогли здесь прочитать какой-то кусочек. С каким-то идентификатором. Из какой-то тачки. Из какого-то дата-центра. С каким-то смещением. И вот почему это произошло. Потому что там 450 код ошибки. Нам, как разработчику, из этого всего полезно только время, когда произошла ошибка. Больше нам из этого ничего не извлечь. Если ERROR перейдет в WARNING, то этого нам будет достаточно.
Нам нужно смотреть на то, что реально влияет на наш прикладной код. Если у нас сервис не сломался, то все хорошо. Если у нас сервис сломался, то по идее логировать ошибку мы должны на своем уровне, на том, который нам будет понятен. Когда мы в алерте прочитаем, что случилось, тогда нам будет понятно, что нам делать. И не нужно будить в данном случае разработчика этой библиотеки или сервиса, к которому мы обращаемся и спрашивать: «Что здесь произошло? Что с этим дальше делать?».
Еще один пример на уровне взаимодействия команд. Если мы говорим про большую продуктовую команду, которая, может быть, поделена на подкоманды, или это взаимодействие на уровне разных проектов, т. е. когда взаимодействий очень много, то это означает, что какие-то сервисы, которые находятся в одной цепочке, находятся в зоне ответственности разных команд.
Теперь представьте ситуацию, что у этих команд разная культура, у них разные практики, у них разная развитость инструментов, которыми они пользуются. И несмотря на то, что мы какие-то общие инструменты предлагаем, все равно так или иначе команды отличаются в своей работе.
Например, вы пользуетесь чужим сервисом. У вас очень хорошо развиты инструменты. Вы очень быстро узнаете о всех проблемах. А у команды того сервиса, который вы используете, ничего этого нет. И это означает, что вы о проблемах будете узнавать раньше, чем ваши коллеги. И, соответственно, вся польза от этих инструментов сводится на нет. Потому что вам придется идти к другой команде и говорить: «Ребята, у вас есть проблема». Они: «Сейчас будем разбираться». И этот процесс может затянуться.
Поэтому очень здорово, когда уровень развитости этих инструментов и культура одинаковые. На практике такое, конечно, встречается очень редко, поэтому это нужно иметь в виду.
В этой истории есть еще и обратная сторона. Не только проблема в том, что мы раньше узнали о какой-то проблеме, а также в том, что какие-то разработчики позаботились о том, чтобы получить нужные алерты и понимать, что есть ошибка, а что нет, а другая команда может это по-разному интерпретировать.
Например, вы рассчитываете, что другой сервис будет работать и у него всегда будет возвращаться успешное выполнение какого-то запроса. А другая команда считает, что она может позволить себе довольно большой error budget. И в этой ситуации пригодится умение договариваться, чтобы решить данную проблему.
И на протяжении долгого времени мы решали эти проблемы.
Результаты
К чему мы в итоге пришли?
У нас появились команды, которые живут с нулевым фоном ошибок. Если вы столкнетесь с командой перфекционистов и дадите им инструмент Sentry, то не беспокойтесь, там они будут держать все на нуле. Но это, скорее, исключение, чем правило.
Как правило, команды приходят к такой ситуации, когда у них сгруппированных ошибок несколько в день возникает.
Вот пример, как рефакторила свои ошибки одна из команд. У них было 100 000 ошибок в день. Это не сгруппированные, это events отдельные. Они после проведенных работ свели это количество до 300 в день. А после того, как эти ошибки сгруппировались до однотипных вещей, то оказалось, что сгруппированных ошибок всего единицы, условно, до 10. И такое проявилось у многих команд. Это здорово.
Но не все так просто. Не всегда все завершается happy end. Были такие команды, которые не смогли это сделать по разным причинам:
Либо они пользуются инструментами, на которые они не смогли никак повлиять с точки зрения логирования и там сыплются ошибки.
Либо это могут быть какие-то внешние вещи. Может быть, какие-то внешние базы данных или еще что-нибудь.
Либо это команды, которые в рамках своего процесса разработки не могут выделить достаточное время.
За это людей сложно осуждать, потому что в некоторых проектах может быть дремучее legacy, которое делали 10 лет назад и которое просто работает – не трогай! И никто не хочет с ним разбираться, и что-то там менять. Такое бывает.
Цифры
Что мы в итоге получили, если говорить в цифрах?
Всего логов на данный момент у нас 150 000 в секунду. Через pipeline Sentry – это 100 000. Понятно, что туда попадают все логи: INFO, WARNING, ERROR. Их мы уже отфильтровываем. И до Sentry отдельные events с уровнем логирования ERROR или FATAL доходят уже около 75 в секунду.
И пришло время рассказать, почему же так важна для нас инсталляция этого сервиса на нашей стороне, а не использование облачного варианта. Есть team plan. В Sentry самый дешевый – 26 баксов в месяц. И в подарок дают 50 000 ошибок. Казалось бы, это копейки. Особенно для такой крупной компании как Контур.
Если хотите больше, то в их калькуляторе можно докрутить до 6 000 000 ошибок за месяц. И за это нужно заплатить + 820 баксов. Казалось бы, деньги тоже не очень большие. Это меньше, чем зарплата одного разработчика.
Но давайте посмотрим. Есть 75 ошибок в секунду. А сколько же это будет в месяц? А в месяц, если перемножить секунды, часы, дни, то мы получим около 200 000 000.
И напомню, максимум, сколько можно выжать – это 6 000 000. То, количество ошибок, которое мы сейчас запустили, очень большое. И если это отправлять через облачный сервис, то на него расходы будут космические.
Инциденты
Но это еще не все. 75 ошибок в секунду – это нормальный средний фон. Но иногда у нас случаются инциденты.
Я для примера взял случайный день, когда был инцидент. И этот график показывает, сколько логов мы зарезали из-за превышения лимитов, которые мы выставили на команды.
Оказалось, что за какие-то 3 минуты мы зарезали 300 000 ошибок. И если бы эти данные шли не через наш pipeline, где у нас выставлен этот троттлинг, то мы бы в Sentry докинули вот это количество ошибок.
И при этом нужно понимать, что если взять какие-нибудь инциденты покрупнее, то за пару тройку таких инцидентов мы уйдем далеко в космос.
Рецепты алертинга и работа дежурного
Но не все так плохо. И, наверное, имеет смысл говорить о том, как у нас устроен алертинг и о том, как поменялась работа дежурных.
Алерты
Давайте начнем с алертов. Здесь я буду говорить на примере одной из команд. И здесь я призываю не смотреть на конкретные цифры, которые настроены в алертах, а больше смотреть на тот подход, который был выработан.
У команды настроен алерт на ошибку, если она появилась больше 10 раз за минуту. Здесь важный момент не в том, что их 10 раз. Это эмпирически определенное значение, когда команде комфортно с этим значением жить. А тут важно, что не на каждую первую ошибку нужно реагировать. Нужно понимать, что есть какой-то бюджет на ошибки и нужно реагировать с каким-то порогом. Это важный момент, который нужно для себя отметить.
Второй важный момент – это то, что у нас новая ошибка тоже проявилась несколько раз. В данном случае у команды выбрано 3 раза за минуту. Обратите внимание, что здесь не на первую же ошибку мы сразу реагируем, а мы ждем некоторое время. Проявилось 3 раза за минуту, значит надо на нее реагировать.
И тут важно понять, что наша реакция срабатывания на новые ошибки должна быть более оперативной. Здесь порог находится более низкий.
И третий тип алертов – это алерты на ошибки, которые переоткрылись. Мы когда-то столкнулись с ошибкой, мы ее исправили, зафиксили. Зафиксили нашу ошибку в Sentry. Все, этой ошибки нет, она не проявляется-не проявляется, а потом – бах и она в каком-то релизе снова проявилась. Воскрес этот зомби.
И тут нужно сразу реагировать, потому что не понятно, с чем это связано. Может быть, мы покатили некорректный релиз не из той ветки или еще что-то. И тут нужно реагировать как можно быстрее.
Как реагировать на это? Нужно понять, какими способами нам важно доставлять наши алерты.
Алерты можно доставлять в Sentry разными способами. Я выписал 4 способа, которыми у нас пользуются команды.
Это:
- Slack,
- Электронная почта,
- Telegram,
- Pushover.
При этом важно понимать, что в зависимости от критичности алерта можно использовать разные каналы доставки.
Например, одна из команд пользуется Slack и Pushover. Slack для всех-всех алертов, а Pushover для самых критичных, которые надо агрессивно доставить на телефон разработчика, чтобы он гарантированно смог его прочитать и дальше начать реагировать.
И тут резонный вопрос: «Как понимать, какие алерты важные, какие неважные и как их вообще дифференцировать?». Самое главное, что важно делать, нужно обогащать наши events, которые мы отправляем тегами и атрибутами в Sentry. Что это может быть? Во-первых, название сервиса. У нас есть какие-то критичные сервисы, без которых не работает наше приложение. И если в нем возникают алерты, они, наверное, важные. Если это какой-то вспомогательный сервис, без которого мы можем жить и там graceful degradation происходит, то почему бы и нет?
Второе, что приходит на ум, это окружение. Если что-то произошло на staging, то, кажется, что будить разработчиков вовсе не надо. Да, какой-то алерт мы можем получить в Slack, чтобы разработчик или тестировщик на это отреагировал, но в целом какой-то необходимости оперативного реагирования на не продакш-окружении нет.
Также это могут быть различные идентификаторы пользователя. Понятно, как добыть его в нашем коде. Другой вопрос: «Как его потом использовать?». На самом деле Sentry позволяет группировать события не только как события-ошибки, но она еще отмечает, как часто эти ошибки возникают и у какого количества пользователей.
И если мы в Sentry видим, что ошибка проявилась у большого количества пользователей, то нужно бежать исправлять. Если у малого количества пользователей, то, может быть, там можно подождать и как-то в рамках наших SLA с этим жить.
Таких вещей, которыми можно обогатить, довольно много. И не все зависят оттого, как мы написали свой код, что мы внутри делаем, что используем. Здесь на свой вкус можно выработать разные методологии.
Инструментарий дежурного в 2019 и в 2020 годах
И если смотреть, как благодаря таким алертам поменялась работа дежурного, то имеет смысл посмотреть, как изменился инструментарий дежурного, т. е. чем раньше пользовались и чем пользуются сейчас.
В 2019-ом году стандартным набором инструментов для дежурного были: Алерты от Moira и активный мониторинг.
Алерты от Moira – это такая точка входа. Разработчику пришел алерт, допустим, в Telegram или в Slack. Он открыл, посмотрел графики в Grafana. Посмотрел, что по метрикам происходит. И уже дальше пошел разбираться по логам в Kibana.
В случае релизов, как недавно приводил пример, если начали сыпаться ошибки в нашем наколеночном инструменте или даже в Kibana, то нужно быстренько бежать и что-то делать.
Что изменилось в 2020-ом году? С точки зрения Moira ничего не поменялось. Это также остается основным инструментом информирования о каких-то аномалиях и внештатных ситуациях.
Но при этом к этому добавились алерты от Sentry. Если раньше нужно было сидеть и активно мониторить, т. е. глазами смотреть, что меняется, то сейчас мы человеческий фактор убрали и за нас это делает Sentry.
Казалось бы, здорово, но надо понять, насколько здорово.
Аналитика факапов 2
И тут мы как раз переходим к следующей части – аналитика факапов на переходном периоде, когда не было Sentry – появился Sentry.
Это на примере одной из команд, которая хорошо документирует свои факапы и делает выводы. И поэтому по этой аналитике можно попробовать сейчас пробежаться.
За первые полгода 2019-го года, когда они еще не использовали Sentry, у них произошло 26 инцидентов, которые зафиксировали в post mortem.
К сожалению, 3 из инцидентов были недостаточно значимыми и по ним не заполнили толком post mortem, поэтому по ним сложно какой-то вывод сделать, но по остальным было все заполнено хорошо, и мы можем их проанализировать.
3 из них были пойманы по алертам по метрикам, т. е. это то, что я говорил про Moira как инструмент алертинга по метрикам. Были пойманы, быстро локализованы и проблему быстренько разрешили. Здорово.
1 инцидент был пойман случайно. Случайно – это означает, что разработчик просто зашел в Kibana посмотреть логи и вдруг увидел какую-то аномалию или целенаправленно смотрел в инструмент своими глазами. Это случайные вещи, которые зависят от человеческого фактора.
Если посмотреть на все остальные, то оказалось, что как раз сама команда их не поймала. Что это означает? В лучшем случае – это было сообщено другой командой, которая пользуется сервисами этой команды. В худшем случае – это пользователи обратились в техподдержку, и мы узнали через очень долгий путь. И, возможно, прошло очень много времени. Понятно, что такой простой может даже измеряться днями. В этом нет ничего хорошего.
Давайте посмотрим, что бы было, если у ребят был бы Sentry. Оказалось, что то, что поймали случайно, вполне можно бы отследить в Sentry. А 9 и 19, которые были не пойманы командой, они вполне могли быть отловлены при помощи инструмента Sentry. Кажется, что это здорово.
Давайте посмотрим, что изменилось за следующий год. Эта статистика примерно за полгода, т. е. это весна, лета, осень. Это то, что попало на период полномасштабной пандемии.
За это время случилось 19 инцидентов. Тут количество сравнивать бессмысленно, потому что оно зависит от многих факторов. Важно смотреть, как с этими инцидентами работали.
5 из них были пойманы случайно. Это когда разработчик куда-то зашел и посмотрел или, может быть, мониторил. Но важно, что это было обнаружено не при помощи наших автоматизированных инструментов.
6 из этих инцидентов не были пойманы командой. Это другая команда могла сообщить или пользователи обратились в техническую поддержку.
5 инцидентов были пойманы при помощи метрик.
И 3 инцидента были пойманы по ошибкам, т. е. при помощи инструмента Sentry.
И это уже радует. Радует, что инструмент приносит пользу.
Но тут важно отметить, что неизвестно, сколько инцидентов удалось избежать. Я говорил о том, что если появится Sentry в командах, то 10-15 % инцидентов можно избегать.
Посмотрим, как дальнейшее развитие инструмента Sentry, а также доработка алертов, ошибок логирования могли бы помочь командам.
Аналитика показывает, что большую часть из этих инцидентов еще можно было бы поймать с использованием Sentry.
Пойманных случайно – 2 из 5. Все 6, которые не поймали сами команды, могли бы поймать с помощью Sentry. И то, что было поймано по метрикам, можно было поймать с помощью Sentry. Но не просто поймать, а поймать быстрее, т. е. реакция была бы быстрее. И ситуация до факапа доведена бы не была. И это действительно здорово. И есть, куда еще расти и как еще развиваться.
Выводы
Подведем выводы. Мы проделали большую работу. У нас на протяжение 2 лет что-то менялось. Какие выводы мы сделали?
В первую очень мы, как строители инфраструктуру, сделали такой вывод, что в действительности инфраструктуру, которую мы делаем, нельзя по умолчанию давать всем. Команды, которые ее используют, должны быть к этому готовы. Это такой факт, с которым приходится жить.
Второй вывод – те изменения, которые мы хотели сделать, они кажутся для нас незначительными, т. е. мы предоставили новый инструмент – ребята пользуйтесь, но в действительности нужно понимать, что с точки зрения команд это может потребовать много времени. Потому что то, что мы хотим, оно не вписывается в бизнес-план, где нужно закрыть какое-то количество бизнес-фич. И поэтому эти изменения могут отнимать очень и очень много времени.
И самое главное, что так просто команды это не смогут сделать. Им нужно помогать. Нужно терпение. Нужно приходить к ним, предлагать помощь. Нужно с ними взаимодействовать. И soft skills здесь нужно прокачивать по максимуму. И с этим приходить в команду, и пытаться им помочь, чтобы они быстрее смогли дотащить до релиза какие-то новые вещи, потому что мы хотим, чтобы наши продукты были надежными и качественными.
И уже несколько раз я делал отсылки к post mortems, которые мы заполняем. И в действительности они помогают делать полезные вещи. Они помогают улучшать существующие продукты, помогают находить новые инструменты, которые могут решить проблемы. Это здорово и всем рекомендую.
Если говорить о выводах, касательно Sentry и того, что вокруг него произошло, то самый главный – это то, что нельзя просто так взять и использовать Sentry. Нужно брать и менять полностью подход к логированию. Нужно провести огромную работу. Но это необходимая вещь, если вы хотите пользоваться таким инструментом.
В целом мы намучались с Sentry. Можно целый доклад сделать о том, с какими проблемами мы сталкивались с точки зрения эксплуатации Sentry. Когда мы добавили свою трубу Hercules к нему, то все стало вполне не плохо и с этим можно жить.
И сейчас мы продолжаем развивать Sentry. Мы продолжаем развивать команду с точки зрения работы с ошибками. Мы анализируем факапы. И пытаемся двигаться все дальше и дальше, чтобы делать наши продукты качественнее.
На этой позитивной ноте я хотел бы закончить. Всем спасибо за внимание! Давайте перейдем к вопросам.
Q/A
Вопрос: Ты говорил, что инженеры сидят, обвешавшись кучей мониторов. И постоянно смотрят на графики, выискивают ошибки. Ты преувеличивал или серьезно люди так сидели и этим занимались?
Ответ: Те фотографии, которые я показал, это не наши фотографии. Это фото из блога другой крупной компании. И там они действительно сидят и круглые сутки смотрят в мониторы. У нас активный мониторинг был в момент релизов. Разработчики целенаправленно смотрели в логи – появились там ошибки или нет. Это было реально.
Вопрос: Дежурные 24х7 не сидят и не смотрят в мониторы, потому что у них есть алерты? А до этого сидели?
Ответы: Ночью, конечно, никто не сидел. И алерты изначально были попроще, т. е. наколеночные через почту. И разработчик от почтового уведомления вряд ли будет просыпаться, потому что не настроены на почтовом клиенте такие возможности. И поэтому был важен алертинг, который можно настроить по различным каналам с разным уровнем навязчивости. И если даже у тебя телефон в беззвучном режиме, ты все равно узнаешь, что пришло уведомление. Pushover проигнорирует все твои настройки в телефоне. И это здорово. Это те вещи, которые позволяют командам в любой ситуации достучаться до инженеров.
Вопрос: Как долго вы шли к тому, чтобы соотношение сигнала с шумом привести хоть к какому-то приличному состоянию?
Ответ: Если говорить в целом за всех, то среднюю температуру по больнице очень сложно посчитать. Есть те команды, которые до сих пор не пользуются Sentry. У них трафик не идет еще в Sentry, потому что мы не можем их туда пустить, т. к. Sentry треснет. Те команды, которые пустили, живут нормально. И благодаря рычагам, когда можно поднять порог срабатывания алерта, они это настраивают. В целом это заняло полгода, если не ошибаюсь. Это долгий период, потому что нужно пережить несколько релизов, чтобы произошло несколько значимых инцидентов, потому что без примеров проявления очень сложно понять, что, например, я поставлю 10 ошибок в минуту и мне будет хорошо. Нет, так не получится.
Вопрос: Означает ли это, что нужно делать так, чтобы в error выводились только те сообщения, которые требуют непосредственной реакции инженера? Т. е. если поднимать инженера в 2 часа ночи не нужно, то это значит не error?
Ответ: В идеальной картине мира это так должно быть. Понятно, что на практике это сейчас не так. Поэтому я и говорю, что ошибки, которые у нас есть, они с некоторым порогом срабатывания. И практика показывает, что нужно задавать бюджет на ошибки, с которым нужно смириться и с которым нужно жить. Хотя не отрицаю, что у нас есть команды-перфекционисты, которые с нулевым фоном ошибок живут.
Вопрос: Мы, когда на production проводим тесты, не по внешним пользователям, а внутри проводим тестирование и видим, что могут быть ошибочные сценария или еще что-то. Но ошибки, которые возникают в результате таких действий, тоже будут проходить через все стандартные операции и будут поднимать инженеров. Как с этим жить? Так и должно быть или нужно как-то игнорировать?».
Ответ: Это очень прикольный сценарий. И действительно о нем стоит поговорить. Если мы делаем какие-то тестовые сценарии, то мы делаем это либо с какими-то тестовыми пользователями, либо мы как-то иначе можем сообщить нашей системе, что это какой-то прогоняемый тестовый сценарий. Это означает, что мы можем наши events снабдить каким-то полезным свойством. Допустим, user ID, который тестовый. А уже непосредственно в алертах мы скажем, что идентификатор такой-то должен ровняться тому то, и тогда алерты не надо отправлять, либо отправлять, но в отдельный Slack-чат, в котором сидят релиз-менеджеры или тестировщики.
Вопрос: Получается, вы пытаетесь какой-то контекст захватить из тех ошибок, которые Sentry вам выдает. Насколько широко вы можете захватывать контекст и кастомизировать его? И насколько вы можете привязать к какому-то upstream-контексту? Например, есть у нас несколько микросервисов. От одного приходит запрос в другой. Может быть, еще по цепочке в третий. И контекст из первого с помощью Sentry вы можете захватить?
Ответ: Это очень хороший вопрос. Из коробки в Sentry мало что можно сделать. Надо все дотачивать. Что сделала одна из команд? Они написали решение к Chrome, которое при открытии странички в Sentry просто хачит html, который есть, вставляет ссылки на другие инструменты. И ты просто открываешь ошибку в Sentry. Нажимаешь ссылку, которая добавила расширение к Chrome, и переходишь в другой инструмент. И ты, допустим, увидишь трассировку или логи, которые относятся ко всей трассировке, т. е. по всем сетевым взаимодействиям, чтобы ты мог уже по ней как-то дальше работать.
Вопрос: А трассировку вы через что выстраиваете? Какой инструмент используете?
Ответ: Если вернуться к истории о том, как у нас все это возникало, то здесь у нас собственный инструмент. Это труба, через которую у нас вся телеметрия идет — Hercules. Там как раз у нас и трассировки, и все прочее. И дальше есть приложение, которое умеет правильно отдавать эти трассировки, есть веб-морда, в которую можно зайти и построить дерево запросов. Можно провалиться в нужный span, посмотреть, что в нем произошло. Понятно, что раз какие-то инструменты мы делаем сами, то там усилия не как у большого community, но мы это продолжаем развивать. Там появляются новые инструменты. Допустим, недавно сделали новую штуку, которая позволяет по идентификатору трассировки получить все логи, которые у нас есть во всех индексах Elastic. У нас там десятки команд в разные индексы пишут. А произошла конкретная ошибка, можно пойти и собрать всю информацию. Это очень прикольная штука. Мы ее пытаемся продавать командам, чтобы они начинали этим пользоваться.
Вопрос: Андрей интересуется, каким инструментом вы умудряетесь поднимать из сна инженеров, у котором в беззвучном режиме телефон. Ты говорил слово «Pushover», это он?
Ответ: Я сам Pushover не пользуюсь. Я говорю со слов разработчиком, с которыми я говорил. Они пользуются Pushover. И он умеет довольно агрессивно доставлять уведомления. И они вроде бы еще продолжают этим инструментом пользоваться.
(Глеб) Могу добавить, что в PagerDuty на android, например, средствами операционной системы может указать, что приложение нужно добавить в исключение. И если ты в режиме «Не беспокоить», то все равно делать алерты. На iOS эта фича не работает. По крайней мере, в последний раз, когда я пытался это включить, не получилось. И поэтому, если дежурил, то нужно было включать уведомления и приходило что-нибудь другое обязательно.
Вопрос: Те, кто дежурят, они код разрабатывают или они только дежурят?
Ответ: Нет, у нас, как правило, люди, которые пишут код, они же и дежурят. Я не буду сейчас говорить за все команды Контура, потому что их сейчас примерно 80, поэтому сложно сказать. Я могу сказать про тех ребят, которых я знаю. У них идет ротация. Даже в моей инфраструктурной команде я и код пишу, и периодически тоже дежурю. И сейчас у меня неделя дежурства. Надеюсь, пока мы сейчас с вами ведем диалог, у меня ничего не сломается и не случится. У меня все уведомления отключены, никакой Pushover ко мне не прорвется, потому что мы его не используем в нашей команде.
Вопрос: А если это случится, то какой у вас протокол работы? У вас есть запасной дежурный, если первый не проснулся или доклад читает?
Ответ: Это в разных командах по-разному. Есть primary-дежурные, backup-дежурные. У меня не очень большая команда. И если ты не можешь в какой-то момент дежурить, ты просто в чатик пишешь: «Ребята, пару часов меня не будет. Пожалуйста, подмените». Сознаюсь, я забыл это сделать. Но я вчера ребят предупредил, что я буду занят. Может быть, они сами догадались. Все-таки человек – это сложная нейронная сеть, которая может понять, что нужно дальше с этим что-то делать.
Вопрос: А по ночам кто дежурит? Специально обученные люди дежурят?
Ответ: Это зависит от размеров команд. Если это большие команды, то у них такая ротация, что ты дежуришь очень редко. Например, одну неделю раз в полгода. Или полнедели ты дежуришь, полнедели кто-то другой и т. д. А так получается, что ночью ребята реагируют. Но на моей памяти в моей команде ночью был факап, но там был другой дежурный. Другой просыпался, мне везло.
(Глеб) Во всяких больших корпорациях, у которых много офисов в разных географических локациях, можно устроить ротацию следующим образом: 8 часов в Европе, 8 часов в Австралии, 8 часов в Штатах. И у всех – это просто рабочее время. И они передают дежурство следующей команде, и никому ночью в нерабочее время дежурить не приходится. Это очень удобно. Но нужно иметь серьезно распределенную географию для этого.
Вопрос: Ты рассказывал про случай, когда ошибка ретраится и успешно проходит. Как в подобных случаях нужно писать код? Мы сделали единичный запрос. Он упал. Нам не в ошибку его писать? А когда в ошибку запишется?
Ответ: Это зависит от того, как код устроен. У нас есть различные библиотеки, которые умеют понимать идемпотентные или неидемпотентные запросы, можно ретраить или нельзя ретраить. Это довольно сложная логика. И как эти запросы делать? Некоторые запросы можно делать параллельно, некоторые последовательно, некоторые чуть-чуть подождать и отправить. Логика может быть очень сложной.
Как она выглядит у нас? Делаются последовательно запросы к одной реплике. Получилась ошибка. И мы ее как ошибку не логируем. Делаем еще один запрос к другой реплике. Если там завершилось успешно, то мы в конце никакой error не делаем. А если все-все наши попытки закончились не успехом, то мы ее тогда логируем как error. И здесь уже вступает в дело error budget. Т. е. мы смотрим по количеству ошибок, которые возникают. Если их было много, то алерт нужно делать. Если их не очень много, то, соответственно, алерт не надо делать.
Вопрос: Т. е. в двух местах настраивается. Во-первых, на стороне источника ошибки. Там есть какой-то retry. И если не упадет, только тогда будет писать. А, во-вторых, есть какой-то tracking error budget. И где он происходит? На стороне Hercules или где-то в Sentry встроен?
Ответ: Нет, конкретно по срабатыванию по какому-то порогу – это в Sentry. Там есть отдельный раздел, где ты можешь алерт rules настраивать. И там ты можешь указать, как часто должна та или иная ошибка проявиться. Язык не очень богатый. Ты можешь сказать, что у меня вот это, вот это и вот это. И если нужно тонко настраивать, то много отдельных алерт rule нужно делать. Их сложно перемежать между собой. Но в целом это можно сделать.
Вопрос: Я тут поясню вопрос. Мы говорили, что алерты появляются из ошибок, из error, а из warning, info и debug вы алерты поднимаете?
Ответ: У нас то количество ошибок, которое приходит, его уже очень много для Sentry. Если делать еще больше, то начинает трещать. Когда, мы пробовали так делать, то мы жестко ограничивали. Что выше уровней, которые более слабые, чем error, мы в Sentry не отправляем. Понятно, что туда можно и warning отправлять, это даже стандартный клиент Sentry позволяет сделать. Но мы такое не делаем. Тогда нам станет еще больнее в разы.
Вопрос: Ты говорил про количество ошибок, которое отправляется в Sentry, но ни разу не говорил про их размер. Вы как-то лимитируете размер текста сообщений stacktrace, которые вы отправляете в систему или у себя внутри обрабатываете?
Ответ: Сейчас не вспомню. По-моему, порядка 64 килобайт размер одного такого события, которое попадает в Sentry. Это максимальный размер, насколько я знаю. Могу ошибаться. У нас особых ограничений вроде бы нет, а про Sentry даже не вспомню.
(Глеб) Мне Володя смешную историю напомнил про размер stacktrace. Я в Флубори долгое время работал. И мы там тоже делали emp, который тоже ошибки захватывает и т. д. И у нас была такая проблема, что к нам прилетела ошибка с гигантским stack. Не знаю, насколько строк. Мы начали его обрабатывать, парсить рекурсивно и схватили stack overflow error, пока пытались обработать этот гигантский stack. В итоге раскрутили рекурсию и все стало нормально. Это жизненная проблема.
Вопрос: Я, допустим, разработчик. И пишу ошибку, например, log что-нибудь. Она же может устареть. Бывает такое, что ошибка говорит об одном, а по факту код немножко поменяли, он уже немного другой. И, соответственно, человек, который смотрит на этот лог, говорит, что у вас не хватило connection в базе. А на самом деле совсем не так. У вас такое было? И как с этим боролись?
Ответ: Я почти уверен, что такое происходит, потому что проблема актуализации логов в коде вполне естественная, она часто встречается. Но каких-то ситуаций, как с этим бороться с ходу не придумаю.
Вопрос: А если я, как разработчик, пишу невозможную ситуацию. В этой дефолт-ветке нужно ли какое-то развернутое сообщение писать или достаточно сказать, что без параметров, т. е. AssertionError – ситуация недостижима?
Ответ: Без какого-то контекста, мне кажется, это очень плохо делать и опасно. Когда возникают такие ситуации, ты примерно сталкиваешься с такой штукой, что без того, чтобы зайти в код и посмотреть – какая же это строчка кода и что там произошло, — не разобраться. И, кажется, что если в логе есть достаточно информации для того, чтобы понять, где конкретно проблема, это намного большой плюс в карму того, кто писал лог в данном месте.
(Глеб) Мне приходит в голову мудрое изречение, которое мне сказал старший коллега по работе, когда я писал логи. Он на мои логи посмотрел и сказал: «Глеб, когда я пишу логи, я задаюсь одним вопросом: «Кто их будет читать и в какой ситуации?»». Если задаваться этим вопросом каждый раз, когда что-то пишешь и выбирать, как логировать, то я понял, что действительно зачастую это очень полезно. Может быть, в будущем я буду читать эти логи в ситуации, когда 4 утра и ни фига не понятно. Поэтому нужно позаботиться об ближнем своем.
(Григорий) И ты заботишься не только о ближнем своем, скорее всего, ты будешь заботиться о себя в будущем.
Вопрос: Давайте позаботимся о себе в будущем. И у меня такой вопрос. Глеб, что ты думаешь про реестр ошибок, чтобы добровольно принудительно каждую ошибку снабжать каким-то кодом ошибки, который будет уникальным в рамках всего проекта, всех компаний, всех компонентов?
Ответ: Это не так просто. Во-первых, Гриша упоминал в своем докладе про группировку ошибок и о том, что можно какие-то паттерны выбирать, матчить их и т. д. Но автоматически это не просто сделать. Это значит, что здесь должен быть где-то человеческий фактор, который будет выбирать, какая ошибка и к чему относится, а также какая у них группа и т. д. И там, и там будут ложные срабатывания. Будет миллион ошибок. У нас такое тоже было, потому что в теле ошибки был какой-нибудь идентификатор и в результате было миллион разных ошибок, которые на самом деле одни и те же. И их нужно группировать. И наоборот может быть. Случайно сгруппировали то, что не является одним и тем же.
И, может быть, когда системы были более монолитные с очень строгими правилами исполнения, то по коду ошибки более-менее можно было понять в чем дело. Наверное. А в современном мире, когда двадцатка микросервисов в цепочку связывается, то там комбинаторный взрыв. И какой реестр в данном случае ошибок? Кто-то хочет оспорить.
(Григорий) По-моему, здесь спорить особо не с чем. Все так.
Вопрос: У вас есть Sentry, откуда приходят новые ошибки и на них алерты. И, наверное, есть какие-то другие источники. Например, мониторинг того, что на диске достаточно места, мониторинг CPU. Вы каким-то образом все это вместе в каком-то месте интегрируете?
Ответ: У нас исторически получилось так, что основным инструментом с такими алертами была Moira. Это как раз алерты по метрикам. Ребята когда-то давным-давно сделали продукт, его заопенсорсили. И сейчас мы им пользуемся. И с точки зрения метрик завязан на стеке Graphite. И Moira является основной точкой входа. Sentry – вспомогательная точка входа, т. е. когда алерты именно от Sentry идут. Понятно, что основная масса алертов идет от метрик. И какого-то сквозного взаимодействия между сервисами на данный момент нет. Возможно, мы когда-нибудь построим свой космолет, в котором можно будет сразу все-все получить, но пока таких планов на данный момент нет.
И я вспомнил про одну классную штуку. У нас ошибки бывают не только в бэкенде, а бывают еще в фронтенде. И тут начинается самое интересное, т. е. то, как их собирать. И там как раз с группировкой все еще хуже. Я разговаривал с ребятами про те инциденты, которые были в первую половину 19-го года и то, что происходит в 20-ом году. У них есть еще много фронтовых ошибок. Они их собирают с использованием своего собственного бэкенда. У них лог с браузера попадает в их endpoint на их сервере. Там обогащается нужным контекстом. И дальше они уже стандартной трубой отправляют как обычные бэкенд-логи. И вроде бы все хорошо.
Но выяснилось, что группировать ошибки с фронта очень тяжело. Почему? Во-первых, там stracktraces с русским тестом. Мы находимся в России, вроде бы все нормально. Stracktaces с английским текстом – это какой-то стандарт. Все хорошо. Но иногда встречаются stractraces с французским текстом. И с этим очень тяжело работать. Там приходится изобретать то, про что говорил Вова. Надо какой-то реестр ошибок придумывать и там классифицировать их как-то. Ровно этим ребята занимаются. У них классификация ошибок. Когда они получают ошибку на бэкенд с фронта, они смотрят: «Ага, вот это сюда, ее надо таким обогатить контекстом, таким контекстом. А это вообще не ошибка, ее надо выкинуть». С фронта может зациклиться какая-нибудь фигня на Internet Explorer.
Телеграм-чат по Sentry
