Skip to content

issues with apache httpclient 5.1.x #1789

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom
Closed
dimovelev opened this issue Jan 20, 2022 · 8 comments
Closed

issues with apache httpclient 5.1.x #1789

dimovelev opened this issue Jan 20, 2022 · 8 comments

Comments

@dimovelev
Copy link

dimovelev commented Jan 20, 2022 •
edited
Loading

When I switch the httpclient version from 5.0.x to 5.1.x, docker-java has problems communicating with docker - the process hangs with such a stack trace:

"main" #1 prio=5 os_prio=0 cpu=4140.63ms elapsed=64.25s tid=0x0000021b0a61af20 nid=0x544c waiting on condition  [0x000000a03dff8000]
   java.lang.Thread.State: WAITING (parking)
	at jdk.internal.misc.Unsafe.park(java.base@17.0.1/Native Method)
	- parking to wait for  <0x00000006070433f8> (a java.util.concurrent.CompletableFuture$Signaller)
	at java.util.concurrent.locks.LockSupport.park(java.base@17.0.1/LockSupport.java:211)
	at java.util.concurrent.CompletableFuture$Signaller.block(java.base@17.0.1/CompletableFuture.java:1864)
	at java.util.concurrent.ForkJoinPool.unmanagedBlock(java.base@17.0.1/ForkJoinPool.java:3463)
	at java.util.concurrent.ForkJoinPool.managedBlock(java.base@17.0.1/ForkJoinPool.java:3434)
	at java.util.concurrent.CompletableFuture.waitingGet(java.base@17.0.1/CompletableFuture.java:1898)
	at java.util.concurrent.CompletableFuture.get(java.base@17.0.1/CompletableFuture.java:2072)
	at java.nio.channels.Channels$2.read(java.base@17.0.1/Channels.java:238)
	- locked <0x000000060371f9f8> (a java.nio.channels.Channels$2)
	at org.apache.hc.core5.http.impl.io.SessionInputBufferImpl.fillBuffer(SessionInputBufferImpl.java:149)
	at org.apache.hc.core5.http.impl.io.BHttpConnectionBase.fillInputBuffer(BHttpConnectionBase.java:265)
	at org.apache.hc.core5.http.impl.io.BHttpConnectionBase.isStale(BHttpConnectionBase.java:295)
	at org.apache.hc.core5.http.impl.io.DefaultBHttpClientConnection.isStale(DefaultBHttpClientConnection.java:67)
	at org.apache.hc.client5.http.impl.io.PoolingHttpClientConnectionManager$1.get(PoolingHttpClientConnectionManager.java:287)
	- locked <0x0000000607043268> (a org.apache.hc.client5.http.impl.io.PoolingHttpClientConnectionManager$1)
	at org.apache.hc.client5.http.impl.classic.InternalExecRuntime.acquireEndpoint(InternalExecRuntime.java:109)
	at org.apache.hc.client5.http.impl.classic.ConnectExec.execute(ConnectExec.java:119)
	at org.apache.hc.client5.http.impl.classic.ExecChainElement.execute(ExecChainElement.java:51)
	at org.apache.hc.client5.http.impl.classic.ExecChainElement$1.proceed(ExecChainElement.java:57)
	at org.apache.hc.client5.http.impl.classic.ProtocolExec.execute(ProtocolExec.java:175)
	at org.apache.hc.client5.http.impl.classic.ExecChainElement.execute(ExecChainElement.java:51)
	at org.apache.hc.client5.http.impl.classic.ExecChainElement$1.proceed(ExecChainElement.java:57)
	at org.apache.hc.client5.http.impl.classic.HttpRequestRetryExec.execute(HttpRequestRetryExec.java:96)
	at org.apache.hc.client5.http.impl.classic.ExecChainElement.execute(ExecChainElement.java:51)
	at org.apache.hc.client5.http.impl.classic.ExecChainElement$1.proceed(ExecChainElement.java:57)
	at org.apache.hc.client5.http.impl.classic.ContentCompressionExec.execute(ContentCompressionExec.java:133)
	at org.apache.hc.client5.http.impl.classic.ExecChainElement.execute(ExecChainElement.java:51)
	at org.apache.hc.client5.http.impl.classic.ExecChainElement$1.proceed(ExecChainElement.java:57)
	at org.apache.hc.client5.http.impl.classic.RedirectExec.execute(RedirectExec.java:115)
	at org.apache.hc.client5.http.impl.classic.ExecChainElement.execute(ExecChainElement.java:51)
	at org.apache.hc.client5.http.impl.classic.InternalHttpClient.doExecute(InternalHttpClient.java:170)
	at org.apache.hc.client5.http.impl.classic.CloseableHttpClient.execute(CloseableHttpClient.java:67)
	at com.github.dockerjava.httpclient5.ApacheDockerHttpClientImpl.execute(ApacheDockerHttpClientImpl.java:175)
	at com.github.dockerjava.httpclient5.ApacheDockerHttpClient.execute(ApacheDockerHttpClient.java:9)
	at com.github.dockerjava.core.DefaultInvocationBuilder.execute(DefaultInvocationBuilder.java:228)
	at com.github.dockerjava.core.DefaultInvocationBuilder.get(DefaultInvocationBuilder.java:202)
	at com.github.dockerjava.core.DefaultInvocationBuilder.get(DefaultInvocationBuilder.java:74)
	at com.github.dockerjava.core.exec.ListImagesCmdExec.execute(ListImagesCmdExec.java:41)
	at com.github.dockerjava.core.exec.ListImagesCmdExec.execute(ListImagesCmdExec.java:16)
	at com.github.dockerjava.core.exec.AbstrSyncDockerCmdExec.exec(AbstrSyncDockerCmdExec.java:21)
	at com.github.dockerjava.core.command.AbstrDockerCmd.exec(AbstrDockerCmd.java:35)

