February 2012 - logback-dev

[JIRA] Created: (LBCORE-243) Return ImmediateFlush and perhaps buffering options to FileAppender
by Petr H (JIRA) 03 May '12

03 May '12

Return ImmediateFlush and perhaps buffering options to FileAppender ------------------------------------------------------------------- Key: LBCORE-243 URL: http://jira.qos.ch/browse/LBCORE-243 Project: logback-core Issue Type: Improvement Components: Appender Affects Versions: 1.0.0 Reporter: Petr H Assignee: Logback dev list Based on the "log4j performance comparison" discussion in the logback-user mailing list: http://old.nabble.com/log4j-performance-comparison-td31183677.html I'd like to see at least the ImmediateFlush option back as it causes really big difference in writing performance at our systems with heavy logging activity. Last logback release with ImmediateFlush option is 0.9.18 and this is the one we have to stay at due to performance reasons. We can't afford to upgrade to later logback release or switch ImmediateFlush to true as it makes some of our systems practically unusable. The best option seems to be the use of FileWriter with the possibility to set the ImmediateFlush option and also buffering (wrapping with BufferedWriter and use of BufferedIO + BufferSize options) can help a little. -- 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

2 2

[JIRA] Created: (LBCLASSIC-234) CLONE -Excessive synchronization in ReconfigureOnChangeFilter.decide
by uri unger (JIRA) 25 Apr '12

25 Apr '12

CLONE -Excessive synchronization in ReconfigureOnChangeFilter.decide -------------------------------------------------------------------- Key: LBCLASSIC-234 URL: http://jira.qos.ch/browse/LBCLASSIC-234 Project: logback-classic Issue Type: Bug Affects Versions: 0.917 Reporter: uri unger Assignee: Ceki Gulcu The synchronization in ReconfigureOnChangeFilter.decide hurts scalability. It seems unnecessary to serialize the code in changeDetected -- it should be possible to use atomic updates of nextCheck and lastModified and only serialize the actual reconfiguration. -- 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

6 18

[JIRA] Created: (LBCORE-221) Error in FileNamePattern::toRegex for index (Integer)
by Dieter Mueller (JIRA) 25 Apr '12

25 Apr '12

Error in FileNamePattern::toRegex for index (Integer) ----------------------------------------------------- Key: LBCORE-221 URL: http://jira.qos.ch/browse/LBCORE-221 Project: logback-core Issue Type: Bug Components: Pattern, Rolling Affects Versions: 0.9.29 Reporter: Dieter Mueller Assignee: Logback dev list Priority: Minor Deletion of old archived logs on rolling failes for index > 99. We have a process which logs much, which results in more than 99 log files per day (config below), e.g. snowball_POLL_MSG_SRV_xdebug-old-2011-09-13.110.log.zip. On rolling event, only the first 99 were deleted, due to bug in FileNamePattern::toRegex for index (Integer): regEx: \d{1,2) which means digits with max length of 2. We need at least 3 digits: regEx: \d{1,3) better 4? ;-) Workarounds like increasing file size, or hourly-rollover to hold index lower than 100 are not very wellcomed. Thanks in advance, Dieter Mueller. config: <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">  <fileNamePattern>${log.vm.file.prefix}_xdebug-old-%d{yyyy-MM-dd}.%i.log.zip</fileNamePattern> <maxHistory>1</maxHistory> <timeBasedFileNamingAndTriggeringPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP"> <maxFileSize>20MB</maxFileSize> </timeBasedFileNamingAndTriggeringPolicy> </rollingPolicy> -- 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

3 2

[JIRA] Created: (LBCORE-169) RollingFileAppender/TimeBasedRollingPolicy failing to ZIP files in different directory
by Tomasz Nurkiewicz (JIRA) 24 Apr '12

24 Apr '12

