- logback-dev - mailman3.qos.ch

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

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

11 Mar '08

Author: ceki Date: Tue Mar 11 10:43:47 2008 New Revision: 1641 Added: logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/spi/LoggingEventSerializationTest.java - copied, changed from r1638, /logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/net/LoggingEventSerializationTest.java logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/spi/LuckyCharms.java Removed: logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/net/LoggingEventSerializationTest.java Modified: logback/trunk/logback-classic/src/main/java/ch/qos/logback/classic/spi/LoggingEvent.java Log: - ongoing work for fixing bug 100 http://bugzilla.qos.ch/show_bug.cgi?id=100 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 Tue Mar 11 10:43:47 2008 @@ -47,6 +47,9 @@ */ private static final long serialVersionUID = 3022264832697160750L; + private static final int NULL_ARGUMENT_ARRAY = -1; + private static final String NULL_ARGUMENT_ARRAY_ELEMENT = "NULL_ARGUMENT_ARRAY_ELEMENT"; + /** * */ @@ -80,7 +83,7 @@ private String message; private String formattedMessage; - private Object[] argumentArray; + private transient Object[] argumentArray; private ThrowableInformation throwableInfo; @@ -113,7 +116,7 @@ // bug 85 (we previously failed to set this.argumentArray) this.argumentArray = argArray; - + if (argArray != null) { formattedMessage = MessageFormatter.arrayFormat(message, argArray); } else { @@ -122,7 +125,8 @@ timeStamp = System.currentTimeMillis(); // the case is ugly but under the circumstances acceptable - LogbackMDCAdapter logbackMDCAdapter = (LogbackMDCAdapter) MDC.getMDCAdapter(); + LogbackMDCAdapter logbackMDCAdapter = (LogbackMDCAdapter) MDC + .getMDCAdapter(); mdcPropertyMap = logbackMDCAdapter.getPropertyMap(); } @@ -185,13 +189,13 @@ * This method should be called prior to serializing an event. It should also * be called when using asynchronous logging. * - * Note that due to performance concerns, this method does NOT extract - * caller data. It is the responsability of the calller to extract caller + * + * Note that due to performance concerns, this method does NOT extract caller + * data. It is the responsability of the calller to extract caller * information. */ public void prepareForDeferredProcessing() { this.getThreadName(); - } public LoggerRemoteView getLoggerRemoteView() { @@ -286,6 +290,20 @@ private void writeObject(ObjectOutputStream out) throws IOException { out.defaultWriteObject(); out.writeInt(level.levelInt); + if (argumentArray != null) { + int len = argumentArray.length; + out.writeInt(len); + for (int i = 0; i < argumentArray.length; i++) { + if (argumentArray[i] != null) { + out.writeUTF(argumentArray[i].toString()); + } else { + out.writeUTF(NULL_ARGUMENT_ARRAY_ELEMENT); + } + } + } else { + out.writeInt(NULL_ARGUMENT_ARRAY); + } + } private void readObject(ObjectInputStream in) throws IOException, @@ -293,8 +311,19 @@ in.defaultReadObject(); int levelInt = in.readInt(); level = Level.toLevel(levelInt); + + int argArrayLen = in.readInt(); + if (argArrayLen != NULL_ARGUMENT_ARRAY) { + argumentArray = new String[argArrayLen]; + for (int i = 0; i < argArrayLen; i++) { + String val = in.readUTF(); + if (!NULL_ARGUMENT_ARRAY_ELEMENT.equals(val)) { + argumentArray[i] = val; + } + } + } } - + @Override public String toString() { StringBuffer sb = new StringBuffer('['); @@ -303,5 +332,4 @@ sb.append("\n"); return sb.toString(); } - } Copied: logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/spi/LoggingEventSerializationTest.java (from r1638, /logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/net/LoggingEventSerializationTest.java) ============================================================================== --- /logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/net/LoggingEventSerializationTest.java (original) +++ logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/spi/LoggingEventSerializationTest.java Tue Mar 11 10:43:47 2008 @@ -1,4 +1,8 @@ -package ch.qos.logback.classic.net; +package ch.qos.logback.classic.spi; + +import static org.junit.Assert.assertEquals; +import static org.junit.Assert.assertNotNull; +import static org.junit.Assert.assertNull; import java.io.ByteArrayInputStream; import java.io.ByteArrayOutputStream; @@ -6,18 +10,16 @@ import java.io.ObjectOutputStream; import java.util.Map; -import junit.framework.TestCase; - +import org.junit.After; +import org.junit.Before; +import org.junit.Test; import org.slf4j.MDC; import ch.qos.logback.classic.Level; import ch.qos.logback.classic.Logger; import ch.qos.logback.classic.LoggerContext; -import ch.qos.logback.classic.spi.LoggerContextRemoteView; -import ch.qos.logback.classic.spi.LoggerRemoteView; -import ch.qos.logback.classic.spi.LoggingEvent; -public class LoggingEventSerializationTest extends TestCase { +public class LoggingEventSerializationTest { LoggerContext lc; Logger logger; @@ -26,24 +28,26 @@ ObjectOutputStream oos; ObjectInputStream inputStream; + @Before public void setUp() throws Exception { - super.setUp(); lc = new LoggerContext(); lc.setName("testContext"); logger = lc.getLogger(LoggerContext.ROOT_NAME); + // create the byte output stream + bos = new ByteArrayOutputStream(); + oos = new ObjectOutputStream(bos); } + + @After public void tearDown() throws Exception { - super.tearDown(); + lc = null; logger = null; } + @Test public void testBasic() throws Exception { - // create the byte output stream - bos = new ByteArrayOutputStream(); - oos = new ObjectOutputStream(bos); - LoggingEvent event = createLoggingEvent(); oos.writeObject(event); @@ -57,11 +61,8 @@ assertEquals(Level.DEBUG, remoteEvent.getLevel()); } + @Test public void testContext() throws Exception { - // create the byte output stream - bos = new ByteArrayOutputStream(); - oos = new ObjectOutputStream(bos); - lc.putProperty("testKey", "testValue"); LoggingEvent event = createLoggingEvent(); oos.writeObject(event); @@ -85,11 +86,8 @@ assertEquals("testValue", props.get("testKey")); } + @Test public void testMDC() throws Exception { - // create the byte output stream - bos = new ByteArrayOutputStream(); - oos = new ObjectOutputStream(bos); - MDC.put("key", "testValue"); LoggingEvent event = createLoggingEvent(); oos.writeObject(event); @@ -104,11 +102,8 @@ assertEquals("testValue", MDCPropertyMap.get("key")); } + @Test public void testUpdatedMDC() throws Exception { - // create the byte output stream - bos = new ByteArrayOutputStream(); - oos = new ObjectOutputStream(bos); - MDC.put("key", "testValue"); LoggingEvent event1 = createLoggingEvent(); oos.writeObject(event1); @@ -131,6 +126,28 @@ 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(); + + Object[] aa = remoteEvent.getArgumentArray(); + assertNotNull(aa); + assertEquals(2, aa.length); + assertEquals("LC(0)", aa[0]); + assertNull(aa[1]); + } + + + private LoggingEvent createLoggingEvent() { LoggingEvent le = new LoggingEvent(this.getClass().getName(), logger, Level.DEBUG, "test message", null, null); Added: logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/spi/LuckyCharms.java ============================================================================== --- (empty file) +++ logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/spi/LuckyCharms.java Tue Mar 11 10:43:47 2008 @@ -0,0 +1,15 @@ +package ch.qos.logback.classic.spi; + +// non serializable object +public class LuckyCharms { + int id; + + LuckyCharms(int id) { + this.id= id; + } + + @Override + public String toString() { + return "LC("+id+")"; + } +}

