March 2008 - logback-dev - mailman3.qos.ch

[Bug 83] New: Parser stops at ')'
by bugzilla-daemon＠pixie.qos.ch 13 Mar '08

13 Mar '08

http://bugzilla.qos.ch/show_bug.cgi?id=83 Summary: Parser stops at ')' Product: logback-core Version: unspecified Platform: All OS/Version: All Status: NEW Severity: blocker Priority: P1 Component: Pattern AssignedTo: logback-dev(a)qos.ch ReportedBy: jel(a)linofee.org The Parser skips everything after incl. ')'. Try e.g. <Pattern>%date{HH:mm:ss,SSS} [%thread] %-5level (%file:%line) - %message%n</Pattern> and thus is completely useless. Bummer! -- Configure bugmail: http://bugzilla.qos.ch/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are the assignee for the bug, or are watching the assignee.

1 1

svn commit: r1644 - in logback/trunk/logback-classic/src: main/java/ch/qos/logback/classic/spi test/java/ch/qos/logback/classic/spi
by noreply.ceki＠qos.ch 13 Mar '08

13 Mar '08

Author: ceki Date: Thu Mar 13 17:09:56 2008 New Revision: 1644 Modified: logback/trunk/logback-classic/src/main/java/ch/qos/logback/classic/spi/LoggingEvent.java logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/spi/LoggingEventSerializationTest.java Log: - support strings of unlimited length Modified: logback/trunk/logback-classic/src/main/java/ch/qos/logback/classic/spi/LoggingEvent.java ============================================================================== --- logback/trunk/logback-classic/src/main/java/ch/qos/logback/classic/spi/LoggingEvent.java (original) +++ logback/trunk/logback-classic/src/main/java/ch/qos/logback/classic/spi/LoggingEvent.java Thu Mar 13 17:09:56 2008 @@ -42,17 +42,11 @@ */ public class LoggingEvent implements Serializable { - /** - * - */ - private static final long serialVersionUID = 3022264832697160750L; + private static final long serialVersionUID = 3075964498087694229L; private static final int NULL_ARGUMENT_ARRAY = -1; private static final String NULL_ARGUMENT_ARRAY_ELEMENT = "NULL_ARGUMENT_ARRAY_ELEMENT"; - // writeUTF method in ObjectOutputStream has a size limit of 2*16; - static final int UTF_SIZE_LIMIT = 0xFFFF; - /** * */ @@ -298,9 +292,9 @@ out.writeInt(len); for (int i = 0; i < argumentArray.length; i++) { if (argumentArray[i] != null) { - out.writeUTF(cap(argumentArray[i].toString())); + out.writeObject(argumentArray[i].toString()); } else { - out.writeUTF(NULL_ARGUMENT_ARRAY_ELEMENT); + out.writeObject(NULL_ARGUMENT_ARRAY_ELEMENT); } } } else { @@ -309,18 +303,6 @@ } - /** - * writeUTF method cannot handle large strings - * @param in - * @return - */ - final String cap(String in) { - if(in.length() > UTF_SIZE_LIMIT) { - return in.substring(0, UTF_SIZE_LIMIT); - } else { - return in; - } - } private void readObject(ObjectInputStream in) throws IOException, ClassNotFoundException { in.defaultReadObject(); @@ -331,7 +313,7 @@ if (argArrayLen != NULL_ARGUMENT_ARRAY) { argumentArray = new String[argArrayLen]; for (int i = 0; i < argArrayLen; i++) { - String val = in.readUTF(); + Object val = in.readObject(); if (!NULL_ARGUMENT_ARRAY_ELEMENT.equals(val)) { argumentArray[i] = val; } Modified: logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/spi/LoggingEventSerializationTest.java ============================================================================== --- logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/spi/LoggingEventSerializationTest.java (original) +++ logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/spi/LoggingEventSerializationTest.java Thu Mar 13 17:09:56 2008 @@ -3,7 +3,6 @@ import static org.junit.Assert.assertEquals; import static org.junit.Assert.assertNotNull; import static org.junit.Assert.assertNull; -import static org.junit.Assert.assertTrue; import java.io.ByteArrayInputStream; import java.io.ByteArrayOutputStream; @@ -154,9 +153,7 @@ assertNotNull(aa); assertEquals(2, aa.length); String stringBack = (String) aa[1]; - - assertTrue(stringBack.startsWith("X")); - assertEquals(LoggingEvent.UTF_SIZE_LIMIT, stringBack.length()); + assertEquals(largeString, stringBack); } private LoggingEvent createLoggingEvent() {

1 0

[Bug 109] New: NullPointerException in deserialized AccessEvent.
by bugzilla-daemon＠pixie.qos.ch 13 Mar '08

13 Mar '08

http://bugzilla.qos.ch/show_bug.cgi?id=109 Summary: NullPointerException in deserialized AccessEvent. Product: logback-access Version: unspecified Platform: All OS/Version: Windows Status: NEW Severity: major Priority: P1 Component: Other AssignedTo: logback-dev(a)qos.ch ReportedBy: joern(a)huxhorn.de The following methods throw NPE's in case of deserialized AccessEvents. They should instead retun null. getRequestHeaderNames() buildRequestHeaderMap() buildRequestParameterMap() getResponseHeader(String key) getResponseHeaderNameList() getRequestContent() getStatusCode() (possibly, wrong if condition) getContentLength() (possibly, wrong if condition) getResponseContent() (please check) -- Configure bugmail: http://bugzilla.qos.ch/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are the assignee for the bug, or are watching the assignee.

1 14

svn commit: r1643 - in logback/trunk/logback-access/src: main/java/ch/qos/logback/access/spi test/java/ch/qos/logback/access/dummy test/java/ch/qos/logback/access/spi
by noreply.ceki＠qos.ch 13 Mar '08

13 Mar '08

Author: ceki Date: Thu Mar 13 03:59:18 2008 New Revision: 1643 Added: logback/trunk/logback-access/src/test/java/ch/qos/logback/access/spi/AccessEventSerializationTest.java - copied, changed from r1629, /logback/trunk/logback-access/src/test/java/ch/qos/logback/access/spi/AccessEventTest.java Removed: logback/trunk/logback-access/src/test/java/ch/qos/logback/access/spi/AccessEventTest.java Modified: logback/trunk/logback-access/src/main/java/ch/qos/logback/access/spi/AccessEvent.java logback/trunk/logback-access/src/test/java/ch/qos/logback/access/dummy/DummyRequest.java logback/trunk/logback-access/src/test/java/ch/qos/logback/access/spi/PackageTest.java Log: - fixing remaining issues with bug 109, in particular NPE thrown for getRequestContent and getResponseContent after serialization. The idea is, as expalined in comment 3, to make a copy of the contents of various httpRequest and httpResponse fields (without serializing httpRequest and httpResponse). Also note many converters in the c.q.l.acces.Pattern package *cannot* deal with null values returned by various get methods in AccessEvent. Thus, it is not enough to avoid NPE as accomplished by attachment 21 (dated 2008-01-28 21:39:11) but also to return valid values. Comment 3: http://bugzilla.qos.ch/show_bug.cgi?id=109#c3 Modified: logback/trunk/logback-access/src/main/java/ch/qos/logback/access/spi/AccessEvent.java ============================================================================== --- logback/trunk/logback-access/src/main/java/ch/qos/logback/access/spi/AccessEvent.java (original) +++ logback/trunk/logback-access/src/main/java/ch/qos/logback/access/spi/AccessEvent.java Thu Mar 13 03:59:18 2008 @@ -29,8 +29,9 @@ */ public class AccessEvent implements Serializable { - private static final long serialVersionUID = -3118194368414470960L; - + + private static final long serialVersionUID = 866718993618836343L; + public final static String NA = "-"; public final static String[] NA_STRING_ARRAY = new String[] { AccessEvent.NA }; @@ -75,10 +76,22 @@ this.serverAdapter = adapter; } + /** + * Returns the underlying HttpServletRequest. After serialization the returned + * value will be null. + * + * @return + */ public HttpServletRequest getRequest() { return httpRequest; } + /** + * Returns the underlying HttpServletResponse. After serialization the returned + * value will be null. + * + * @return + */ public HttpServletResponse getResponse() { return httpResponse; } @@ -462,6 +475,7 @@ getStatusCode(); getContentLength(); - // getPostContent(); + getRequestContent(); + getResponseContent(); } } \ No newline at end of file Modified: logback/trunk/logback-access/src/test/java/ch/qos/logback/access/dummy/DummyRequest.java ============================================================================== --- logback/trunk/logback-access/src/test/java/ch/qos/logback/access/dummy/DummyRequest.java (original) +++ logback/trunk/logback-access/src/test/java/ch/qos/logback/access/dummy/DummyRequest.java Thu Mar 13 03:59:18 2008 @@ -15,8 +15,17 @@ import javax.servlet.http.HttpServletRequest; import javax.servlet.http.HttpSession; +import ch.qos.logback.access.Constants; + public class DummyRequest implements HttpServletRequest { + public final static String DUMMY_CONTENT_STRING = "request contents"; + public final static byte[] DUMMY_CONTENT_BYTES = DUMMY_CONTENT_STRING.getBytes(); + + + public static final String DUMMY_RESPONSE_CONTENT_STRING = "response contents"; + public static final byte[] DUMMY_RESPONSE_CONTENT_BYTES =DUMMY_RESPONSE_CONTENT_STRING.getBytes(); + Hashtable<String, String> headerNames; String uri; @@ -130,6 +139,10 @@ public Object getAttribute(String key) { if (key.equals("testKey")) { return "testKey"; + } else if (Constants.LB_INPUT_BUFFER.equals(key)) { + return DUMMY_CONTENT_BYTES; + } else if (Constants.LB_OUTPUT_BUFFER.equals(key)) { + return DUMMY_RESPONSE_CONTENT_BYTES; } else { return null; } Copied: logback/trunk/logback-access/src/test/java/ch/qos/logback/access/spi/AccessEventSerializationTest.java (from r1629, /logback/trunk/logback-access/src/test/java/ch/qos/logback/access/spi/AccessEventTest.java) ============================================================================== --- /logback/trunk/logback-access/src/test/java/ch/qos/logback/access/spi/AccessEventTest.java (original) +++ logback/trunk/logback-access/src/test/java/ch/qos/logback/access/spi/AccessEventSerializationTest.java Thu Mar 13 03:59:18 2008 @@ -1,16 +1,21 @@ package ch.qos.logback.access.spi; +import static org.junit.Assert.assertEquals; +import static org.junit.Assert.assertNotNull; + import java.io.ByteArrayInputStream; import java.io.ByteArrayOutputStream; import java.io.IOException; import java.io.ObjectInputStream; import java.io.ObjectOutputStream; -import junit.framework.TestCase; +import org.junit.Test; + import ch.qos.logback.access.dummy.DummyAccessEventBuilder; +import ch.qos.logback.access.dummy.DummyRequest; import ch.qos.logback.access.dummy.DummyResponse; -public class AccessEventTest extends TestCase { +public class AccessEventSerializationTest { private Object buildSerializedAccessEvent() throws IOException, ClassNotFoundException { @@ -28,11 +33,13 @@ return ois.readObject(); } + @Test public void testSerialization() throws IOException, ClassNotFoundException { Object o = buildSerializedAccessEvent(); assertNotNull(o); AccessEvent aeBack = (AccessEvent) o; + assertEquals(DummyResponse.DUMMY_DEFAULT_HDEADER_MAP, aeBack .getResponseHeaderMap()); assertEquals(DummyResponse.DUMMY_DEFAULT_HDEADER_MAP.get("x"), aeBack @@ -45,6 +52,12 @@ .getContentLength()); assertEquals(DummyResponse.DUMMY_DEFAULT_STATUS, aeBack.getStatusCode()); + assertEquals(DummyRequest.DUMMY_CONTENT_STRING, aeBack + .getRequestContent()); + + assertEquals(DummyRequest.DUMMY_RESPONSE_CONTENT_STRING, aeBack + .getResponseContent()); + } } Modified: logback/trunk/logback-access/src/test/java/ch/qos/logback/access/spi/PackageTest.java ============================================================================== --- logback/trunk/logback-access/src/test/java/ch/qos/logback/access/spi/PackageTest.java (original) +++ logback/trunk/logback-access/src/test/java/ch/qos/logback/access/spi/PackageTest.java Thu Mar 13 03:59:18 2008 @@ -15,7 +15,7 @@ public static Test suite() { TestSuite suite = new TestSuite(); - suite.addTestSuite(AccessEventTest.class); + suite.addTest(new JUnit4TestAdapter(AccessEventSerializationTest.class)); return suite; } } \ No newline at end of file

1 0

[Bug 118] New: Console appender stops working after using paramter logging
by bugzilla-daemon＠pixie.qos.ch 13 Mar '08

13 Mar '08

http://bugzilla.qos.ch/show_bug.cgi?id=118 Summary: Console appender stops working after using paramter logging Product: Console Plugin Version: unspecified Platform: PC OS/Version: Windows Status: NEW Severity: critical Priority: P1 Component: interface AssignedTo: logback-dev(a)qos.ch ReportedBy: graham(a)crazysquirrel.com I'm pretty new to LOGBack but I've come across what appears to be a fairly major failing in the Eclipse console plugin. The first time a parameter replacing log message is used the console plugin stops working and doesn't log any further messages. I haven't written a simplified test case yet but here are three lines from my code that reliably trigger the problem: //This line appears in the console pluging and the standard tomcat console logger.debug( "Loading foo: " + foo ); //Neither of these two lines appear in the console plugin but do appear in the //standard tomcat console logger.debug( "Loading foo {} bar {} for baz {}", new Object[]{ foo, bar, baz} ); logger.debug( "Loading bar: " + bar ); -- Configure bugmail: http://bugzilla.qos.ch/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are the assignee for the bug, or are watching the assignee.

1 8

svn commit: r1642 - in logback/trunk/logback-classic/src: main/java/ch/qos/logback/classic/spi test/java/ch/qos/logback/classic/spi
by noreply.ceki＠qos.ch 13 Mar '08

13 Mar '08

Author: ceki Date: Thu Mar 13 01:27:23 2008 New Revision: 1642 Modified: logback/trunk/logback-classic/src/main/java/ch/qos/logback/classic/spi/LoggingEvent.java logback/trunk/logback-classic/src/main/java/ch/qos/logback/classic/spi/ThrowableInformation.java logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/spi/LoggingEventSerializationTest.java Log: - large string values in argAray are now capped in size - testing that ThrowableInformation is serialized correctly Modified: logback/trunk/logback-classic/src/main/java/ch/qos/logback/classic/spi/LoggingEvent.java ============================================================================== --- logback/trunk/logback-classic/src/main/java/ch/qos/logback/classic/spi/LoggingEvent.java (original) +++ logback/trunk/logback-classic/src/main/java/ch/qos/logback/classic/spi/LoggingEvent.java Thu Mar 13 01:27:23 2008 @@ -49,7 +49,10 @@ private static final int NULL_ARGUMENT_ARRAY = -1; private static final String NULL_ARGUMENT_ARRAY_ELEMENT = "NULL_ARGUMENT_ARRAY_ELEMENT"; - + + // writeUTF method in ObjectOutputStream has a size limit of 2*16; + static final int UTF_SIZE_LIMIT = 0xFFFF; + /** * */ @@ -295,7 +298,7 @@ out.writeInt(len); for (int i = 0; i < argumentArray.length; i++) { if (argumentArray[i] != null) { - out.writeUTF(argumentArray[i].toString()); + out.writeUTF(cap(argumentArray[i].toString())); } else { out.writeUTF(NULL_ARGUMENT_ARRAY_ELEMENT); } @@ -306,6 +309,18 @@ } + /** + * writeUTF method cannot handle large strings + * @param in + * @return + */ + final String cap(String in) { + if(in.length() > UTF_SIZE_LIMIT) { + return in.substring(0, UTF_SIZE_LIMIT); + } else { + return in; + } + } private void readObject(ObjectInputStream in) throws IOException, ClassNotFoundException { in.defaultReadObject(); Modified: logback/trunk/logback-classic/src/main/java/ch/qos/logback/classic/spi/ThrowableInformation.java ============================================================================== --- logback/trunk/logback-classic/src/main/java/ch/qos/logback/classic/spi/ThrowableInformation.java (original) +++ logback/trunk/logback-classic/src/main/java/ch/qos/logback/classic/spi/ThrowableInformation.java Thu Mar 13 01:27:23 2008 @@ -9,6 +9,8 @@ */ package ch.qos.logback.classic.spi; +import java.util.Arrays; + import ch.qos.logback.classic.ClassicGlobal; public class ThrowableInformation implements java.io.Serializable { @@ -100,4 +102,28 @@ public String[] getThrowableStrRep() { return sa; } + + @Override + public int hashCode() { + final int PRIME = 31; + int result = 1; + result = PRIME * result + Arrays.hashCode(sa); + return result; + } + + @Override + public boolean equals(Object obj) { + if (this == obj) + return true; + if (obj == null) + return false; + if (getClass() != obj.getClass()) + return false; + final ThrowableInformation other = (ThrowableInformation) obj; + if (!Arrays.equals(sa, other.sa)) + return false; + return true; + } + + } Modified: logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/spi/LoggingEventSerializationTest.java ============================================================================== --- logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/spi/LoggingEventSerializationTest.java (original) +++ logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/spi/LoggingEventSerializationTest.java Thu Mar 13 01:27:23 2008 @@ -3,9 +3,11 @@ import static org.junit.Assert.assertEquals; import static org.junit.Assert.assertNotNull; import static org.junit.Assert.assertNull; +import static org.junit.Assert.assertTrue; import java.io.ByteArrayInputStream; import java.io.ByteArrayOutputStream; +import java.io.IOException; import java.io.ObjectInputStream; import java.io.ObjectOutputStream; import java.util.Map; @@ -19,7 +21,7 @@ import ch.qos.logback.classic.Logger; import ch.qos.logback.classic.LoggerContext; -public class LoggingEventSerializationTest { +public class LoggingEventSerializationTest { LoggerContext lc; Logger logger; @@ -37,41 +39,27 @@ bos = new ByteArrayOutputStream(); oos = new ObjectOutputStream(bos); } - @After public void tearDown() throws Exception { - lc = null; logger = null; + oos.close(); } @Test - public void testBasic() throws Exception { + public void smoke() throws Exception { LoggingEvent event = createLoggingEvent(); - oos.writeObject(event); - - // create the input stream based on the ouput stream - ByteArrayInputStream bis = new ByteArrayInputStream(bos.toByteArray()); - inputStream = new ObjectInputStream(bis); - - LoggingEvent remoteEvent = (LoggingEvent) inputStream.readObject(); - - assertEquals("test message", remoteEvent.getMessage()); - assertEquals(Level.DEBUG, remoteEvent.getLevel()); + LoggingEvent remoteEvent = writeAndRead(event); + checkForEquality(event, remoteEvent); } @Test public void testContext() throws Exception { lc.putProperty("testKey", "testValue"); LoggingEvent event = createLoggingEvent(); - oos.writeObject(event); - - // create the input stream based on the ouput stream - ByteArrayInputStream bis = new ByteArrayInputStream(bos.toByteArray()); - inputStream = new ObjectInputStream(bis); - - LoggingEvent remoteEvent = (LoggingEvent) inputStream.readObject(); + LoggingEvent remoteEvent = writeAndRead(event); + checkForEquality(event, remoteEvent); LoggerRemoteView loggerRemoteView = remoteEvent.getLoggerRemoteView(); assertNotNull(loggerRemoteView); @@ -85,19 +73,13 @@ assertNotNull(props); assertEquals("testValue", props.get("testKey")); } - + @Test public void testMDC() throws Exception { MDC.put("key", "testValue"); LoggingEvent event = createLoggingEvent(); - oos.writeObject(event); - - // create the input stream based on the ouput stream - ByteArrayInputStream bis = new ByteArrayInputStream(bos.toByteArray()); - inputStream = new ObjectInputStream(bis); - - LoggingEvent remoteEvent = (LoggingEvent) inputStream.readObject(); - + LoggingEvent remoteEvent = writeAndRead(event); + checkForEquality(event, remoteEvent); Map<String, String> MDCPropertyMap = remoteEvent.getMDCPropertyMap(); assertEquals("testValue", MDCPropertyMap.get("key")); } @@ -107,7 +89,7 @@ MDC.put("key", "testValue"); LoggingEvent event1 = createLoggingEvent(); oos.writeObject(event1); - + MDC.put("key", "updatedTestValue"); LoggingEvent event2 = createLoggingEvent(); oos.writeObject(event2); @@ -117,27 +99,22 @@ inputStream = new ObjectInputStream(bis); // skip over one object - inputStream.readObject(); - LoggingEvent remoteEvent2 = (LoggingEvent) inputStream.readObject(); - + inputStream.readObject(); + LoggingEvent remoteEvent2 = (LoggingEvent) inputStream.readObject(); + // We observe the second logging event. It should provide us with // the updated MDC property. Map<String, String> MDCPropertyMap = remoteEvent2.getMDCPropertyMap(); assertEquals("updatedTestValue", MDCPropertyMap.get("key")); } - + @Test public void nonSerializableParameters() throws Exception { LoggingEvent event = createLoggingEvent(); LuckyCharms lucky0 = new LuckyCharms(0); - event.setArgumentArray(new Object[] {lucky0, null}); - oos.writeObject(event); - - // create the input stream based on the ouput stream - ByteArrayInputStream bis = new ByteArrayInputStream(bos.toByteArray()); - inputStream = new ObjectInputStream(bis); - - LoggingEvent remoteEvent = (LoggingEvent) inputStream.readObject(); + event.setArgumentArray(new Object[] { lucky0, null }); + LoggingEvent remoteEvent = writeAndRead(event); + checkForEquality(event, remoteEvent); Object[] aa = remoteEvent.getArgumentArray(); assertNotNull(aa); @@ -146,12 +123,66 @@ assertNull(aa[1]); } + @Test + public void testThrowable() throws Exception { + LoggingEvent event = createLoggingEvent(); + Throwable throwable = new Throwable("just testing"); + ThrowableInformation th = new ThrowableInformation(throwable); + event.setThrowableInformation(th); + + LoggingEvent remoteEvent = writeAndRead(event); + checkForEquality(event, remoteEvent); + } + + @Test + public void testSerializeLargeArgs() throws Exception { + + StringBuffer buffer = new StringBuffer(); + for (int i = 0; i < 100000; i++) { + buffer.append("X"); + } + String largeString = buffer.toString(); + Object[] argArray = new Object[] {new LuckyCharms(2), + largeString }; + + LoggingEvent event = createLoggingEvent(); + event.setArgumentArray(argArray); + + LoggingEvent remoteEvent = writeAndRead(event); + checkForEquality(event, remoteEvent); + Object[] aa = remoteEvent.getArgumentArray(); + assertNotNull(aa); + assertEquals(2, aa.length); + String stringBack = (String) aa[1]; + + assertTrue(stringBack.startsWith("X")); + assertEquals(LoggingEvent.UTF_SIZE_LIMIT, stringBack.length()); + } - private LoggingEvent createLoggingEvent() { LoggingEvent le = new LoggingEvent(this.getClass().getName(), logger, Level.DEBUG, "test message", null, null); return le; } + private void checkForEquality(LoggingEvent original, + LoggingEvent afterSerialization) { + assertEquals(original.getLevel(), afterSerialization.getLevel()); + assertEquals(original.getFormattedMessage(), afterSerialization + .getFormattedMessage()); + assertEquals(original.getMessage(), afterSerialization.getMessage()); + assertEquals(original.getThrowableInformation(), afterSerialization + .getThrowableInformation()); + + } + + private LoggingEvent writeAndRead(LoggingEvent event) throws IOException, + ClassNotFoundException { + oos.writeObject(event); + ByteArrayInputStream bis = new ByteArrayInputStream(bos.toByteArray()); + inputStream = new ObjectInputStream(bis); + + return (LoggingEvent) inputStream.readObject(); + } + }

1 0

[Bug 134] New: Suggestion: Make LoggingEvent dumber, Logger more intelligent
by bugzilla-daemon＠pixie.qos.ch 11 Mar '08

11 Mar '08

http://bugzilla.qos.ch/show_bug.cgi?id=134 Summary: Suggestion: Make LoggingEvent dumber, Logger more intelligent Product: logback-classic Version: unspecified Platform: All OS/Version: All Status: NEW Severity: enhancement Priority: P1 Component: Other AssignedTo: logback-dev(a)qos.ch ReportedBy: joern(a)huxhorn.de This change would introduce incompatibilities with previous versions but would increase general logging performance and decrease size of serialized events. After I have turned you off sufficiently ;), let me explain my idea: At the moment, LoggingEvent is handling it's own initialization. It even contains measures against manipulation after initialization in that a call of a setter results in an IllegalStateException if the attribute has already been initialized before. Instead, I'd suggest that LoggingEvent is changed into a dumb data container with getter and setters for all it's attributes. If it's really necessary to have a semi-const LoggingEvent I'd suggest to define LoggingEvent as an interface containing only the getters of the attributes and an implementation LoggingEventImpl that implements LoggingEvent including getters and setters. This communicates the *intent* that LoggingEvents aren't supposed to be modified but nothing more. It would still be possible to change e.g. the content of an array like argumentArray. Even if the getter would return a copy of the contained array, generating heat in the process, it would *still* be possible to brutally manipulate the LoggingEvent using java.lang.reflection setAccessible(true) so it's just not possible to guarantee constness. Instead of having a pseudo-const LoggingEvent let's dump the constness altogether and make it a dumb data container that contains no logic at all. This would instead be moved to the Logger class. I'd also suggest to remove formattedMessage and change the argumentArray to String[]. This is possible because logback-classic/slf4j promises formatted message, not LoggingEvent. It would increase performance because a Logger would simply create a LoggingEvent without performing a possibly unnecessary formatting of the message. Creation of LoggingEvents should be as fast and simple as possible, obviously. The formatting of the message should/would instead be performed in the appender (or, more generally, user of the event) if required. A serializing appender, an xml appender (e.g. using java.beans.XMLEncoder) or a socket appender would *not* require a formatted message, executing significantly faster than before. The argumentArray should be String[] to securely prevent java.io.NotSerializableException in the serializer and . java.lang.ClassNotFoundException in the deserializer. LoggerRemoteView and LoggerContextRemoteView should be changed the same way as LoggingEvent, i.e. just data container, logic moved to Logger, for similar reasons. I have to admit, though, that I currently don't understand the reason the LoggingEvent needs to know about LoggerContext beside resolving of the Logger name. I couldn't find code that uses LoggerContextRemoteView.getPropertyMap(), beside loading and saving it. So I think it may be possible that LoggerRemoteView isn't really necessary and could be removed from LoggingEvent... remembering the Logger name instead. fqnOfLoggerClass could be omitted because the CallerData would be created in the Logger where fqnOfLoggerClass is known. And last but not least I'd also change Level into an java.lang.Enum. I don't expect that all this will be done but I wanted to suggest it nevertheless because it would both increase performance and produce cleaner code. Breaking compatibility would IMHO be worth it - after all, logback isn't 1.0, yet ;) If you are interested I'd volunteer to implement those changes, after signing http://logback.qos.ch/cla.txt of course. Keywords: Inversion of Control (IoC), separation of concerns, KISS principle Related bugs: http://bugzilla.qos.ch/show_bug.cgi?id=100 http://bugzilla.qos.ch/show_bug.cgi?id=118 http://bugzilla.slf4j.org/show_bug.cgi?id=70 -- Configure bugmail: http://bugzilla.qos.ch/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are the assignee for the bug, or are watching the assignee.

1 1

[Bug 105] New: SocketAppenderBase - ObjectOutputStream is not closed in case of an IOException.
by bugzilla-daemon＠pixie.qos.ch 11 Mar '08

11 Mar '08

http://bugzilla.qos.ch/show_bug.cgi?id=105 Summary: SocketAppenderBase - ObjectOutputStream is not closed in case of an IOException. Product: logback-core Version: unspecified Platform: All OS/Version: All Status: NEW Severity: normal Priority: P1 Component: Appender AssignedTo: logback-dev(a)qos.ch ReportedBy: joern(a)huxhorn.de I think this is the cause of "hanging connections" in case of webserver restarts that I sometimes experience in lumberjack. Anyway, the stream should be closed in case of exception. -- Configure bugmail: http://bugzilla.qos.ch/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are the assignee for the bug, or are watching the assignee.

1 5

svn commit: r1636 - logback/trunk/logback-site/src/site/pages
by noreply.ceki＠qos.ch 11 Mar '08

11 Mar '08

Author: ceki Date: Tue Mar 11 20:50:38 2008 New Revision: 1636 Modified: logback/trunk/logback-site/src/site/pages/news.html Log: - updating news file to keep up with bug fixes Modified: logback/trunk/logback-site/src/site/pages/news.html ============================================================================== --- logback/trunk/logback-site/src/site/pages/news.html (original) +++ logback/trunk/logback-site/src/site/pages/news.html Tue Mar 11 20:50:38 2008 @@ -45,15 +45,39 @@ Fixed <a href="http://bugzilla.qos.ch/show_bug.cgi?id=104">bug - 104</a>, silly but but nonetheless serious copy-and-paste errors in - the c.q.l.classic.Logger class, reported by Joern Huxhorn. - + 104</a>, silly but but nonetheless serious copy-and-paste errors in + the c.q.l.classic.Logger class, reported by Joern Huxhorn. + - Fixed <a href="http://bugzilla.qos.ch/show_bug.cgi?id=104">bug + Having been replaced by <code>SimpleSocketServer</code>, the + <code>SocketServer</code> class has been removed. + + + Fixed <a href="http://bugzilla.qos.ch/show_bug.cgi?id=105">bug + 105</a>, sockets created by <code>SocketAppenderBase</code> is now + closed, reported by Joern Huxhorn. More generally, + <code>SimpleSocketServer</code> is much more careful to track open + client connections and to close them. + + + + + Fixed <a href="http://bugzilla.qos.ch/show_bug.cgi?id=110">bug 110</a> in relation with the <code>requestParameterMap</code> field in <code>AccessEvent</code> - reported by Joern Huxhorn. + + + Fixed <a href="http://bugzilla.slf4j.org/show_bug.cgi?id=66"> + SLF4J bug 66</a> in relation with caller data when using + log4j-over-slf4j - reported by Frnack Routier. + Fixed <a href="http://bugzilla.qos.ch/show_bug.cgi?id=129">bug + 129</a> reported by Michael Franz. As a result, Joran now supports + nested as well as multiple file inclusions. + + + <hr width="80%" align="center" />

1 0

svn commit: r1635 - in logback/trunk: logback-classic/src/main/java/ch/qos/logback/classic/net logback-classic/src/test/java/ch/qos/logback/classic/net logback-core/src/main/java/ch/qos/logback/core/net logback-core/src/main/java/ch/qos/logback/core/util
by noreply.ceki＠qos.ch 11 Mar '08

11 Mar '08

Author: ceki Date: Tue Mar 11 20:43:31 2008 New Revision: 1635 Removed: logback/trunk/logback-classic/src/main/java/ch/qos/logback/classic/net/SocketServer.java Modified: logback/trunk/logback-classic/src/main/java/ch/qos/logback/classic/net/SimpleSocketServer.java logback/trunk/logback-classic/src/main/java/ch/qos/logback/classic/net/SocketNode.java logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/net/PackageTest.java logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/net/SocketAppenderTest.java logback/trunk/logback-core/src/main/java/ch/qos/logback/core/net/SocketAppenderBase.java logback/trunk/logback-core/src/main/java/ch/qos/logback/core/util/StatusPrinter.java Log: - StatusPrinter can now print time of statii - Applied patch 10 mentioned in bug 105 onto SocketAppenderBase - SocketServer class has been removed and replaced by SimpleSocketServer - SimpleSocketServer is much more careful to track open client connections and to close them. Added relevant test cases. Modified: logback/trunk/logback-classic/src/main/java/ch/qos/logback/classic/net/SimpleSocketServer.java ============================================================================== --- logback/trunk/logback-classic/src/main/java/ch/qos/logback/classic/net/SimpleSocketServer.java (original) +++ logback/trunk/logback-classic/src/main/java/ch/qos/logback/classic/net/SimpleSocketServer.java Tue Mar 11 20:43:31 2008 @@ -12,6 +12,8 @@ import java.io.IOException; import java.net.ServerSocket; import java.net.Socket; +import java.util.ArrayList; +import java.util.List; import org.slf4j.Logger; import org.slf4j.LoggerFactory; @@ -46,7 +48,8 @@ private final LoggerContext lc; private boolean closed = false; private ServerSocket serverSocket; - + private List<SocketNode> socketNodeList = new ArrayList<SocketNode>(); + public static void main(String argv[]) throws Exception { int port = -1; if (argv.length == 2) { @@ -77,18 +80,31 @@ Socket socket = serverSocket.accept(); logger.info("Connected to client at " + socket.getInetAddress()); logger.info("Starting new socket node."); - new Thread(new SocketNode(socket, lc)).start(); + SocketNode newSocketNode = new SocketNode(this, socket, lc); + synchronized (socketNodeList) { + socketNodeList.add(newSocketNode); + } + new Thread(newSocketNode).start(); + signalSocketNodeCreation(); } } catch (Exception e) { if(closed) { - logger.info("Exception in run method for a closed server. This is expected"); + logger.info("Exception in run method for a closed server. This is normal."); } else { - logger.error("Failure in run method", e); + logger.error("Unexpected failure in run method", e); } } } - + /** + * Signal another thread that we have established a conneciton + * This is useful for testing purposes. + */ + void signalSocketNodeCreation() { + synchronized(this) { + this.notifyAll(); + } + } public boolean isClosed() { return closed; } @@ -100,10 +116,29 @@ serverSocket.close(); } catch (IOException e) { logger.error("Failed to close serverSocket", e); + } finally { + serverSocket = null; } + } + + synchronized (socketNodeList) { + for(SocketNode sn: socketNodeList) { + sn.close(); + } + socketNodeList.clear(); } } + public void socketNodeClosing(SocketNode sn) { + logger.debug("Removing {}", sn); + + // don't allow simultaneous access to the socketNodeList + // (e.g. removal whole iterating on the list causes + // java.util.ConcurrentModificationException + synchronized (socketNodeList) { + socketNodeList.remove(sn); + } + } static void usage(String msg) { System.err.println(msg); System.err.println("Usage: java " + SimpleSocketServer.class.getName() Modified: logback/trunk/logback-classic/src/main/java/ch/qos/logback/classic/net/SocketNode.java ============================================================================== --- logback/trunk/logback-classic/src/main/java/ch/qos/logback/classic/net/SocketNode.java (original) +++ logback/trunk/logback-classic/src/main/java/ch/qos/logback/classic/net/SocketNode.java Tue Mar 11 20:43:31 2008 @@ -14,6 +14,7 @@ import java.io.IOException; import java.io.ObjectInputStream; import java.net.Socket; +import java.net.SocketAddress; import ch.qos.logback.classic.Logger; import org.slf4j.LoggerFactory; @@ -42,11 +43,16 @@ Socket socket; LoggerContext context; ObjectInputStream ois; - + SocketAddress remoteSocketAddress; + static Logger logger = (Logger) LoggerFactory.getLogger(SocketNode.class); - - public SocketNode(Socket socket, LoggerContext context) { + boolean closed = false; + SimpleSocketServer socketServer; + + public SocketNode(SimpleSocketServer socketServer, Socket socket, LoggerContext context) { + this.socketServer = socketServer; this.socket = socket; + remoteSocketAddress = socket.getRemoteSocketAddress(); this.context = context; try { ois = new ObjectInputStream(new BufferedInputStream(socket @@ -67,7 +73,7 @@ Logger remoteLogger; try { - while (true) { + while (!closed) { // read an event from the wire event = (LoggingEvent) ois.readObject(); // get a logger from the hierarchy. The name of the logger is taken to @@ -90,10 +96,28 @@ logger.error("Unexpected exception. Closing connection.", e); } - try { - ois.close(); - } catch (Exception e) { - logger.info("Could not close connection.", e); + socketServer.socketNodeClosing(this); + close(); + } + + void close() { + if(closed) { + return; + } + closed = true; + if (ois != null) { + try { + ois.close(); + } catch (IOException e) { + logger.warn("Could not close connection.", e); + } finally { + ois = null; + } } } + + @Override + public String toString() { + return this.getClass().getName()+remoteSocketAddress.toString(); + } } Modified: logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/net/PackageTest.java ============================================================================== --- logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/net/PackageTest.java (original) +++ logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/net/PackageTest.java Tue Mar 11 20:43:31 2008 @@ -10,6 +10,7 @@ package ch.qos.logback.classic.net; +import junit.framework.JUnit4TestAdapter; import junit.framework.Test; import junit.framework.TestCase; import junit.framework.TestSuite; @@ -20,7 +21,7 @@ TestSuite suite = new TestSuite(); suite.addTestSuite(SyslogAppenderTest.class); suite.addTestSuite(SMTPAppenderTest.class); - suite.addTestSuite(SocketAppenderTest.class); + suite.addTest(new JUnit4TestAdapter(SocketAppenderTest.class)); suite.addTestSuite(JMSTopicAppenderTest.class); return suite; } Modified: logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/net/SocketAppenderTest.java ============================================================================== --- logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/net/SocketAppenderTest.java (original) +++ logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/net/SocketAppenderTest.java Tue Mar 11 20:43:31 2008 @@ -9,10 +9,13 @@ */ package ch.qos.logback.classic.net; + +import static org.junit.Assert.*; + import java.util.Map; -import junit.framework.TestCase; +import org.junit.Test; import org.slf4j.MDC; import org.slf4j.Marker; import org.slf4j.MarkerFactory; @@ -24,8 +27,9 @@ import ch.qos.logback.classic.spi.LoggerRemoteView; import ch.qos.logback.classic.spi.LoggingEvent; import ch.qos.logback.core.read.ListAppender; +import ch.qos.logback.core.util.StatusPrinter; -public class SocketAppenderTest extends TestCase { +public class SocketAppenderTest { static final String LIST_APPENDER_NAME = "la"; int port = 4560; @@ -33,9 +37,9 @@ LoggerContext serverLC = new LoggerContext(); ListAppender<LoggingEvent> la = new ListAppender<LoggingEvent>(); - //private MockSocketServer mockSocketServer; private SimpleSocketServer simpleSocketServer; - + + @Test public void testStartFailNoRemoteHost() { SocketAppender appender = new SocketAppender(); appender.setContext(lc); @@ -44,8 +48,9 @@ assertEquals(1, lc.getStatusManager().getCount()); } + @Test public void testRecieveMessage() throws InterruptedException { - startServer(1); + fireServer(); configureClient(); Logger logger = lc.getLogger(LoggerContext.ROOT_NAME); @@ -65,8 +70,9 @@ assertEquals(Level.DEBUG, remoteEvent.getLevel()); } + @Test public void testRecieveWithContext() throws InterruptedException { - startServer(1); + fireServer(); configureClient(); Logger logger = lc.getLogger(LoggerContext.ROOT_NAME); @@ -94,8 +100,9 @@ assertEquals("testValue", props.get("testKey")); } + @Test public void testMessageWithMDC() throws InterruptedException { - startServer(1); + fireServer(); configureClient(); Logger logger = lc.getLogger(LoggerContext.ROOT_NAME); @@ -117,8 +124,9 @@ assertEquals("testValue", MDCPropertyMap.get("key")); } + @Test public void testMessageWithMarker() throws InterruptedException { - startServer(1); + fireServer(); configureClient(); Logger logger = lc.getLogger(LoggerContext.ROOT_NAME); @@ -139,8 +147,9 @@ assertEquals("testMarker", remoteEvent.getMarker().getName()); } + @Test public void testMessageWithUpdatedMDC() throws InterruptedException { - startServer(2); + fireServer(); configureClient(); Logger logger = lc.getLogger(LoggerContext.ROOT_NAME); @@ -169,7 +178,33 @@ assertEquals("updatedTestValue", MDCPropertyMap.get("key")); } - private void startServer(int expectedNumberOfEvents) throws InterruptedException { + @Test + public void lateServerLaunch() throws InterruptedException { + configureClient(); + Logger logger = lc.getLogger(LoggerContext.ROOT_NAME); + logger.debug("test msg"); + + fireServer(); + synchronized (simpleSocketServer) { + simpleSocketServer.wait(1000); + } + logger.debug("test msg 2"); + + StatusPrinter.print(lc); + + // Wait max 2 seconds for mock server to finish. However, it should + // finish much sooner than that. + simpleSocketServer.close(); + simpleSocketServer.join(2000); + assertTrue(simpleSocketServer.isClosed()); + assertEquals(1, la.list.size()); + + LoggingEvent remoteEvent = la.list.get(0); + assertEquals("test msg 2", remoteEvent.getMessage()); + assertEquals(Level.DEBUG, remoteEvent.getLevel()); + } + + private void fireServer() throws InterruptedException { Logger root = serverLC.getLogger("root"); la.setName(LIST_APPENDER_NAME); la.setContext(serverLC); Modified: logback/trunk/logback-core/src/main/java/ch/qos/logback/core/net/SocketAppenderBase.java ============================================================================== --- logback/trunk/logback-core/src/main/java/ch/qos/logback/core/net/SocketAppenderBase.java (original) +++ logback/trunk/logback-core/src/main/java/ch/qos/logback/core/net/SocketAppenderBase.java Tue Mar 11 20:43:31 2008 @@ -20,9 +20,8 @@ /** * - * This is the base class for module specific SocketAppender - * implementations. - * + * This is the base class for module specific SocketAppender implementations. + * * @author Ceki Gülcü * @author Sébastien Pennec */ @@ -49,7 +48,6 @@ protected int port = DEFAULT_PORT; protected ObjectOutputStream oos; protected int reconnectionDelay = DEFAULT_RECONNECTION_DELAY; - private Connector connector; @@ -72,12 +70,16 @@ int errorCount = 0; if (port == 0) { errorCount++; - addError("No port was configured for appender" + name + " For more information, please visit http://logback.qos.ch/codes.html#socket_no_port"); + addError("No port was configured for appender" + + name + + " For more information, please visit http://logback.qos.ch/codes.html#socket_no_port"); } if (address == null) { errorCount++; - addError("No remote address was configured for appender" + name + " For more information, please visit http://logback.qos.ch/codes.html#socket_no_host"); + addError("No remote address was configured for appender" + + name + + " For more information, please visit http://logback.qos.ch/codes.html#socket_no_host"); } connect(address, port); @@ -149,7 +151,8 @@ return; if (address == null) { - addError("No remote host is set for SocketAppender named \"" + this.name + addError("No remote host is set for SocketAppender named \"" + + this.name + "\". For more information, please visit http://logback.qos.ch/codes.html#socket_no_host"); return; } @@ -168,6 +171,13 @@ oos.reset(); } } catch (IOException e) { + if (oos != null) { + try { + oos.close(); + } catch (IOException ignore) { + } + } + oos = null; addWarn("Detected problem with connection: " + e); if (reconnectionDelay > 0) { @@ -176,7 +186,7 @@ } } } - + protected abstract void postProcessEvent(E event); void fireConnector() { @@ -228,7 +238,6 @@ public int getPort() { return port; } - /** * The ReconnectionDelay option takes a positive integer representing Modified: logback/trunk/logback-core/src/main/java/ch/qos/logback/core/util/StatusPrinter.java ============================================================================== --- logback/trunk/logback-core/src/main/java/ch/qos/logback/core/util/StatusPrinter.java (original) +++ logback/trunk/logback-core/src/main/java/ch/qos/logback/core/util/StatusPrinter.java Tue Mar 11 20:43:31 2008 @@ -11,6 +11,8 @@ package ch.qos.logback.core.util; import java.io.PrintStream; +import java.text.SimpleDateFormat; +import java.util.Date; import java.util.Iterator; import ch.qos.logback.core.Context; @@ -21,6 +23,8 @@ private static PrintStream ps = System.out; + static SimpleDateFormat simpleDateFormat = new SimpleDateFormat("HH:mm:ss,SSS"); + public static void setPrintStream(PrintStream printStream) { ps = printStream; } @@ -57,7 +61,15 @@ } else { prefix = indentation + "|-"; } - ps.println(prefix+s); + + if(simpleDateFormat != null) { + Date date = new Date(s.getDate()); + String dateStr = simpleDateFormat.format(date); + ps.print(dateStr); + ps.print(" "); + } + ps.println(prefix+s); + if (s.getThrowable() != null) { s.getThrowable().printStackTrace(ps); }

1 0