April 2011 - logback-dev - mailman3.qos.ch

[JIRA] Created: (LBCLASSIC-217) Exception stack trace printing starting from root cause
by Tomasz Nurkiewicz (JIRA) 24 Sep '11

24 Sep '11

Exception stack trace printing starting from root cause ------------------------------------------------------- Key: LBCLASSIC-217 URL: http://jira.qos.ch/browse/LBCLASSIC-217 Project: logback-classic Issue Type: New Feature Affects Versions: 0.9.22 Reporter: Tomasz Nurkiewicz Assignee: Logback dev list A typical exception in multi-tier application looks similar to this: com.acme.BusinessException: Can't process request at ... at ... Caused by: com.acme.dao.PersistenceException: Can't access database at ... at ... ... 49 common frames omitted Caused by: org.springframework.jdbc.datasource.lookup.DataSourceLookupFailureException: Unable to locate datasource at ... at ... ... 65 common frames omitted Caused by: java.net.UnknownHostException: Unknown host localhostt at ... at ... ... 84 common frames omitted The deeper exception, the more specific information it gives. Typically the last "Caused by" is the most interesting one. So it seems like reversing the order in which the exceptions are thrown (from most specific to consecutive, less specific wrappers) might be more intuitive: java.net.UnknownHostException: Unknown host localhostt at ... at ... Wrapped by: org.springframework.jdbc.datasource.lookup.DataSourceLookupFailureException: Unable to connect to the database at ... at ... Wrapped by: com.acme.dao.PersistenceException: Can't access database at ... at ... Wrapped by: com.acme.BusinessException: Can't process request at ... at ... It is not only easier to read and follow (business exception is interesting for the end user while the most precise, technical information is for developers and system administrators - so it should be easily accessible in the logs), but also the stack trace isn't mixed. You can read stack frames in exactly the same order as they were executed, no need to jump from one stack trace line to another (see attachment from the real application). This also means that the beginning of the thread is always at the bottom and the line that caused the very first exception - at the top. (look at the attached real exception) I already implemented this feature by adding RootCauseFirstThrowableProxyConverter extending ch.qos.logback.classic.pattern.ExtendedThrowableProxyConverter. It is turned on by appending "%rEx" to the encoder pattern. If you like this feature, I will push the changes (just few classes have changed) into my GitHub fork. -- 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 8

[JIRA] Created: (LBCLASSIC-263) Logback Classic causes SecurityException
by NC (JIRA) 11 Sep '11

11 Sep '11

Logback Classic causes SecurityException ---------------------------------------- Key: LBCLASSIC-263 URL: http://jira.qos.ch/browse/LBCLASSIC-263 Project: logback-classic Issue Type: Bug Affects Versions: 0.9.28 Reporter: NC Assignee: Logback dev list PackagingDataCalculator invokes Class.getClassLoader(). This method throws a SecurityException when running under a security manager and that manager denies access to the ClassLoader. I'm submitting a PackagingDataCalculator patch which wraps the getClassLoader() invocation in a doPrivileged block. This allows these calls to succeed when the getClassLoader RuntimePermission is granted to logback-classic. -- 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 8

[JIRA] Created: (LBCORE-79) FixedWindowRollingPolicy performs compression on the logging thread
by Szel Zoltan (JIRA) 02 Sep '11

02 Sep '11

FixedWindowRollingPolicy performs compression on the logging thread ------------------------------------------------------------------- Key: LBCORE-79 URL: http://jira.qos.ch/browse/LBCORE-79 Project: logback-core Issue Type: Improvement Components: Rolling Affects Versions: 0.9.13 Reporter: Szel Zoltan Assignee: Logback dev list Hi, the FixedWindowRollingPolicy performs the compression on the logging thread which can bring the application to halt, when compressing large files. Please consider modifing the FixedWindowRollingPolicy to perform the operation on a background thread as requested in LBCORE-48. Regards, Zoltan Szel -- 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: (LBCORE-179) conversion word %ex length handling is off by one
by Michael Osipov (JIRA) 26 Aug '11

26 Aug '11

conversion word %ex length handling is off by one ------------------------------------------------- Key: LBCORE-179 URL: http://jira.qos.ch/browse/LBCORE-179 Project: logback-core Issue Type: Bug Components: Pattern Affects Versions: 0.9.26 Reporter: Michael Osipov Assignee: Logback dev list The %ex and %xEx define a stack trace length. The integer spec is somewhat faulty and misleading. First of all this is a stack trace depth imho and not length. Anyway, I was poking around with the SMTPAppender and wanted to include the sole exception message into the subject. The outcome was: 1. The docs do not define a valid interval for the integer value. You can only deduce from logic. 2. I defined %ex{short} and it included 2 lines of the stack trace. 3. I defined %ex{2} and it included 3 lines of the stack trace. 4. I defined %ex{0} and it included 1 line of the stack trace. 5. Defining any negative number omits the stack trace. But it does not make sense at all to have a negative stack trace depth. I checked also the source of the [https://github.com/ceki/logback/blob/master/logback-classic/src/main/java/c… converter], the lines 54 and 58 cause the problem. -- 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 3

[JIRA] Created: (LBGENERAL-35) TimeBasedRollingWithArchiveRemovalTest failed
by Ralph Goers (JIRA) 25 Aug '11

25 Aug '11

TimeBasedRollingWithArchiveRemovalTest failed --------------------------------------------- Key: LBGENERAL-35 URL: http://jira.qos.ch/browse/LBGENERAL-35 Project: logback-general Issue Type: Sub-task Affects Versions: 0.9.17 Environment: Mac OSX Reporter: Ralph Goers Assignee: Logback dev list This is not a frequent occurence. ------------------------------------------------------------------------------- Test set: ch.qos.logback.core.rolling.TimeBasedRollingWithArchiveRemovalTest ------------------------------------------------------------------------------- Tests run: 6, Failures: 0, Errors: 1, Skipped: 0, Time elapsed: 1.411 sec <<< FAILURE! montlyRollover(ch.qos.logback.core.rolling.TimeBasedRollingWithArchiveRemovalTest) Time elapsed: 0.114 sec montlyRolloverOverManyPeriods(ch.qos.logback.core.rolling.TimeBasedRollingWithArchiveRemovalTest) Time elapsed: 0.253 sec dailyRollover(ch.qos.logback.core.rolling.TimeBasedRollingWithArchiveRemovalTest) Time elapsed: 0.058 sec dailyCronologRollover(ch.qos.logback.core.rolling.TimeBasedRollingWithArchiveRemovalTest) Time elapsed: 0.108 sec dailySizeBasedRollover(ch.qos.logback.core.rolling.TimeBasedRollingWithArchiveRemovalTest) Time elapsed: 0.454 sec dailyChronologSizeBasedRollover(ch.qos.logback.core.rolling.TimeBasedRollingWithArchiveRemovalTest) Time elapsed: 0.417 sec <<< ERROR! java.util.concurrent.TimeoutException at java.util.concurrent.FutureTask$Sync.innerGet(FutureTask.java:228) at java.util.concurrent.FutureTask.get(FutureTask.java:91) at ch.qos.logback.core.rolling.TimeBasedRollingWithArchiveRemovalTest.doRollover(TimeBasedRollingWithArchiveRemovalTest.java:194) at ch.qos.logback.core.rolling.TimeBasedRollingWithArchiveRemovalTest.dailyChronologSizeBasedRollover(TimeBasedRollingWithArchiveRemovalTest.java:157) 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.internal.runners.TestMethod.invoke(TestMethod.java:59) at org.junit.internal.runners.MethodRoadie.runTestMethod(MethodRoadie.java:98) at org.junit.internal.runners.MethodRoadie$2.run(MethodRoadie.java:79) at org.junit.internal.runners.MethodRoadie.runBeforesThenTestThenAfters(MethodRoadie.java:87) at org.junit.internal.runners.MethodRoadie.runTest(MethodRoadie.java:77) at org.junit.internal.runners.MethodRoadie.run(MethodRoadie.java:42) at org.junit.internal.runners.JUnit4ClassRunner.invokeTestMethod(JUnit4ClassRunner.java:88) at org.junit.internal.runners.JUnit4ClassRunner.runMethods(JUnit4ClassRunner.java:51) at org.junit.internal.runners.JUnit4ClassRunner$1.run(JUnit4ClassRunner.java:44) at org.junit.internal.runners.ClassRoadie.runUnprotected(ClassRoadie.java:27) at org.junit.internal.runners.ClassRoadie.runProtected(ClassRoadie.java:37) at org.junit.internal.runners.JUnit4ClassRunner.run(JUnit4ClassRunner.java:42) at org.apache.maven.surefire.junit4.JUnit4TestSet.execute(JUnit4TestSet.java:62) at org.apache.maven.surefire.suite.AbstractDirectoryTestSuite.executeTestSet(AbstractDirectoryTestSuite.java:140) at org.apache.maven.surefire.suite.AbstractDirectoryTestSuite.execute(AbstractDirectoryTestSuite.java:127) at org.apache.maven.surefire.Surefire.run(Surefire.java:177) 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.apache.maven.surefire.booter.SurefireBooter.runSuitesInProcess(SurefireBooter.java:338) at org.apache.maven.surefire.booter.SurefireBooter.main(SurefireBooter.java:997) -- 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

