Better connect operation logging

This commit is contained in:
Oleg Kalnichevski 2021-09-16 17:20:52 +02:00
parent 90f69c87b2
commit 9496bb8475
3 changed files with 51 additions and 20 deletions

View File

@ -361,6 +361,9 @@ public class BasicHttpClientConnectionManager implements HttpClientConnectionMan
final ConnectionConfig config = connectionConfig != null ? connectionConfig : ConnectionConfig.DEFAULT; final ConnectionConfig config = connectionConfig != null ? connectionConfig : ConnectionConfig.DEFAULT;
final TimeValue connectTimeout = timeout != null ? timeout : config.getConnectTimeout(); final TimeValue connectTimeout = timeout != null ? timeout : config.getConnectTimeout();
final ManagedHttpClientConnection connection = internalEndpoint.getConnection(); final ManagedHttpClientConnection connection = internalEndpoint.getConnection();
if (LOG.isDebugEnabled()) {
LOG.debug("{} connecting endpoint to {} ({})", ConnPoolSupport.getId(endpoint), host, connectTimeout);
}
this.connectionOperator.connect( this.connectionOperator.connect(
connection, connection,
host, host,
@ -368,6 +371,9 @@ public class BasicHttpClientConnectionManager implements HttpClientConnectionMan
connectTimeout, connectTimeout,
this.socketConfig, this.socketConfig,
context); context);
if (LOG.isDebugEnabled()) {
LOG.debug("{} connected {}", ConnPoolSupport.getId(endpoint), ConnPoolSupport.getId(conn));
}
final Timeout socketTimeout = config.getSocketTimeout(); final Timeout socketTimeout = config.getSocketTimeout();
if (socketTimeout != null) { if (socketTimeout != null) {
connection.setSocketTimeout(socketTimeout); connection.setSocketTimeout(socketTimeout);

View File

@ -30,6 +30,7 @@ import java.io.IOException;
import java.net.InetAddress; import java.net.InetAddress;
import java.net.InetSocketAddress; import java.net.InetSocketAddress;
import java.net.Socket; import java.net.Socket;
import java.util.Arrays;
import org.apache.hc.client5.http.ConnectExceptionSupport; import org.apache.hc.client5.http.ConnectExceptionSupport;
import org.apache.hc.client5.http.DnsResolver; import org.apache.hc.client5.http.DnsResolver;
@ -115,12 +116,25 @@ public class DefaultHttpClientConnectionOperator implements HttpClientConnection
if (sf == null) { if (sf == null) {
throw new UnsupportedSchemeException(host.getSchemeName() + " protocol is not supported"); throw new UnsupportedSchemeException(host.getSchemeName() + " protocol is not supported");
} }
final InetAddress[] addresses = host.getAddress() != null ? final InetAddress[] remoteAddresses;
new InetAddress[] { host.getAddress() } : this.dnsResolver.resolve(host.getHostName()); 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); final int port = this.schemePortResolver.resolve(host);
for (int i = 0; i < addresses.length; i++) { for (int i = 0; i < remoteAddresses.length; i++) {
final InetAddress address = addresses[i]; final InetAddress address = remoteAddresses[i];
final boolean last = i == addresses.length - 1; final boolean last = i == remoteAddresses.length - 1;
Socket sock = sf.createSocket(context); Socket sock = sf.createSocket(context);
sock.setSoTimeout(socketConfig.getSoTimeout().toMillisecondsIntBound()); sock.setSoTimeout(socketConfig.getSoTimeout().toMillisecondsIntBound());
@ -142,22 +156,30 @@ public class DefaultHttpClientConnectionOperator implements HttpClientConnection
final InetSocketAddress remoteAddress = new InetSocketAddress(address, port); final InetSocketAddress remoteAddress = new InetSocketAddress(address, port);
if (LOG.isDebugEnabled()) { if (LOG.isDebugEnabled()) {
LOG.debug("{} connecting to {}", ConnPoolSupport.getId(conn), remoteAddress); LOG.debug("{}:{} connecting {}->{} ({})",
host.getHostName(), host.getPort(), localAddress, remoteAddress, connectTimeout);
} }
try { try {
sock = sf.connectSocket(connectTimeout, sock, host, remoteAddress, localAddress, context); sock = sf.connectSocket(connectTimeout, sock, host, remoteAddress, localAddress, context);
conn.bind(sock); conn.bind(sock);
if (LOG.isDebugEnabled()) { 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; return;
} catch (final IOException ex) { } catch (final IOException ex) {
if (last) { if (last) {
throw ConnectExceptionSupport.enhance(ex, host, addresses);
}
}
if (LOG.isDebugEnabled()) { if (LOG.isDebugEnabled()) {
LOG.debug("{} connect to {} timed out. Connection will be retried using another IP address", ConnPoolSupport.getId(conn), remoteAddress); 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());
}
}
} }
} }
} }

