[jira] [Resolved] (LOG4J2-2867) ContextDataProvider will cause concurrent threads blocking at the first logging time

["Ralph Goers (Jira)" <ji...@apache.org>]

     [ https://issues.apache.org/jira/browse/LOG4J2-2867?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Ralph Goers resolved LOG4J2-2867.
---------------------------------
    Fix Version/s: 2.14.0
       Resolution: Fixed

> ContextDataProvider will cause concurrent threads blocking at the first logging time
> ------------------------------------------------------------------------------------
>
>                 Key: LOG4J2-2867
>                 URL: https://issues.apache.org/jira/browse/LOG4J2-2867
>             Project: Log4j 2
>          Issue Type: Bug
>          Components: Core
>    Affects Versions: 2.13.2, 2.13.3
>         Environment: Java Version: 1.8.0_45
> Web Server: Tomcat 8.0.30
> OS: CentOS 6.8
>            Reporter: Zishun Jiao
>            Priority: Major
>              Labels: performance
>             Fix For: 2.14.0
>
>   Original Estimate: 48h
>  Remaining Estimate: 48h
>
> The recently introduced  `ContextDataProvider` use `ServiceLoader` to find all possible implementations of ContextDataProvider, which will try to scan all jar files. So when many new threads comes in the first logging time concurrently, all thread will be blocking on the` getProviders` method. It will make web service get very bad performance to serve requests in the beginning.
> Here is an example of blocking thread stack:
> at java.util.zip.ZipFile.getEntry (ZipFile.java:309)at java.util.zip.ZipFile.getEntry (ZipFile.java:309)at java.util.jar.JarFile.getEntry (JarFile.java:240)at java.util.jar.JarFile.getJarEntry (JarFile.java:223)at sun.misc.URLClassPath$JarLoader.getResource (URLClassPath.java:1005)at sun.misc.URLClassPath$JarLoader.findResource (URLClassPath.java:983)at sun.misc.URLClassPath$1.next (URLClassPath.java:240)at sun.misc.URLClassPath$1.hasMoreElements (URLClassPath.java:250)at java.net.URLClassLoader$3$1.run (URLClassLoader.java:601)at java.net.URLClassLoader$3$1.run (URLClassLoader.java:599)at java.security.AccessController.doPrivileged (Native Method)at java.net.URLClassLoader$3.next (URLClassLoader.java:598)at java.net.URLClassLoader$3.hasMoreElements (URLClassLoader.java:623)at sun.misc.CompoundEnumeration.next (CompoundEnumeration.java:45)at sun.misc.CompoundEnumeration.hasMoreElements (CompoundEnumeration.java:54)at sun.misc.CompoundEnumeration.next (CompoundEnumeration.java:45)at sun.misc.CompoundEnumeration.hasMoreElements (CompoundEnumeration.java:54)at java.util.ServiceLoader$LazyIterator.hasNextService (ServiceLoader.java:354)at java.util.ServiceLoader$LazyIterator.hasNext (ServiceLoader.java:393)at java.util.ServiceLoader$1.hasNext (ServiceLoader.java:474)at org.apache.logging.log4j.core.impl.ThreadContextDataInjector.getProviders (ThreadContextDataInjector.java:254)at org.apache.logging.log4j.core.impl.ThreadContextDataInjector.access$000 (ThreadContextDataInjector.java:53)at org.apache.logging.log4j.core.impl.ThreadContextDataInjector$ForDefaultThreadContextMap.<init> (ThreadContextDataInjector.java:74)at org.apache.logging.log4j.core.impl.ContextDataInjectorFactory.createDefaultInjector (ContextDataInjectorFactory.java:91)at org.apache.logging.log4j.core.impl.ContextDataInjectorFactory.createInjector (ContextDataInjectorFactory.java:71)at org.apache.logging.log4j.core.async.RingBufferLogEventTranslator.<init> (RingBufferLogEventTranslator.java:40)at org.apache.logging.log4j.core.async.AsyncLogger.getCachedTranslator (AsyncLogger.java:121)at org.apache.logging.log4j.core.async.AsyncLogger.logWithThreadLocalTranslator (AsyncLogger.java:222)at org.apache.logging.log4j.core.async.AsyncLogger.access$000 (AsyncLogger.java:67)at org.apache.logging.log4j.core.async.AsyncLogger$1.log (AsyncLogger.java:152)at org.apache.logging.log4j.core.async.AsyncLogger.log (AsyncLogger.java:136)at org.apache.logging.log4j.spi.AbstractLogger.tryLogMessage (AbstractLogger.java:2198)at org.apache.logging.log4j.spi.AbstractLogger.logMessageTrackRecursion (AbstractLogger.java:2152)at org.apache.logging.log4j.spi.AbstractLogger.logMessageSafely (AbstractLogger.java:2135)at org.apache.logging.log4j.spi.AbstractLogger.logMessage (AbstractLogger.java:2011)at org.apache.logging.log4j.spi.AbstractLogger.logIfEnabled (AbstractLogger.java:1983)at org.apache.logging.slf4j.Log4jLogger.warn



--
This message was sent by Atlassian Jira
(v8.3.4#803005)