Java无垃圾稳态设计

语言: CN / TW / HK

最近在重构 《简明日志规范》 ,就是重构我自己之前开源的一个统一日志的组件。对于打印日志,最重要的我认为有两点:第一点是异步,不能因为打印日志而影响正常的程序执行,导致等待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是自己要监控的对象,有空不妨试一试。

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