From fcac103566f5a880c5d57c3fe761f2e3733fc99a Mon Sep 17 00:00:00 2001 From: sebr72 Date: Tue, 17 Dec 2024 19:14:15 +0100 Subject: [PATCH] Close http response, temp file and improve logging --- ...ConfigFileResolvingHttpRequestFactory.java | 4 +- .../http/ConfigFileResolvingRequest.java | 75 ++++++++++--------- .../print/http/HttpRequestFetcher.java | 22 +++--- .../http/MfClientHttpRequestFactoryImpl.java | 10 ++- .../job/impl/ThreadPoolJobManager.java | 7 +- .../mapfish/print/TestHttpClientFactory.java | 23 ++---- .../http/ConfigFileResolvingRequestTest.java | 6 +- 7 files changed, 84 insertions(+), 63 deletions(-) diff --git a/core/src/main/java/org/mapfish/print/http/ConfigFileResolvingHttpRequestFactory.java b/core/src/main/java/org/mapfish/print/http/ConfigFileResolvingHttpRequestFactory.java index 3c3736373e..099ad2e8c4 100644 --- a/core/src/main/java/org/mapfish/print/http/ConfigFileResolvingHttpRequestFactory.java +++ b/core/src/main/java/org/mapfish/print/http/ConfigFileResolvingHttpRequestFactory.java @@ -54,7 +54,9 @@ public void register(@Nonnull final RequestConfigurator callback) { } @Override - public ClientHttpRequest createRequest(final URI uri, final HttpMethod httpMethod) { + @Nonnull + public ClientHttpRequest createRequest( + @Nonnull final URI uri, @Nonnull final HttpMethod httpMethod) { return new ConfigFileResolvingRequest(this, uri, httpMethod); } diff --git a/core/src/main/java/org/mapfish/print/http/ConfigFileResolvingRequest.java b/core/src/main/java/org/mapfish/print/http/ConfigFileResolvingRequest.java index 59874de66a..9754e009bc 100644 --- a/core/src/main/java/org/mapfish/print/http/ConfigFileResolvingRequest.java +++ b/core/src/main/java/org/mapfish/print/http/ConfigFileResolvingRequest.java @@ -141,16 +141,28 @@ private ClientHttpResponse doFileRequest() throws IOException { } private ClientHttpResponse doHttpRequestWithRetry(final HttpHeaders headers) throws IOException { - AtomicInteger counter = new AtomicInteger(); + final AtomicInteger counter = new AtomicInteger(); do { logFetchingURIResource(headers); try { - ClientHttpResponse response = attemptToFetchResponse(headers, counter); + ClientHttpResponse response = attemptToFetchResponse(headers); if (response != null) { return response; + } else { + if (canRetry(counter)) { + sleepWithExceptionHandling(); + LOGGER.debug("Retry fetching {}", this.getURI()); + } else { + PrintException printException = new PrintException("Failed fetching " + getURI()); + LOGGER.debug("Throwing exception since it cannot retry.", printException); + throw printException; + } + } + } catch (final IOException | RuntimeException e) { + boolean hasSlept = sleepIfPossible(e, counter); + if (!hasSlept) { + throw e; } - } catch (final IOException e) { - handleIOException(e, counter); } } while (true); } @@ -158,56 +170,51 @@ private ClientHttpResponse doHttpRequestWithRetry(final HttpHeaders headers) thr private void logFetchingURIResource(final HttpHeaders headers) { // Display headers, one by line : LOGGER.debug( - "Fetching URI resource {}, headers:\n{}", + "Fetching {}, using headers:\n{}", this.getURI(), headers.entrySet().stream() .map(entry -> entry.getKey() + "=" + String.join(", ", entry.getValue())) .collect(Collectors.joining("\n"))); } - private ClientHttpResponse attemptToFetchResponse( - final HttpHeaders headers, final AtomicInteger counter) throws IOException { + private ClientHttpResponse attemptToFetchResponse(final HttpHeaders headers) throws IOException { ClientHttpRequest requestUsed = this.request != null ? this.request : createRequestFromWrapped(headers); LOGGER.debug("Executing http request: {}", requestUsed.getURI()); ClientHttpResponse response = executeCallbacksAndRequest(requestUsed); - if (response.getRawStatusCode() < 500) { - LOGGER.debug( - "Fetching success URI resource {}, status code {}", - getURI(), - response.getRawStatusCode()); - return response; - } - LOGGER.debug( - "Fetching failed URI resource {}, error code {}", getURI(), response.getRawStatusCode()); - if (canRetry(counter)) { - sleepWithExceptionHandling(); - LOGGER.debug("Retry fetching URI resource {}", this.getURI()); - } else { - throw new PrintException( - String.format( - "Fetching failed URI resource %s, error code %s", - getURI(), response.getRawStatusCode())); + final int minStatusCodeError = HttpStatus.INTERNAL_SERVER_ERROR.value(); + int rawStatusCode = minStatusCodeError; + try { + rawStatusCode = response.getRawStatusCode(); + if (rawStatusCode < minStatusCodeError) { + LOGGER.debug("Successfully fetched {}, with status code {}", getURI(), rawStatusCode); + return response; + } + LOGGER.debug("Failed fetching {}, with error code {}", getURI(), rawStatusCode); + return null; + } finally { + if (rawStatusCode >= minStatusCodeError) { + response.close(); + } } - return null; } - private void handleIOException(final IOException e, final AtomicInteger counter) - throws IOException { - + private boolean sleepIfPossible(final Exception e, final AtomicInteger counter) { if (canRetry(counter)) { sleepWithExceptionHandling(); - LOGGER.debug("Retry fetching URI resource {}", this.getURI()); + LOGGER.debug("Retry fetching {} following exception", this.getURI(), e); + return true; } else { - LOGGER.debug("Fetching failed URI resource {}", getURI()); - throw e; + LOGGER.debug("Has reached maximum number of retry for {}", getURI()); + return false; } } private void sleepWithExceptionHandling() { + int sleepMs = configFileResolvingHttpRequestFactory.getHttpRequestFetchRetryIntervalMillis(); + LOGGER.debug("Sleeping {} ms before retrying.", sleepMs); try { - TimeUnit.MILLISECONDS.sleep( - configFileResolvingHttpRequestFactory.getHttpRequestFetchRetryIntervalMillis()); + TimeUnit.MILLISECONDS.sleep(sleepMs); } catch (InterruptedException e) { Thread.currentThread().interrupt(); throw new PrintException("Interrupted while sleeping", e); @@ -215,7 +222,7 @@ private void sleepWithExceptionHandling() { } private boolean canRetry(final AtomicInteger counter) { - return counter.incrementAndGet() < getHttpRequestMaxNumberFetchRetry(); + return counter.incrementAndGet() <= getHttpRequestMaxNumberFetchRetry(); } private int getHttpRequestMaxNumberFetchRetry() { diff --git a/core/src/main/java/org/mapfish/print/http/HttpRequestFetcher.java b/core/src/main/java/org/mapfish/print/http/HttpRequestFetcher.java index d8f1827fbc..51a81325f9 100644 --- a/core/src/main/java/org/mapfish/print/http/HttpRequestFetcher.java +++ b/core/src/main/java/org/mapfish/print/http/HttpRequestFetcher.java @@ -87,18 +87,22 @@ private CachedClientHttpResponse(final ClientHttpResponse originalResponse) thro this.headers = originalResponse.getHeaders(); this.status = originalResponse.getRawStatusCode(); this.statusText = originalResponse.getStatusText(); - this.cachedFile = + this.cachedFile = createCachedFile(originalResponse.getBody()); + } + + private File createCachedFile(final InputStream originalBody) throws IOException { + File tempFile = File.createTempFile("cacheduri", null, HttpRequestFetcher.this.temporaryDirectory); - LOGGER.debug("Caching URI resource to {}", this.cachedFile); - try (OutputStream os = Files.newOutputStream(this.cachedFile.toPath())) { - InputStream body = originalResponse.getBody(); + LOGGER.debug("Caching URI resource to {}", tempFile); + try (OutputStream os = Files.newOutputStream(tempFile.toPath())) { LOGGER.debug( - "Get from input stream {}, for response {}, body available: {}", - body.getClass(), - originalResponse.getClass(), - body.available()); - IOUtils.copy(body, os); + "Get from input stream {}, body available: {}", + originalBody.getClass(), + originalBody.available()); + IOUtils.copy(originalBody, os); + originalBody.close(); } + return tempFile; } @Override diff --git a/core/src/main/java/org/mapfish/print/http/MfClientHttpRequestFactoryImpl.java b/core/src/main/java/org/mapfish/print/http/MfClientHttpRequestFactoryImpl.java index dc6767edc4..ca59c7c04c 100644 --- a/core/src/main/java/org/mapfish/print/http/MfClientHttpRequestFactoryImpl.java +++ b/core/src/main/java/org/mapfish/print/http/MfClientHttpRequestFactoryImpl.java @@ -94,6 +94,7 @@ private static CloseableHttpClient createHttpClient( // allow extension only for testing @Override + @Nonnull public ConfigurableRequest createRequest( @Nonnull final URI uri, @Nonnull final HttpMethod httpMethod) { HttpRequestBase httpRequest = (HttpRequestBase) createHttpUriRequest(httpMethod, uri); @@ -161,20 +162,24 @@ public HttpMethod getMethod() { return HttpMethod.valueOf(this.request.getMethod()); } + @Nonnull @Override public String getMethodValue() { return this.request.getMethod(); } + @Nonnull public URI getURI() { return this.request.getURI(); } + @Nonnull @Override protected OutputStream getBodyInternal(@Nonnull final HttpHeaders headers) { return this.outputStream; } + @Nonnull @Override protected Response executeInternal(@Nonnull final HttpHeaders headers) throws IOException { CURRENT_CONFIGURATION.set(this.configuration); @@ -207,7 +212,7 @@ protected Response executeInternal(@Nonnull final HttpHeaders headers) throws IO } } - static class Response extends AbstractClientHttpResponse { + public static class Response extends AbstractClientHttpResponse { private static final Logger LOGGER = LoggerFactory.getLogger(Response.class); private static final AtomicInteger ID_COUNTER = new AtomicInteger(); private final HttpResponse response; @@ -224,6 +229,7 @@ public int getRawStatusCode() { return this.response.getStatusLine().getStatusCode(); } + @Nonnull @Override public String getStatusText() { return this.response.getStatusLine().getReasonPhrase(); @@ -247,6 +253,7 @@ public void close() { LOGGER.trace("Closed Http Response object: {}", this.id); } + @Nonnull @Override public synchronized InputStream getBody() throws IOException { if (this.inputStream == null) { @@ -262,6 +269,7 @@ public synchronized InputStream getBody() throws IOException { return this.inputStream; } + @Nonnull @Override public HttpHeaders getHeaders() { final HttpHeaders translatedHeaders = new HttpHeaders(); diff --git a/core/src/main/java/org/mapfish/print/servlet/job/impl/ThreadPoolJobManager.java b/core/src/main/java/org/mapfish/print/servlet/job/impl/ThreadPoolJobManager.java index a6fa026e3b..b5863fdffb 100644 --- a/core/src/main/java/org/mapfish/print/servlet/job/impl/ThreadPoolJobManager.java +++ b/core/src/main/java/org/mapfish/print/servlet/job/impl/ThreadPoolJobManager.java @@ -452,10 +452,13 @@ private boolean updateRegistry() { final SubmittedPrintJob printJob = submittedJobs.next(); if (!printJob.getReportFuture().isDone() && (isTimeoutExceeded(printJob) || isAbandoned(printJob))) { - LOGGER.info("Canceling job after timeout {}", printJob.getEntry().getReferenceId()); + LOGGER.info( + "About to attempt timeout based automatic cancellation of job {}", + printJob.getEntry().getReferenceId()); if (!printJob.getReportFuture().cancel(true)) { LOGGER.info( - "Could not cancel job after timeout {}", printJob.getEntry().getReferenceId()); + "Automatic cancellation after timeout failed for job {}", + printJob.getEntry().getReferenceId()); } // remove all canceled tasks from the work queue (otherwise the queue comparator // might stumble on non-PrintJob entries) diff --git a/core/src/test/java/org/mapfish/print/TestHttpClientFactory.java b/core/src/test/java/org/mapfish/print/TestHttpClientFactory.java index 7d81666b3f..b941966cf8 100644 --- a/core/src/test/java/org/mapfish/print/TestHttpClientFactory.java +++ b/core/src/test/java/org/mapfish/print/TestHttpClientFactory.java @@ -1,13 +1,12 @@ package org.mapfish.print; -import static org.junit.Assert.fail; - import java.io.IOException; import java.io.OutputStream; import java.net.URI; import java.util.Map; import java.util.concurrent.ConcurrentHashMap; import java.util.function.Predicate; +import javax.annotation.Nonnull; import org.apache.http.client.methods.HttpRequestBase; import org.mapfish.print.config.Configuration; import org.mapfish.print.http.ConfigurableRequest; @@ -37,8 +36,9 @@ public void registerHandler(Predicate matcher, Handler handler) { handlers.put(matcher, handler); } + @Nonnull @Override - public ConfigurableRequest createRequest(URI uri, final HttpMethod httpMethod) { + public ConfigurableRequest createRequest(@Nonnull URI uri, @Nonnull final HttpMethod httpMethod) { for (Map.Entry, Handler> entry : handlers.entrySet()) { if (entry.getKey().test(uri)) { try { @@ -75,18 +75,6 @@ public MockClientHttpRequest error404(URI uri, HttpMethod httpMethod) { request.setResponse(response); return request; } - - public MockClientHttpRequest failOnExecute(final URI uri, final HttpMethod httpMethod) { - MockClientHttpRequest request = - new MockClientHttpRequest(httpMethod, uri) { - @Override - protected ClientHttpResponse executeInternal() throws IOException { - fail("request should not be executed " + uri.toString()); - throw new IOException(); - } - }; - return request; - } } private static class TestConfigurableRequest implements ConfigurableRequest { @@ -106,11 +94,13 @@ public void setConfiguration(Configuration configuration) { // ignore } + @Nonnull @Override public ClientHttpResponse execute() throws IOException { return httpRequest.execute(); } + @Nonnull @Override public OutputStream getBody() throws IOException { return httpRequest.getBody(); @@ -121,6 +111,7 @@ public HttpMethod getMethod() { return httpRequest.getMethod(); } + @Nonnull @Override public String getMethodValue() { final HttpMethod method = httpRequest.getMethod(); @@ -128,11 +119,13 @@ public String getMethodValue() { return method.name(); } + @Nonnull @Override public URI getURI() { return httpRequest.getURI(); } + @Nonnull @Override public HttpHeaders getHeaders() { return httpRequest.getHeaders(); diff --git a/core/src/test/java/org/mapfish/print/http/ConfigFileResolvingRequestTest.java b/core/src/test/java/org/mapfish/print/http/ConfigFileResolvingRequestTest.java index d52cab391e..331d3964bc 100644 --- a/core/src/test/java/org/mapfish/print/http/ConfigFileResolvingRequestTest.java +++ b/core/src/test/java/org/mapfish/print/http/ConfigFileResolvingRequestTest.java @@ -29,6 +29,7 @@ public void executeInternalShouldDoDataUriRequestWhenSchemeIsData() throws IOExc // Then assertEquals("OK", resp.getStatusText()); + resp.close(); } @Test @@ -46,6 +47,7 @@ public void httpRequestWithRetryShouldSucceedAtSecondAttempt() throws IOExceptio // Then assertEquals(200, resp.getRawStatusCode()); + resp.close(); } @Test @@ -66,6 +68,7 @@ public void httpRequestWithRetryShouldSucceedDespiteException() throws IOExcepti // Then assertEquals(200, resp.getRawStatusCode()); + resp.close(); } @Test @@ -81,9 +84,10 @@ public void httpRequestWithRetryDoNotBlockWhenFailing() throws IOException { try { ClientHttpResponse resp = req.executeInternal(new HttpHeaders()); fail("Should not have return the response " + resp); + resp.close(); } catch (PrintException e) { // Then - assertEquals("Fetching failed URI resource http://ex.com, error code 500", e.getMessage()); + assertEquals("Failed fetching http://ex.com", e.getMessage()); } }