September 2010 - logback-dev

[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

[JIRA] Created: (LBCORE-168) Locking issues when prudent logging to a (windows) clustered storage device on owner-switch
by alex (JIRA) 08 Apr '11

08 Apr '11

Locking issues when prudent logging to a (windows) clustered storage device on owner-switch ------------------------------------------------------------------------------------------- Key: LBCORE-168 URL: http://jira.qos.ch/browse/LBCORE-168 Project: logback-core Issue Type: Bug Components: Appender Affects Versions: 0.9.24 Environment: Windows Server 2003 Enterprise edition Reporter: alex Assignee: Logback dev list Priority: Blocker We have a clustered windows environment (2 nodes) and each node is logging to the same file which is stored on a clustered storage device (prudent is set to true) Logging works great until we switch the owner of the storage device where the logs are being written to at which point one of two things happens: - one or both servers go into a sort of deadlock state, meaning the code that logs just hangs indefinatly. it seems the safeWrite() in FileAppender may be to blame because of the "lock()" statement (note that a jvm reboot will fix this problem). I have been able to reproduce this locked state and verify that it is the lock() by trying to get a lock on the log file in the same jvm but without using logback code. This code will hang as well. - if there is no deadlock, any log written after the switch will just vanish into thin air (I have no idea where the outputstream points to when you start switching the owner) I have no idea how this can be fixed without resorting to a reload/reboot of our servers (which is not an option in production). We used to log synchronously, but then each thread that called logback would hang resulting in a massive amount of idling threads, so now we log asynchronously (this was already an option in the system we built around it) which gives us one advantage: we never write concurrently to the same file, although different nodes may write serially. As a temporary work around I am thinking to implement a simple appender that opens/closes the outputstream for each write (performance is less of an issue) and that does not implement locking. -- 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 4

[JIRA] Created: (LBACCESS-12) Please add IAccessEvent (and AccessEventVO) similar to the LoggingEvent counterparts
by Joern Huxhorn (JIRA) 28 Mar '11

28 Mar '11

Please add IAccessEvent (and AccessEventVO) similar to the LoggingEvent counterparts ------------------------------------------------------------------------------------ Key: LBACCESS-12 URL: http://jira.qos.ch/browse/LBACCESS-12 Project: logback-access Issue Type: Improvement Affects Versions: 0.9.20 Reporter: Joern Huxhorn Assignee: Logback dev list I'm currently implementing "cat" functionality for Lilith data files, i.e. events stored in Lilith data files can be printed using ch.qos.logback.classic.PatternLayout and ch.qos.logback.access.PatternLayout. This works for LoggingEvent since I could implement a iLoggingEvent wrapper for my own LoggingEvent. It does not work for AccessEvent, though, because there is no IAccessEvent interface and I can't instantiate AccessEvent and set the properties manually. ch.qos.logback.access.PatternLayout is currently working on an AccessEvent and I'd like to use it's functionality. -- 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

[JIRA] Created: (LBCLASSIC-156) SocketAppender is reporting an WARN if connection could not be established.
by Joern Huxhorn (JIRA) 28 Mar '11

28 Mar '11

SocketAppender is reporting an WARN if connection could not be established. --------------------------------------------------------------------------- Key: LBCLASSIC-156 URL: http://jira.qos.ch/browse/LBCLASSIC-156 Project: logback-classic Issue Type: Improvement Components: appender Affects Versions: 0.917 Environment: java version "1.6.0_15" Java(TM) SE Runtime Environment (build 1.6.0_15-b03-226) Java HotSpot(TM) 64-Bit Server VM (build 14.1-b02-92, mixed mode) Reporter: Joern Huxhorn Assignee: Logback dev list This is a followup to LBCLASSIC-143 which changed the message from ERROR to WARN. The WARN message still results in a dump of the logging status messages. This means that a whole bunch of text is printed to the console whenever Lilith is started - and it looks quite broken due to the stacktrace. So there are two possible solutions for this problem: a) the status is only printed in case of an ERROR b) SocketAppender considers this as an INFO instead of a WARN. I think b) would be reasonable. Other WARNs are much more important, like duplicate logback.xml. Lilith is only an example, btw. We routinely add SocketAppender[localhost] to our console applications. In case of trouble one can simply start Lilith and check the logs that way instead of reading them on the console. The default use-case is executing the app without Lilith, though, so we get the logback status messages on every start - which is quite noisy and annoying. -- 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

[JIRA] Created: (LBCORE-166) RenameUtil not truncating file if delete fails during rollover
by Jose David Barrio (JIRA) 18 Mar '11

18 Mar '11

RenameUtil not truncating file if delete fails during rollover -------------------------------------------------------------- Key: LBCORE-166 URL: http://jira.qos.ch/browse/LBCORE-166 Project: logback-core Issue Type: Bug Components: Rolling Affects Versions: 0.9.24 Environment: Microsoft Windows XP SP2 OAS 10.1.3.4 Java 1.5.0_14 Reporter: Jose David Barrio Assignee: Logback dev list Priority: Minor Attachments: RenameUtil.patch When using logback under Windows over Oracle Application Server, if you redeploy the web application, the log file is keep open by some reason so when a new rollover happens it fails to rename the log file. Currently RenameUtil does: - Try to rename log file. - If rename fails then rename by copy (copy plus delete). If for some reason deletion fails the log file keeps all its content so I just added a truncate if deletion fails: - Try to rename log file. - If rename fails then rename by copy (copy plus delete). - If delete fails then truncate file. I do have a patch file if it's useful. -- 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 7

[JIRA] Created: (LBGENERAL-37) Need to scan included files
by lala (JIRA) 10 Feb '11

10 Feb '11

Need to scan included files --------------------------- Key: LBGENERAL-37 URL: http://jira.qos.ch/browse/LBGENERAL-37 Project: logback-general Issue Type: New Feature Reporter: lala Assignee: Logback dev list Priority: Minor I'm using the following configuration and I'm looking for a method to scan included files. <configuration scan="true" scanPeriod="10 seconds"> <insertFromJNDI env-entry-name="java:comp/env/logback-file" as="logback-file" /> <contextName>lala</contextName> <include file="${logback-file}" /> </configuration> Once scan directive is used, logback is going to rescan this file every 10 seconds whether its modification date has changed. The issue is that I have to overwrite the previous file in order to rescan the target ${logback-file}. I suggest adding an attribute in the configuration marker in order to force logback to scan included files . It could be something like that: <configuration scan="true" scanPeriod="10 seconds" scanIncluded="true"> ..... </configuration> In order to process this task, at each scan logback should memorize the reference to the included files, and their latest modification date. Consequently, every 10 seconds, logback check the whole list of files and rescan the main file if something has changed. -- 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 5

[JIRA] Created: (LBCORE-120) ArrayIndexOutOfBoundsException when using Oracle driver ojdbc6 with DBAppender
by Manuel Kueblboeck (JIRA) 09 Feb '11

09 Feb '11

ArrayIndexOutOfBoundsException when using Oracle driver ojdbc6 with DBAppender ------------------------------------------------------------------------------ Key: LBCORE-120 URL: http://jira.qos.ch/browse/LBCORE-120 Project: logback-core Issue Type: Bug Components: Appender Affects Versions: 0.9.17 Environment: Windows XP, Oracle Database 11g Release 11.1.0.0.0, jdk1.6.0_16 Reporter: Manuel Kueblboeck Assignee: Logback dev list Priority: Minor When using the Oracle driver ojdbc6 (11.1.0.7.0) an ArrayIndexOutOfBoundsException occurs when trying to write a log message to the database (see stacktrace below). I am using ch.qos.logback.core.db.DriverManagerConnectionSource in my logback.xml. When using ojdbc14 (10.2.0.4), this works fine. 07:31:43,997 |-ERROR in ch.qos.logback.classic.db.DBAppender[LogDB] - problem appending event java.lang.ArrayIndexOutOfBoundsException: 10 at java.lang.ArrayIndexOutOfBoundsException: 10 at at oracle.jdbc.driver.OracleSql.computeBasicInfo(OracleSql.java:950) at at oracle.jdbc.driver.OracleSql.getSqlKind(OracleSql.java:623) at at oracle.jdbc.driver.OraclePreparedStatement.<init>(OraclePreparedStatement.java:1212) at at oracle.jdbc.driver.T4CPreparedStatement.<init>(T4CPreparedStatement.java:28) at at oracle.jdbc.driver.T4CDriverExtension.allocatePreparedStatement(T4CDriverExtension.java:68) at at oracle.jdbc.driver.PhysicalConnection.prepareStatement(PhysicalConnection.java:3140) at at oracle.jdbc.driver.PhysicalConnection.prepareStatement(PhysicalConnection.java:3042) at at oracle.jdbc.driver.PhysicalConnection.prepareStatement(PhysicalConnection.java:6022) at at ch.qos.logback.core.db.DBAppenderBase.append(DBAppenderBase.java:90) at at ch.qos.logback.core.AppenderBase.doAppend(AppenderBase.java:87) at at ch.qos.logback.core.spi.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:60) at at ch.qos.logback.classic.Logger.appendLoopOnAppenders(Logger.java:271) at at ch.qos.logback.classic.Logger.callAppenders(Logger.java:258) at at ch.qos.logback.classic.Logger.buildLoggingEventAndAppend(Logger.java:440) at at ch.qos.logback.classic.Logger.filterAndLog_0_Or3Plus(Logger.java:394) at at ch.qos.logback.classic.Logger.debug(Logger.java:521) at at nz.co.integrationworks.reporting.AbstractReporter.log(AbstractReporter.java:37) at at nz.co.integrationworks.reporting.AbstractReporter.log(AbstractReporter.java:29) at at nz.co.integrationworks.reporting.BusinessLoggerManualTest.main(BusinessLoggerManualTest.java:28) -- 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 4

[JIRA] Created: (LBCLASSIC-183) Tomcat reports SEVERE ThreadLocal issues upon shutdown
by Anthony Whitford (JIRA) 01 Feb '11

01 Feb '11

Tomcat reports SEVERE ThreadLocal issues upon shutdown ------------------------------------------------------ Key: LBCLASSIC-183 URL: http://jira.qos.ch/browse/LBCLASSIC-183 Project: logback-classic Issue Type: Bug Affects Versions: 0.9.18 Environment: Tomcat 6.0.24, JDK 6, Windows or Solaris Reporter: Anthony Whitford Assignee: Logback dev list I have a webapp that uses Logback, deployed on a Tomcat instance. Upon shutdown, Tomcat reports this and doesn't completely shut down: SEVERE: A web application created a ThreadLocal with key of type [org.slf4j.impl.CopyOnInheritThreadLocal] (value [org.slf4j.impl.CopyOnInheritThreadLocal@1bb35 b]) and a value of type [null] (value [null]) but failed to remove it when the web application was stopped. To prevent a memory leak, the ThreadLocal has been forcibly removed. Feb 3, 2010 10:49:22 PM org.apache.catalina.loader.WebappClassLoader clearThreadLocalMap SEVERE: A web application created a ThreadLocal with key of type [null] (value [ch.qos.logback.core.UnsynchronizedAppenderBase$1@10e2558]) and a value of type [java.lang.Boolean] (value [false]) but failed to remove it when the web application was stopped. To prevent a memory leak, the ThreadLocal has been forcibly removed. Is LogBack leaking resources? -- 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

7 12

[JIRA] Created: (LBSITE-38) Reference the configuration chapter from onJoran and vice versa
by Ceki Gulcu (JIRA) 11 Jan '11

11 Jan '11

Reference the configuration chapter from onJoran and vice versa --------------------------------------------------------------- Key: LBSITE-38 URL: http://jira.qos.ch/browse/LBSITE-38 Project: logback-site Issue Type: Task Components: Documentation Reporter: Ceki Gulcu Assignee: Logback dev list The onJoran chapter provides low level details about joran and the configuration chapter shows usage of joran. each chapter should reference the other for completeness. -- 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: (LBCORE-160) TimeBasedRollingWithArchiveRemovalTest keeps failing
by Joern Huxhorn (JIRA) 29 Dec '10

29 Dec '10

TimeBasedRollingWithArchiveRemovalTest keeps failing ---------------------------------------------------- Key: LBCORE-160 URL: http://jira.qos.ch/browse/LBCORE-160 Project: logback-core Issue Type: Bug Components: Appender Affects Versions: unspecified Environment: Apache Maven 2.2.1 (r801777; 2009-08-06 21:16:01+0200) Java version: 1.6.0_20 Java home: /System/Library/Frameworks/JavaVM.framework/Versions/1.6.0/Home Default locale: en_US, platform encoding: MacRoman OS name: "mac os x" version: "10.6.4" arch: "x86_64" Family: "mac" Reporter: Joern Huxhorn Assignee: Logback dev list Revision: 15b5239b5d583a86877b79e77336729317cf2dc0 The following error happens every time I try to build Logback: dailySizeBasedRollover(ch.qos.logback.core.rolling.TimeBasedRollingWithArchiveRemovalTest) Time elapsed: 0.443 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.waitForCompression(TimeBasedRollingWithArchiveRemovalTest.java:216) at ch.qos.logback.core.rolling.TimeBasedRollingWithArchiveRemovalTest.doRollover(TimeBasedRollingWithArchiveRemovalTest.java:206) at ch.qos.logback.core.rolling.TimeBasedRollingWithArchiveRemovalTest.dailySizeBasedRollover(TimeBasedRollingWithArchiveRemovalTest.java:146) 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:44) at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15) at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:41) 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.internal.runners.statements.RunAfters.evaluate(RunAfters.java:31) at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:76) at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:50) at org.junit.runners.ParentRunner$3.run(ParentRunner.java:193) at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:52) at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:191) at org.junit.runners.ParentRunner.access$000(ParentRunner.java:42) at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:184) at org.junit.runners.ParentRunner.run(ParentRunner.java:236) 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:345) at org.apache.maven.surefire.booter.SurefireBooter.main(SurefireBooter.java:1009) -- 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