RollingFileAppender/TimeBasedRollingPolicy failing to ZIP files in different directory -------------------------------------------------------------------------------------- Key: LBCORE-169 URL: http://jira.qos.ch/browse/LBCORE-169 Project: logback-core Issue Type: Bug Components: Rolling Affects Versions: 0.9.24 Reporter: Tomasz Nurkiewicz Assignee: Logback dev list When using ZIP feature to compress old log files, Logback does not allow to put ZIP files in different directory like in this example: <file>logs\server.log</file> <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy"> <fileNamePattern>logs\arch\server.%d{yyyy-MM-dd_HHmm}.log.zip</fileNamePattern> </rollingPolicy> Running the attached test maven project (it takes 1 minute to run) will create server.log3560979839057.tmp (or similar) temporary file instead of ZIP file in /arch subdirectory (preferably this directory should be created if not exists). If fileNamePattern in rollingPolicy is changed to: "logs\server.%d{yyyy-MM-dd_HHmm}.log.zip" everything works as expected. The root of this issue is to be able to automatically ZIP files AND archive them in different directory. It would be great to be able to use date placeholders in folder names, for instance: <fileNamePattern>logs\arch-%d{yyyy-MM}\server.%d{yyyy-MM-dd_HHmm}.log.zip</fileNamePattern> so that Logback would automatically create folders for each month with ZIPped files. -- 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

8 9

[JIRA] Created: (LBCORE-84) Typo in PropertyAction
by Michael Franz (JIRA) 24 Apr '12

24 Apr '12

Typo in PropertyAction ---------------------- Key: LBCORE-84 URL: http://jira.qos.ch/browse/LBCORE-84 Project: logback-core Issue Type: Bug Components: Joran Affects Versions: 0.9.14 Reporter: Michael Franz Assignee: Logback dev list Priority: Trivial The following message is printed |-WARN in ch.qos.logback.core.joran.action.PropertyAction - [substitutionProperty] element has been deprecated. Plase use the [property] element instead. There an 'e' missing in "Please". -- 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

2 2

[JIRA] Created: (LBCLASSIC-309) Groovy-config fails without outside code noticing
by Endre Stølsvik (JIRA) 10 Apr '12

10 Apr '12

Groovy-config fails without outside code noticing ------------------------------------------------- Key: LBCLASSIC-309 URL: http://jira.qos.ch/browse/LBCLASSIC-309 Project: logback-classic Issue Type: Bug Components: joran Affects Versions: unspecified Environment: na Reporter: Endre Stølsvik Assignee: Logback dev list Priority: Minor [As reported on the user-list, where I was requested to make a bug report] This groovy-file ...: import ch.qos.logback.classic.PatternLayout import ch.qos.logback.core.ConsoleAppender import ch.qos.logback.core.encoder.LayoutWrappingEncoder appender("STDOUT", ConsoleAppender) { encoder(LayoutWrappingEncoder) { layout(PatternLayout) { pattern = "%d{HH:mm:ss.SSS} [%thread] %-5level %logger{55}.%M.%L - %msg%n" } } } root(ALL, ["STDOUT"]) ... apparently crashes the configuration as such: Failed to instantiate [ch.qos.logback.classic.LoggerContext] Reported exception: groovy.lang.MissingPropertyException: No such property: ALL for class: Script1 at org.codehaus.groovy.runtime.ScriptBytecodeAdapter.unwrap(ScriptBytecodeAdapter.java:50) at org.codehaus.groovy.runtime.callsite.PogoGetPropertySite.getProperty(PogoGetPropertySite.java:49) at org.codehaus.groovy.runtime.callsite.AbstractCallSite.callGroovyObjectGetProperty(AbstractCallSite.java:231) at Script1.run(Script1.groovy:13) at Script1$run.call(Unknown Source) at org.codehaus.groovy.runtime.callsite.CallSiteArray.defaultCall(CallSiteArray.java:42) at org.codehaus.groovy.runtime.callsite.AbstractCallSite.call(AbstractCallSite.java:108) at org.codehaus.groovy.runtime.callsite.AbstractCallSite.call(AbstractCallSite.java:112) at ch.qos.logback.classic.gaffer.GafferConfigurator.run(GafferConfigurator.groovy:59) at ch.qos.logback.classic.gaffer.GafferConfigurator$run.callCurrent(Unknown Source) at org.codehaus.groovy.runtime.callsite.CallSiteArray.defaultCallCurrent(CallSiteArray.java:46) at org.codehaus.groovy.runtime.callsite.AbstractCallSite.callCurrent(AbstractCallSite.java:133) at org.codehaus.groovy.runtime.callsite.AbstractCallSite.callCurrent(AbstractCallSite.java:141) at ch.qos.logback.classic.gaffer.GafferConfigurator.run(GafferConfigurator.groovy:37) at ch.qos.logback.classic.gaffer.GafferUtil.runGafferConfiguratorOn(GafferUtil.java:44) at ch.qos.logback.classic.util.ContextInitializer.configureByResource(ContextInitializer.java:67) at ch.qos.logback.classic.util.ContextInitializer.autoConfig(ContextInitializer.java:150) at org.slf4j.impl.StaticLoggerBinder.init(StaticLoggerBinder.java:85) at org.slf4j.impl.StaticLoggerBinder.<clinit>(StaticLoggerBinder.java:55) at org.slf4j.LoggerFactory.bind(LoggerFactory.java:128) at org.slf4j.LoggerFactory.performInitialization(LoggerFactory.java:108) at org.slf4j.LoggerFactory.getILoggerFactory(LoggerFactory.java:279) at XYZ.doLogConfig(XYZ.java:40) at XYZ.main(XYZ:169) The problem is obviously, as the error message states, the not-defined property "ALL". *The problem I am reporting is that this isn't caught*. The console-dump happens in the "We should never get here" catch block below: void init() { try { try { new ContextInitializer(defaultLoggerContext).autoConfig(); } catch (JoranException je) { Util.report("Failed to auto configure default logger context", je); } StatusPrinter.printInCaseOfErrorsOrWarnings(defaultLoggerContext); contextSelectorBinder.init(defaultLoggerContext, KEY); initialized = true; } catch (Throwable t) { // we should never get here Util.report("Failed to instantiate [" + LoggerContext.class.getName() + "]", t); } } Notice that the StatusManager does not know that the config failed: 13:32:07,643 |-INFO in ch.qos.logback.classic.LoggerContext[Emma logcontext] - Found resource [logback.groovy] at [file:/XYZ/target/classes/logback.groovy] 13:32:08,807 |-INFO in ch.qos.logback.classic.gaffer.ConfigurationDelegate@2111e072 - About to instantiate appender of type [ch.qos.logback.core.ConsoleAppender] 13:32:08,809 |-INFO in ch.qos.logback.classic.gaffer.ConfigurationDelegate@2111e072 - Naming appender as [STDOUT] -- 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

