Author: rgoers
Date: Sat Apr 20 05:58:22 2013
New Revision: 1470110
URL: http://svn.apache.org/r1470110
Log:
LOG4J2-205 - Fix deadlock in SocketAppender. Added option to not wait for
socket reconnect.
Modified:
logging/log4j/log4j2/trunk/core/src/main/java/org/apache/logging/log4j/core/appender/SocketAppender.java
logging/log4j/log4j2/trunk/core/src/main/java/org/apache/logging/log4j/core/appender/SyslogAppender.java
logging/log4j/log4j2/trunk/core/src/main/java/org/apache/logging/log4j/core/net/TCPSocketManager.java
logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/appender/SocketAppenderTest.java
logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/appender/SyslogAppenderTest.java
logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/net/SocketServerTest.java
logging/log4j/log4j2/trunk/src/changes/changes.xml
logging/log4j/log4j2/trunk/src/site/xdoc/manual/appenders.xml
Modified:
logging/log4j/log4j2/trunk/core/src/main/java/org/apache/logging/log4j/core/appender/SocketAppender.java
URL:
http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/core/src/main/java/org/apache/logging/log4j/core/appender/SocketAppender.java?rev=1470110&r1=1470109&r2=1470110&view=diff
==============================================================================
---
logging/log4j/log4j2/trunk/core/src/main/java/org/apache/logging/log4j/core/appender/SocketAppender.java
(original)
+++
logging/log4j/log4j2/trunk/core/src/main/java/org/apache/logging/log4j/core/appender/SocketAppender.java
Sat Apr 20 05:58:22 2013
@@ -71,6 +71,7 @@ public class SocketAppender extends Abst
* @param portNum The port to connect to on the target host.
* @param protocol The Protocol to use.
* @param delay The interval in which failed writes should be retried.
+ * @param immediateFail True if the write should fail if no socket is
immediately available.
* @param name The name of the Appender.
* @param immediateFlush "true" if data should be flushed on each write.
* @param suppress "true" if exceptions should be hidden from the
application, "false" otherwise.
@@ -78,7 +79,7 @@ public class SocketAppender extends Abst
* @param layout The layout to use (defaults to SerializedLayout).
* @param filter The Filter or null.
* @param advertise "true" if the appender configuration should be
advertised, "false" otherwise.
- * @param config The Configuration
+ * @param config The Configuration
* @return A SocketAppender.
*/
@PluginFactory
@@ -86,6 +87,7 @@ public class SocketAppender extends Abst
@PluginAttr("port") final
String portNum,
@PluginAttr("protocol") final
String protocol,
@PluginAttr("reconnectionDelay") final String delay,
+ @PluginAttr("immediateFail")
final String immediateFail,
@PluginAttr("name") final
String name,
@PluginAttr("immediateFlush")
final String immediateFlush,
@PluginAttr("suppressExceptions") final String suppress,
@@ -97,6 +99,7 @@ public class SocketAppender extends Abst
final boolean isFlush = immediateFlush == null ? true :
Boolean.valueOf(immediateFlush);
boolean isAdvertise = advertise == null ? false :
Boolean.valueOf(advertise);
final boolean handleExceptions = suppress == null ? true :
Boolean.valueOf(suppress);
+ final boolean fail = immediateFail == null ? true :
Boolean.valueOf(immediateFail);
final int reconnectDelay = delay == null ? 0 : Integer.parseInt(delay);
final int port = portNum == null ? 0 : Integer.parseInt(portNum);
if (layout == null) {
@@ -110,7 +113,7 @@ public class SocketAppender extends Abst
final String prot = protocol != null ? protocol : Protocol.TCP.name();
- final AbstractSocketManager manager = createSocketManager(prot, host,
port, reconnectDelay);
+ final AbstractSocketManager manager = createSocketManager(prot, host,
port, reconnectDelay, fail);
if (manager == null) {
return null;
}
@@ -119,11 +122,11 @@ public class SocketAppender extends Abst
}
protected static AbstractSocketManager createSocketManager(final String
protocol, final String host, final int port,
- final int
delay) {
+ final int
delay, final boolean immediateFail) {
final Protocol p = EnglishEnums.valueOf(Protocol.class, protocol);
switch (p) {
case TCP:
- return TCPSocketManager.getSocketManager(host, port, delay);
+ return TCPSocketManager.getSocketManager(host, port, delay,
immediateFail);
case UDP:
return DatagramSocketManager.getSocketManager(host, port);
default:
Modified:
logging/log4j/log4j2/trunk/core/src/main/java/org/apache/logging/log4j/core/appender/SyslogAppender.java
URL:
http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/core/src/main/java/org/apache/logging/log4j/core/appender/SyslogAppender.java?rev=1470110&r1=1470109&r2=1470110&view=diff
==============================================================================
---
logging/log4j/log4j2/trunk/core/src/main/java/org/apache/logging/log4j/core/appender/SyslogAppender.java
(original)
+++
logging/log4j/log4j2/trunk/core/src/main/java/org/apache/logging/log4j/core/appender/SyslogAppender.java
Sat Apr 20 05:58:22 2013
@@ -52,6 +52,7 @@ public class SyslogAppender extends Sock
* @param portNum The port to connect to on the target host.
* @param protocol The Protocol to use.
* @param delay The interval in which failed writes should be retried.
+ * @param immediateFail True if the write should fail if no socket is
immediately available.
* @param name The name of the Appender.
* @param immediateFlush "true" if data should be flushed on each write.
* @param suppress "true" if exceptions should be hidden from the
application, "false" otherwise.
@@ -84,6 +85,7 @@ public class SyslogAppender extends Sock
@PluginAttr("port") final
String portNum,
@PluginAttr("protocol") final
String protocol,
@PluginAttr("reconnectionDelay") final String delay,
+ @PluginAttr("immediateFail")
final String immediateFail,
@PluginAttr("name") final
String name,
@PluginAttr("immediateFlush")
final String immediateFlush,
@PluginAttr("suppressExceptions") final String suppress,
@@ -111,6 +113,7 @@ public class SyslogAppender extends Sock
final boolean isFlush = immediateFlush == null ? true :
Boolean.valueOf(immediateFlush);
final boolean handleExceptions = suppress == null ? true :
Boolean.valueOf(suppress);
final int reconnectDelay = delay == null ? 0 : Integer.parseInt(delay);
+ final boolean fail = immediateFail == null ? true :
Boolean.valueOf(immediateFail);
final int port = portNum == null ? 0 : Integer.parseInt(portNum);
boolean isAdvertise = advertise == null ? false :
Boolean.valueOf(advertise);
final Layout<String> layout = RFC5424.equalsIgnoreCase(format) ?
@@ -123,7 +126,7 @@ public class SyslogAppender extends Sock
return null;
}
final String prot = protocol != null ? protocol : Protocol.UDP.name();
- final AbstractSocketManager manager = createSocketManager(prot, host,
port, reconnectDelay);
+ final AbstractSocketManager manager = createSocketManager(prot, host,
port, reconnectDelay, fail);
if (manager == null) {
return null;
}
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=1470110&r1=1470109&r2=1470110&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
Sat Apr 20 05:58:22 2013
@@ -54,6 +54,8 @@ public class TCPSocketManager extends Ab
private final boolean retry;
+ private final boolean immediateFail;
+
/**
* The Constructor.
* @param name The unique name of this connection.
@@ -65,10 +67,11 @@ public class TCPSocketManager extends Ab
* @param delay Reconnection interval.
*/
public TCPSocketManager(final String name, final OutputStream os, final
Socket sock, final InetAddress addr,
- final String host, final int port, final int
delay) {
+ final String host, final int port, final int
delay, final boolean immediateFail) {
super(name, os, addr, host, port);
this.reconnectionDelay = delay;
this.socket = sock;
+ this.immediateFail = immediateFail;
retry = delay > 0;
if (sock == null) {
connector = new Reconnector(this);
@@ -85,7 +88,7 @@ public class TCPSocketManager extends Ab
* @param delay The interval to pause between retries.
* @return A TCPSocketManager.
*/
- public static TCPSocketManager getSocketManager(final String host, int
port, int delay) {
+ public static TCPSocketManager getSocketManager(final String host, int
port, int delay, boolean immediateFail) {
if (host == null || host.length() == 0) {
throw new IllegalArgumentException("A host name is required");
}
@@ -95,13 +98,14 @@ public class TCPSocketManager extends Ab
if (delay == 0) {
delay = DEFAULT_RECONNECTION_DELAY;
}
- return (TCPSocketManager) getManager("TCP:" + host + ":" + port, new
FactoryData(host, port, delay), FACTORY);
+ return (TCPSocketManager) getManager("TCP:" + host + ":" + port,
+ new FactoryData(host, port, delay, immediateFail), FACTORY);
}
@Override
- protected synchronized void write(final byte[] bytes, final int offset,
final int length) {
+ protected void write(final byte[] bytes, final int offset, final int
length) {
if (socket == null) {
- if (connector != null) {
+ if (connector != null && !immediateFail) {
connector.latch();
}
if (socket == null) {
@@ -109,17 +113,19 @@ public class TCPSocketManager extends Ab
throw new AppenderRuntimeException(msg);
}
}
- try {
- getOutputStream().write(bytes, offset, length);
- } catch (final IOException ex) {
- if (retry && connector == null) {
- connector = new Reconnector(this);
- connector.setDaemon(true);
- connector.setPriority(Thread.MIN_PRIORITY);
- connector.start();
+ synchronized (this) {
+ try {
+ getOutputStream().write(bytes, offset, length);
+ } catch (final IOException ex) {
+ if (retry && connector == null) {
+ connector = new Reconnector(this);
+ connector.setDaemon(true);
+ connector.setPriority(Thread.MIN_PRIORITY);
+ connector.start();
+ }
+ final String msg = "Error writing to " + getName();
+ throw new AppenderRuntimeException(msg, ex);
}
- final String msg = "Error writing to " + getName();
- throw new AppenderRuntimeException(msg, ex);
}
}
@@ -146,7 +152,7 @@ public class TCPSocketManager extends Ab
result.put("direction", "out");
return result;
}
-
+
/**
* Handles reconnecting to a Thread.
*/
@@ -214,11 +220,13 @@ public class TCPSocketManager extends Ab
private final String host;
private final int port;
private final int delay;
+ private final boolean immediateFail;
- public FactoryData(final String host, final int port, final int delay)
{
+ public FactoryData(final String host, final int port, final int delay,
final boolean immediateFail) {
this.host = host;
this.port = port;
this.delay = delay;
+ this.immediateFail = immediateFail;
}
}
@@ -240,7 +248,8 @@ public class TCPSocketManager extends Ab
try {
final Socket socket = new Socket(data.host, data.port);
os = socket.getOutputStream();
- return new TCPSocketManager(name, os, socket, address,
data.host, data.port, data.delay);
+ return new TCPSocketManager(name, os, socket, address,
data.host, data.port, data.delay,
+ data.immediateFail);
} catch (final IOException ex) {
LOGGER.error("TCPSocketManager (" + name + ") " + ex);
os = new ByteArrayOutputStream();
@@ -248,7 +257,7 @@ public class TCPSocketManager extends Ab
if (data.delay == 0) {
return null;
}
- return new TCPSocketManager(name, os, null, address, data.host,
data.port, data.delay);
+ return new TCPSocketManager(name, os, null, address, data.host,
data.port, data.delay, data.immediateFail);
}
}
}
Modified:
logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/appender/SocketAppenderTest.java
URL:
http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/appender/SocketAppenderTest.java?rev=1470110&r1=1470109&r2=1470110&view=diff
==============================================================================
---
logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/appender/SocketAppenderTest.java
(original)
+++
logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/appender/SocketAppenderTest.java
Sat Apr 20 05:58:22 2013
@@ -43,6 +43,7 @@ import java.util.concurrent.TimeUnit;
import static org.junit.Assert.assertTrue;
import static org.junit.Assert.assertNotNull;
+import static org.junit.Assert.fail;
/**
*
@@ -51,7 +52,10 @@ public class SocketAppenderTest {
private static final String HOST = "localhost";
private static final String PORT = "8199";
- private static final int PORTNUM = Integer.parseInt(PORT);
+ private static final String DYN_PORT = "8300";
+ private static final String ERROR_PORT = "8301";
+ private static final int PORTNUM1 = Integer.parseInt(PORT);
+ private static final int PORTNUM2 = Integer.parseInt(DYN_PORT);
private static BlockingQueue<LogEvent> list = new
ArrayBlockingQueue<LogEvent>(10);
@@ -66,7 +70,7 @@ public class SocketAppenderTest {
@BeforeClass
public static void setupClass() throws Exception {
- tcp = new TCPSocketServer();
+ tcp = new TCPSocketServer(PORTNUM1);
tcp.start();
udp = new UDPSocketServer();
udp.start();
@@ -97,7 +101,7 @@ public class SocketAppenderTest {
public void testTCPAppender() throws Exception {
final SocketAppender appender =
SocketAppender.createAppender("localhost", PORT, "tcp", "-1",
- "Test", null, null, null, null, null, null);
+ "false", "Test", null, null, null, null, null, null);
appender.start();
// set appender on root and set level to debug
@@ -125,7 +129,7 @@ public class SocketAppenderTest {
public void testUDPAppender() throws Exception {
final SocketAppender appender =
SocketAppender.createAppender("localhost", PORT, "udp", "-1",
- "Test", null, null, null, null, null, null);
+ "false", "Test", null, null, null, null, null, null);
appender.start();
// set appender on root and set level to debug
@@ -139,13 +143,52 @@ public class SocketAppenderTest {
assertTrue("Message not delivered via UDP", udpCount > 0);
}
+ @Test
+ public void testTcpAppenderDeadlock() throws Exception {
+
+ final SocketAppender appender =
SocketAppender.createAppender("localhost", DYN_PORT, "tcp", "10000",
+ "false", "Test", null, null, null, null, null, null);
+ appender.start();
+ // set appender on root and set level to debug
+ root.addAppender(appender);
+ root.setAdditive(false);
+ root.setLevel(Level.DEBUG);
+
+ new TCPSocketServer(PORTNUM2).start();
+
+ root.debug("This message is written because a deadlock never.");
+
+ LogEvent event = list.poll(3, TimeUnit.SECONDS);
+ assertNotNull("No event retrieved", event);
+ }
+
+ @Test
+ public void testTcpAppenderNoWait() throws Exception {
+
+ final SocketAppender appender =
SocketAppender.createAppender("localhost", ERROR_PORT, "tcp", "10000",
+ "true", "Test", null, "false", null, null, null, null);
+ appender.start();
+ // set appender on root and set level to debug
+ root.addAppender(appender);
+ root.setAdditive(false);
+ root.setLevel(Level.DEBUG);
+
+ try {
+ root.debug("This message is written because a deadlock never.");
+ fail("No Exception was thrown");
+ } catch (Exception ex) {
+ // Failure is expected.
+ }
+ }
+
+
public static class UDPSocketServer extends Thread {
private final DatagramSocket sock;
private boolean shutdown = false;
private Thread thread;
public UDPSocketServer() throws IOException {
- this.sock = new DatagramSocket(PORTNUM);
+ this.sock = new DatagramSocket(PORTNUM1);
}
public void shutdown() {
@@ -178,8 +221,8 @@ public class SocketAppenderTest {
private final ServerSocket sock;
private boolean shutdown = false;
- public TCPSocketServer() throws IOException {
- this.sock = new ServerSocket(PORTNUM);
+ public TCPSocketServer(int port) throws IOException {
+ this.sock = new ServerSocket(port);
}
public void shutdown() {
Modified:
logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/appender/SyslogAppenderTest.java
URL:
http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/appender/SyslogAppenderTest.java?rev=1470110&r1=1470109&r2=1470110&view=diff
==============================================================================
---
logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/appender/SyslogAppenderTest.java
(original)
+++
logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/appender/SyslogAppenderTest.java
Sat Apr 20 05:58:22 2013
@@ -210,7 +210,7 @@ public class SyslogAppenderTest {
}
private SyslogAppender createAppender(final String protocol, final String
format) {
- return SyslogAppender.createAppender("localhost", PORT, protocol,
"-1", "Test", "true", "false", "LOCAL0", "Audit",
+ return SyslogAppender.createAppender("localhost", PORT, protocol,
"-1", null, "Test", "true", "false", "LOCAL0", "Audit",
"18060", "true", "RequestContext", null, null, "true", null,
"TestApp", "Test", null, "ipAddress,loginId",
null, format, null, null, null, null, null);
}
Modified:
logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/net/SocketServerTest.java
URL:
http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/net/SocketServerTest.java?rev=1470110&r1=1470109&r2=1470110&view=diff
==============================================================================
---
logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/net/SocketServerTest.java
(original)
+++
logging/log4j/log4j2/trunk/core/src/test/java/org/apache/logging/log4j/core/net/SocketServerTest.java
Sat Apr 20 05:58:22 2013
@@ -92,7 +92,7 @@ public class SocketServerTest {
final Filter socketFilter = new ThreadFilter(Filter.Result.NEUTRAL,
Filter.Result.DENY);
final Filter serverFilter = new ThreadFilter(Filter.Result.DENY,
Filter.Result.NEUTRAL);
final SocketAppender appender =
SocketAppender.createAppender("localhost", PORT, "tcp", "-1",
- "Test", null, null, null, socketFilter, null, null);
+ null, "Test", null, null, null, socketFilter, null, null);
appender.start();
final ListAppender listApp = new ListAppender("Events", serverFilter,
null, false, false);
listApp.start();
Modified: logging/log4j/log4j2/trunk/src/changes/changes.xml
URL:
http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/src/changes/changes.xml?rev=1470110&r1=1470109&r2=1470110&view=diff
==============================================================================
--- logging/log4j/log4j2/trunk/src/changes/changes.xml (original)
+++ logging/log4j/log4j2/trunk/src/changes/changes.xml Sat Apr 20 05:58:22 2013
@@ -23,6 +23,9 @@
<body>
<release version="2.0-beta5" date="@TBD@" description="Bug fixes and
enhancements">
+ <action issue="LOG4J2-205" dev="rgoers" type="fix">
+ Fix deadlock in SocketAppender. Added option to not wait for socket
reconnect.
+ </action>
<action issue="LOG4J2-207" dev="rgoers" type="add" due-to="Remko Popma">
Add JMX support.
</action>
Modified: logging/log4j/log4j2/trunk/src/site/xdoc/manual/appenders.xml
URL:
http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/src/site/xdoc/manual/appenders.xml?rev=1470110&r1=1470109&r2=1470110&view=diff
==============================================================================
--- logging/log4j/log4j2/trunk/src/site/xdoc/manual/appenders.xml (original)
+++ logging/log4j/log4j2/trunk/src/site/xdoc/manual/appenders.xml Sat Apr 20
05:58:22 2013
@@ -1373,7 +1373,7 @@
instead of a
<tt>BufferedOutputStream</tt>.
We saw a 20-200% performance
improvement compared to
- FileAppender with "bufferedIO=true" in
our
+ FileAppender with "bufferedIO=true" in
our
<a
href="async.html#FastFileAppenderPerformance">measurements</a>.
Similar to the FileAppender,
FastFileAppender uses a FastFileManager
to actually perform the
@@ -1485,9 +1485,9 @@
<tt>BufferedOutputStream</tt>.
We saw a 20-200% performance
improvement compared to
RollingFileAppender with
"bufferedIO=true"
- in our
+ in our
<a
href="async.html#FastFileAppenderPerformance">measurements</a>.
-
+
The FastRollingFileAppender writes
to the File named in the
fileName parameter
@@ -1496,7 +1496,7 @@
and the RolloverPolicy.
Similar to the RollingFileAppender,
- FastRollingFileAppender uses a
FastRollingFileManager
+ FastRollingFileAppender uses a
FastRollingFileManager
to actually perform the
file I/O and perform the rollover.
While FastRollingFileAppender
from different Configurations cannot be
@@ -1569,7 +1569,7 @@
<a
href="http://download.oracle.com/javase/6/docs/api/java/text/SimpleDateFormat.html";>
SimpleDateFormat</a>
-
+
and/or a %i which
represents an integer counter. The pattern
also supports
interpolation at
runtime so any of the
Lookups (such
@@ -1980,6 +1980,12 @@
<td>The name or address of the system that is listening for log
events. This parameter is required.</td>
</tr>
<tr>
+ <td>immediateFail</td>
+ <td>boolean</td>
+ <td>When set to true, log events will not wait to try to
reconnect and will fail immediately if the
+ socket is not available.</td>
+ </tr>
+ <tr>
<td>immediateFlush</td>
<td>boolean</td>
<td>When set to true, each write will be followed by a flush.
This will guarantee the data is written
@@ -2102,6 +2108,12 @@
a StructuredDataMessage the id from the Message will be used
instead of this value.</td>
</tr>
<tr>
+ <td>immediateFail</td>
+ <td>boolean</td>
+ <td>When set to true, log events will not wait to try to
reconnect and will fail immediately if the
+ socket is not available.</td>
+ </tr>
+ <tr>
<td>immediateFlush</td>
<td>boolean</td>
<td>When set to true, each write will be followed by a flush.
This will guarantee the data is written
