You are viewing a plain text version of this content. The canonical link for it is here.
Posted to log4j-dev@logging.apache.org by "Ralph Goers (JIRA)" <ji...@apache.org> on 2013/09/11 01:49:52 UTC

[jira] [Comment Edited] (LOG4J2-393) Low initialization performance when using Log4J with jar packages

    [ https://issues.apache.org/jira/browse/LOG4J2-393?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13763724#comment-13763724 ] 

Ralph Goers edited comment on LOG4J2-393 at 9/10/13 11:49 PM:
--------------------------------------------------------------

Scott,

I am noticing that the "advertiser" attribute is on the configuration element along with the "packages" attribute. Prior to the advertiser change the PluginManager was initialized in the start method in BaseConfiguration. In that case all the packages would already have been registered. When you moved the PluginManager initialization into XMLConfiguration you made it indeterminate since the packages element might be processed before or after the advertisers element. 

The "correct" way to do this is to create an advertisers Node in XMLConfiguration and JSONConfiguration and then perform that actual Plugin work in doConfiguration.

I'm not sure what you mean by "lookups" as the config file isn't referencing any variables? Do you mean looking up plugins in the test package? That is done all over the place to get the ListAppender, AlwaysFailAppender, etc and worked just fine before the advertiser change.

I am going to change the code to what I described above to correct this.
                
      was (Author: ralph.goers@dslextreme.com):
    Scott,

I am noticing that the "advertiser" attribute is on the configuration element along with the "packages" attribute. Prior to the advertiser change the PluginManager was initialized in the start method in BaseConfiguration. In that case all the packages would already have been registered. When you moved into XMLConfiguration you made it indeterminate since the packages element might be processed before or after the advertisers element. 

The "correct" way to do this is to create an advertisers Node in XMLConfiguration and JSONConfiguration and then perform that actual Plugin work in doConfiguration.

I'm not sure what you mean by "lookups" as the config file isn't referencing any variables? Do you mean looking up plugins in the test package? That is done all over the place to get the ListAppender, AlwaysFailAppender, etc and worked just fine before the advertiser change.

I am going to change it to what I described above to correct this.
                  
> Low initialization performance when using Log4J with jar packages
> -----------------------------------------------------------------
>
>                 Key: LOG4J2-393
>                 URL: https://issues.apache.org/jira/browse/LOG4J2-393
>             Project: Log4j 2
>          Issue Type: Bug
>          Components: Configurators, Core
>    Affects Versions: 2.0-beta8
>            Reporter: Philipp Hedwig
>              Labels: performance
>
> 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|https://issues.apache.org/jira/browse/LOG4J2-184], only without the jar problem.
> The solution to [LOG4J2-175|https://issues.apache.org/jira/browse/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!

--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira

---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org