February 2012 - logback-dev

[JIRA] Created: (LBCLASSIC-316) SiftingAppender and the lifecycle of created appenders
by Guus Bloemsma (JIRA) 06 Mar '12

06 Mar '12

SiftingAppender and the lifecycle of created appenders ------------------------------------------------------ Key: LBCLASSIC-316 URL: http://jira.qos.ch/browse/LBCLASSIC-316 Project: logback-classic Issue Type: Improvement Components: appender Affects Versions: 1.0.0 Environment: servlet container Reporter: Guus Bloemsma Assignee: Logback dev list I'm using SiftingAppender to create logfiles per servlet request. I wrote a servlet filter to add session and request id's into MDC. A custom appender (nested into SiftingAppender) buffers all logging events. Only when a WARN or ERROR occurred it writes all of them at the end of the servlet request to yet another nested appender. Logback made this surprisingly easy! This all works fine except for one little problem. The SiftingAppender creates a new custom appender for each request. It uses a AppenderTrackerImpl to keep track of them. That AppenderTrackerImpl holds on to those appenders for half an hour even though it is guaranteed that they won't be needed after the request. That is a lot of unused appenders! Being able to configure that timeout per SiftingAppender would be one solution. Another way would be to make the method ch.qos.logback.core.sift.AppenderTrackerImpl.isEntryStale(Entry, long) check whether the appender in the entry is stopped. In that case it should be treated as stale as well. My custom appender would simply stop itself once it is no longer used. BTW, I understand that I'm kind of abusing SiftingAppender. Maybe I should just make my own... -- 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: (LBCORE-213) Do not restrict SMTPAppender <to> to only 1 email address
by Alexandre Garnier (JIRA) 06 Mar '12

06 Mar '12

Do not restrict SMTPAppender <to> to only 1 email address --------------------------------------------------------- Key: LBCORE-213 URL: http://jira.qos.ch/browse/LBCORE-213 Project: logback-core Issue Type: Bug Reporter: Alexandre Garnier Assignee: Logback dev list It's not possible to have multiple email address in <to> element of SMTPAppender because only the first one is used (https://github.com/ceki/logback/blob/master/logback-core/src/main/java/ch/q…) When using a property, multiple <to> element is not really easy (if even possible)... Example: <appender name="email" class="ch.qos.logback.classic.net.SMTPAppender"> ... <to>${mail.log.to}</to> ... </appender> With properties : mail.log.to = admin@domain.com,dev@domain.com,op@domain.com => Only admin(a)domain.com get the email ! -- 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: (LBCLASSIC-221) SMTPAppender includes irrelevant logging events
by Chris Cheshire (JIRA) 06 Mar '12

06 Mar '12

SMTPAppender includes irrelevant logging events ----------------------------------------------- Key: LBCLASSIC-221 URL: http://jira.qos.ch/browse/LBCLASSIC-221 Project: logback-classic Issue Type: Bug Components: appender Affects Versions: 0.9.24 Environment: Java6, Tomcat6 Reporter: Chris Cheshire Assignee: Logback dev list The BufferSize parameter to SMTPAppender has been removed with no replacement. When the SMTPAppender is triggered by an error event it also includes the previous 255 logging events, whether they were errors or not (now that the buffer size is fixed). By using BufferSize = 1, I was able to send a single error email every time an error occurred with just that error. Now I get completely irrelevant logging events, potentially days old with nothing to do with the error being logged and no simple way to change this. I'm not sure what version this was introduced - I just upgraded from 0.9.17 to 0.9.24. -- 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 5

[JIRA] Created: (LBCLASSIC-322) class and line conversion words don't work in SMTPAppender
by Chris Cheshire (JIRA) 23 Feb '12

23 Feb '12

class and line conversion words don't work in SMTPAppender ---------------------------------------------------------- Key: LBCLASSIC-322 URL: http://jira.qos.ch/browse/LBCLASSIC-322 Project: logback-classic Issue Type: Bug Components: appender Affects Versions: 1.0.0 Environment: logback-1.0.0, slf4j-1.6.4, java 6 Reporter: Chris Cheshire Assignee: Logback dev list The following layout works as expected when in a FileAppender or RollingFileAppender <layout class="ch.qos.logback.classic.PatternLayout"> <pattern>%date [%thread] %-5level %logger %n%n Class : %class %n Line : %line %n%n%message%n</pattern> </layout> but when in an SMTPAppender, the class and line conversion words only produce a '?' instead of their correct values. This was working in 0.9.24 (my last used version). Chris -- 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: (LBCORE-246) ResilientOutputStreamBase does not recover from transient network outage when the appender uses the LayoutWrappingEncoder
by Thomas P Rees (JIRA) 21 Feb '12

21 Feb '12

ResilientOutputStreamBase does not recover from transient network outage when the appender uses the LayoutWrappingEncoder ------------------------------------------------------------------------------------------------------------------------- Key: LBCORE-246 URL: http://jira.qos.ch/browse/LBCORE-246 Project: logback-core Issue Type: Bug Components: Layout Affects Versions: 0.9.30 Environment: Windows Reporter: Thomas P Rees Assignee: Logback dev list Our customer has a problem with network glitches, so we upgraded from 0.9.17 to 0.9.30 to take advantage of the ResilientOutputStream. The particular appender that caused problems at the customer site used a custom layout class, so we wrapped that class in a LayoutWrappingEncoder in build.xml: <appender name="AUDIT" class="ch.qos.logback.core.rolling.RollingFileAppender"> <File>${logging.audit.root}/audit/audit.log</File> <encoder class="ch.qos.logback.core.encoder.LayoutWrappingEncoder"> <layout class="com.chiliad.log.util.PropertiesLayout" /> </encoder> <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">  </rollingPolicy> </appender> We tested the ResilientOutputStream by editing logback.xml to write the logfile to another system, then we removed the ethernet cable from that other system. A couple minutes later we plugged the ethernet cable back into the other system. Stdout of the logging system reported 2012/02/14 16:33:47 | INFO | jvm 1 | srvmain | 16:33:47,414 |-ERROR in c.q.l.c.recovery.ResilientFileOutputStream@12297237 - IO failure while writing to file [\\cushman\e\logs\audit\audit.log] java.io.IOException: The specified network name is no longer available There was also a long stack trace from Java with more detail about the IOException. However immediately after this stack trace the following message appeared 2012/02/14 16:33:47 | INFO | jvm 1 | srvmain | 16:33:47,408 |-INFO in c.q.l.c.recovery.ResilientFileOutputStream@12297237 - Recovered from IO failure on file [\\cushman\e\logs\audit\audit.log] Furthermore, logging did not actually recover. The audit log on the remote server did not get any more messages, and stdout continued to record the messaages shown above, always paired with the complaint about the IO failure and then saying that it recovered from the IO failure. I downloaded the source code and found the source of the problem. The LayoutWrappingEncoder always calls write and then flush together: outputStream.write(convertToBytes(txt)); outputStream.flush(); In ResilientOutputStreamBase the write method checks for a bad state in the output stream, but the flush method does not: public void write(int b) { if (isPresumedInError()) { if (!recoveryCoordinator.isTooSoon()) { attemptRecovery(); } return; // return regardless of the success of the recovery attempt } try { os.write(b); postSuccessfulWrite(); } catch (IOException e) { postIOFailure(e); } } public void flush() { if (os != null) { try { os.flush(); postSuccessfulWrite(); } catch (IOException e) { postIOFailure(e); } } } So, the write method encounters the IOException and sets the presumedClean flag to false. However, the flush method does not call isPresumedInError and the flush succeeds (I presume because there is no data to flush). The flush method then calls postSuccessfulWrite, which sets the presumedClean flag to true. I fixed this problem by changing the flush method to call isPresumedInError:: public void flush() { if (os != null) { if (isPresumedInError()) { if (!recoveryCoordinator.isTooSoon()) { attemptRecovery(); } return; // return regardless of the success of the recovery attempt } try { os.flush(); postSuccessfulWrite(); } catch (IOException e) { postIOFailure(e); } } } Now when we run the test of unplugging the ethernet cable on the system where the audit logs are written and then plug the cable back in the logger starts logging again and the logfile resumes recording messages. Does this solution look correct to you? thanks Tom -- 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 0

[JIRA] Created: (LBCORE-210) Upgrade Janino support to latest 2.6.1
by Jason Klapste (JIRA) 21 Feb '12

21 Feb '12

