Логирование запросов через middleware в Express.js

1. Зачем вообще логировать запросы?

Представьте, что вы — шеф-повар в большом ресторане. Каждый раз, когда к вам приходит заказ, вы делаете пометку: кто заказал, что заказал, когда заказал. Если вдруг что-то пошло не так (например, официант уронил тарелку с борщом), вы всегда сможете разобраться, что произошло, когда и почему.

В мире серверов логирование — это ваш журнал заказов. Оно помогает:

• Отслеживать, какие запросы приходят на сервер, когда и от кого.
• Диагностировать ошибки и странное поведение пользователей (или программистов, которые делают странные запросы).
• Видеть нагрузку на сервер и выявлять узкие места.
• Быстро находить баги — ведь если что-то сломалось, вы сможете посмотреть, какой запрос это вызвал.

В Express.js логирование запросов чаще всего реализуется через middleware. Это удобно: один раз написали функцию — и она автоматически срабатывает для каждого запроса.

Как устроен middleware для логирования

Middleware-функция в Express — это обычная функция, которая получает три аргумента: req, res, next. Она может делать что угодно: читать данные из запроса, модифицировать их, логировать, а потом передавать управление дальше по цепочке.

Логирующий middleware обычно:

• Смотрит на объект req (запрос): метод, путь, параметры.
• Иногда — на объект res (ответ): статус-код, размер ответа.
• Записывает нужную информацию в консоль или файл.
• Передаёт управление следующему middleware через next().

Давайте разберёмся с этим на практике.

2. Первый логирующий middleware: самый простой вариант

Создадим простейший middleware, который будет выводить в консоль метод и путь каждого запроса.

// logger.js
function logger(req, res, next) {
  // req.method — HTTP-метод (GET, POST и т.д.), req.url — путь запроса
  console.log(`${req.method} ${req.url}`);
  next(); // обязательно вызвать next(), иначе запрос "зависнет"
}

module.exports = logger;

Подключаем его в наше Express-приложение:

const express = require('express');
const logger = require('./logger');

const app = express();

app.use(logger);

app.get('/', (req, res) => {
  res.send('Главная страница');
});

app.listen(3000, () => {
  console.log('Сервер запущен на http://localhost:3000');
});

Теперь при каждом запросе к серверу в консоли будет появляться строка вроде:

GET /

или

POST /login

Уже полезно! Но мы можем сделать гораздо круче.

3. Логирование времени запроса

Иногда хочется знать не только, какой запрос пришёл, но и когда это случилось. Давайте добавим вывод времени:

function logger(req, res, next) {
  const now = new Date().toISOString();
  console.log(`[${now}] ${req.method} ${req.url}`);
  next();
}

Теперь лог будет выглядеть так:

[2024-06-01T10:45:23.123Z] GET /api/user

Это уже почти как в настоящем продакшене!

4. Логирование времени обработки запроса

А что если мы хотим узнать, сколько времени сервер тратит на обработку каждого запроса? Например, чтобы выявить медленные маршруты. Для этого можно засечь время в начале и в конце обработки.

В Express объект ответа (res) умеет реагировать на событие 'finish', когда ответ полностью отправлен клиенту. Давайте воспользуемся этим:

function logger(req, res, next) {
  const start = Date.now();

  res.on('finish', () => {
    const duration = Date.now() - start;
    const now = new Date().toISOString();
    console.log(`[${now}] ${req.method} ${req.url} ${res.statusCode} - ${duration}ms`);
  });

  next();
}

Теперь после каждого запроса мы увидим, например:

[2024-06-01T10:46:10.789Z] GET /api/user 200 - 4ms

Здесь:

• GET — метод запроса,
• /api/user — путь,
• 200 — статус ответа,
• 4ms — время обработки.

5. Логирование тела запроса (осторожно!)

Иногда для дебага полезно видеть не только метод и путь, но и тело запроса (например, для POST-запросов). Но делать это надо очень аккуратно: не стоит логировать пароли, токены и другую чувствительную информацию!

Пример (только для POST-запросов и только если тело уже распарсено, например, через express.json()):

function logger(req, res, next) {
  const start = Date.now();

  res.on('finish', () => {
    const duration = Date.now() - start;
    const now = new Date().toISOString();
    let body = '';
    if (req.method === 'POST' && req.body) {
      body = ` BODY: ${JSON.stringify(req.body)}`;
    }
    console.log(`[${now}] ${req.method} ${req.url} ${res.statusCode} - ${duration}ms${body}`);
  });

  next();
}

Не забывайте: если вы используете express.json(), подключайте логгер после этого middleware, иначе req.body будет undefined.

6. Как логгер вписывается в цепочку middleware

Логгер — это обычный middleware. Его можно ставить:

• В самом начале цепочки — чтобы логировать все запросы, даже если они потом будут обработаны другими middleware или роутерами.
• После парсеров тела (express.json(), express.urlencoded()) — если нужно логировать тело запроса.
• Локально для отдельных маршрутов — если нужно логировать только часть запросов.

Пример глобального логгера:

app.use(logger); // Логирует всё

Пример локального логгера:

app.post('/api/secret', logger, (req, res) => {
  // ...
});

7. Использование готовых логгеров: morgan

В реальных проектах редко пишут логирование с нуля. Есть популярные готовые middleware, например, morgan. Он умеет логировать всё, что нужно, и очень гибко настраивается.

Установка:

npm install morgan

Использование:

const express = require('express');
const morgan = require('morgan');

const app = express();

// Встроенный формат 'dev' — цветной, красивый для разработки
app.use(morgan('dev'));

app.get('/', (req, res) => {
  res.send('Hello, Morgan!');
});

app.listen(3000);

Пример вывода:

GET / 200 7.294 ms - 15

Можно выбрать другой формат или создать свой:

// Краткий формат
app.use(morgan('tiny'));

// Свой формат
app.use(morgan(':date[iso] :method :url :status :response-time ms'));

Morgan — отличный выбор для быстрого старта и прототипирования. В боевых проектах логи часто пишут в файлы или систему сбора логов (например, Winston, Bunyan, Logstash и т.д.).

8. Типичные ошибки при логировании через middleware

Ошибка №1: забыли вызвать next()
Если в логирующем middleware забыть вызвать next(), запрос «зависнет» и браузер будет ждать ответа вечно. Это классическая боль новичков: всегда завершайте middleware вызовом next()!

Ошибка №2: логирование больших тел запроса
Если вы логируете большие объёмы данных (например, массивы файлов, изображения, длинные тексты), это быстро засорит консоль и может даже замедлить сервер. Логируйте только то, что действительно нужно для отладки.

Ошибка №3: логирование до парсера тела
Если middleware логирует req.body, а парсер тела (express.json()) ещё не отработал, тело будет undefined или пустым. Всегда размещайте логгер после нужных парсеров, если хотите видеть тело запроса.

Ошибка №4: логирование чувствительных данных
Никогда не логируйте пароли, токены, номера карт и другую приватную информацию. Такие логи могут попасть в чужие руки — и тогда придётся объяснять начальству, почему база клиентов оказалась в интернете.

Ошибка №5: логгер пишет слишком много
Если логировать каждый запрос в файл без ротации, лог быстро разрастётся до гигабайтов. Используйте специальные библиотеки, которые поддерживают ротацию файлов или отправку логов на удалённый сервер.