OS: Windows 10 with Docker Desktop
Docker-Java: 3.2.11 and 3.2.12
JDK: Corretto 17.0.1

Some commands seem to succeed but sooner or later one hangs forever. So far I have not been able to create a small reproducer - executing e.g. listImages in a loop did not produce the issue.
@peterdnight
Copy link

Same issue - thanks for taking time to report (although i still burned many hours isolating JVM crashes)

	<!-- 
		- DockerJava integration
		-  5.1.2 hangs,  5.0.4 is the workaround pending next release 3.2.13 ?
	 -->
	<dependency>
		<groupId>org.apache.httpcomponents.client5</groupId>
		<artifactId>httpclient5</artifactId>
		<version>5.0.4</version> 
	</dependency>
	
	<dependency>
		<groupId>com.github.docker-java</groupId>
		<artifactId>docker-java-transport-httpclient5</artifactId>
		<version>3.2.12</version>
		<exclusions>
			<exclusion>
				<groupId>org.apache.httpcomponents.client5</groupId>
				<artifactId>httpclient5</artifactId>
			</exclusion>
		</exclusions>
	</dependency>


	<dependency>
		<groupId>com.github.docker-java</groupId>
		<artifactId>docker-java</artifactId>
		<version>3.2.12</version>
		<exclusions>
			<exclusion>
				<groupId>com.github.docker-java</groupId>
				<artifactId>
					docker-java-transport-jersey
				</artifactId>
			</exclusion>
			<exclusion>
				<groupId>com.github.docker-java</groupId>
				<artifactId>docker-java-transport-netty</artifactId>
			</exclusion>
		</exclusions>
	</dependency>

@dimovelev
Copy link
Author

@peterdnight i switched to the zerodep client - it seems to be a shaded httpclient5 so it does not clash with the version i have in the remaining part of my application. I guess that is the safer bet for future updates and i will stick to it.

@dimovelev dimovelev mentioned this issue Jan 21, 2022
Closed
@dimovelev
Copy link
Author

After reading through the other issue I have a short reproducer:

package com.example;

import java.io.IOException;
import java.util.List;

import com.github.dockerjava.api.DockerClient;
import com.github.dockerjava.api.model.Image;
import com.github.dockerjava.core.DefaultDockerClientConfig;
import com.github.dockerjava.core.DockerClientImpl;
import com.github.dockerjava.httpclient5.ApacheDockerHttpClient;
import com.github.dockerjava.transport.DockerHttpClient;
import org.slf4j.Logger;

import static org.slf4j.LoggerFactory.getLogger;

public class Issue {
    private static final Logger LOGGER = getLogger(Issue.class);

    public static void main(String[] args) throws IOException, InterruptedException {
        final var config = DefaultDockerClientConfig.createDefaultConfigBuilder() //
            .withDockerHost("npipe:////./pipe/docker_engine") //
            .build();
        final DockerHttpClient httpClient = new ApacheDockerHttpClient.Builder() //
            .dockerHost(config.getDockerHost()) //
            .build();
        final DockerClient client = DockerClientImpl.getInstance(config, httpClient);
        try {
            LOGGER.info("Listing images");
            final List<Image> result1 = client.listImagesCmd().exec();
            LOGGER.info("Found {} images", result1.size());
            Thread.sleep(2_000);
            LOGGER.info("Listing images");
            final List<Image> result2 = client.listImagesCmd().exec();
            LOGGER.info("Found {} images", result2.size());
        } finally {
            client.close();
            httpClient.close();
        }
    }
}

The second list images hangs forever.
The crucial part is sleeping for at least 2 seconds (1 second is fine). With that and going through the apache httpclient commits I would guess that the issue is this one - apache/httpcomponents-client@10e2deb

@dimovelev
Copy link
Author

So the connection staleness check in org.apache.hc.client5.http.impl.io.PoolingHttpClientConnectionManager seems to block forever. It is triggered (with default configuration) after 2 seconds of inactivity. If you change that to -1 the check is disabled and the code above does not block. you can call this method after creating the client to change the value:

    private static void changeValidateAfterInactivity(final DockerHttpClient httpClient) throws NoSuchFieldException,
        IllegalAccessException {
        final Field httpClientField = httpClient.getClass().getSuperclass().getDeclaredField("httpClient");
        httpClientField.setAccessible(true);
        final Object apacheClient = httpClientField.get(httpClient);
        final Field connManagerField = apacheClient.getClass().getDeclaredField("connManager");
        connManagerField.setAccessible(true);
        final PoolingHttpClientConnectionManager connManager =
            (PoolingHttpClientConnectionManager) connManagerField.get(apacheClient);
        connManager.setValidateAfterInactivity(TimeValue.NEG_ONE_MILLISECOND);
    }

So I guess a change in com.github.dockerjava.httpclient5.ApacheDockerHttpClientImpl will be required to set this value.

@dimovelev
Copy link
Author

dimovelev commented Jan 21, 2022 •
edited
Loading

The connection staleness check in apache httpclient seems to rely on modifying the socket timeout to 1 ms then trying to read something and resetting the timeout back to the original value. I guess that this fails in our case - the timeout is not reset and thus the read blocks forever (as the original timeout was 0).

@dimovelev
Copy link
Author

dimovelev commented Jan 21, 2022 •
edited
Loading

that was a big waste of time. the issue has been fixed (well the timeout set to -1 as i figured out above) in November 2021 - see #1727 . The latest release of docker-java does not include the fix.

@bsideup when is the next released planned?

@peterdnight
Copy link

@dimovelev - i feel your pain. fyi - if you are curious regarding my use case, check out my docker tutorial:
https://www.youtube.com/playlist?list=PLETtnz3MXNMUBFq_kSSXrXm1lnp10rt0I

@bsideup
Copy link
Member

bsideup commented Feb 15, 2022

Should be fixed in 3.2.13

@bsideup bsideup closed this as completed Feb 15, 2022
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@dimovelev @bsideup @peterdnight