乐趣区

关于java:别再乱打日志了这样才是定位-bug-打日志的方式

概述

日常工作中,程序员须要常常解决线上的各种大小故障,如果业务代码没打印日志或者日志打印的不好,会极大的加大了定位问题的难度,使得解决 bug 的工夫变长了。

对于那种影响比拟大的 bug,解决工夫是争分夺秒的,慢几秒解决完,可能 GMV 就哗啦啦的掉了很多。

一个程序员是否优良,其中一个判断维度就是: 解决线上问题是否快狠准,而其中日志是帮咱们疾速定位问题的绝佳伎俩。

上面分享一下笔者平时在业务零碎里记日志的一些手法和习惯,心愿对大家有一些帮忙。

请对立日志格局

日志格局最好是对立的,即不便查看定位问题又不便统计收集。我个别喜爱定义一个 LogObject 对象,外面定义日志的各个字段。例如:

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: 调用链 id
  • eventName: 事件名称, 个别就是业务办法名称
  • userId: C 端用户 id
  • msg: 后果音讯
  • 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 的,间接在代码里应用 try catch finally,例如:

@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 加 thread local 的形式,将申请对立拦挡且将返回值和申请参数串起来,这个网络上的计划很多,这里就不论述了。

对于对性能要求比拟高的利用,反而举荐第一种计划,因为应用 aop,有一些性能损耗。像我之前在唯品会参加的商品聚合服务,用的就是第一种计划,毕竟每一秒要解决上百万的申请。

另外,对于怎么正确的打日志,之前也分享过,没看过的能够关注公众号:Java 技术栈,去历史文章搜寻浏览。

日志里退出 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",
         "signType":"MD5",
         "sign":"test",
         "timeStamp":"1575270929"
      }
   }
}

能够看到聚合层须要调用营销、订单和领取三个利用的接口,调用的过程中,应用 traceId 为 createOrder_1575270928956 的串了起来,这样咱们只须要 grep 这个 traceId 就能够把所有相干的调用和上下文找进去。

traceId 如何生成呢,一种简略的做法是,应用 System.currentTimeMillis() 加上业务接口名字,如:

 long beginTime = System.currentTimeMillis();
 String traceId = "createOrder_"+beginTime;

加 traceId 会侵入到业务办法里,比如说:

public void createOrder(Object obj) {long beginTime = System.currentTimeMillis();
   String traceId = "createOrder_"+beginTime;
   pmsService.getInfo(obj,traceId);
   orderService.createOrder(obj,traceId);
   payService.getPrepayId(obj,traceId);
}

像 pmsService 这些外部的 service 办法,都须要加一个 traceId 字段,目前我感觉还好,要是感觉入侵了,也能够思考 thread local 的形式,解决申请的时候,为以后线程存储一下 traceId,而后在业务办法里,再从以后线程里拿进去,防止接口办法里的 traceId 满天飞。

最初,另外,关注公众号 Java 技术栈,在后盾回复:面试,能够获取我整顿的 Java 系列面试题和答案,十分齐全。

原文:https://blog.csdn.net/linsong…

版权申明:本文为 CSDN 博主「Sam 哥哥」的原创文章,遵循 CC 4.0 BY-SA 版权协定,转载请附上原文出处链接及本申明。

近期热文举荐:

1.600+ 道 Java 面试题及答案整顿 (2021 最新版)

2. 终于靠开源我的项目弄到 IntelliJ IDEA 激活码了,真香!

3. 阿里 Mock 工具正式开源,干掉市面上所有 Mock 工具!

4.Spring Cloud 2020.0.0 正式公布,全新颠覆性版本!

5.《Java 开发手册(嵩山版)》最新公布,速速下载!

感觉不错,别忘了顺手点赞 + 转发哦!

退出移动版