温斯顿记录器自定义格式覆盖时间戳

Question

我在节点应用程序中使用 winston 记录器版本 3.3.3。我有一个用于输出的自定义格式化程序，如下所示：

const winston = require('winston');
const jsonStr = require('fast-safe-stringify');

const customFormat = winston.format.printf(data => {
    const { level, message, timestamp } = data;
    const args = data[Symbol.for('splat')];

    let strArgs = '';

    if (args) {
        strArgs = args.map(jsonStr).join(' ');
    } 

    return `${timestamp} ${level}: ${message} ${strArgs}\n`;
});

logger = winston.createLogger({
    level: 'debug',
    format: winston.format.combine(winston.format.timestamp(), customFormat),
    transports: [new winston.transports.Console()]
});

logger.log('debug', 'hi', 123, { a: 1, b: 'two' });
logger.log('debug', 'hi', { timestamp: 'this is bad' });

这让我可以用不同类型的多个参数记录事物：

logger.log('debug', 'hi', 123, { a: 1, b: 'two' });
> 2020-11-11T19:01:46.942Z debug: hi 123 {"a":1,"b":"two"}

这就是我想要的。问题是，如果我记录一个包含名为 timestamp 的字段的对象，它会覆盖格式化程序中的 timestamp 字段。

logger.log('debug', 'hi', { timestamp: 'this is bad' } );
> this is bad debug: hi {"timestamp":"this is bad"}

所以现在记录器的时间戳是字符串"this is bad"，这很糟糕。如果我将data 参数输出到printf() 方法，我会看到：

{
    timestamp: 'this is bad',
    level: 'debug',
    message: 'hi',
    [Symbol(level)]: 'debug',
    [Symbol(splat)]: [ { timestamp: 'this is bad' } ] }
}

所以你可以看到timestamp 字段显然被我传入的参数覆盖了。只有当log() 方法的第三个参数是一个具有名为timestamp 的属性的对象时才会发生这种情况。所以这很好：

logger.log('debug', 'hi', 123, { timestamp: 'this is fine' } );

data: {
    level: 'debug',
    message: 'hi',
    timestamp: '2020-11-11T19:08:27.326Z',
    [Symbol(level)]: 'debug',
    [Symbol(splat)]: [ 123, { timestamp: 'this is fine' } ]
}
> 2020-11-11T19:08:27.326Z debug: hi 123 {"timestamp":"this is fine"}

这是 winston 中的错误还是我的 printf() 方法不对？

请注意，我有一个 git repo 可以重现此问题 here。

Answer 1

一个简单的解决方案是为timeStamp.format() 中的时间戳添加格式或别名，如下所示

logger = winston.createLogger({
    level: 'debug',
    format: winston.format.combine(
        winston.format.timestamp({ format: 'YYYY-MM-DD HH:mm:ss' }), // can also alias
        customFormat
    ),
    transports: [new winston.transports.Console()]
});

logger.log('debug', 'hi', { timestamp: 'this is bad' } );

// outputs
2020-11-19 20:08:36 debug: hi {"timestamp":"this is bad"}
{
  timestamp: '2020-11-19 20:08:36',
  level: 'debug',
  message: 'hi',
  [Symbol(level)]: 'debug',
  [Symbol(splat)]: [ { timestamp: 'this is bad' } ]
}

进入解释部分，我实际上不确定为什么 timeStamp 会被覆盖，这很奇怪。

Answer 2

嘿）我试图重现你的情况，但我无法重现。试试这个代码

const winston = require('winston');

const customFormat = winston.format.printf((data) => {
  const { level, message, timestamp } = data;
  console.log('data', data);
  const args = data[Symbol.for('splat')];

  let strArgs = '';

  if (args) {
    console.log('args', args);
    strArgs = args.map((argument) => JSON.stringify(argument)).join(' ');
  }

  return `${timestamp} ${level}: ${message} ${strArgs}\n`;
});

const logger = winston.createLogger({
  format: customFormat,
  transports: [
    new winston.transports.Console({
      level: 'debug',
    }),
  ],
});

logger.log('debug', 'hi', 123, { a: 1, b: 'two' });
// logger.log('debug', 'hi', { timestamp: 'this is bad' });

我检查过，在第一种情况下时间戳是未定义的。在第二种情况下，我得到了时间戳：'这很糟糕'。温斯顿没有将他自己的时间戳传递给我的日志信息。