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

Low initialization performance when using Log4J with jar packages

    XMLWordPrintableJSON

Details

    Description

      We discovered a huge performance difference when initializing Log4J with deployed jar packages compared to using it directly with normal class files.

      As it seems,
      org.apache.logging.log4j.core.config.plugins.ResolverUtil#loadImplementationsInJar
      is way slower than its counterpart
      org.apache.logging.log4j.core.config.plugins.ResolverUtil#loadImplementationsInDirectory
      and since this method gets called a few hundred times at initialization in this project, initialization of Log4J took more than 2 minutes with jar packages, compared to a few seconds with class files.

      The performance issue was already mentioned in LOG4J2-184, only without the jar problem.
      The solution to LOG4J2-175 might cause this, but we are unsure why the methods exactly get called this often.

      I just can tell that
      org.apache.logging.log4j.core.config.plugins.PluginManager#collectPlugins() gets called VERY often via
      org.apache.logging.log4j.core.config.BaseConfiguration#getPluginManager, which gets called by
      org.apache.logging.log4j.core.config.XMLConfiguration#constructHierarchy

      And collectPlugins() is remapped to collectPlugins(boolean preLoad, final String pkgs) with collectPlugins(true, null);. I'm unsure what this preLoad is for, since it gets overridden with false and apparently no kind of caching is used. In this method, resolver.findInPackage(test, pkg); takes a whole lot of time searching within the jars, as described in the beginning.

      The only way to work around this was for us to extract the custom appender in a sperate ant build target, and with this in a seperate jar, to minimize the size of the jar, reducing the search time.

      Can you cache things and maybe reduce the calls to collectPlugins()? I don't see the probability of changing plugins during initialization as described in LOG4J2-175 or the comment in org.apache.logging.log4j.core.config.BaseConfiguration#getPluginManager.
      Introducing a variable for the plugin manager within the for loop in org.apache.logging.log4j.core.config.XMLConfiguration#constructHierarchy might be a good idea!

      Attachments

        Activity

          People

            Unassigned Unassigned
            philipp.hedwig Philipp Hedwig
            Votes:
            0 Vote for this issue
            Watchers:
            4 Start watching this issue

            Dates

              Created:
              Updated:
              Resolved: