Получение контекста для каждого запроса в NodeJS с помощью async_hooks

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

Самый простой способ — передать этот идентификатор запроса в качестве аргумента в каждую из моих функций. Проблема в том, что это не поддерживается: если у меня 5 функций глубоко в моем стеке, и я хочу что-то регистрировать, мне нужно отредактировать 5 функций, чтобы добавить аргумент и отредактировать каждый вызов функции.

Вы можете всегда передавать объект «контекст» в каждую из ваших функций, но проблема все еще остается. Я использую библиотеку SQL, которую можно настроить для запуска функции при обнаружении длинного запроса, но эта функция вызывается только со строкой запроса. Я не могу передать ему контекст своего запроса.

Если вы готовы использовать экспериментальный материал NodeJS, у меня есть для вас действительно элегантное решение благодаря async_hooks.

Немного теории об async_hooks

async_hooks модуль предоставляет функции для отслеживания асинхронных ресурсов. Эти хуки вызываются всякий раз, когда setTimeoutпрослушиватель сервера или любая другая асинхронная задача создается, запускается, завершается и уничтожается.

При создании асинхронного ресурса новый asyncId будет присвоено ему и нашему init хук будет вызываться с этим идентификатором и asyncId родительского ресурса. Этот модуль также предоставляет очень полезную executionAsyncId() способ получить текущий asyncId выполнения нашей функции.

Вот как мы можем использовать его, чтобы просто регистрировать сообщение при вызове хуков:

const fs = require('fs');
const async_hooks = require('async_hooks');

const log = (str) => fs.writeSync(1, `${str}\n`);

async_hooks.createHook({
  init(asyncId, type, triggerAsyncId) {
    log(`INIT: asyncId: ${asyncId} / type: ${type} / trigger: ${triggerAsyncId}`);
  },
  destroy(asyncId) {
    log(`DESTROY: asyncId: ${asyncId}`);
  },
}).enable();

Вы можете заметить, что мы не используем console.log здесь. Это потому что console.log является асинхронной операцией и вызовет хук, который вызовет console.log которая является асинхронной операцией и вызовет хук… И это случай бесконечного цикла. Решение заключается в использовании fs.writeSync который является синхронным и не вызовет срабатывания одного из наших хуков.

Давайте попробуем эти крючки с помощью простого setTimeout пример, в котором мы регистрируем текущий asyncId снаружи и внутри setTimeout:

log(`>> Calling setTimeout: asyncId: ${async_hooks.executionAsyncId()}`);
setTimeout(() => {
  log(`>> Inside setTimeout callback: asyncId: ${async_hooks.executionAsyncId()}`);
}, 0);
log(`>> Called setTimeout: asyncId: ${async_hooks.executionAsyncId()}`);

При выполнении этого кода мы получим такой вывод:

>> Calling setTimeout: asyncId: 1
INIT: asyncId: 2 / type: Timeout / trigger: 1
>> Called setTimeout: asyncId: 1
>> Inside setTimeout callback: asyncId: 2
DESTROY: asyncId: 2

Давайте посмотрим, что здесь произошло.

• Мы начали с asyncId равен 1 и называется setTimeout.
• Это создало Timeout асинхронный ресурс и активировал наш init крючок с только что созданным asyncId из 2 и его родителей asyncId из 1.
• Мы зарегистрировали конец нашей программы с помощью asyncId по-прежнему равно 1
• Timeout был вызван обратный вызов ресурса, и мы зарегистрировали текущий asyncId что равно 2
• Timeout ресурс был уничтожен и наш destroy хук был запущен

Есть также два других крючка: before а также after. Их можно использовать для мониторинга времени некоторых асинхронных ресурсов, таких как внешние HTTP-запросы или SQL-запросы.

Хорошо, но в чем смысл?

С executionAsyncId() и init мы можем воссоздать «стек» вызовов наших функций, даже если они были асинхронными.

Вот реальный пример. Мы создаем HTTP-сервер, читаем и отправляем содержимое test.txt файл по каждому запросу.

const fs = require('fs');
const async_hooks = require('async_hooks');
const http = require('http');

const log = (str) => fs.writeSync(1, `${str}\n`);

