September 2011 - logback-dev

[JIRA] Created: (LBCORE-220) DBAppender.java performance improvement
by Greg Thomas (JIRA) 28 Oct '11

28 Oct '11

DBAppender.java performance improvement --------------------------------------- Key: LBCORE-220 URL: http://jira.qos.ch/browse/LBCORE-220 Project: logback-core Issue Type: Bug Components: Other Affects Versions: 0.9.29 Reporter: Greg Thomas Assignee: Logback dev list We're seeing a distinct lack of performance with the DBAppender. Although it works fine in a single threaded environment, in a multi-threaded environment it slows down considerably. We've done some investigation, and narrowed it down to the pair of synchronized calls to subAppend() and selectEventId() (lines 107->110). I've had a look at this, and can see no reason for these to be synchronized; If using the JDBC3 getGeneratedKeys() method then as this applies to the thread specific statement there is no need to be synchronized. All the "Dialect" based calls are also connection specific; in detail; H2, HSQLDB and MySQL all call a database function, which is connection specific. MsSQL and Sybase both select a connection specific variable. Oracle and PostgreSQL both select the currval from a sequence, which again is connection specific. Having removed the synchronisation, we're seeing vastly improved logging throughput in our application. So to summarise; there is unnecessary synchronisation in the DBAppender that slows down multi-threaded applications; removing that synchronisation will improve performance in multi-threaded applications with no side affects. -- 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: (LBCLASSIC-171) Exception data sometimes does not get logged when using warn(String, Throwable)
by Marshall Pierce (JIRA) 25 Oct '11

25 Oct '11

Exception data sometimes does not get logged when using warn(String, Throwable) ------------------------------------------------------------------------------- Key: LBCLASSIC-171 URL: http://jira.qos.ch/browse/LBCLASSIC-171 Project: logback-classic Issue Type: Bug Affects Versions: 0.917 Environment: Linux, sun jdk 1.6.0_07 Reporter: Marshall Pierce Assignee: Logback dev list Source: try { doStuff(); } catch (PhaseException e) { this.logger.warn("Phase failed:", e); this.logger.debug("Another log message"); ... Log contents: phase.StandardPhase - Phase failed: phase.StandardPhase - Another log message The strange thing is that this doesn't happen all the time or even most of the time. Almost always, the exception data does get logged. -- 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: (LBCLASSIC-131) Missing Import-Package declaration in logback-classic causes problem with RollingFileAppender
by Pavol Juhos (JIRA) 25 Oct '11

25 Oct '11

Missing Import-Package declaration in logback-classic causes problem with RollingFileAppender --------------------------------------------------------------------------------------------- Key: LBCLASSIC-131 URL: http://jira.qos.ch/browse/LBCLASSIC-131 Project: logback-classic Issue Type: Bug Affects Versions: 0.9.15 Environment: OSGi Service Platform Release 4 Reporter: Pavol Juhos Assignee: Logback dev list In OSGi environment logback-core will correctly try to use the class-loader of logback-classic bundle to load classes of the selected Appenders. This however means that logback-classic needs to have visibility to the requested Appender classes. Since RollingFileAppender is located in a separate package "ch.qos.logback.core.rolling" and not explicitly referenced from logback-classic code, the respective Import-Package declaration will not be generated automatically by the BND tool (embedded in maven-bundle-plugin). In order to avoid ClassNotFound exceptions when trying to use RollingFileAppender the appropriate Import-Package declarations have to be added explicitly to the configuration of maven-bundle-plugin in logback-classic POM. The current <Import-Package> settings in maven-bundle-plugin configuration: <Import-Package>sun.reflect;resolution:=optional, javax.jms;resolution:=optional, * </Import-Package> Suggested update: <Import-Package>sun.reflect;resolution:=optional, javax.jms;resolution:=optional, ch.qos.logback.core.rolling, ch.qos.logback.core.rolling.helper, * </Import-Package> Please consider also to implement the related issue LBCLASSIC-121 when fixing this defect. -- 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 6

[JIRA] Created: (LBCLASSIC-278) Give access to environment variables in configuration file
by Alexandre Garnier (JIRA) 17 Oct '11

17 Oct '11

Give access to environment variables in configuration file ---------------------------------------------------------- Key: LBCLASSIC-278 URL: http://jira.qos.ch/browse/LBCLASSIC-278 Project: logback-classic Issue Type: New Feature Reporter: Alexandre Garnier Assignee: Logback dev list It would be very nice to be able to access environment variables in configuration files. Maybe like in ant with <property environment="env"/> and then ${env.PATH} to access variable. In my use case, it's necessary to get the path to the property file to load... -- 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-296) Allow hook/override in PackagingDataCalculator
by Chris Dolan (JIRA) 15 Oct '11

