Uploaded image for project: 'Log4j 2'
  1. Log4j 2
  2. LOG4J2-1042

Socket and Syslog appenders don't take timeout into account at startup

    Details

    • Type: Bug
    • Status: Closed
    • Priority: Minor
    • Resolution: Fixed
    • Affects Version/s: 2.3
    • Fix Version/s: 2.4
    • Component/s: Appenders
    • Labels:
      None
    • Environment:

      Tested on ubuntu 14.04, with java:

      java version "1.7.0_79"
      OpenJDK Runtime Environment (IcedTea 2.5.5) (7u79-2.5.5-0ubuntu0.14.04.2)
      OpenJDK 64-Bit Server VM (build 24.79-b02, mixed mode)

      Description

      • Steps to reproduce:

      run this code

      import org.apache.logging.log4j.LogManager;
      import org.apache.logging.log4j.Logger;
      
      public class App
      {
      	private static final Logger _logger = LogManager.getLogger("TestLogger");
      
      	public static void main( String[] args )
      	{
      		_logger.error("some message");
      		System.out.println("Done");
      	}
      }
      

      with this config

      <?xml version="1.0" encoding="UTF-8"?>
      <Configuration status="WARN">
        <Appenders>
          <Syslog name="my-syslog" host="192.168.12.8" port="12201" protocol="TCP" format="RFC5424" mdcId="mdc" includeMDC="true" appName="testGTApp" newLine="true" connectTimeoutMillis="100" immediateFail="true" reconnectionDelayMillis="3000" immediateFlush="true" />
        </Appenders>
        <Loggers>
          <Root level="info">
            <AppenderRef ref="my-syslog"/>
          </Root>
        </Loggers>
      </Configuration>
      

      where 192.168.12.8 is a host that actually exist (it can be pinged), but nothing is listening on this port.
      (for some reason I don't completely understand, the host must not be localhost; otherwise we correctly get the expected behavior)

      • Expected result:
        • log4j2 gives up trying to connect to the server after the specified timeout (here: 100ms)
        • the program prints "Done" on the console, and exits
      • Actual result: the program doesn't print anything, and hangs forever.

      A thread dump shows

      "main" prio=10 tid=0x00007f8eac00a000 nid=0x2ca1 runnable [0x00007f8eb455a000]
         java.lang.Thread.State: RUNNABLE
      	at java.net.PlainSocketImpl.socketConnect(Native Method)
      	at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:339)
      	- locked <0x00000007d94f5e38> (a java.net.SocksSocketImpl)
      	at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:200)
      	at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:182)
      	at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392)
      	at java.net.Socket.connect(Socket.java:579)
      	at java.net.Socket.connect(Socket.java:528)
      	at java.net.Socket.<init>(Socket.java:425)
      	at java.net.Socket.<init>(Socket.java:208)
      	at org.apache.logging.log4j.core.net.TcpSocketManager$TcpSocketManagerFactory.createManager(TcpSocketManager.java:285)
      	at org.apache.logging.log4j.core.net.TcpSocketManager$TcpSocketManagerFactory.createManager(TcpSocketManager.java:272)
      	at org.apache.logging.log4j.core.appender.AbstractManager.getManager(AbstractManager.java:71)
      	at org.apache.logging.log4j.core.appender.OutputStreamManager.getManager(OutputStreamManager.java:60)
      	at org.apache.logging.log4j.core.net.TcpSocketManager.getSocketManager(TcpSocketManager.java:114)
      	at org.apache.logging.log4j.core.appender.SocketAppender.createSocketManager(SocketAppender.java:173)
      	at org.apache.logging.log4j.core.appender.SyslogAppender.createAppender(SyslogAppender.java:145)
      
      • potential fix:
        With the following patch, I get the expected result, along with a logged "Error writing to TCP:192.168.12.8:12201 socket not available":
      diff --git i/log4j-core/src/main/java/org/apache/logging/log4j/core/net/TcpSocketManager.java w/log4j-core/src/main/java/org/apache/logging/log4j/core/net/TcpSocketManager.java
      index 9ab9f5f..0ba8d8a 100644
      --- i/log4j-core/src/main/java/org/apache/logging/log4j/core/net/TcpSocketManager.java
      +++ w/log4j-core/src/main/java/org/apache/logging/log4j/core/net/TcpSocketManager.java
      @@ -282,7 +282,8 @@ public class TcpSocketManager extends AbstractSocketManager {
                       return null;
                   }
                   try {
      -                final Socket socket = new Socket(data.host, data.port);
      +               final Socket socket = new Socket();
      +               socket.connect(new InetSocketAddress(data.host, data.port), data.connectTimeoutMillis);
                       os = socket.getOutputStream();
                       return new TcpSocketManager(name, os, socket, inetAddress, data.host, data.port,
                               data.connectTimeoutMillis, data.delayMillis, data.immediateFail, data.layout);
      

        Attachments

          Activity

            People

            • Assignee:
              Unassigned
              Reporter:
              gturri Guillaume Turri
            • Votes:
              0 Vote for this issue
              Watchers:
              2 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved: