Details
-
Bug
-
Resolution: Fixed
-
Major
-
None
-
1.0.13
-
None
-
Java 7u25 64bit, Logback 1.0.13, SLF4J 1.7.5
Description
In an attempt to upgrade to latest logback I hit problem with new version not being able to properly replace variable value if that variable has defualt. Version which I am upgrading from is 0.9.24 so I can not really tell when this was introduced. I searched Jira and found issues where similar functionality was not working (leaving bracket behind) but this is different problem.
Simplified definition of what we have as appender
<appender name="TRACE_FILE" class="ch.qos.logback.core.rolling.RollingFileAppender"> ... <file>${LOG_PATH}_trace.log</file> <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy"> <FileNamePattern> ${ARCHIVE_PATH}_trace_${ARCHIVE_SUFFIX} </FileNamePattern> <MaxHistory>10</MaxHistory> </rollingPolicy> ... </appender>
and variables are defined in separate file logback.properties
LOG_HOME=${logfilepath.default:-logs}
LOG_PATH=${LOG_HOME}/${APP_NAME}
ARCHIVE_PATH=${LOG_HOME}/archive/${APP_NAME}
Above configuration fails for both RollingPolicy/FileNamePattern and appender/file with exceptions indicating that substitution for default value failed (exception below is for the RollingPolicy but same thing happens for appender/file when I correct the pattern for policy)
13:34:55,636 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.rolling.RollingFileAppender]
13:34:55,652 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [TRACE_FILE]
13:34:55,744 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default type [ch.qos.logback.classic.boolex.JaninoEventEvaluator] for [evaluator] property
13:34:56,005 |-INFO in ch.qos.logback.classic.boolex.JaninoEventEvaluator@14bc1199 - Adding [return] prefix and a semicolon suffix. Expression becomes [return marker!=null && "audit".equals(marker.getName());]
13:34:56,005 |-INFO in ch.qos.logback.classic.boolex.JaninoEventEvaluator@14bc1199 - See also http://logback.qos.ch/codes.html#block
13:34:56,423 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy - Will use zip compression
13:34:56,429 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy - Will use the pattern ${logfilepath.default:-logs}/archive/comms_trace_%d{yyyyMMddHHmm}.log for the active file
13:34:56,439 |-INFO in c.q.l.core.rolling.DefaultTimeBasedFileNamingAndTriggeringPolicy - The date pattern is 'yyyyMMddHHmm' from file name pattern '${logfilepath.default:-logs}/archive/comms_trace_%d{yyyyMMddHHmm}.log.zip'.
13:34:56,439 |-INFO in c.q.l.core.rolling.DefaultTimeBasedFileNamingAndTriggeringPolicy - Roll-over every minute.
13:34:56,446 |-INFO in c.q.l.core.rolling.DefaultTimeBasedFileNamingAndTriggeringPolicy - Setting initial period to Tue Jan 21 13:34:56 CET 2014
13:34:56,516 |-ERROR in ch.qos.logback.core.joran.spi.Interpreter@28:16 - RuntimeException in Action for tag [appender] java.util.regex.PatternSyntaxException: Illegal repetition near index 0
${logfilepath.default:-logs}/archive/comms_trace_\d{4}\d{2}\d{2}\d{2}\d{2}.log.zip
^
at java.util.regex.PatternSyntaxException: Illegal repetition near index 0
${logfilepath.default:-logs}/archive/comms_trace_\d{4}\d{2}\d{2}\d{2}\d{2}.log.zip
^
at at java.util.regex.Pattern.error(Pattern.java:1924)
at at java.util.regex.Pattern.closure(Pattern.java:3104)
at at java.util.regex.Pattern.sequence(Pattern.java:2101)
at at java.util.regex.Pattern.expr(Pattern.java:1964)
at at java.util.regex.Pattern.compile(Pattern.java:1665)
at at java.util.regex.Pattern.<init>(Pattern.java:1337)
at at java.util.regex.Pattern.compile(Pattern.java:1022)
at at java.util.regex.Pattern.matches(Pattern.java:1128)
at at java.lang.String.matches(String.java:2063)
at at ch.qos.logback.core.rolling.RollingFileAppender.fileAndPatternCollide(RollingFileAppender.java:96)
at at ch.qos.logback.core.rolling.RollingFileAppender.start(RollingFileAppender.java:67)
at at ch.qos.logback.core.joran.action.AppenderAction.end(AppenderAction.java:96)
at at ch.qos.logback.core.joran.spi.Interpreter.callEndAction(Interpreter.java:317)
at at ch.qos.logback.core.joran.spi.Interpreter.endElement(Interpreter.java:196)
at at ch.qos.logback.core.joran.spi.Interpreter.endElement(Interpreter.java:182)
at at ch.qos.logback.core.joran.spi.EventPlayer.play(EventPlayer.java:62)
at at ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:149)
at at ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:135)
at at ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:99)
at at ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:49)
at at ch.qos.logback.classic.util.ContextInitializer.configureByResource(ContextInitializer.java:75)
at at ch.qos.logback.classic.util.ContextInitializer.autoConfig(ContextInitializer.java:148)
at at org.slf4j.impl.StaticLoggerBinder.init(StaticLoggerBinder.java:85)
at at org.slf4j.impl.StaticLoggerBinder.<clinit>(StaticLoggerBinder.java:55)
at at org.slf4j.LoggerFactory.bind(LoggerFactory.java:128)
at at org.slf4j.LoggerFactory.performInitialization(LoggerFactory.java:107)
at at org.slf4j.LoggerFactory.getILoggerFactory(LoggerFactory.java:295)
at at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:269)
at at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:281)
...
Changing the logback.properties to following resolves the problem
LOG_PATH=${logfilepath.default:-logs}/${APP_NAME}
ARCHIVE_PATH=${logfilepath.default:-logs}/archive/${APP_NAME}
Unfortunately we can not release that to customers for reasons which are beyond this issue. Old version of logback does not roll files which do not get written every day so we need to upgrade...