DefaultTimeBasedFileNamingAndTriggeringPolicy should ignore early Joran call
----------------------------------------------------------------------------
Key: LBCORE-196
URL: http://jira.qos.ch/browse/LBCORE-196
Project: logback-core
Issue Type: Bug
Components: Rolling
Affects Versions: 0.9.27
Reporter: Juergen Hermann
Assignee: Logback dev list
Priority: Minor
Given a config snippet like this, where we _explicitely_ use the
DefaultTimeBasedFileNamingAndTriggeringPolicy to cause the problem:
<appender name="sandbox"
class="ch.qos.logback.core.rolling.RollingFileAppender">
<file>${catalina.base}/log/sandbox.log</file>
<append>true</append>
<rollingPolicy
class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
<fileNamePattern>${catalina.base}/log/sandbox.log.%d{yyyyMMdd}-000000</fileNamePattern>
<timeBasedFileNamingAndTriggeringPolicy
class="ch.qos.logback.core.rolling.DefaultTimeBasedFileNamingAndTriggeringPolicy"/>
</rollingPolicy>
<encoder>
<pattern>%d{ISO8601} %9relative [%thread] %-5level %logger -
%msg%n</pattern>
</encoder>
</appender>
we get this stacktrace:
-INFO in ch.qos.logback.classic.joran.action.JMXConfiguratorAction - begin
-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate
appender of type [ch.qos.logback.core.rolling.RollingFileAppender]
-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as
[sandbox]
-ERROR in ch.qos.logback.core.joran.spi.Interpreter@22:100 - RuntimeException
in Action for tag [timeBasedFileNamingAndTriggeringPolicy]
java.lang.NullPointerException
at
ch.qos.logback.core.rolling.TimeBasedFileNamingAndTriggeringPolicyBase.start(TimeBasedFileNamingAndTriggeringPolicyBase.java:44)
at
ch.qos.logback.core.rolling.DefaultTimeBasedFileNamingAndTriggeringPolicy.start(DefaultTimeBasedFileNamingAndTriggeringPolicy.java:32)
at
ch.qos.logback.core.joran.action.NestedComplexPropertyIA.end(NestedComplexPropertyIA.java:167)
Why is that? The code in TimeBasedRollingPolicy that sets the default
implementation if none is given
does so AFTER the "tbrp" member is set. Also, at the same location the
setContext(context) and
setTimeBasedRollingPolicy(this) calls are made, then start() is called on the
TBFNATP (in a fully
pre-initialized state).
But before that and with an explicit policy configuration, Joran calls the
start() method when the tag is
closed on the newly created TBFNATP (see above stack trace), and that call must
be ignored. That fact
is suprising at first and should be documented, and the default TBFNATP should
be augmented to be
able to be used explicitely as above.
My own TBFNATP, derived from the default, thus has this code:
@Override
public void start() {
if (tbrp == null) {
// Containing policy did not initialize us yet!
// This happens when Joran calls our start() when the config tag is
closed.
addInfo("Premature start ignored.");
return;
}
super.start();
...
which prevents the problem. Maybe there could also be a more global solution
that tells Joran
that this is a nested, yet incomplete element and to not call start() in the
first place, but let the
containing element do it.
--
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators:
http://jira.qos.ch/secure/Administrators.jspa
-
For more information on JIRA, see: http://www.atlassian.com/software/jira
_______________________________________________
logback-dev mailing list
[email protected]
http://qos.ch/mailman/listinfo/logback-dev
