Spring的@PreDestroy导致记录随机而不是日志记录 [英] Spring's @PreDestroy results in logging randomly not logging

问题描述

我正在使用Spring，在终止时我正在使用@PreDestroy来清理bean。我不明白为什么有时候记录随机成功，而对其他记录则失败。

I'm using Spring, and on termination I'm having @PreDestroy clean up beans. I don't understand why logging randomly succeeds sometimes, and fails on others.

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

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

有时我什么也得不到（没有记录测试），其他时间我会得到：

Sometimes I will get nothing (no "Test" is logged), other times I will get:

[13:48:44] INFO  MyClass: Test

如果我包含 System.out.println（这是否运行？）; 在close（）方法，它将始终打印。

If I include System.out.println("Is this run?"); in the close() method, it will always print.

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

I'm not actually sure what is happening. I don't know if it's because the JVM is shutting down and the logger is killed... but I thought that would throw some kind of exception?

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

Note that the logging logs both to a file + stdout, I don't know if that would affect anything. Logging works fine for the other countless thousands of lines of code, but not this.

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

NOTE: I am open to switching logging libraries if it ends up being this particular library.

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

MyClass would be a bean in a spring.xml document.

推荐答案

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

I think it comes down to this, from Runtime.addShutdownHook:

当虚拟机开始关机时，它将启动所有已注册的关闭钩子都在 某些未指定的顺序 中并让它们同时运行。

When the virtual machine begins its shutdown sequence it will start all registered shutdown hooks in some unspecified order and let them run concurrently.

因此，只要LogManager和Spring IOC容器都被JVM关闭挂钩关闭，就无法确保将记录消息。如果首先关闭LogManager，则消息将丢失。如果首先关闭IOC容器，则会记录该消息。

So, as long as LogManager and the Spring IOC container are both shut down by JVM shutdown hooks, there is no way to ensure the message will be recorded. If the LogManager is shut down first, the message is lost. If the IOC container is shut down first, the message is recorded.

如果您在JEE容器中运行，则可能无法更改此消息。

If you are running in a JEE container, there's probably little you can do to change this.

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

However, if you're running in a stand-alone environment, you can add a shutdownHook="disable" to the Log4j 2 <configuration> tag. This prevents Log4j 2 from registering it's own shutdown hook. Then, instead of calling ctx.registerShutdownHook() (the recommended way to shutdown the IOC), you register your own shutdown hook. Something like:

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。

Update: Corrected process of shutting down Log4j2.
Caveat: I am away from my usual build machines, so I have not compiled this, but I believe it's hitting the correct APIs.

这篇关于Spring的@PreDestroy导致记录随机而不是日志记录的文章就介绍到这了，希望我们推荐的答案对大家有所帮助，也希望大家多多支持IT屋！