From 9496bb8475792ffd1cf695c26c0671df3640b9d2 Mon Sep 17 00:00:00 2001 From: Oleg Kalnichevski Date: Thu, 16 Sep 2021 17:20:52 +0200 Subject: [PATCH] Better connect operation logging --- .../io/BasicHttpClientConnectionManager.java | 6 +++ .../DefaultHttpClientConnectionOperator.java | 44 ++++++++++++++----- .../impl/nio/MultihomeIOSessionRequester.java | 21 +++++---- 3 files changed, 51 insertions(+), 20 deletions(-) diff --git a/httpclient5/src/main/java/org/apache/hc/client5/http/impl/io/BasicHttpClientConnectionManager.java b/httpclient5/src/main/java/org/apache/hc/client5/http/impl/io/BasicHttpClientConnectionManager.java index a529dfbc2..b9866c1a1 100644 --- a/httpclient5/src/main/java/org/apache/hc/client5/http/impl/io/BasicHttpClientConnectionManager.java +++ b/httpclient5/src/main/java/org/apache/hc/client5/http/impl/io/BasicHttpClientConnectionManager.java @@ -361,6 +361,9 @@ public class BasicHttpClientConnectionManager implements HttpClientConnectionMan final ConnectionConfig config = connectionConfig != null ? connectionConfig : ConnectionConfig.DEFAULT; final TimeValue connectTimeout = timeout != null ? timeout : config.getConnectTimeout(); final ManagedHttpClientConnection connection = internalEndpoint.getConnection(); + if (LOG.isDebugEnabled()) { + LOG.debug("{} connecting endpoint to {} ({})", ConnPoolSupport.getId(endpoint), host, connectTimeout); + } this.connectionOperator.connect( connection, host, @@ -368,6 +371,9 @@ public class BasicHttpClientConnectionManager implements HttpClientConnectionMan connectTimeout, this.socketConfig, context); + if (LOG.isDebugEnabled()) { + LOG.debug("{} connected {}", ConnPoolSupport.getId(endpoint), ConnPoolSupport.getId(conn)); + } final Timeout socketTimeout = config.getSocketTimeout(); if (socketTimeout != null) { connection.setSocketTimeout(socketTimeout); diff --git a/httpclient5/src/main/java/org/apache/hc/client5/http/impl/io/DefaultHttpClientConnectionOperator.java b/httpclient5/src/main/java/org/apache/hc/client5/http/impl/io/DefaultHttpClientConnectionOperator.java index 14a45f076..926f58878 100644 --- a/httpclient5/src/main/java/org/apache/hc/client5/http/impl/io/DefaultHttpClientConnectionOperator.java +++ b/httpclient5/src/main/java/org/apache/hc/client5/http/impl/io/DefaultHttpClientConnectionOperator.java @@ -30,6 +30,7 @@ import java.io.IOException; import java.net.InetAddress; import java.net.InetSocketAddress; import java.net.Socket; +import java.util.Arrays; import org.apache.hc.client5.http.ConnectExceptionSupport; import org.apache.hc.client5.http.DnsResolver; @@ -115,12 +116,25 @@ public class DefaultHttpClientConnectionOperator implements HttpClientConnection if (sf == null) { throw new UnsupportedSchemeException(host.getSchemeName() + " protocol is not supported"); } - final InetAddress[] addresses = host.getAddress() != null ? - new InetAddress[] { host.getAddress() } : this.dnsResolver.resolve(host.getHostName()); + final InetAddress[] remoteAddresses; + if (host.getAddress() != null) { + remoteAddresses = new InetAddress[] { host.getAddress() }; + } else { + if (LOG.isDebugEnabled()) { + LOG.debug("{} resolving remote address", host.getHostName()); + } + + remoteAddresses = this.dnsResolver.resolve(host.getHostName()); + + if (LOG.isDebugEnabled()) { + LOG.debug("{} resolved to {}", host.getHostName(), Arrays.asList(remoteAddresses)); + } + } + final int port = this.schemePortResolver.resolve(host); - for (int i = 0; i < addresses.length; i++) { - final InetAddress address = addresses[i]; - final boolean last = i == addresses.length - 1; + for (int i = 0; i < remoteAddresses.length; i++) { + final InetAddress address = remoteAddresses[i]; + final boolean last = i == remoteAddresses.length - 1; Socket sock = sf.createSocket(context); sock.setSoTimeout(socketConfig.getSoTimeout().toMillisecondsIntBound()); @@ -142,23 +156,31 @@ public class DefaultHttpClientConnectionOperator implements HttpClientConnection final InetSocketAddress remoteAddress = new InetSocketAddress(address, port); if (LOG.isDebugEnabled()) { - LOG.debug("{} connecting to {}", ConnPoolSupport.getId(conn), remoteAddress); + LOG.debug("{}:{} connecting {}->{} ({})", + host.getHostName(), host.getPort(), localAddress, remoteAddress, connectTimeout); } try { sock = sf.connectSocket(connectTimeout, sock, host, remoteAddress, localAddress, context); conn.bind(sock); if (LOG.isDebugEnabled()) { - LOG.debug("{} connection established {}", ConnPoolSupport.getId(conn), conn); + LOG.debug("{}:{} connected {}->{} as {}", + host.getHostName(), host.getPort(), localAddress, remoteAddress, ConnPoolSupport.getId(conn)); } return; } catch (final IOException ex) { if (last) { - throw ConnectExceptionSupport.enhance(ex, host, addresses); + if (LOG.isDebugEnabled()) { + LOG.debug("{}:{} connection to {} failed ({}); terminating operation", + host.getHostName(), host.getPort(), remoteAddress, ex.getClass()); + } + throw ConnectExceptionSupport.enhance(ex, host, remoteAddresses); + } else { + if (LOG.isDebugEnabled()) { + LOG.debug("{}:{} connection to {} failed ({}); retrying connection to the next address", + host.getHostName(), host.getPort(), remoteAddress, ex.getClass()); + } } } - if (LOG.isDebugEnabled()) { - LOG.debug("{} connect to {} timed out. Connection will be retried using another IP address", ConnPoolSupport.getId(conn), remoteAddress); - } } } 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 4d90b8558..bb4264b70 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 @@ -68,13 +68,14 @@ final class MultihomeIOSessionRequester { if (remoteAddress != null) { if (LOG.isDebugEnabled()) { - LOG.debug("{} connecting {} to {} ({})", remoteEndpoint, localAddress, remoteAddress, connectTimeout); + LOG.debug("{}:{} connecting {} to {} ({})", + remoteEndpoint.getHostName(), remoteEndpoint.getPort(), localAddress, remoteAddress, connectTimeout); } return connectionInitiator.connect(remoteEndpoint, remoteAddress, localAddress, connectTimeout, attachment, callback); } if (LOG.isDebugEnabled()) { - LOG.debug("{} resolving remote address", remoteEndpoint); + LOG.debug("{} resolving remote address", remoteEndpoint.getHostName()); } final ComplexFuture future = new ComplexFuture<>(callback); @@ -87,7 +88,7 @@ final class MultihomeIOSessionRequester { } if (LOG.isDebugEnabled()) { - LOG.debug("{} resolved to {}", remoteEndpoint, Arrays.asList(remoteAddresses)); + LOG.debug("{} resolved to {}", remoteEndpoint.getHostName(), Arrays.asList(remoteAddresses)); } final Runnable runnable = new Runnable() { @@ -99,7 +100,8 @@ final class MultihomeIOSessionRequester { final InetSocketAddress remoteAddress = new InetSocketAddress(remoteAddresses[index], remoteEndpoint.getPort()); if (LOG.isDebugEnabled()) { - LOG.debug("{} connecting {} to {} ({})", remoteEndpoint, localAddress, remoteAddress, connectTimeout); + LOG.debug("{}:{} connecting {}->{} ({})", + remoteEndpoint.getHostName(), remoteEndpoint.getPort(), localAddress, remoteAddress, connectTimeout); } final Future sessionFuture = connectionInitiator.connect( @@ -113,9 +115,8 @@ final class MultihomeIOSessionRequester { @Override public void completed(final IOSession session) { if (LOG.isDebugEnabled()) { - if (LOG.isDebugEnabled()) { - LOG.debug("{} connected {} {}->{}", remoteEndpoint, session.getId(), session.getLocalAddress(), session.getRemoteAddress()); - } + LOG.debug("{}:{} connected {}->{} as {}", + remoteEndpoint.getHostName(), remoteEndpoint.getPort(), localAddress, remoteAddress, session.getId()); } future.completed(session); } @@ -124,7 +125,8 @@ final class MultihomeIOSessionRequester { public void failed(final Exception cause) { if (attempt.get() >= remoteAddresses.length) { if (LOG.isDebugEnabled()) { - LOG.debug("{} connection to {} failed ({}); terminating operation", remoteEndpoint, remoteAddress, cause.getClass()); + LOG.debug("{}:{} connection to {} failed ({}); terminating operation", + remoteEndpoint.getHostName(), remoteEndpoint.getPort(), remoteAddress, cause.getClass()); } if (cause instanceof IOException) { future.failed(ConnectExceptionSupport.enhance((IOException) cause, remoteEndpoint, remoteAddresses)); @@ -133,7 +135,8 @@ final class MultihomeIOSessionRequester { } } else { if (LOG.isDebugEnabled()) { - LOG.debug("{} connection to {} failed ({}); retrying connection to the next address", remoteEndpoint, remoteAddress, cause.getClass()); + LOG.debug("{}:{} connection to {} failed ({}); retrying connection to the next address", + remoteEndpoint.getHostName(), remoteEndpoint.getPort(), remoteAddress, cause.getClass()); } executeNext(); }