diff --git a/httpclient5/src/main/java/org/apache/hc/client5/http/impl/DefaultAuthenticationStrategy.java b/httpclient5/src/main/java/org/apache/hc/client5/http/impl/DefaultAuthenticationStrategy.java index 98e654ce4..ca0fdd408 100644 --- a/httpclient5/src/main/java/org/apache/hc/client5/http/impl/DefaultAuthenticationStrategy.java +++ b/httpclient5/src/main/java/org/apache/hc/client5/http/impl/DefaultAuthenticationStrategy.java @@ -80,11 +80,14 @@ public class DefaultAuthenticationStrategy implements AuthenticationStrategy { Args.notNull(challenges, "Map of auth challenges"); Args.notNull(context, "HTTP context"); final HttpClientContext clientContext = HttpClientContext.adapt(context); + final String exchangeId = clientContext.getExchangeId(); final List options = new ArrayList<>(); final Lookup registry = clientContext.getAuthSchemeRegistry(); if (registry == null) { - LOG.debug("Auth scheme registry not set in the context"); + if (LOG.isDebugEnabled()) { + LOG.debug("{} Auth scheme registry not set in the context", exchangeId); + } return options; } final RequestConfig config = clientContext.getRequestConfig(); @@ -94,7 +97,9 @@ public class DefaultAuthenticationStrategy implements AuthenticationStrategy { authPrefs = DEFAULT_SCHEME_PRIORITY; } if (LOG.isDebugEnabled()) { - LOG.debug("Authentication schemes in the order of preference: {}", authPrefs); + if (LOG.isDebugEnabled()) { + LOG.debug("{} Authentication schemes in the order of preference: {}", exchangeId, authPrefs); + } } for (final String schemeName: authPrefs) { @@ -103,7 +108,7 @@ public class DefaultAuthenticationStrategy implements AuthenticationStrategy { final AuthSchemeFactory authSchemeFactory = registry.lookup(schemeName); if (authSchemeFactory == null) { if (LOG.isWarnEnabled()) { - LOG.warn("Authentication scheme {} not supported", schemeName); + LOG.warn("{} Authentication scheme {} not supported", exchangeId, schemeName); // Try again } continue; @@ -112,7 +117,7 @@ public class DefaultAuthenticationStrategy implements AuthenticationStrategy { options.add(authScheme); } else { if (LOG.isDebugEnabled()) { - LOG.debug("Challenge for {} authentication scheme not available", schemeName); + LOG.debug("{}, Challenge for {} authentication scheme not available", exchangeId, schemeName); } } } diff --git a/httpclient5/src/main/java/org/apache/hc/client5/http/impl/async/AsyncConnectExec.java b/httpclient5/src/main/java/org/apache/hc/client5/http/impl/async/AsyncConnectExec.java index 07fa73928..10f8ebff7 100644 --- a/httpclient5/src/main/java/org/apache/hc/client5/http/impl/async/AsyncConnectExec.java +++ b/httpclient5/src/main/java/org/apache/hc/client5/http/impl/async/AsyncConnectExec.java @@ -129,7 +129,7 @@ public final class AsyncConnectExec implements AsyncExecChainHandler { if (!execRuntime.isEndpointAcquired()) { final Object userToken = clientContext.getUserToken(); if (LOG.isDebugEnabled()) { - LOG.debug("{}: acquiring connection with route {}", exchangeId, route); + LOG.debug("{} acquiring connection with route {}", exchangeId, route); } cancellableDependency.setDependency(execRuntime.acquireEndpoint( exchangeId, route, userToken, clientContext, new FutureCallback() { @@ -198,7 +198,7 @@ public final class AsyncConnectExec implements AsyncExecChainHandler { public void completed(final AsyncExecRuntime execRuntime) { tracker.connectTarget(route.isSecure()); if (LOG.isDebugEnabled()) { - LOG.debug("{}: connected to target", exchangeId); + LOG.debug("{} connected to target", exchangeId); } proceedToNextHop(state, request, entityProducer, scope, chain, asyncExecCallback); } @@ -224,7 +224,7 @@ public final class AsyncConnectExec implements AsyncExecChainHandler { final HttpHost proxy = route.getProxyHost(); tracker.connectProxy(proxy, route.isSecure() && !route.isTunnelled()); if (LOG.isDebugEnabled()) { - LOG.debug("{}: connected to proxy", exchangeId); + LOG.debug("{} connected to proxy", exchangeId); } proceedToNextHop(state, request, entityProducer, scope, chain, asyncExecCallback); } @@ -264,7 +264,7 @@ public final class AsyncConnectExec implements AsyncExecChainHandler { @Override public void completed() { if (LOG.isDebugEnabled()) { - LOG.debug("{}: tunnel to target created", exchangeId); + LOG.debug("{} tunnel to target created", exchangeId); } tracker.tunnelTarget(false); proceedToNextHop(state, request, entityProducer, scope, chain, asyncExecCallback); @@ -292,7 +292,7 @@ public final class AsyncConnectExec implements AsyncExecChainHandler { case HttpRouteDirector.LAYER_PROTOCOL: execRuntime.upgradeTls(clientContext); if (LOG.isDebugEnabled()) { - LOG.debug("{}: upgraded to TLS", exchangeId); + LOG.debug("{} upgraded to TLS", exchangeId); } tracker.layerProtocol(route.isSecure()); break; @@ -304,7 +304,7 @@ public final class AsyncConnectExec implements AsyncExecChainHandler { case HttpRouteDirector.COMPLETE: if (LOG.isDebugEnabled()) { - LOG.debug("{}: route fully established", exchangeId); + LOG.debug("{} route fully established", exchangeId); } try { chain.proceed(request, entityProducer, scope, asyncExecCallback); diff --git a/httpclient5/src/main/java/org/apache/hc/client5/http/impl/async/AsyncHttpRequestRetryExec.java b/httpclient5/src/main/java/org/apache/hc/client5/http/impl/async/AsyncHttpRequestRetryExec.java index 5dad5e8ab..0a9d31065 100644 --- a/httpclient5/src/main/java/org/apache/hc/client5/http/impl/async/AsyncHttpRequestRetryExec.java +++ b/httpclient5/src/main/java/org/apache/hc/client5/http/impl/async/AsyncHttpRequestRetryExec.java @@ -102,7 +102,7 @@ public final class AsyncHttpRequestRetryExec implements AsyncExecChainHandler { final HttpClientContext clientContext = scope.clientContext; if (entityProducer != null && !entityProducer.isRepeatable()) { if (LOG.isDebugEnabled()) { - LOG.debug("{}: cannot retry non-repeatable request", exchangeId); + LOG.debug("{} cannot retry non-repeatable request", exchangeId); } return asyncExecCallback.handleResponse(response, entityDetails); } @@ -140,11 +140,11 @@ public final class AsyncHttpRequestRetryExec implements AsyncExecChainHandler { final HttpClientContext clientContext = scope.clientContext; if (entityProducer != null && !entityProducer.isRepeatable()) { if (LOG.isDebugEnabled()) { - LOG.debug("{}: cannot retry non-repeatable request", exchangeId); + LOG.debug("{} cannot retry non-repeatable request", exchangeId); } } else if (retryStrategy.retryRequest(request, (IOException) cause, state.execCount, clientContext)) { if (LOG.isDebugEnabled()) { - LOG.debug("{}: {}", exchangeId, cause.getMessage(), cause); + LOG.debug("{} {}", exchangeId, cause.getMessage(), cause); } if (LOG.isInfoEnabled()) { LOG.info("Recoverable I/O exception ({}) caught when processing request to {}", diff --git a/httpclient5/src/main/java/org/apache/hc/client5/http/impl/async/AsyncProtocolExec.java b/httpclient5/src/main/java/org/apache/hc/client5/http/impl/async/AsyncProtocolExec.java index bcf43415f..406c26f30 100644 --- a/httpclient5/src/main/java/org/apache/hc/client5/http/impl/async/AsyncProtocolExec.java +++ b/httpclient5/src/main/java/org/apache/hc/client5/http/impl/async/AsyncProtocolExec.java @@ -168,13 +168,13 @@ public final class AsyncProtocolExec implements AsyncExecChainHandler { if (!request.containsHeader(HttpHeaders.AUTHORIZATION)) { if (LOG.isDebugEnabled()) { - LOG.debug("{}: target auth state: {}", exchangeId, targetAuthExchange.getState()); + LOG.debug("{} target auth state: {}", exchangeId, targetAuthExchange.getState()); } authenticator.addAuthResponse(target, ChallengeType.TARGET, request, targetAuthExchange, clientContext); } if (!request.containsHeader(HttpHeaders.PROXY_AUTHORIZATION) && !route.isTunnelled()) { if (LOG.isDebugEnabled()) { - LOG.debug("{}: proxy auth state: {}", exchangeId, proxyAuthExchange.getState()); + LOG.debug("{} proxy auth state: {}", exchangeId, proxyAuthExchange.getState()); } authenticator.addAuthResponse(proxy, ChallengeType.PROXY, request, proxyAuthExchange, clientContext); } @@ -213,14 +213,14 @@ public final class AsyncProtocolExec implements AsyncExecChainHandler { if (proxyAuthExchange.getState() == AuthExchange.State.SUCCESS && proxyAuthExchange.isConnectionBased()) { if (LOG.isDebugEnabled()) { - LOG.debug("{}: resetting proxy auth state", exchangeId); + LOG.debug("{} resetting proxy auth state", exchangeId); } proxyAuthExchange.reset(); } if (targetAuthExchange.getState() == AuthExchange.State.SUCCESS && targetAuthExchange.isConnectionBased()) { if (LOG.isDebugEnabled()) { - LOG.debug("{}: resetting target auth state", exchangeId); + LOG.debug("{} resetting target auth state", exchangeId); } targetAuthExchange.reset(); } @@ -229,7 +229,7 @@ public final class AsyncProtocolExec implements AsyncExecChainHandler { if (challenged.get()) { if (entityProducer != null && !entityProducer.isRepeatable()) { if (LOG.isDebugEnabled()) { - LOG.debug("{}: cannot retry non-repeatable request", exchangeId); + LOG.debug("{} cannot retry non-repeatable request", exchangeId); } asyncExecCallback.completed(); } else { diff --git a/httpclient5/src/main/java/org/apache/hc/client5/http/impl/async/AsyncRedirectExec.java b/httpclient5/src/main/java/org/apache/hc/client5/http/impl/async/AsyncRedirectExec.java index c2b331c6e..ea4568303 100644 --- a/httpclient5/src/main/java/org/apache/hc/client5/http/impl/async/AsyncRedirectExec.java +++ b/httpclient5/src/main/java/org/apache/hc/client5/http/impl/async/AsyncRedirectExec.java @@ -127,7 +127,7 @@ public final class AsyncRedirectExec implements AsyncExecChainHandler { final URI redirectUri = redirectStrategy.getLocationURI(request, response, clientContext); if (LOG.isDebugEnabled()) { - LOG.debug("{}: redirect requested to location '{}'", exchangeId, redirectUri); + LOG.debug("{} redirect requested to location '{}'", exchangeId, redirectUri); } if (!config.isCircularRedirectsAllowed()) { if (state.redirectLocations.contains(redirectUri)) { @@ -171,14 +171,14 @@ public final class AsyncRedirectExec implements AsyncExecChainHandler { state.reroute = true; final AuthExchange targetAuthExchange = clientContext.getAuthExchange(currentRoute.getTargetHost()); if (LOG.isDebugEnabled()) { - LOG.debug("{}: resetting target auth state", exchangeId); + LOG.debug("{} resetting target auth state", exchangeId); } targetAuthExchange.reset(); if (currentRoute.getProxyHost() != null) { final AuthExchange proxyAuthExchange = clientContext.getAuthExchange(currentRoute.getProxyHost()); if (proxyAuthExchange.isConnectionBased()) { if (LOG.isDebugEnabled()) { - LOG.debug("{}: resetting proxy auth state", exchangeId); + LOG.debug("{} resetting proxy auth state", exchangeId); } proxyAuthExchange.reset(); } @@ -190,7 +190,7 @@ public final class AsyncRedirectExec implements AsyncExecChainHandler { } if (state.redirectURI != null) { if (LOG.isDebugEnabled()) { - LOG.debug("{}: redirecting to '{}' via {}", exchangeId, state.redirectURI, currentRoute); + LOG.debug("{} redirecting to '{}' via {}", exchangeId, state.redirectURI, currentRoute); } return null; } @@ -214,7 +214,7 @@ public final class AsyncRedirectExec implements AsyncExecChainHandler { } if (entityProducer != null && !entityProducer.isRepeatable()) { if (LOG.isDebugEnabled()) { - LOG.debug("{}: cannot redirect non-repeatable request", exchangeId); + LOG.debug("{} cannot redirect non-repeatable request", exchangeId); } asyncExecCallback.completed(); } else { diff --git a/httpclient5/src/main/java/org/apache/hc/client5/http/impl/async/H2AsyncMainClientExec.java b/httpclient5/src/main/java/org/apache/hc/client5/http/impl/async/H2AsyncMainClientExec.java index 1127bd9c3..2a006b785 100644 --- a/httpclient5/src/main/java/org/apache/hc/client5/http/impl/async/H2AsyncMainClientExec.java +++ b/httpclient5/src/main/java/org/apache/hc/client5/http/impl/async/H2AsyncMainClientExec.java @@ -83,7 +83,7 @@ public class H2AsyncMainClientExec implements AsyncExecChainHandler { final AsyncExecRuntime execRuntime = scope.execRuntime; if (LOG.isDebugEnabled()) { - LOG.debug("{}: executing {}", exchangeId, new RequestLine(request)); + LOG.debug("{} executing {}", exchangeId, new RequestLine(request)); } final AsyncClientExchangeHandler internalExchangeHandler = new AsyncClientExchangeHandler() { diff --git a/httpclient5/src/main/java/org/apache/hc/client5/http/impl/async/HttpAsyncMainClientExec.java b/httpclient5/src/main/java/org/apache/hc/client5/http/impl/async/HttpAsyncMainClientExec.java index 806c35229..7816f4485 100644 --- a/httpclient5/src/main/java/org/apache/hc/client5/http/impl/async/HttpAsyncMainClientExec.java +++ b/httpclient5/src/main/java/org/apache/hc/client5/http/impl/async/HttpAsyncMainClientExec.java @@ -98,7 +98,7 @@ class HttpAsyncMainClientExec implements AsyncExecChainHandler { final AsyncExecRuntime execRuntime = scope.execRuntime; if (LOG.isDebugEnabled()) { - LOG.debug("{}: executing {}", exchangeId, new RequestLine(request)); + LOG.debug("{} executing {}", exchangeId, new RequestLine(request)); } final AtomicInteger messageCountDown = new AtomicInteger(2); diff --git a/httpclient5/src/main/java/org/apache/hc/client5/http/impl/async/InternalAbstractHttpAsyncClient.java b/httpclient5/src/main/java/org/apache/hc/client5/http/impl/async/InternalAbstractHttpAsyncClient.java index ca9ffc0a8..a8f145fc5 100644 --- a/httpclient5/src/main/java/org/apache/hc/client5/http/impl/async/InternalAbstractHttpAsyncClient.java +++ b/httpclient5/src/main/java/org/apache/hc/client5/http/impl/async/InternalAbstractHttpAsyncClient.java @@ -180,10 +180,11 @@ abstract class InternalAbstractHttpAsyncClient extends AbstractHttpAsyncClientBa clientContext); final String exchangeId = ExecSupport.getNextExchangeId(); if (LOG.isDebugEnabled()) { - LOG.debug("{}: preparing request execution", exchangeId); + LOG.debug("{} preparing request execution", exchangeId); } final AsyncExecRuntime execRuntime = createAsyncExecRuntime(pushHandlerFactory); + clientContext.setExchangeId(exchangeId); setupContext(clientContext); final AsyncExecChain.Scope scope = new AsyncExecChain.Scope(exchangeId, route, request, future, @@ -290,7 +291,7 @@ abstract class InternalAbstractHttpAsyncClient extends AbstractHttpAsyncClientBa @Override public void completed() { if (LOG.isDebugEnabled()) { - LOG.debug("{}: message exchange successfully completed", exchangeId); + LOG.debug("{} message exchange successfully completed", exchangeId); } try { execRuntime.releaseEndpoint(); @@ -303,7 +304,7 @@ abstract class InternalAbstractHttpAsyncClient extends AbstractHttpAsyncClientBa @Override public void failed(final Exception cause) { if (LOG.isDebugEnabled()) { - LOG.debug("{}: request failed: {}", exchangeId, cause.getMessage()); + LOG.debug("{} request failed: {}", exchangeId, cause.getMessage()); } try { execRuntime.discardEndpoint(); diff --git a/httpclient5/src/main/java/org/apache/hc/client5/http/impl/async/InternalH2AsyncExecRuntime.java b/httpclient5/src/main/java/org/apache/hc/client5/http/impl/async/InternalH2AsyncExecRuntime.java index 9a7a644dc..957eeacf8 100644 --- a/httpclient5/src/main/java/org/apache/hc/client5/http/impl/async/InternalH2AsyncExecRuntime.java +++ b/httpclient5/src/main/java/org/apache/hc/client5/http/impl/async/InternalH2AsyncExecRuntime.java @@ -89,7 +89,7 @@ class InternalH2AsyncExecRuntime implements AsyncExecRuntime { final RequestConfig requestConfig = context.getRequestConfig(); final Timeout connectTimeout = requestConfig.getConnectTimeout(); if (log.isDebugEnabled()) { - log.debug("{}: acquiring endpoint ({})", id, connectTimeout); + log.debug("{} acquiring endpoint ({})", id, connectTimeout); } return Operations.cancellable(connPool.getSession( target, @@ -101,7 +101,7 @@ class InternalH2AsyncExecRuntime implements AsyncExecRuntime { sessionRef.set(new Endpoint(target, ioSession)); reusable = true; if (log.isDebugEnabled()) { - log.debug("{}: acquired endpoint", id); + log.debug("{} acquired endpoint", id); } callback.completed(InternalH2AsyncExecRuntime.this); } @@ -125,7 +125,7 @@ class InternalH2AsyncExecRuntime implements AsyncExecRuntime { private void closeEndpoint(final Endpoint endpoint) { endpoint.session.close(CloseMode.GRACEFUL); if (log.isDebugEnabled()) { - log.debug("{}: endpoint closed", ConnPoolSupport.getId(endpoint)); + log.debug("{} endpoint closed", ConnPoolSupport.getId(endpoint)); } } @@ -186,7 +186,7 @@ class InternalH2AsyncExecRuntime implements AsyncExecRuntime { final RequestConfig requestConfig = context.getRequestConfig(); final Timeout connectTimeout = requestConfig.getConnectTimeout(); if (log.isDebugEnabled()) { - log.debug("{}: connecting endpoint ({})", ConnPoolSupport.getId(endpoint), connectTimeout); + log.debug("{} connecting endpoint ({})", ConnPoolSupport.getId(endpoint), connectTimeout); } return Operations.cancellable(connPool.getSession(target, connectTimeout, new FutureCallback() { @@ -196,7 +196,7 @@ class InternalH2AsyncExecRuntime implements AsyncExecRuntime { sessionRef.set(new Endpoint(target, ioSession)); reusable = true; if (log.isDebugEnabled()) { - log.debug("{}: endpoint connected", ConnPoolSupport.getId(endpoint)); + log.debug("{} endpoint connected", ConnPoolSupport.getId(endpoint)); } callback.completed(InternalH2AsyncExecRuntime.this); } @@ -229,7 +229,7 @@ class InternalH2AsyncExecRuntime implements AsyncExecRuntime { final IOSession session = endpoint.session; if (session.isOpen()) { if (log.isDebugEnabled()) { - log.debug("{}: start execution {}", ConnPoolSupport.getId(endpoint), id); + log.debug("{} start execution {}", ConnPoolSupport.getId(endpoint), id); } session.enqueue( new RequestExecutionCommand(exchangeHandler, pushHandlerFactory, complexCancellable, context), @@ -245,7 +245,7 @@ class InternalH2AsyncExecRuntime implements AsyncExecRuntime { sessionRef.set(new Endpoint(target, ioSession)); reusable = true; if (log.isDebugEnabled()) { - log.debug("{}: start execution {}", ConnPoolSupport.getId(endpoint), id); + log.debug("{} start execution {}", ConnPoolSupport.getId(endpoint), id); } session.enqueue( new RequestExecutionCommand(exchangeHandler, pushHandlerFactory, complexCancellable, context), 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 f29cbcbc3..7d47c47a3 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("{}: acquiring endpoint ({})", id, connectionRequestTimeout); + log.debug("{} acquiring endpoint ({})", id, 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("{}: acquired endpoint {}", id, ConnPoolSupport.getId(connectionEndpoint)); + log.debug("{} acquired endpoint {}", id, ConnPoolSupport.getId(connectionEndpoint)); } callback.completed(InternalHttpAsyncExecRuntime.this); } @@ -133,11 +133,11 @@ class InternalHttpAsyncExecRuntime implements AsyncExecRuntime { try { endpoint.close(CloseMode.IMMEDIATE); if (log.isDebugEnabled()) { - log.debug("{}: endpoint closed", ConnPoolSupport.getId(endpoint)); + log.debug("{} endpoint closed", ConnPoolSupport.getId(endpoint)); } } finally { if (log.isDebugEnabled()) { - log.debug("{}: discarding endpoint", ConnPoolSupport.getId(endpoint)); + log.debug("{} discarding endpoint", ConnPoolSupport.getId(endpoint)); } manager.release(endpoint, null, TimeValue.ZERO_MILLISECONDS); } @@ -149,7 +149,7 @@ class InternalHttpAsyncExecRuntime implements AsyncExecRuntime { if (endpoint != null) { if (reusable) { if (log.isDebugEnabled()) { - log.debug("{}: releasing valid endpoint", ConnPoolSupport.getId(endpoint)); + log.debug("{} releasing valid endpoint", ConnPoolSupport.getId(endpoint)); } manager.release(endpoint, state, validDuration); } else { @@ -205,7 +205,7 @@ class InternalHttpAsyncExecRuntime implements AsyncExecRuntime { final RequestConfig requestConfig = context.getRequestConfig(); final Timeout connectTimeout = requestConfig.getConnectTimeout(); if (log.isDebugEnabled()) { - log.debug("{}: connecting endpoint ({})", ConnPoolSupport.getId(endpoint), connectTimeout); + log.debug("{} connecting endpoint ({})", ConnPoolSupport.getId(endpoint), connectTimeout); } return Operations.cancellable(manager.connect( endpoint, @@ -218,7 +218,7 @@ class InternalHttpAsyncExecRuntime implements AsyncExecRuntime { @Override public void completed(final AsyncConnectionEndpoint endpoint) { if (log.isDebugEnabled()) { - log.debug("{}: endpoint connected", ConnPoolSupport.getId(endpoint)); + log.debug("{} endpoint connected", ConnPoolSupport.getId(endpoint)); } callback.completed(InternalHttpAsyncExecRuntime.this); } @@ -241,7 +241,7 @@ class InternalHttpAsyncExecRuntime implements AsyncExecRuntime { public void upgradeTls(final HttpClientContext context) { final AsyncConnectionEndpoint endpoint = ensureValid(); if (log.isDebugEnabled()) { - log.debug("{}: upgrading endpoint", ConnPoolSupport.getId(endpoint)); + log.debug("{} upgrading endpoint", ConnPoolSupport.getId(endpoint)); } manager.upgrade(endpoint, versionPolicy, context); } @@ -252,7 +252,7 @@ class InternalHttpAsyncExecRuntime implements AsyncExecRuntime { final AsyncConnectionEndpoint endpoint = ensureValid(); if (endpoint.isConnected()) { if (log.isDebugEnabled()) { - log.debug("{}: start execution {}", ConnPoolSupport.getId(endpoint), id); + log.debug("{} start execution {}", ConnPoolSupport.getId(endpoint), id); } final RequestConfig requestConfig = context.getRequestConfig(); final Timeout responseTimeout = requestConfig.getResponseTimeout(); @@ -275,7 +275,7 @@ class InternalHttpAsyncExecRuntime implements AsyncExecRuntime { @Override public void completed(final AsyncExecRuntime runtime) { if (log.isDebugEnabled()) { - log.debug("{}: start execution {}", ConnPoolSupport.getId(endpoint), id); + log.debug("{} start execution {}", ConnPoolSupport.getId(endpoint), id); } try { endpoint.execute(id, exchangeHandler, pushHandlerFactory, context); diff --git a/httpclient5/src/main/java/org/apache/hc/client5/http/impl/async/LoggingAsyncClientExchangeHandler.java b/httpclient5/src/main/java/org/apache/hc/client5/http/impl/async/LoggingAsyncClientExchangeHandler.java index 40365ddf8..29d954d3c 100644 --- a/httpclient5/src/main/java/org/apache/hc/client5/http/impl/async/LoggingAsyncClientExchangeHandler.java +++ b/httpclient5/src/main/java/org/apache/hc/client5/http/impl/async/LoggingAsyncClientExchangeHandler.java @@ -77,7 +77,8 @@ final class LoggingAsyncClientExchangeHandler implements AsyncClientExchangeHand final EntityDetails entityDetails, final HttpContext context) throws HttpException, IOException { if (log.isDebugEnabled()) { - log.debug("{}: send request {}, {}", exchangeId, new RequestLine(request), entityDetails != null ? "entity len " + entityDetails.getContentLength() : "null entity"); + log.debug("{} send request {}, {}", exchangeId, new RequestLine(request), + entityDetails != null ? "entity len " + entityDetails.getContentLength() : "null entity"); } channel.sendRequest(request, entityDetails, context); } @@ -93,7 +94,7 @@ final class LoggingAsyncClientExchangeHandler implements AsyncClientExchangeHand @Override public void produce(final DataStreamChannel channel) throws IOException { if (log.isDebugEnabled()) { - log.debug("{}: produce request data", exchangeId); + log.debug("{} produce request data", exchangeId); } handler.produce(new DataStreamChannel() { @@ -105,7 +106,7 @@ final class LoggingAsyncClientExchangeHandler implements AsyncClientExchangeHand @Override public int write(final ByteBuffer src) throws IOException { if (log.isDebugEnabled()) { - log.debug("{}: produce request data, len {} bytes", exchangeId, src.remaining()); + log.debug("{} produce request data, len {} bytes", exchangeId, src.remaining()); } return channel.write(src); } @@ -113,7 +114,7 @@ final class LoggingAsyncClientExchangeHandler implements AsyncClientExchangeHand @Override public void endStream() throws IOException { if (log.isDebugEnabled()) { - log.debug("{}: end of request data", exchangeId); + log.debug("{} end of request data", exchangeId); } channel.endStream(); } @@ -121,7 +122,7 @@ final class LoggingAsyncClientExchangeHandler implements AsyncClientExchangeHand @Override public void endStream(final List trailers) throws IOException { if (log.isDebugEnabled()) { - log.debug("{}: end of request data", exchangeId); + log.debug("{} end of request data", exchangeId); } channel.endStream(trailers); } @@ -134,7 +135,7 @@ final class LoggingAsyncClientExchangeHandler implements AsyncClientExchangeHand final HttpResponse response, final HttpContext context) throws HttpException, IOException { if (log.isDebugEnabled()) { - log.debug("{}: information response {}", exchangeId, new StatusLine(response)); + log.debug("{} information response {}", exchangeId, new StatusLine(response)); } handler.consumeInformation(response, context); } @@ -145,7 +146,7 @@ final class LoggingAsyncClientExchangeHandler implements AsyncClientExchangeHand final EntityDetails entityDetails, final HttpContext context) throws HttpException, IOException { if (log.isDebugEnabled()) { - log.debug("{}: consume response {}, {}", exchangeId, new StatusLine(response), entityDetails != null ? "entity len " + entityDetails.getContentLength() : " null entity"); + log.debug("{} consume response {}, {}", exchangeId, new StatusLine(response), entityDetails != null ? "entity len " + entityDetails.getContentLength() : " null entity"); } handler.consumeResponse(response, entityDetails, context); } @@ -158,7 +159,7 @@ final class LoggingAsyncClientExchangeHandler implements AsyncClientExchangeHand @Override public void update(final int increment) throws IOException { if (log.isDebugEnabled()) { - log.debug("{}: capacity update {}", exchangeId, increment); + log.debug("{} capacity update {}", exchangeId, increment); } capacityChannel.update(increment); } @@ -169,7 +170,7 @@ final class LoggingAsyncClientExchangeHandler implements AsyncClientExchangeHand @Override public void consume(final ByteBuffer src) throws IOException { if (log.isDebugEnabled()) { - log.debug("{}: consume response data, len {} bytes", exchangeId, src.remaining()); + log.debug("{} consume response data, len {} bytes", exchangeId, src.remaining()); } handler.consume(src); } @@ -177,7 +178,7 @@ final class LoggingAsyncClientExchangeHandler implements AsyncClientExchangeHand @Override public void streamEnd(final List trailers) throws HttpException, IOException { if (log.isDebugEnabled()) { - log.debug("{}: end of response data", exchangeId); + log.debug("{} end of response data", exchangeId); } handler.streamEnd(trailers); } @@ -185,7 +186,7 @@ final class LoggingAsyncClientExchangeHandler implements AsyncClientExchangeHand @Override public void failed(final Exception cause) { if (log.isDebugEnabled()) { - log.debug("{}: execution failed: {}", exchangeId, cause.getMessage()); + log.debug("{} execution failed: {}", exchangeId, cause.getMessage()); } handler.failed(cause); } @@ -193,7 +194,7 @@ final class LoggingAsyncClientExchangeHandler implements AsyncClientExchangeHand @Override public void cancel() { if (log.isDebugEnabled()) { - log.debug("{}: execution cancelled", exchangeId); + log.debug("{} execution cancelled", exchangeId); } handler.cancel(); } diff --git a/httpclient5/src/main/java/org/apache/hc/client5/http/impl/async/MinimalH2AsyncClient.java b/httpclient5/src/main/java/org/apache/hc/client5/http/impl/async/MinimalH2AsyncClient.java index 2a2361a14..cb67732ab 100644 --- a/httpclient5/src/main/java/org/apache/hc/client5/http/impl/async/MinimalH2AsyncClient.java +++ b/httpclient5/src/main/java/org/apache/hc/client5/http/impl/async/MinimalH2AsyncClient.java @@ -235,7 +235,7 @@ public final class MinimalH2AsyncClient extends AbstractMinimalHttpAsyncClientBa }; if (LOG.isDebugEnabled()) { final String exchangeId = ExecSupport.getNextExchangeId(); - LOG.debug("{}: executing message exchange {}", ConnPoolSupport.getId(session), exchangeId); + LOG.debug("{} executing message exchange {}", exchangeId, ConnPoolSupport.getId(session)); session.enqueue( new RequestExecutionCommand( new LoggingAsyncClientExchangeHandler(LOG, exchangeId, internalExchangeHandler), diff --git a/httpclient5/src/main/java/org/apache/hc/client5/http/impl/async/MinimalHttpAsyncClient.java b/httpclient5/src/main/java/org/apache/hc/client5/http/impl/async/MinimalHttpAsyncClient.java index 2c41d8da3..bb5e696af 100644 --- a/httpclient5/src/main/java/org/apache/hc/client5/http/impl/async/MinimalHttpAsyncClient.java +++ b/httpclient5/src/main/java/org/apache/hc/client5/http/impl/async/MinimalHttpAsyncClient.java @@ -469,7 +469,7 @@ public final class MinimalHttpAsyncClient extends AbstractMinimalHttpAsyncClient final String exchangeId = ExecSupport.getNextExchangeId(); if (LOG.isDebugEnabled()) { - LOG.debug("{}: executing message exchange {}", ConnPoolSupport.getId(connectionEndpoint), exchangeId); + LOG.debug("{} executing message exchange {}", exchangeId, ConnPoolSupport.getId(connectionEndpoint)); connectionEndpoint.execute( exchangeId, new LoggingAsyncClientExchangeHandler(LOG, exchangeId, exchangeHandler), diff --git a/httpclient5/src/main/java/org/apache/hc/client5/http/impl/auth/BasicScheme.java b/httpclient5/src/main/java/org/apache/hc/client5/http/impl/auth/BasicScheme.java index 427df1c82..438cc682c 100644 --- a/httpclient5/src/main/java/org/apache/hc/client5/http/impl/auth/BasicScheme.java +++ b/httpclient5/src/main/java/org/apache/hc/client5/http/impl/auth/BasicScheme.java @@ -49,6 +49,7 @@ import org.apache.hc.client5.http.auth.AuthenticationException; import org.apache.hc.client5.http.auth.Credentials; import org.apache.hc.client5.http.auth.CredentialsProvider; import org.apache.hc.client5.http.auth.MalformedChallengeException; +import org.apache.hc.client5.http.protocol.HttpClientContext; import org.apache.hc.client5.http.utils.ByteArrayBuilder; import org.apache.hc.core5.http.HttpHost; import org.apache.hc.core5.http.HttpRequest; @@ -154,7 +155,11 @@ public class BasicScheme implements AuthScheme, Serializable { return true; } - LOG.debug("No credentials found for auth scope [{}]", authScope); + if (LOG.isDebugEnabled()) { + final HttpClientContext clientContext = HttpClientContext.adapt(context); + final String exchangeId = clientContext.getExchangeId(); + LOG.debug("{} No credentials found for auth scope [{}]", exchangeId, authScope); + } this.username = null; this.password = null; return false; diff --git a/httpclient5/src/main/java/org/apache/hc/client5/http/impl/auth/DigestScheme.java b/httpclient5/src/main/java/org/apache/hc/client5/http/impl/auth/DigestScheme.java index 9aec18893..08cf173f7 100644 --- a/httpclient5/src/main/java/org/apache/hc/client5/http/impl/auth/DigestScheme.java +++ b/httpclient5/src/main/java/org/apache/hc/client5/http/impl/auth/DigestScheme.java @@ -54,6 +54,7 @@ import org.apache.hc.client5.http.auth.Credentials; import org.apache.hc.client5.http.auth.CredentialsProvider; import org.apache.hc.client5.http.auth.MalformedChallengeException; import org.apache.hc.client5.http.auth.StandardAuthScheme; +import org.apache.hc.client5.http.protocol.HttpClientContext; import org.apache.hc.client5.http.utils.ByteArrayBuilder; import org.apache.hc.core5.annotation.Internal; import org.apache.hc.core5.http.ClassicHttpRequest; @@ -194,7 +195,11 @@ public class DigestScheme implements AuthScheme, Serializable { return true; } - LOG.debug("No credentials found for auth scope [{}]", authScope); + if (LOG.isDebugEnabled()) { + final HttpClientContext clientContext = HttpClientContext.adapt(context); + final String exchangeId = clientContext.getExchangeId(); + LOG.debug("{} No credentials found for auth scope [{}]", exchangeId, authScope); + } this.username = null; this.password = null; return false; diff --git a/httpclient5/src/main/java/org/apache/hc/client5/http/impl/auth/GGSSchemeBase.java b/httpclient5/src/main/java/org/apache/hc/client5/http/impl/auth/GGSSchemeBase.java index a64d31ca9..a8e9dd2c9 100644 --- a/httpclient5/src/main/java/org/apache/hc/client5/http/impl/auth/GGSSchemeBase.java +++ b/httpclient5/src/main/java/org/apache/hc/client5/http/impl/auth/GGSSchemeBase.java @@ -44,6 +44,7 @@ import org.apache.hc.client5.http.auth.InvalidCredentialsException; import org.apache.hc.client5.http.auth.KerberosConfig; import org.apache.hc.client5.http.auth.KerberosCredentials; import org.apache.hc.client5.http.auth.MalformedChallengeException; +import org.apache.hc.client5.http.protocol.HttpClientContext; import org.apache.hc.core5.http.HttpHost; import org.apache.hc.core5.http.HttpRequest; import org.apache.hc.core5.http.protocol.HttpContext; @@ -115,7 +116,11 @@ public abstract class GGSSchemeBase implements AuthScheme { token = Base64.decodeBase64(challenge.getBytes()); state = State.CHALLENGE_RECEIVED; } else { - LOG.debug("Authentication already attempted"); + if (LOG.isDebugEnabled()) { + final HttpClientContext clientContext = HttpClientContext.adapt(context); + final String exchangeId = clientContext.getExchangeId(); + LOG.debug("{} Authentication already attempted", exchangeId); + } state = State.FAILED; } } @@ -220,7 +225,9 @@ public abstract class GGSSchemeBase implements AuthScheme { final String serviceName = host.getSchemeName().toUpperCase(Locale.ROOT); if (LOG.isDebugEnabled()) { - LOG.debug("init {}", authServer); + final HttpClientContext clientContext = HttpClientContext.adapt(context); + final String exchangeId = clientContext.getExchangeId(); + LOG.debug("{} init {}", exchangeId, authServer); } token = generateToken(token, serviceName, authServer); state = State.TOKEN_GENERATED; @@ -245,7 +252,9 @@ public abstract class GGSSchemeBase implements AuthScheme { final Base64 codec = new Base64(0); final String tokenstr = new String(codec.encode(token)); if (LOG.isDebugEnabled()) { - LOG.debug("Sending response '{}' back to the auth server", tokenstr); + final HttpClientContext clientContext = HttpClientContext.adapt(context); + final String exchangeId = clientContext.getExchangeId(); + LOG.debug("{} Sending response '{}' back to the auth server", exchangeId, tokenstr); } return StandardAuthScheme.SPNEGO + " " + tokenstr; default: diff --git a/httpclient5/src/main/java/org/apache/hc/client5/http/impl/auth/HttpAuthenticator.java b/httpclient5/src/main/java/org/apache/hc/client5/http/impl/auth/HttpAuthenticator.java index 041170f39..ceff31733 100644 --- a/httpclient5/src/main/java/org/apache/hc/client5/http/impl/auth/HttpAuthenticator.java +++ b/httpclient5/src/main/java/org/apache/hc/client5/http/impl/auth/HttpAuthenticator.java @@ -118,9 +118,12 @@ public final class HttpAuthenticator { } final HttpClientContext clientContext = HttpClientContext.adapt(context); + final String exchangeId = clientContext.getExchangeId(); if (response.getCode() == challengeCode) { - log.debug("Authentication required"); + if (log.isDebugEnabled()) { + log.debug("{} Authentication required", exchangeId); + } if (authExchange.getState() == AuthExchange.State.SUCCESS) { clearCache(host, clientContext); } @@ -129,7 +132,9 @@ public final class HttpAuthenticator { switch (authExchange.getState()) { case CHALLENGED: case HANDSHAKE: - log.debug("Authentication succeeded"); + if (log.isDebugEnabled()) { + log.debug("{} Authentication succeeded", exchangeId); + } authExchange.setState(AuthExchange.State.SUCCESS); updateCache(host, authExchange.getAuthScheme(), clientContext); break; @@ -162,11 +167,12 @@ public final class HttpAuthenticator { final AuthExchange authExchange, final HttpContext context) { - if (log.isDebugEnabled()) { - log.debug("{} requested authentication", host.toHostString()); - } - final HttpClientContext clientContext = HttpClientContext.adapt(context); + final String exchangeId = clientContext.getExchangeId(); + + if (log.isDebugEnabled()) { + log.debug("{} {} requested authentication", exchangeId, host.toHostString()); + } final Header[] headers = response.getHeaders( challengeType == ChallengeType.PROXY ? HttpHeaders.PROXY_AUTHENTICATE : HttpHeaders.WWW_AUTHENTICATE); @@ -192,7 +198,7 @@ public final class HttpAuthenticator { authChallenges = parser.parse(challengeType, buffer, cursor); } catch (final ParseException ex) { if (log.isWarnEnabled()) { - log.warn("Malformed challenge: {}", header.getValue()); + log.warn("{} Malformed challenge: {}", exchangeId, header.getValue()); } continue; } @@ -204,7 +210,9 @@ public final class HttpAuthenticator { } } if (challengeMap.isEmpty()) { - log.debug("Response contains no valid authentication challenges"); + if (log.isDebugEnabled()) { + log.debug("{} Response contains no valid authentication challenges", exchangeId); + } clearCache(host, clientContext); authExchange.reset(); return false; @@ -225,19 +233,23 @@ public final class HttpAuthenticator { final String schemeName = authScheme.getName(); final AuthChallenge challenge = challengeMap.get(schemeName.toLowerCase(Locale.ROOT)); if (challenge != null) { - log.debug("Authorization challenge processed"); + if (log.isDebugEnabled()) { + log.debug("{} Authorization challenge processed", exchangeId); + } try { authScheme.processChallenge(challenge, context); } catch (final MalformedChallengeException ex) { if (log.isWarnEnabled()) { - log.warn(ex.getMessage()); + log.warn("{} {}", exchangeId, ex.getMessage()); } clearCache(host, clientContext); authExchange.reset(); return false; } if (authScheme.isChallengeComplete()) { - log.debug("Authentication failed"); + if (log.isDebugEnabled()) { + log.debug("{} Authentication failed", exchangeId); + } clearCache(host, clientContext); authExchange.reset(); authExchange.setState(AuthExchange.State.FAILURE); @@ -254,12 +266,16 @@ public final class HttpAuthenticator { final List preferredSchemes = authStrategy.select(challengeType, challengeMap, context); final CredentialsProvider credsProvider = clientContext.getCredentialsProvider(); if (credsProvider == null) { - log.debug("Credentials provider not set in the context"); + if (log.isDebugEnabled()) { + log.debug("{} Credentials provider not set in the context", exchangeId); + } return false; } final Queue authOptions = new LinkedList<>(); - log.debug("Selecting authentication options"); + if (log.isDebugEnabled()) { + log.debug("{} Selecting authentication options", exchangeId); + } for (final AuthScheme authScheme: preferredSchemes) { try { final String schemeName = authScheme.getName(); @@ -276,7 +292,7 @@ public final class HttpAuthenticator { } if (!authOptions.isEmpty()) { if (log.isDebugEnabled()) { - log.debug("Selected authentication options: {}", authOptions); + log.debug("{} Selected authentication options: {}", exchangeId, authOptions); } authExchange.reset(); authExchange.setState(AuthExchange.State.CHALLENGED); @@ -302,6 +318,8 @@ public final class HttpAuthenticator { final HttpRequest request, final AuthExchange authExchange, final HttpContext context) { + final HttpClientContext clientContext = HttpClientContext.adapt(context); + final String exchangeId = clientContext.getExchangeId(); AuthScheme authScheme = authExchange.getAuthScheme(); switch (authExchange.getState()) { case FAILURE: @@ -322,7 +340,8 @@ public final class HttpAuthenticator { authScheme = authOptions.remove(); authExchange.select(authScheme); if (log.isDebugEnabled()) { - log.debug("Generating response to an authentication challenge using {} scheme", authScheme.getName()); + log.debug("{} Generating response to an authentication challenge using {} scheme", + exchangeId, authScheme.getName()); } try { final String authResponse = authScheme.generateAuthResponse(host, request, context); @@ -333,7 +352,7 @@ public final class HttpAuthenticator { break; } catch (final AuthenticationException ex) { if (log.isWarnEnabled()) { - log.warn("{} authentication error: {}", authScheme, ex.getMessage()); + log.warn("{} {} authentication error: {}", exchangeId, authScheme, ex.getMessage()); } } } @@ -351,7 +370,7 @@ public final class HttpAuthenticator { request.addHeader(header); } catch (final AuthenticationException ex) { if (log.isErrorEnabled()) { - log.error("{} authentication error: {}", authScheme, ex.getMessage()); + log.error("{} {} authentication error: {}", exchangeId, authScheme, ex.getMessage()); } } } @@ -366,7 +385,8 @@ public final class HttpAuthenticator { clientContext.setAuthCache(authCache); } if (log.isDebugEnabled()) { - log.debug("Caching '{}' auth scheme for {}", authScheme.getName(), host); + final String exchangeId = clientContext.getExchangeId(); + log.debug("{} Caching '{}' auth scheme for {}", exchangeId, authScheme.getName(), host); } authCache.put(host, authScheme); } @@ -377,7 +397,8 @@ public final class HttpAuthenticator { final AuthCache authCache = clientContext.getAuthCache(); if (authCache != null) { if (log.isDebugEnabled()) { - log.debug("Clearing cached auth scheme for {}", host); + final String exchangeId = clientContext.getExchangeId(); + log.debug("{} Clearing cached auth scheme for {}", exchangeId, host); } authCache.remove(host); } diff --git a/httpclient5/src/main/java/org/apache/hc/client5/http/impl/auth/NTLMScheme.java b/httpclient5/src/main/java/org/apache/hc/client5/http/impl/auth/NTLMScheme.java index d00644e9c..9a529c8d4 100644 --- a/httpclient5/src/main/java/org/apache/hc/client5/http/impl/auth/NTLMScheme.java +++ b/httpclient5/src/main/java/org/apache/hc/client5/http/impl/auth/NTLMScheme.java @@ -37,6 +37,7 @@ import org.apache.hc.client5.http.auth.Credentials; import org.apache.hc.client5.http.auth.CredentialsProvider; import org.apache.hc.client5.http.auth.MalformedChallengeException; import org.apache.hc.client5.http.auth.NTCredentials; +import org.apache.hc.client5.http.protocol.HttpClientContext; import org.apache.hc.core5.http.HttpHost; import org.apache.hc.core5.http.HttpRequest; import org.apache.hc.core5.http.protocol.HttpContext; @@ -138,7 +139,11 @@ public final class NTLMScheme implements AuthScheme { return true; } - LOG.debug("No credentials found for auth scope [{}]", authScope); + if (LOG.isDebugEnabled()) { + final HttpClientContext clientContext = HttpClientContext.adapt(context); + final String exchangeId = clientContext.getExchangeId(); + LOG.debug("{} No credentials found for auth scope [{}]", exchangeId, authScope); + } return false; } diff --git a/httpclient5/src/main/java/org/apache/hc/client5/http/impl/classic/ConnectExec.java b/httpclient5/src/main/java/org/apache/hc/client5/http/impl/classic/ConnectExec.java index 524a9dd04..e0a410acd 100644 --- a/httpclient5/src/main/java/org/apache/hc/client5/http/impl/classic/ConnectExec.java +++ b/httpclient5/src/main/java/org/apache/hc/client5/http/impl/classic/ConnectExec.java @@ -113,14 +113,14 @@ public final class ConnectExec implements ExecChainHandler { if (!execRuntime.isEndpointAcquired()) { final Object userToken = context.getUserToken(); if (LOG.isDebugEnabled()) { - LOG.debug("{}: acquiring connection with route {}", exchangeId, route); + LOG.debug("{} acquiring connection with route {}", exchangeId, route); } execRuntime.acquireEndpoint(exchangeId, route, userToken, context); } try { if (!execRuntime.isEndpointConnected()) { if (LOG.isDebugEnabled()) { - LOG.debug("{}: opening connection {}", exchangeId, route); + LOG.debug("{} opening connection {}", exchangeId, route); } final RouteTracker tracker = new RouteTracker(route); @@ -143,7 +143,7 @@ public final class ConnectExec implements ExecChainHandler { case HttpRouteDirector.TUNNEL_TARGET: { final boolean secure = createTunnelToTarget(exchangeId, route, request, execRuntime, context); if (LOG.isDebugEnabled()) { - LOG.debug("{}: tunnel to target created.", exchangeId); + LOG.debug("{} tunnel to target created.", exchangeId); } tracker.tunnelTarget(secure); } break; @@ -156,7 +156,7 @@ public final class ConnectExec implements ExecChainHandler { final int hop = fact.getHopCount()-1; // the hop to establish final boolean secure = createTunnelToProxy(route, hop, context); if (LOG.isDebugEnabled()) { - LOG.debug("{}: tunnel to proxy created.", exchangeId); + LOG.debug("{} tunnel to proxy created.", exchangeId); } tracker.tunnelProxy(route.getHopTarget(hop), secure); } break; @@ -234,7 +234,7 @@ public final class ConnectExec implements ExecChainHandler { // Retry request if (this.reuseStrategy.keepAlive(request, response, context)) { if (LOG.isDebugEnabled()) { - LOG.debug("{}: connection kept alive", exchangeId); + LOG.debug("{} connection kept alive", exchangeId); } // Consume response content final HttpEntity entity = response.getEntity(); diff --git a/httpclient5/src/main/java/org/apache/hc/client5/http/impl/classic/HttpRequestRetryExec.java b/httpclient5/src/main/java/org/apache/hc/client5/http/impl/classic/HttpRequestRetryExec.java index 4252f6d8a..bea13a451 100644 --- a/httpclient5/src/main/java/org/apache/hc/client5/http/impl/classic/HttpRequestRetryExec.java +++ b/httpclient5/src/main/java/org/apache/hc/client5/http/impl/classic/HttpRequestRetryExec.java @@ -98,13 +98,13 @@ public class HttpRequestRetryExec implements ExecChainHandler { final HttpEntity requestEntity = request.getEntity(); if (requestEntity != null && !requestEntity.isRepeatable()) { if (LOG.isDebugEnabled()) { - LOG.debug("{}: cannot retry non-repeatable request", exchangeId); + LOG.debug("{} cannot retry non-repeatable request", exchangeId); } throw ex; } if (retryStrategy.retryRequest(request, ex, execCount, context)) { if (LOG.isDebugEnabled()) { - LOG.debug("{}: {}", exchangeId, ex.getMessage(), ex); + LOG.debug("{} {}", exchangeId, ex.getMessage(), ex); } if (LOG.isInfoEnabled()) { LOG.info("Recoverable I/O exception ({}) caught when processing request to {}", @@ -127,7 +127,7 @@ public class HttpRequestRetryExec implements ExecChainHandler { final HttpEntity entity = request.getEntity(); if (entity != null && !entity.isRepeatable()) { if (LOG.isDebugEnabled()) { - LOG.debug("{}: cannot retry non-repeatable request", exchangeId); + LOG.debug("{} cannot retry non-repeatable request", exchangeId); } return response; } @@ -138,7 +138,7 @@ public class HttpRequestRetryExec implements ExecChainHandler { if (TimeValue.isPositive(nextInterval)) { try { if (LOG.isDebugEnabled()) { - LOG.debug("{}: wait for {}", exchangeId, nextInterval); + LOG.debug("{} wait for {}", exchangeId, nextInterval); } nextInterval.sleep(); } catch (final InterruptedException e) { 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 abd8afede..a3442653d 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("{}: acquiring endpoint ({})", id, connectionRequestTimeout); + log.debug("{} acquiring endpoint ({})", id, 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("{}: acquired endpoint {}", id, ConnPoolSupport.getId(connectionEndpoint)); + log.debug("{} acquired endpoint {}", id, ConnPoolSupport.getId(connectionEndpoint)); } } catch(final TimeoutException ex) { throw new ConnectionRequestTimeoutException(ex.getMessage()); @@ -159,11 +159,11 @@ class InternalExecRuntime implements ExecRuntime, Cancellable { final RequestConfig requestConfig = context.getRequestConfig(); final Timeout connectTimeout = requestConfig.getConnectTimeout(); if (log.isDebugEnabled()) { - log.debug("{}: connecting endpoint ({})", ConnPoolSupport.getId(endpoint), connectTimeout); + log.debug("{} connecting endpoint ({})", ConnPoolSupport.getId(endpoint), connectTimeout); } manager.connect(endpoint, connectTimeout, context); if (log.isDebugEnabled()) { - log.debug("{}: endpoint connected", ConnPoolSupport.getId(endpoint)); + log.debug("{} endpoint connected", ConnPoolSupport.getId(endpoint)); } } @@ -181,7 +181,7 @@ class InternalExecRuntime implements ExecRuntime, Cancellable { if (endpoint != null) { endpoint.close(); if (log.isDebugEnabled()) { - log.debug("{}: endpoint closed", ConnPoolSupport.getId(endpoint)); + log.debug("{} endpoint closed", ConnPoolSupport.getId(endpoint)); } } } @@ -190,7 +190,7 @@ class InternalExecRuntime implements ExecRuntime, Cancellable { public void upgradeTls(final HttpClientContext context) throws IOException { final ConnectionEndpoint endpoint = ensureValid(); if (log.isDebugEnabled()) { - log.debug("{}: upgrading endpoint", ConnPoolSupport.getId(endpoint)); + log.debug("{} upgrading endpoint", ConnPoolSupport.getId(endpoint)); } manager.upgrade(endpoint, context); } @@ -210,7 +210,7 @@ class InternalExecRuntime implements ExecRuntime, Cancellable { endpoint.setSocketTimeout(responseTimeout); } if (log.isDebugEnabled()) { - log.debug("{}: start execution {}", ConnPoolSupport.getId(endpoint), id); + log.debug("{} start execution {}", ConnPoolSupport.getId(endpoint), id); } return endpoint.execute(id, request, requestExecutor, context); } @@ -236,11 +236,11 @@ class InternalExecRuntime implements ExecRuntime, Cancellable { try { endpoint.close(CloseMode.IMMEDIATE); if (log.isDebugEnabled()) { - log.debug("{}: endpoint closed", ConnPoolSupport.getId(endpoint)); + log.debug("{} endpoint closed", ConnPoolSupport.getId(endpoint)); } } finally { if (log.isDebugEnabled()) { - log.debug("{}: discarding endpoint", ConnPoolSupport.getId(endpoint)); + log.debug("{} discarding endpoint", ConnPoolSupport.getId(endpoint)); } manager.release(endpoint, null, TimeValue.ZERO_MILLISECONDS); } @@ -252,7 +252,7 @@ class InternalExecRuntime implements ExecRuntime, Cancellable { if (endpoint != null) { if (reusable) { if (log.isDebugEnabled()) { - log.debug("{}: releasing valid endpoint", ConnPoolSupport.getId(endpoint)); + log.debug("{} releasing valid endpoint", ConnPoolSupport.getId(endpoint)); } manager.release(endpoint, state, validDuration); } else { @@ -275,7 +275,7 @@ class InternalExecRuntime implements ExecRuntime, Cancellable { final ConnectionEndpoint endpoint = endpointRef.getAndSet(null); if (endpoint != null) { if (log.isDebugEnabled()) { - log.debug("{}: cancel", ConnPoolSupport.getId(endpoint)); + log.debug("{} cancel", ConnPoolSupport.getId(endpoint)); } discardEndpoint(endpoint); } diff --git a/httpclient5/src/main/java/org/apache/hc/client5/http/impl/classic/InternalHttpClient.java b/httpclient5/src/main/java/org/apache/hc/client5/http/impl/classic/InternalHttpClient.java index 4cc9ce098..aa59a570d 100644 --- a/httpclient5/src/main/java/org/apache/hc/client5/http/impl/classic/InternalHttpClient.java +++ b/httpclient5/src/main/java/org/apache/hc/client5/http/impl/classic/InternalHttpClient.java @@ -169,7 +169,7 @@ class InternalHttpClient extends CloseableHttpClient implements Configurable { final HttpRoute route = determineRoute(target, request, localcontext); final String exchangeId = ExecSupport.getNextExchangeId(); if (LOG.isDebugEnabled()) { - LOG.debug("{}: preparing request execution", exchangeId); + LOG.debug("{} preparing request execution", exchangeId); } final ExecRuntime execRuntime = new InternalExecRuntime(LOG, connManager, requestExecutor, diff --git a/httpclient5/src/main/java/org/apache/hc/client5/http/impl/classic/MainClientExec.java b/httpclient5/src/main/java/org/apache/hc/client5/http/impl/classic/MainClientExec.java index 61b844bba..7bf2ea75f 100644 --- a/httpclient5/src/main/java/org/apache/hc/client5/http/impl/classic/MainClientExec.java +++ b/httpclient5/src/main/java/org/apache/hc/client5/http/impl/classic/MainClientExec.java @@ -99,7 +99,7 @@ public final class MainClientExec implements ExecChainHandler { final ExecRuntime execRuntime = scope.execRuntime; if (LOG.isDebugEnabled()) { - LOG.debug("{}: executing {}", exchangeId, new RequestLine(request)); + LOG.debug("{} executing {}", exchangeId, new RequestLine(request)); } try { RequestEntityProxy.enhance(request); @@ -123,7 +123,7 @@ public final class MainClientExec implements ExecChainHandler { } else { s = "indefinitely"; } - LOG.debug("{}: connection can be kept alive {}", exchangeId, s); + LOG.debug("{} connection can be kept alive {}", exchangeId, s); } execRuntime.markConnectionReusable(userToken, duration); } else { diff --git a/httpclient5/src/main/java/org/apache/hc/client5/http/impl/classic/ProtocolExec.java b/httpclient5/src/main/java/org/apache/hc/client5/http/impl/classic/ProtocolExec.java index 931202f6f..4fb7a904e 100644 --- a/httpclient5/src/main/java/org/apache/hc/client5/http/impl/classic/ProtocolExec.java +++ b/httpclient5/src/main/java/org/apache/hc/client5/http/impl/classic/ProtocolExec.java @@ -158,13 +158,13 @@ public final class ProtocolExec implements ExecChainHandler { if (!request.containsHeader(HttpHeaders.AUTHORIZATION)) { if (LOG.isDebugEnabled()) { - LOG.debug("{}: target auth state: {}", exchangeId, targetAuthExchange.getState()); + LOG.debug("{} target auth state: {}", exchangeId, targetAuthExchange.getState()); } authenticator.addAuthResponse(target, ChallengeType.TARGET, request, targetAuthExchange, context); } if (!request.containsHeader(HttpHeaders.PROXY_AUTHORIZATION) && !route.isTunnelled()) { if (LOG.isDebugEnabled()) { - LOG.debug("{}: proxy auth state: {}", exchangeId, proxyAuthExchange.getState()); + LOG.debug("{} proxy auth state: {}", exchangeId, proxyAuthExchange.getState()); } authenticator.addAuthResponse(proxy, ChallengeType.PROXY, request, proxyAuthExchange, context); } @@ -181,7 +181,7 @@ public final class ProtocolExec implements ExecChainHandler { final HttpEntity requestEntity = request.getEntity(); if (requestEntity != null && !requestEntity.isRepeatable()) { if (LOG.isDebugEnabled()) { - LOG.debug("{}: Cannot retry non-repeatable request", exchangeId); + LOG.debug("{} Cannot retry non-repeatable request", exchangeId); } return response; } @@ -195,14 +195,14 @@ public final class ProtocolExec implements ExecChainHandler { if (proxyAuthExchange.getState() == AuthExchange.State.SUCCESS && proxyAuthExchange.isConnectionBased()) { if (LOG.isDebugEnabled()) { - LOG.debug("{}: resetting proxy auth state", exchangeId); + LOG.debug("{} resetting proxy auth state", exchangeId); } proxyAuthExchange.reset(); } if (targetAuthExchange.getState() == AuthExchange.State.SUCCESS && targetAuthExchange.isConnectionBased()) { if (LOG.isDebugEnabled()) { - LOG.debug("{}: resetting target auth state", exchangeId); + LOG.debug("{} resetting target auth state", exchangeId); } targetAuthExchange.reset(); } diff --git a/httpclient5/src/main/java/org/apache/hc/client5/http/impl/classic/RedirectExec.java b/httpclient5/src/main/java/org/apache/hc/client5/http/impl/classic/RedirectExec.java index 85e721cce..4e1bea800 100644 --- a/httpclient5/src/main/java/org/apache/hc/client5/http/impl/classic/RedirectExec.java +++ b/httpclient5/src/main/java/org/apache/hc/client5/http/impl/classic/RedirectExec.java @@ -119,7 +119,7 @@ public final class RedirectExec implements ExecChainHandler { final HttpEntity requestEntity = request.getEntity(); if (requestEntity != null && !requestEntity.isRepeatable()) { if (LOG.isDebugEnabled()) { - LOG.debug("{}: cannot redirect non-repeatable request", exchangeId); + LOG.debug("{} cannot redirect non-repeatable request", exchangeId); } return response; } @@ -130,7 +130,7 @@ public final class RedirectExec implements ExecChainHandler { final URI redirectUri = this.redirectStrategy.getLocationURI(currentRequest, response, context); if (LOG.isDebugEnabled()) { - LOG.debug("{}: redirect requested to location '{}'", exchangeId, redirectUri); + LOG.debug("{} redirect requested to location '{}'", exchangeId, redirectUri); } if (!config.isCircularRedirectsAllowed()) { if (redirectLocations.contains(redirectUri)) { @@ -171,18 +171,18 @@ public final class RedirectExec implements ExecChainHandler { final HttpRoute newRoute = this.routePlanner.determineRoute(newTarget, context); if (!LangUtils.equals(currentRoute, newRoute)) { if (LOG.isDebugEnabled()) { - LOG.debug("{}: new route required", exchangeId); + LOG.debug("{} new route required", exchangeId); } final AuthExchange targetAuthExchange = context.getAuthExchange(currentRoute.getTargetHost()); if (LOG.isDebugEnabled()) { - LOG.debug("{}: resetting target auth state", exchangeId); + LOG.debug("{} resetting target auth state", exchangeId); } targetAuthExchange.reset(); if (currentRoute.getProxyHost() != null) { final AuthExchange proxyAuthExchange = context.getAuthExchange(currentRoute.getProxyHost()); if (proxyAuthExchange.isConnectionBased()) { if (LOG.isDebugEnabled()) { - LOG.debug("{}: resetting proxy auth state", exchangeId); + LOG.debug("{} resetting proxy auth state", exchangeId); } proxyAuthExchange.reset(); } @@ -197,7 +197,7 @@ public final class RedirectExec implements ExecChainHandler { } if (LOG.isDebugEnabled()) { - LOG.debug("{}: redirecting to '{}' via {}", exchangeId, redirectUri, currentRoute); + LOG.debug("{} redirecting to '{}' via {}", exchangeId, redirectUri, currentRoute); } currentRequest = redirect; RequestEntityProxy.enhance(currentRequest); @@ -217,7 +217,7 @@ public final class RedirectExec implements ExecChainHandler { EntityUtils.consume(response.getEntity()); } catch (final IOException ioex) { if (LOG.isDebugEnabled()) { - LOG.debug("{}: I/O error while releasing connection", exchangeId, ioex); + LOG.debug("{} I/O error while releasing connection", exchangeId, ioex); } } finally { response.close(); 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 3a4bb51af..e3ebefc5b 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 @@ -32,6 +32,7 @@ import java.util.Date; import java.util.concurrent.ExecutionException; import java.util.concurrent.TimeoutException; import java.util.concurrent.atomic.AtomicBoolean; +import java.util.concurrent.atomic.AtomicLong; import java.util.concurrent.atomic.AtomicReference; import org.apache.hc.client5.http.DnsResolver; @@ -253,9 +254,10 @@ public class BasicHttpClientConnectionManager implements HttpClientConnectionMan public synchronized void release(final ConnectionEndpoint endpoint, final Object state, final TimeValue keepAlive) { Args.notNull(endpoint, "Managed endpoint"); final InternalConnectionEndpoint internalEndpoint = cast(endpoint); + final String id = internalEndpoint.id; final ManagedHttpClientConnection conn = internalEndpoint.detach(); if (conn != null && LOG.isDebugEnabled()) { - LOG.debug("Releasing connection {}", conn); + LOG.debug("{} Releasing connection {}", id, conn); } if (this.closed.get()) { return; @@ -271,7 +273,7 @@ public class BasicHttpClientConnectionManager implements HttpClientConnectionMan this.conn = null; this.expiry = Long.MAX_VALUE; if (LOG.isDebugEnabled()) { - LOG.debug("Connection is not kept alive"); + LOG.debug("{} Connection is not kept alive", id); } } else { this.state = state; @@ -280,12 +282,12 @@ public class BasicHttpClientConnectionManager implements HttpClientConnectionMan } if (TimeValue.isPositive(keepAlive)) { if (LOG.isDebugEnabled()) { - LOG.debug("Connection can be kept alive for {}", keepAlive); + LOG.debug("{} Connection can be kept alive for {}", id, keepAlive); } this.expiry = this.updated + keepAlive.toMilliseconds(); } else { if (LOG.isDebugEnabled()) { - LOG.debug("Connection can be kept alive indefinitely"); + LOG.debug("{} Connection can be kept alive indefinitely", id); } this.expiry = Long.MAX_VALUE; } @@ -358,14 +360,18 @@ public class BasicHttpClientConnectionManager implements HttpClientConnectionMan } } + private static final AtomicLong COUNT = new AtomicLong(0); + class InternalConnectionEndpoint extends ConnectionEndpoint { private final HttpRoute route; private final AtomicReference connRef; + private final String id; public InternalConnectionEndpoint(final HttpRoute route, final ManagedHttpClientConnection conn) { this.route = route; this.connRef = new AtomicReference<>(conn); + this.id = String.format("ep-%010d", COUNT.getAndIncrement()); } HttpRoute getRoute() { @@ -419,12 +425,15 @@ public class BasicHttpClientConnectionManager implements HttpClientConnectionMan @Override public ClassicHttpResponse execute( - final String id, + final String exchangeId, final ClassicHttpRequest request, final HttpRequestExecutor requestExecutor, final HttpContext context) throws IOException, HttpException { Args.notNull(request, "HTTP request"); Args.notNull(requestExecutor, "Request executor"); + if (LOG.isDebugEnabled()) { + LOG.debug("{} executing exchange {}", id, exchangeId); + } return requestExecutor.execute(request, getValidatedConnection(), context); } 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 c2be78350..14a45f076 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 @@ -142,13 +142,13 @@ 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 to {}", ConnPoolSupport.getId(conn), remoteAddress); } 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("{} connection established {}", ConnPoolSupport.getId(conn), conn); } return; } catch (final IOException ex) { @@ -157,7 +157,7 @@ public class DefaultHttpClientConnectionOperator implements HttpClientConnection } } if (LOG.isDebugEnabled()) { - LOG.debug("{}: connect to {} timed out. Connection will be retried using another IP address", ConnPoolSupport.getId(conn), remoteAddress); + 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/io/DefaultManagedHttpClientConnection.java b/httpclient5/src/main/java/org/apache/hc/client5/http/impl/io/DefaultManagedHttpClientConnection.java index f92ac5e33..a5f80a169 100644 --- a/httpclient5/src/main/java/org/apache/hc/client5/http/impl/io/DefaultManagedHttpClientConnection.java +++ b/httpclient5/src/main/java/org/apache/hc/client5/http/impl/io/DefaultManagedHttpClientConnection.java @@ -153,7 +153,7 @@ final class DefaultManagedHttpClientConnection public void close() throws IOException { if (this.closed.compareAndSet(false, true)) { if (LOG.isDebugEnabled()) { - LOG.debug("{}: Close connection", this.id); + LOG.debug("{} Close connection", this.id); } super.close(); } @@ -162,7 +162,7 @@ final class DefaultManagedHttpClientConnection @Override public void setSocketTimeout(final Timeout timeout) { if (LOG.isDebugEnabled()) { - LOG.debug("{}: set socket timeout to {}", this.id, timeout); + LOG.debug("{} set socket timeout to {}", this.id, timeout); } super.setSocketTimeout(timeout); } @@ -171,7 +171,7 @@ final class DefaultManagedHttpClientConnection public void close(final CloseMode closeMode) { if (this.closed.compareAndSet(false, true)) { if (LOG.isDebugEnabled()) { - LOG.debug("{}: close connection {}", this.id, closeMode); + LOG.debug("{} close connection {}", this.id, closeMode); } super.close(closeMode); } diff --git a/httpclient5/src/main/java/org/apache/hc/client5/http/impl/io/PoolingHttpClientConnectionManager.java b/httpclient5/src/main/java/org/apache/hc/client5/http/impl/io/PoolingHttpClientConnectionManager.java index fcb6ab6dc..4c8d6d498 100644 --- a/httpclient5/src/main/java/org/apache/hc/client5/http/impl/io/PoolingHttpClientConnectionManager.java +++ b/httpclient5/src/main/java/org/apache/hc/client5/http/impl/io/PoolingHttpClientConnectionManager.java @@ -255,7 +255,7 @@ public class PoolingHttpClientConnectionManager final Object state) { Args.notNull(route, "HTTP route"); if (LOG.isDebugEnabled()) { - LOG.debug("{}: endpoint lease request ({}) {}", id, requestTimeout, ConnPoolSupport.formatStats(route, state, pool)); + LOG.debug("{} endpoint lease request ({}) {}", id, requestTimeout, ConnPoolSupport.formatStats(route, state, pool)); } final Future> leaseFuture = this.pool.lease(route, state, requestTimeout, null); return new LeaseRequest() { @@ -280,7 +280,7 @@ public class PoolingHttpClientConnectionManager throw ex; } if (LOG.isDebugEnabled()) { - LOG.debug("{}: endpoint leased {}", id, ConnPoolSupport.formatStats(route, state, pool)); + LOG.debug("{} endpoint leased {}", id, ConnPoolSupport.formatStats(route, state, pool)); } try { final TimeValue validateAfterInactivitySnapshot = validateAfterInactivity; @@ -296,7 +296,7 @@ public class PoolingHttpClientConnectionManager } if (stale) { if (LOG.isDebugEnabled()) { - LOG.debug("{}: connection {} is stale", id, ConnPoolSupport.getId(conn)); + LOG.debug("{} connection {} is stale", id, ConnPoolSupport.getId(conn)); } poolEntry.discardConnection(CloseMode.IMMEDIATE); } @@ -310,19 +310,19 @@ public class PoolingHttpClientConnectionManager } if (leaseFuture.isCancelled()) { if (LOG.isDebugEnabled()) { - LOG.debug("{}: endpoint lease cancelled", id); + LOG.debug("{} endpoint lease cancelled", id); } pool.release(poolEntry, false); } else { this.endpoint = new InternalConnectionEndpoint(poolEntry); if (LOG.isDebugEnabled()) { - LOG.debug("{}: acquired {}", id, ConnPoolSupport.getId(endpoint)); + LOG.debug("{} acquired {}", id, ConnPoolSupport.getId(endpoint)); } } return this.endpoint; } catch (final Exception ex) { if (LOG.isDebugEnabled()) { - LOG.debug("{}: endpoint lease failed", id); + LOG.debug("{} endpoint lease failed", id); } pool.release(poolEntry, false); throw new ExecutionException(ex.getMessage(), ex); @@ -346,7 +346,7 @@ public class PoolingHttpClientConnectionManager return; } if (LOG.isDebugEnabled()) { - LOG.debug("{}: releasing endpoint", ConnPoolSupport.getId(endpoint)); + LOG.debug("{} releasing endpoint", ConnPoolSupport.getId(endpoint)); } final ManagedHttpClientConnection conn = entry.getConnection(); if (conn != null && keepAlive == null) { @@ -365,11 +365,11 @@ public class PoolingHttpClientConnectionManager } else { s = "indefinitely"; } - LOG.debug("{}: connection {} can be kept alive {}", ConnPoolSupport.getId(endpoint), ConnPoolSupport.getId(conn), s); + LOG.debug("{} connection {} can be kept alive {}", ConnPoolSupport.getId(endpoint), ConnPoolSupport.getId(conn), s); } } else { if (LOG.isDebugEnabled()) { - LOG.debug("{}: connection is not kept alive", ConnPoolSupport.getId(endpoint)); + LOG.debug("{} connection is not kept alive", ConnPoolSupport.getId(endpoint)); } } } catch (final RuntimeException ex) { @@ -378,7 +378,7 @@ public class PoolingHttpClientConnectionManager } finally { this.pool.release(entry, reusable); if (LOG.isDebugEnabled()) { - LOG.debug("{}: connection released {}", ConnPoolSupport.getId(endpoint), ConnPoolSupport.formatStats(entry.getRoute(), entry.getState(), pool)); + LOG.debug("{} connection released {}", ConnPoolSupport.getId(endpoint), ConnPoolSupport.formatStats(entry.getRoute(), entry.getState(), pool)); } } } @@ -402,7 +402,7 @@ public class PoolingHttpClientConnectionManager host = route.getTargetHost(); } if (LOG.isDebugEnabled()) { - LOG.debug("{}: connecting endpoint to {} ({})", ConnPoolSupport.getId(endpoint), host, connectTimeout); + LOG.debug("{} connecting endpoint to {} ({})", ConnPoolSupport.getId(endpoint), host, connectTimeout); } final ManagedHttpClientConnection conn = poolEntry.getConnection(); final SocketConfig defaultSocketConfigSnapshot = defaultSocketConfig; @@ -414,7 +414,7 @@ public class PoolingHttpClientConnectionManager defaultSocketConfigSnapshot != null ? defaultSocketConfigSnapshot : SocketConfig.DEFAULT, context); if (LOG.isDebugEnabled()) { - LOG.debug("{}: connected {}", ConnPoolSupport.getId(endpoint), ConnPoolSupport.getId(conn)); + LOG.debug("{} connected {}", ConnPoolSupport.getId(endpoint), ConnPoolSupport.getId(conn)); } } @@ -591,7 +591,7 @@ public class PoolingHttpClientConnectionManager Args.notNull(requestExecutor, "Request executor"); final ManagedHttpClientConnection connection = getValidatedPoolEntry().getConnection(); if (LOG.isDebugEnabled()) { - LOG.debug("{}: executing exchange {} over {}", id, exchangeId, ConnPoolSupport.getId(connection)); + LOG.debug("{} executing exchange {} over {}", id, exchangeId, ConnPoolSupport.getId(connection)); } return requestExecutor.execute(request, connection, context); } diff --git a/httpclient5/src/main/java/org/apache/hc/client5/http/impl/nio/DefaultManagedAsyncClientConnection.java b/httpclient5/src/main/java/org/apache/hc/client5/http/impl/nio/DefaultManagedAsyncClientConnection.java index 4dd59a63e..5aa84393c 100644 --- a/httpclient5/src/main/java/org/apache/hc/client5/http/impl/nio/DefaultManagedAsyncClientConnection.java +++ b/httpclient5/src/main/java/org/apache/hc/client5/http/impl/nio/DefaultManagedAsyncClientConnection.java @@ -78,7 +78,7 @@ final class DefaultManagedAsyncClientConnection implements ManagedAsyncClientCon public void close(final CloseMode closeMode) { if (this.closed.compareAndSet(false, true)) { if (LOG.isDebugEnabled()) { - LOG.debug("{}: Shutdown connection {}", getId(), closeMode); + LOG.debug("{} Shutdown connection {}", getId(), closeMode); } ioSession.close(closeMode); } @@ -88,7 +88,7 @@ final class DefaultManagedAsyncClientConnection implements ManagedAsyncClientCon public void close() throws IOException { if (this.closed.compareAndSet(false, true)) { if (LOG.isDebugEnabled()) { - LOG.debug("{}: Close connection", getId()); + LOG.debug("{} Close connection", getId()); } ioSession.enqueue(new ShutdownCommand(CloseMode.GRACEFUL), Command.Priority.IMMEDIATE); } @@ -146,7 +146,7 @@ final class DefaultManagedAsyncClientConnection implements ManagedAsyncClientCon final SSLSessionVerifier verifier, final Timeout handshakeTimeout) throws UnsupportedOperationException { if (LOG.isDebugEnabled()) { - LOG.debug("{}: start TLS", getId()); + LOG.debug("{} start TLS", getId()); } if (ioSession instanceof TransportSecurityLayer) { ((TransportSecurityLayer) ioSession).startTls(sslContext, endpoint, sslBufferMode, initializer, verifier, @@ -170,7 +170,7 @@ final class DefaultManagedAsyncClientConnection implements ManagedAsyncClientCon @Override public void submitCommand(final Command command, final Command.Priority priority) { if (LOG.isDebugEnabled()) { - LOG.debug("{}: {} with {} priority", getId(), command.getClass().getSimpleName(), priority); + LOG.debug("{} {} with {} priority", getId(), command.getClass().getSimpleName(), priority); } ioSession.enqueue(command, Command.Priority.IMMEDIATE); } 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 c8fce14b5..4d90b8558 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,13 @@ final class MultihomeIOSessionRequester { if (remoteAddress != null) { if (LOG.isDebugEnabled()) { - LOG.debug("{}: connecting {} to {} ({})", remoteEndpoint, localAddress, remoteAddress, connectTimeout); + LOG.debug("{} connecting {} to {} ({})", remoteEndpoint, 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); } final ComplexFuture future = new ComplexFuture<>(callback); @@ -87,7 +87,7 @@ final class MultihomeIOSessionRequester { } if (LOG.isDebugEnabled()) { - LOG.debug("{}: resolved to {}", remoteEndpoint, Arrays.asList(remoteAddresses)); + LOG.debug("{} resolved to {}", remoteEndpoint, Arrays.asList(remoteAddresses)); } final Runnable runnable = new Runnable() { @@ -99,7 +99,7 @@ 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 {} to {} ({})", remoteEndpoint, localAddress, remoteAddress, connectTimeout); } final Future sessionFuture = connectionInitiator.connect( @@ -114,7 +114,7 @@ final class MultihomeIOSessionRequester { 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 {} {}->{}", remoteEndpoint, session.getId(), session.getLocalAddress(), session.getRemoteAddress()); } } future.completed(session); @@ -124,7 +124,7 @@ 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, remoteAddress, cause.getClass()); } if (cause instanceof IOException) { future.failed(ConnectExceptionSupport.enhance((IOException) cause, remoteEndpoint, remoteAddresses)); @@ -133,7 +133,7 @@ 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, remoteAddress, cause.getClass()); } executeNext(); } diff --git a/httpclient5/src/main/java/org/apache/hc/client5/http/impl/nio/PoolingAsyncClientConnectionManager.java b/httpclient5/src/main/java/org/apache/hc/client5/http/impl/nio/PoolingAsyncClientConnectionManager.java index b187cd183..a5d0aabef 100644 --- a/httpclient5/src/main/java/org/apache/hc/client5/http/impl/nio/PoolingAsyncClientConnectionManager.java +++ b/httpclient5/src/main/java/org/apache/hc/client5/http/impl/nio/PoolingAsyncClientConnectionManager.java @@ -219,7 +219,7 @@ public class PoolingAsyncClientConnectionManager implements AsyncClientConnectio final Timeout requestTimeout, final FutureCallback callback) { if (LOG.isDebugEnabled()) { - LOG.debug("{}: endpoint lease request ({}) {}", id, requestTimeout, ConnPoolSupport.formatStats(route, state, pool)); + LOG.debug("{} endpoint lease request ({}) {}", id, requestTimeout, ConnPoolSupport.formatStats(route, state, pool)); } final ComplexFuture resultFuture = new ComplexFuture<>(callback); final Future> leaseFuture = pool.lease( @@ -231,11 +231,11 @@ public class PoolingAsyncClientConnectionManager implements AsyncClientConnectio connection.activate(); } if (LOG.isDebugEnabled()) { - LOG.debug("{}: endpoint leased {}", id, ConnPoolSupport.formatStats(route, state, pool)); + LOG.debug("{} endpoint leased {}", id, ConnPoolSupport.formatStats(route, state, pool)); } final AsyncConnectionEndpoint endpoint = new InternalConnectionEndpoint(poolEntry); if (LOG.isDebugEnabled()) { - LOG.debug("{}: acquired {}", id, ConnPoolSupport.getId(endpoint)); + LOG.debug("{} acquired {}", id, ConnPoolSupport.getId(endpoint)); } resultFuture.completed(endpoint); } @@ -254,7 +254,7 @@ public class PoolingAsyncClientConnectionManager implements AsyncClientConnectio public void execute(final Boolean result) { if (result == null || !result) { if (LOG.isDebugEnabled()) { - LOG.debug("{}: connection {} is stale", id, ConnPoolSupport.getId(connection)); + LOG.debug("{} connection {} is stale", id, ConnPoolSupport.getId(connection)); } poolEntry.discardConnection(CloseMode.IMMEDIATE); } @@ -265,7 +265,7 @@ public class PoolingAsyncClientConnectionManager implements AsyncClientConnectio } else { if (!connection.isOpen()) { if (LOG.isDebugEnabled()) { - LOG.debug("{}: connection {} is closed", id, ConnPoolSupport.getId(connection)); + LOG.debug("{} connection {} is closed", id, ConnPoolSupport.getId(connection)); } poolEntry.discardConnection(CloseMode.IMMEDIATE); } @@ -279,7 +279,7 @@ public class PoolingAsyncClientConnectionManager implements AsyncClientConnectio @Override public void failed(final Exception ex) { if (LOG.isDebugEnabled()) { - LOG.debug("{}: endpoint lease failed", id); + LOG.debug("{} endpoint lease failed", id); } resultFuture.failed(ex); } @@ -287,7 +287,7 @@ public class PoolingAsyncClientConnectionManager implements AsyncClientConnectio @Override public void cancelled() { if (LOG.isDebugEnabled()) { - LOG.debug("{}: endpoint lease cancelled", id); + LOG.debug("{} endpoint lease cancelled", id); } resultFuture.cancel(); } @@ -307,7 +307,7 @@ public class PoolingAsyncClientConnectionManager implements AsyncClientConnectio return; } if (LOG.isDebugEnabled()) { - LOG.debug("{}: releasing endpoint", ConnPoolSupport.getId(endpoint)); + LOG.debug("{} releasing endpoint", ConnPoolSupport.getId(endpoint)); } final ManagedAsyncClientConnection connection = entry.getConnection(); boolean reusable = connection != null && connection.isOpen(); @@ -323,7 +323,7 @@ public class PoolingAsyncClientConnectionManager implements AsyncClientConnectio } else { s = "indefinitely"; } - LOG.debug("{}: connection {} can be kept alive {}", ConnPoolSupport.getId(endpoint), ConnPoolSupport.getId(connection), s); + LOG.debug("{} connection {} can be kept alive {}", ConnPoolSupport.getId(endpoint), ConnPoolSupport.getId(connection), s); } } } catch (final RuntimeException ex) { @@ -332,7 +332,7 @@ public class PoolingAsyncClientConnectionManager implements AsyncClientConnectio } finally { pool.release(entry, reusable); if (LOG.isDebugEnabled()) { - LOG.debug("{}: connection released {}", ConnPoolSupport.getId(endpoint), ConnPoolSupport.formatStats(entry.getRoute(), entry.getState(), pool)); + LOG.debug("{} connection released {}", ConnPoolSupport.getId(endpoint), ConnPoolSupport.formatStats(entry.getRoute(), entry.getState(), pool)); } } } @@ -364,7 +364,7 @@ public class PoolingAsyncClientConnectionManager implements AsyncClientConnectio } final InetSocketAddress localAddress = route.getLocalSocketAddress(); if (LOG.isDebugEnabled()) { - LOG.debug("{}: connecting endpoint to {} ({})", ConnPoolSupport.getId(endpoint), host, connectTimeout); + LOG.debug("{} connecting endpoint to {} ({})", ConnPoolSupport.getId(endpoint), host, connectTimeout); } final Future connectFuture = connectionOperator.connect( connectionInitiator, host, localAddress, connectTimeout, attachment, new FutureCallback() { @@ -373,7 +373,7 @@ public class PoolingAsyncClientConnectionManager implements AsyncClientConnectio public void completed(final ManagedAsyncClientConnection connection) { try { if (LOG.isDebugEnabled()) { - LOG.debug("{}: connected {}", ConnPoolSupport.getId(endpoint), ConnPoolSupport.getId(connection)); + LOG.debug("{} connected {}", ConnPoolSupport.getId(endpoint), ConnPoolSupport.getId(connection)); } poolEntry.assignConnection(connection); resultFuture.completed(internalEndpoint); @@ -409,7 +409,7 @@ public class PoolingAsyncClientConnectionManager implements AsyncClientConnectio final ManagedAsyncClientConnection connection = poolEntry.getConnection(); connectionOperator.upgrade(poolEntry.getConnection(), route.getTargetHost(), attachment); if (LOG.isDebugEnabled()) { - LOG.debug("{}: upgraded {}", ConnPoolSupport.getId(internalEndpoint), ConnPoolSupport.getId(connection)); + LOG.debug("{} upgraded {}", ConnPoolSupport.getId(internalEndpoint), ConnPoolSupport.getId(connection)); } } @@ -524,7 +524,7 @@ public class PoolingAsyncClientConnectionManager implements AsyncClientConnectio final PoolEntry poolEntry = poolEntryRef.get(); if (poolEntry != null) { if (LOG.isDebugEnabled()) { - LOG.debug("{}: close {}", id, closeMode); + LOG.debug("{} close {}", id, closeMode); } poolEntry.discardConnection(closeMode); } @@ -560,7 +560,7 @@ public class PoolingAsyncClientConnectionManager implements AsyncClientConnectio final HttpContext context) { final ManagedAsyncClientConnection connection = getValidatedPoolEntry().getConnection(); if (LOG.isDebugEnabled()) { - LOG.debug("{}: executing exchange {} over {}", id, exchangeId, ConnPoolSupport.getId(connection)); + LOG.debug("{} executing exchange {} over {}", id, exchangeId, ConnPoolSupport.getId(connection)); } connection.submitCommand( new RequestExecutionCommand(exchangeHandler, pushHandlerFactory, context), diff --git a/httpclient5/src/main/java/org/apache/hc/client5/http/protocol/HttpClientContext.java b/httpclient5/src/main/java/org/apache/hc/client5/http/protocol/HttpClientContext.java index 6036dd7d8..217dac8ba 100644 --- a/httpclient5/src/main/java/org/apache/hc/client5/http/protocol/HttpClientContext.java +++ b/httpclient5/src/main/java/org/apache/hc/client5/http/protocol/HttpClientContext.java @@ -130,6 +130,12 @@ public class HttpClientContext extends HttpCoreContext { */ public static final String REQUEST_CONFIG = "http.request-config"; + /** + * Attribute name of a {@link java.lang.String} object that represents the ID of the + * current message exchange. + */ + public static final String EXCHANGE_ID = "http.exchange-id"; + public static HttpClientContext adapt(final HttpContext context) { Args.notNull(context, "HTTP context"); if (context instanceof HttpClientContext) { @@ -276,4 +282,18 @@ public class HttpClientContext extends HttpCoreContext { setAttribute(REQUEST_CONFIG, config); } + /** + * @since 5.1 + */ + public String getExchangeId() { + return getAttribute(EXCHANGE_ID, String.class); + } + + /** + * @since 5.1 + */ + public void setExchangeId(final String id) { + setAttribute(EXCHANGE_ID, id); + } + } diff --git a/httpclient5/src/main/java/org/apache/hc/client5/http/protocol/RequestAddCookies.java b/httpclient5/src/main/java/org/apache/hc/client5/http/protocol/RequestAddCookies.java index d2e9ffdd9..a0d926119 100644 --- a/httpclient5/src/main/java/org/apache/hc/client5/http/protocol/RequestAddCookies.java +++ b/httpclient5/src/main/java/org/apache/hc/client5/http/protocol/RequestAddCookies.java @@ -83,25 +83,32 @@ public class RequestAddCookies implements HttpRequestInterceptor { } final HttpClientContext clientContext = HttpClientContext.adapt(context); + final String exchangeId = clientContext.getExchangeId(); // Obtain cookie store final CookieStore cookieStore = clientContext.getCookieStore(); if (cookieStore == null) { - LOG.debug("Cookie store not specified in HTTP context"); + if (LOG.isDebugEnabled()) { + LOG.debug("{} Cookie store not specified in HTTP context", exchangeId); + } return; } // Obtain the registry of cookie specs final Lookup registry = clientContext.getCookieSpecRegistry(); if (registry == null) { - LOG.debug("CookieSpec registry not specified in HTTP context"); + if (LOG.isDebugEnabled()) { + LOG.debug("{} CookieSpec registry not specified in HTTP context", exchangeId); + } return; } // Obtain the route (required) final RouteInfo route = clientContext.getHttpRoute(); if (route == null) { - LOG.debug("Connection route not set in the context"); + if (LOG.isDebugEnabled()) { + LOG.debug("{} Connection route not set in the context", exchangeId); + } return; } @@ -111,7 +118,7 @@ public class RequestAddCookies implements HttpRequestInterceptor { cookieSpecName = StandardCookieSpec.STRICT; } if (LOG.isDebugEnabled()) { - LOG.debug("Cookie spec selected: {}", cookieSpecName); + LOG.debug("{} Cookie spec selected: {}", exchangeId, cookieSpecName); } final URIAuthority authority = request.getAuthority(); @@ -133,9 +140,8 @@ public class RequestAddCookies implements HttpRequestInterceptor { final CookieSpecFactory factory = registry.lookup(cookieSpecName); if (factory == null) { if (LOG.isDebugEnabled()) { - LOG.debug("Unsupported cookie spec: {}", cookieSpecName); + LOG.debug("{} Unsupported cookie spec: {}", exchangeId, cookieSpecName); } - return; } final CookieSpec cookieSpec = factory.create(clientContext); @@ -149,13 +155,13 @@ public class RequestAddCookies implements HttpRequestInterceptor { if (!cookie.isExpired(now)) { if (cookieSpec.match(cookie, cookieOrigin)) { if (LOG.isDebugEnabled()) { - LOG.debug("Cookie {} match {}", cookie, cookieOrigin); + LOG.debug("{} Cookie {} match {}", exchangeId, cookie, cookieOrigin); } matchedCookies.add(cookie); } } else { if (LOG.isDebugEnabled()) { - LOG.debug("Cookie {} expired", cookie); + LOG.debug("{} Cookie {} expired", exchangeId, cookie); } expired = true; } diff --git a/httpclient5/src/main/java/org/apache/hc/client5/http/protocol/RequestAuthCache.java b/httpclient5/src/main/java/org/apache/hc/client5/http/protocol/RequestAuthCache.java index f44241012..597bb21a0 100644 --- a/httpclient5/src/main/java/org/apache/hc/client5/http/protocol/RequestAuthCache.java +++ b/httpclient5/src/main/java/org/apache/hc/client5/http/protocol/RequestAuthCache.java @@ -70,22 +70,29 @@ public class RequestAuthCache implements HttpRequestInterceptor { Args.notNull(context, "HTTP context"); final HttpClientContext clientContext = HttpClientContext.adapt(context); + final String exchangeId = clientContext.getExchangeId(); final AuthCache authCache = clientContext.getAuthCache(); if (authCache == null) { - LOG.debug("Auth cache not set in the context"); + if (LOG.isDebugEnabled()) { + LOG.debug("{} Auth cache not set in the context", exchangeId); + } return; } final CredentialsProvider credsProvider = clientContext.getCredentialsProvider(); if (credsProvider == null) { - LOG.debug("Credentials provider not set in the context"); + if (LOG.isDebugEnabled()) { + LOG.debug("{} Credentials provider not set in the context", exchangeId); + } return; } final RouteInfo route = clientContext.getHttpRoute(); if (route == null) { - LOG.debug("Route info not set in the context"); + if (LOG.isDebugEnabled()) { + LOG.debug("{} Route info not set in the context", exchangeId); + } return; } @@ -104,7 +111,7 @@ public class RequestAuthCache implements HttpRequestInterceptor { final AuthScheme authScheme = authCache.get(target); if (authScheme != null) { if (LOG.isDebugEnabled()) { - LOG.debug("Re-using cached '{}' auth scheme for {}", authScheme.getName(), target); + LOG.debug("{} Re-using cached '{}' auth scheme for {}", exchangeId, authScheme.getName(), target); } targetAuthExchange.select(authScheme); } @@ -117,7 +124,7 @@ public class RequestAuthCache implements HttpRequestInterceptor { final AuthScheme authScheme = authCache.get(proxy); if (authScheme != null) { if (LOG.isDebugEnabled()) { - LOG.debug("Re-using cached '{}' auth scheme for {}", authScheme.getName(), proxy); + LOG.debug("{} Re-using cached '{}' auth scheme for {}", exchangeId, authScheme.getName(), proxy); } proxyAuthExchange.select(authScheme); } diff --git a/httpclient5/src/main/java/org/apache/hc/client5/http/protocol/RequestClientConnControl.java b/httpclient5/src/main/java/org/apache/hc/client5/http/protocol/RequestClientConnControl.java index deee1c20b..563a5fb7e 100644 --- a/httpclient5/src/main/java/org/apache/hc/client5/http/protocol/RequestClientConnControl.java +++ b/httpclient5/src/main/java/org/apache/hc/client5/http/protocol/RequestClientConnControl.java @@ -70,11 +70,14 @@ public class RequestClientConnControl implements HttpRequestInterceptor { } final HttpClientContext clientContext = HttpClientContext.adapt(context); + final String exchangeId = clientContext.getExchangeId(); // Obtain the client connection (required) final RouteInfo route = clientContext.getHttpRoute(); if (route == null) { - LOG.debug("Connection route not set in the context"); + if (LOG.isDebugEnabled()) { + LOG.debug("{} Connection route not set in the context", exchangeId); + } return; } diff --git a/httpclient5/src/main/java/org/apache/hc/client5/http/protocol/ResponseProcessCookies.java b/httpclient5/src/main/java/org/apache/hc/client5/http/protocol/ResponseProcessCookies.java index c6d4e9dfa..587a9cd8b 100644 --- a/httpclient5/src/main/java/org/apache/hc/client5/http/protocol/ResponseProcessCookies.java +++ b/httpclient5/src/main/java/org/apache/hc/client5/http/protocol/ResponseProcessCookies.java @@ -70,30 +70,38 @@ public class ResponseProcessCookies implements HttpResponseInterceptor { Args.notNull(context, "HTTP context"); final HttpClientContext clientContext = HttpClientContext.adapt(context); + final String exchangeId = clientContext.getExchangeId(); // Obtain actual CookieSpec instance final CookieSpec cookieSpec = clientContext.getCookieSpec(); if (cookieSpec == null) { - LOG.debug("Cookie spec not specified in HTTP context"); + if (LOG.isDebugEnabled()) { + LOG.debug("{} Cookie spec not specified in HTTP context", exchangeId); + } return; } // Obtain cookie store final CookieStore cookieStore = clientContext.getCookieStore(); if (cookieStore == null) { - LOG.debug("Cookie store not specified in HTTP context"); + if (LOG.isDebugEnabled()) { + LOG.debug("{} Cookie store not specified in HTTP context", exchangeId); + } return; } // Obtain actual CookieOrigin instance final CookieOrigin cookieOrigin = clientContext.getCookieOrigin(); if (cookieOrigin == null) { - LOG.debug("Cookie origin not specified in HTTP context"); + if (LOG.isDebugEnabled()) { + LOG.debug("{} Cookie origin not specified in HTTP context", exchangeId); + } return; } final Iterator
it = response.headerIterator("Set-Cookie"); - processCookies(it, cookieSpec, cookieOrigin, cookieStore); + processCookies(exchangeId, it, cookieSpec, cookieOrigin, cookieStore); } private void processCookies( + final String exchangeId, final Iterator
iterator, final CookieSpec cookieSpec, final CookieOrigin cookieOrigin, @@ -108,17 +116,19 @@ public class ResponseProcessCookies implements HttpResponseInterceptor { cookieStore.addCookie(cookie); if (LOG.isDebugEnabled()) { - LOG.debug("Cookie accepted [{}]", formatCooke(cookie)); + if (LOG.isDebugEnabled()) { + LOG.debug("{} Cookie accepted [{}]", exchangeId, formatCooke(cookie)); + } } } catch (final MalformedCookieException ex) { if (LOG.isWarnEnabled()) { - LOG.warn("Cookie rejected [{}] {}", formatCooke(cookie), ex.getMessage()); + LOG.warn("{} Cookie rejected [{}] {}", exchangeId, formatCooke(cookie), ex.getMessage()); } } } } catch (final MalformedCookieException ex) { if (LOG.isWarnEnabled()) { - LOG.warn("Invalid cookie header: \"{}\". {}", header, ex.getMessage()); + LOG.warn("{} Invalid cookie header: \"{}\". {}", exchangeId, header, ex.getMessage()); } } }