- PVSM.RU - https://www.pvsm.ru -

Поиск проблем производительности NodeJs приложения (с примерами)

Из-за однопоточной архитектуры Node.js важно быть настороже высокой производительности вашего приложения и избегать узких мест в коде, которые могут привести к просадкам в производительности и отнимать ценные ресурсы CPU у серверного приложения.
В этой статье речь пойдет о том, как производить мониторинг загрузки CPU nodejs-приложения, обнаружить ресурсоемкие участки кода, решить возможные проблемы со 100% загрузкой ядра CPU.


image

1. CPU-профайлинг приложения. Инструменты

К счастью, у разработчиков есть удобные инструменты для обнаружения и визуализации “хот-спотов” загрузки CPU.

Chrome DevTools Inspector

В первую очередь, это профайлер, встроенный в Chrome DevTools, который будет связываться с NodeJs приложением через WebSocket (стандартный порт 9229).

Запустите nodejs-приложение с флагом --inspect

(по умолчанию будет использоваться стандартный порт 9229, который можно изменить через --inspect=<порт>).

Если NodeJs сервер в докер-контейнере, нужно запускать ноду с --inspect=0.0.0.0:9229 и открыть порт в Dockerfile или docker-compose.yml

Откройте в браузере chrome://inspect

image

Найдите ваше приложение в “Remote Target” и нажмите “inspect”.

Откроется окно инспектора, схожее со стандартным “браузерным” Chrome DevTools.
Нас интересует вкладка “Profiler”, в которой можно записывать CPU профайл в любое время работы приложения:

image

После записи собранная информация будет представлена в удобном таблично-древовидном виде с указанием времени работы каждой ф-ии в ms и % от общего времени записи (см. ниже).

Возьмем для экспериментов простое приложение (можно склонировать отсюда [1]), эксплуатирующее узкое место в либе cycle [2] (используемой в другой популярной либе winston v2.x [3]) для эмуляции JS кода с высокой нагрузкой на CPU.

Будем сравнивать работу оригинальной либы cycle и моей исправленной версии [4].

Установите приложение, запустите через npm run inspect. Откройте инспектор, начните запись CPU профайла. В открывшейся странице http://localhost:5001/ нажмите "Run CPU intensive task", после завершения (алерта с текстом “ok”) завершите запись CPU профайла. В результате можно увидеть картину, которая укажет на наиболее прожорливые ф-ии (в данном случае — runOrigDecycle() и runFixedDecycle(), сравните их %):

image

NodeJs Profiler

Другой вариант — использование встроенного в NodeJs профайлера для создания отчетов о CPU производительности. В отличие от инспектора, он покажет данные за все время работы приложения.

Запустите nodejs-приложение с флагом --prof

В папке приложения будет создан файл вида isolate-0xXXXXXXX-v8.log, в который будут записываться данные о “тиках”.

Данные в этом файле неудобны для анализа, но из него можно сгенерировать человеко-читаемый отчет с помощью команды
node --prof-process <файл isolate-*-v8.log>

Пример такого отчета для тестового приложения выше тут [5]
(Чтобы сгенерировать самому, запустите npm run prof)

Существуют также некоторые npm-пакеты для профайлинга — v8-profiler
, предоставляющий JS-интерфейс к API V8 профайлера, а также node-inspector (устарел после выхода встроенного в Chrome DevTools-based профайлера).

2. Решение проблемы блокирующего JS-кода без инспектора

Предположим, так случилось, что в коде закрался бесконечный цикл или другая ошибка, приводящая к полной блокировке выполнения JS-кода на сервере. В этом случае единственный поток NodeJs будет заблокирован, сервер перестанет отвечать на запросы, а загрузка ядра CPU достигнет 100%. Если инспектор еще не запущен, то его запуск вам не поможет выловить виновный кусок кода.

В этом случае на помощь может прийти дебаггер gdb [6].

Для докера нужно использовать
--cap-add=SYS_PTRACE
и установить пакеты
apt-get install libc6-dbg libc-dbg gdb valgrind
Итак, нужно подключиться к nodejs процессу (зная его pid):
sudo gdb -p <pid>

После подключения ввести команды:

b v8::internal::Runtime_StackGuard
p 'v8::Isolate::GetCurrent'()
p 'v8::Isolate::TerminateExecution'($1)
c
p 'v8::internal::Runtime_DebugTrace'(0, 0, (void *)($1))
quit

Я не буду вдаваться в подробности, что делает каждая команда, скажу лишь, что тут используются некоторые внутренние ф-ии движка V8 [7].