Upgrade Janino support to latest 2.6.1 -------------------------------------- Key: LBCORE-210 URL: http://jira.qos.ch/browse/LBCORE-210 Project: logback-core Issue Type: Improvement Components: Joran Affects Versions: 0.9.28, 0.9.29 Reporter: Jason Klapste Assignee: Logback dev list Logback officially supports 2.4.3 (from 2006!) and should probably be upgraded to a more recent version. Janino 2.6.1 *WAS* working previously in logback (0.9.27) until EnvUtil.isJaninoAvailable()'s check was added. org.codehaus.janino.Cookable does not exist in 2.6.1. -- 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 10

[JIRA] Created: (LBGENERAL-52) Need a simple api to reloadDefaultConfiguration other than using jmx
by Yony Feng (JIRA) 18 Feb '12

18 Feb '12

Need a simple api to reloadDefaultConfiguration other than using jmx --------------------------------------------------------------------- Key: LBGENERAL-52 URL: http://jira.qos.ch/browse/LBGENERAL-52 Project: logback-general Issue Type: Improvement Reporter: Yony Feng Assignee: Logback dev list Would like a way to locally invoke reloadDefaultConfiguration without getting an instance of the logback MBean and invoking the operation. Thanks! -- 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 0

[JIRA] Created: (LBCLASSIC-281) Don't evaluate formattedMessage in LoggingEvent constructor
by Andrew Brett (JIRA) 16 Feb '12

16 Feb '12

Don't evaluate formattedMessage in LoggingEvent constructor ----------------------------------------------------------- Key: LBCLASSIC-281 URL: http://jira.qos.ch/browse/LBCLASSIC-281 Project: logback-classic Issue Type: Improvement Affects Versions: 0.9.29 Reporter: Andrew Brett Assignee: Logback dev list Whenever a ch.qos.logback.classic.spi.LoggingEvent is constructed, MessageFormatter.arrayFormat(...) is called, and the formattedMessage member variable assigned. This involves calling toString() on all arguments in argArray, which can be slow, and occurs even if the formattedMessage is not part of any appender layouts. For my project's purposes, I have a custom formatter which only outputs an abbreviated string form of certain objects with expensive toString() methods; however, I am still paying the overhead in the toString() calls, since they're made even when getFormattedMessage() is never called. Note that I don't control the source of the objects with expensive toString() methods, nor do I control the source everywhere they're logged, so I can't simply change them directly. formattedMessage is already evaluated lazily in getFormattedMessage(), so the only side effect of this change is the introspection of argsArray to look for a Throwable at the end, which is a trivial operation to perform separately. -- 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 3

[android] support for SMTPAppender: almost there?
by Enrico Spinielli 11 Feb '12

11 Feb '12

