Log4j2异步日志之异步格式化

在优化系统响应时间的时候，除了优化业务逻辑/代码逻辑之外，把日志改成异步也是一种不错的方案

Log4j2在异步日志的性能上已经无人能挡了，其异步效率高的主要原因是使用disruptor来做异步队列

但是很多业务系统，尤其是核心业务系统，需要打印详细的报文和处理参数来追踪问题；但是如果在logger.info之前就对报文进行格式化（转json/xml之类），又会非常影响日志输出的性能，因为就算日志打印这一步是异步的，但是logger.info这一操作是同步的；如果报文较大，格式化的这个操作可能会比较消耗时间

那么能不能让序列化这一步也变成异步呢，让logger.info直接输出报文(对象)？

log4j2当然是支持这种扩展的，只是需要自己定制一下

MessageFactory

log4j2提供了一个MessageFactory接口，该接口用于根据消息类型的不同来创建消息，通过该接口即可实现对不同消息类型的格式化

public class ExtendParameterizedMessageFactory extends AbstractMessageFactory {

    /**
     * 匹配对象类型消息，如果用logger.info(object)输出，则会调用本方法
     * @param message
     * @return
     */
    @Override
    public Message newMessage(Object message) {
        Function<Object, String> formattedFunction = MessageTypeMapping.match(message);
        //创建自己的扩展消息类型
        if(formattedFunction != null){
            return new ExtendObjectParameterizedMessage(message,formattedFunction);
        }else{
            return super.newMessage(message);
        }
    }

    @Override
    public Message newMessage(final String message, final Object... params) {
        return new ParameterizedMessage(message, params);
    }

    @Override
    public Message newMessage(final String message, final Object p0) {
        return new ParameterizedMessage(message, p0);
    }

    @Override
    public Message newMessage(final String message, final Object p0, final Object p1) {
        return new ParameterizedMessage(message, p0, p1);
    }

    @Override
    public Message newMessage(final String message, final Object p0, final Object p1, final Object p2) {
        return new ParameterizedMessage(message, p0, p1, p2);
    }

    @Override
    public Message newMessage(final String message, final Object p0, final Object p1, final Object p2, final Object p3) {
        return new ParameterizedMessage(message, p0, p1, p2, p3);
    }

    @Override
    public Message newMessage(final String message, final Object p0, final Object p1, final Object p2, final Object p3, final Object p4) {
        return new ParameterizedMessage(message, p0, p1, p2, p3, p4);
    }

    @Override
    public Message newMessage(final String message, final Object p0, final Object p1, final Object p2, final Object p3, final Object p4, final Object p5) {
        return new ParameterizedMessage(message, p0, p1, p2, p3, p4, p5);
    }

    @Override
    public Message newMessage(final String message, final Object p0, final Object p1, final Object p2, final Object p3, final Object p4, final Object p5,
                              final Object p6) {
        return new ParameterizedMessage(message, p0, p1, p2, p3, p4, p5, p6);
    }

    @Override
    public Message newMessage(final String message, final Object p0, final Object p1, final Object p2, final Object p3, final Object p4, final Object p5,
                              final Object p6, final Object p7) {
        return new ParameterizedMessage(message, p0, p1, p2, p3, p4, p5, p6, p7);
    }

    
    @Override
    public Message newMessage(final String message, final Object p0, final Object p1, final Object p2, final Object p3, final Object p4, final Object p5,
                              final Object p6, final Object p7, final Object p8) {
        return new ParameterizedMessage(message, p0, p1, p2, p3, p4, p5, p6, p7, p8);
    }

    @Override
    public Message newMessage(final String message, final Object p0, final Object p1, final Object p2, final Object p3, final Object p4, final Object p5,
                              final Object p6, final Object p7, final Object p8, final Object p9) {
        return new ParameterizedMessage(message, p0, p1, p2, p3, p4, p5, p6, p7, p8, p9);
    }
}

MessageFactory实现后，通过环境变量指定具体的MessageFactory实现类即可-Dlog4j2.messageFactory=com.github.kongwur.log4j2test.log4j2.extend.ExtendParameterizedMessageFactory

