Node.js
Предыдущие части: Часть 1

Понимание проблемной области

В кратком руководстве Clinic Doctor говорится что, если задержки Event Loop на уровне, который мы наблюдаем, весьма вероятно, что одна или несколько функций «блокируют» Event Loop.

Работая с Node.js очень важно учитывать основную характеристику JavaScript: асинхронные события не могут произойти, пока в настоящее время не выполнен код.

Вот почему setTimeoutне может быть точным.

Например, попробуйте выполнить следующий код в DevTools браузера или в Node REPL:

Результат измерений никогда не покажет 100мс. Скорее всего, он будет в диапазоне от 150 до 250мс. setTimeoutзапланировал асинхронную операцию (console.timeEnd), но текущий код еще не завершен; есть еще две строки. Исполняющийся код называется текущим «тиком». Для завершения тика, Math.random должен быть вызван десять миллионов раз. Если это занимает 100мс, то общее время до выполнения тайм-аута будет 200мс (плюс, функции setTimeout требуется время чтобы фактически поставить тайм-аут в очередь, обычно пару миллисекунд).

Говоря в контексте бэкенда, если операция в текущем тике занимает длительное время, чтобы завершить запросы, она не может быть обработана, и извлечение данных не может произойти, потому что асинхронный код не будет выполняться до завершения текущего тика. Это означает, что «дорогой» в вычислительном смысле код замедлит все взаимодействия с сервером. Поэтому рекомендуется разделить ресурсоемкую работу на отдельные процессы и вызывать их с основного сервера. Это позволит избежать случаев, когда на редко используемом, но «дорогом» маршруте замедляется производительность других часто используемых, но не дорогих маршрутов.

В нашем сервере есть код, который блокирует Event Loop, поэтому следующим шагом будет поиск этот кода.

Анализируем

Один из способов быстро определить плохо выполняющийся код — создать и проанализировать flame graph. Этот граф представляет вызовы функций в виде блоков, расположенных друг над другом — не во времени, а в совокупности. Flame graph называется так, потому что он использует оранжево-красную цветовую схему: чем краснее блок, тем «горячее» функция. То есть,скорее всего она и блокирует Event Loop. Захват данных для flame graph осуществляется путем семплирования CPU — делается снапшот функции которая выполняется и её стека. Цвет определяется процентом времени, в течение которого данная функция находится в топе стека (например, функция выполняется в данный момент) и так для каждого семпла. Если это не последняя функция, которая когда-либо вызывалась в этом стеке, то, скорее всего, она и блокирует Event Loop.

Давайте запустим clinic flame для создания flame graph’а нашего приложения:

В результате в нашем браузере увидим примерно следующее:

Визуализация flame graph

Ширина блока показывает, сколько времени у CPU заняло выполнение в целом. Мы видим три основных стека, которые заняли больше всего времени. Все они показывают что server.on самая «горячая» функция. На самом деле, все три стека это одно и тоже. Они расходятся, поскольку во время профилирования оптимизированные и не оптимизированные функции рассматриваются как отдельные фреймы вызовов. Функции с префиксом *оптимизированы движком JavaScript, а функции с префиксом ~не оптимизированы. Если нас не интересует данный показатель, мы можем упростить график, нажав кнопку Merge. Это должно выглядеть примерно так:

Объединение flame graph

Уже сейчас мы можем сделать вывод, что проблемный код в файле util.js.

Медлительная функция также является обработчиком событий: функции, ведут к функции, которая являются частью ядра модуля eventsи server.on. Это резервное имя анонимной функции, представленной в качестве функции обработки событий. Мы также видим, что этот код не относится к тому же «тику», что и код, который обрабатывает запрос. Если бы это было так, функции из ядра httpnet и streamмодулей были бы в стеке.

Чтобы найти основные функции нужно раскрыть более мелкие части flame graph. Например, попробуйте использовать поиск в правом верхнем углу интерфейса чтобы найти send (имя внутренних методов из restifyи http). Он должен находиться справа от графика (функции отсортированы по алфавиту):