1 1

[JIRA] Created: (LBCLASSIC-157) Add option to include caller data in JMS Appender or to disable caller data in DB Appender
by Ging Ming Chan (JIRA) 22 Mar '12

22 Mar '12

Add option to include caller data in JMS Appender or to disable caller data in DB Appender ------------------------------------------------------------------------------------------ Key: LBCLASSIC-157 URL: http://jira.qos.ch/browse/LBCLASSIC-157 Project: logback-classic Issue Type: New Feature Components: appender Affects Versions: 0.917 Reporter: Ging Ming Chan Assignee: Logback dev list Priority: Minor We are using the JMSQueueAppender remotely with a centralised server that uses the DBAppender to log to the database. However, since the JMSQueueAppender does not send the caller data, and the DBAppender always expect it, the operation never succeeded. There are two options to fix this, either add the includeCallerData option in the JMS Appender or to exclude caller data in the DB Appender. -- 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

4 4

[JIRA] Created: (LBCLASSIC-320) Allow logger pattern filter to collapse x levels of package name
by Antony Stubbs (JIRA) 08 Mar '12

08 Mar '12

Allow logger pattern filter to collapse x levels of package name ---------------------------------------------------------------- Key: LBCLASSIC-320 URL: http://jira.qos.ch/browse/LBCLASSIC-320 Project: logback-classic Issue Type: Improvement Components: layout Affects Versions: 1.0.0 Reporter: Antony Stubbs Assignee: Logback dev list It would be great, instead of only working on a character level, to be able to work at a package level. I.e. logger{p3} would convert org.apache.solr.handlers.dataimporthandler to o.a.s.handlers.dataimporthandler -- 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

2 1

[JIRA] Created: (LBCLASSIC-312) SiftingAppender does not substitute variable value inside sift
by Dmitrius Listo (JIRA) 08 Mar '12

08 Mar '12

