什么是全链路日志

在线上项目运行期间，经常会出现各种莫名奇妙的bug，而且一个请求往往会经过多个项目的接口调用，比如电商中的下订单，可能会调用到商品服务，优惠券满减服务，会员服务之类的，假如某一时刻下单失败，前端报了个系统异常，怎么样快速定位到底是哪个服务发生了异常，以及定位发生异常的服务具体是报了什么异常日志呢。这就是全链路日志要做的事情，它把这个请求内调用到的所有请求通过全局id串起来，通过全局id可以把所有涉及到的系统日志都快速的定位出来。

日志开发架构图

之后logstash后可能需要加queue为后续大数据做准备

技术栈

功能技术栈
日志log4js
异步资源追踪cls-hooked
web框架koa
node12
rest-传递header[trace-id]axios

思路

1
2
3
4
1. 请求打进来, 由网关下发全局唯一id
2. koa框架可以获取同步请求的上下文, 但在异步中需要上下文持久的问题(比如async_hook)
3. 需要保证当前项目所有category的log可用,且打印trace-id
4. 需要考虑解耦,避免大量修改

开发

封装log包

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
- config.json
{
  "levels": {
    "acc": {
      "value": 5000,
      "colour": "green"
    },
    "biz": {
      "value": 10000,
      "colour": "cyan"
    },
    "debug": {
      "value": 20000,
      "colour": "blue"
    },
    "warn": {
      "value": 30000,
      "colour": "yellow"
    },
    "error": {
      "value": 40000,
      "colour": "red"
    },
    "sql": {
      "value": 50000,
      "colour": "grey"
    }
  },
  "appenders": {
    "console": {
      "type": "console",
      "layout": {
        "type": "pattern",
        "pattern": "%[[%d{yyyy-MM-dd hh:mm:ss.SSS}] [%p]%] ~ %m"
      }
    },
    "acc": {
      "type": "dateFile",
      "filename": "log/acc/acc",
      "pattern": ".yyyy-MM-dd.log",
      "alwaysIncludePattern": true,
      "compress": true,
      "daysToKeep": 1,
      "layout": {
        "type": "pattern",
        "pattern": "[%d{yyyy-MM-dd hh:mm:ss.SSS}] [%p] ~ %m"
      }
    },
    "biz": {
      "type": "dateFile",
      "filename": "log/biz/biz",
      "pattern": ".yyyy-MM-dd.log",
      "alwaysIncludePattern": true,
      "compress": true,
      "daysToKeep": 1,
      "layout": {
        "type": "pattern",
        "pattern": "[%d{yyyy-MM-dd hh:mm:ss.SSS}] [%p] ~ %m"
      }
    },
    "debug": {
      "type": "dateFile",
      "filename": "log/app/debug",
      "pattern": ".yyyy-MM-dd.log",
      "alwaysIncludePattern": true,
      "compress": true,
      "daysToKeep": 1,
      "layout": {
        "type": "pattern",
        "pattern": "[%d{yyyy-MM-dd hh:mm:ss.SSS}] [%p] ~ %m"
      }
    },
    "warn": {
      "type": "dateFile",
      "filename": "log/app/warn",
      "pattern": ".yyyy-MM-dd.log",
      "alwaysIncludePattern": true,
      "compress": true,
      "daysToKeep": 1,
      "layout": {
        "type": "pattern",
        "pattern": "[%d{yyyy-MM-dd hh:mm:ss.SSS}] [%p] ~ %m"
      }
    },
    "error": {
      "type": "dateFile",
      "filename": "log/app/error",
      "pattern": ".yyyy-MM-dd.log",
      "alwaysIncludePattern": true,
      "compress": true,
      "daysToKeep": 1,
      "layout": {
        "type": "pattern",
        "pattern": "[%d{yyyy-MM-dd hh:mm:ss.SSS}] [%p] ~ %m"
      }
    },
    "sql": {
      "type": "dateFile",
      "filename": "log/sql/sql",
      "pattern": ".yyyy-MM-dd.log",
      "alwaysIncludePattern": true,
      "compress": true,
      "daysToKeep": 1,
      "layout": {
        "type": "pattern",
        "pattern": "[%d{yyyy-MM-dd hh:mm:ss.SSS}] [%p] ~ %m"
      }
    }
  },
  "categories": {
    "default": {
      "appenders": [
        "console"
      ],
      "level": "all"
    },
    "acc": {
      "appenders": [
        "acc","console"
      ],
      "level": "acc"
    },
    "biz": {
      "appenders": [
        "biz","console"
      ],
      "level": "biz"
    },
    "debug": {
      "appenders": [
        "debug","console"
      ],
      "level": "debug"
    },
    "warn": {
      "appenders": [
        "warn","console"
      ],
      "level": "warn"
    },
    "error": {
      "appenders": [
        "error","console"
      ],
      "level": "error"
    },
    "sql": {
      "appenders": [
        "sql","console"
      ],
      "level": "sql"
    }
  }
}
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
- log包核心类
const util = require('util')
const {configure, getLogger} = require('log4js')
const config = require('./config.json')
const {createNamespace} = require('cls-hooked')
const session = createNamespace('xxx')

const localIp = getLocalIp()
function getLocalIp() {
  const os = require('os');
  const ifaces = os.networkInterfaces();
  let ip = '';
  for (let dev in ifaces) {
    for (let i = 0; i < ifaces[dev].length; i++) {
      if (!ifaces[dev][i].internal && ifaces[dev][i].family === 'IPv4' && !ifaces[dev][i].address.includes('::') && ifaces[dev][i].address !== '127.0.0.1') {
        ip = ifaces[dev][i].address;
        break;
      }
    }
  }
  return ip;
}
class Logger {
  constructor(ctx, opts) {
    configure(config);
    const self = this;
    const functions = ['acc', 'biz', 'debug', 'warn', 'error', 'sql'];
    for (const fn of functions) {
      const logger = getLogger(fn);
      Logger.prototype[fn] = function(...args) {
        for (const [i, arg] of args.entries()) {
          if (typeof arg !== "object") continue;
          args[i] = util.inspect(arg, {depth: Infinity});
        }
		// appName:module名
        logger[fn].call(logger, `${opts.appName} ~ ${session.get('requestId') || '-'} ~ ${localIp} ~`, ...args);
      };
    }
	// 声明到全局
    ctx.log = this;
  }
};
module.exports = (context,opts) => {
  const log = new Logger(context,opts);
  return async (ctx, next) => {
    ctx.log = log;
    await session.runPromise(async () => {
      // 获取 requestId
      const requestId = ctx.header['trace-id'] || '-'
      ctx.res.setHeader('trace-id', requestId)
      // CLS 中设置 requestId
      session.set('requestId', requestId)
	  // 也可以去掉async,这里直接返回next()
    })
    try {
      await next();
    } catch (e) {
      ctx.log.error(e.message);
    }
  };
}

rest包

1
2
3
4
5
6
7
8
9
10
const axios = require('axios')
const {getNamespace} = require('cls-hooked')
const session = getNamespace('sopei')
...
client.get(url, {params,headers:{'trace-id': session.get('requestId')}})
                .then(res => resolve(res.data))
                .catch((err) => {
                    self.ctx.log.error(err.message, 'GET', url, logParams);
                    reject(err);
                });

koa

1
2
3
4
const app = new Koa();
// 确保logger中间件先执行
app.use(logger(app.context, { appName: xxx }));
app.use(rest(app.context))