В результате этого выполнение текущего блокирующего JS-кода в текущем “тике” будет остановлено, приложение продолжит свою работу (если вы используете Express, сервер сможет обрабатывать поступающее запросы дальше), а в стандартный поток вывода NodeJs-приложения будет выведен stack trace.

Он довольно длинный [8], но в нем можно найти полезную информацию — стек вызовов JS функций.

Находите строки такого вида:

--------- s o u r c e   c o d e ---------
function infLoopFunc() {x0a    //this will lock serverx0a    while(1) {;}x0a}
-----------------------------------------

Они должны помочь определить “виноватый” код.

Для удобства написал скрипт для автоматизации этого процесса с записью стека вызовов в отдельный лог-файл: loop-terminator.sh [9]

Также см. пример приложения [10] с его наглядным использованием.

3. Обновляйте NodeJs (и npm-пакеты)

Иногда вы не виноваты :)

Наткнулся на забавный баг в nodejs < v8.5.0 (проверил на 8.4.0, 8.3.0), который при определенных обстоятельствах вызывает 100% загрузку 1 ядра CPU.
Код простого приложения для повторения этого бага находится тут [11].

Смысл в том, что приложение запускает WebSocket-сервер (на socket-io [12]) и запускает один дочерний процесс через child_process.fork(). Следующая последовательность действий гарантированно вызывает 100% загрузку 1 ядра CPU:

  1. К WS-северу подключается клиент
  2. Дочерний процесс завершается и пересоздается
  3. Клиент отключается от WS

Причем приложение все еще работает, Express сервер отвечает на запросы.
Вероятно, баг находится в libuv, а не в самой ноде. Истинную причину этого бага и исправляющий его коммит в changelog’ах я не нашел. Легкое “гугление” привело к подобным багам в старых версиях:

https://github.com/joyent/libuv/issues/1099 [13]
https://github.com/nodejs/node-v0.x-archive/issues/6271 [14]

Решение простое — обновить ноду до v8.5.0+.

4. Используйте дочерние процессы

Если в вашем серверном приложении есть ресурсоемкий код, изрядно нагружающий CPU, хорошим решением может стать вынесение его в отдельный дочерний процесс. Например, это может быть серверный рендеринг React-приложения.

Создайте отдельное NodeJs-приложение и запускайте его из главного через child_process.fork() [15]. Для связи между процессами используйте IPC-канал. Разработать систему обмена сообщениями между процессами довольно легко, ведь ChildProcess — потомок EventEmitter.
Но помните, что создавать слишком большое количество дочерних NodeJs процессов не рекомендуется.

Говоря о производительности, другой не менее важной метрикой является потребление RAM. Существуют инструменты и техники для поиска утечек памяти, но это тема для отдельной статьи.

Автор: Денис

Источник [16]


Сайт-источник PVSM.RU: https://www.pvsm.ru

Путь до страницы источника: https://www.pvsm.ru/node-js/270690

Ссылки в тексте:

[1] отсюда: https://github.com/ukrbublik/nodejs-debug-notes/tree/master/0-profiling

[2] cycle: https://www.npmjs.com/package/cycle

[3] winston v2.x: https://github.com/winstonjs/winston/tree/2.x

[4] исправленной версии: https://github.com/ukrbublik/nodejs-debug-notes/blob/master/0-profiling/fixed_cycle.js#L84

[5] тут: https://raw.githubusercontent.com/ukrbublik/nodejs-debug-notes/master/resources/0-d-prof-report.txt

[6] gdb: https://www.gnu.org/software/gdb/

[7] V8: https://github.com/v8/v8

[8] довольно длинный: https://github.com/ukrbublik/nodejs-debug-notes/blob/master/resources/1-gdb-stack-trace.txt

[9] loop-terminator.sh: https://github.com/ukrbublik/nodejs-debug-notes/blob/master/1-break-inf-loop/loop-terminator.sh

[10] пример приложения: https://github.com/ukrbublik/nodejs-debug-notes/tree/master/1-break-inf-loop

[11] находится тут: https://github.com/ukrbublik/nodejs-debug-notes/tree/master/2-ws-bug

[12] socket-io: https://socket.io/

[13] https://github.com/joyent/libuv/issues/1099: https://github.com/joyent/libuv/issues/1099

[14] https://github.com/nodejs/node-v0.x-archive/issues/6271: https://github.com/nodejs/node-v0.x-archive/issues/6271

[15] child_process.fork(): https://nodejs.org/api/child_process.html#child_process_child_process_fork_modulepath_args_options

[16] Источник: https://habrahabr.ru/post/344672/?utm_source=habrahabr&utm_medium=rss&utm_campaign=sandbox