You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@logging.apache.org by rg...@apache.org on 2012/11/19 18:05:31 UTC

svn commit: r1411311 - in /logging/log4j/log4j2/trunk: core/src/main/java/org/apache/logging/log4j/core/net/ core/src/test/java/org/apache/logging/log4j/core/net/ core/src/test/resources/ src/changes/

Author: rgoers
Date: Mon Nov 19 17:05:30 2012
New Revision: 1411311

URL: http://svn.apache.org/viewvc?rev=1411311&view=rev
Log:
LOG4J2-119 & LOG4J2-120 - TCPSocketManager would fail if the initial connection could not be established. A broken socket connection would cause the TCPSocketManager to continuously reconnect.

Added:
    logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/net/SocketTest.java
    logging/log4j/log4j2/trunk/core/src/test/resources/log4j-socket.xml
Modified:
    logging/log4j/log4j2/trunk/core/src/main/java/org/apache/logging/log4j/core/net/TCPSocketManager.java
    logging/log4j/log4j2/trunk/src/changes/changes.xml

Modified: logging/log4j/log4j2/trunk/core/src/main/java/org/apache/logging/log4j/core/net/TCPSocketManager.java
URL: http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/core/src/main/java/org/apache/logging/log4j/core/net/TCPSocketManager.java?rev=1411311&r1=1411310&r2=1411311&view=diff
==============================================================================
--- logging/log4j/log4j2/trunk/core/src/main/java/org/apache/logging/log4j/core/net/TCPSocketManager.java (original)
+++ logging/log4j/log4j2/trunk/core/src/main/java/org/apache/logging/log4j/core/net/TCPSocketManager.java Mon Nov 19 17:05:30 2012
@@ -20,12 +20,15 @@ import org.apache.logging.log4j.core.app
 import org.apache.logging.log4j.core.appender.ManagerFactory;
 import org.apache.logging.log4j.core.appender.OutputStreamManager;
 
+import java.io.ByteArrayOutputStream;
 import java.io.IOException;
 import java.io.OutputStream;
 import java.net.ConnectException;
 import java.net.InetAddress;
+import java.net.InterfaceAddress;
 import java.net.Socket;
 import java.net.UnknownHostException;
