From d5a6ad23459d601e94f07a397a96d75c40179095 Mon Sep 17 00:00:00 2001 From: Simone Bordet Date: Thu, 26 Feb 2015 10:55:58 +0100 Subject: [PATCH 1/5] 460905 - Make sure TimeoutCompleteListener is cancelled if the request cannot be sent. --- .../org/eclipse/jetty/client/HttpRequest.java | 21 +++++++++++---- .../jetty/client/TimeoutCompleteListener.java | 26 +++++++++++++------ .../jetty/client/HttpClientTimeoutTest.java | 22 ++++++++++++++++ 3 files changed, 56 insertions(+), 13 deletions(-) diff --git a/jetty-client/src/main/java/org/eclipse/jetty/client/HttpRequest.java b/jetty-client/src/main/java/org/eclipse/jetty/client/HttpRequest.java index 2dd02292c5c..79f75048025 100644 --- a/jetty-client/src/main/java/org/eclipse/jetty/client/HttpRequest.java +++ b/jetty-client/src/main/java/org/eclipse/jetty/client/HttpRequest.java @@ -666,13 +666,24 @@ public class HttpRequest implements Request @Override public void send(Response.CompleteListener listener) { - if (getTimeout() > 0) + TimeoutCompleteListener timeoutListener = null; + try { - TimeoutCompleteListener timeoutListener = new TimeoutCompleteListener(this); - timeoutListener.schedule(client.getScheduler()); - responseListeners.add(timeoutListener); + if (getTimeout() > 0) + { + timeoutListener = new TimeoutCompleteListener(this); + timeoutListener.schedule(client.getScheduler()); + responseListeners.add(timeoutListener); + } + send(this, listener); + } + catch (Throwable x) + { + // Do not leak the scheduler task if we + // can't even start sending the request. + if (timeoutListener != null) + timeoutListener.cancel(); } - send(this, listener); } private void send(HttpRequest request, Response.CompleteListener listener) diff --git a/jetty-client/src/main/java/org/eclipse/jetty/client/TimeoutCompleteListener.java b/jetty-client/src/main/java/org/eclipse/jetty/client/TimeoutCompleteListener.java index 00f2de78978..45b9a8178be 100644 --- a/jetty-client/src/main/java/org/eclipse/jetty/client/TimeoutCompleteListener.java +++ b/jetty-client/src/main/java/org/eclipse/jetty/client/TimeoutCompleteListener.java @@ -44,21 +44,20 @@ public class TimeoutCompleteListener implements Response.CompleteListener, Runna @Override public void onComplete(Result result) { - Scheduler.Task task = this.task.getAndSet(null); - if (task != null) - { - boolean cancelled = task.cancel(); - if (LOG.isDebugEnabled()) - LOG.debug("Cancelled (successfully: {}) timeout task {}", cancelled, task); - } + cancel(); } public boolean schedule(Scheduler scheduler) { long timeout = request.getTimeout(); Scheduler.Task task = scheduler.schedule(this, timeout, TimeUnit.MILLISECONDS); - if (this.task.getAndSet(task) != null) + Scheduler.Task existing = this.task.getAndSet(task); + if (existing != null) + { + existing.cancel(); + cancel(); throw new IllegalStateException(); + } if (LOG.isDebugEnabled()) LOG.debug("Scheduled timeout task {} in {} ms for {}", task, timeout, request); return true; @@ -71,4 +70,15 @@ public class TimeoutCompleteListener implements Response.CompleteListener, Runna LOG.debug("Executing timeout task {} for {}", task, request); request.abort(new TimeoutException("Total timeout elapsed")); } + + public void cancel() + { + Scheduler.Task task = this.task.getAndSet(null); + if (task != null) + { + boolean cancelled = task.cancel(); + if (LOG.isDebugEnabled()) + LOG.debug("Cancelled (successfully: {}) timeout task {}", cancelled, task); + } + } } diff --git a/jetty-client/src/test/java/org/eclipse/jetty/client/HttpClientTimeoutTest.java b/jetty-client/src/test/java/org/eclipse/jetty/client/HttpClientTimeoutTest.java index df347c4bc5f..971ebf75b7d 100644 --- a/jetty-client/src/test/java/org/eclipse/jetty/client/HttpClientTimeoutTest.java +++ b/jetty-client/src/test/java/org/eclipse/jetty/client/HttpClientTimeoutTest.java @@ -428,6 +428,28 @@ public class HttpClientTimeoutTest extends AbstractHttpClientServerTest Assert.assertTrue(latch.await(5, TimeUnit.SECONDS)); } + @Test + public void testTimeoutCancelledWhenSendingThrowsException() throws Exception + { + start(new EmptyServerHandler()); + + long timeout = 1000; + Request request = client.newRequest("bad_scheme://localhost:" + connector.getLocalPort()); + request.timeout(timeout, TimeUnit.MILLISECONDS) + .send(new Response.CompleteListener() + { + @Override + public void onComplete(Result result) + { + } + }); + + Thread.sleep(2 * timeout); + + // If the task was not cancelled, it aborted the request. + Assert.assertNull(request.getAbortCause()); + } + private void assumeConnectTimeout(String host, int port, int connectTimeout) throws IOException { try (Socket socket = new Socket()) From 008b03ac78c685b1e858acf566f824da35a1fbca Mon Sep 17 00:00:00 2001 From: Simone Bordet Date: Thu, 26 Feb 2015 12:25:42 +0100 Subject: [PATCH 2/5] 460905 - Make sure TimeoutCompleteListener is cancelled if the request cannot be sent. --- .../org/eclipse/jetty/client/HttpRequest.java | 1 + .../jetty/client/HttpClientTimeoutTest.java | 24 ++++++++++++------- 2 files changed, 17 insertions(+), 8 deletions(-) diff --git a/jetty-client/src/main/java/org/eclipse/jetty/client/HttpRequest.java b/jetty-client/src/main/java/org/eclipse/jetty/client/HttpRequest.java index 79f75048025..0f68b039bbc 100644 --- a/jetty-client/src/main/java/org/eclipse/jetty/client/HttpRequest.java +++ b/jetty-client/src/main/java/org/eclipse/jetty/client/HttpRequest.java @@ -683,6 +683,7 @@ public class HttpRequest implements Request // can't even start sending the request. if (timeoutListener != null) timeoutListener.cancel(); + throw x; } } diff --git a/jetty-client/src/test/java/org/eclipse/jetty/client/HttpClientTimeoutTest.java b/jetty-client/src/test/java/org/eclipse/jetty/client/HttpClientTimeoutTest.java index 971ebf75b7d..a715177ca9b 100644 --- a/jetty-client/src/test/java/org/eclipse/jetty/client/HttpClientTimeoutTest.java +++ b/jetty-client/src/test/java/org/eclipse/jetty/client/HttpClientTimeoutTest.java @@ -434,15 +434,23 @@ public class HttpClientTimeoutTest extends AbstractHttpClientServerTest start(new EmptyServerHandler()); long timeout = 1000; - Request request = client.newRequest("bad_scheme://localhost:" + connector.getLocalPort()); - request.timeout(timeout, TimeUnit.MILLISECONDS) - .send(new Response.CompleteListener() - { - @Override - public void onComplete(Result result) + Request request = client.newRequest("badscheme://localhost:" + connector.getLocalPort()); + + try + { + request.timeout(timeout, TimeUnit.MILLISECONDS) + .send(new Response.CompleteListener() { - } - }); + @Override + public void onComplete(Result result) + { + } + }); + Assert.fail(); + } + catch (Exception expected) + { + } Thread.sleep(2 * timeout); From 31a0b36f3ccda180a38832ec1ce410cb1edeb153 Mon Sep 17 00:00:00 2001 From: Simone Bordet Date: Thu, 26 Feb 2015 22:49:20 +0100 Subject: [PATCH 3/5] Improved logging and toString() implementations. --- .../org/eclipse/jetty/client/HttpChannel.java | 2 +- .../org/eclipse/jetty/client/HttpReceiver.java | 5 +++-- .../org/eclipse/jetty/client/HttpSender.java | 17 +++++++++-------- .../jetty/client/http/HttpChannelOverHTTP.java | 5 ++--- 4 files changed, 15 insertions(+), 14 deletions(-) diff --git a/jetty-client/src/main/java/org/eclipse/jetty/client/HttpChannel.java b/jetty-client/src/main/java/org/eclipse/jetty/client/HttpChannel.java index 400ed930c91..74d762e8939 100644 --- a/jetty-client/src/main/java/org/eclipse/jetty/client/HttpChannel.java +++ b/jetty-client/src/main/java/org/eclipse/jetty/client/HttpChannel.java @@ -86,6 +86,6 @@ public abstract class HttpChannel @Override public String toString() { - return String.format("%s@%h", getClass().getSimpleName(), this); + return String.format("%s@%x(exchange=%s)", getClass().getSimpleName(), hashCode(), exchange); } } diff --git a/jetty-client/src/main/java/org/eclipse/jetty/client/HttpReceiver.java b/jetty-client/src/main/java/org/eclipse/jetty/client/HttpReceiver.java index ff00322d1be..52d7aca8aef 100644 --- a/jetty-client/src/main/java/org/eclipse/jetty/client/HttpReceiver.java +++ b/jetty-client/src/main/java/org/eclipse/jetty/client/HttpReceiver.java @@ -524,10 +524,11 @@ public abstract class HttpReceiver @Override public String toString() { - return String.format("%s@%x(rcv=%s)", + return String.format("%s@%x(rsp=%s,failure=%s)", getClass().getSimpleName(), hashCode(), - responseState); + responseState, + failure); } /** diff --git a/jetty-client/src/main/java/org/eclipse/jetty/client/HttpSender.java b/jetty-client/src/main/java/org/eclipse/jetty/client/HttpSender.java index 79806669bf7..57519ba3c1e 100644 --- a/jetty-client/src/main/java/org/eclipse/jetty/client/HttpSender.java +++ b/jetty-client/src/main/java/org/eclipse/jetty/client/HttpSender.java @@ -206,7 +206,7 @@ public abstract class HttpSender implements AsyncContentProvider.Listener if (!updateRequestState(RequestState.BEGIN, RequestState.TRANSIENT)) return false; if (LOG.isDebugEnabled()) - LOG.debug("Request headers {}{}{}", request, System.getProperty("line.separator"), request.getHeaders().toString().trim()); + LOG.debug("Request headers {}{}{}", request, System.lineSeparator(), request.getHeaders().toString().trim()); RequestNotifier notifier = getHttpChannel().getHttpDestination().getRequestNotifier(); notifier.notifyHeaders(request); if (!updateRequestState(RequestState.TRANSIENT, RequestState.HEADERS)) @@ -238,7 +238,7 @@ public abstract class HttpSender implements AsyncContentProvider.Listener if (!updateRequestState(current, RequestState.TRANSIENT_CONTENT)) return false; if (LOG.isDebugEnabled()) - LOG.debug("Request content {}{}{}", request, System.getProperty("line.separator"), BufferUtil.toDetailString(content)); + LOG.debug("Request content {}{}{}", request, System.lineSeparator(), BufferUtil.toDetailString(content)); RequestNotifier notifier = getHttpChannel().getHttpDestination().getRequestNotifier(); notifier.notifyContent(request, content); if (!updateRequestState(RequestState.TRANSIENT_CONTENT, RequestState.CONTENT)) @@ -327,7 +327,7 @@ public abstract class HttpSender implements AsyncContentProvider.Listener Request request = exchange.getRequest(); if (LOG.isDebugEnabled()) - LOG.debug("Request failure {} {}", exchange, failure); + LOG.debug("Request failure {} {} on {}: {}", request, exchange, getHttpChannel(), failure); HttpDestination destination = getHttpChannel().getHttpDestination(); destination.getRequestNotifier().notifyFailure(request, failure); @@ -365,7 +365,7 @@ public abstract class HttpSender implements AsyncContentProvider.Listener if (failure != null) { if (LOG.isDebugEnabled()) - LOG.debug("Response failure from request {}", exchange); + LOG.debug("Response failure from request {} {}", request, exchange); getHttpChannel().abortResponse(failure); } } @@ -500,7 +500,7 @@ public abstract class HttpSender implements AsyncContentProvider.Listener private boolean updateRequestState(RequestState from, RequestState to) { boolean updated = requestState.compareAndSet(from, to); - if (!updated) + if (!updated && LOG.isDebugEnabled()) LOG.debug("RequestState update failed: {} -> {}: {}", from, to, requestState.get()); return updated; } @@ -508,7 +508,7 @@ public abstract class HttpSender implements AsyncContentProvider.Listener private boolean updateSenderState(SenderState from, SenderState to) { boolean updated = senderState.compareAndSet(from, to); - if (!updated) + if (!updated && LOG.isDebugEnabled()) LOG.debug("SenderState update failed: {} -> {}: {}", from, to, senderState.get()); return updated; } @@ -548,11 +548,12 @@ public abstract class HttpSender implements AsyncContentProvider.Listener @Override public String toString() { - return String.format("%s@%x(req=%s,snd=%s)", + return String.format("%s@%x(req=%s,snd=%s,failure=%s)", getClass().getSimpleName(), hashCode(), requestState, - senderState); + senderState, + failure); } /** diff --git a/jetty-client/src/main/java/org/eclipse/jetty/client/http/HttpChannelOverHTTP.java b/jetty-client/src/main/java/org/eclipse/jetty/client/http/HttpChannelOverHTTP.java index b99ebaa71df..38de40fc7c1 100644 --- a/jetty-client/src/main/java/org/eclipse/jetty/client/http/HttpChannelOverHTTP.java +++ b/jetty-client/src/main/java/org/eclipse/jetty/client/http/HttpChannelOverHTTP.java @@ -119,9 +119,8 @@ public class HttpChannelOverHTTP extends HttpChannel @Override public String toString() { - return String.format("%s@%x(send=%s,recv=%s)", - getClass().getSimpleName(), - hashCode(), + return String.format("%s[send=%s,recv=%s]", + super.toString(), sender, receiver); } From bbc2d0c29d1f84b66a2d45a16b6ea9435eea11af Mon Sep 17 00:00:00 2001 From: Simone Bordet Date: Thu, 26 Feb 2015 23:24:44 +0100 Subject: [PATCH 4/5] Simplified abort logic. --- .../org/eclipse/jetty/client/HttpSender.java | 31 +------------------ 1 file changed, 1 insertion(+), 30 deletions(-) diff --git a/jetty-client/src/main/java/org/eclipse/jetty/client/HttpSender.java b/jetty-client/src/main/java/org/eclipse/jetty/client/HttpSender.java index 57519ba3c1e..308f3cb941a 100644 --- a/jetty-client/src/main/java/org/eclipse/jetty/client/HttpSender.java +++ b/jetty-client/src/main/java/org/eclipse/jetty/client/HttpSender.java @@ -492,9 +492,7 @@ public abstract class HttpSender implements AsyncContentProvider.Listener public boolean abort(Throwable failure) { - RequestState current = requestState.get(); - boolean abortable = isBeforeCommit(current) || isSending(current); - return abortable && anyToFailure(failure); + return anyToFailure(failure); } private boolean updateRequestState(RequestState from, RequestState to) @@ -513,33 +511,6 @@ public abstract class HttpSender implements AsyncContentProvider.Listener return updated; } - private boolean isBeforeCommit(RequestState requestState) - { - switch (requestState) - { - case TRANSIENT: - case QUEUED: - case BEGIN: - case HEADERS: - return true; - default: - return false; - } - } - - private boolean isSending(RequestState requestState) - { - switch (requestState) - { - case TRANSIENT_CONTENT: - case COMMIT: - case CONTENT: - return true; - default: - return false; - } - } - private RuntimeException illegalSenderState(SenderState current) { return new IllegalStateException("Expected " + current + " found " + senderState.get() + " instead"); From da80498c56da590bf5b70cca3ba27187a71d37ba Mon Sep 17 00:00:00 2001 From: Simone Bordet Date: Thu, 26 Feb 2015 23:38:02 +0100 Subject: [PATCH 5/5] Improved logging. --- .../src/main/java/org/eclipse/jetty/client/HttpReceiver.java | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/jetty-client/src/main/java/org/eclipse/jetty/client/HttpReceiver.java b/jetty-client/src/main/java/org/eclipse/jetty/client/HttpReceiver.java index 52d7aca8aef..3709c4a8fa6 100644 --- a/jetty-client/src/main/java/org/eclipse/jetty/client/HttpReceiver.java +++ b/jetty-client/src/main/java/org/eclipse/jetty/client/HttpReceiver.java @@ -435,7 +435,7 @@ public abstract class HttpReceiver HttpResponse response = exchange.getResponse(); if (LOG.isDebugEnabled()) - LOG.debug("Response failure {} {}", response, failure); + LOG.debug("Response failure {} {} on {}: {}", response, exchange, getHttpChannel(), failure); List listeners = exchange.getConversation().getResponseListeners(); ResponseNotifier notifier = getHttpDestination().getResponseNotifier(); notifier.notifyFailure(listeners, response, failure);