Uploaded image for project: 'Log4j 2'
  1. Log4j 2
  2. LOG4J2-3663

JAR file containing Log4j configuration isn't closed on Tomcat

    XMLWordPrintableJSON

Details

    • Bug
    • Status: Open
    • Major
    • Resolution: Unresolved
    • 2.18.0
    • None
    • Configuration, Core
    • None

    Description

      This issue is related to LOG4J2-3423 - JAR file containing Log4j configuration isn't closed.

      But the problem still occurs when application is running on Tomcat (9.0.74 in my case) and log4j configuration (log4j2.xml) is present jar file.

      I think that way how to acquire last modified timestamp (work around https://bugs.openjdk.java.net/browse/JDK-6956385) works only when "standard java" sun.net.www.protocol.jar.Handler URLStreamHandler is used. But in Tomcat is used org.apache.catalina.webresources.CachedResource.CachedResourceURLStreamHandler due Tomcat Resource Caching, which is enabled by default.

      I verified, that disabling Tomcat Resource Caching can be used as workaround to this problem.
      In this case CachedResourceURLStreamHandler is not configured and web application can be undeploy without problem with deleting jar file (windows). But disable resource cache is not usually what we want and in addition Tomcat Resource Caching is enabled by default.

      AFAIU, the problem with CachedResourceURLStreamHandler is in org.apache.catalina.webresources.CachedResource.CachedResourceJarURLConnection.getJarFile() method, see (https://github.com/apache/tomcat/blob/9.0.74/java/org/apache/catalina/webresources/CachedResource.java#L623-L625). In this method the new JarURLConnection/JarFile is created and if this JarFile is not closed, then we get a file descriptor leak.

      Here is a piece of stack trace, where file descriptor is opened (based on log4j2-core:2.19.0 and tomcat:9.0.74):

      Opened .../apache-tomcat-9.0.74/webapps/.../WEB-INF/lib/....jar by thread:http-nio-8080-exec-6...
          at java.util.zip.ZipFile.<init>(ZipFile.java:156)
          at java.util.jar.JarFile.<init>(JarFile.java:170)
          at java.util.jar.JarFile.<init>(JarFile.java:107)
          at sun.net.www.protocol.jar.URLJarFile.<init>(URLJarFile.java:93)
          at sun.net.www.protocol.jar.URLJarFile.getJarFile(URLJarFile.java:69)
          at sun.net.www.protocol.jar.JarFileFactory.get(JarFileFactory.java:168)
          at sun.net.www.protocol.jar.JarFileFactory.getOrCreate(JarFileFactory.java:91)
          at sun.net.www.protocol.jar.JarURLConnection.connect(JarURLConnection.java:129)
          at sun.net.www.protocol.jar.JarURLConnection.getJarFile(JarURLConnection.java:89)
          at org.apache.catalina.webresources.CachedResource$CachedResourceJarURLConnection.getJarFile(CachedResource.java:624)
          at org.apache.logging.log4j.core.config.ConfigurationSource.getConfigurationSource(ConfigurationSource.java:372)
          at org.apache.logging.log4j.core.config.ConfigurationSource.fromResource(ConfigurationSource.java:360)
        ...
      

      I know (or it seems), that this problem is probably not directly related to log4j (because of Tomcat/Java bug...), but finally when web application, which uses log4j framework is deployed to Tomcat, we got this problem (unable to delete jar file on windows).

      I tried to find different way how to acquire last timestamp and it seems that following should work, because java.net.JarURLConnection.getJarFileURL() method works for both URLStreamHandlers and no additional file descriptor is opened (difference against sun.net.www.protocol.jar.JarURLConnection.getJarFile(), which open it).

      See my proposed pull request 1513 for details.

      private static ConfigurationSource getConfigurationSource(URL url) {
      ...
          } else if (urlConnection instanceof JarURLConnection) {
              // Work around https://bugs.openjdk.java.net/browse/JDK-6956385.
              URL jarFileUrl = ((JarURLConnection)urlConnection).getJarFileURL();
              File jarFile = new File(jarFileUrl.getFile());
              long lastModified = jarFile.lastModified();
              return new ConfigurationSource(urlConnection.getInputStream(), url, lastModified);
          }
      ...
      

      Attachments

        Issue Links

          Activity

            People

              Unassigned Unassigned
              rkraus Radek Kraus
              Votes:
              0 Vote for this issue
              Watchers:
              1 Start watching this issue

              Dates

                Created:
                Updated:

                Time Tracking

                  Estimated:
                  Original Estimate - Not Specified
                  Not Specified
                  Remaining:
                  Remaining Estimate - 0h
                  0h
                  Logged:
                  Time Spent - 20m
                  20m