守护线程在logback中的使用 - 论基础知识的重要性
守护线程在logback中的使用
先说问题,在java应用中,logback的异步Appender是怎么在主线程结束后,停下来的?
复盘
我在一个logback
的测试用例中,写了这样的代码和logback
的配置:
// 一个测试类,main函数中简单的打印了几行日志
public class Test {
private static final Logger LOGGER = LoggerFactory.getLogger(Test.class);
public static void main(String[] args) {
LOGGER.info("test log 1");
LOGGER.info("test log 2");
}
}
这是我使用的logback
的配置,为root-logger
配置了两个appender
,一个是ConsoleAppender
,会将日志内容输出到控制台中,另一个是套在AsyncAppender
中的FileAppender
,它采用异步的方式将日志内容输出到文件中
<?xml version="1.0" encoding="UTF-8" ?>
<configuration>
<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
<encoder>
<pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n</pattern>
</encoder>
</appender>
<appender name="FILE" class="ch.qos.logback.core.FileAppender">
<file>/usr/local/test.log</file>
<encoder>
<pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n</pattern>
</encoder>
</appender>
<appender name="ASYNC" class="ch.qos.logback.classic.AsyncAppender">
<appender-ref ref="FILE" />
</appender>
<root level="debug">
<appender-ref ref="STDOUT"/>
<appender-ref ref="ASYNC"/>
</root>
</configuration>
当我正常执行Test.main()
,观察控制台和文件中都正常输出了日志。然后,为了观察AsyncAppender
的原理,我在AsyncAppender
的父类AsyncAppenderBase
中,看了一下大致的原理:AsyncAppenderBase
的start()
方法中,调用了worker.start()
,其实就是启动了一个线程。截取Worker.run()
方法中比较重要的代码,就是在一个while
循环中,从阻塞队列获取ILoggerEvent
,我在这里打了断点,希望追进具体的Appender
中看一下
while (parent.isStarted()) {
try {
E e = parent.blockingQueue.take();
// 这里打了断点
aai.appendLoopOnAppenders(e);
} catch (InterruptedException ie) {
break;
}
}
当执行到断点处,观察了一会儿变量后,点击步进,突然发现整个java应用结束了。没有任何异常发生。这种情况我重试了很多次,不一定在断点处结束,可能再往下几步,但是debug模式下,java应用一定会在某个点毫无征兆的“正常结束”。
我当时去确认了一下,控制台中两行日志都打印了出来,这说明主线程一定执行完了,但是我当时的知识储备是,java主线程结束时,如果子线程没有结束,那么会等待子线程结束后,JVM才会执行最后的结束任务。(这里完全不记得守护线程的概念)
!!!上面这个结论是错误的
然后就想通过jstack
来观测一下,当main-Thread
结束后,线程到底是什么情况:
这里发现:
DestroyJavaVM
线程居然处于RUNNABLE
阶段,可是还有子线程在执行啊,为什么它就开始了
带着疑问再看一下AsyncAppender-Worker-ASYNC
线程,这就是异步日志打印任务的线程了,也是RUNNABLE
状态,但是它好像是一个守护线程(daemon)
,这才想起来java线程的基础知识,用户线程和守护线程,这里直接贴出来Thread
的setDaemon
方法,代码注释中说:标记该线程为user thread或daemon thread,JVM只会在当前运行的线程,全部都是daemon thread时,才会结束。
再看看AsyncAppenderBase
中的start()
方法:
可以看到,它将worker
指定为了daemon
线程,问题到这里其实也就解决了。
结论
这次碰到的问题,其实并不复杂,主要还是知识储备的问题
java多线程中,用户线程和守护线程在能力上并没有什么区别,最重要的区别是当JVM退出时,如果还有存活的用户线程,则不会退出;如果只剩下守护线程了,那么JVM则会杀掉所有的守护线程,并退出。
PS:
没人知道我DEBUG了多久。。。简直超出认知范围了!!!差点以为是玄学