+import java.util.concurrent.CountDownLatch;
 
 /**
  * Manager of TCP Socket connections.
@@ -66,6 +69,12 @@ public class TCPSocketManager extends Ab
         this.reconnectionDelay = delay;
         this.socket = sock;
         retry = delay > 0;
+        if (sock == null) {
+            connector = new Reconnector(this);
+            connector.setDaemon(true);
+            connector.setPriority(Thread.MIN_PRIORITY);
+            connector.start();
+        }
     }
 
     /**
@@ -90,6 +99,15 @@ public class TCPSocketManager extends Ab
 
     @Override
     protected synchronized void write(byte[] bytes, int offset, int length)  {
+        if (socket == null) {
+            if (connector != null) {
+                connector.latch();
+            }
+            if (socket == null) {
+                String msg = "Error writing to " + getName() + " socket not available";
+                throw new AppenderRuntimeException(msg);
+            }
+        }
         try {
             getOutputStream().write(bytes, offset, length);
             socket.setSendBufferSize(length);
@@ -122,12 +140,22 @@ public class TCPSocketManager extends Ab
 
         private boolean shutdown = false;
 
+        public CountDownLatch latch = new CountDownLatch(1);
+
         private final Object owner;
 
         public Reconnector(OutputStreamManager owner) {
             this.owner = owner;
         }
 
+        public void latch()  {
+            try {
+                latch.await();
+            } catch (InterruptedException ex) {
+                // Ignore the exception.
+            }
+        }
+
         public void shutdown() {
             shutdown = true;
         }
@@ -149,6 +177,7 @@ public class TCPSocketManager extends Ab
                         setOutputStream(newOS);
                         socket = sock;
                         connector = null;
+                        shutdown = true;
                     }
                     LOGGER.debug("Connection to " + host + ":" + port + " reestablished.");
                 } catch (InterruptedException ie) {
@@ -157,6 +186,8 @@ public class TCPSocketManager extends Ab
                     LOGGER.debug(host + ":" + port + " refused connection");
                 } catch (IOException ioe) {
                     LOGGER.debug("Unable to reconnect to " + host + ":" + port);
+                } finally {
+                    latch.countDown();
                 }
             }
         }
@@ -183,17 +214,27 @@ public class TCPSocketManager extends Ab
     private static class TCPSocketManagerFactory implements ManagerFactory<TCPSocketManager, FactoryData> {
 
         public TCPSocketManager createManager(String name, FactoryData data) {
+
+            InetAddress address;
+            OutputStream os = null;
             try {
-                InetAddress address = InetAddress.getByName(data.host);
-                Socket socket = new Socket(data.host, data.port);
-                OutputStream os = socket.getOutputStream();
-                return new TCPSocketManager(name, os, socket, address, data.host, data.port, data.delay);
+                address = InetAddress.getByName(data.host);
             } catch (UnknownHostException ex) {
                 LOGGER.error("Could not find address of " + data.host, ex);
+                return null;
+            }
+            try {
+                Socket socket = new Socket(data.host, data.port);
+                os = socket.getOutputStream();
+                return new TCPSocketManager(name, os, socket, address, data.host, data.port, data.delay);
             } catch (IOException ex) {
                 LOGGER.error("TCPSocketManager (" + name + ") " + ex);
+                os = new ByteArrayOutputStream();
+            }
+            if (data.delay == 0) {
+                return null;
             }
-            return null;
+            return new TCPSocketManager(name, os, null, address, data.host, data.port, data.delay);
         }
     }
 }

Added: logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/net/SocketTest.java
URL: http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/net/SocketTest.java?rev=1411311&view=auto
==============================================================================
--- logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/net/SocketTest.java (added)
+++ logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/net/SocketTest.java Mon Nov 19 17:05:30 2012
@@ -0,0 +1,155 @@
+package org.apache.logging.log4j.core.net;
+
+import java.io.BufferedReader;
+import java.io.IOException;
+import java.io.InputStream;
+import java.io.InputStreamReader;
+import java.net.ServerSocket;
+import java.net.Socket;
+import java.util.concurrent.Callable;
+import java.util.concurrent.ExecutorService;
+import java.util.concurrent.Executors;
+import java.util.concurrent.Future;
+
+import org.apache.logging.log4j.LogManager;
+import org.apache.logging.log4j.Logger;
+import org.apache.logging.log4j.core.appender.AppenderRuntimeException;
+import org.apache.logging.log4j.core.config.XMLConfigurationFactory;
+import org.junit.BeforeClass;
+import org.junit.Test;
+
+import static org.junit.Assert.assertEquals;
+import static org.junit.Assert.fail;
+
+public class SocketTest {
+    private static final int SOCKET_PORT = 5514;
+
+    private static final String CONFIG = "log4j-socket.xml";
+
+    @BeforeClass
+    public static void before() {
+        System.setProperty(XMLConfigurationFactory.CONFIGURATION_FILE_PROPERTY, CONFIG);
+    }
+
+    @Test
+    public void testConnect() throws Exception {
+        System.err.println("Initializing logger");
+        Logger logger = null;
+        try {
+            logger = LogManager.getLogger(SocketTest.class);
+        } catch (NullPointerException e) {
+            fail("Unexpected exception; should not occur until first logging statement " + e.getMessage());
+        }
+
+        String message = "Log #1";
+        try {
+            logger.error(message);
+            fail("Expected exception not thrown");
+        } catch (AppenderRuntimeException e) {
+            //System.err.println("Expected exception here, but already errored out when initializing logger");
+        }
+    }
+
+    @Test
+    public void testReconnect() throws Exception {
+        TestSocketServer testServer = null;
+        ExecutorService executor = null;
+        Future<InputStream> futureIn;
+        InputStream in;
+
+        try {
+            executor = Executors.newSingleThreadExecutor();
+            System.err.println("Initializing server");
+            testServer = new TestSocketServer();
+            futureIn = executor.submit(testServer);
+            Thread.sleep(300);
+
+            //System.err.println("Initializing logger");
+            Logger logger = LogManager.getLogger(SocketTest.class);
+
+            String message = "Log #1";
+            logger.error(message);
+
+            BufferedReader reader = new BufferedReader(new InputStreamReader(futureIn.get()));
+            assertEquals(message, reader.readLine());
+
+            closeQuietly(testServer);
+
+            message = "Log #2";
+            logger.error(message);
+
+            message = "Log #3";
+            try {
+                logger.error(message);
+            } catch (AppenderRuntimeException e) {
+                // System.err.println("Caught expected exception");
+            }
+
+            //System.err.println("Re-initializing server");
+            testServer = new TestSocketServer();
+            futureIn = executor.submit(testServer);
+            Thread.sleep(500);
+
+            try {
+                logger.error(message);
+                reader = new BufferedReader(new InputStreamReader(futureIn.get()));
+                assertEquals(message, reader.readLine());
+            } catch (AppenderRuntimeException e) {
+                e.printStackTrace();
+                fail("Unexpected Exception");
+            }
+            //System.err.println("Sleeping to demonstrate repeated re-connections");
+            //Thread.sleep(5000);
+        } finally {
+            closeQuietly(testServer);
+            closeQuietly(executor);
+        }
+    }
+
+
+    private static class TestSocketServer implements Callable<InputStream> {
+        private ServerSocket server;
+        private Socket client;
+
+        public InputStream call() throws Exception {
+            server = new ServerSocket(SOCKET_PORT);
+            client = server.accept();
+            return client.getInputStream();
+        }
+
+        public void close() {
+            closeQuietly(client);
+            closeQuietly(server);
+        }
+
+        private void closeQuietly(ServerSocket socket) {
+            if (null != socket) {
+                try {
+                    socket.close();
+                } catch (IOException ignore) {
+                }
+            }
+        }
+
+        private void closeQuietly(Socket socket) {
+            if (null != socket) {
+                try {
+                    socket.close();
+                } catch (IOException ignore) {
+                }
+            }
+        }
+    }
+
+    private static void closeQuietly(ExecutorService executor) {
+        if (null != executor) {
+            executor.shutdownNow();
+        }
+    }
+
+    private static void closeQuietly(TestSocketServer testServer) {
+        if (null != testServer) {
+            testServer.close();
+        }
+    }
+}

Added: logging/log4j/log4j2/trunk/core/src/test/resources/log4j-socket.xml
URL: http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/core/src/test/resources/log4j-socket.xml?rev=1411311&view=auto
==============================================================================
--- logging/log4j/log4j2/trunk/core/src/test/resources/log4j-socket.xml (added)
+++ logging/log4j/log4j2/trunk/core/src/test/resources/log4j-socket.xml Mon Nov 19 17:05:30 2012
@@ -0,0 +1,14 @@
+<?xml version="1.0" encoding="UTF-8"?>
+<configuration status="debug" name="MyApp">
+	<appenders>
+		<Socket name="socket" host="localhost" port="5514" protocol="TCP" suppressExceptions="false"
+				reconnectionDelay="250">
+			<PatternLayout pattern="%msg%n"/>
+		</Socket>
+	</appenders>
+	<loggers>
+		<root level="debug">
+			<appender-ref ref="socket"/>
+		</root>
+	</loggers>
+</configuration>
\ No newline at end of file

Modified: logging/log4j/log4j2/trunk/src/changes/changes.xml
URL: http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/src/changes/changes.xml?rev=1411311&r1=1411310&r2=1411311&view=diff
==============================================================================
--- logging/log4j/log4j2/trunk/src/changes/changes.xml (original)
+++ logging/log4j/log4j2/trunk/src/changes/changes.xml Mon Nov 19 17:05:30 2012
@@ -23,6 +23,12 @@
 
   <body>
     <release version="2.0-beta4" date="TBD" description="Bug fixes and enhancements">
+      <action issue="LOG4J2-120" dev="rgoers" type="fix">
+        TCPSocketManager would fail if the initial connection could not be established.
+      </action>
+      <action issue="LOG4J2-119" dev="rgoers" type="fix">
+        A broken socket connection would cause the TCPSocketManager to continuously reconnect.
+      </action>
       <action issue="LOG4J2-123" dev="rgoers" type="fix" due-to="Olivier Lamy">
         The example for ThreadContextMapFilter was incorrect.
       </action>