[logback-dev] 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

noreply.ceki at qos.ch noreply.ceki at qos.ch
Tue Mar 11 20:43:31 CET 2008


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&uuml;lc&uuml;
  * @author S&eacute;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 <b>ReconnectionDelay</b> 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);
     }



More information about the logback-dev mailing list