使用 express-winston 记录：错误的日志顺序

Question

我正在使用这样的代码：

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 路由时，我在控制台中得到了这个：

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

如您所见，来自中间件的时间晚于来自路由处理程序的时间。

为什么？我该如何解决？我需要获得传递中间件的正确顺序。

Answer 1

更新

根据此 issue.

，express-winston 中尚不存在此功能

一种解决方法是在路由之前添加一个中间件来表达以拦截所有请求，然后通过自定义记录器记录所需的信息，或者创建一个 custom transport in winston for that。一个简单的例子就是

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

  next();
}

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

上一个回答

问题一：

As you can see, time from middleware is later than time from route handler. Why?

答案：

这是因为控制台传输 new winston.transports.Console() 将您的 HTTP 请求记录到控制台而不是您的 console.log(<some-text>)。这是来自 express-winston

的文档

Use expressWinston.logger(options) to create a middleware to log your HTTP requests

为了演示这一点，让我们使用您的代码并查看结果：

// 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

从结果我们看到，您只在我们调用 res.end('OK') 之后从 winston 收到自定义消息 Date from winston: 1588616065807，而不是在我们调用 console.log('Date from route: ${Date.now()}');.

时

问题二：

How can I fix it?

答案：

您可以创建自己的记录器，而不是使用默认值 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') 时，您会看到格式化的消息显示。

总而言之，使用您的自定义记录器让日志看起来像您想要的那样。

使用 express-winston 记录：错误的日志顺序

Logging with express-winston: wrong order of logs

express

winston

更新

上一个回答