Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

如何记录日志? -- node/winston #10

Open
nonocast opened this issue Mar 2, 2020 · 0 comments
Open

如何记录日志? -- node/winston #10

nonocast opened this issue Mar 2, 2020 · 0 comments

Comments

@nonocast
Copy link
Owner

@nonocast nonocast commented Mar 2, 2020

日志是程序很重要的组成部分,程序在线上只能通过日志才能观察到运行情况,所以好的日志能够帮助你了解情况,分析问题。

一般来说,日志记录应以rotate方式记录成文件,常规日志文件会采用plain text,

[INFO] 11:06:12 login ok.

但现在更多的倾向于持久化为结构化JSON,

{"requestId":"0f111049-09f9-4f8e-9306-900652c833bf","filename":"server/middleware/koa-winston.js","line":14,"level":"info","message":"--> GET /oauth/me?token=WZbxb6O5 200","timestamp":1581954414}

在生产大量日志后,经由filebeat推送到ELK进行分析,这个单开issues说明。
来看winston使用方式,

const winston = require('winston');
const { format } = winston;

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

logger.log('info', 'some message');
logger.info('some info');
logger.error('some error');

输出内容:

$ node app
info: some message
info: some info
error: some error

Log调用方法

logger.log('info', 'hello world');

logger.log({
  level: 'info',
  message: 'hello world'
});

// string interpolation
// format中必须开启format.splat()
logger.log('info', 'hello world, %s, %s', 'hui', 'http://nonocast.cn');

logger.log({
  level: 'info',
  message: 'hello world, %s, %s',
  splat: ['hui', 'http://nonocast.cn']

});


logger.log({
  level: 'info',
  message: 'hello world, %s',
  splat: ['hui'],
  tag: 'rx'
});

logger.log({
  level: 'info',
  message: 'hello world',
  user: {
    name: 'hui',
    homepage: 'http://nonocast.cn'
  }
});

注:

  • splat 就是对应 string interpolation, 实现字符串格式化。
  • level: error: 0, warn: 1, info: 2, http: 3, verbose: 4, debug: 5, silly: 6。

The info parameter provided to a given format represents a single log message. The object itself is mutable. Every info must have at least the level and message properties.

format

format是一个对info处理的chain,类似middleware:

new winston.transports.File({
  filename: 'app.log',
  format: format.combine(
    format(info => {
      info.message = strip(info.message);
      return info;
    })(),
    format.json()
  )
})

transport

transport表达的就是记录通道,这个比较容易理解。

container

借由winson.loggers这个container管理多个logger。
比如一个category给service,一个给web controller。

winston.loggers.add('category1', { format: ..., transports: ... });
winston.loggers.add('category2', { format: ..., transports: ... });

let logger = winson.loggers.get('category2');

error

format.errors({ stack: true })

然后如果 info(new Error(...)) 就会输出stack

输出的stack内容,

{"level":"info","message":"Yo, it's on fire","stack":"Error: Yo, it's on fire\n at Object. (/Users/nonocast/Desktop/hello-winston/app.js:34:20)\n at Module._compile (internal/modules/cjs/loader.js:701:30)\n at Object.Module._extensions..js (internal/modules/cjs/loader.js:712:10)\n at Module.load (internal/modules/cjs/loader.js:600:32)\n at tryModuleLoad (internal/modules/cjs/loader.js:539:12)\n at Function.Module._load (internal/modules/cjs/loader.js:531:3)\n at Function.Module.runMain (internal/modules/cjs/loader.js:754:12)\n at startup (internal/bootstrap/node.js:283:19)\n at bootstrapNodeJSCore (internal/bootstrap/node.js:622:3)"}

query

可以通过logger查询记录,这个可以的。

const options = {
  from: moment().subtract(1, 'hours').unix(),
  until: moment().unix(),
  limit: 10,
  start: 0,
  order: 'desc',
  fields: ['message']
};

//
// Find items logged between today and yesterday.
//
logger.query(options, function (err, results) {
  if (err) {
    /* TODO: handle me */
    throw err;
  }

  console.log(results);
});

Koa 整合

先来看koa-logger,

const logger = require('koa-logger');
app.use(logger());

一个请求输出两个,但是信息量实在太少了,

 <-- GET /
  --> GET / 200 9ms 12b

然后logger可以拦截,

  .use(logger((str, args) => {
    // redirect koa logger to other output pipe
    // default is process.stdout(by console.log function)

}));
  • Param str is output string with ANSI Color, and you can get pure text with other modules like strip-ansi. 带颜色的字符串。
  • Param args is a array by [format, method, url, status, time, length]

整个koa-logger连注释157行,简单看一下他是怎么拦截请求的:

  • 在middleware先行log请求
  • 然后在await next()等同于所有middleware结束以后再记录结束log

所以我们借用这个套路配合koa-requestid写一个koa-winston的middleware,

const chalk = require('chalk');

module.exports = (logger) => {
  return async function (ctx, next) {
    let child = logger.child({ requestId: ctx.state.id });

    ctx.logger = child;

    ctx.logger.info(`${chalk.gray('<--')} ${chalk.bold(ctx.method)} ${chalk.gray(ctx.originalUrl)}`);

    try {
      await next()
    } catch (err) {
      ctx.logger.warn(err);
      throw err
    }

    ctx.logger.info(`${chalk.gray('-->')} ${chalk.bold(ctx.method)} ${chalk.gray(ctx.originalUrl)}`);
  }
}
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Linked pull requests

Successfully merging a pull request may close this issue.

None yet
1 participant
You can’t perform that action at this time.