在容器环境中优雅地停止 Logback

Gracefully stop Logback in container environment

今天我收到 PermGen OutOfMemory 错误。

分析表明 最近的 GC Root for WebappClassLoader 是 Logback 线程:

this     - value: org.apache.catalina.loader.WebappClassLoader #4
  <- contextClassLoader (thread object)     - class: java.lang.Thread, value: org.apache.catalina.loader.WebappClassLoader #4

即:

java.lang.Thread#11 - logback-1

此线程的堆转储中的线程转储:

"logback-1" daemon prio=5 tid=34 WAITING
at sun.misc.Unsafe.park(Native Method)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)
at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:458)
at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:359)
   Local Variable: java.util.concurrent.SynchronousQueue$TransferStack$SNode#1
   Local Variable: java.util.concurrent.SynchronousQueue$TransferStack#6
at java.util.concurrent.SynchronousQueue.take(SynchronousQueue.java:925)
   Local Variable: java.util.concurrent.SynchronousQueue#6
at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130)
   Local Variable: java.util.concurrent.ThreadPoolExecutor#34
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
   Local Variable: java.util.concurrent.ThreadPoolExecutor$Worker#11
at java.lang.Thread.run(Thread.java:745)

我使用具有热重新部署功能的 Tomcat 8 reloadable="true" 并通过 PreResources:

外部化 CLASSPATH
<Context docBase="/home/user/devel/app/src/main/webapp"
         reloadable="true">
    <Resources>
        <!-- To override application.properties and logback.xml -->
        <PreResources className="org.apache.catalina.webresources.DirResourceSet"
                       base="/home/user/devel/app/.config"
                       internalPath="/"
                       webAppMount="/WEB-INF/classes" />
    </Resources>
</Context>

logback.xmlscan="true":

<configuration debug="false" scan="true" scanPeriod="5 seconds">
    <appender name="FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
    ...

/home/user/devel/app/.config/logback.xml 中保存修改后 Tomcat 8 收到通知(我不确定 API 用于监视 fs 上的更改)并开始重新部署应用程序。那就是 PermGen OutOfMemory.

之前发生的事情

如何在容器环境中优雅地停止 Logback?

如何停止 "logback-1" 线程?

我找到了一些相关的讨论,但不明白如何处理这些信息:

UPDATE 我在 visualvm 玩堆转储。从坏的 logback-1 thread:

跳转参考水平
lvl1 = flatten(filter(referees(heap.findObject(0xf4c77610)), "!/WebappClassLoader/(classof(it).name)"))

lvl2 = flatten(map(lvl1, "referees(it)"))

lvl3 = flatten(map(lvl2, "referees(it)"))

指的是

ch.qos.logback.core.util.ExecutorServiceUtil

通过在 Logback 源中查找 ExecutorServiceUtil I found changelog entry:

All threads opened by ch.qos.logback.core.util.ExecutorServiceUtil#THREAD_FACTORY are now daemons, which fixes an application hang on shutdown when LoggerContext#stop() is not called (LOGBACK-929). Note that daemon threads are abruptly terminated by the JVM, which may cause undesirable results, such as corrupted files written by the FileAppender. It is still highly recommended for the application to call LoggerContext#stop() (e.g., in a shutdown hook) to gracefully shutdown appenders.

在容器环境中,守护线程是危险的并会导致内存泄漏,对吗?

我不完全明白我应该做什么。目前我从项目 pom.xml 和这一行中删除了 jul-to-slf4j 桥:

<contextListener class="ch.qos.logback.classic.jul.LevelChangePropagator"/>

来自 logback.xml。即使有这条线,应用程序也没有 "logback-1" 线程。

As suggest official docs 我注册:

public class ShutdownCleanupListener implements ServletContextListener {
    @Override
    public void contextInitialized(ServletContextEvent sce) { }

    @Override
    public void contextDestroyed(ServletContextEvent sce) {
        if (LoggerFactory.getILoggerFactory() instanceof LoggerContext) {
            ((LoggerContext) LoggerFactory.getILoggerFactory() ).stop();
        } 
    }
}

web.xml中:

<listener>
    <listener-class>com.app.servlet.ShutdownCleanupListener</listener-class>
</listener>

删除对以下内容的直接依赖:

import ch.qos.logback.classic.LoggerContext;

可以使用反射。

不确定我做的是否正确。我会看看是否因为 Logback 而出现 PermGen OutOfMemory 错误。

UPDATE 在我从 ExecutorServiceUtil class 中发现引用依赖关系后,我检查了 Logback 源代码,发现这个 class 创建了带有名称的线程喜欢上面的坏:

 thread.setName("logback-" + threadNumber.getAndIncrement());

这个class只在ch.qos.logback.core.ContextBase中使用过,线程在里面倾斜:

public void stop() {
  // We don't check "started" here, because the executor service uses
  // lazy initialization, rather than being created in the start method
  stopExecutorService();
  started = false;
}

请注意 LoggerContextContextBase 的子class 所以 以上解决方案确实解决了我的问题 .

Is that right that in container environment daemon threads are danger and lead to memory leaks?

关于守护线程的声明指的是独立应用程序的情况(如 bug report),其中 JVM 应该在应用程序完成时关闭。 non-daemon 线程阻止 JVM 关闭。

在 JavaEE 上下文中,应用程序服务器的 JVM 在多个应用程序的潜在多个生命周期中保持不变,守护进程与 non-daemon 不影响 live threads are GC roots.

根据 Spring Boot logback 示例项目,您应该关闭上下文以清理日志系统:https://github.com/spring-projects/spring-boot/commit/10402a651f1ee51704b58985c7ef33619df2c110

示例:

public static void main(String[] args) throws Exception {
        SpringApplication.run(SampleLogbackApplication.class, args).close();
    }