Привет! На связи команда Yandex Monium, это вторая часть серии про эффективный мониторинг. Исторически Monium был разработан командой Yandex Infrastructure как внутренняя observability-платформа и использовался для мониторинга критических сервисов внутри Яндекса. В прошлый раз мы рассказали о том, что важно знать про мониторинг в целом, а также рассмотрели подробнее асинхронные задачи. На примере кейса с таинственным зависанием задач мы увидели, как с помощью метрик можно определить не очевидную проблему, вызванную скрытым багом.
Но вполне возможно, что у вас всё взаимодействие происходит через очереди, а не через асинхронные задачи. Асинхронная задача — это операция, которая запускается системой и выполняется независимо от основного процесса, не блокируя его и не требуя немедленного ожидания результата.
Далее в этой статье:
В первой части разберём кейсы на примере in‑memory‑очереди. Это также применимо для различных типов очередей, в том числе для Apache Kafka.
Во второй части перейдём к клиент‑серверному взаимодействию.
Какие метрики важно отслеживать для очередей
Количество сообщений в очереди на данный момент. Если оно растёт, это значит, что потребитель не успевает их обрабатывать, начинается затор.
Размеры очереди в байтах. Это бывает полезно, чтобы не упереться в ограничение по памяти.
Время, которое сообщения проводят в очереди. По этой метрике мы смотрим перцентили. Например, 99-й перцентиль, равный пяти секундам, означает, что 1% самых медленных запросов ждут в очереди пять секунд, прежде чем их обработают. Если время нахождения в очереди увеличивается, то есть консьюмер не успевает обрабатывать, то растёт saturation.
RPS или throughput очереди, то есть сколько сообщений в единицу времени входит в очередь и сколько из неё выходит.
Успехи и ошибки обработки сообщений, но обычно это измеряется уже на стороне консьюмера. Идея простая: если входящий поток превышает способность системы их обрабатывать, очередь начинает расти. Сначала растёт её длина, потом увеличивается время ожидания.
Мониторинг всех этих показателей сможет показать проблему ещё до того, как очередь заполнилась полностью и сервис начнет деградировать.
Проблема: очередь как узкое место
На схеме представлена упрощённая схема работы Monium Metrics:
Приходит запрос, он отправляется в очередь на парсинг, отдельный поток читает из очереди, парсит запрос, формирует новый запрос и сохраняет результат в базу. Вроде бы здесь всё асинхронно и должно работать быстро, но пользователи начали жаловаться на задержки.
Попытаемся найти проблему и решить её. Для этого соберём на дашборде все графики пайплайна запроса. Нам понадобится:
время ожидания в очереди: сколько запрос лежит в очереди, прежде чем его взяли в работу;
время обработки одного сообщения, или время на парсинг;
время записи результата в базу.
Далее попробуем выявить самое проблемное место. Видим, что 99-й перцентиль ожидания в очереди превышает семь секунд.
То есть самые медленные запросы живут очень долго.
При этом 99-й перцентиль парсинга составляет 100 миллисекунд, а 99-й перцентиль записи в базу — где‑то 1,3 секунды. Получается, для того чтобы выполнить всю работу за 100 миллисекунд и записать результат за 1,3 секунды в базу, некоторые запросы проводят в очереди семь секунд. В худшем сценарии надо ждать 8,4 секунды, чтобы работа была выполнена.
Очевидно, что очередь — очень узкое место. Здесь мы делаем вывод, что либо обработчику не хватает процессорного времени, либо он обрабатывает очередь не очень эффективно.
Дальше нам нужно посмотреть метрики консьюмера. Как вообще это можно починить? За счёт оптимизации консьюмера или масштабирования: например, запустить несколько потоков. После масштабирования время ожидания в очереди должно снизиться.
Какой можно сделать вывод из этого кейса? Метрика времени в очереди сразу указала на проблему, которая была в том, что пользователи ждали не из‑за замедленной логики обработки, не из‑за того, что мы долго пишем в базу, а из‑за очереди. Без мониторинга мы могли бы думать, что проблема в базе или в коде парсера, а оказалось, нам не хватило мощности.
Проблема: нагрузка на очередь и рост времени ожидания
Разберём ещё один случай с очередью. Без видимых причин наша система начала получать гораздо больше сообщений, чем обычно.
По метрикам мы видим, что входящий поток резко взлетел с некоторого околонулевого значения до 18 тыс. сообщений в секунду.
Очередь растёт, но не бесконечно, значит консьюмер успевает обрабатывать сообщения. По графикам мы видим, что её размер стабилизировался на уровне где‑то 470 МБ.
Неприятно, память проедается.
Смотрим время ожидания. 99-й перцентиль достиг 15 секунд. Это половина от установленного тайм‑аута ожидания, то есть каждый сотый запрос ждёт 15 секунд, чтобы его обработали.
Очевидно, что мы упёрлись в какие‑то пределы пропускной способности. Помним, что очередь не растёт бесконечно, значит консьюмер пока успевает обрабатывать входящие запросы.
Первая гипотеза — обработчики задыхаются от количества запросов.
Чтобы проверить эту гипотезу, нам нужно понять, а все ли консьюмеры загружены равномерно или на какой‑то приходит очень много запросов и портит нам метрики.
Для этого мы на нашем дашборде меняем параметры с host=cluster на host*. Так мы сможем увидеть и сравнить графики разных хостов. Или же мы можем, как в прошлом примере, перейти в график и смотреть запрос в Metrics Explorer.
Возьмём топ-15 хостов, чтобы не перегружать картинку. На графике мы видим, что у разных хостов разные RPS, а ещё — что очень сильно выделяется хост номер 36. На него приходится 550 запросов в секунду.
Кажется, мы нашли тот самый хост, который не справляется с количеством запросов и портит тайминги. Проверим, так ли это.
В нашем дашборде выберем хост 36 и посмотрим на его тайминги. Если хост не справляется с нагрузкой, мы ожидаем увидеть, что тайминги на нём увеличились.
На этот хост приходится больше всего сообщений в секунду. Но мы видим, что время ожидания в очереди в 99-м перцентиле меньше одной секунды (за исключением нескольких всплесков), а по всему кластеру мы наблюдали 15 секунд. Это значит, что где‑то есть хост с большим временем ожидания и меньшим количеством входящих запросов. Получается, что RPS не связан с этой проблемой, как мы предположили. Сообщения долго обрабатываются не из‑за этой проблемы. Первая гипотеза не подтвердилась.
Вторая гипотеза — проблема в таймингах обработчика. Чтобы проверить вторую гипотезу, найдём хост с медленной обработкой. Для этого возвращаемся на дашборд кластера и смотрим гистограмму ожидания в очереди.
У нас есть бакеты, в которые мы складываем время обработки сообщений. Нам нужно выбрать любой бакет, который больше того, что мы видели в 99-м перцентиле.
Возьмём бакет 16384. Там лежат запросы, которые пролежали в очереди от 8 до 16 секунд. Наши 15 секунд, которые мы видели на кластере, тоже попадают в этот бакет. Наводим курсор на три точки, нажимаем «Перейти к линии».
Там мы ожидаем найти хосты с ��лохими таймингами. Давайте посмотрим, так ли это. Мы перешли к графику в мониторинге и на графике нажимаем кнопку «Разбивка графика».
Выбираем сортировку по среднему и видим, что у нас в топе хост 40. Открываем дашборд этого хоста:
Видим, что в очередь этого хоста поступает 260 запросов в секунду. Это практически в два раза меньше, чем на предыдущем.
Ждут они своей очереди 32 секунды. Мы, похоже, нашли, кто тот самый отстающий консьюмер. Вторая гипотеза оказалась верной.
Дело не во входящем потоке, а в медленном обработчике. На 36-м хосте RPS почти в два раза больше, но запросы ждут меньше одной секунды. Почему так? Возможно, на 40-м хосте меньше ресурсов или хост перегружен другими задачами. Но факт остаётся фактом: из‑за замедленной работы одного экземпляра очередь на нём стала расти быстрее. В итоге 99-й перцентиль по всему кластеру увеличился до 15 секунд.
Что здесь можно сделать? Можно перераспределить нагрузку, то есть выключить или перезапустить медленный хост, чтобы трафик ушёл на другие. Или выяснить, что у него не так. В нашем случае оказалось, что на больном хосте шёл фоновый поток, который отъедал CPU. Мы это устранили, и работа выровнялась.
Что мы должны забрать из этого кейса? Мониторинг очереди плюс умение разложить метрики по хостам позволили быстро найти слабое звено. Главное — мы заранее увидели приближение к лимитам и смогли отреагировать ещё до того, как система упала.
Что учесть в сценариях клиент-серверного взаимодействия
В первую очередь важно помнить: когда у вас клиент‑серверное взаимодействие, нужно смотреть на картинку с двух сторон, со стороны клиента, который инициирует вызов, ждёт ответ и получает его, а также со стороны сервера. Эти две точки зрения дополняют друг друга.
Например, у клиента может расти время отклика, но сервер считает, что он отдаёт ответ быстро. Тогда задержка может быть, например, в сети или в том, что клиент не успевает читать. Другой пример: сервер может начать сыпать ошибками, но у разных клиентов эти ошибки могут проявляться по‑разному. Ещё один простой пример: на сервере падает RPS, и нам нужно понять — это клиент перестал слать запросы или запросы он отправил, но почему‑то до сервера они не дошли.
У нас в системе большинство внутренних вызовов между сервисами идут по gRPC‑протоколу. Поэтому в примерах я буду приводить кейсы с gRPC, но материал справедлив и для других клиент‑серверных взаимодействий, в том числе для HTML.
Какие клиентские метрики собирать
Если мониторить только сервер и не мониторить клиент, то будет достаточно сложно решать многие проблемы. И надеюсь, что после прочтения этой статьи вы пойдёте настраивать мониторинг клиента, если этого ещё нет. Мы рекомендуем замерять метрики как на клиенте, так и на сервере.
Что важно отслеживать:
grpc.client.call.started— сколько вызовов начали выполняться, то есть сколько запросов было отправлено.grpc.client.call.completed— сколько из них завершилось, то есть был ли получен ответ независимо от того, успех это или ошибка.grpc.client.call.status{code=...}— статусы ответов. Это разбивка завершённых вызовов по коду ошибки, по коду статуса. Это очень удобно, когда мы хотим посмотреть, растут ли ошибки определённого типа.
Если к ва�� придёт просто error, нужно будет совершать дополнительные действия, чтобы понять, а какая конкретно ошибка пришла. Придётся лезть в логи и изучать данные, но при правильной настройке это можно увидеть сразу в метриках.
grpc.client.call.inflight— число запросов в работе, которые отправлены, но ответ ещё не получен — это помогает понять загрузку клиента и косвенную загрузку сервера.grpc.client.call.outbound_bytes / inbound_bytes— объём данных, сколько байтов мы отправляем и получаем в секунду.grpc.client.call.elapsed_time_ms— полное время выполнения запроса с точки зрения клиента. Клиент отправляет запрос, запрос обрабатывается, уходит на сервер, сервер выполняет, и запрос возвращается обратно, то есть, по сути, это latency — сколько времени ждал клиент.grpc.client.call.delivery_time_ms— ещё одна неочевидная метрика, время доставки запроса от сервера до клиента.
Прежде чем переходить к примерам, давайте посмотрим, зачем мы добавили дополнительные метрики, которые кажутся не совсем очевидными. На схеме изображено клиент‑серверное взаимодействие:
На клиенте у нас формируется запрос, этот запрос сериализуется и попадает в in‑memory‑очередь для отправки на сервер. Далее запрос передаётся по сети на сервер и попадает в очередь на обработку. Как подходит очередь, запрос десериализуется, вычисляется на сервере и отправляется обратно к клиенту.
Если мы ограничимся elapsed time, то будем знать две метрики: всё время, за которое выполнялся запрос client.call.elapsed time, а также сколько времени запрос обрабатывался на сервере server.call.elapsed time. Если полное время выполнения запроса внезапно выросло, а серверные метрики не изменились, то у нас будет сразу несколько гипотез для расследования. Может быть, у нас медленная сериализация (например, большой размер запроса), медленный сетевой канал, перегружена очередь обработки.
Поэтому мы ориентируемся ещё на две метрики. Это server.call.dellivery_time — время доставки запроса до сервера — и client.call.dellivery_time — время доставки запроса до сервера и обратно до клиента. Эти две метрики включены в метрику elapsed time.
Проблема: клиент генерирует нагрузку
Посмотрим на примере, где это может быть полезно. Все вышеперечисленные метрики клиента мы собрали на одном дашборде.
Представим, что у нас есть высоконагруженный сервис. Клиент генерирует нагрузку на сервер порядка 14 млн запросов в секунду.
Суммарно около 33 ГБ данных в секунду передаётся через сеть. Метрика обработки ошибок сообщает, что ошибок нет.
Но нас смущают метрики времени.
В метриках есть время доставки запроса от сервера до клиента — client.call.dellivery_time. На графике видно, что 99-й перцентиль этой метрики составляет где‑то 200 миллисекунд.
При этом полное время выполнения запроса с точки зрения клиента, от момента отправки запроса до получения ответа, в 99-м перцентиле составляет 500 миллисекунд. Значит, сервер ответ сгенерировал, а клиент получил его на 300 миллисекунд позже. Похоже, что проблема где‑то на стороне клиента.
Воспользуемся приёмом, который мы уже использовали: посмотрим на гистограмме время доставки запроса до сервера и обратно, то есть delivery time.
Нам нужны значения, которые хуже, чем p99, то есть любой бакет больше 500 миллисекунд. Поэтому мы выбираем бакет 512 миллисекунд и нажимаем «Перейти к линии», которая скрывается за тремя точками.
Мы ищем самые медленные хосты. Для этого разобьём график по метке «Хосты», отсортируем по среднему значению.
Тут мы видим, что интересующие нас хосты — это 34, 361 и 10.
Возвращаемся к нашему дашборду и выбираем хост 34.
Видим, что время обработки запросов с этого хоста в 99-м перцентиле — одна секунда. А время на получение готового ответа от сервера — 400 миллисекунд. Похоже, что‑то происходит на клиенте. Например, тут может произойти истощение ресурсов, которое сказывается на таймингах. Давайте проверим эту гипотезу.
Мы используем gRPC‑протокол для клиент‑серверного взаимодействия, чтобы не блокировать основные воркеры, которые используют пул потоков для обработки операций ввода‑вывода. Он называется I/O ThreadPool.
Если I/O ThreadPool загружен, то сообщения из сокета не читаются. А если сообщения не читаются, то копится delivery lag. Очень похоже, что мы только что увидели delivery lag на дашборде. Давайте посмотрим метрику загруженности ThreadPool для хоста 34. Для этого открываем Metrics Explorer и вводим запрос.
Там же мы добавили функцию histogram_percentile, чтобы посмотреть значение метрики на заданном перцентиле. На графике видим, что в 99-м перцентиле задержка ThreadPool составляет примерно полсекунды.
ThreadPool может обрабатывать запросы с задержкой, если в нём много задач или ему не выделили процессорного времени, потому что какие‑то другие фоновые процессы отъели ресурс. Дальше для оптимизации времени можно покопаться в нагрузке ThreadPool или добавить потоки.
Итак, что нужно взять из этого кейса? Этот сценарий показал нам, как важно мониторить на клиенте не только ошибки, но и время ответа. Клиентские метрики помогли обнаружить задержку. Вместе с серверными метриками мы поняли, что тормозил клиент, а не сервер. Без мониторинга мы могли бы думать, что проблема где‑то в сети или на сервере, а настоящая причина на клиенте осталась бы скрытой от нас.
Какие метрики собирать на сервере
Ключевые метрики на сервере аналогичны клиентским. Это RPS входящих запросов, статусы ответов, активные запросы, объём данных, время обработки и время запроса доставки до сервера.
grpc.server.call.started— сколько запросов получили.grpc.server.call.completed— сколько обработали.grpc.server.call.status{code=...}— сколько ответов с каждым статусом возвращено (OK, INTERNAL, UNAVAILABLE, и так далее).grpc.server.call.inflight— число запросов, которые сейчас в обработке, то есть не завершены.grpc.server.call.inbound_bytes / outbound_bytes— входящий/исходящий трафик (байтов в секунду) на этом сервисе.grpc.server.call.elapsed_time_ms— время выполнения запроса на сервере (от момента получения до отправки ответа). Это чисто серверная задержка (compute + I/O локальный).grpc.server.call.delivery_time_ms— время доставки запроса до сервера.
Вместе с клиентскими эти метрики дают полную картину. Если мы сюда ещё добавим метку client id, это позволит увидеть на сервере, от какого сервиса идут запросы, и можно будет заметить, что один из клиентов шлёт особенно много ошибок или ведёт себя необычным образом.
Проблема: рост количества ошибок на сервере при релизе
Рассмотрим кейс, где метка client id нам помогла. Мы выпускаем новую версию нашего сервиса. Мониторинг серверных метрик показывает странную тенденцию.
Очень плавно растёт количество ошибок с кодами PERMISSION_DENIED. Сначала их почти нет, потом всё больше и больше. Но опыт нам подсказывает, что, скорее всего, мы где‑то поломали процесс аутентификации и авторизации. Потому что PERMISSION_DENIED означает, что клиент не авторизован выполнить операцию. UNAVAILABLE — «сервис недоступен или не отвечает». Но код UNAVAILABLE может быть и следствием того, что клиент отвалился из‑за первой ошибки. Возможно из за роста количества PERMISSION_DENIED сервис стал перегружен и стал периодично отвечать UNAVAILABLE. Нужно копать глубже.
Перейдём к линии на графике ошибок и выберем линию PERMISSION_DENIED.
Так мы попадём в Metrics Explorer, где можно смотреть распределение по хостам и клиентам. Сначала проверим по хостам: в запросе поменяем условия host=cluster на host!=cluster. Мы посмотрим по каждому хосту отдельно, а не на всём кластере вместе.
Видим интересное. Релиз мы раскатываем host by host, то есть одна виртуальная машина за другой. И по мере раскатки релиза на каждом очередном хосте появляется фон ошибок PERMISSION_DENIED, то есть проблема явно привнесена новым кодом, который мы катим в продакшн.
Давайте посмотрим на клиентскую часть. Теперь мы вернём host=cluster и посмотрим на всём кластере.
Тут пригодится метка client, которую мы рекомендовали заводить, когда обсуждали, какие нам нужны метрики для клиент‑серверного взаимодействия. Смотрим, для какого клиента возникают ошибки. Для этого client id разбиваем по клиентам: client id!=total и видим, что рост ошибок касается только сервиса orders. Все остальные клиенты не получают ошибки PERMISSION_DENIED. Значит, наш релиз сломал права доступа исключительно для одного сервиса.
Может быть, мы забыли включить order в список разрешённых или поменяли роли? Вернёмся на общий дашборд по сервису и в параметре client id выберем orders.
Видим, что все запросы клиента завершаются с ошибкой PERMISSION_DENIED. Выглядит как инцидент, поэтому мы откатываем релиз.
Параллельно с этим команда смотрит diff и видит, что в новой версии ужесточили авторизацию. Сервис orders, который тоже ходит за данными, не был прописан в конфиге как доверенный клиент, и клиент начал слать ошибки. Что мы делаем? Мы исправляем конфиг и раскатываем релиз заново.
Что мы должны забрать из этого кейса? Мониторинг показал проблему ещё до того, как пришли клиенты и начали жаловаться на ситуацию. Мы увидели растущую аномалию и смогли быстро её локализовать. Конкретный код ошибки и конкретный client id подсказали нам, что это связано с нашим релизом. Это позволило быстро принять решение об откате. Client id подсказал, что был задействован только один сервис, а не все сервисы, которые у нас есть.
Лучшие практики
Инструментируйте всё, что критично. Каждая важная часть системы, будь то http‑endpoint, фоновая работа, очередь или внешнее API, — всё должно быть покрыто метриками.
Чем больше метрик, тем лучше. Во время инцидента вы не сможете завести метрику задним числом. Это упростит диагностику и сократит количество слепых зон.
Следуйте методологиям золотых сигналов и другим методологиям инструментирования метрик. Выпускаете новую фичу — инструментируете её метриками. Это даст вам гарантию того, что вы не забудете что‑то важное.
Используйте перцентили, потому что средние значения врут. Смотрите на 95–99-й перцентили времени, то есть на хвосты распределения. Именно там прячутся проблемные запросы. Помните, мы разбирали пример, когда запрос проводил в очереди семь секунд, у нас на графиках всё было хорошо, но пользователи начали жаловаться? Это потому, что пользовательский опыт определяется именно худшими случаями, а не средними.
Регулярно проверяйте дашборды, даже когда всё кажется нормальным. Если вы будете смотреть на дашборд регулярно, то будете знать типичное поведение вашей системы и сразу сможете заметить отклонение от нормы. Плюс таким образом вы заранее увидите тенденции и сможете принять меры ещё до того, как случилась авария.
Обучайте команду, обменивайтесь историями, разбирайте их на postmortem.
По их результатам вы можете добавить метрику, настроить новый алерт, увидеть, что чего‑то не хватило.
В общем и целом мониторинг — это не разовая настройка, а часть культуры разработки и эксплуатации. Когда каждый в команде знает метрики и доверяет им, то сервисы становятся стабильнее и надёжнее.
Все примеры в этой серии показаны на основе возможностей Monium Metrics, который является частью платформы Yandex Monium. Сервис открыт в общем доступе, попробовать можно тут: https://monium.yandex.cloud/metrics
