Logging of multihome connect operations

This commit is contained in:
Oleg Kalnichevski 2019-06-15 12:28:35 +02:00
parent 19a87e0c77
commit a0aa438be8
4 changed files with 43 additions and 6 deletions

View File

@ -89,7 +89,7 @@ class InternalHttp2AsyncExecRuntime implements AsyncExecRuntime {
final RequestConfig requestConfig = context.getRequestConfig(); final RequestConfig requestConfig = context.getRequestConfig();
final Timeout connectTimeout = requestConfig.getConnectTimeout(); final Timeout connectTimeout = requestConfig.getConnectTimeout();
if (log.isDebugEnabled()) { if (log.isDebugEnabled()) {
log.debug(id + ": aquiring endpoint (" + connectTimeout + ")"); log.debug(id + ": acquiring endpoint (" + connectTimeout + ")");
} }
return Operations.cancellable(connPool.getSession( return Operations.cancellable(connPool.getSession(
target, target,
@ -101,7 +101,7 @@ class InternalHttp2AsyncExecRuntime implements AsyncExecRuntime {
sessionRef.set(new Endpoint(target, ioSession)); sessionRef.set(new Endpoint(target, ioSession));
reusable = true; reusable = true;
if (log.isDebugEnabled()) { if (log.isDebugEnabled()) {
log.debug(id + ": aquired endpoint"); log.debug(id + ": acquired endpoint");
} }
callback.completed(InternalHttp2AsyncExecRuntime.this); callback.completed(InternalHttp2AsyncExecRuntime.this);
} }

View File

@ -95,7 +95,7 @@ class InternalHttpAsyncExecRuntime implements AsyncExecRuntime {
final RequestConfig requestConfig = context.getRequestConfig(); final RequestConfig requestConfig = context.getRequestConfig();
final Timeout connectionRequestTimeout = requestConfig.getConnectionRequestTimeout(); final Timeout connectionRequestTimeout = requestConfig.getConnectionRequestTimeout();
if (log.isDebugEnabled()) { if (log.isDebugEnabled()) {
log.debug(id + ": aquiring endpoint (" + connectionRequestTimeout + ")"); log.debug(id + ": acquiring endpoint (" + connectionRequestTimeout + ")");
} }
return Operations.cancellable(manager.lease( return Operations.cancellable(manager.lease(
id, id,
@ -109,7 +109,7 @@ class InternalHttpAsyncExecRuntime implements AsyncExecRuntime {
endpointRef.set(connectionEndpoint); endpointRef.set(connectionEndpoint);
reusable = connectionEndpoint.isConnected(); reusable = connectionEndpoint.isConnected();
if (log.isDebugEnabled()) { if (log.isDebugEnabled()) {
log.debug(id + ": aquired endpoint " + ConnPoolSupport.getId(connectionEndpoint)); log.debug(id + ": acquired endpoint " + ConnPoolSupport.getId(connectionEndpoint));
} }
callback.completed(InternalHttpAsyncExecRuntime.this); callback.completed(InternalHttpAsyncExecRuntime.this);
} }

View File

@ -98,7 +98,7 @@ class InternalExecRuntime implements ExecRuntime, Cancellable {
final RequestConfig requestConfig = context.getRequestConfig(); final RequestConfig requestConfig = context.getRequestConfig();
final Timeout connectionRequestTimeout = requestConfig.getConnectionRequestTimeout(); final Timeout connectionRequestTimeout = requestConfig.getConnectionRequestTimeout();
if (log.isDebugEnabled()) { if (log.isDebugEnabled()) {
log.debug(id + ": aquiring endpoint (" + connectionRequestTimeout + ")"); log.debug(id + ": acquiring endpoint (" + connectionRequestTimeout + ")");
} }
final LeaseRequest connRequest = manager.lease(id, route, connectionRequestTimeout, object); final LeaseRequest connRequest = manager.lease(id, route, connectionRequestTimeout, object);
state = object; state = object;
@ -117,7 +117,7 @@ class InternalExecRuntime implements ExecRuntime, Cancellable {
cancellableDependency.setDependency(this); cancellableDependency.setDependency(this);
} }
if (log.isDebugEnabled()) { if (log.isDebugEnabled()) {
log.debug(id + ": aquired endpoint " + ConnPoolSupport.getId(connectionEndpoint)); log.debug(id + ": acquired endpoint " + ConnPoolSupport.getId(connectionEndpoint));
} }
} catch(final TimeoutException ex) { } catch(final TimeoutException ex) {
throw new ConnectionRequestTimeoutException(ex.getMessage()); throw new ConnectionRequestTimeoutException(ex.getMessage());

View File

@ -32,6 +32,7 @@ import java.net.InetAddress;
import java.net.InetSocketAddress; import java.net.InetSocketAddress;
import java.net.SocketAddress; import java.net.SocketAddress;
import java.net.UnknownHostException; import java.net.UnknownHostException;
import java.util.Arrays;
import java.util.concurrent.Future; import java.util.concurrent.Future;
import java.util.concurrent.atomic.AtomicInteger; 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.ConnectionInitiator;
import org.apache.hc.core5.reactor.IOSession; import org.apache.hc.core5.reactor.IOSession;
import org.apache.hc.core5.util.Timeout; import org.apache.hc.core5.util.Timeout;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
final class MultihomeIOSessionRequester { final class MultihomeIOSessionRequester {
private final Logger log = LoggerFactory.getLogger(getClass());
private final DnsResolver dnsResolver; private final DnsResolver dnsResolver;
MultihomeIOSessionRequester(final DnsResolver dnsResolver) { MultihomeIOSessionRequester(final DnsResolver dnsResolver) {
@ -61,9 +65,18 @@ final class MultihomeIOSessionRequester {
final Timeout connectTimeout, final Timeout connectTimeout,
final Object attachment, final Object attachment,
final FutureCallback<IOSession> callback) { final FutureCallback<IOSession> callback) {
if (remoteAddress != null) { if (remoteAddress != null) {
if (log.isDebugEnabled()) {
log.debug(remoteEndpoint + ": connecting " + localAddress + " to " + remoteAddress + " (" + connectTimeout + ")");
}
return connectionInitiator.connect(remoteEndpoint, remoteAddress, localAddress, connectTimeout, attachment, callback); return connectionInitiator.connect(remoteEndpoint, remoteAddress, localAddress, connectTimeout, attachment, callback);
} }
if (log.isDebugEnabled()) {
log.debug(remoteEndpoint + ": resolving remote address");
}
final ComplexFuture<IOSession> future = new ComplexFuture<>(callback); final ComplexFuture<IOSession> future = new ComplexFuture<>(callback);
final InetAddress[] remoteAddresses; final InetAddress[] remoteAddresses;
try { try {
@ -72,6 +85,11 @@ final class MultihomeIOSessionRequester {
future.failed(ex); future.failed(ex);
return future; return future;
} }
if (log.isDebugEnabled()) {
log.debug(remoteEndpoint + ": resolved to " + Arrays.asList(remoteAddresses));
}
final Runnable runnable = new Runnable() { final Runnable runnable = new Runnable() {
private final AtomicInteger attempt = new AtomicInteger(0); private final AtomicInteger attempt = new AtomicInteger(0);
@ -79,6 +97,11 @@ final class MultihomeIOSessionRequester {
void executeNext() { void executeNext() {
final int index = attempt.getAndIncrement(); final int index = attempt.getAndIncrement();
final InetSocketAddress remoteAddress = new InetSocketAddress(remoteAddresses[index], remoteEndpoint.getPort()); final InetSocketAddress remoteAddress = new InetSocketAddress(remoteAddresses[index], remoteEndpoint.getPort());
if (log.isDebugEnabled()) {
log.debug(remoteEndpoint + ": connecting " + localAddress + " to " + remoteAddress + " (" + connectTimeout + ")");
}
final Future<IOSession> sessionFuture = connectionInitiator.connect( final Future<IOSession> sessionFuture = connectionInitiator.connect(
remoteEndpoint, remoteEndpoint,
remoteAddress, remoteAddress,
@ -89,18 +112,32 @@ final class MultihomeIOSessionRequester {
@Override @Override
public void completed(final IOSession session) { 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); future.completed(session);
} }
@Override @Override
public void failed(final Exception cause) { public void failed(final Exception cause) {
if (attempt.get() >= remoteAddresses.length) { if (attempt.get() >= remoteAddresses.length) {
if (log.isDebugEnabled()) {
log.debug(remoteEndpoint + ": connection to " + remoteAddress + " failed " +
"(" + cause.getClass() + "); terminating operation");
}
if (cause instanceof IOException) { if (cause instanceof IOException) {
future.failed(new HttpHostConnectException((IOException) cause, remoteEndpoint, remoteAddresses)); future.failed(new HttpHostConnectException((IOException) cause, remoteEndpoint, remoteAddresses));
} else { } else {
future.failed(cause); future.failed(cause);
} }
} else { } else {
if (log.isDebugEnabled()) {
log.debug(remoteEndpoint + ": connection to " + remoteAddress + " failed " +
"(" + cause.getClass() + "); retrying connection to the next address");
}
executeNext(); executeNext();
} }
} }