Регистрация с express -winston: неправильный порядок журналов - PullRequest
Новая
       52

Регистрация с express -winston: неправильный порядок журналов

0 голосов
/ 03 мая 2020

Я использую такой код: 

const app = require('express')();
const winston = require('winston');
const expressWinston = require('express-winston');

app.use(expressWinston.logger({
  transports: [
    new winston.transports.Console(),
  ],
  format: winston.format.combine(
    winston.format.printf(info => `Date from winston: ${Date.now()} ${info.message}`),
  ),
  expressFormat: true,
}));

app.get('/check', (req, res) => {
    console.log(`Date from route: ${Date.now()}`);
    res.end('OK');
});

app.listen(3000, () => console.log('Listening...'));

и когда я пытаюсь вызвать /check route, я получаю это в консоли: 

Date from route: 1588531901238
Date from winston: 1588531901247 GET /check 200 2ms

Как вы можете видите, время от промежуточного ПО позже, чем от обработчика маршрута.

Почему? Как я могу это исправить? Мне нужно получить правильный порядок прохождения промежуточного программного обеспечения.

1 Ответ

0 голосов
/ 04 мая 2020

Обновление

Эта функция еще не существует в express -winston в соответствии с этой проблемой .

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

function logRequest(req, res, next) {
  console.log('Request', req.path, Date.now());

  next();
}

app.use(logRequest);
// routes...

Предыдущий ответ

Вопрос 1:

Как видите, время от промежуточного ПО позже чем время от обработчика маршрута. Почему?

Ответ:

Это потому, что консольный транспорт new winston.transports.Console() регистрирует ваш HTTP-запрос к консоли, а не console.log(<some-text>). Это из документации express -winston

Используйте expressWinston.logger (опции) для создания промежуточного программного обеспечения для регистрации ваших HTTP-запросов

Чтобы продемонстрировать это, давайте возьмем ваш код и увидим результат: 

// Your above code here...

app.get('/check', (req, res) => {
    console.log(`Date from route: ${Date.now()}`);
    let i = 1;

    const handle = setInterval(() => {
      console.log('i:', i);
      i++;
    }, 1000);

    setTimeout(() => {
      console.log('i before response:', i);
      clearInterval(handle);
      res.end('OK');
    }, 3000);
});

app.listen(3000, () => console.log('Listening...'));

Результат 

Listening...
Date from route: 1588616514869
i: 1
i: 2
i before response: 3
Date from winston: 1588616517889 GET /check 200 3005ms

Из результата мы видим, что вы получаете только пользовательский сообщение Date from winston: 1588616065807 от winston после того, как мы позвоним res.end('OK') вместо того, чтобы позвонить console.log('Date from route: ${Date.now()}');.

Вопрос 2:

Как мне исправить это?

Ответ:

Вместо использования по умолчанию console.log вы создаете свой собственный регистратор, в котором вы форматируете сообщение, а затем выводите его. Примерно так: 

const app = require('express')();
const winston = require('winston');

const { combine, timestamp, printf } = winston.format;
const myFormat = printf(({ message, timestamp }) => {
  const customMessage = `Date from winston: ${timestamp}`;
  return `${customMessage}\n${message}`;
});

const logger = winston.createLogger({
  transports: [
    new winston.transports.Console(),
  ],
  format: combine(timestamp(), myFormat)
});

app.get('/check', (req, res) => {
  logger.info(`Date from route: ${Date.now()}`);
  let i = 1;

  const handle = setInterval(() => {
    console.log('i:', i);
    i++;
  }, 1000);

  setTimeout(() => {
    console.log('i before response:', i);
    clearInterval(handle);
    res.end('OK');
  }, 3000);
});

app.listen(3000, () => console.log('Listening...'));

Результат 

Listening...
Date from winston: 2020-05-04T18:26:26.508Z
Date from route: 1588616786506
i: 1
i: 2
i before response: 3

В этом случае вы видите отформатированное сообщение, когда вы звоните logger.info, а не когда вы звоните res.end('OK').

В итоге используйте ваш собственный регистратор, чтобы журналы выглядели так, как вы хотите.

...