Log4j And Web Application Thread Leaks

Let's breathe some life back into this blog!

I'll start off by talking about an issue and solution I recently came across.

The Apache Log4J framework provides a way to re-configure logging on-the-fly by editing the configuration file.  The implementation spawns a thread (FileWatchdog.java) that monitors the configuration file for changes.  FileWatchdog never checks Thread.isInterrupted() .  Instead, it catches the interruption making the FileWatchdog thread live until the jvm is stopped.

The problem with this implementation (in version 1.2.16 I tested) is there is no easy way to stop the thread--some people have written that stopping it is impossible.  In a web application environment where you may re-deploy offten, the end result is several threads that never stop along with memory leaks on any held resources in the running threads.

Tomcat 7 provides us a warning:

Sep 27, 2013 10:29:36 AM org.apache.catalina.loader.WebappClassLoader clearReferencesThreads
SEVERE: The web application [/log4jtest] appears to have started a thread named [FileWatchdog] but has failed to stop it. This is very likely to create a memory leak.

With a simple test case, I discovered an easy way to forcibly kill these threads:

 /**
   * @see ServletContextListener#contextDestroyed(ServletContextEvent)
 */
  @SuppressWarnings("deprecation")
  public void contextDestroyed(ServletContextEvent sce) {
    for (Thread t : Thread.getAllStackTraces().keySet()) {
      if (t.getName().equals("FileWatchdog")) {
        System.out.println("Found FileWatchdog thread.  Killing it");
        t.stop();
      }
    }
    System.out.println("contextDestroyed");
  }

The downside with this approach is you have call the deprecated Thread.stop() method. The upside is this method is still available in Java 7. Placing the call in a ServletContextListener allows the container to stop these threads during the undeploy process.

Tomcat now shows no warning the tread was left running:

INFO: Reloading Context with name [/log4jtest] has started
Found FileWatchdog thread.  Killing it
contextDestroyed
Sep 27, 2013 10:40:18 AM org.apache.catalina.core.StandardContext reload

Using jvisualvm or any other tool confirms the thread was stopped.

It seems like such a quick fix (e.g. || isInterrupted()) FileWatchdog could throw in there--I'm not sure why this hasn't been addressed. Given the design decisions of Log4J to really have one instance per jvm, the current implementation makes sense.  However, it's common for individual web apps to configure their logging independent of any other web apps or global logging.  In addition it's just good coding standards for frameworks to provide clean startup/shutdown apis.  Maybe this is been addressed in the upcoming Log4j 2 .