Hi, it looks like I am close to be able to add support for SMTPAppender. I modified the build.xml to include the relevant code, re-introduced the tests (SocketAppenderTest.class, DilutedSMTPAppenderTest.class, SMTPAppender_GreenTest.class) and (properly?) set the bootclasspath to use the android version of javax.mail (see my previous post on SMTPAppender). I forked logback-android and pushed my changes in https://github.com/espinielli/logback-android It looks like the features I am interested in are ok, since I am getting only html/htmlLong test cases failing (see below) and I am not interested in sending html formatted logs via email. I will try this version out on my android app soon and provide feedback on this list. Of course I will welcome any feedbacks from anyone on what I did, i.e. mistakes, bugs ... fixes and ideas are welcome too. Thanks in advance Bye Enrico When I run the tests I get html/htmlLong failing with the following: [junit] Testcase: html took 260.281 sec [junit] Caused an ERROR [junit] Unexpected end of file from server Nested exception: Unexpected end of file from server [junit] org.dom4j.DocumentException: Unexpected end of file from server Nested exception: Unexpected end of file from server [junit] at org.dom4j.io.SAXReader.read(SAXReader.java:484) [junit] at org.dom4j.io.SAXReader.read(SAXReader.java:343) [junit] at ch.qos.logback.classic.net.SMTPAppender_GreenTest.html(Unknown Source) [junit] Nested exception: [junit] java.net.SocketException: Unexpected end of file from server [junit] at sun.net.www.http.HttpClient.parseHTTPHeader(HttpClient.java:777) [junit] at sun.net.www.http.HttpClient.parseHTTP(HttpClient.java:640) [junit] at sun.net.www.http.HttpClient.parseHTTPHeader(HttpClient.java:774) [junit] at sun.net.www.http.HttpClient.parseHTTP(HttpClient.java:640) [junit] at sun.net.www.protocol.http.HttpURLConnection.getInputStream(HttpURLConnection.java:1195) [junit] at com.sun.org.apache.xerces.internal.impl.XMLEntityManager.setupCurrentEntity(XMLEntityManager.java:677) [junit] at com.sun.org.apache.xerces.internal.impl.XMLEntityManager.startEntity(XMLEntityManager.java:1315) [junit] at com.sun.org.apache.xerces.internal.impl.XMLEntityManager.startEntity(XMLEntityManager.java:1252) [junit] at com.sun.org.apache.xerces.internal.impl.XMLDTDScannerImpl.startPE(XMLDTDScannerImpl.java:722) [junit] at com.sun.org.apache.xerces.internal.impl.XMLDTDScannerImpl.skipSeparator(XMLDTDScannerImpl.java:2069) [junit] at com.sun.org.apache.xerces.internal.impl.XMLDTDScannerImpl.scanDecls(XMLDTDScannerImpl.java:2032) [junit] at com.sun.org.apache.xerces.internal.impl.XMLDTDScannerImpl.scanDTDExternalSubset(XMLDTDScannerImpl.java:320) [junit] at com.sun.org.apache.xerces.internal.impl.XMLDocumentScannerImpl$DTDDriver.dispatch(XMLDocumentScannerImpl.java:1203) [junit] at com.sun.org.apache.xerces.internal.impl.XMLDocumentScannerImpl$DTDDriver.next(XMLDocumentScannerImpl.java:1090) [junit] at com.sun.org.apache.xerces.internal.impl.XMLDocumentScannerImpl$PrologDriver.next(XMLDocumentScannerImpl.java:1003) [junit] at com.sun.org.apache.xerces.internal.impl.XMLDocumentScannerImpl.next(XMLDocumentScannerImpl.java:648) [junit] at com.sun.org.apache.xerces.internal.impl.XMLNSDocumentScannerImpl.next(XMLNSDocumentScannerImpl.java:140) [junit] at com.sun.org.apache.xerces.internal.impl.XMLDocumentFragmentScannerImpl.scanDocument(XMLDocumentFragmentScannerImpl.java:511) [junit] at com.sun.org.apache.xerces.internal.parsers.XML11Configuration.parse(XML11Configuration.java:808) [junit] at com.sun.org.apache.xerces.internal.parsers.XML11Configuration.parse(XML11Configuration.java:737) [junit] at com.sun.org.apache.xerces.internal.parsers.XMLParser.parse(XMLParser.java:119) [junit] at com.sun.org.apache.xerces.internal.parsers.AbstractSAXParser.parse(AbstractSAXParser.java:1205) [junit] at com.sun.org.apache.xerces.internal.jaxp.SAXParserImpl$JAXPSAXParser.parse(SAXParserImpl.java:522) [junit] at org.dom4j.io.SAXReader.read(SAXReader.java:465) [junit] at org.dom4j.io.SAXReader.read(SAXReader.java:343) [junit] at ch.qos.logback.classic.net.SMTPAppender_GreenTest.html(Unknown Source) [junit] [junit] Testcase: htmlLong took 736.286 sec [junit] Caused an ERROR [junit] Unexpected end of file from server Nested exception: Unexpected end of file from server [junit] org.dom4j.DocumentException: Unexpected end of file from server Nested exception: Unexpected end of file from server [junit] at org.dom4j.io.SAXReader.read(SAXReader.java:484) [junit] at org.dom4j.io.SAXReader.read(SAXReader.java:343) [junit] at ch.qos.logback.classic.net.SMTPAppender_GreenTest.htmlLong(Unknown Source) [junit] Nested exception: [junit] java.net.SocketException: Unexpected end of file from server [junit] at sun.net.www.http.HttpClient.parseHTTPHeader(HttpClient.java:777) [junit] at sun.net.www.http.HttpClient.parseHTTP(HttpClient.java:640) [junit] at sun.net.www.http.HttpClient.parseHTTPHeader(HttpClient.java:774) [junit] at sun.net.www.http.HttpClient.parseHTTP(HttpClient.java:640) [junit] at sun.net.www.protocol.http.HttpURLConnection.getInputStream(HttpURLConnection.java:1195) [junit] at com.sun.org.apache.xerces.internal.impl.XMLEntityManager.setupCurrentEntity(XMLEntityManager.java:677) [junit] at com.sun.org.apache.xerces.internal.impl.XMLEntityManager.startEntity(XMLEntityManager.java:1315) [junit] at com.sun.org.apache.xerces.internal.impl.XMLEntityManager.startEntity(XMLEntityManager.java:1252) [junit] at com.sun.org.apache.xerces.internal.impl.XMLDTDScannerImpl.startPE(XMLDTDScannerImpl.java:722) [junit] at com.sun.org.apache.xerces.internal.impl.XMLDTDScannerImpl.skipSeparator(XMLDTDScannerImpl.java:2069) [junit] at com.sun.org.apache.xerces.internal.impl.XMLDTDScannerImpl.scanDecls(XMLDTDScannerImpl.java:2032) [junit] at com.sun.org.apache.xerces.internal.impl.XMLDTDScannerImpl.scanDTDExternalSubset(XMLDTDScannerImpl.java:320) [junit] at com.sun.org.apache.xerces.internal.impl.XMLDocumentScannerImpl$DTDDriver.dispatch(XMLDocumentScannerImpl.java:1203) [junit] at com.sun.org.apache.xerces.internal.impl.XMLDocumentScannerImpl$DTDDriver.next(XMLDocumentScannerImpl.java:1090) [junit] at com.sun.org.apache.xerces.internal.impl.XMLDocumentScannerImpl$PrologDriver.next(XMLDocumentScannerImpl.java:1003) [junit] at com.sun.org.apache.xerces.internal.impl.XMLDocumentScannerImpl.next(XMLDocumentScannerImpl.java:648) [junit] at com.sun.org.apache.xerces.internal.impl.XMLNSDocumentScannerImpl.next(XMLNSDocumentScannerImpl.java:140) [junit] at com.sun.org.apache.xerces.internal.impl.XMLDocumentFragmentScannerImpl.scanDocument(XMLDocumentFragmentScannerImpl.java:511) [junit] at com.sun.org.apache.xerces.internal.parsers.XML11Configuration.parse(XML11Configuration.java:808) [junit] at com.sun.org.apache.xerces.internal.parsers.XML11Configuration.parse(XML11Configuration.java:737) [junit] at com.sun.org.apache.xerces.internal.parsers.XMLParser.parse(XMLParser.java:119) [junit] at com.sun.org.apache.xerces.internal.parsers.AbstractSAXParser.parse(AbstractSAXParser.java:1205) [junit] at com.sun.org.apache.xerces.internal.jaxp.SAXParserImpl$JAXPSAXParser.parse(SAXParserImpl.java:522) [junit] at org.dom4j.io.SAXReader.read(SAXReader.java:465) [junit] at org.dom4j.io.SAXReader.read(SAXReader.java:343) [junit] at ch.qos.logback.classic.net.SMTPAppender_GreenTest.htmlLong(Unknown Source) -- Enrico Spinielli "Do Androids dream of electric sheep?"— Philip K. Dick "Hear and forget; see and remember;do and understand."—Mitchel Resnick "He who refuses to do arithmetic is doomed to talk nonsense."—John McCarthy

1 1

[JIRA] Created: (LBGENERAL-51) Implementation-Version missed in Manifest-File
by Rudolf Pfister (JIRA) 10 Feb '12

10 Feb '12

Implementation-Version missed in Manifest-File ---------------------------------------------- Key: LBGENERAL-51 URL: http://jira.qos.ch/browse/LBGENERAL-51 Project: logback-general Issue Type: Improvement Components: build-structure Affects Versions: 1.0.0 Reporter: Rudolf Pfister Assignee: Logback dev list Priority: Minor In the Manifest-File of the logback-*.jar-files there are np properties like - Implementation-Version, Implementation-Title, Implementation-Vendor - Specification-Version, Specification-Title, Specification-Vendor These Properties are useful to retreive Information about an package via the java.lang.Package-class. Example: System.out.println( org.slf4j.Logger.class.getPackage() .getImplementationVersion()); System.out.println( ch.qos.logback.core.Appender.class.getPackage() .getImplementationVersion()); First sysout returns e.g. 1.6.4, whereas second sysout returns null. -- 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 0