Skip to content

Update failed with org.apache.hc.core5.http.ConnectionClosedException #6144

Closed
#6153
#6151
Closed
Update failed with org.apache.hc.core5.http.ConnectionClosedException#6144
#6153
#6151
Labels
bug
@aarongoldenthal

Description

@aarongoldenthal
aarongoldenthal
opened on Nov 27, 2023

Describe the bug
When building a container image that pre-populates the dependency database from the owasp/dependency-check image:

FROM owasp/dependency-check:9.0.1

RUN --mount=type=secret,id=nvd,target=/kaniko/NVD_API_KEY \ 
    /usr/share/dependency-check/bin/dependency-check.sh --updateonly --nvdApiKey "$(cat /kaniko/NVD_API_KEY)"

Dependency Check fails to download the update with the following error:

[INFO] Checking for updates
[WARN] NVD API request failures are occurring; retrying request for the 5 time
[WARN] NVD API request failures are occurring; retrying request for the 6 time
[WARN] NVD API request failures are occurring; retrying request for the 7 time
[WARN] NVD API request failures are occurring; retrying request for the 8 time
[INFO] NVD API has 171,546 records in this update
[WARN] NVD API request failures are occurring; retrying request for the 5 time
[WARN] NVD API request failures are occurring; retrying request for the 5 time
[WARN] NVD API request failures are occurring; retrying request for the 5 time
[WARN] NVD API request failures are occurring; retrying request for the 5 time
[WARN] NVD API request failures are occurring; retrying request for the 6 time
[WARN] NVD API request failures are occurring; retrying request for the 6 time
[WARN] NVD API request failures are occurring; retrying request for the 6 time
[WARN] NVD API request failures are occurring; retrying request for the 6 time
[WARN] NVD API request failures are occurring; retrying request for the 7 time
[WARN] NVD API request failures are occurring; retrying request for the 7 time
[WARN] NVD API request failures are occurring; retrying request for the 7 time
[WARN] NVD API request failures are occurring; retrying request for the 7 time
[WARN] NVD API request failures are occurring; retrying request for the 8 time
[WARN] NVD API request failures are occurring; retrying request for the 8 time
[WARN] NVD API request failures are occurring; retrying request for the 8 time
[WARN] NVD API request failures are occurring; retrying request for the 8 time
[WARN] NVD API request failures are occurring; retrying request for the 9 time
[WARN] NVD API request failures are occurring; retrying request for the 9 time
[WARN] NVD API request failures are occurring; retrying request for the 9 time
[WARN] NVD API request failures are occurring; retrying request for the 9 time
[INFO] Downloaded 10,000/171,546 (6%)
[INFO] Recoverable I/O exception (org.apache.hc.core5.http.ConnectionClosedException) caught when processing request to {s}->https://services.nvd.nist.gov:443
[ERROR] Task java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask@4c6f618f[Not completed, task = java.util.concurrent.Executors$RunnableAdapter@6aca07d1[Wrapped task = org.apache.hc.client5.http.impl.async.InternalAbstractHttpAsyncClient$ScheduledRequestExecution@1bc553fc]] rejected from java.util.concurrent.ScheduledThreadPoolExecutor@520808f6[Terminated, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 19]
java.util.concurrent.RejectedExecutionException: Task java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask@4c6f618f[Not completed, task = java.util.concurrent.Executors$RunnableAdapter@6aca07d1[Wrapped task = org.apache.hc.client5.http.impl.async.InternalAbstractHttpAsyncClient$ScheduledRequestExecution@1bc553fc]] rejected from java.util.concurrent.ScheduledThreadPoolExecutor@520808f6[Terminated, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 19]
	at java.base/java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution(ThreadPoolExecutor.java:2065)
	at java.base/java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:833)
	at java.base/java.util.concurrent.ScheduledThreadPoolExecutor.delayedExecute(ScheduledThreadPoolExecutor.java:340)
	at java.base/java.util.concurrent.ScheduledThreadPoolExecutor.schedule(ScheduledThreadPoolExecutor.java:562)
	at java.base/java.util.concurrent.ScheduledThreadPoolExecutor.execute(ScheduledThreadPoolExecutor.java:[70](https://gitlab.com/gitlab-ci-utils/docker-dependency-check/-/jobs/5619745796#L70)5)
	at java.base/java.util.concurrent.Executors$DelegatedExecutorService.execute(Executors.java:721)
	at org.apache.hc.client5.http.impl.async.InternalAbstractHttpAsyncClient.executeScheduled(InternalAbstractHttpAsyncClient.java:361)
	at org.apache.hc.client5.http.impl.async.AsyncHttpRequestRetryExec$1.failed(AsyncHttpRequestRetryExec.java:164)
	at org.apache.hc.client5.http.impl.async.AsyncProtocolExec$1.failed(AsyncProtocolExec.java:295)
	at org.apache.hc.client5.http.impl.async.HttpAsyncMainClientExec$1.failed(HttpAsyncMainClientExec.java:131)
	at org.apache.hc.core5.http.impl.nio.ClientHttp1StreamHandler.failed(ClientHttp1StreamHandler.java:285)
	at org.apache.hc.core5.http.impl.nio.ClientHttp1StreamDuplexer.disconnected(ClientHttp1StreamDuplexer.java:220)
	at org.apache.hc.core5.http.impl.nio.AbstractHttp1StreamDuplexer.onDisconnect(AbstractHttp1StreamDuplexer.java:409)
	at org.apache.hc.core5.http.impl.nio.AbstractHttp1IOEventHandler.disconnected(AbstractHttp1IOEventHandler.java:95)
	at org.apache.hc.core5.http.impl.nio.ClientHttp1IOEventHandler.disconnected(ClientHttp1IOEventHandler.java:41)
	at org.apache.hc.core5.reactor.ssl.SSLIOSession$1.disconnected(SSLIOSession.java:247)
	at org.apache.hc.core5.reactor.InternalDataChannel.disconnected(InternalDataChannel.java:204)
	at org.apache.hc.core5.reactor.SingleCoreIOReactor.processClosedSessions(SingleCoreIOReactor.java:231)
	at org.apache.hc.core5.reactor.SingleCoreIOReactor.doTerminate(SingleCoreIOReactor.java:106)
	at org.apache.hc.core5.reactor.AbstractSingleCoreIOReactor.execute(AbstractSingleCoreIOReactor.java:93)
	at org.apache.hc.core5.reactor.IOReactorWorker.run(IOReactorWorker.java:44)
	at java.base/java.lang.Thread.run(Thread.java:840)
[INFO] Recoverable I/O exception (org.apache.hc.core5.http.ConnectionClosedException) caught when processing request to {s}->https://services.nvd.nist.gov:443
[ERROR] Task java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask@3c27b846[Not completed, task = java.util.concurrent.Executors$RunnableAdapter@61598479[Wrapped task = org.apache.hc.client5.http.impl.async.InternalAbstractHttpAsyncClient$ScheduledRequestExecution@67987bb4]] rejected from java.util.concurrent.ScheduledThreadPoolExecutor@484026a4[Terminated, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 8]
java.util.concurrent.RejectedExecutionException: Task java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask@3c27b846[Not completed, task = java.util.concurrent.Executors$RunnableAdapter@61598479[Wrapped task = org.apache.hc.client5.http.impl.async.InternalAbstractHttpAsyncClient$ScheduledRequestExecution@67987bb4]] rejected from java.util.concurrent.ScheduledThreadPoolExecutor@484026a4[Terminated, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 8]
	at java.base/java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution(ThreadPoolExecutor.java:2065)
	at java.base/java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:833)
	at java.base/java.util.concurrent.ScheduledThreadPoolExecutor.delayedExecute(ScheduledThreadPoolExecutor.java:340)
	at java.base/java.util.concurrent.ScheduledThreadPoolExecutor.schedule(ScheduledThreadPoolExecutor.java:562)
	at java.base/java.util.concurrent.ScheduledThreadPoolExecutor.execute(ScheduledThreadPoolExecutor.java:705)
	at java.base/java.util.concurrent.Executors$DelegatedExecutorService.execute(Executors.java:721)
	at org.apache.hc.client5.http.impl.async.InternalAbstractHttpAsyncClient.executeScheduled(InternalAbstractHttpAsyncClient.java:361)
	at org.apache.hc.client5.http.impl.async.AsyncHttpRequestRetryExec$1.failed(AsyncHttpRequestRetryExec.java:164)
	at org.apache.hc.client5.http.impl.async.AsyncProtocolExec$1.failed(AsyncProtocolExec.java:295)
	at org.apache.hc.client5.http.impl.async.HttpAsyncMainClientExec$1.failed(HttpAsyncMainClientExec.java:131)
	at org.apache.hc.core5.http.impl.nio.ClientHttp1StreamHandler.failed(ClientHttp1StreamHandler.java:285)
	at org.apache.hc.core5.http.impl.nio.ClientHttp1StreamDuplexer.disconnected(ClientHttp1StreamDuplexer.java:220)
	at org.apache.hc.core5.http.impl.nio.AbstractHttp1StreamDuplexer.onDisconnect(AbstractHttp1StreamDuplexer.java:409)
	at org.apache.hc.core5.http.impl.nio.AbstractHttp1IOEventHandler.disconnected(AbstractHttp1IOEventHandler.java:95)
	at org.apache.hc.core5.http.impl.nio.ClientHttp1IOEventHandler.disconnected(ClientHttp1IOEventHandler.java:41)
	at org.apache.hc.core5.reactor.ssl.SSLIOSession$1.disconnected(SSLIOSession.java:247)
	at org.apache.hc.core5.reactor.InternalDataChannel.disconnected(InternalDataChannel.java:204)
	at org.apache.hc.core5.reactor.SingleCoreIOReactor.processClosedSessions(SingleCoreIOReactor.java:231)
	at org.apache.hc.core5.reactor.SingleCoreIOReactor.doTerminate(SingleCoreIOReactor.java:106)
	at org.apache.hc.core5.reactor.AbstractSingleCoreIOReactor.execute(AbstractSingleCoreIOReactor.java:93)
	at org.apache.hc.core5.reactor.IOReactorWorker.run(IOReactorWorker.java:44)
	at java.base/java.lang.Thread.run(Thread.java:840)
[ERROR] Error updating the NVD Data
org.owasp.dependencycheck.data.update.exception.UpdateException: Error updating the NVD Data
	at org.owasp.dependencycheck.data.update.NvdApiDataSource.processApi(NvdApiDataSource.java:338)
	at org.owasp.dependencycheck.data.update.NvdApiDataSource.update(NvdApiDataSource.java:110)
	at org.owasp.dependencycheck.Engine.doUpdates(Engine.java:904)
	at org.owasp.dependencycheck.Engine.doUpdates(Engine.java:876)
	at org.owasp.dependencycheck.App.runUpdateOnly(App.java:426)
	at org.owasp.dependencycheck.App.run(App.java:1[71](https://gitlab.com/gitlab-ci-utils/docker-dependency-check/-/jobs/5619745796#L71))
	at org.owasp.dependencycheck.App.main(App.java:88)
Caused by: io.github.jeremylong.openvulnerability.client.nvd.NvdApiException: NVD Returned Status Code: 504
	at io.github.jeremylong.openvulnerability.client.nvd.NvdCveClient.next(NvdCveClient.java:346)
	at org.owasp.dependencycheck.data.update.NvdApiDataSource.processApi(NvdApiDataSource.java:317)
	... 6 common frames omitted
[INFO] Updating CISA Known Exploited Vulnerability list: https://www.cisa.gov/sites/default/files/feeds/known_exploited_vulnerabilities.json
[INFO] Begin database defrag
[INFO] End database defrag (604 ms)
[ERROR] Error updating the NVD Data
org.owasp.dependencycheck.data.update.exception.UpdateException: Error updating the NVD Data
	at org.owasp.dependencycheck.data.update.NvdApiDataSource.processApi(NvdApiDataSource.java:338)
	at org.owasp.dependencycheck.data.update.NvdApiDataSource.update(NvdApiDataSource.java:110)
	at org.owasp.dependencycheck.Engine.doUpdates(Engine.java:904)
	at org.owasp.dependencycheck.Engine.doUpdates(Engine.java:8[76](https://gitlab.com/gitlab-ci-utils/docker-dependency-check/-/jobs/5619745796#L76))
	at org.owasp.dependencycheck.App.runUpdateOnly(App.java:426)
	at org.owasp.dependencycheck.App.run(App.java:171)
	at org.owasp.dependencycheck.App.main(App.java:88)
Caused by: io.github.jeremylong.openvulnerability.client.nvd.NvdApiException: NVD Returned Status Code: 504
	at io.github.jeremylong.openvulnerability.client.nvd.NvdCveClient.next(NvdCveClient.java:346)
	at org.owasp.dependencycheck.data.update.NvdApiDataSource.processApi(NvdApiDataSource.java:317)
	... 6 common frames omitted
[INFO] Shutdown hook activated. Shutdown was not called. Shutting down JCS.
[INFO] Element event queue destroyed: org.apache.commons.jcs3.engine.control.event.ElementEventQueue@77d67cf3
...
ERROR: Job failed: exit code 8

Version of dependency-check used

Dependency Check CLI v9.0.1 (from the owasp/dependency-check image).

To Reproduce

  1. Build the Dockerfile show above. In some cases it happens quickly (within 5 minutes), in some cases later (e.g. 30 minutes). It does not always happen, earlier today a couple of successful builds with 9.0.1 were completed (although tonight the NVD API seems more heavily loaded).

Metadata

Metadata

Assignees

No one assigned

    Labels

    bug

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions