一、同步打印日志中的坑
1.1 高并发场景下 logback 造成线程泄露
调用 logback 去打印日志的时候是会加锁的,加锁的位置在:
// ch.qos.logback.core.OutputStreamAppender#writeBytes
private void writeBytes(byte[] byteArray) throws IOException {
if (byteArray != null && byteArray.length != 0) {
this.lock.lock();
try {
this.outputStream.write(byteArray);
if (this.immediateFlush) {
this.outputStream.flush();
}
} finally {
this.lock.unlock();
}
}
}
这就意味着同一个appender的日志写是串行的,在高并发的场景下因为有锁的争用现象,所以看似很简单的一行日志,耗费的时间却不少。接下来我们在本地简单的模拟一下高并发的场景,并记录打一行日志的耗时是多少
public static void main(String[] args) {
ExecutorService threadPool = new ThreadPoolExecutor(500, 750, 20, TimeUnit.MINUTES, new ArrayBlockingQueue<>(1),
new ThreadFactoryBuilder().setNameFormat("test-log-thread").build(), new ThreadPoolExecutor.CallerRunsPolicy());
for (int i = 0; i < 750; i++) {
LoggerExecutor commonExecutor = new LoggerExecutor();
threadPool.submit(commonExecutor);
}
}
static class LoggerExecutor implements Runnable {
@SneakyThrows
@Override
public void run() {
while (true) {
long start = System.currentTimeMillis();
logger.info("log info message at {}", System.currentTimeMillis());
long end = System.currentTimeMillis();
long time = end - start;
System.out.println(time);
}
}
}
需要说明的是,现实中高并发的请求应当用一个线程池向另一个线程池反复提交任务来模拟,这里我们简化了这个过程。


本文分析了高并发场景下,日志打印可能导致的线程泄露和性能问题,包括logback同步日志的线程争用、异常日志引发的性能毛刺以及异步日志配置不当的影响。提出了最佳实践,建议日志声明为private static final,使用占位符,区分日志级别,并在高并发环境下谨慎使用info日志,采用异步日志且设置合理的丢日志策略。
1907

被折叠的 条评论
为什么被折叠?