1 0

svn commit: r1640 - in logback/trunk/logback-core/src/test/input/joran: implcitAction implicitAction
by noreply.ceki＠qos.ch 11 Mar '08

11 Mar '08

Author: ceki Date: Tue Mar 11 09:23:19 2008 New Revision: 1640 Added: logback/trunk/logback-core/src/test/input/joran/implicitAction/ - copied from r1639, /logback/trunk/logback-core/src/test/input/joran/implcitAction/ Removed: logback/trunk/logback-core/src/test/input/joran/implcitAction/ Log: - typo fix

1 0

svn commit: r1639 - logback/trunk/logback-classic/src/test/resources
by noreply.ceki＠qos.ch 11 Mar '08

11 Mar '08

Author: ceki Date: Tue Mar 11 09:20:50 2008 New Revision: 1639 Modified: logback/trunk/logback-classic/src/test/resources/logback-test.xml Log: - less noise in tests is good Modified: logback/trunk/logback-classic/src/test/resources/logback-test.xml ============================================================================== --- logback/trunk/logback-classic/src/test/resources/logback-test.xml (original) +++ logback/trunk/logback-classic/src/test/resources/logback-test.xml Tue Mar 11 09:20:50 2008 @@ -9,7 +9,7 @@ </appender> <root> - <level value="debug" /> + <level value="ERROR" /> <appender-ref ref="STDOUT" /> </root> </configuration> \ No newline at end of file