15 Oct '11

Allow hook/override in PackagingDataCalculator ---------------------------------------------- Key: LBCLASSIC-296 URL: http://jira.qos.ch/browse/LBCLASSIC-296 Project: logback-classic Issue Type: New Feature Affects Versions: 0.9.29 Reporter: Chris Dolan Assignee: Logback dev list Priority: Minor I'm running Logback as my SLF4J implementation in an OSGi container (Karaf). I love the feature of ThrowableProxy that populates stacktraces with the jar/version. Under Karaf, unfortunately, that data is always wrong because Karaf processes the jars into its data/generated-bundles folder before loading. So, I forked PackagingDataCalculator in my own code to some class resolution logic (attached). That code is not important because it's too OSGi-specific for inclusion into Logback. But I'd like the ability to inject something like that calculation code into Logback so I don't have to fork PackagingDataCalculator any longer. -- 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-224) java.lang.IllegalMonitorStateException at ch.qos.logback.core.spi.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:68)
by César Álvarez Núñez (JIRA) 13 Oct '11

13 Oct '11

java.lang.IllegalMonitorStateException at ch.qos.logback.core.spi.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:68) ---------------------------------------------------------------------------------------------------------------------------------------------- Key: LBCORE-224 URL: http://jira.qos.ch/browse/LBCORE-224 Project: logback-core Issue Type: Bug Components: Appender Affects Versions: 0.9.30 Environment: W7 64 bits, JRE 6u26 64 bits. Reporter: César Álvarez Núñez Assignee: Logback dev list I'm trying (unsuccessfully for the time being) to create a test case that will reproduce it. It happens randomly with 0.9.30 when running a regression testing with TestNG + Zookeeper + Own code. Apparently it does not happen with 0.9.29. java.lang.IllegalMonitorStateException at java.util.concurrent.locks.ReentrantReadWriteLock$Sync.tryReleaseShared(Unknown Source) at java.util.concurrent.locks.AbstractQueuedSynchronizer.releaseShared(Unknown Source) at java.util.concurrent.locks.ReentrantReadWriteLock$ReadLock.unlock(Unknown Source) at ch.qos.logback.core.spi.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:68) at ch.qos.logback.classic.Logger.appendLoopOnAppenders(Logger.java:285) at ch.qos.logback.classic.Logger.callAppenders(Logger.java:272) at ch.qos.logback.classic.Logger.buildLoggingEventAndAppend(Logger.java:473) at ch.qos.logback.classic.Logger.filterAndLog_0_Or3Plus(Logger.java:427) at ch.qos.logback.classic.Logger.info(Logger.java:631) at org.apache.zookeeper.server.ZooKeeperServer.shutdown(ZooKeeperServer.java:420) at org.apache.zookeeper.server.quorum.Leader.shutdown(Leader.java:443) at org.apache.zookeeper.server.quorum.QuorumPeer.shutdown(QuorumPeer.java:766) at org.apache.zookeeper.test.QuorumUtil.shutdown(QuorumUtil.java:224) at org.apache.zookeeper.test.QuorumUtil.shutdownAll(QuorumUtil.java:211) at org.apache.zookeeper.test.QuorumUtil.tearDown(QuorumUtil.java:255) at eswf.zk2.agents.ZkEphemeralInfoPublisherTest.tearDown(ZkEphemeralInfoPublisherTest.java:55) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source) at java.lang.reflect.Method.invoke(Unknown Source) at org.testng.internal.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:80) at org.testng.internal.Invoker.invokeConfigurationMethod(Invoker.java:543) at org.testng.internal.Invoker.invokeConfigurations(Invoker.java:212) at org.testng.internal.Invoker.invokeMethod(Invoker.java:772) at org.testng.internal.Invoker.invokeTestMethod(Invoker.java:883) at org.testng.internal.Invoker.invokeTestMethods(Invoker.java:1208) at org.testng.internal.TestMethodWorker.invokeTestMethods(TestMethodWorker.java:127) at org.testng.internal.TestMethodWorker.run(TestMethodWorker.java:111) at org.testng.TestRunner.privateRun(TestRunner.java:753) at org.testng.TestRunner.run(TestRunner.java:613) at org.testng.SuiteRunner.runTest(SuiteRunner.java:335) at org.testng.SuiteRunner.runSequentially(SuiteRunner.java:330) at org.testng.SuiteRunner.privateRun(SuiteRunner.java:292) at org.testng.SuiteRunner.run(SuiteRunner.java:241) at org.testng.SuiteRunnerWorker.runSuite(SuiteRunnerWorker.java:52) at org.testng.SuiteRunnerWorker.run(SuiteRunnerWorker.java:86) at org.testng.TestNG.runSuitesSequentially(TestNG.java:1169) at org.testng.TestNG.runSuitesLocally(TestNG.java:1094) at org.testng.TestNG.run(TestNG.java:1006) at org.testng.remote.RemoteTestNG.run(RemoteTestNG.java:107) at org.testng.remote.RemoteTestNG.initAndRun(RemoteTestNG.java:199) at org.testng.remote.RemoteTestNG.main(RemoteTestNG.java:170) -- 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 38

