Spring 的 @PreDestroy 导致随机记录而不是记录

Question

我正在使用 Spring，并在终止时让 @PreDestroy 清理 bean。我不明白为什么日志记录有时会随机成功，而另一些则失败。

// Using Log4j2
Logger log = LogManager.getLogger(MyClass.class);

@PreDestroy
public void close() {
    log.warn("Test");
}

有时我什么也得不到（没有记录“测试”），有时我会得到：

[13:48:44] INFO  MyClass: Test

如果我在 close() 方法中包含System.out.println("Is this run?");，它将始终打印。

我实际上不确定发生了什么。我不知道是不是因为JVM正在关闭并且记录器被杀死......但我认为这会引发某种异常？

请注意，日志记录到文件+标准输出，我不知道这是否会影响任何事情。其他无数行代码的日志记录工作正常，但不是这个。

注意：如果它最终成为这个特定的库，我愿意切换日志库。

编辑：MyClass 将是 spring.xml 文档中的一个 bean。

Answer 1

与@Devon_C_Miller 的答案完全相同，但已更新以反映最新版本的 log4j2

public class MonolithApplication {
  public static void main(String[] args) {
    AnnotationConfigApplicationContext context = new AnnotationConfigApplicationContext();
    context.refresh();
    Runtime.getRuntime().addShutdownHook(new Log4j2AwareShutdownHook(context));
  }
}

class Log4j2AwareShutdownHook extends Thread {
  private AbstractApplicationContext ctx;
  Log4j2AwareShutdownHook(AbstractApplicationContext ctx) {
    this.ctx = ctx;
  }
  public void run() {
    ctx.close();
    LogManager.shutdown();
  }
}

并且在 log4j2 配置中

<?xml version="1.0" encoding="UTF-8"?>
<Configuration shutdownHook="disable">
    <Properties>
        <Property name="LOG_EXCEPTION_CONVERSION_WORD">%xEx</Property>
        <Property name="LOG_LEVEL_PATTERN">%5p</Property>
        <Property name="LOG_DATEFORMAT_PATTERN">yyyy-MM-dd HH:mm:ss.SSS</Property>
        <Property name="CONSOLE_LOG_PATTERN">%d{${LOG_DATEFORMAT_PATTERN}} ${LOG_LEVEL_PATTERN} %pid --- [%t] %-40.40c{1.} : %m%n${sys:LOG_EXCEPTION_CONVERSION_WORD}</Property>
    </Properties>
    <Appenders>
        <Console name="Console" target="SYSTEM_OUT">
            <PatternLayout pattern="${sys:CONSOLE_LOG_PATTERN}"/>
        </Console>
    </Appenders>
    <Loggers>
        <Logger name="com.acme" level="debug"/>
        <Root level="info">
            <AppenderRef ref="Console"/>
        </Root>
    </Loggers>
</Configuration>

Answer 2

我认为归根结底，来自Runtime.addShutdownHook：

当虚拟机开始其关闭序列时，它将以一些未指定的顺序启动所有已注册的关闭挂钩，并让它们同时运行。

所以，只要 LogManager 和 Spring IOC 容器都被 JVM 关闭钩子关闭，就无法确保消息会被记录。如果先关闭 LogManager，则消息丢失。如果先关闭 IOC 容器，则记录消息。

如果您在 JEE 容器中运行，您可能几乎无法更改它。

但是，如果您在独立环境中运行，则可以将 shutdownHook="disable" 添加到 Log4j 2 <configuration> 标记中。这可以防止 Log4j 2 注册它自己的关闭挂钩。然后，您注册自己的关闭挂钩，而不是调用ctx.registerShutdownHook()（关闭 IOC 的推荐方法）。比如：

class MyShutdownHook extends Thread {
    private AbstractApplicationContext ctx;
    public MyShutdownHook(AbstractApplicationContext ctx) {
        this.ctx = ctx;
    }
    public void run() {
        ctx.close();
        Set<LoggerContext> contexts = new HashSet<>();
        for (Logger logger : LoggerContext.getLoggers()) {
            contexts.add(logger.getContext());
        }
        for (LoggerContext ctx : contexts) {
            Configurator.shutdown(LogManager.getContext());
        }
    }
}

AbstractApplicationContext ctx = /* create context */
Runtime.getRunTime().addShutdownHook(new MyShutdownHook(ctx);

更新：更正了关闭 Log4j2 的过程。
警告：我远离我通常的构建机器，所以我没有编译这个，但我相信它击中了正确的 API。

Answer 3

我没有足够的声誉来添加评论，所以我会在这里回答：

根据 JavaEE API javadoc：

• 在非拦截器类上定义的方法必须具有以下签名：void ()
• 应用 PreDestroy 的方法可以是 public、protected、package private 或 private。
• 方法不能是静态的。
• 方法可能是最终的。
• 如果方法抛出未经检查的异常，则忽略该异常，但 EJB 可以处理异常的 EJB 除外。

检查是否在其他地方“静默”抛出异常，这可能是一个原因。