How to log within shutdown hooks with Log4j2?

Question

Log4j2 also uses shutdown hooks to end it's services. But of course I want to log throughout the whole lifecycle of my application - shutdown included. With Log4j this was no problem. Now it seems to be impossible. Logging shuts down, while my application is still working on it. Has anyone some hope for me?

Best regards Martin

Catchword

Logging, or depending on any other services in shutdown hooks, has been bad practice all along, and now it's catching up with you. – Collincolline

@MarkoTopolnik If it is bad practise as you say, what do you suggest is done if the output of a shutdown hook thread needs recording/logging? – Barragan

Since in the shutdown hook you can't count on any part of initialized state to still exist, the only thing I see as semi-reliable is a completely self-contained piece of code which creates a file and writes to it. Similar to the way a core dump is made. – Collincolline

Answer 1

As of 2.0-beta9 this is now configurable in xml

<configuration ... shutdownHook="disable">

Considering its now disabled, I guess I need to manually shutdown the logging system at the end of my shutdown hook. However I couldn't find a means thorough the external interface, only in the internal api

import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.core.config.Configurator;
import org.apache.logging.log4j.core.LoggerContext;
...

public static void main(String[] args) {
    final AnnotationConfigApplicationContext springContext = new AnnotationConfigApplicationContext(AppConfig.class)

    Runtime.getRuntime().addShutdownHook(new Thread() {
        public void run() {
            //shutdown application
            LOG.info("Shutting down spring context");
            springContext.close();

            //shutdown log4j2
            if( LogManager.getContext() instanceof LoggerContext ) {
                logger.info("Shutting down log4j2");
                Configurator.shutdown((LoggerContext)LogManager.getContext());
            } else
                logger.warn("Unable to shutdown log4j2");
        }
    });

    //more application initialization
}

Update:

There is LogManager.shutdown() method since log4j version 2.6

Quiz

Problem is, that the shutdown hooks of Java are started in parallel. So to really make sure you can log everywhere you have to avoid just adding your hooks to the given Runtime.getRuntime().addShutdownHook(Thread)-API but create your own workflow that manually stops log4j 2.0 after everything is down. But the main problem was solved when Log4j offered the shutdownHook-trigger. – Catchword

I agree that you need to create your own workflow. I normally run my app on linux and shutdown via a signal to the JVM, so a shutdown hook is suitable for this purpose (i've updated the code snippet to show this context). I couldn't find any shutdownHookTrigger references after a brief google, would you mind linking? – Quiz

Good solution. I am using SLF4j API with Log4j2 as impl. Is there a way to get this working without log4j2 API in my code. – Nalepka

I don't know if things have changed since. If you find out I'll be interested. – Quiz

<configuration ... shutdownHook="disable"> this is for XML based configuration, could you also give properties file version? – Laminated

As of Log4j 2.6 LogManager has shutdown methods. – Ahlers

It would be good to update the code example as per rgoers comment. Configurator is not part of log4j-api (it's in implementation JAR) so it is preferable to use LogManager.shutdown() going forward. – Upkeep

Answer 2

I basically just answered the same question and I tough I'll share my answer here. I encourage you to read the complete answer available here. I'll try to provide a summary here and adapt my answer to the current context.

In the first version, Log4j was providing an API to manually call the shutdown procedure. For reasons we don't have the knowledge of, it was removed from the second version. Now, the right way of doing it (according to the none-existent documentation), is to provide your own implementation of the ShutdownCallbackRegistry interface, which is responsible of the shutdown procedure.

Proposed solution

What I did to fix this issue is that I implemented my own version of the ShutdownCallbackRegistry interface. It mostly does the same things the default implementation does, but instead of registering itself as a shutdown hook to the JVM, it wait until it's invoked manually.

You can find the complete solution and instructions on GitHub/DjDCH/Log4j-StaticShutdown and use it in you own projects. Basically, at the end, you only have to do something like this in your application:

Runtime.getRuntime().addShutdownHook(new Thread(new Runnable() {
    @Override
    public void run() {
        try {
            // Do your usual shutdown stuff here that need logging
        } finally {
            // Shutdown Log4j 2 manually
            StaticShutdownCallbackRegistry.invoke();
        }
    }
}));

I can't say without any doubt that this is the perfect solution and that my implementation is perfect, but I tried to do it the right way. I'll be glad to hear feedback from you, either if you find this solution appropriate or not.

Schmo

Answer 3

I encountered the same problem from my Java app not long ago: The shutdown hook started, but after 1-2 log entries, the logging stopped due to the logger's shutdown process, as described above.

Since I use a wrapper logger class in my app without access to its shutdown hook, I chose to direct output to stdout and stderr, which allowed me to verify that the shutdown process works as designed.

System.println.out("shutting down servers");

You may also need to verify that the output and error streams are enabled within the pod config YAML; in my case, it worked out of the box.

Violaviolable