SiftingAppender does not substitute variable value inside sift -------------------------------------------------------------- Key: LBCLASSIC-312 URL: http://jira.qos.ch/browse/LBCLASSIC-312 Project: logback-classic Issue Type: Bug Components: appender Affects Versions: 1.0.0 Environment: Ubuntu 11.04, Eclipse 3.7 Reporter: Dmitrius Listo Assignee: Logback dev list Faced a probable bug (at least, did not find any mention about such issue at manual/google/other bugs in category). Brief logging configuration description: I have a property defined in my logback configuration. There is a property with log file location defined: <property name="LOG_HOME" value="/tmp/aicore" /> Also, I have ConsoleAppender and two RollingFileAppender appenders, attached to root logger. RollingFileAppender configuration contains LOG_HOME variable in path and substitution is done without any issues, log file is created and updated. But when I add SiftingAppender (log files are created on per-threadId basis), that contains FileAppender in it's sift section, variable value is not substituted. Here is the logback log fragment, generated using OnConsoleStatusListener: 22:11:27,396 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.FileAppender] 22:11:27,396 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [FILE-server] 22:11:27,398 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder] property 22:11:27,400 |-INFO in ch.qos.logback.core.FileAppender[FILE-server] - File property is set to [LOG_HOME_IS_UNDEFINED/thread-server.log] Note the "LOG_HOME_IS_UNDEFINED/thread-server.log" value. As a result, no any sift log file is created in expected location. When I substitute ${LOG_HOME} value manually, everything works well. Below is my SiftingAppender config: <appender name="SIFT" class="ch.qos.logback.classic.sift.SiftingAppender"> <discriminator class="ch.qos.logback.classic.sift.MDCBasedDiscriminator"> <key>threadId</key> <defaultValue>unclassified</defaultValue> </discriminator> <sift> <appender name="FILE-${threadId}" class="ch.qos.logback.core.FileAppender"> <file>${LOG_HOME}/thread-${threadId}.log</file> <append>false</append> <encoder> <pattern>%d [%thread] %level %mdc %logger{35} - %msg%n</pattern> </encoder> </appender> </sift> </appender> Sorry if bug report is not formed perfectly, I have not much expertise yet :) -- 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

2 5

TimeBasedFileNamingAndTriggeringPolicyBaseTest fails
by Ralph Goers 06 Mar '12

06 Mar '12

I just got a new Mac at work and at home. The Logback build is failing on both. I have no idea if the error is due to the upgrade or not. ------------------------------------------------------------------------------- Test set: ch.qos.logback.core.rolling.TimeBasedFileNamingAndTriggeringPolicyBaseTest ------------------------------------------------------------------------------- Tests run: 2, Failures: 1, Errors: 0, Skipped: 0, Time elapsed: 1,133,311.978 sec <<< FAILURE! singleDate(ch.qos.logback.core.rolling.TimeBasedFileNamingAndTriggeringPolicyBaseTest) Time elapsed: 0 secmultiDate(ch.qos.logback.core.rolling.TimeBasedFileNamingAndTriggeringPolicyBaseTest) Time elapsed: 0.002 sec <<< FAILURE! java.lang.AssertionError: expected:<foo-2011-12/59.log> but was:<null> at org.junit.Assert.fail(Assert.java:93) at org.junit.Assert.failNotEquals(Assert.java:647) at org.junit.Assert.assertEquals(Assert.java:128) at org.junit.Assert.assertEquals(Assert.java:147) at ch.qos.logback.core.rolling.TimeBasedFileNamingAndTriggeringPolicyBaseTest.multiDate(TimeBasedFileNamingAndTriggeringPolicyBaseTest.java:65) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) at java.lang.reflect.Method.invoke(Method.java:597) at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:45) at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15) at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:42) at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:20) at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:28) at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:263) at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:68) at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:47) at org.junit.runners.ParentRunner$3.run(ParentRunner.java:231) at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:60) at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:229) at org.junit.runners.ParentRunner.access$000(ParentRunner.java:50) at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:222) at org.junit.runners.ParentRunner.run(ParentRunner.java:300) at org.junit.runners.Suite.runChild(Suite.java:128) at org.junit.runners.Suite.runChild(Suite.java:24) at org.junit.runners.ParentRunner$3.run(ParentRunner.java:231) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441) at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303) at java.util.concurrent.FutureTask.run(FutureTask.java:138) at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) at java.lang.Thread.run(Thread.java:680) ~

3 8