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