Я работаю техлидом в команде System, которая отвечает за производительность и стабильность сервиса. С марта по ноябрь 2020 года Miro вырос в семь раз до 600+ тысяч уникальных пользователей за сутки. Сейчас наш монолит работает на 350 серверах, около 150 инстансов мы используем для хранения данных пользователей.
Чем больше пользователей взаимодействует с сервисом, тем больше внимания требуют поиск и устранение узких мест на серверах. Расскажу, как мы решили эту задачу.
Часть первая: постановка задачи и вводные
В моем понимании любое приложение можно представить в виде модели: она состоит из задач и обработчиков. Задачи выстраиваются в очереди и исполняются последовательно, как на рисунке ниже:
Не все согласны с такой постановкой проблемы: кто-то скажет, что на RESTful серверах нет очередей только хэндлеры, методы обработки запросов.
Я вижу это иначе: не все запросы процессятся одновременно, некоторые ждут своей очереди в памяти веб-движка, в сокетах или где-то еще. Очередь есть в любом случае.
В Miro для поддержки коллаборации на доске мы используем WebSocket соединение, а сам сервер состоит из множества очередей задач. Есть очередь на прием данных, на процессинг, на запись обратно в сокеты или персистент. Соответственно, есть очереди и есть обработчики.
Опыт показывает, что очереди всегда есть на этом фундаменте строится весь кейс.
Что мы искали и что нашли
Обнаружив очереди, мы занялись поиском метрик для мониторинга времени выполнения процессов в них. Прежде, чем найти их, мы совершили три ошибки.
Первая ошибка: исследовали размер очереди. Кажется, что большая очередь это плохо, а маленькая хорошо. На самом деле это не всегда так: размер не влияет на наличие или отсутствие проблемы. Типичная ситуация: очередь всегда будет пустой, если выполнение одной задачи зависит от другой. Но это не значит, что все в порядке задачи все равно выполняются медленно.
Вторая ошибка: искали среднее время выполнения задачи. Если измерять размер очереди смысла нет, можно рассчитать среднее время на выполнение задачи. Но в результате мы получаем цифру, которая не несет в себе полезной информации. Ниже объясню, почему.
Анализ ошибок показал, что искать нужно не среднее арифметическое, а медианное значение времени, за которое выполняется задача. Медиана помогает очертить круг задач, которые заслуживают внимания, и отбросить аномальные отклонения.
В нашем случае больше подошел перцентиль. Он помог разбить все процессы на два типа: аномалии (1%) и задачи, которые укладываются в общую картину (99%).
Перцентиль помог осознать третью ошибку: не нужно пытаться решить все проблемы с очередями. Нужно сосредоточиться только на тех, которые напрямую влияют на пользовательские действия (users action).
Поясню: отсечение 2% аномалий помогло нам сосредоточиться на оптимизации процессов, с которыми сталкивается абсолютное большинство пользователей, а не единицы тех, кто зашел с медленного интернета. В результате мы улучшили UX повысили продуктовую метрику, а не техническую. Это очень важный момент.
Часть вторая: решение проблемы
В предыдущем разделе мы определили метод поиска узких мест. Теперь найдём самую медленную часть задачи.
Опыт показывает, что время, за которое задача выполняется, можно разбить на две части: когда мы что-то считаем и когда процессор ждет завершения операции input/output (IO).
Ошибки происходят и в первой части процесса, но в этом кейсе речь не о них. Интерес представляет вторая часть период ожидания ответа от базы данных. К нему, например, относится отправка данных по сети и ожидание выполнения SQL-запросов от базы данных.
На этом этапе у нас должна быть возможность вклиниться в слой абстракции (data access layer, DAL) и написать участок кода, который может быть вызван перед началом операции и по ее завершении. Другими словами, функция должна быть наблюдаемой (observable).
Рассмотрим пример: в Miro мы используем jOOQ для работы с SQL. В библиотеке есть листенеры: они позволяют написать код на каждый SQL-запрос, который будет выполняться перед запросом и после него. В Redis используется сторонняя библиотека, которая не позволяет добавлять листнеры. В этом случае можно написать свой DAL для доступа. Другими словами, вместо прямого использование библиотеки к коде, можно прикрыть её своим интерфейсом. А у же в его реализации обеспечить вызовы необходимых нам обработчиков.
Тот же паттерн хорошо работает с RESTful приложением, когда функциональный или бизнес-метод обернуты в листенеры. В этом случае
мы можем во входящем интерцепторе сохранить значение его счетчика, а уже в исходящем интерцепторе получить разницу и отправить это значение в систему мониторинга.
Проиллюстрируем этот процесс на примере нашего дашборда. Мы профилируем конкретную задачу и получаем как общее время ее выполнения, так и время, которое было потрачено на запросы в SQL и в Redis. Мы также можем поставить различные time-counters: например, в разрезе команд, отправляемых в Redis .
Информация по выполнению каждого запроса дублируется в Prometheus и Jaeger. Зачем нам две системы? Графики наглядные, а логи детальные. Системы дополняют друг друга.
Разберем на примере: есть команда на открытие доски Miro, ее длительность напрямую зависит от размера доски. На графике мы технически не можем показать, что маленькие доски открываются быстро, а большие медленно. Зато Prometheus в реальном времени показывает аномалии, на которые можно быстро среагировать.
В логах мы получаем более детальную информацию например, можем запросить время на открытие маленькой доски. При этом в Jaeger данные появляются с задержкой примерно в одну минуту. Использование обоих инструментов позволяет видеть полную картину информации из них достаточно для поиска узких мест.
Stack trace для частных случаев
Инструмент для оптимизации медленных задач, описанный выше, подходит для ситуаций, когда все работает в пределах нормы. Следующим шагом стало создание методики для частных случаев когда происходит всплеск запросов или нужно найти и оптимизировать длинные очереди.
Добавление data access layers дало возможность снимать stack trace. Это позволяет трейсить запросы только от определенной базы данных, для конкретного end point или команды Redis.
Мы можем снимать stack trace с каждой десятой или сотой операции и написать логи, тем самым снизив нагрузку. Выборочно обрабатывать отчеты нетрудно сложность в том, как визуализировать полученную информацию в понятном виде, чтобы ей было удобно пользоваться.
В Miro мы отправляем stack traces в Grafana, предварительно удаляя из dump все third-party библиотеки и формируем значение метрики как результат конкатенации части дампа. Выглядит это так: после перечисленных манипуляций лог projects.pt.server.RepositoryImpl.findUser (RepositoryImpl.java:171) превращается в RepositoryImpl.findUser:171.
WatchDog для постоянного мониторинга
Снятие stack trace дорогое исследование, держать его активным постоянно не получится. Кроме того, в отчетах генерируется слишком много информации, обработать которую сложно.
Более универсальный метод отслеживания аномалий WatchDog. Это наша библиотека, которая отслеживает медленно выполняющиеся или зависшие задачи. Инструмент регистрирует задачу перед выполнением, а после завершения снимает с регистрации.
Иногда задачи зависают вместо 100 миллисекунд выполняются 5 секунд. Для таких случаев у WatchDog есть свой thread, который периодически проверяет статус задачи и снимает stack trace.
На практике это выглядит так: если через 5 секунд задача еще висит, мы видим это в логе stack trace. Кроме того, система посылает alert, если задача висит слишком долго например, из-за deadlock на сервере.
Вместо заключения
В марте 2020 года, когда началась самоизоляция, число пользователей Miro росло на 20% каждый день. Все описанные фичи мы написали за несколько дней, они не были очень трудоемкими.
По сути, мы создали велосипед на рынке есть готовые продукты, которые решают нашу проблему. Но все они стоят дорого. Главная цель этого текста показать простой инструмент, который можно быстро собрать на коленке. Он не уступает большим и дорогим решениям и поможет небольшим проектам пережить быстрое масштабирование.
