From a0aa438be8f42d3401455f8bfc4716cb534b6e45 Mon Sep 17 00:00:00 2001 From: Oleg Kalnichevski Date: Sat, 15 Jun 2019 12:28:35 +0200 Subject: [PATCH] Logging of multihome connect operations --- .../async/InternalHttp2AsyncExecRuntime.java | 4 +- .../async/InternalHttpAsyncExecRuntime.java | 4 +- .../impl/classic/InternalExecRuntime.java | 4 +- .../impl/nio/MultihomeIOSessionRequester.java | 37 +++++++++++++++++++ 4 files changed, 43 insertions(+), 6 deletions(-) diff --git a/httpclient5/src/main/java/org/apache/hc/client5/http/impl/async/InternalHttp2AsyncExecRuntime.java b/httpclient5/src/main/java/org/apache/hc/client5/http/impl/async/InternalHttp2AsyncExecRuntime.java index 2c17c9f55..5fc835c00 100644 --- a/httpclient5/src/main/java/org/apache/hc/client5/http/impl/async/InternalHttp2AsyncExecRuntime.java +++ b/httpclient5/src/main/java/org/apache/hc/client5/http/impl/async/InternalHttp2AsyncExecRuntime.java @@ -89,7 +89,7 @@ class InternalHttp2AsyncExecRuntime implements AsyncExecRuntime { final RequestConfig requestConfig = context.getRequestConfig(); final Timeout connectTimeout = requestConfig.getConnectTimeout(); if (log.isDebugEnabled()) { - log.debug(id + ": aquiring endpoint (" + connectTimeout + ")"); + log.debug(id + ": acquiring endpoint (" + connectTimeout + ")"); } return Operations.cancellable(connPool.getSession( target, @@ -101,7 +101,7 @@ class InternalHttp2AsyncExecRuntime implements AsyncExecRuntime { sessionRef.set(new Endpoint(target, ioSession)); reusable = true; if (log.isDebugEnabled()) { - log.debug(id + ": aquired endpoint"); + log.debug(id + ": acquired endpoint"); } callback.completed(InternalHttp2AsyncExecRuntime.this); } diff --git a/httpclient5/src/main/java/org/apache/hc/client5/http/impl/async/InternalHttpAsyncExecRuntime.java b/httpclient5/src/main/java/org/apache/hc/client5/http/impl/async/InternalHttpAsyncExecRuntime.java index 03a7db24a..c6cb2a4e7 100644 --- a/httpclient5/src/main/java/org/apache/hc/client5/http/impl/async/InternalHttpAsyncExecRuntime.java +++ b/httpclient5/src/main/java/org/apache/hc/client5/http/impl/async/InternalHttpAsyncExecRuntime.java @@ -95,7 +95,7 @@ class InternalHttpAsyncExecRuntime implements AsyncExecRuntime { final RequestConfig requestConfig = context.getRequestConfig(); final Timeout connectionRequestTimeout = requestConfig.getConnectionRequestTimeout(); if (log.isDebugEnabled()) { - log.debug(id + ": aquiring endpoint (" + connectionRequestTimeout + ")"); + log.debug(id + ": acquiring endpoint (" + connectionRequestTimeout + ")"); } return Operations.cancellable(manager.lease( id, @@ -109,7 +109,7 @@ class InternalHttpAsyncExecRuntime implements AsyncExecRuntime { endpointRef.set(connectionEndpoint); reusable = connectionEndpoint.isConnected(); if (log.isDebugEnabled()) { - log.debug(id + ": aquired endpoint " + ConnPoolSupport.getId(connectionEndpoint)); + log.debug(id + ": acquired endpoint " + ConnPoolSupport.getId(connectionEndpoint)); } callback.completed(InternalHttpAsyncExecRuntime.this); } diff --git a/httpclient5/src/main/java/org/apache/hc/client5/http/impl/classic/InternalExecRuntime.java b/httpclient5/src/main/java/org/apache/hc/client5/http/impl/classic/InternalExecRuntime.java index 63d67b160..49a9b15cf 100644 --- a/httpclient5/src/main/java/org/apache/hc/client5/http/impl/classic/InternalExecRuntime.java +++ b/httpclient5/src/main/java/org/apache/hc/client5/http/impl/classic/InternalExecRuntime.java @@ -98,7 +98,7 @@ class InternalExecRuntime implements ExecRuntime, Cancellable { final RequestConfig requestConfig = context.getRequestConfig(); final Timeout connectionRequestTimeout = requestConfig.getConnectionRequestTimeout(); if (log.isDebugEnabled()) { - log.debug(id + ": aquiring endpoint (" + connectionRequestTimeout + ")"); + log.debug(id + ": acquiring endpoint (" + connectionRequestTimeout + ")"); } final LeaseRequest connRequest = manager.lease(id, route, connectionRequestTimeout, object); state = object; @@ -117,7 +117,7 @@ class InternalExecRuntime implements ExecRuntime, Cancellable { cancellableDependency.setDependency(this); } if (log.isDebugEnabled()) { - log.debug(id + ": aquired endpoint " + ConnPoolSupport.getId(connectionEndpoint)); + log.debug(id + ": acquired endpoint " + ConnPoolSupport.getId(connectionEndpoint)); } } catch(final TimeoutException ex) { throw new ConnectionRequestTimeoutException(ex.getMessage()); diff --git a/httpclient5/src/main/java/org/apache/hc/client5/http/impl/nio/MultihomeIOSessionRequester.java b/httpclient5/src/main/java/org/apache/hc/client5/http/impl/nio/MultihomeIOSessionRequester.java index ab0a7ba1f..9eb518620 100644 --- a/httpclient5/src/main/java/org/apache/hc/client5/http/impl/nio/MultihomeIOSessionRequester.java +++ b/httpclient5/src/main/java/org/apache/hc/client5/http/impl/nio/MultihomeIOSessionRequester.java @@ -32,6 +32,7 @@ import java.net.InetAddress; import java.net.InetSocketAddress; import java.net.SocketAddress; import java.net.UnknownHostException; +import java.util.Arrays; import java.util.concurrent.Future; import java.util.concurrent.atomic.AtomicInteger; @@ -44,9 +45,12 @@ import org.apache.hc.core5.net.NamedEndpoint; import org.apache.hc.core5.reactor.ConnectionInitiator; import org.apache.hc.core5.reactor.IOSession; import org.apache.hc.core5.util.Timeout; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; final class MultihomeIOSessionRequester { + private final Logger log = LoggerFactory.getLogger(getClass()); private final DnsResolver dnsResolver; MultihomeIOSessionRequester(final DnsResolver dnsResolver) { @@ -61,9 +65,18 @@ final class MultihomeIOSessionRequester { final Timeout connectTimeout, final Object attachment, final FutureCallback callback) { + if (remoteAddress != null) { + if (log.isDebugEnabled()) { + log.debug(remoteEndpoint + ": connecting " + localAddress + " to " + remoteAddress + " (" + connectTimeout + ")"); + } return connectionInitiator.connect(remoteEndpoint, remoteAddress, localAddress, connectTimeout, attachment, callback); } + + if (log.isDebugEnabled()) { + log.debug(remoteEndpoint + ": resolving remote address"); + } + final ComplexFuture future = new ComplexFuture<>(callback); final InetAddress[] remoteAddresses; try { @@ -72,6 +85,11 @@ final class MultihomeIOSessionRequester { future.failed(ex); return future; } + + if (log.isDebugEnabled()) { + log.debug(remoteEndpoint + ": resolved to " + Arrays.asList(remoteAddresses)); + } + final Runnable runnable = new Runnable() { private final AtomicInteger attempt = new AtomicInteger(0); @@ -79,6 +97,11 @@ final class MultihomeIOSessionRequester { void executeNext() { final int index = attempt.getAndIncrement(); final InetSocketAddress remoteAddress = new InetSocketAddress(remoteAddresses[index], remoteEndpoint.getPort()); + + if (log.isDebugEnabled()) { + log.debug(remoteEndpoint + ": connecting " + localAddress + " to " + remoteAddress + " (" + connectTimeout + ")"); + } + final Future sessionFuture = connectionInitiator.connect( remoteEndpoint, remoteAddress, @@ -89,18 +112,32 @@ final class MultihomeIOSessionRequester { @Override public void completed(final IOSession session) { + if (log.isDebugEnabled()) { + if (log.isDebugEnabled()) { + log.debug(remoteEndpoint + ": connected " + session.getId() + " " + + session.getLocalAddress() + "->" + session.getRemoteAddress()); + } + } future.completed(session); } @Override public void failed(final Exception cause) { if (attempt.get() >= remoteAddresses.length) { + if (log.isDebugEnabled()) { + log.debug(remoteEndpoint + ": connection to " + remoteAddress + " failed " + + "(" + cause.getClass() + "); terminating operation"); + } if (cause instanceof IOException) { future.failed(new HttpHostConnectException((IOException) cause, remoteEndpoint, remoteAddresses)); } else { future.failed(cause); } } else { + if (log.isDebugEnabled()) { + log.debug(remoteEndpoint + ": connection to " + remoteAddress + " failed " + + "(" + cause.getClass() + "); retrying connection to the next address"); + } executeNext(); } }