一、背景

java后端研发过程中，日志是必不可少的工具。

我们在打印日志中经常遇到的一个情况就是打印对象，打印对象的常用方案就是toJsonString后打印。

典型例子如下：

log.info("sync2JhForOldBizJingKa,end,targetBizInfo:{},result:{}", targetBizInfo,JSON.toJSONString(result));

二、问题

这种写法在我们平常日志级别固定不用更改级别的时候还好,性能谈不上有问题。但是遇到11.11、618等大促场景的时候，我们可能就会对线上日志进行降级处理，例如：日志级别从INFO调整为ERROR。这个时候就会遇到了日志性能问题。

我们通过对日志打印的过程整体链路进行分析得出如下概要执行处理步骤：

a、日志参数部分的 JSON.toJSONString() 方法处理。

b、日志框架内部的 isInfoEnabled() 日志级别方法判断。

这块对应的日志代码内部实现截图如下：

JAVA日志toJSON打印的优化写法_日志框架



c、日志内部进行要打印的日志占位符拼装。即把日志占位符”{}“部分替换为要打印的内容。

本例中就是"sync2JhForOldBizJingKa,end,targetBizInfo:{},result:{}"中”{}“替换为相关信息的过程。

d、日志IO操作，把日志打印到机器文件上去。

就是把信息打印到 xxxx.log文件上的过程。



那么结合我们日志从INFO降级为ERROR的过程可以分析下我们的日志打印过程。

日志级别为INFO的时候：a->b->c->d->end。

日志级别为ERROR的时候：a->b->end。



我们可以看出造成日志级别切换时候引发的性能问题原因，主要是 JSON.toJSONString() 造成的。当需要toJson的对象比较小的时候性能损耗还好。但是当对象较大的时候toJsonString的性能问题就不容忽视了。

三、如何解决

其实解决办法的核心就是在于我们最好在日志判断级别后在进行对象的toJsonString转化。

可以引申出三种办法：

方法1

业务代码编写的时候，统一化写法格式如下。

if(log.isInfoEnabled()){    
      log.info("sync2JhForOldBizJingKa,end,targetBizInfo:{},result:{}", targetBizInfo,JSON.toJSONString(result));
}

优点：可以有控制性的指定需要进行特殊处理的代码，直接使用已有的日志框架工具即可。

缺点：业务代码的侵入性太强，需要进行判断的相似代码涉及点太多。



方法2

一种业务组件扩展写法。我们新封装一个SLF4J的实现类，实现类里面封装对实际处理日志框架（log4j，logback等等）的封装。我们在方法实现的里面对需要打印的对象进行判断后toJSONString()处理。解决方法1中到处需要进行isInfoEnabled()判断的问题。

概要实现类的代码片段如下：

import org.slf4j.Logger;
public class Slf4jJsonAdapterImpl implements Logger{

 public Object toJsonStr(Object object){
    //此处的判断可以进行扩展，增加支持的类型
    if(object == null || object instanceof String || object instanceof Throwable){
            return object;
    } else {
            return JSON.toJSONString(object);
    }
 }

 public Object[] toJsonStr(Object... objects){
    if(objects == null || objects.length == 0){
            return objects;
    }    
    Object[] result = new Object[objects.length];
    for(int i=0;i<objects.length;i++){
            result[i] = toJsonStr(objects[i]);    
    }    
    return result;
 }

 public void info(Marker marker, String format, Object... arguments) {
    if(logger.isInfoEnabled(marker)){
        logger.info(marker, format, toJsonStr(arguments));
    }
 }
}

日志代码写法如下：

log.info("sync2JhForOldBizJingKa,end,targetBizInfo:{},result:{}", result);

优点：日志代码对业务逻辑的侵入度低。

缺点：

1）重写了日志的实现框架，需要对日志框架有足够的技术熟悉度的人才可以进行。毕竟日志框架后续还有版本迭代问题。

2）里面涉及到的toJSONString的对象判断，不一定适合所有需要打印日志的地方。例如Map<String,String>这种格式的对象就没必要进行toJSONString()打印。(其实遇到不需要进行jsonstring日志格式的对象打印，也可以把对象进行string处理后，再当成日志参数)。

方法3

延迟toJsonString的打印到日志处理步骤c的时候。

实现代码如下。

log.info("sync2JhForOldBizJingKa,end,targetBizInfo:{},result:{}", targetBizInfo,AsyncLogJson.toJsonStr(result));
public class AsyncLogJson{    
     private Object targetObj;    
     public AsyncLogJson(Object targetObj){
             this.targetObj = targetObj;    
     }    
     @Override
     public String toString() {
             return JSON.toJSONString(targetObj);
     }
     public static AsyncLogJson toJsonStr(Object targetObj){
             return new AsyncLogJson(targetObj);    
     }
}

通过改造最终日志打印的步骤过程大概如下：

a1、日志框架内部的 isInfoEnabled() 日志级别方法判断。

b1、日志内部进行要打印的日志占位符拼装。即把日志占位符”{}“部分替换为要打印的内容。

进行占位符拼装执行到对象toString()的时候，触发AsyncLogJson.toString()里面的JSON.toJSONString()。

c1、日志IO操作，把日志打印到机器文件上去。



优点：业务代码的侵入性比方法2高，比方法1低。可以有控制性的指定需要进行特殊处理的代码，直接使用已有的日志框架工具即可。

缺点：

1）需要打印toJSONString()日志的时候，需要注意好使用特定的toJSONString()的相关类。

2）日志打印入参的时候，其实是创建了一个对象进行上下文传输。同步化的日志打印还好，如果是异步进行日志打印的时候，那么需要保证日志打印的时候对象最好是没发生变化的。



四、总结

以上只是分析了日志切换级别过程中的性能问题原因，总结了一些解决办法。具体使用那种方案来解决问题还是需要各位大佬们自己结合实际情况来进行选择。