No log output on contextDestroyed using ServletContextListener & SLF4J

Question

I am trying to write a message to the logger that a (Vaadin) servlet has stopped, this using SLF4J and Log4j2.

For this I am using a ServletContextListener which logs a message when the application has started. However I have been unable to get any output when logging inside the contextDestroyed method... Here is my implementation:

@WebListener
public class VaadinLogger implements ServletContextListener {

    private static final Logger logger = LoggerFactory.getLogger(VaadinLogger.class);

    @Override
    public void contextInitialized(ServletContextEvent contextEvent) {
        // Remove appenders from JUL loggers
        SLF4JBridgeHandler.removeHandlersForRootLogger();

        // Install bridge
        SLF4JBridgeHandler.install();

        // Get servlet context
        ServletContext context = contextEvent.getServletContext();

        // Retrieve name
        String name = context.getServletContextName();

        // Log servlet init information
        logger.info("Start \"{}\"", name);
    }

    @Override
    public void contextDestroyed(ServletContextEvent contextEvent) {
        // Get servlet context
        ServletContext context = contextEvent.getServletContext();

        // Retrieve name
        String name = context.getServletContextName();

        // Log servlet destroy information
        logger.info("End \"{}\"{}", name, System.lineSeparator()));

        // Uninstall bridge
        SLF4JBridgeHandler.uninstall();
    }
}

At this point, I'm guessing this is probably because at the point contextDestroyed is called, logging is no longer possible because they have already been destroyed by the garbage collector.

So now my question is, is it possible to either log that the servlet has stopped before the context is destroyed, or make the contextlistener execute before log4j2 loggers are destroyed?

Thanks in advance!

Kimes

If you have a live reference to the logger, then it's not garbage collected. Are you sure that the ServletContext has actually been destroyed? What is causing its destruction? – Crotchet

I'm hoping the context is destroyed when I stop the tomcat server. I asume this is working because SLF4JBridgeHandler.uninstall(); fixed some errors in my console output.. Also when I change logger.info(... to System.out.println(... the message is printed to console. – Kimes

Did you gracefully shutdown the container, or did you abruptly terminate the JVM? Often I see starters using Eclipse thinking that the red button on the Console tab would gracefully shutdown the container, but it actually immediately kills the JVM. You should use the red button on Servers tab instead (or rightclick server and choose "Stop"). – Eccentric

Yeah I did notice that a while ago, so I've been stopping the server using the stop button in the servers tab ever since. So unfortunately this is not the issue... – Kimes

We had a similar issue with logback, and resolved with this: https://mcmap.net/q/1168905/-logging-from-servlet-context-destroyed-event – Chane

Answer 1

Since log4j 2.14.1, you can disable the auto-shutdown and add a listener to stop the logger.

<context-param>
    <!-- auto-shutdown stops log4j when the web fragment unloads, but that
         is too early because it is before the listeners shut down. To 
         compensate, use a Log4jShutdownOnContextDestroyedListener and
         register it before any other listeners which means it will shut
         down *after* all other listeners. -->
    <param-name>isLog4jAutoShutdownDisabled</param-name>
    <param-value>true</param-value>
</context-param>    

<listener>
   <!-- ensure logging stops after other listeners by registering
        the shutdown listener first -->
    <listener-class>
       org.apache.logging.log4j.web.Log4jShutdownOnContextDestroyedListener
    </listener-class>
</listener>
<listener>
    <listener-class>
        org.springframework.web.context.ContextLoaderListener
    </listener-class>
</listener>

Birkner

Answer 2

First, do you have the log4j 2.x api, core and web jars in your classpath? The log4j-web-2.x.jar also registers a context listener used to shut down the logging subsystem when the web app is unloaded.

If your listener runs after that you won't be able to log anything anymore.

You can check what's happening by setting <Configuration status="trace" ... in your log4j2 configuration file.

Est

Yeah all jars (api,core,web) are loaded into the classpath, so that should not be the issue. I will try to use set the status to trace and see what output I get first thing in the morning! – Kimes

Answer 3

log4j2 (log4j-web-xx.jar) comes with a web-fragment. This fragment contains a ServletContextListener. The order of listeners are depend of the initialization (see Servlet Specification). Default: your application first then others.

Your can change the order to specify an <absolut-ordering> in your web.xml:

<web-app>
  <absolute-ordering>
    <name>log4j</name>
    <others/>
  </absolute-ordering>

See also: servlet-30-web-fragmentxml

Infuriate

Thanks for the suggestion, I'll try it tomorrow and let u know! – Kimes