Java无垃圾稳态设计

最近在重构《简明日志规范》，就是重构我自己之前开源的一个统一日志的组件。对于打印日志，最重要的我认为有两点：第一点是异步，不能因为打印日志而影响正常的程序执行，导致等待IO卡顿；第二点是尽量减少垃圾，所谓垃圾是说许多日志库在日志记录期间分配临时对象，如日志事件对象，字符串，字符数组，字节数组等。这会对垃圾收集器造成压力并增加GC暂停发生的频率。

其中，异步设计已经是很成熟的领域了。但是低垃圾、无垃圾的研究还比较少。

在《应用程序怎样划分模块？》里我提到使用登高类比法进行业界调研。业界调研自然不会放过Log4j、Logback这些都广泛认可的优秀日志组件。

Log4j2从版本2.6开始，默认情况下以“无垃圾”模式运行。无垃圾原理就是《ThreadLocal&MDC内存泄漏问题》中介绍的ThreadLocal。因为重用对象和缓冲区，并且尽可能不分配临时对象。从物理层面上，对象的内存区域是通过数据覆盖，而不是垃圾回收来达到日志读写和上下文信息保存的目的。

以下是官网对无垃圾记录响应时间行为进行的试验：

下图将 Log4j 的异步 Logger 的“经典”记录与无垃圾记录响应时间行为进行了比较。在图中，“ 100k”表示以 100,000 消息/秒的持续负载进行记录，“ 800k”表示 800,000 消息/秒的持续负载。

在“经典”模式下，我们看到大量次要垃圾回收，这些垃圾回收会使应用程序线程暂停 3 毫秒或更长时间。这很快就增加了将近 10 毫秒的响应时间延迟。如您在图表中所见，增加负载将曲线向左移动(存在更多尖峰)。这是有道理的：更多的日志记录意味着对垃圾收集器施加更大的压力，从而导致更小的 GC 暂停。我们做了一些实验，将负载减少到 50,000 甚至 5000 条消息/秒，但这并没有消除 3 毫秒的暂停，只是使它们的发生频率降低了。请注意，此测试中的所有 GC 暂停都是次要的 GC 暂停。我们没有看到任何完整的垃圾回收。

在“无垃圾”模式下，在各种负载下，最大响应时间仍远低于 1 毫秒。(最大 780 us，800,000 消息/秒，最大 407 us，600,000 消息/秒，其中 99％围绕 5 us 达到 800,000 消息/秒的所有负载.)增加或减少负载不会改变响应时间。我们没有调查在这些测试中看到的 200-300 微秒暂停的原因。

当我们进一步增加负载时，我们开始看到经典和无垃圾记录的响应时间都有较大的暂停。在 100 万条消息/秒或更多的持续负载下，我们开始接近底层 RandomAccessFile Appender 的最大吞吐量(请参见下面的同步日志记录吞吐量图表)。在这些负载下，环形缓冲区开始填满，反压开始起作用：在环形缓冲区已满时尝试添加另一条消息将阻塞，直到有可用插槽可用为止。我们开始看到响应时间为数十毫秒或更长；尝试进一步增加负载会导致越来越大的响应时间峰值。

试验可以看出无垃圾模式对性能提升上有极大的好处。那如果是自制结构化日志组件怎么实现无垃圾模式呢？

我自己做的简明日志组件是为了公司的结构化日志做抽象而产生。我将结构化日志要打印的列定义为一个对象LogBuilder。属性就是日志要输出的内容。这样大家就可以用面向对象的方式来组装日志对象了。

LogBuilder的变量有三种情况：

第一种是全局变量，比如机房信息，服务启动时机房就固定不变了。这种变量可以定义为静态变量，全局唯一，不会被垃圾回收器处理。

class LogBuilder {

    private static String idc; 

    static {

         idc = 从配置文件等处读取并初始化；

    }

}

第二种是线程唯一，比如线程追踪号，这种信息可以通过切面在请求入口处设置一次保存到MDC中，使用时从MDC中取得，《ThreadLocal&MDC内存泄漏问题》中有介绍，MDC相对安全无内存泄漏风险。MDC由于跟着线程走，线程采用线程池时它可以被复写无需垃圾回收。

class LogBuilder {

    private static String traceId; 

    public void static setTraceId(String traceId) {

         MDC.set("traceId", traceId);

    }

}

第三种是线程内变化的，比如执行阶段，这种对象只能跟着LogBuilder的实例对象走，中间可以被重新赋值并打印。这时候就需要把整个LogBuilder对象放到ThreadLocal中，让它也跟着对象实例走。但是这里面有个关键，就是对象的toString方法被调用后这个打印的string就会被回收。所以我们打印日志时组装的字符串最好不用toString，而是新写一个方法来生成并将结果保存到LogBuilder的局部变量中。这样打印完成对象就不会被回收。而是在下次使用时被复写。

@Data

class LogBuilder {

    private static ThreadLocal threadLocal = new ThreadLocal();

    private static String idc; 

    private static String traceId; 

    private String step; 

    private String toString;

    public static LogBuilder getInstance() {

          if(threadLocal.get()==null) {

            threadLocal.set(new LogBuilder());

          }
          return threadLocal.get();

    }

    public String buildString() {

       toString = idc+"|"+traceId+"|"+step;

    }

}

当然这里只是为了说明无垃圾写的示例代码，实际上的实现使用了一些反射等技术，代码很精简，通用性强。实际原理和Log4j2的无垃圾稳态原理一致。

总结和小技巧

LogBuilder对象最初我的设计是使用静态工厂方法new出来的。这也是《有效的Java》推荐的方式，可以很好的进行实例控制，保持清晰性和简洁性。后来加入了ThreadLocal来进行无垃圾稳态设计。这时要注意提供clear方法清空属性值，因为和主题无关，我在代码中省略了这一部分。关键来了，性能提升了，内存使用减少了怎么来测试验证呢？

我使用了jol工具来监控内存情况，使用方法，先上maven坐标：

<dependency>
    <groupId>org.openjdk.jol</groupId>
    <artifactId>jol-core</artifactId>
    <version>0.14</version>
</dependency>

代码中使用时

log.info("内部信息：[{}]", ClassLayout.parseInstance(pojo).toPrintable());
log.info("外部信息[{}]", GraphLayout.parseInstance(pojo).toPrintable());
log.info("totalSize[{}]", GraphLayout.parseInstance(pojo).totalSize());

其中pojo是自己要监控的对象，有空不妨试一试。

不要假定，要证明！-----《程序员修炼之道》