Поиск функций обработки HTTP во flame graph’е

Обратите внимание, насколько малы все фактические блоки обработки HTTP.

Мы можем нажать на один из блоков, выделенных бирюзовым, чтобы увидеть такие функции, как writeHeadи writeв файле http_outgoing.JS (часть ядра Node библиотека http):

Раскрытый список графика flame в соответствующих стеках HTTP

Чтобы вернуться к главному виду, нужно нажать all stacks

Ключевой момент: функция server.on не находится в том же тике, что и фактический код обработки запросов. Несмотря на это она по-прежнему влияет на общую производительность сервера, задерживая выполнение эффективного кода.

Отладка

Благодаря flame graph мы знаем, что проблемной функцией является обработчик событий, передаваемый server.on в файле util.js.

Давайте посмотрим:

Раскрытый список flame graph в соответствующих стеках HTTP

Хорошо известно, что криптография, как правило, является затратной, как и сериализация ( JSON.stringify), но почему они не появляются на flame graph? Эти операции семплированы, но они скрыты cpp фильтром. Если мы нажмем кнопку cpp мы увидим следующее:

Выявление сериализации и криптографии C++ фреймов

Внутренние инструкции V8, относящиеся как к сериализации, так и к криптографии, теперь отображаются как самые горячие стеки и занимают большую часть времени. Метод JSON.stringify напрямую вызывает код C++, поэтому мы не видим функции JavaScript. В случае криптографии такие функции, как createHash и update, находятся в данных, но они либо встроены (что означает, что они исчезают в объединенном представлении), либо слишком малы для визуализации.

Как только мы начнем вникать в код в функции etagger, быстро становится очевидным, что она плохо спроектирована. Почему мы берем инстанс serverиз контекста функции? Происходит много хэширования, так ли это необходимо? В реализации также нет поддержки заголовка If-None-Match, которая уменьшила бы некоторые нагрузки в реальных сценариях. Потому что клиенты будут делать только запрос к head для определения актуальности.

Давайте пока проигнорируем эти нюансы и проверим нашу догадку, что фактическая работа выполняемая в server.on действительно бутылочное горлышко. Этого можно добиться, установив код server.on пустой функции и сгенерировать новый flame graph.

Внесите изменения в функцию etagger:

Выявление сериализации и криптографии C++ фреймов

Функция слушателя событий показывает, что в server.on сейчас нет операций.

Давайте снова запустим clinic flame:

Новый flame graph будет выглядеть так:

Flame graph сервера, когда server.on — пустая функция

Выглядит лучше и мы должны были заметить увеличение количества запросов в секунду. Но почему код, генерирующий события такой «красный»? На данный момент мы ожидаем, что код обработки HTTP займет большую часть времени процессора, в server.on вообще нечего выполнять

Этот тип бутылочного горлышка вызван тем, что функция выполняется больше, чем требуется.

Следующий подозрительный код в начале util.js может быть ключом:

Давайте удалим эту строку и запустим процесс с флагом --trace-warnings:

Если мы направим AutoCannon в другой терминал, вот так:

Наш процесс выдаст что-то подобное:

Node говорит нам, что множество ивентов присоединяется к объекту server. Это странно, потому что есть boolean, который проверяет, было ли событие присоединено, а затем возвращается выше, делая attachAfterEvent no-op после прикрепления первого события.

Давайте взглянем на функцию attachAfterEvent:

Условие проверяется неправильно! Оно проверяет attachAfterEventна истинность вместо afterEventAttached. Это означает, что новое событие присоединяется к инстансу server при каждом запросе, а затем все предыдущие прикрепленные события запускаются после каждого запроса. Упс!

В заключительной части оптимизируем наш код. Несколько советов чтобы достичь максимальной производительности. На что следует обращать внимание разработчику на Node.js

Перевод статьи: David Mark Clements Keeping Node.js Fast: Tools, Techniques, And Tips For Making High-Performance Node.js Servers