Skip to content

Commit fac66b6

Browse files
ok2cok2c
committed
HTTPCLIENT-2371: Logging of request re-execution at INFO priority
1 parent aab688b commit fac66b6

2 files changed

Lines changed: 26 additions & 20 deletions

File tree

‎httpclient5/src/main/java/org/apache/hc/client5/http/impl/async/AsyncHttpRequestRetryExec.java‎

Lines changed: 12 additions & 10 deletions
Original file line numberDiff line numberDiff line change
@@ -29,7 +29,6 @@
2929
import java.io.IOException;
3030

3131
import org.apache.hc.client5.http.HttpRequestRetryStrategy;
32-
import org.apache.hc.client5.http.HttpRoute;
3332
import org.apache.hc.client5.http.async.AsyncExecCallback;
3433
import org.apache.hc.client5.http.async.AsyncExecChain;
3534
import org.apache.hc.client5.http.async.AsyncExecChainHandler;
@@ -40,6 +39,7 @@
4039
import org.apache.hc.core5.annotation.ThreadingBehavior;
4140
import org.apache.hc.core5.http.EntityDetails;
4241
import org.apache.hc.core5.http.HttpException;
42+
import org.apache.hc.core5.http.HttpHost;
4343
import org.apache.hc.core5.http.HttpRequest;
4444
import org.apache.hc.core5.http.HttpResponse;
4545
import org.apache.hc.core5.http.nio.AsyncDataConsumer;
@@ -96,6 +96,7 @@ public AsyncHttpRequestRetryExec(final HttpRequestRetryStrategy retryStrategy) {
9696
private static class State {
9797

9898
volatile boolean retrying;
99+
volatile int status;
99100
volatile TimeValue delay;
100101

101102
}
@@ -125,6 +126,7 @@ public AsyncDataConsumer handleResponse(
125126
}
126127
state.retrying = retryStrategy.retryRequest(response, scope.execCount.get(), clientContext);
127128
if (state.retrying) {
129+
state.status = response.getCode();
128130
state.delay = retryStrategy.getRetryInterval(response, scope.execCount.get(), clientContext);
129131
return new DiscardingEntityConsumer<>();
130132
}
@@ -143,9 +145,11 @@ public void completed() {
143145
if (entityProducer != null) {
144146
entityProducer.releaseResources();
145147
}
148+
final HttpHost target = scope.route.getTargetHost();
146149
final TimeValue delay = TimeValue.isPositive(state.delay) ? state.delay : TimeValue.ZERO_MILLISECONDS;
147-
if (LOG.isDebugEnabled()) {
148-
LOG.debug("{} wait for {}", exchangeId, delay);
150+
if (LOG.isInfoEnabled()) {
151+
LOG.info("{} {} responded with status {}; request will be automatically re-executed in {}",
152+
exchangeId, target, state.status, delay);
149153
}
150154
scope.scheduler.scheduleExecution(
151155
request,
@@ -162,7 +166,7 @@ public void completed() {
162166
@Override
163167
public void failed(final Exception cause) {
164168
if (cause instanceof IOException) {
165-
final HttpRoute route = scope.route;
169+
final HttpHost target = scope.route.getTargetHost();
166170
final HttpClientContext clientContext = scope.clientContext;
167171
if (entityProducer != null && !entityProducer.isRepeatable()) {
168172
if (LOG.isDebugEnabled()) {
@@ -172,10 +176,6 @@ public void failed(final Exception cause) {
172176
if (LOG.isDebugEnabled()) {
173177
LOG.debug("{} {}", exchangeId, cause.getMessage(), cause);
174178
}
175-
if (LOG.isInfoEnabled()) {
176-
LOG.info("Recoverable I/O exception ({}) caught when processing request to {}",
177-
cause.getClass().getName(), route);
178-
}
179179
scope.execRuntime.discardEndpoint();
180180
if (entityProducer != null) {
181181
entityProducer.releaseResources();
@@ -184,8 +184,10 @@ public void failed(final Exception cause) {
184184
final int execCount = scope.execCount.incrementAndGet();
185185
state.delay = retryStrategy.getRetryInterval(request, (IOException) cause, execCount - 1, clientContext);
186186
final TimeValue delay = TimeValue.isPositive(state.delay) ? state.delay : TimeValue.ZERO_MILLISECONDS;
187-
if (LOG.isDebugEnabled()) {
188-
LOG.debug("{} wait for {}", exchangeId, delay);
187+
if (LOG.isInfoEnabled()) {
188+
LOG.info("{} recoverable I/O exception ({}) caught when sending request to {};" +
189+
"request will be automatically re-executed in {}",
190+
exchangeId, cause.getClass().getName(), target, delay);
189191
}
190192
scope.scheduler.scheduleExecution(
191193
request,

‎httpclient5/src/main/java/org/apache/hc/client5/http/impl/classic/HttpRequestRetryExec.java‎

Lines changed: 14 additions & 10 deletions
Original file line numberDiff line numberDiff line change
@@ -43,6 +43,7 @@
4343
import org.apache.hc.core5.http.ClassicHttpResponse;
4444
import org.apache.hc.core5.http.HttpEntity;
4545
import org.apache.hc.core5.http.HttpException;
46+
import org.apache.hc.core5.http.HttpHost;
4647
import org.apache.hc.core5.http.NoHttpResponseException;
4748
import org.apache.hc.core5.http.io.support.ClassicRequestBuilder;
4849
import org.apache.hc.core5.util.Args;
@@ -102,6 +103,7 @@ public ClassicHttpResponse execute(
102103
Args.notNull(scope, "scope");
103104
final String exchangeId = scope.exchangeId;
104105
final HttpRoute route = scope.route;
106+
final HttpHost target = route.getTargetHost();
105107
final HttpClientContext context = scope.clientContext;
106108
ClassicHttpRequest currentRequest = request;
107109

@@ -119,7 +121,11 @@ public ClassicHttpResponse execute(
119121
if (retryStrategy.retryRequest(response, execCount, context)) {
120122
response.close();
121123
final TimeValue delay = retryStrategy.getRetryInterval(response, execCount, context);
122-
pause(exchangeId, delay);
124+
if (LOG.isInfoEnabled()) {
125+
LOG.info("{} {} responded with status {}; request will be automatically re-executed in {}",
126+
exchangeId, target, response.getCode(), delay);
127+
}
128+
pause(delay);
123129
currentRequest = ClassicRequestBuilder.copy(scope.originalRequest).build();
124130
} else {
125131
return response;
@@ -143,18 +149,19 @@ public ClassicHttpResponse execute(
143149
if (LOG.isDebugEnabled()) {
144150
LOG.debug("{} {}", exchangeId, ex.getMessage(), ex);
145151
}
152+
final TimeValue delay = retryStrategy.getRetryInterval(request, ex, execCount, context);
146153
if (LOG.isInfoEnabled()) {
147-
LOG.info("Recoverable I/O exception ({}) caught when processing request to {}",
148-
ex.getClass().getName(), route);
154+
LOG.info("{} recoverable I/O exception ({}) caught when sending request to {};" +
155+
"request will be automatically re-executed in {}",
156+
exchangeId, ex.getClass().getName(), target, delay);
149157
}
150-
final TimeValue delay = retryStrategy.getRetryInterval(request, ex, execCount, context);
151-
pause(exchangeId, delay);
158+
pause(delay);
152159
currentRequest = ClassicRequestBuilder.copy(scope.originalRequest).build();
153160
continue;
154161
}
155162
if (ex instanceof NoHttpResponseException) {
156163
final NoHttpResponseException updatedex = new NoHttpResponseException(
157-
route.getTargetHost().toHostString() + " failed to respond");
164+
target.toHostString() + " failed to respond");
158165
updatedex.setStackTrace(ex.getStackTrace());
159166
throw updatedex;
160167
}
@@ -163,10 +170,7 @@ public ClassicHttpResponse execute(
163170
}
164171
}
165172

166-
private static void pause(final String exchangeId, final TimeValue delay) throws InterruptedIOException {
167-
if (LOG.isDebugEnabled()) {
168-
LOG.debug("{} wait for {}", exchangeId, delay);
169-
}
173+
private static void pause(final TimeValue delay) throws InterruptedIOException {
170174
if (TimeValue.isPositive(delay)) {
171175
try {
172176
delay.sleep();

0 commit comments

Comments
 (0)