别再乱打日志了这样才是定位 bug 打日志的方式

别再乱打日志了，这样才是定位bug打日志的方式！概述请统一日志格式将request和response放置在一起日志里加入traceId概述日常工作中，程序员需要经常处理线上的各种大小故障，如果业务代码没打印日志或者日志打印的不好，会极大的加大了定位问题的难度，使得解决bug的时间变长了。对于那种影响比较大的bug，处理时间是分秒必争的，慢几秒处理完，可能GMV就哗啦啦的掉了很多。一个程序员是否优秀，其中一个判断维度就是：处理线上问题是否快狠准，而其中日志是帮我们快速定位问题的绝佳手段。下面分享一下笔者平时在业务系统里记日志的一些手法和习惯，希望对大家有一些帮助。请统一日志格式日志格式最好是统一的，即方便查看定位问题又方便统计收集。我一般喜欢定义一个LogObject对象，里面定义日志的各个字段。例如：搜索公众号顶级架构师后台回复“offer”，获取一份惊喜礼包。import

com.fasterxml.jackson.annotation.JsonInclude;

import

com.fasterxml.jackson.annotation.JsonInclude.Include;

import

com.fasterxml.jackson.annotation.JsonProperty;

public

class

LogObject

{

@JsonProperty(index

=

1)

private

String

eventName;

@JsonProperty(index

=

2)

private

String

traceId;

@JsonProperty(index

=

3)

private

String

msg;

@JsonProperty(index

=

4)

private

long

costTime;

@JsonProperty(index

=

6)

private

Integer

userId;

@JsonProperty(index

=

7)

private

Object

others;

@JsonProperty(index

=

8)

private

Object

request;

@JsonProperty(index

=

9)

private

Object

response;

public

String

getEventName()

{

return

eventName;

}

public

LogObject

setEventName(String

eventName)

{

this.eventName

=

eventName;

return

this;

}

public

Object

getRequest()

{

return

request;

}

public

LogObject

setRequest(Object

request)

{

this.request

=

request;

return

this;

}

public

Object

getResponse()

{

return

response;

}

public

LogObject

setResponse(Object

response)

{

this.response

=

response;

return

this;

}

public

String

getMsg()

{

return

msg;

}

public

LogObject

setMsg(String

msg)

{

this.msg

=

msg;

return

this;

}

public

long

getCostTime()

{

return

costTime;

}

public

LogObject

setCostTime(long

costTime)

{

this.costTime

=

costTime;

return

this;

}

public

Integer

getUserId()

{

return

userId;

}

public

LogObject

setUserId(Integer

userId)

{

this.userId

=

userId;

return

this;

}

public

Object

getOthers()

{

return

others;

}

public

LogObject

setOthers(Object

others)

{

this.others

=

others;

return

this;

}

public

String

getTraceId()

{

return

traceId;

}

public

LogObject

setTraceId(String

traceId)

{

this.traceId

=

traceId;

return

this;

}traceId:调用链iduserId:C端用户idmsg:结果消息costTime:接口响应时间request:接口请求入参response:接口返回值others:其他业务参数使用链式的风格，方便设置字段的值：long

endTime

=

System.currentTimeMillis();

LogObject

logObject

=

new

LogObject();

logObject.setEventName(methodName)

.setMsg(msg)

.setTraceId(traceId)

.setUserId(backendId)

.setRequest(liveRoomPushOrderReqDto)

.setResponse(response)

.setCostTime((endTime

-

beginTime));

LOGGER.info(JSON.toJSONString(logObject));当然最好还是封装出一个工具类出来,例如叫:LogTemplate，作为一个统一的入口。另外可以使用JsonProperty注解，指定字段的顺序，例如通过index=1，将eventName放置在最前面。@JsonProperty(index

=

1)

private

String

eventName;将request和response放置在一起将请求和返回值，放置在同一条日志里，有个好处，就是非常方便查看上下文日志。如果打印成两条，返回值那条可能被冲到很后面，而且也得再做一次grep操作，影响效率。具体的日志如下：{

"eventName":"createOrder",

"traceId":"createOrder_1574923602015",

"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(value

=

"/createOrder")

public

JsonResult

createOrder(@RequestBody

Object

request)

throws

Exception

{

String

methodName

=

"/createOrder";

Integer

backendId

=

null;

String

msg

=

"success";

long

beginTime

=

System.currentTimeMillis();

String

traceId

=

"createOrder_"+beginTime;

JsonResult

response

=

null;

try

{

OrderCreateRsp

orderCreateRsp

=

orderOperateService.createOrder(request,

traceId);

response

=

JsonResult.success(orderCreateRsp);

}

catch

(Exception

e)

{

msg

=

e.getMessage();

LOGGER.error(methodName+",userId:"+backendId+",request:"+

JsonHelper.toJson(request),e);

throw

new

BizException(0,"下单失败");

}

finally

{

long

endTime

=

System.currentTimeMillis();

LogObject

logObject

=

new

LogObject();

logObject.setEventName(methodName)

.setMsg(msg)

.setTraceId(traceId)

.setUserId(backendId)

.setRequest(request)

.setResponse(response)

.setCostTime((endTime

-

beginTime));

LOGGER.info(JSON.toJSONString(logObject));

}

return

response;

}[种方案呢，有个缺点，就是每个业务方法都得处理日志，更好的方案是使用aop加threadlocal的方式，将请求统一拦截且将返回值和请求参数串起来，这个网络上的方案很多，这里就不阐述了。搜索公众号后端架构师后台回复“架构整洁”，获取一份惊喜礼包。对于对性能要求比较高的应用，反而推荐第一种方案，因为使用aop，有一些性能损耗。像我之前在唯品会参与的商品聚合服务，用的就是第一种方案，毕竟每一秒要处理上百万的请求。日志里加入traceId如果应用中已经使用了统一调用链监控方案，且能根据调用链id查询接口情况的，可以不用在代码里手动加入traceId。如果应用还没接入调用链系统，建议加一下traceId，尤其是针对聚合服务，需要调用中台各种微服务接口的。像聚合层下单业务，需要调用的微服务就有如下这么些：营销系统订单系统支付系统下单业务调用这些接口的时候，如果没有使用traceId进行跟踪的话，当下单失败的时候，到底是哪个微服务接口失败了，就比较难找。下面以小程序端，调用聚合层下单接口的例子作为展示：营销系统：{

"eventName":"pms/getInfo",

"traceId":"createOrder_1575270928956",

"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":"orderservice/createOrder",

"traceId":"createOrder_1575270928956",

"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":"payservice/pay",

"traceId":"createOrder_1575270928956",

"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",

"