View File

@ -68,13 +68,14 @@ final class MultihomeIOSessionRequester {
if (remoteAddress != null) { if (remoteAddress != null) {
if (LOG.isDebugEnabled()) { 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); return connectionInitiator.connect(remoteEndpoint, remoteAddress, localAddress, connectTimeout, attachment, callback);
} }
if (LOG.isDebugEnabled()) { if (LOG.isDebugEnabled()) {
LOG.debug("{} resolving remote address", remoteEndpoint); LOG.debug("{} resolving remote address", remoteEndpoint.getHostName());
} }
final ComplexFuture<IOSession> future = new ComplexFuture<>(callback); final ComplexFuture<IOSession> future = new ComplexFuture<>(callback);
@ -87,7 +88,7 @@ final class MultihomeIOSessionRequester {
} }
if (LOG.isDebugEnabled()) { 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() { final Runnable runnable = new Runnable() {
@ -99,7 +100,8 @@ final class MultihomeIOSessionRequester {
final InetSocketAddress remoteAddress = new InetSocketAddress(remoteAddresses[index], remoteEndpoint.getPort()); final InetSocketAddress remoteAddress = new InetSocketAddress(remoteAddresses[index], remoteEndpoint.getPort());
if (LOG.isDebugEnabled()) { if (LOG.isDebugEnabled()) {
LOG.debug("{} connecting {} to {} ({})", remoteEndpoint, localAddress, remoteAddress, connectTimeout); LOG.debug("{}:{} connecting {}->{} ({})",
remoteEndpoint.getHostName(), remoteEndpoint.getPort(), localAddress, remoteAddress, connectTimeout);
} }
final Future<IOSession> sessionFuture = connectionInitiator.connect( final Future<IOSession> sessionFuture = connectionInitiator.connect(
@ -113,9 +115,8 @@ final class MultihomeIOSessionRequester {
@Override @Override
public void completed(final IOSession session) { public void completed(final IOSession session) {
if (LOG.isDebugEnabled()) { if (LOG.isDebugEnabled()) {
if (LOG.isDebugEnabled()) { LOG.debug("{}:{} connected {}->{} as {}",
LOG.debug("{} connected {} {}->{}", remoteEndpoint, session.getId(), session.getLocalAddress(), session.getRemoteAddress()); remoteEndpoint.getHostName(), remoteEndpoint.getPort(), localAddress, remoteAddress, session.getId());
}
} }
future.completed(session); future.completed(session);
} }
@ -124,7 +125,8 @@ final class MultihomeIOSessionRequester {
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()) { 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) { if (cause instanceof IOException) {
future.failed(ConnectExceptionSupport.enhance((IOException) cause, remoteEndpoint, remoteAddresses)); future.failed(ConnectExceptionSupport.enhance((IOException) cause, remoteEndpoint, remoteAddresses));
@ -133,7 +135,8 @@ final class MultihomeIOSessionRequester {
} }
} else { } else {
if (LOG.isDebugEnabled()) { 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(); executeNext();
} }