[
https://issues.apache.org/jira/browse/LOG4J2-565?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13933160#comment-13933160
]
Tiago Cardoso edited comment on LOG4J2-565 at 3/13/14 12:19 PM:
----------------------------------------------------------------
I was in fact extracting all jars into my application Jar.
I have redone the tests while keeping the log4j-api-2.0-rc1.jar and the
log4j-core-2.0-rc1.jar separate. The AppJar.jar has only 4KB and 3 classes with
it (only one is being used). Now I've got the following results:
Starting application:1394712834342
Getting the first logger:1394712834355
2014-03-13 12:14:08,847 DEBUG Generated plugins in 0.000383692 seconds
2014-03-13 12:14:08,919 DEBUG Found Plugin Map at
jar:file:/tmp/AppJar_lib/log4j-core-2.0-rc1.jar!/org/apache/logging/log4j/core/config/plugins/Log4j2Plugins.dat
2014-03-13 12:14:18,214 DEBUG Generated plugins in 9.338745544 seconds
2014-03-13 12:14:23,052 DEBUG Generated plugins in 4.723707079 seconds
2014-03-13 12:14:23,484 DEBUG Calling createLayout on class
org.apache.logging.log4j.core.layout.PatternLayout for element PatternLayout
with params(pattern="[%d{dd MMM yyyy - HH:mm:ss.SSS}] %p - %m%n",
Configuration(/tmp/log4j2.xml), null, charset="null",
alwaysWriteExceptions="null", noConsoleNoAnsi="null")
2014-03-13 12:14:28,500 DEBUG Generated plugins in 5.000661231 seconds
2014-03-13 12:14:28,643 DEBUG Calling createAppender on class
org.apache.logging.log4j.core.appender.ConsoleAppender for element Console with
params(PatternLayout([%d{dd MMM yyyy - HH:mm:ss.SSS}] %p - %m%n), null,
target="SYSTEM_OUT", name="Console", follow="null", ignoreExceptions="null")
2014-03-13 12:14:28,717 DEBUG Calling createLayout on class
org.apache.logging.log4j.core.layout.PatternLayout for element PatternLayout
with params(pattern="[%d{dd MMM yyyy - HH:mm:ss.SSS}] %p - %m%n",
Configuration(/tmp/log4j2.xml), null, charset="null",
alwaysWriteExceptions="null", noConsoleNoAnsi="null")
2014-03-13 12:14:28,793 DEBUG Calling createPolicy on class
org.apache.logging.log4j.core.appender.rolling.SizeBasedTriggeringPolicy for
element SizeBasedTriggeringPolicy with params(size="100 KB")
2014-03-13 12:14:28,894 DEBUG Calling createPolicy on class
org.apache.logging.log4j.core.appender.rolling.CompositeTriggeringPolicy for
element Policies with params(Policies={SizeBasedTriggeringPolicy(size=102400)})
2014-03-13 12:14:29,006 DEBUG Calling createStrategy on class
org.apache.logging.log4j.core.appender.rolling.DefaultRolloverStrategy for
element DefaultRolloverStrategy with params(max="200", min="null",
fileIndex="null", compressionLevel="1", Configuration(/tmp/log4j2.xml))
2014-03-13 12:14:29,125 DEBUG Calling createAppender on class
org.apache.logging.log4j.core.appender.RollingRandomAccessFileAppender for
element RollingRandomAccessFile with params(fileName="/tmp/teste.log",
filePattern="/tmp/testingLog.PART_%i.gz", append="null",
name="RollingRandomAccessFile", immediateFlush="true",
Policies(CompositeTriggeringPolicy{SizeBasedTriggeringPolicy(size=102400)}),
DefaultRolloverStrategy(DefaultRolloverStrategy(min=1, max=200)),
PatternLayout([%d{dd MMM yyyy - HH:mm:ss.SSS}] %p - %m%n), null,
ignoreExceptions="null", advertise="null", advertiseURI="null",
Configuration(/tmp/log4j2.xml))
2014-03-13 12:14:29,212 TRACE RandomAccessFile /tmp/teste.log seek to 548
2014-03-13 12:14:29,229 DEBUG Starting RollingRandomAccessFileManager
/tmp/teste.log
2014-03-13 12:14:34,857 DEBUG Generated plugins in 5.581791074 seconds
2014-03-13 12:14:34,893 DEBUG Calling createAppenders on class
org.apache.logging.log4j.core.config.plugins.AppendersPlugin for element
Appenders with params(Appenders={Console, RollingRandomAccessFile})
2014-03-13 12:14:34,926 DEBUG Calling createAppenderRef on class
org.apache.logging.log4j.core.config.AppenderRef for element AppenderRef with
params(ref="RollingRandomAccessFile", level="null", null)
2014-03-13 12:14:34,955 DEBUG Calling createAppenderRef on class
org.apache.logging.log4j.core.config.AppenderRef for element AppenderRef with
params(ref="Console", level="null", null)
2014-03-13 12:14:35,012 DEBUG Calling createLogger on class
org.apache.logging.log4j.core.config.LoggerConfig$RootLogger for element Root
with params(additivity="null", level="trace", includeLocation="null",
AppenderRef={RollingRandomAccessFile, Console}, Properties={},
Configuration(/tmp/log4j2.xml), null)
2014-03-13 12:14:35,050 DEBUG Calling createLoggers on class
org.apache.logging.log4j.core.config.plugins.LoggersPlugin for element Loggers
with params(Loggers={root})
2014-03-13 12:14:37,687 DEBUG Registering MBean
org.apache.logging.log4j2:type=sun.misc.Launcher$AppClassLoader@cac268
2014-03-13 12:14:37,782 DEBUG Registering MBean
org.apache.logging.log4j2:type=sun.misc.Launcher$AppClassLoader@cac268,component=StatusLogger
2014-03-13 12:14:37,847 DEBUG Registering MBean
org.apache.logging.log4j2:type=sun.misc.Launcher$AppClassLoader@cac268,component=ContextSelector
2014-03-13 12:14:37,954 DEBUG Registering MBean
org.apache.logging.log4j2:type=sun.misc.Launcher$AppClassLoader@cac268,component=Loggers,name=
2014-03-13 12:14:38,039 DEBUG Registering MBean
org.apache.logging.log4j2:type=sun.misc.Launcher$AppClassLoader@cac268,component=Appenders,name=Console
2014-03-13 12:14:38,104 DEBUG Registering MBean
org.apache.logging.log4j2:type=sun.misc.Launcher$AppClassLoader@cac268,component=Appenders,name=RollingRandomAccessFile
2014-03-13 12:14:38,128 DEBUG Reconfiguration completed
Loggers are fully loaded:
[13 Mar 2014 - 12:14:38.441] TRACE - Entering application.
[13 Mar 2014 - 12:14:38.514] TRACE - Going to leave application.1394712878514
2014-03-13 12:14:38,565 DEBUG Shutting down RollingRandomAccessFileManager
/tmp/teste.log
2014-03-13 12:14:38,585 DEBUG Shutting down OutputStreamManager SYSTEM_OUT
2014-03-13 12:14:38,613 DEBUG Unregistering MBean
org.apache.logging.log4j2:type=sun.misc.Launcher$AppClassLoader@cac268
2014-03-13 12:14:38,636 DEBUG Unregistering MBean
org.apache.logging.log4j2:type=sun.misc.Launcher$AppClassLoader@cac268,component=StatusLogger
2014-03-13 12:14:38,653 DEBUG Unregistering MBean
org.apache.logging.log4j2:type=sun.misc.Launcher$AppClassLoader@cac268,component=ContextSelector
2014-03-13 12:14:38,719 DEBUG Unregistering MBean
org.apache.logging.log4j2:type=sun.misc.Launcher$AppClassLoader@cac268,component=Loggers,name=
2014-03-13 12:14:38,757 DEBUG Unregistering MBean
org.apache.logging.log4j2:type=sun.misc.Launcher$AppClassLoader@cac268,component=Appenders,name=RollingRandomAccessFile
2014-03-13 12:14:38,770 DEBUG Unregistering MBean
org.apache.logging.log4j2:type=sun.misc.Launcher$AppClassLoader@cac268,component=Appenders,name=Console
was (Author: matutano):
I was in fact extracting all jars into my application Jar.
I have redone the tests while keeping the log4j-api-2.0-rc1.jar and the
log4j-core-2.0-rc1.jar separate with the following results:
Starting application:1394712834342
Getting the first logger:1394712834355
2014-03-13 12:14:08,847 DEBUG Generated plugins in 0.000383692 seconds
2014-03-13 12:14:08,919 DEBUG Found Plugin Map at
jar:file:/tmp/AppJar_lib/log4j-core-2.0-rc1.jar!/org/apache/logging/log4j/core/config/plugins/Log4j2Plugins.dat
2014-03-13 12:14:18,214 DEBUG Generated plugins in 9.338745544 seconds
2014-03-13 12:14:23,052 DEBUG Generated plugins in 4.723707079 seconds
2014-03-13 12:14:23,484 DEBUG Calling createLayout on class
org.apache.logging.log4j.core.layout.PatternLayout for element PatternLayout
with params(pattern="[%d{dd MMM yyyy - HH:mm:ss.SSS}] %p - %m%n",
Configuration(/tmp/log4j2.xml), null, charset="null",
alwaysWriteExceptions="null", noConsoleNoAnsi="null")
2014-03-13 12:14:28,500 DEBUG Generated plugins in 5.000661231 seconds
2014-03-13 12:14:28,643 DEBUG Calling createAppender on class
org.apache.logging.log4j.core.appender.ConsoleAppender for element Console with
params(PatternLayout([%d{dd MMM yyyy - HH:mm:ss.SSS}] %p - %m%n), null,
target="SYSTEM_OUT", name="Console", follow="null", ignoreExceptions="null")
2014-03-13 12:14:28,717 DEBUG Calling createLayout on class
org.apache.logging.log4j.core.layout.PatternLayout for element PatternLayout
with params(pattern="[%d{dd MMM yyyy - HH:mm:ss.SSS}] %p - %m%n",
Configuration(/tmp/log4j2.xml), null, charset="null",
alwaysWriteExceptions="null", noConsoleNoAnsi="null")
2014-03-13 12:14:28,793 DEBUG Calling createPolicy on class
org.apache.logging.log4j.core.appender.rolling.SizeBasedTriggeringPolicy for
element SizeBasedTriggeringPolicy with params(size="100 KB")
2014-03-13 12:14:28,894 DEBUG Calling createPolicy on class
org.apache.logging.log4j.core.appender.rolling.CompositeTriggeringPolicy for
element Policies with params(Policies={SizeBasedTriggeringPolicy(size=102400)})
2014-03-13 12:14:29,006 DEBUG Calling createStrategy on class
org.apache.logging.log4j.core.appender.rolling.DefaultRolloverStrategy for
element DefaultRolloverStrategy with params(max="200", min="null",
fileIndex="null", compressionLevel="1", Configuration(/tmp/log4j2.xml))
2014-03-13 12:14:29,125 DEBUG Calling createAppender on class
org.apache.logging.log4j.core.appender.RollingRandomAccessFileAppender for
element RollingRandomAccessFile with params(fileName="/tmp/teste.log",
filePattern="/tmp/testingLog.PART_%i.gz", append="null",
name="RollingRandomAccessFile", immediateFlush="true",
Policies(CompositeTriggeringPolicy{SizeBasedTriggeringPolicy(size=102400)}),
DefaultRolloverStrategy(DefaultRolloverStrategy(min=1, max=200)),
PatternLayout([%d{dd MMM yyyy - HH:mm:ss.SSS}] %p - %m%n), null,
ignoreExceptions="null", advertise="null", advertiseURI="null",
Configuration(/tmp/log4j2.xml))
2014-03-13 12:14:29,212 TRACE RandomAccessFile /tmp/teste.log seek to 548
2014-03-13 12:14:29,229 DEBUG Starting RollingRandomAccessFileManager
/tmp/teste.log
2014-03-13 12:14:34,857 DEBUG Generated plugins in 5.581791074 seconds
2014-03-13 12:14:34,893 DEBUG Calling createAppenders on class
org.apache.logging.log4j.core.config.plugins.AppendersPlugin for element
Appenders with params(Appenders={Console, RollingRandomAccessFile})
2014-03-13 12:14:34,926 DEBUG Calling createAppenderRef on class
org.apache.logging.log4j.core.config.AppenderRef for element AppenderRef with
params(ref="RollingRandomAccessFile", level="null", null)
2014-03-13 12:14:34,955 DEBUG Calling createAppenderRef on class
org.apache.logging.log4j.core.config.AppenderRef for element AppenderRef with
params(ref="Console", level="null", null)
2014-03-13 12:14:35,012 DEBUG Calling createLogger on class
org.apache.logging.log4j.core.config.LoggerConfig$RootLogger for element Root
with params(additivity="null", level="trace", includeLocation="null",
AppenderRef={RollingRandomAccessFile, Console}, Properties={},
Configuration(/tmp/log4j2.xml), null)
2014-03-13 12:14:35,050 DEBUG Calling createLoggers on class
org.apache.logging.log4j.core.config.plugins.LoggersPlugin for element Loggers
with params(Loggers={root})
2014-03-13 12:14:37,687 DEBUG Registering MBean
org.apache.logging.log4j2:type=sun.misc.Launcher$AppClassLoader@cac268
2014-03-13 12:14:37,782 DEBUG Registering MBean
org.apache.logging.log4j2:type=sun.misc.Launcher$AppClassLoader@cac268,component=StatusLogger
2014-03-13 12:14:37,847 DEBUG Registering MBean
org.apache.logging.log4j2:type=sun.misc.Launcher$AppClassLoader@cac268,component=ContextSelector
2014-03-13 12:14:37,954 DEBUG Registering MBean
org.apache.logging.log4j2:type=sun.misc.Launcher$AppClassLoader@cac268,component=Loggers,name=
2014-03-13 12:14:38,039 DEBUG Registering MBean
org.apache.logging.log4j2:type=sun.misc.Launcher$AppClassLoader@cac268,component=Appenders,name=Console
2014-03-13 12:14:38,104 DEBUG Registering MBean
org.apache.logging.log4j2:type=sun.misc.Launcher$AppClassLoader@cac268,component=Appenders,name=RollingRandomAccessFile
2014-03-13 12:14:38,128 DEBUG Reconfiguration completed
Loggers are fully loaded:
[13 Mar 2014 - 12:14:38.441] TRACE - Entering application.
[13 Mar 2014 - 12:14:38.514] TRACE - Going to leave application.1394712878514
2014-03-13 12:14:38,565 DEBUG Shutting down RollingRandomAccessFileManager
/tmp/teste.log
2014-03-13 12:14:38,585 DEBUG Shutting down OutputStreamManager SYSTEM_OUT
2014-03-13 12:14:38,613 DEBUG Unregistering MBean
org.apache.logging.log4j2:type=sun.misc.Launcher$AppClassLoader@cac268
2014-03-13 12:14:38,636 DEBUG Unregistering MBean
org.apache.logging.log4j2:type=sun.misc.Launcher$AppClassLoader@cac268,component=StatusLogger
2014-03-13 12:14:38,653 DEBUG Unregistering MBean
org.apache.logging.log4j2:type=sun.misc.Launcher$AppClassLoader@cac268,component=ContextSelector
2014-03-13 12:14:38,719 DEBUG Unregistering MBean
org.apache.logging.log4j2:type=sun.misc.Launcher$AppClassLoader@cac268,component=Loggers,name=
2014-03-13 12:14:38,757 DEBUG Unregistering MBean
org.apache.logging.log4j2:type=sun.misc.Launcher$AppClassLoader@cac268,component=Appenders,name=RollingRandomAccessFile
2014-03-13 12:14:38,770 DEBUG Unregistering MBean
org.apache.logging.log4j2:type=sun.misc.Launcher$AppClassLoader@cac268,component=Appenders,name=Console
> Log4j2 loading time
> -------------------
>
> Key: LOG4J2-565
> URL: https://issues.apache.org/jira/browse/LOG4J2-565
> Project: Log4j 2
> Issue Type: Bug
> Components: API
> Affects Versions: 2.0-rc1
> Environment: Using ejre1.6.0_25 in an ARM926EJ-S rev 5 (v5l)
> Reporter: Tiago Cardoso
>
> Everything runs fine on the Desktop computer, but the embedded system
> struggles to obtain the Logger.
> It takes 17 seconds just to run this line:
> Logger logger = LogManager.getLogger("testLogger");
> The classpath is empty and the whole applications is just:
> public static void main(String[] arg){
> System.out.println("Starting application:" + System.currentTimeMillis());
> Logger logger = LogManager.getLogger("testLogger");
> logger.trace("Going to leave application." + System.currentTimeMillis());
> System.exit(1);
> }
> The same system is able to run a client graphic application without this kind
> of event.
--
This message was sent by Atlassian JIRA
(v6.2#6252)
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