[JIRA] Created: (LBCLASSIC-282) DBAppender: Connection obtained was never closed
by Ralph Schaer (JIRA) 12 Oct '11

12 Oct '11

DBAppender: Connection obtained was never closed ------------------------------------------------ Key: LBCLASSIC-282 URL: http://jira.qos.ch/browse/LBCLASSIC-282 Project: logback-classic Issue Type: Bug Components: appender Affects Versions: 0.9.29 Environment: Windows 7, Java 6, Spring 3.1 Snapshot, slf4j 1.6.1, logback 0.9.29, bonecp 0.7.1 Reporter: Ralph Schaer Assignee: Logback dev list Priority: Minor I use BoneCP together with logback. BoneCP complains about a connection that is never closed in the DBAppender The problem is in the method discoverConnnectionProperties in ConnectionSourceBase. This method does not close the database connection 19:48:56.896 [BoneCP-connection-watch-thread] ERROR com.jolbox.bonecp.CloseThreadMonitor - Connection obtained from thread [Thread-4] was never closed. Stack trace of location where connection was obtained follows: java.lang.Thread.getStackTrace(Thread.java:1479) com.jolbox.bonecp.BoneCP.captureStackTrace(BoneCP.java:543) com.jolbox.bonecp.BoneCP.watchConnection(BoneCP.java:532) com.jolbox.bonecp.BoneCP.getConnection(BoneCP.java:518) com.jolbox.bonecp.BoneCPDataSource.getConnection(BoneCPDataSource.java:114) ch.qos.logback.core.db.DataSourceConnectionSource.getConnection(DataSourceConnectionSource.java:72) ch.qos.logback.core.db.ConnectionSourceBase.discoverConnnectionProperties(ConnectionSourceBase.java:47) ch.qos.logback.core.db.DataSourceConnectionSource.start(DataSourceConnectionSource.java:52) -- 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-225) Do not require authentication to use TLS in SMTPAppender
by Mark Woon (JIRA) 11 Oct '11

11 Oct '11

Do not require authentication to use TLS in SMTPAppender -------------------------------------------------------- Key: LBCORE-225 URL: http://jira.qos.ch/browse/LBCORE-225 Project: logback-core Issue Type: Bug Affects Versions: 0.9.30 Reporter: Mark Woon Assignee: Logback dev list Enabling TLS should not require authentication. Pull request submitted to remove this requirement. -- 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

About LBCORE-224...
by Joern Huxhorn 11 Oct '11

11 Oct '11

This issue is still creeping me out. First of all, I'm perfectly fine with your workaround. Nevertheless, we should probably create an app that produces the IllegalMonitorStateException and deliver it to the Java developers. If this is a Java bug - and I have no other explanation - then it's a really critical one... Cheers, Joern.

5 20

[JIRA] Created: (LBCORE-147) RollingPolicy MaxHistory not deleting old files
by Rafael Diaz Maurin (JIRA) 04 Oct '11

04 Oct '11

RollingPolicy MaxHistory not deleting old files ----------------------------------------------- Key: LBCORE-147 URL: http://jira.qos.ch/browse/LBCORE-147 Project: logback-core Issue Type: Bug Components: Rolling Affects Versions: 0.9.18 Environment: linux 2.6.18 64bits apache-tomcat-6.0.20 java/jre1.6.0_18 Reporter: Rafael Diaz Maurin Assignee: Logback dev list The MaxHistory does not do the trick : the old files are not deleted at all : cat logging.xml <appender name="IDP_ACCESS" class="ch.qos.logback.core.rolling.RollingFileAppender"> <File>/shibboleth-idp/logs/idp-access.log</File> <Append>false</Append> <ImmediateFlush>true</ImmediateFlush> <RollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy"> <FileNamePattern>/shibboleth-idp/logs/old/idp-access-%d{yyyy-MM-dd_HH-mm}.log.gz</FileNamePattern> <MaxHistory>3</MaxHistory> </RollingPolicy> <layout class="ch.qos.logback.classic.PatternLayout"> <Pattern>%msg%n</Pattern> </layout> </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

11 35