基于Egg框架的日志链路追踪实践分享

快速导航

需求背景

实现全链路日志追踪,便于日志监控、问题排查、接口响应耗时数据统计等,首先 API 接口服务接收到调用方请求,根据调用方传的 traceId,在该次调用链中处理业务时,如需打印日志的,日志信息按照约定的规范进行打印,并记录 traceId,实现日志链路追踪。

  • 日志路径约定
/var/logs/${projectName}/bizLog/${projectName}-yyyyMMdd.log
  • 日志格式约定
日志时间[]traceId[]服务端IP[]客户端IP[]日志级别[]日志内容

采用 Egg.js 框架 egg-logger 中间件,在实现过程中发现对于按照以上日志格式打印是无法满足需求的(至少目前我还没找到可实现方式),如果要自己实现,可能要自己造轮子了,好在官方的 egg-logger 中间件提供了自定义日志扩展功能,参考 高级自定义日志,本身也提供了日志分割、多进程日志处理等功能。

egg-logger 提供了多种传输通道,我们的需求主要是对请求的业务日志自定义格式存储,主要用到 fileTransport 和 consoleTransport 两个通道,分别打印日志到文件和终端。

自定义日志插件开发

基于 egg-logger 定制开发一个插件项目,参考 插件开发,以下以 egg-logger-custom 为项目,展示核心代码编写

  • 编写logger.js

egg-logger-custom/lib/logger.js

const moment = require('moment');
const FileTransport = require('egg-logger').FileTransport;
const utils = require('./utils');
const util = require('util');

/**
 * 继承 FileTransport
 */
class AppTransport extends FileTransport {
    constructor(options, ctx) {
        super(options);

        this.ctx = ctx; // 得到每次请求的上下文
    }

    log(level, args, meta) {
        // 获取自定义格式消息
        const customMsg = this.messageFormat({
            level,
        });

        // 针对 Error 消息打印出错误的堆栈
        if (args[0] instanceof Error) {
            const err = args[0] || {};
            args[0] = util.format('%s: %s\n%s\npid: %s\n', err.name, err.message, err.stack, process.pid);
        } else {
            args[0] = util.format(customMsg, args[0]);
        }

        // 这个是必须的,否则日志文件不会写入
        super.log(level, args, meta);
    }

    /**
     * 自定义消息格式
     * 可以根据自己的业务需求自行定义
     * @param { String } level
     */
    messageFormat({
        level
    }) {
        const { ctx } = this;
        const params = JSON.stringify(Object.assign({}, ctx.request.query, ctx.body));

        return [
            moment().format('YYYY/MM/DD HH:mm:ss'),
            ctx.request.get('traceId'),
            utils.serviceIPAddress,
            utils.clientIPAddress(ctx.req),
            level,
        ].join(utils.loggerDelimiter) + utils.loggerDelimiter;
    }
}

module.exports = AppTransport;
  • 工具

egg-logger-custom/lib/utils.js

const interfaces = require('os').networkInterfaces();

module.exports = {

    /**
     * 日志分隔符
     */
    loggerDelimiter: '[]',

    /**
     * 获取当前服务器IP
     */
    serviceIPAddress: (() => {
        for (const devName in interfaces) {
            const iface = interfaces[devName];

            for (let i = 0; i < iface.length; i++) {
                const alias = iface[i];

                if (alias.family === 'IPv4' && alias.address !== '127.0.0.1' && !alias.internal) {
                    return alias.address;
                }
            }
        }
    })(),

    /**
     * 获取当前请求客户端IP
     * 不安全的写法
     */
    clientIPAddress: req => {
        const address = req.headers['x-forwarded-for'] || // 判断是否有反向代理 IP
        req.connection.remoteAddress || // 判断 connection 的远程 IP
        req.socket.remoteAddress || // 判断后端的 socket 的 IP
        req.connection.socket.remoteAddress;

        return address.replace(/::ffff:/ig, '');
    },

    clientIPAddress: ctx => {    
        return ctx.ip;
    },
}

注意:以上获取当前请求客户端IP的方式,如果你需要对用户的 IP 做限流、防刷限制,请不要使用如上方式,参见 科普文:如何伪造和获取用户真实 IP ?,在 Egg.js 里你也可以通过 ctx.ip 来获取,参考 前置代理模式

  • 初始化 Logger
egg-logger-custom/app.js
const Logger = require('egg-logger').Logger;
const ConsoleTransport = require('egg-logger').ConsoleTransport;
const AppTransport = require('./app/logger');

module.exports = (ctx, options) => {
    const logger = new Logger();

    logger.set('file', new AppTransport({
        level: options.fileLoggerLevel || 'INFO',
        file: `/var/logs/${options.appName}/bizLog/${options.appName}.log`,
    }, ctx));

    logger.set('console', new ConsoleTransport({
        level: options.consoleLevel || 'INFO',
    }));

    return logger;
}

以上对于日志定制格式开发已经好了,如果你有实际业务需要可以根据自己团队的需求,封装为团队内部的一个 npm 中间件来使用。

项目扩展

自定义日志中间件封装好之后,在实际项目应用中我们还需要一步操作,Egg 提供了 框架扩展 功能,包含五项:Application、Context、Request、Response、Helper,可以对这几项进行自定义扩展,对于日志因为每次日志记录我们需要记录当前请求携带的 traceId 做一个链路追踪,需要用到 Context(是 Koa 的请求上下文) 扩展项。

新建 app/extend/context.js 文件

const AppLogger = require('egg-logger-custom'); // 上面定义的中间件

module.exports = {
    get logger() { // 名字自定义 也可以是 customLogger
        return AppLogger(this, {
            appName: 'test', // 项目名称
            consoleLevel: 'DEBUG', // 终端日志级别
            fileLoggerLevel: 'DEBUG', // 文件日志级别
        });
    }
}

建议:对于日志级别,可以采用配置中心如 Consul 进行配置,上线时日志级别设置为 INFO,当需要生产问题排查时,可以动态开启 DEBUG 模式。关于 Consul 可以关注我之前写的 服务注册发现 Consul 系列

项目应用

错误日志记录,直接会将错误日志完整堆栈信息记录下来,并且输出到 errorLog 中,为了保证异常可追踪,必须保证所有抛出的异常都是 Error 类型,因为只有 Error 类型才会带上堆栈信息,定位到问题。

const Controller = require('egg').Controller;

class ExampleController extends Controller {
    async list() {
        const { ctx } = this;

        ctx.logger.error(new Error('程序异常!'));

        ctx.logger.debug('测试');

        ctx.logger.info('测试');
    }
}

最终日志打印格式如下所示:

2019/05/30 01:50:21[]d373c38a-344b-4b36-b931-1e8981aef14f[]192.168.1.20[]221.69.245.153[]INFO[]测试

contextFormatter自定义日志格式

Egg-Logger 最新版本支持通过 contextFormatter 函数自定义日志格式,参见之前 PR:support contextFormatter #51

应用也很简单,通过配置 contextFormatter 函数即可,以下是简单的应用

config.logger = {
    contextFormatter: function(meta) {
        console.log(meta);
        return [
            meta.date,
            meta.message
        ].join('[]')
    },
    ...
};

同样的在你的业务里对于需要打印日志的地方,和之前一样

ctx.logger.info('这是一个测试数据');

输出结果如下所示:

2019-06-04 12:20:10,421[]这是一个测试数据

日志切割

框架提供了 egg-logrotator 中间件,默认切割为按天切割,其它方式可参考官网自行配置。

  • 框架默认日志路径

egg-logger 模块 lib/egg/config/config.default.js

config.logger = {
    dir: path.join(appInfo.root, 'logs', appInfo.name),
    ...
};
  • 自定义日志目录

很简单按照我们的需求在项目配置文件重新定义 logger 的 dir 路径

config.logger = {
    dir: /var/logs/test/bizLog/
}

这样是否就可以呢?按照我们上面自定义的日志文件名格式(${projectName}-yyyyMMdd.log),貌似是不行的,在日志分割过程中默认的文件名格式为 .log.YYYY-MM-DD,参考源码

https://github.com/eggjs/egg-logrotator/blob/master/app/lib/day_rotator.js

 _setFile(srcPath, files) {
    // don't rotate logPath in filesRotateBySize
    if (this.filesRotateBySize.indexOf(srcPath) > -1) {
      return;
    }

    // don't rotate logPath in filesRotateByHour
    if (this.filesRotateByHour.indexOf(srcPath) > -1) {
      return;
    }

    if (!files.has(srcPath)) {
      // allow 2 minutes deviation
      const targetPath = srcPath + moment()
        .subtract(23, 'hours')
        .subtract(58, 'minutes')
        .format('.YYYY-MM-DD'); // 日志格式定义
      debug('set file %s => %s', srcPath, targetPath);
      files.set(srcPath, { srcPath, targetPath });
    }
 }
  • 日志分割扩展

中间件 egg-logrotator 预留了扩展接口,对于自定义的日志文件名,可以用框架提供的 app.LogRotator 做一个定制。

app/schedule/custom.js

const moment = require('moment');

