Details
Minor 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);