From 2ef23a672504cec68b2c194527750c19e8caf42b Mon Sep 17 00:00:00 2001 From: Greg Wilkins Date: Wed, 23 Nov 2016 16:56:58 +1100 Subject: [PATCH] Issue #572 Improved to the toString and dump output of connections, endpoints and channel to assist with debugging made the SSL callbacks and runnables Invocable to avoid thread starvation. --- .../client/http/HttpConnectionOverHTTP.java | 16 ++-- .../client/http/HttpConnectionOverFCGI.java | 14 ++-- .../eclipse/jetty/io/AbstractConnection.java | 17 ++-- .../eclipse/jetty/io/AbstractEndPoint.java | 23 +++-- .../org/eclipse/jetty/io/ChannelEndPoint.java | 15 +++- .../org/eclipse/jetty/io/ManagedSelector.java | 5 ++ .../org/eclipse/jetty/io/WriteFlusher.java | 8 +- .../eclipse/jetty/io/ssl/SslConnection.java | 83 +++++++++++++++---- .../eclipse/jetty/proxy/ProxyConnection.java | 11 +-- .../eclipse/jetty/server/HttpConnection.java | 7 +- .../jetty/server/ThreadStarvationTest.java | 4 +- .../io/AbstractWebSocketConnection.java | 9 +- 12 files changed, 150 insertions(+), 62 deletions(-) diff --git a/jetty-client/src/main/java/org/eclipse/jetty/client/http/HttpConnectionOverHTTP.java b/jetty-client/src/main/java/org/eclipse/jetty/client/http/HttpConnectionOverHTTP.java index 15629570add..50945e9fbf9 100644 --- a/jetty-client/src/main/java/org/eclipse/jetty/client/http/HttpConnectionOverHTTP.java +++ b/jetty-client/src/main/java/org/eclipse/jetty/client/http/HttpConnectionOverHTTP.java @@ -182,15 +182,15 @@ public class HttpConnectionOverHTTP extends AbstractConnection implements Connec } @Override - public String toString() + public String toConnectionString() { - return String.format("%s@%h(l:%s <-> r:%s,closed=%b)[%s]", - getClass().getSimpleName(), - this, - getEndPoint().getLocalAddress(), - getEndPoint().getRemoteAddress(), - closed.get(), - channel); + return String.format("%s@%x(l:%s <-> r:%s,closed=%b)=>%s", + getClass().getSimpleName(), + hashCode(), + getEndPoint().getLocalAddress(), + getEndPoint().getRemoteAddress(), + closed.get(), + channel); } private class Delegate extends HttpConnection diff --git a/jetty-fcgi/fcgi-client/src/main/java/org/eclipse/jetty/fcgi/client/http/HttpConnectionOverFCGI.java b/jetty-fcgi/fcgi-client/src/main/java/org/eclipse/jetty/fcgi/client/http/HttpConnectionOverFCGI.java index cf0954eecd7..e62bab745ef 100644 --- a/jetty-fcgi/fcgi-client/src/main/java/org/eclipse/jetty/fcgi/client/http/HttpConnectionOverFCGI.java +++ b/jetty-fcgi/fcgi-client/src/main/java/org/eclipse/jetty/fcgi/client/http/HttpConnectionOverFCGI.java @@ -292,15 +292,15 @@ public class HttpConnectionOverFCGI extends AbstractConnection implements Connec } @Override - public String toString() + public String toConnectionString() { - return String.format("%s@%h(l:%s <-> r:%s)", - getClass().getSimpleName(), - this, - getEndPoint().getLocalAddress(), - getEndPoint().getRemoteAddress()); + return String.format("%s@%x[l:%s<->r:%s]", + getClass().getSimpleName(), + hashCode(), + getEndPoint().getLocalAddress(), + getEndPoint().getRemoteAddress()); } - + private class Delegate extends HttpConnection { private Delegate(HttpDestination destination) diff --git a/jetty-io/src/main/java/org/eclipse/jetty/io/AbstractConnection.java b/jetty-io/src/main/java/org/eclipse/jetty/io/AbstractConnection.java index e0c97481d82..cac0e124cbd 100644 --- a/jetty-io/src/main/java/org/eclipse/jetty/io/AbstractConnection.java +++ b/jetty-io/src/main/java/org/eclipse/jetty/io/AbstractConnection.java @@ -249,12 +249,16 @@ public abstract class AbstractConnection implements Connection } @Override - public String toString() + public final String toString() { - return String.format("%s@%x[%s]", - getClass().getSimpleName(), - hashCode(), - _endPoint); + return String.format("%s<-%s",toConnectionString(),getEndPoint()); + } + + public String toConnectionString() + { + return String.format("%s@%h", + getClass().getSimpleName(), + this); } private class ReadCallback implements Callback @@ -274,7 +278,8 @@ public abstract class AbstractConnection implements Connection @Override public String toString() { - return String.format("AC.ReadCB@%x{%s}", AbstractConnection.this.hashCode(),AbstractConnection.this); + return String.format("AC.ReadCB@%h{%s}", AbstractConnection.this,AbstractConnection.this); } } + } diff --git a/jetty-io/src/main/java/org/eclipse/jetty/io/AbstractEndPoint.java b/jetty-io/src/main/java/org/eclipse/jetty/io/AbstractEndPoint.java index 8fce610f8b6..c34b88b1e9e 100644 --- a/jetty-io/src/main/java/org/eclipse/jetty/io/AbstractEndPoint.java +++ b/jetty-io/src/main/java/org/eclipse/jetty/io/AbstractEndPoint.java @@ -427,6 +427,11 @@ public abstract class AbstractEndPoint extends IdleTimeout implements EndPoint @Override public String toString() + { + return String.format("%s->%s",toEndPointString(),toConnectionString()); + } + + public String toEndPointString() { Class c=getClass(); String name=c.getSimpleName(); @@ -436,20 +441,26 @@ public abstract class AbstractEndPoint extends IdleTimeout implements EndPoint name=c.getSimpleName(); } - Connection connection = getConnection(); - return String.format("%s@%x{%s<->%s,%s,%s|%s,%d/%d,%s@%x}", + return String.format("%s@%h{%s<->%s,%s,fill=%s,flush=%s,to=%d/%d}", name, - hashCode(), + this, getRemoteAddress(), getLocalAddress(), _state.get(), _fillInterest.toStateString(), _writeFlusher.toStateString(), getIdleFor(), - getIdleTimeout(), - connection == null ? null : connection.getClass().getSimpleName(), - connection == null ? 0 : connection.hashCode()); + getIdleTimeout()); } + + public String toConnectionString() + { + Connection connection = getConnection(); + if (connection instanceof AbstractConnection) + return ((AbstractConnection)connection).toConnectionString(); + return String.format("%s@%x",connection.getClass().getSimpleName(),connection.hashCode()); + } + private enum State { diff --git a/jetty-io/src/main/java/org/eclipse/jetty/io/ChannelEndPoint.java b/jetty-io/src/main/java/org/eclipse/jetty/io/ChannelEndPoint.java index 5fad2bcc95d..4b176782572 100644 --- a/jetty-io/src/main/java/org/eclipse/jetty/io/ChannelEndPoint.java +++ b/jetty-io/src/main/java/org/eclipse/jetty/io/ChannelEndPoint.java @@ -60,7 +60,7 @@ public abstract class ChannelEndPoint extends AbstractEndPoint implements Manage private abstract class RunnableTask implements Runnable, Invocable { - private final String _operation; + final String _operation; protected RunnableTask(String op) { @@ -70,7 +70,7 @@ public abstract class ChannelEndPoint extends AbstractEndPoint implements Manage @Override public String toString() { - return ChannelEndPoint.this.toString()+":"+_operation; + return String.format("CEP:%s:%s:%s",ChannelEndPoint.this,_operation,getInvocationType()); } } @@ -138,6 +138,13 @@ public abstract class ChannelEndPoint extends AbstractEndPoint implements Manage { getWriteFlusher().completeWrite(); } + + @Override + public String toString() + { + return String.format("CEP:%s:%s:%s->%s",ChannelEndPoint.this,_operation,getInvocationType(),getWriteFlusher()); + } + }; private final Runnable _runCompleteWriteFillable = new RunnableCloseable("runCompleteWriteFillable") @@ -424,7 +431,7 @@ public abstract class ChannelEndPoint extends AbstractEndPoint implements Manage @Override - public String toString() + public String toEndPointString() { // We do a best effort to print the right toString() and that's it. try @@ -433,7 +440,7 @@ public abstract class ChannelEndPoint extends AbstractEndPoint implements Manage int keyInterests = valid ? _key.interestOps() : -1; int keyReadiness = valid ? _key.readyOps() : -1; return String.format("%s{io=%d/%d,kio=%d,kro=%d}", - super.toString(), + super.toEndPointString(), _currentInterestOps, _desiredInterestOps, keyInterests, diff --git a/jetty-io/src/main/java/org/eclipse/jetty/io/ManagedSelector.java b/jetty-io/src/main/java/org/eclipse/jetty/io/ManagedSelector.java index ffeeaeccf28..fa40e6e9561 100644 --- a/jetty-io/src/main/java/org/eclipse/jetty/io/ManagedSelector.java +++ b/jetty-io/src/main/java/org/eclipse/jetty/io/ManagedSelector.java @@ -838,4 +838,9 @@ public class ManagedSelector extends AbstractLifeCycle implements Dumpable } } } + + public Selector getSelector() + { + return _selector; + } } diff --git a/jetty-io/src/main/java/org/eclipse/jetty/io/WriteFlusher.java b/jetty-io/src/main/java/org/eclipse/jetty/io/WriteFlusher.java index 1ccbd04048b..99d43c4a5c3 100644 --- a/jetty-io/src/main/java/org/eclipse/jetty/io/WriteFlusher.java +++ b/jetty-io/src/main/java/org/eclipse/jetty/io/WriteFlusher.java @@ -275,6 +275,11 @@ abstract public class WriteFlusher { return Invocable.getInvocationType(_callback); } + + public Object getCallback() + { + return _callback; + } } public InvocationType getCallbackInvocationType() @@ -523,7 +528,8 @@ abstract public class WriteFlusher @Override public String toString() { - return String.format("WriteFlusher@%x{%s}", hashCode(), _state.get()); + State s = _state.get(); + return String.format("WriteFlusher@%x{%s}->%s", hashCode(), s,s instanceof PendingState?((PendingState)s).getCallback():null); } public String toStateString() diff --git a/jetty-io/src/main/java/org/eclipse/jetty/io/ssl/SslConnection.java b/jetty-io/src/main/java/org/eclipse/jetty/io/ssl/SslConnection.java index bec39111f58..8eb83faa785 100644 --- a/jetty-io/src/main/java/org/eclipse/jetty/io/ssl/SslConnection.java +++ b/jetty-io/src/main/java/org/eclipse/jetty/io/ssl/SslConnection.java @@ -44,6 +44,7 @@ import org.eclipse.jetty.util.BufferUtil; import org.eclipse.jetty.util.Callback; import org.eclipse.jetty.util.log.Log; import org.eclipse.jetty.util.log.Logger; +import org.eclipse.jetty.util.thread.Invocable; /** * A Connection that acts as an interceptor between an EndPoint providing SSL encrypted data @@ -93,21 +94,52 @@ public class SslConnection extends AbstractConnection private final boolean _decryptedDirectBuffers = false; private boolean _renegotiationAllowed; private boolean _closedOutbound; - private final Runnable _runCompletWrite = new Runnable() + + + private abstract class RunnableTask implements Runnable, Invocable + { + private final String _operation; + + protected RunnableTask(String op) + { + _operation=op; + } + + @Override + public String toString() + { + return String.format("SSL:%s:%s:%s",SslConnection.this,_operation,getInvocationType()); + } + } + + private final Runnable _runCompleteWrite = new RunnableTask("runCompleteWrite") { @Override public void run() { _decryptedEndPoint.getWriteFlusher().completeWrite(); } + + @Override + public InvocationType getInvocationType() + { + return getDecryptedEndPoint().getWriteFlusher().getCallbackInvocationType(); + } }; - private final Runnable _runFillable = new Runnable() + + private final Runnable _runFillable = new RunnableTask("runFillable") { @Override public void run() { _decryptedEndPoint.getFillInterest().fillable(); } + + @Override + public InvocationType getInvocationType() + { + return getDecryptedEndPoint().getFillInterest().getCallbackInvocationType(); + } }; Callback _sslReadCallback = new Callback() @@ -234,7 +266,7 @@ public class SslConnection extends AbstractConnection if (_decryptedEndPoint._flushRequiresFillToProgress) { _decryptedEndPoint._flushRequiresFillToProgress = false; - _runCompletWrite.run(); + _runCompleteWrite.run(); } } @@ -266,7 +298,7 @@ public class SslConnection extends AbstractConnection } @Override - public String toString() + public String toConnectionString() { ByteBuffer b = _encryptedInput; int ei=b==null?-1:b.remaining(); @@ -275,22 +307,17 @@ public class SslConnection extends AbstractConnection b = _decryptedInput; int di=b==null?-1:b.remaining(); - return String.format("SslConnection@%x{%s,eio=%d/%d,di=%d} -> %s", + return String.format("%s@%x{%s,eio=%d/%d,di=%d}=>%s", + getClass().getSimpleName(), hashCode(), _sslEngine.getHandshakeStatus(), ei,eo,di, - _decryptedEndPoint.getConnection()); - } + ((AbstractConnection)_decryptedEndPoint.getConnection()).toConnectionString()); + } public class DecryptedEndPoint extends AbstractEndPoint { - private boolean _fillRequiresFlushToProgress; - private boolean _flushRequiresFillToProgress; - private boolean _cannotAcceptMoreAppDataToFlush; - private boolean _handshaken; - private boolean _underFlown; - - private final Callback _writeCallback = new Callback() + private final class WriteCallBack implements Callback, Invocable { @Override public void succeeded() @@ -316,7 +343,7 @@ public class SslConnection extends AbstractConnection } if (fillable) getFillInterest().fillable(); - _runCompletWrite.run(); + _runCompleteWrite.run(); } @Override @@ -355,7 +382,27 @@ public class SslConnection extends AbstractConnection } },x); } - }; + + @Override + public InvocationType getInvocationType() + { + return getWriteFlusher().getCallbackInvocationType(); + } + + @Override + public String toString() + { + return String.format("SSL@%h.DEP.writeCallback",SslConnection.this); + } + } + + private boolean _fillRequiresFlushToProgress; + private boolean _flushRequiresFillToProgress; + private boolean _cannotAcceptMoreAppDataToFlush; + private boolean _handshaken; + private boolean _underFlown; + + private final Callback _writeCallback = new WriteCallBack(); public DecryptedEndPoint() { @@ -452,7 +499,7 @@ public class SslConnection extends AbstractConnection { // try to flush what is pending // execute to avoid recursion - getExecutor().execute(_runCompletWrite); + getExecutor().execute(_runCompleteWrite); } } } @@ -738,7 +785,7 @@ public class SslConnection extends AbstractConnection if (_flushRequiresFillToProgress) { _flushRequiresFillToProgress = false; - getExecutor().execute(_runCompletWrite); + getExecutor().execute(_runCompleteWrite); } if (_encryptedInput != null && !_encryptedInput.hasRemaining()) diff --git a/jetty-proxy/src/main/java/org/eclipse/jetty/proxy/ProxyConnection.java b/jetty-proxy/src/main/java/org/eclipse/jetty/proxy/ProxyConnection.java index f921fc6be39..5fbe63b3728 100644 --- a/jetty-proxy/src/main/java/org/eclipse/jetty/proxy/ProxyConnection.java +++ b/jetty-proxy/src/main/java/org/eclipse/jetty/proxy/ProxyConnection.java @@ -77,12 +77,13 @@ public abstract class ProxyConnection extends AbstractConnection protected abstract void write(EndPoint endPoint, ByteBuffer buffer, Callback callback); @Override - public String toString() + public String toConnectionString() { - return String.format("%s[l:%d<=>r:%d]", - super.toString(), - getEndPoint().getLocalAddress().getPort(), - getEndPoint().getRemoteAddress().getPort()); + return String.format("%s@%x[l:%d<=>r:%d]", + getClass().getSimpleName(), + hashCode(), + getEndPoint().getLocalAddress().getPort(), + getEndPoint().getRemoteAddress().getPort()); } private class ProxyIteratingCallback extends IteratingCallback diff --git a/jetty-server/src/main/java/org/eclipse/jetty/server/HttpConnection.java b/jetty-server/src/main/java/org/eclipse/jetty/server/HttpConnection.java index f963f3078ae..ad9aa326bb5 100644 --- a/jetty-server/src/main/java/org/eclipse/jetty/server/HttpConnection.java +++ b/jetty-server/src/main/java/org/eclipse/jetty/server/HttpConnection.java @@ -562,10 +562,11 @@ public class HttpConnection extends AbstractConnection implements Runnable, Http } @Override - public String toString() + public String toConnectionString() { - return String.format("%s[p=%s,g=%s,c=%s]", - super.toString(), + return String.format("%s@%x[p=%s,g=%s]=>%s", + getClass().getSimpleName(), + hashCode(), _parser, _generator, _channel); diff --git a/jetty-server/src/test/java/org/eclipse/jetty/server/ThreadStarvationTest.java b/jetty-server/src/test/java/org/eclipse/jetty/server/ThreadStarvationTest.java index 10d5cccfdae..d51241e7167 100644 --- a/jetty-server/src/test/java/org/eclipse/jetty/server/ThreadStarvationTest.java +++ b/jetty-server/src/test/java/org/eclipse/jetty/server/ThreadStarvationTest.java @@ -27,6 +27,7 @@ import java.io.IOException; import java.io.InputStream; import java.io.OutputStream; import java.net.Socket; +import java.nio.channels.SelectionKey; import java.nio.charset.StandardCharsets; import java.nio.file.Path; import java.util.ArrayList; @@ -49,6 +50,7 @@ import javax.servlet.http.HttpServletResponse; import org.eclipse.jetty.http.HttpStatus; import org.eclipse.jetty.io.ByteBufferPool; import org.eclipse.jetty.io.LeakTrackingByteBufferPool; +import org.eclipse.jetty.io.ManagedSelector; import org.eclipse.jetty.io.MappedByteBufferPool; import org.eclipse.jetty.server.handler.AbstractHandler; import org.eclipse.jetty.toolchain.test.MavenTestingUtils; @@ -69,7 +71,7 @@ public class ThreadStarvationTest final static int BUFFER_SIZE=1024*1024; final static int BUFFERS=64; final static int THREADS=5; - final static int CLIENTS=THREADS*2; + final static int CLIENTS=THREADS+2; @Rule public TestTracker tracker = new TestTracker(); diff --git a/jetty-websocket/websocket-common/src/main/java/org/eclipse/jetty/websocket/common/io/AbstractWebSocketConnection.java b/jetty-websocket/websocket-common/src/main/java/org/eclipse/jetty/websocket/common/io/AbstractWebSocketConnection.java index 5a4d309c9c5..0ca4d4b2f01 100644 --- a/jetty-websocket/websocket-common/src/main/java/org/eclipse/jetty/websocket/common/io/AbstractWebSocketConnection.java +++ b/jetty-websocket/websocket-common/src/main/java/org/eclipse/jetty/websocket/common/io/AbstractWebSocketConnection.java @@ -758,11 +758,14 @@ public abstract class AbstractWebSocketConnection extends AbstractConnection imp } @Override - public String toString() + public String toConnectionString() { - return String.format("%s@%X{endp=%s,ios=%s,f=%s,g=%s,p=%s}",getClass().getSimpleName(),hashCode(),getEndPoint(),ioState,flusher,generator,parser); + return String.format("%s@%x[ios=%s,f=%s,g=%s,p=%s]", + getClass().getSimpleName(), + hashCode(), + ioState,flusher,generator,parser); } - + @Override public int hashCode() {