module.exports = app => {
    const rotator = getRotator(app);

    return {
        schedule: {
            type: 'worker', // only one worker run this task
            cron: '1 0 0 * * *', // run every day at 00:00
        },
        async task() {
            await rotator.rotate();
        }
    };
};

function getRotator(app) {
    class CustomRotator extends app.LogRotator {
        async getRotateFiles() {
            const files = new Map();
            const srcPath = `/var/logs/test/bizLog/test.log`;
            const targetPath = `/var/logs/test/bizLog/test-${moment().subtract(1, 'days').format('YYYY-MM-DD')}.log`;
            files.set(srcPath, { srcPath, targetPath });
            return files;
        }
    }

    return new CustomRotator({ app });
}

经过分割之后文件展示如下:

$ ls -lh /var/logs/test/bizLog/
total 188K
-rw-r--r-- 1 root root 135K Jun  1 11:00 test-2019-06-01.log
-rw-r--r-- 1 root root  912 Jun  2 09:44 test-2019-06-02.log
-rw-r--r-- 1 root root  40K Jun  3 11:49 test.log

扩展:基于以上日志格式,可以采用 ELK 做日志搜集、分析、检索。

作者:五月君
链接:https://www.imooc.com/article/287529
来源:慕课网

阅读推荐

最后编辑于
©著作权归作者所有,转载或内容合作请联系作者
  • 序言:七十年代末,一起剥皮案震惊了整个滨河市,随后出现的几起案子,更是在滨河造成了极大的恐慌,老刑警刘岩,带你破解...
    沈念sama阅读 206,602评论 6 481
  • 序言:滨河连续发生了三起死亡事件,死亡现场离奇诡异,居然都是意外死亡,警方通过查阅死者的电脑和手机,发现死者居然都...
    沈念sama阅读 88,442评论 2 382
  • 文/潘晓璐 我一进店门,熙熙楼的掌柜王于贵愁眉苦脸地迎上来,“玉大人,你说我怎么就摊上这事。” “怎么了?”我有些...
    开封第一讲书人阅读 152,878评论 0 344
  • 文/不坏的土叔 我叫张陵,是天一观的道长。 经常有香客问我,道长,这世上最难降的妖魔是什么? 我笑而不...
    开封第一讲书人阅读 55,306评论 1 279
  • 正文 为了忘掉前任,我火速办了婚礼,结果婚礼上,老公的妹妹穿的比我还像新娘。我一直安慰自己,他们只是感情好,可当我...
    茶点故事阅读 64,330评论 5 373
  • 文/花漫 我一把揭开白布。 她就那样静静地躺着,像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上,一...
    开封第一讲书人阅读 49,071评论 1 285
  • 那天,我揣着相机与录音,去河边找鬼。 笑死,一个胖子当着我的面吹牛,可吹牛的内容都是我干的。 我是一名探鬼主播,决...
    沈念sama阅读 38,382评论 3 400
  • 文/苍兰香墨 我猛地睁开眼,长吁一口气:“原来是场噩梦啊……” “哼!你这毒妇竟也来了?” 一声冷哼从身侧响起,我...
    开封第一讲书人阅读 37,006评论 0 259
  • 序言:老挝万荣一对情侣失踪,失踪者是张志新(化名)和其女友刘颖,没想到半个月后,有当地人在树林里发现了一具尸体,经...
    沈念sama阅读 43,512评论 1 300
  • 正文 独居荒郊野岭守林人离奇死亡,尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 35,965评论 2 325
  • 正文 我和宋清朗相恋三年,在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 38,094评论 1 333
  • 序言:一个原本活蹦乱跳的男人离奇死亡,死状恐怖,灵堂内的尸体忽然破棺而出,到底是诈尸还是另有隐情,我是刑警宁泽,带...
    沈念sama阅读 33,732评论 4 323
  • 正文 年R本政府宣布,位于F岛的核电站,受9级特大地震影响,放射性物质发生泄漏。R本人自食恶果不足惜,却给世界环境...
    茶点故事阅读 39,283评论 3 307
  • 文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹,春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 30,286评论 0 19
  • 文/苍兰香墨 我抬头看了看天上的太阳。三九已至,却和暖如春,着一层夹袄步出监牢的瞬间,已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 31,512评论 1 262
  • 我被黑心中介骗来泰国打工, 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留,地道东北人。 一个月前我还...
    沈念sama阅读 45,536评论 2 354
  • 正文 我出身青楼,却偏偏与公主长得像,于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子,可洞房花烛夜当晚...
    茶点故事阅读 42,828评论 2 345

推荐阅读更多精彩内容