5 7

[JIRA] Created: (LBCLASSIC-116) SyslogAppender should support RFC 5424
by Ralph Goers (JIRA) 16 Aug '11

16 Aug '11

SyslogAppender should support RFC 5424 -------------------------------------- Key: LBCLASSIC-116 URL: http://jira.qos.ch/browse/LBCLASSIC-116 Project: logback-classic Issue Type: Improvement Components: appender Affects Versions: 0.9.16 Environment: All Reporter: Ralph Goers Assignee: Logback dev list The SyslogAppender supports RFC 3164. RFC 5424 has been released with obsoletes RFC 3164. See http://www.ietf.org/rfc/rfc5424.txt. At the very least the format of the timestamp has been changed. Either the SyslogAppender should be enhanced to comply with RFC 5424 or a new SyslogAppender should be created which does. -- 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 19

[JIRA] Created: (LBCLASSIC-146) SysLog Appender and Line Breaks = :(
by Ingo Siebert (JIRA) 16 Aug '11

16 Aug '11

SysLog Appender and Line Breaks = :( -------------------------------------- Key: LBCLASSIC-146 URL: http://jira.qos.ch/browse/LBCLASSIC-146 Project: logback-classic Issue Type: Bug Components: appender Environment: Debian 4 Etch, 64 Bit (most likely all enviroments) Reporter: Ingo Siebert Assignee: Logback dev list I'm using the SysLog appender and it works well. But I've problems with line breaks, especially for exceptions. Every strack trace line is written as new SysLog-Entry. Example: Aug 11 20:25:21 192.168.33.11 app2-cas org.osgi.framework.BundleException: The bundle class path entry "patch.jar"..." Aug 11 20:25:21 192.168.33.11 app2-cas ^Iat org.eclipse.osgi.baseadaptor.loader.ClasspathManager.findClassPathEntry(ClasspathManager.java:168) Aug 11 20:25:21 192.168.33.11 app2-cas ^Iat org.eclipse.osgi.baseadaptor.loader.ClasspathManager.buildClasspath(ClasspathManager.java:145) Aug 11 20:25:21 192.168.33.11 app2-cas ^Iat org.eclipse.osgi.baseadaptor.loader.ClasspathManager.initialize(ClasspathManager.java:79) ... That's quire annoying if you want to filter or highlight entries. I think it's major, because there isn't a good workaround to filter/highlight syslog files. I'm using Logback 0.9.13, but I thinks it still exists in the trunk. -- 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-247) ConfigurationWatchList produces a warinig a correct configuration
by Michael Franz (JIRA) 16 Jun '11

16 Jun '11

ConfigurationWatchList produces a warinig a correct configuration ----------------------------------------------------------------- Key: LBCLASSIC-247 URL: http://jira.qos.ch/browse/LBCLASSIC-247 Project: logback-classic Issue Type: Bug Components: joran Affects Versions: 0.9.28 Reporter: Michael Franz Assignee: Logback dev list I get the following warning for included files: 12:09:40,657 |-WARN in ch.qos.logback.core.joran.util.ConfigurationWatchListUtil@7c959fa1 - Null ConfigurationWatchList. Cannot add file:/D:/dev/.../logback-lilith.xml Scanning is off. I configure logback in the following way: JoranConfigurator configurator = new JoranConfigurator(); configurator.setContext(loggerContext); loggerContext.reset(); configurator.doConfigure(new ByteArrayInputStream(config.getBytes("UTF-8"))); The generated main configuration (variable config) contains mainly includes to files within the file system. -- 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 8

[JIRA] Created: (LBCORE-199) RollingFileAppender with zip & %i doesn't rename active log file before being zipped
by Deepak Vadgama (JIRA) 25 May '11

25 May '11

RollingFileAppender with zip & %i doesn't rename active log file before being zipped ------------------------------------------------------------------------------------ Key: LBCORE-199 URL: http://jira.qos.ch/browse/LBCORE-199 Project: logback-core Issue Type: Bug Components: Rolling Affects Versions: 0.9.28 Reporter: Deepak Vadgama Assignee: Logback dev list http://old.nabble.com/RollingFileAppender-with-compress----i-td31037552.html When compression is used for FixedWindowRollingPolicy, with %i in the file name pattern, the log files are not renamed with %i before compression. Resulting zip-files are created with appropriate rolled over names (%i). But all the log files inside those zip have a same name. Configuration (non relevant elements removed before posting) <appender name="FILE" class="ch.qos.logback.core.rolling.RollingFileAppender"> <File>logs/gateway.log</File> <rollingPolicy class="ch.qos.logback.core.rolling.FixedWindowRollingPolicy"> <maxIndex>20</maxIndex> <FileNamePattern>logs/gateway.log.%i.zip</FileNamePattern> </rollingPolicy> </appender> Results gateway.log.1.zip (with log file gateway.log.1) gateway.log.2.zip (with log file gateway.log.1) gateway.log.3.zip (with log file gateway.log.1) ... Should have been gateway.log.1.zip (with log file gateway.log.1) gateway.log.2.zip (with log file gateway.log.2) gateway.log.3.zip (with log file gateway.log.3) .... -- 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 5

[JIRA] Created: (LBCLASSIC-82) Allow an Appender to be added to a Logger with a Level for more fine grained control of logging output
by Robert Elliot (JIRA) 20 May '11

20 May '11

Allow an Appender to be added to a Logger with a Level for more fine grained control of logging output ------------------------------------------------------------------------------------------------------ Key: LBCLASSIC-82 URL: http://jira.qos.ch/browse/LBCLASSIC-82 Project: logback-classic Issue Type: New Feature Components: appender, joran Environment: N/A Reporter: Robert Elliot Assignee: Logback dev list Priority: Minor Here's my use case: I have an appender, standard.log, whose job is to log major system events such as startup and shutdown, and all problems. I have configured my logger levels very carefully to ensure I get exactly the output I want - in some cases suppressing WARN messages that I know are not a problem by setting the level to ERROR, in some cases allowing INFO messages that let me see important lifecycle events. A simplified example might look like this: root=WARN,standard.log x.y=INFO a=ERROR I have a problem in a couple of parts of the system which means I want to turn on debug logging for that part of the system. I want the output of this to go to a separate appender - debug.log. So now my config looks like this: root=WARN,standard.log x.y=INFO x.y.z=DEBUG,debug.log a=ERROR a.b=DEBUG,debug.log But now I have an issue; all my debug statements are going to standard.log. It is being polluted with a load of information I don't want in it. I have several options: 1) Set additivity to false on x.y.z and a.b. But then any ERROR messages in a.b or INFO or above messages in x.y.z no longer get to standard.log, so this won't do 2) Add a filter of INFO or greater to the standard.log appender But then any INFO and WARN messages in a.b will get to standard.log - and I only want ERROR messages from a and its descendants in there 3) Add a filter of WARN or greater to the standard.log appender Now I still get the WARN messages from a.b that I don't want - and I've lost the INFO messages from x.y that I do want 4) Create two new appenders, standard.log2 for a and standard.log3 for x.y.z. Add a filter to standard.log2 so that it only accepts ERROR. Add a filter to standard.log3 so it only accepts INFO or above. Set additivity to false on a and x.y.z. That works. But it's a huge amount of added configuration, and that would rapidly multiply in a real world setting. 5) Create a custom filter for standard.log which would effectively mirror the logger config by querying the event for its logger and and level. That blows DRY out of the water, of course, and again is a large amount of work for a simple use case. My suggestion to make this easy is to allow Appenders to be added to a Logger with a Level. This solution would operate in parallel with the existing solution, and would not alter the existing behaviour one iota. This would allow me to add debug,log as an appender on a and x.y.z with a level of debug. All debug statements in a and x.y.z & their descendants would be appended to that appender. All statements would also be passed to the "normal" appender and logger hierarchy, so standard.log would still get the same output as before. I have written unit tests for this behaviour and attach a patch fulfilling them; I hope the unit tests flesh out any queries you may have around how this behaves in edge cases. The only change to the public API is a new method addAppender(Appender<LoggingEvent> newAppender, Level level) on Logger. The only change to the config format is allowing an optional level attribute on appender-ref. -- 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 6