切记，这样打日志定位Bug又快又准

　　概述
　　日常工作中，程序员需要经常处理线上的各种大小故障，如果业务代码没打印日志或者日志打印的不好，会极大的加大了定位问题的难度，使得解决bug的时间变长了。对于那种影响比较大的bug，处理时间是分秒必争的，慢几秒处理完，可能GMV就哗啦啦的掉了很多。
　　一个程序员是否优秀，其中一个判断维度就是：处理线上问题是否快狠准，而其中日志是帮我们快速定位问题的绝佳手段。
　　下面分享一下笔者平时在业务系统里记日志的一些手法和习惯，希望对大家有一些帮助。请统一日志格式
　　日志格式最好是统一的，即方便查看定位问题又方便统计收集。我一般喜欢定义一个LogObject对象，里面定义日志的各个字段。例如：importcom。fasterxml。jackson。annotation。JsonInclude；importcom。fasterxml。jackson。annotation。JsonInclude。Include；importcom。fasterxml。jackson。annotation。JsonProperty；publicclassLogObject｛JsonProperty（index1）privateStringeventName；JsonProperty（index2）privateStringtraceId；JsonProperty（index3）privateStringmsg；JsonProperty（index4）privatelongcostTime；JsonProperty（index6）privateIntegeruserId；JsonProperty（index7）privateObjectothers；JsonProperty（index8）privateObjectrequest；JsonProperty（index9）privateObjectresponse；publicStringgetEventName（）｛returneventName；｝publicLogObjectsetEventName（StringeventName）｛this。eventNameeventName；returnthis；｝publicObjectgetRequest（）｛returnrequest；｝publicLogObjectsetRequest（Objectrequest）｛this。requestrequest；returnthis；｝publicObjectgetResponse（）｛returnresponse；｝publicLogObjectsetResponse（Objectresponse）｛this。responseresponse；returnthis；｝publicStringgetMsg（）｛returnmsg；｝publicLogObjectsetMsg（Stringmsg）｛this。msgmsg；returnthis；｝publiclonggetCostTime（）｛returncostTime；｝publicLogObjectsetCostTime（longcostTime）｛this。costTimecostTime；returnthis；｝publicIntegergetUserId（）｛returnuserId；｝publicLogObjectsetUserId（IntegeruserId）｛this。userIduserId；returnthis；｝publicObjectgetOthers（）｛returnothers；｝publicLogObjectsetOthers（Objectothers）｛this。othersothers；returnthis；｝publicStringgetTraceId（）｛returntraceId；｝publicLogObjectsetTraceId（StringtraceId）｛this。traceIdtraceId；returnthis；｝
　　traceId：调用链id
　　eventName：事件名称，一般就是业务方法名称
　　userId：C端用户id
　　msg：结果消息
　　costTime：接口响应时间
　　request：接口请求入参
　　response：接口返回值
　　others：其他业务参数
　　使用链式的风格，方便设置字段的值：longendTimeSystem。currentTimeMillis（）；LogObjectlogObjectnewLogObject（）；logObject。setEventName（methodName）。setMsg（msg）。setTraceId（traceId）。setUserId（backendId）。setRequest（liveRoomPushOrderReqDto）。setResponse（response）。setCostTime（（endTimebeginTime））；LOGGER。info（JSON。toJSONString（logObject））；
　　当然最好还是封装出一个工具类出来，例如叫：LogTemplate，作为一个统一的入口。另外可以使用JsonProperty注解，指定字段的顺序，例如通过index1，将eventName放置在最前面。JsonProperty（index1）privateStringeventName；将request和response放置在一起
　　将请求和返回值，放置在同一条日志里，有个好处，就是非常方便查看上下文日志。如果打印成两条，返回值那条可能被冲到很后面，而且也得再做一次grep操作，影响效率。
　　具体的日志如下：｛eventName：createOrder，traceId：createOrder1574923602015，msg：success，costTime：317，request：｛uId：111111111，skuList：〔｛skuId：22222222，buyNum：1，buyPrice：8800，｝〕｝，response：｛code：0，message：操作成功，data：｛bigOrderId：BIG2019，m2LOrderIds：｛MID2019：｛22222222：LIT2019｝｝｝｝｝
　　为了能拼成一条，有两种方案，一种是比较low的，直接在代码里使用trycatchfinally，例如：PostMapping（valuecreateOrder）publicJsonResultcreateOrder（RequestBodyObjectrequest）throwsException｛StringmethodNamecreateOrder；IntegerbackendIdnull；Stringmsgsuccess；longbeginTimeSystem。currentTimeMillis（）；StringtraceIdcreateOrderbeginTime；JsonResultresponsenull；try｛OrderCreateRsporderCreateRsporderOperateService。createOrder（request，traceId）；responseJsonResult。success（orderCreateRsp）；｝catch（Exceptione）｛msge。getMessage（）；LOGGER。error（methodName，userId：backendId，request：JsonHelper。toJson（request），e）；thrownewBizException（0，下单失败）；｝finally｛longendTimeSystem。currentTimeMillis（）；LogObjectlogObjectnewLogObject（）；logObject。setEventName（methodName）。setMsg（msg）。setTraceId（traceId）。setUserId（backendId）。setRequest（request）。setResponse（response）。setCostTime（（endTimebeginTime））；LOGGER。info（JSON。toJSONString（logObject））；｝returnresponse；｝
　　这种方案呢，有个缺点，就是每个业务方法都得处理日志，更好的方案是使用aop加threadlocal的方式，将请求统一拦截且将返回值和请求参数串起来，这个网络上的方案很多，这里就不阐述了。
　　对于对性能要求比较高的应用，反而推荐第一种方案，因为使用aop，有一些性能损耗。像我之前在唯品会参与的商品聚合服务，用的就是第一种方案，毕竟每一秒要处理上百万的请求。另外，附送学习资源：Java进阶视频资源日志里加入traceId
　　如果应用中已经使用了统一调用链监控方案，且能根据调用链id查询接口情况的，可以不用在代码里手动加入traceId。如果应用还没接入调用链系统，建议加一下traceId，尤其是针对聚合服务，需要调用中台各种微服务接口的。像聚合层下单业务，需要调用的微服务就有如下这么些：营销系统订单系统支付系统
　　下单业务调用这些接口的时候，如果没有使用traceId进行跟踪的话，当下单失败的时候，到底是哪个微服务接口失败了，就比较难找。下面以小程序端，调用聚合层下单接口的例子作为展示：营销系统｛eventName：pmsgetInfo，traceId：createOrder1575270928956，msg：success，costTime：2，userId：1111111111，request：｛userId：1111111111，skuList：〔｛skuId：2222，skuPrice：65900，buyNum：1，activityType：0，activityId：0，｝〕，｝，response：｛result：1，msg：success，data：｛realPayFee：100，｝｝｝订单系统｛eventName：orderservicecreateOrder，traceId：createOrder1575270928956，msg：success，costTime：29，userId：null，request：｛skuList：〔｛skuId：2222，buyNum：1，buyPrice：65900，｝〕，｝，response：｛result：200，msg：调用成功，data：｛bigOrderId：BIG2019，m2LOrderIds：｛MID2019：｛88258135：LIT2019｝｝｝｝｝支付系统｛eventName：payservicepay，traceId：createOrder1575270928956，msg：success，costTime：301，request：｛orderId：BIG2019，paySubject：测试，totalFee：65900，｝，response：｛requestId：test，code：0，message：操作成功，data：｛payId：123，orderId：BIG2019，tradeType：JSAPI，perpayId：test，nonceStr：test，appId：test，signType：MD5，sign：test，timeStamp：1575270929｝｝｝
　　可以看到聚合层需要调用营销、订单和支付三个应用的接口，调用的过程中，使用traceId为createOrder1575270928956的串了起来，这样我们只需要grep这个traceId就可以把所有相关的调用和上下文找出来。
　　traceId如何生成呢，一种简单的做法是，使用System。currentTimeMillis（）加上业务接口名字，如：longbeginTimeSystem。currentTimeMillis（）；StringtraceIdcreateOrderbeginTime；加traceId会侵入到业务方法里，比如说：publicvoidcreateOrder（Objectobj）｛longbeginTimeSystem。currentTimeMillis（）；StringtraceIdcreateOrderbeginTime；pmsService。getInfo（obj，traceId）；orderService。createOrder（obj，traceId）；payService。getPrepayId（obj，traceId）；｝
　　像pmsService这些内部的service方法，都需要加一个traceId字段，目前我觉得还好，要是觉得入侵了，也可以考虑threadlocal的方式，处理请求的时候，为当前线程存储一下traceId，然后在业务方法里，再从当前线程里拿出来，避免接口方法里的traceId满天飞。