async_hooks.createHook({
  init(asyncId, type, triggerAsyncId) {
    log(`asyncId: ${asyncId} / trigger: ${triggerAsyncId}`);
  },
}).enable();

const readAndSendFile = (res) => {
  fs.readFile('./test.txt', (err, file) => {
    log(`>> Inside readAndSendFile: execution: ${async_hooks.executionAsyncId()}`);
    res.end(file);
  });
}

const requestHandler = (req, res) => {
  log(`>> Inside request: execution: ${async_hooks.executionAsyncId()}`);
  readAndSendFile(res);
}

const server = http.createServer(requestHandler);

server.listen(8080);

Давайте выполним этот код и отправим два запроса. Я удалил несколько бесполезных строк из вывода.

>> Inside request: execution: 6
asyncId: 9 / trigger: 6
asyncId: 11 / trigger: 9
asyncId: 12 / trigger: 11
asyncId: 13 / trigger: 12
>> Inside readAndSendFile: execution: 13
[...]
>> Inside request: execution: 31
asyncId: 34 / trigger: 31
asyncId: 36 / trigger: 34
asyncId: 37 / trigger: 36
asyncId: 38 / trigger: 37
>> Inside readAndSendFile: execution: 38

Мы видим, что нашим двум запросам были присвоены два asyncId: 6 и 31. Чтение нашего файла создало новые асинхронные ресурсы, прозрачные для нашего кода, а затем наш readAndSendFile зарегистрировал два asyncId: 13 и 38.

От readAndSendFile функция, мы можем получить наш первоначальный запрос asyncId путем повторения нашего «асинхронного пути». Например, для нашего первого запроса мы начинаем с asyncId равно 13, и тогда мы получаем 13 → 12 → 11 → 9 → 6.

Получение чего-то полезного

Со всем этим мы можем создать две функции для создания и получения объекта контекста для каждого из наших запросов. Это также можно использовать для любого другого использования, а не только для HTTP-сервера.

const async_hooks = require('async_hooks');

const contexts = {};

async_hooks.createHook({
  init: (asyncId, type, triggerAsyncId) => {
    
    
    
    if (contexts[triggerAsyncId]) {
      contexts[asyncId] = contexts[triggerAsyncId];
    }
  },
  destroy: (asyncId) => {
    
    delete contexts[asyncId];
  },
}).enable();


function initContext(fn) {
  
  const asyncResource = new async_hooks.AsyncResource('REQUEST_CONTEXT');
  return asyncResource.runInAsyncScope(() => {
    
    const asyncId = async_hooks.executionAsyncId();
    
    contexts[asyncId] = {}
    return fn(contexts[asyncId]);
  });
}

function getContext() {
  const asyncId = async_hooks.executionAsyncId();
  
  
  return contexts[asyncId] || {};
};

module.exports = {
  initContext,
  getContext,
};

Давайте напишем небольшой тест, чтобы проверить, все ли работает правильно.

const {initContext, getContext} = require('./context.js');

const logId = () => {
  const context = getContext();
  console.log(`My context id is: ${context.id}`);
}

initContext((context) => {
  context.id = 1;
  setTimeout(logId, 100);
  setTimeout(logId, 300);
});

initContext((context) => {
  context.id = 2;
  setTimeout(logId, 200);
  setTimeout(logId, 400);
});

Выполнив это, мы получим:

My context id is: 1
My context id is: 2
My context id is: 1
My context id is: 2

Что дальше?

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

Реальное использование будет создавать контекст для каждого HTTP-запроса, генерировать идентификатор запроса и извлекать этот идентификатор внутри нашей функции ведения журнала, чтобы печатать его в каждой строке. Я также использовал его для запуска каждого вызова базы данных одного HTTP-запроса в одной и той же транзакции SQL.

Вы должны быть осторожны с тем, сколько информации вы включаете в свой контекст. Это должно быть максимально простым, чтобы поток данных в вашей программе был простым для понимания и предотвращал крайние случаи, которые могут создавать ошибки. Использование такого рода контекста также запутает такие инструменты, как TypeScript, которые не смогут узнать, что находится в вашем текущем контексте.

Имейте в виду, что async_hooks все еще экспериментальный, но если вам нравится жить на грани, идите и попробуйте!

Изображение на обложке Эфе Курназ на Unsplash