[
https://issues.apache.org/jira/browse/LOG4J2-459?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13840055#comment-13840055
]
Shaddy Baddah commented on LOG4J2-459:
--------------------------------------
Thanks for the explanation Ralph. But what I mean is that LogManager.getContext
*indirectly* is kicking-off the configuration. I've included the full stack
trace of a run at the base of the comment, but the telling portion is directly
below this line:
{noformat}
LoggerContext.start() line: 149
Log4jContextFactory.getContext(String, ClassLoader, boolean, URI) line:
104
Log4jContextFactory.getContext(String, ClassLoader, boolean, URI) line:
34
LogManager.getContext(ClassLoader, boolean, URI) line: 187
Configurator.initialize(String, ClassLoader, URI, Object) line: 103
Configurator.initialize(String, ClassLoader, String, Object) line: 63
Log4jWebInitializerImpl.initializeNonJndi(String) line: 136
Log4jWebInitializerImpl.initialize() line: 82
Log4jServletContainerInitializer.onStartup(Set<Class<?>>,
ServletContext) line: 41
{noformat}
So you can see that LogManager.getContext() leads a path down to the very same
call to start as the lines you listed.
{noformat}
Thread [main] (Suspended (breakpoint at line 49 in WebLookup))
WebLookup.lookup(String) line: 49
Interpolator.lookup(LogEvent, String) line: 121
StrSubstitutor.resolveVariable(LogEvent, String, StringBuilder, int,
int) line: 904
StrSubstitutor.substitute(LogEvent, StringBuilder, int, int,
List<String>) line: 825
StrSubstitutor.substitute(LogEvent, StringBuilder, int, int) line: 737
StrSubstitutor.replace(LogEvent, String) line: 306
XMLConfiguration(BaseConfiguration).createPluginObject(PluginType<T>,
Node, LogEvent) line: 720
XMLConfiguration(BaseConfiguration).createConfiguration(Node, LogEvent)
line: 595
XMLConfiguration(BaseConfiguration).createConfiguration(Node, LogEvent)
line: 587
XMLConfiguration(BaseConfiguration).doConfigure() line: 244
XMLConfiguration(BaseConfiguration).start() line: 142
LoggerContext.setConfiguration(Configuration) line: 339
LoggerContext.reconfigure() line: 378
LoggerContext.start() line: 149
Log4jContextFactory.getContext(String, ClassLoader, boolean, URI) line:
104
Log4jContextFactory.getContext(String, ClassLoader, boolean, URI) line:
34
LogManager.getContext(ClassLoader, boolean, URI) line: 187
Configurator.initialize(String, ClassLoader, URI, Object) line: 103
Configurator.initialize(String, ClassLoader, String, Object) line: 63
Log4jWebInitializerImpl.initializeNonJndi(String) line: 136
Log4jWebInitializerImpl.initialize() line: 82
Log4jServletContainerInitializer.onStartup(Set<Class<?>>,
ServletContext) line: 41
ContainerInitializer.callStartup(WebAppContext) line: 106
ServletContainerInitializerListener.doStart() line: 107
ServletContainerInitializerListener(AbstractLifeCycle).start() line: 64
JettyWebAppContext(AggregateLifeCycle).doStart() line: 81
JettyWebAppContext(AbstractHandler).doStart() line: 58
JettyWebAppContext(HandlerWrapper).doStart() line: 96
JettyWebAppContext(ScopedHandler).doStart() line: 115
JettyWebAppContext(ContextHandler).startContext() line: 763
JettyWebAppContext(ServletContextHandler).startContext() line: 249
JettyWebAppContext(WebAppContext).startContext() line: 1242
JettyWebAppContext(ContextHandler).doStart() line: 717
JettyWebAppContext(WebAppContext).doStart() line: 494
JettyWebAppContext.doStart() line: 298
JettyWebAppContext(AbstractLifeCycle).start() line: 64
ContextHandlerCollection(HandlerCollection).doStart() line: 229
ContextHandlerCollection.doStart() line: 172
ContextHandlerCollection(AbstractLifeCycle).start() line: 64
HandlerCollection.doStart() line: 229
HandlerCollection(AbstractLifeCycle).start() line: 64
JettyServer(HandlerWrapper).doStart() line: 95
JettyServer(Server).doStart() line: 282
JettyServer.doStart() line: 65
JettyServer(AbstractLifeCycle).start() line: 64
JettyRunMojo(AbstractJettyMojo).startJetty() line: 520
JettyRunMojo(AbstractJettyMojo).execute() line: 365
JettyRunMojo.execute() line: 523
DefaultBuildPluginManager.executeMojo(MavenSession, MojoExecution)
line: 101
MojoExecutor.execute(MavenSession, MojoExecution, ProjectIndex,
DependencyContext) line: 209
MojoExecutor.execute(MavenSession, MojoExecution, ProjectIndex,
DependencyContext, PhaseRecorder) line: 153
MojoExecutor.execute(MavenSession, List<MojoExecution>, ProjectIndex)
line: 145
LifecycleModuleBuilder.buildProject(MavenSession, MavenSession,
ReactorContext, MavenProject, TaskSegment) line: 84
LifecycleModuleBuilder.buildProject(MavenSession, ReactorContext,
MavenProject, TaskSegment) line: 59
LifecycleStarter.singleThreadedBuild(MavenSession, ReactorContext,
ProjectBuildList, List<TaskSegment>, ReactorBuildStatus) line: 183
LifecycleStarter.execute(MavenSession) line: 161
DefaultMaven.doExecute(MavenExecutionRequest) line: 320
DefaultMaven.execute(MavenExecutionRequest) line: 156
MavenCli.execute(MavenCli$CliRequest) line: 537
MavenCli.doMain(MavenCli$CliRequest) line: 196
MavenCli.main(String[], ClassWorld) line: 141
NativeMethodAccessorImpl.invoke0(Method, Object, Object[]) line: not
available [native method]
NativeMethodAccessorImpl.invoke(Object, Object[]) line: 57
DelegatingMethodAccessorImpl.invoke(Object, Object[]) line: 43
Method.invoke(Object, Object...) line: 606
Launcher.launchEnhanced(String[]) line: 290
Launcher.launch(String[]) line: 230
Launcher.mainWithExitCode(String[]) line: 409
Launcher.main(String[]) line: 352
{noformat}
> Race condition on Web app configuration prevents ${web:initParam. lookup
> ------------------------------------------------------------------------
>
> Key: LOG4J2-459
> URL: https://issues.apache.org/jira/browse/LOG4J2-459
> Project: Log4j 2
> Issue Type: Bug
> Components: Core
> Affects Versions: 2.0-beta9
> Reporter: Shaddy Baddah
> Priority: Minor
>
> I am happy for someone to challenge me on this assertion, but I cannot see
> how ${web:initParam.*} notation in XML configuration could ever work in
> 2.0-beta9 at least. Well at least for bootstrapped config.
> I have a Web application that includes an XML configfile in the WAR at:
> WEB-INF/classes/log4j2.xml
> The file looks something like this:
> ?xml version="1.0" encoding="UTF-8"?>
> <Configuration status="WARN">
> <Appenders>
> <File name="file" fileName="${web:initParam.myapp.logdir}/myapp.log"
> append="true">
> <PatternLayout pattern="%d [%t] %-5p %c - %m%n"/>
> </File>
> </Appenders>
> <Loggers>
> <Root level="warn">
> <AppenderRef ref="file"/>
> </Root>
> </Loggers>
> </Configuration>
> For the uninitiated, a recap on how ${web:initParam.myapp.logdir} is
> resolved, to the best of my understanding.
> The ${web: prefix will indicate to log4j2 that it should use the WebLookup
> class to resolve what comes after it; initParam.myapp.logdir.
> WebLookup will then check if that key is prefixed with initParam. (as well as
> another attr type prefix), and seeing that it is, will use the remainder as
> the real key name: myapp.logdir.
> It then calls getInitParameter() with that key on the ServletContext for the
> parent web application. That should pluck a value that could, for example, be
> configured in the web.xml like this:
> <context-param>
> <param-name>myapp.logdir</param-name>
> <param-value>c:/myapp_logs</param-value>
> </context-param>
> However, this is where there is a race condition. To get the ServletContext ,
> the WebLookup.lookup() method will call its own getServletContext() method.
> This in term attempt to get the ServletContext from the LogManager singleton,
> which stores it as an untyped (java.lang.Object) externalContext concept.
> For a Web App, this externalContext is not being set ahead of the
> bootstrapping parse of the XML config file.The problem can be seen in the
> sequencing of instructions in the Configurator.initialize() method:
> public static LoggerContext initialize(final String name, final
> ClassLoader loader, final URI configLocation,
> final Object externalContext) {
> try {
> final org.apache.logging.log4j.spi.LoggerContext context =
> LogManager.getContext(loader, false, configLocation);
> if (context instanceof LoggerContext) {
> final LoggerContext ctx = (LoggerContext) context;
> ContextAnchor.THREAD_CONTEXT.set(ctx);
> if (externalContext != null) {
> ctx.setExternalContext(externalContext);
> }
> This line:
> final org.apache.logging.log4j.spi.LoggerContext context =
> LogManager.getContext(loader, false, configLocation);
> kicks-off the boostrapped parse of the XML config, that in turn utilizes
> WebLookup.lookup().
> You can see however that ctx.setExternalContext(externalContext) is called
> after.
> Simple reasoning suggests that this initialization could be moved ahead.
> However this code applies to non-web apps too, and being not familiar with
> the design and intentions, I'd be very appreciative of someone looking into a
> fix for this.
> Thanks.
--
This message was sent by Atlassian JIRA
(v6.1#6144)
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]