node如何优雅地打印全链路日志?下面本篇文章就来给大家介绍一下在node中优雅打印全链路日志的方法,希望对大家有所帮助!
当用户报问题:线上某个功能使用报错时,如何快速准确地定位?当某个请求接口返回数据缓慢时,如何有效地追踪优化?
一、原理和实践
众所周知,当一个请求到来时,大概会有以下日志产生:
1、AceesLog:用户访问日志
2、Exception:代码异常日志
3、SQL:sql查询日志
4、ThirdParty:第三方服务日志
该如何追踪一条请求产生的所有日志?
一般做法是使用一个requestId来做唯一标识,
然后写一个中间件,把requestId注入到context上下文中,当需要打日志时,再从context中取出打印,
在第三方服务和SQL日志中,还需要把requestId传入到相应的函数里面打印,这样层层传递,实在太麻烦,代码侵入性也比较强。
我们的目标是降低代码侵入性,一次注入,自动跟踪。
经过调研,async_hooks可以追踪异步行为的生命周期,在每个异步资源(每个请求都是一个异步资源)中,它都有2个ID,
分别是asyncId(异步资源当前生命周期ID),trigerAsyncId(父级异步资源ID)。
async_hooks提供了以下生命周期钩子来监听异步资源:
asyncHook=async_hook.createHook({//监听异步资源的创建init(asyncId,type,triggerAsyncId,resource){},//异步资源回调函数开始执行之前before(asyncId){},//异步资源回调函数开始执行后after(asyncId){},//监听异步资源的销毁destroy(asyncId){}})
那如果我们做一个映射,每个asyncId映射一个storage,storage里面再存储对应的requestId,那requestId就可以很容易获取了。
正好cls-hooked这个库已经基于async_hooks做好了封装,在同一份异步资源维护一份数据,以键值对的形式存储。(注意:async_hooked需要在高版本node>=8.2.1使用)当然社区中还有其他的实现,比如cls-session,node-continuation-local-storage等。
下面讲下我把cls-hooked运用在我项目中的实例:
/session.js 创建命名存储空间
constcreateNamespace=require('cls-hooked').createNamespaceconstsession=createNamespace('requestId-store')module.exports=session
/logger.js 打印日志
constsession=require('./session')module.exports={info:(message)=>{constrequestId=session.get('requestId')console.log(`requestId:${requestId}`,message)},error:(message)=>{constrequestId=session.get('requestId')console.error(`requestId:${requestId}`,message)}}
/sequelize.js sql调用logger打印日志
constlogger=require("./logger")newSequelize(logging:function(sql,costtime){logger.error(`sqlexe:${sql}|costtime${costtime}ms`);})
/app.js 设置requestId、设置requestId返回响应头、打印访问日志
constsession=require('./session')constlogger=require('./logger')asyncfunctionaccessHandler(ctx,next){constrequestId=ctx.header['x-request-id']||uuid()constparams=ctx.request.body?JSON.stringify(ctx.request.body):JSON.stringify(ctx.request.query)//设置requestIdsession.run(()=>{session.set('requestId',requestId)logger.info(`url:${ctx.request.path};params:${params}`)next()//设置返回响应头ctx.res.setHeader('X-Request-Id',requestId)})}
我们看下当一条请求路径是/home?a=1到来时的日志:
访问日志:
requestId:79f422a6-6151-4bfd-93ca-3c6f892fb9acurl:/home;params:{"a":"1"}
Sql日志:
requestId:79f422a6-6151-4bfd-93ca-3c6f892fb9acsqlexe:Executed(default):SELECT`id`FROMt_user
可以看到同一条请求整个链路的日志requestId是一样的。如果后面有告警发到告警平台,那么我们根据requestId就可以找到这条请求执行的整个链路了。
细心的同学可能会观察到我在接口返回的响应头里面也设置了requestId,目的就是为了后续如果发现某条请求响应缓慢或者有问题,那直接从浏览器就可以知道requestId,就可以做分析了。
二、性能开销
我本地做了一下压测,
这是内存的占用对比:
比未使用async_hook多了约10%。
对于我们qps是百级别的系统还好,但是如果是高并发的服务,可能要慎重考虑下了。
ps:有错误欢迎指出,不喜勿喷
产品猿社区致力收录更多优质的商业产品,给服务商以及软件采购客户提供更多优质的软件产品,帮助开发者变现来实现多方共赢;
日常运营的过程中我们难免会遇到各种版权纠纷等问题,如果您在社区内发现有您的产品未经您授权而被用户提供下载或使用,您可按照我们投诉流程处理,点我投诉;
本文来自用户发布投稿,不代表产品猿立场 ;若对此文有疑问或内容有严重错误,可联系平台客服反馈;
部分产品是用户投稿,可能本文没有提供官方下下载地址或教程,若您看到的内容没有下载入口,您可以在我们产品园商城搜索看开发者是否有发布商品;若您是开发者,也诚邀您入驻商城平台发布的产品,地址:点我进入;
如若转载,请注明出处:https://www.chanpinyuan.cn/33245.html;