Context
- MapFish print version: 4.0.7 (also reproduced by reading current
master, and present in the latest tagged release, 4.0.6)
- Java version: 21 (
camptocamp/mapfish_print:4.0 Docker image)
- OS: Linux (Kubernetes/GKE)
Describe the bug
HttpRequestFetcher.CachedClientHttpResponse wraps the response returned by originalRequest.execute() and spools it to a temp file so it can be re-read. If creating that temp file fails, the constructor throws before originalResponse is ever read or closed:
// core/src/main/java/org/mapfish/print/http/HttpRequestFetcher.java
private CachedClientHttpResponse(final ClientHttpResponse originalResponse) throws IOException {
this.headers = originalResponse.getHeaders();
this.status = originalResponse.getStatusCode();
this.statusText = originalResponse.getStatusText();
this.cachedFile = createCachedFile(originalResponse.getBody()); // can throw
}
private File createCachedFile(final InputStream originalBody) throws IOException {
File tempFile = File.createTempFile("cacheduri", null, HttpRequestFetcher.this.temporaryDirectory);
...
}
The caller catches the exception, logs it, and substitutes an ErrorResponseClientHttpResponse:
try {
context.stopIfCanceled();
this.response = new CachedClientHttpResponse(this.originalRequest.execute());
} catch (IOException | RuntimeException e) {
LOGGER.error("Request failed {}", this.originalRequest.getURI(), e);
this.response = new ErrorResponseClientHttpResponse(e);
}
Nothing keeps a reference to the real originalResponse after this, so it's never closed and its pooled HTTP connection is never released. Each occurrence leaks one connection permanently. On a print server under modest load, this accumulates over a few hours until maxConnectionsPerRoute/maxConnectionsTotal is exhausted, and every subsequent request starts failing with ConnectionRequestTimeoutException - indistinguishable from an overloaded server, except restarting the process "fixes" it, which is what pointed us at a leak rather than genuine load.
What actually triggers the temp file failure
In our logs, File.createTempFile failed with IOException: No such file or directory because of a separate race: when a multi-layer print job fails partway through rendering (e.g. one layer's GeoServer response isn't a valid image, Wrong content-type: application/vnd.ogc.se_xml in our case), MapPrinter.print()'s finally block deletes the job's task directory immediately:
final File taskDirectory = this.workingDirectories.getTaskDirectory();
try {
return format.print(..., taskDirectory, out);
} finally {
this.workingDirectories.removeDirectory(taskDirectory);
}
But CreateMapProcessor.prepareLayers() dispatches every layer's WMS fetch to the shared ForkJoinPool up front, before rendering starts, and createLayerGraphics() has no per-layer isolation. A failure on one layer aborts the whole job without waiting for or canceling the other layers' already-submitted fetch tasks. When one of those orphaned tasks finishes later, it tries to cache its response into the now-deleted task directory and gets IOException: No such file or directory. We saw the same directory-deletion race hit LegendProcessor's Jasper subreport too (FileNotFoundException on task-<uuid>/legend-report-*.jasper), so it isn't specific to HttpRequestFetcher. It's a structural gap between MapPrinter.print()'s cleanup and the async work it kicks off. I'm not proposing a fix for that race here; it's included only to explain why the temp file creation fails in the first place. The connection leak in HttpRequestFetcher is real and worth fixing regardless of what triggers the underlying IOException.
How to reproduce
- Configure
maxConnectionsPerRoute/maxConnectionsTotal on the underlying HTTP client (as recommended for concurrent print jobs).
- Submit a multi-layer print job where at least one layer's GeoServer/WMS backend returns a non-image response (a
ServiceException, wrong content-type, or similar) while other layers are still being fetched concurrently.
- Repeat over time. Each time a layer's fetch is orphaned by the job failing (see above), and the task directory is gone by the time that fetch completes, a connection leaks.
- Eventually
maxConnectionsPerRoute/maxConnectionsTotal for the affected route is exhausted and all further requests to that host fail with ConnectionRequestTimeoutException until the process is restarted.
Actual results
java.io.IOException: No such file or directory
at java.base/java.io.UnixFileSystem.createFileExclusively0(Native Method)
at java.base/java.io.UnixFileSystem.createFileExclusively(UnixFileSystem.java:258)
at java.base/java.io.File.createTempFile(File.java:2184)
at org.mapfish.print.http.HttpRequestFetcher$CachedClientHttpResponse.createCachedFile(HttpRequestFetcher.java:96)
at org.mapfish.print.http.HttpRequestFetcher$CachedClientHttpResponse.<init>(HttpRequestFetcher.java:91)
at org.mapfish.print.http.HttpRequestFetcher$CachedClientHttpRequest.lambda$call$0(HttpRequestFetcher.java:226)
...
...followed, after enough of these accumulate, by unrelated jobs failing with:
org.apache.hc.core5.http.ConnectionRequestTimeoutException: Timeout deadline: 30000 MILLISECONDS, actual: 30000 MILLISECONDS
CreateMapProcessor runs affected by the exhausted pool consistently took 90203-90211ms (three sequential 30-second connection-lease waits back to back, with essentially no variance) before failing, consistent with waiting on a pool with no free connections rather than ordinary contention from concurrent load. Restarting the print server pod immediately resolves it, until it recurs.
Expected results
A failure while caching a response (for any reason) should not leak the underlying pooled connection. originalResponse should be closed whenever CachedClientHttpResponse's constructor fails to complete.
I have a fix and a regression test ready and i'm happy to open a PR if you like.
Context
master, and present in the latest tagged release, 4.0.6)camptocamp/mapfish_print:4.0Docker image)Describe the bug
HttpRequestFetcher.CachedClientHttpResponsewraps the response returned byoriginalRequest.execute()and spools it to a temp file so it can be re-read. If creating that temp file fails, the constructor throws beforeoriginalResponseis ever read or closed:The caller catches the exception, logs it, and substitutes an
ErrorResponseClientHttpResponse:Nothing keeps a reference to the real
originalResponseafter this, so it's never closed and its pooled HTTP connection is never released. Each occurrence leaks one connection permanently. On a print server under modest load, this accumulates over a few hours untilmaxConnectionsPerRoute/maxConnectionsTotalis exhausted, and every subsequent request starts failing withConnectionRequestTimeoutException- indistinguishable from an overloaded server, except restarting the process "fixes" it, which is what pointed us at a leak rather than genuine load.What actually triggers the temp file failure
In our logs,
File.createTempFilefailed withIOException: No such file or directorybecause of a separate race: when a multi-layer print job fails partway through rendering (e.g. one layer's GeoServer response isn't a valid image,Wrong content-type: application/vnd.ogc.se_xmlin our case),MapPrinter.print()'sfinallyblock deletes the job's task directory immediately:But
CreateMapProcessor.prepareLayers()dispatches every layer's WMS fetch to the sharedForkJoinPoolup front, before rendering starts, andcreateLayerGraphics()has no per-layer isolation. A failure on one layer aborts the whole job without waiting for or canceling the other layers' already-submitted fetch tasks. When one of those orphaned tasks finishes later, it tries to cache its response into the now-deleted task directory and getsIOException: No such file or directory. We saw the same directory-deletion race hitLegendProcessor's Jasper subreport too (FileNotFoundExceptionontask-<uuid>/legend-report-*.jasper), so it isn't specific toHttpRequestFetcher. It's a structural gap betweenMapPrinter.print()'s cleanup and the async work it kicks off. I'm not proposing a fix for that race here; it's included only to explain why the temp file creation fails in the first place. The connection leak inHttpRequestFetcheris real and worth fixing regardless of what triggers the underlyingIOException.How to reproduce
maxConnectionsPerRoute/maxConnectionsTotalon the underlying HTTP client (as recommended for concurrent print jobs).ServiceException, wrong content-type, or similar) while other layers are still being fetched concurrently.maxConnectionsPerRoute/maxConnectionsTotalfor the affected route is exhausted and all further requests to that host fail withConnectionRequestTimeoutExceptionuntil the process is restarted.Actual results
...followed, after enough of these accumulate, by unrelated jobs failing with:
CreateMapProcessorruns affected by the exhausted pool consistently took 90203-90211ms (three sequential 30-second connection-lease waits back to back, with essentially no variance) before failing, consistent with waiting on a pool with no free connections rather than ordinary contention from concurrent load. Restarting the print server pod immediately resolves it, until it recurs.Expected results
A failure while caching a response (for any reason) should not leak the underlying pooled connection.
originalResponseshould be closed wheneverCachedClientHttpResponse's constructor fails to complete.I have a fix and a regression test ready and i'm happy to open a PR if you like.