1 0

svn commit: r1638 - logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/net
by noreply.ceki＠qos.ch 11 Mar '08

11 Mar '08

Author: ceki Date: Tue Mar 11 09:16:23 2008 New Revision: 1638 Modified: logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/net/SocketAppenderTest.java Log: - Give the server more time to consume the message. This changed is needed on Linux platforms 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 09:16:23 2008 @@ -190,9 +190,9 @@ synchronized (simpleSocketServer) { simpleSocketServer.wait(1000); } - // give the server a little more time - Thread.yield(); + Thread.yield(); // give the server a little more time logger.debug("test msg 2"); + Thread.yield(); // give the server a little more time simpleSocketServer.close(); simpleSocketServer.join(2000); @@ -213,6 +213,7 @@ root.addAppender(la); simpleSocketServer = new SimpleSocketServer(serverLC, port); simpleSocketServer.start(); + Thread.yield(); }

1 0

svn commit: r1637 - logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/net
by noreply.ceki＠qos.ch 11 Mar '08

11 Mar '08

Author: ceki Date: Tue Mar 11 09:05:12 2008 New Revision: 1637 Modified: logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/net/SocketAppenderTest.java Log: - For the SocketAppenderTest#launchLateServer test to pass, the socketAppender's reconnection delay parameter has to be set. 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 09:05:12 2008 @@ -32,10 +32,11 @@ public class SocketAppenderTest { static final String LIST_APPENDER_NAME = "la"; - int port = 4560; + int port = 4561; LoggerContext lc = new LoggerContext(); LoggerContext serverLC = new LoggerContext(); ListAppender<LoggingEvent> la = new ListAppender<LoggingEvent>(); + SocketAppender socketAppender = new SocketAppender(); private SimpleSocketServer simpleSocketServer; @@ -180,6 +181,7 @@ @Test public void lateServerLaunch() throws InterruptedException { + socketAppender.setReconnectionDelay(20); configureClient(); Logger logger = lc.getLogger(LoggerContext.ROOT_NAME); logger.debug("test msg"); @@ -188,14 +190,13 @@ synchronized (simpleSocketServer) { simpleSocketServer.wait(1000); } + // give the server a little more time + Thread.yield(); 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); + StatusPrinter.print(lc); assertTrue(simpleSocketServer.isClosed()); assertEquals(1, la.list.size()); @@ -212,10 +213,6 @@ root.addAppender(la); simpleSocketServer = new SimpleSocketServer(serverLC, port); simpleSocketServer.start(); - //mockSocketServer = new MockSocketServer(expectedNumberOfEvents); - //mockSocketServer.start(); - // give MockSocketServer head start - Thread.sleep(100); } @@ -229,7 +226,6 @@ lc.setName("test"); lc.putProperty("testKey", "testValue"); Logger root = lc.getLogger(LoggerContext.ROOT_NAME); - SocketAppender socketAppender = new SocketAppender(); socketAppender.setContext(lc); socketAppender.setName("socket"); socketAppender.setPort(port);

1 0