异步格式化

上面已经实现了MessageFactory，那么怎么才能做到异步格式化呢？

log4j2提供了一个@AsynchronouslyFormattable注解，用该注解修饰的Message Class，在async logger时，会将getFormat的操作放实际打印之前（即异步之后），而不是异步之前

1. If the Message is annotated withAsynchronouslyFormattable, it can be passed to another thread as is.
2. Otherwise, asynchronous logging components in the Log4j implementation will callMessage.getFormattedMessage()before passing the Message object to another thread. This gives the Message implementation class a chance to create a formatted message String with the current value of the mutable object. The intention is that the Message implementation caches this formatted message and returns it on subsequent calls.

所以只需要创建自己的扩展消息类型，用@AsynchronouslyFormattable修饰即可

@AsynchronouslyFormattable
public class ExtendObjectParameterizedMessage implements Message {

    private final transient Object obj;
    private transient String objectString;
    private final transient Function<Object,String> formattedFunction;

    public ExtendObjectParameterizedMessage(final Object obj,Function<Object,String> formattedFunction) {
        this.obj = obj;
        this.formattedFunction = formattedFunction;
    }

    @Override
    public String getFormattedMessage() {
        if (objectString == null) {
            objectString = formattedFunction.apply(obj);
        }
        return objectString;
    }

    @Override
    public String getFormat() {
        return getFormattedMessage();
    }

    @Override
    public Object[] getParameters() {
        return new Object[] {obj};
    }

    @Override
    public Throwable getThrowable() {
        return null;
    }

    @Override
    public int hashCode() {
        return obj != null ? obj.hashCode() : 0;
    }

    @Override
    public String toString() {
        return getFormattedMessage();
    }

}

动态类型匹配

实际项目中，可能会对多种对象/报文进行异步格式化，所以最好可以动态匹配报文的类型，定制不同的格式化规则

这里还可以写一个简单类型格式化的映射：

public class MessageTypeMapping {  
    private static final Map<Class, Function<Object,String>> MAPPING = new HashMap<>();  
  
 static {  
        //添加对应类型的映射规则  
  MAPPING.put(BizObj.class,t -> {  
            try {  
                Thread.sleep(10);  
  } catch (InterruptedException e) {  
                e.printStackTrace();  
  }  
            return t.toString();  
  });  
  }  
  
    public static Function<Object,String> match(Object message){  
        if(message == null){  
            return null;  
  }  
        Class messageClass = message.getClass();  
 return MAPPING.get(messageClass);  
  }  
}

使用

实际调用时，无法通过slf4j之类的api来打印，因为slf4j并没有提供直接打印对象的方法

org.slf4j.Logger#info(java.lang.String)
org.slf4j.Logger#info(java.lang.String, java.lang.Object)
org.slf4j.Logger#info(java.lang.String, java.lang.Object, java.lang.Object)
org.slf4j.Logger#info(java.lang.String, java.lang.Object...)
org.slf4j.Logger#info(java.lang.String, java.lang.Throwable)
org.slf4j.Logger#isInfoEnabled(org.slf4j.Marker)
org.slf4j.Logger#info(org.slf4j.Marker, java.lang.String)
org.slf4j.Logger#info(org.slf4j.Marker, java.lang.String, java.lang.Object)
org.slf4j.Logger#info(org.slf4j.Marker, java.lang.String, java.lang.Object, java.lang.Object)
org.slf4j.Logger#info(org.slf4j.Marker, java.lang.String, java.lang.Object...)
org.slf4j.Logger#info(org.slf4j.Marker, java.lang.String, java.lang.Throwable)

但是我们可以直接通过log4j2的api来打印：

org.apache.logging.log4j.Logger logger = LogManager.getLogger(getClass());
//这里打印对象会调用上面定义的ExtendObjectParameterizedMessage，实现“异步格式化”
logger.info(new BizObj());

参考

• http://logging.apache.org/log4j/2.x/manual/extending.html