Skip to content
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

Error "Could not find a valid Docker environment. Please check configuration." from testcontainers-java on 1.16.1+ and JVM 17th #5030

Closed
ashirman opened this issue Feb 7, 2022 · 6 comments
Closed

Error "Could not find a valid Docker environment. Please check configuration." from testcontainers-java on 1.16.1+ and JVM 17th #5030

ashirman opened this issue Feb 7, 2022 · 6 comments

Comments

@ashirman
Copy link

ashirman commented Feb 7, 2022 •
edited

Having "Could not find a valid Docker environment. " error what causes test flakiness.

Environment:

  • Docker Desktop Engine: 20.10.12 on Mac OS 12.1. issue is reproduced on Github Actions as well.
  • JDK 17. Tried different releases such as 17.0.2 (x86_64) "Homebrew" - "OpenJDK 17.0.2" , 17.0.2 (x86_64) "Oracle Corporation" - "OpenJDK 17.0.2", 17.0.2 (x86_64) "Eclipse Temurin" - "Eclipse Temurin 17"
  • Kotlin 1.6.10
  • Junit 5.8.2
  • trying to use postgres 11 container as the following
      private fun initContainerDatabase(): Database {
            println("Initialising container database")

            val dockerImage =
                System.getProperty(
                    "postgresdaltest.testcontainers.postgresdockerimagename",
                    "postgres:11"
                )

            val localContainer = PostgreSQLContainer<Nothing>(dockerImage)
                .apply {
                    if (isRunning) {
                        return@apply
                    }

                    start()

                    Flyway.configure()
                        .dataSource(jdbcUrl, username, password)
                        .load()
                        .migrate()
                }

but not sure if exact docker image does matter.

Workaround:

  • downgrade to testcontainers 1.16.0. Looks like this version is more stable on JVM 17.

We have seen this issue on JVM 11 as well but on JVM 17 it becomes even more painful. Assume issue can be related to changes in 1.16.1 where a sort of race-conditions are possible so looks like fix #4597 does not solve issue completely.

debug logs are below

Initialising container database
17:33:28.992 [Test worker] DEBUG org.testcontainers.utility.TestcontainersConfiguration - Testcontainers configuration overrides will be loaded from file:/Users/alexey/.testcontainers.properties
17:33:29.217 [Test worker] INFO org.testcontainers.dockerclient.DockerClientProviderStrategy - Loaded org.testcontainers.dockerclient.UnixSocketClientProviderStrategy from ~/.testcontainers.properties, will try it first
17:33:29.338 [Test worker] DEBUG org.testcontainers.dockerclient.DockerClientProviderStrategy - Trying out strategy: UnixSocketClientProviderStrategy
17:33:36.874 [ducttape-0] DEBUG org.testcontainers.dockerclient.DockerClientProviderStrategy - Pinging docker daemon...
17:33:37.071 [ducttape-0] DEBUG org.testcontainers.shaded.com.github.dockerjava.core.command.AbstrDockerCmd - Cmd:
17:33:37.605 [ducttape-0] DEBUG com.github.dockerjava.zerodep.shaded.org.apache.hc.client5.http.impl.classic.InternalHttpClient - ex-00000001: preparing request execution
17:33:37.749 [ducttape-0] DEBUG com.github.dockerjava.zerodep.shaded.org.apache.hc.client5.http.protocol.RequestAddCookies - Cookie spec selected: strict
17:33:37.960 [ducttape-0] DEBUG com.github.dockerjava.zerodep.shaded.org.apache.hc.client5.http.protocol.RequestAuthCache - Auth cache not set in the context
17:33:37.960 [ducttape-0] DEBUG com.github.dockerjava.zerodep.shaded.org.apache.hc.client5.http.impl.classic.ProtocolExec - ex-00000001: target auth state: UNCHALLENGED
17:33:37.964 [ducttape-0] DEBUG com.github.dockerjava.zerodep.shaded.org.apache.hc.client5.http.impl.classic.ProtocolExec - ex-00000001: proxy auth state: UNCHALLENGED
17:33:37.965 [ducttape-0] DEBUG com.github.dockerjava.zerodep.shaded.org.apache.hc.client5.http.impl.classic.ConnectExec - ex-00000001: acquiring connection with route {}->unix://localhost:2375
17:33:37.966 [ducttape-0] DEBUG com.github.dockerjava.zerodep.shaded.org.apache.hc.client5.http.impl.classic.InternalHttpClient - ex-00000001: acquiring endpoint (3 MINUTES)
17:33:37.973 [ducttape-0] DEBUG com.github.dockerjava.zerodep.shaded.org.apache.hc.client5.http.impl.io.PoolingHttpClientConnectionManager - ex-00000001: endpoint lease request (3 MINUTES) [route: {}->unix://localhost:2375][total available: 0; route allocated: 0 of 2147483647; total allocated: 0 of 2147483647]
17:33:38.102 [ducttape-0] DEBUG com.github.dockerjava.zerodep.shaded.org.apache.hc.client5.http.impl.io.PoolingHttpClientConnectionManager - ex-00000001: endpoint leased [route: {}->unix://localhost:2375][total available: 0; route allocated: 1 of 2147483647; total allocated: 1 of 2147483647]
17:33:38.464 [ducttape-0] DEBUG com.github.dockerjava.zerodep.shaded.org.apache.hc.client5.http.impl.io.PoolingHttpClientConnectionManager - ex-00000001: acquired ep-00000000
17:33:38.465 [ducttape-0] DEBUG com.github.dockerjava.zerodep.shaded.org.apache.hc.client5.http.impl.classic.InternalHttpClient - ex-00000001: acquired endpoint ep-00000000
17:33:38.465 [ducttape-0] DEBUG com.github.dockerjava.zerodep.shaded.org.apache.hc.client5.http.impl.classic.ConnectExec - ex-00000001: opening connection {}->unix://localhost:2375
17:33:38.468 [ducttape-0] DEBUG com.github.dockerjava.zerodep.shaded.org.apache.hc.client5.http.impl.classic.InternalHttpClient - ep-00000000: connecting endpoint (3 MINUTES)
17:33:38.468 [ducttape-0] DEBUG com.github.dockerjava.zerodep.shaded.org.apache.hc.client5.http.impl.io.PoolingHttpClientConnectionManager - ep-00000000: connecting endpoint to unix://localhost:2375 (3 MINUTES)
17:33:38.577 [ducttape-0] DEBUG com.github.dockerjava.zerodep.shaded.org.apache.hc.client5.http.impl.io.DefaultHttpClientConnectionOperator - http-outgoing-0: connecting to localhost/127.0.0.1:2375
17:33:38.618 [ducttape-0] DEBUG com.github.dockerjava.zerodep.shaded.org.apache.hc.client5.http.impl.io.DefaultHttpClientConnectionOperator - http-outgoing-0: connection established /var/run/docker.sock<->/var/run/docker.sock
17:33:38.627 [ducttape-0] DEBUG com.github.dockerjava.zerodep.shaded.org.apache.hc.client5.http.impl.io.PoolingHttpClientConnectionManager - ep-00000000: connected http-outgoing-0
17:33:38.628 [ducttape-0] DEBUG com.github.dockerjava.zerodep.shaded.org.apache.hc.client5.http.impl.classic.InternalHttpClient - ep-00000000: endpoint connected
17:33:38.634 [ducttape-0] DEBUG com.github.dockerjava.zerodep.shaded.org.apache.hc.client5.http.impl.classic.MainClientExec - ex-00000001: executing GET /v1.32/info HTTP/1.1
17:33:38.637 [ducttape-0] DEBUG com.github.dockerjava.zerodep.shaded.org.apache.hc.client5.http.impl.classic.InternalHttpClient - ep-00000000: start execution ex-00000001
17:33:38.637 [ducttape-0] DEBUG com.github.dockerjava.zerodep.shaded.org.apache.hc.client5.http.impl.io.PoolingHttpClientConnectionManager - ep-00000000: executing exchange ex-00000001 over http-outgoing-0
17:33:38.638 [ducttape-0] DEBUG com.github.dockerjava.zerodep.shaded.org.apache.hc.client5.http.headers - http-outgoing-0 >> GET /v1.32/info HTTP/1.1
17:33:38.639 [ducttape-0] DEBUG com.github.dockerjava.zerodep.shaded.org.apache.hc.client5.http.headers - http-outgoing-0 >> Accept-Encoding: gzip, x-gzip, deflate
17:33:38.639 [ducttape-0] DEBUG com.github.dockerjava.zerodep.shaded.org.apache.hc.client5.http.headers - http-outgoing-0 >> Host: localhost:2375
17:33:38.639 [ducttape-0] DEBUG com.github.dockerjava.zerodep.shaded.org.apache.hc.client5.http.headers - http-outgoing-0 >> Connection: keep-alive
17:33:38.640 [ducttape-0] DEBUG com.github.dockerjava.zerodep.shaded.org.apache.hc.client5.http.headers - http-outgoing-0 >> User-Agent: Apache-HttpClient/5.0.3 (Java/17.0.2)
17:33:38.641 [ducttape-0] DEBUG com.github.dockerjava.zerodep.shaded.org.apache.hc.client5.http.wire - http-outgoing-0 >> "GET /v1.32/info HTTP/1.1[\r][\n]"
17:33:38.641 [ducttape-0] DEBUG com.github.dockerjava.zerodep.shaded.org.apache.hc.client5.http.wire - http-outgoing-0 >> "Accept-Encoding: gzip, x-gzip, deflate[\r][\n]"
17:33:38.641 [ducttape-0] DEBUG com.github.dockerjava.zerodep.shaded.org.apache.hc.client5.http.wire - http-outgoing-0 >> "Host: localhost:2375[\r][\n]"
17:33:38.641 [ducttape-0] DEBUG com.github.dockerjava.zerodep.shaded.org.apache.hc.client5.http.wire - http-outgoing-0 >> "Connection: keep-alive[\r][\n]"
17:33:38.642 [ducttape-0] DEBUG com.github.dockerjava.zerodep.shaded.org.apache.hc.client5.http.wire - http-outgoing-0 >> "User-Agent: Apache-HttpClient/5.0.3 (Java/17.0.2)[\r][\n]"
17:33:38.642 [ducttape-0] DEBUG com.github.dockerjava.zerodep.shaded.org.apache.hc.client5.http.wire - http-outgoing-0 >> "[\r][\n]"
17:33:39.367 [ducttape-0] DEBUG com.github.dockerjava.zerodep.shaded.org.apache.hc.client5.http.wire - http-outgoing-0 << "HTTP/1.1 200 OK[\r][\n]"
17:33:39.367 [ducttape-0] DEBUG com.github.dockerjava.zerodep.shaded.org.apache.hc.client5.http.wire - http-outgoing-0 << "Api-Version: 1.41[\r][\n]"
17:33:39.367 [ducttape-0] DEBUG com.github.dockerjava.zerodep.shaded.org.apache.hc.client5.http.wire - http-outgoing-0 << "Content-Type: application/json[\r][\n]"
17:33:39.367 [ducttape-0] DEBUG com.github.dockerjava.zerodep.shaded.org.apache.hc.client5.http.wire - http-outgoing-0 << "Date: Fri, 04 Feb 2022 14:33:39 GMT[\r][\n]"
17:33:39.367 [ducttape-0] DEBUG com.github.dockerjava.zerodep.shaded.org.apache.hc.client5.http.wire - http-outgoing-0 << "Docker-Experimental: false[\r][\n]"
17:33:39.367 [ducttape-0] DEBUG com.github.dockerjava.zerodep.shaded.org.apache.hc.client5.http.wire - http-outgoing-0 << "Ostype: linux[\r][\n]"
17:33:39.368 [ducttape-0] DEBUG com.github.dockerjava.zerodep.shaded.org.apache.hc.client5.http.wire - http-outgoing-0 << "Server: Docker/20.10.12 (linux)[\r][\n]"
17:33:39.368 [ducttape-0] DEBUG com.github.dockerjava.zerodep.shaded.org.apache.hc.client5.http.wire - http-outgoing-0 << "Transfer-Encoding: chunked[\r][\n]"
17:33:39.368 [ducttape-0] DEBUG com.github.dockerjava.zerodep.shaded.org.apache.hc.client5.http.wire - http-outgoing-0 << "[\r][\n]"
17:33:39.379 [ducttape-0] DEBUG com.github.dockerjava.zerodep.shaded.org.apache.hc.client5.http.headers - http-outgoing-0 << HTTP/1.1 200 OK
17:33:39.380 [ducttape-0] DEBUG com.github.dockerjava.zerodep.shaded.org.apache.hc.client5.http.headers - http-outgoing-0 << Api-Version: 1.41
17:33:39.380 [ducttape-0] DEBUG com.github.dockerjava.zerodep.shaded.org.apache.hc.client5.http.headers - http-outgoing-0 << Content-Type: application/json
17:33:39.380 [ducttape-0] DEBUG com.github.dockerjava.zerodep.shaded.org.apache.hc.client5.http.headers - http-outgoing-0 << Date: Fri, 04 Feb 2022 14:33:39 GMT
17:33:39.380 [ducttape-0] DEBUG com.github.dockerjava.zerodep.shaded.org.apache.hc.client5.http.headers - http-outgoing-0 << Docker-Experimental: false
17:33:39.380 [ducttape-0] DEBUG com.github.dockerjava.zerodep.shaded.org.apache.hc.client5.http.headers - http-outgoing-0 << Ostype: linux
17:33:39.380 [ducttape-0] DEBUG com.github.dockerjava.zerodep.shaded.org.apache.hc.client5.http.headers - http-outgoing-0 << Server: Docker/20.10.12 (linux)
17:33:39.380 [ducttape-0] DEBUG com.github.dockerjava.zerodep.shaded.org.apache.hc.client5.http.headers - http-outgoing-0 << Transfer-Encoding: chunked
17:33:39.404 [ducttape-0] DEBUG com.github.dockerjava.zerodep.shaded.org.apache.hc.client5.http.impl.classic.MainClientExec - ex-00000001: connection can be kept alive for 3 MINUTES
17:33:39.532 [ducttape-0] DEBUG com.github.dockerjava.zerodep.shaded.org.apache.hc.client5.http.wire - http-outgoing-0 << "8f5[\r][\n]"
17:33:39.535 [ducttape-0] DEBUG com.github.dockerjava.zerodep.shaded.org.apache.hc.client5.http.wire - http-outgoing-0 << "{"ID":"4WGZ:I5FG:XPZ2:SZ7D:KA7B:J7XL:BORT:UWZR:Y5QG:ON4U:EUZO:4SCN","Containers":90,"ContainersRunning":11,"ContainersPaused":0,"ContainersStopped":79,"Images":14,"Driver":"overlay2","DriverStatus":[["Backing Filesystem","extfs"],["Supports d_type","true"],["Native Overlay Diff","true"],["userxattr","false"]],"Plugins":{"Volume":["local"],"Network":["bridge","host","ipvlan","macvlan","null","overlay"],"Authorization":null,"Log":["awslogs","fluentd","gcplogs","gelf","journald","json-file","local","logentries","splunk","syslog"]},"MemoryLimit":true,"SwapLimit":true,"KernelMemory":false,"KernelMemoryTCP":false,"CpuCfsPeriod":true,"CpuCfsQuota":true,"CPUShares":true,"CPUSet":true,"PidsLimit":true,"IPv4Forwarding":true,"BridgeNfIptables":true,"BridgeNfIp6tables":true,"Debug":false,"NFd":94,"OomKillDisable":false,"NGoroutines":84,"SystemTime":"2022-02-04T14:33:38.8004248Z","LoggingDriver":"json-file","CgroupDriver":"cgroupfs","CgroupVersion":"2","NEventsListener":7,"KernelVersion":"5.10.76-linuxkit","OperatingSystem":"Docker Desktop","OSVersion":"","OSType":"linux","Architecture":"x86_64","IndexServerAddress":"https://index.docker.io/v1/","RegistryConfig":{"AllowNondistributableArtifactsCIDRs":[],"AllowNondistributableArtifactsHostnames":[],"InsecureRegistryCIDRs":["127.0.0.0/8"],"IndexConfigs":{"docker.io":{"Name":"docker.io","Mirrors":[],"Secure":true,"Official":true}},"Mirrors":[]},"NCPU":4,"MemTotal":2082197504,"GenericResources":null,"DockerRootDir":"/var/lib/docker","HttpProxy":"","HttpsProxy":"","NoProxy":"","Name":"docker-desktop","Labels":[],"ExperimentalBuild":false,"ServerVersion":"20.10.12","Runtimes":{"io.containerd.runc.v2":{"path":"runc"},"io.containerd.runtime.v1.linux":{"path":"runc"},"runc":{"path":"runc"}},"DefaultRuntime":"runc","Swarm":{"NodeID":"","NodeAddr":"","LocalNodeState":"inactive","ControlAvailable":false,"Error":"","RemoteManagers":null},"LiveRestoreEnabled":false,"Isolation":"","InitBinary":"docker-init","ContainerdCommit":{"ID":"7b11cfaabd73bb80907dd23182b9347b4245eb5d","Expected":"7b11cfaabd73bb80907dd23182b9347b4245eb5d"},"RuncCommit":{"ID":"v1.0.2-0-g52b36a2","Expected":"v1.0.2-0-g52b36a2"},"InitCommit":{"ID":"de40ad0","Expected":"de40ad0"},"SecurityOptions":["name=seccomp,profile=default","name=cgroupns"],"Warnings":null}[\n]"
17:33:39.546 [ducttape-0] DEBUG com.github.dockerjava.zerodep.shaded.org.apache.hc.client5.http.wire - http-outgoing-0 << "[\r][\n]"
17:33:39.558 [ducttape-0] DEBUG com.github.dockerjava.zerodep.shaded.org.apache.hc.client5.http.wire - http-outgoing-0 << "0[\r][\n]"
17:33:39.558 [ducttape-0] DEBUG com.github.dockerjava.zerodep.shaded.org.apache.hc.client5.http.wire - http-outgoing-0 << "[\r][\n]"
17:33:41.913 [Test worker] DEBUG com.github.dockerjava.zerodep.shaded.org.apache.hc.client5.http.impl.io.PoolingHttpClientConnectionManager - Shutdown connection pool GRACEFUL
17:33:41.913 [Test worker] DEBUG com.github.dockerjava.zerodep.shaded.org.apache.hc.client5.http.impl.io.DefaultManagedHttpClientConnection - http-outgoing-0: close connection GRACEFUL
17:33:41.916 [Test worker] DEBUG com.github.dockerjava.zerodep.shaded.org.apache.hc.client5.http.impl.io.PoolingHttpClientConnectionManager - Connection pool shut down
17:33:41.920 [Test worker] DEBUG org.testcontainers.dockerclient.DockerClientProviderStrategy - UnixSocketClientProviderStrategy: failed with exception TimeoutException (org.rnorth.ducttape.TimeoutException: java.util.concurrent.TimeoutException). Root cause TimeoutException (null)
17:33:41.923 [ducttape-0] DEBUG com.github.dockerjava.zerodep.shaded.org.apache.hc.client5.http.impl.classic.InternalHttpClient - ep-00000000: releasing valid endpoint
17:33:41.924 [ducttape-0] DEBUG com.github.dockerjava.zerodep.shaded.org.apache.hc.client5.http.impl.io.PoolingHttpClientConnectionManager - ep-00000000: releasing endpoint
17:33:41.925 [ducttape-0] DEBUG com.github.dockerjava.zerodep.shaded.org.apache.hc.client5.http.impl.io.PoolingHttpClientConnectionManager - ep-00000000: connection is not kept alive
17:33:41.926 [ducttape-0] DEBUG com.github.dockerjava.zerodep.shaded.org.apache.hc.client5.http.impl.io.PoolingHttpClientConnectionManager - ep-00000000: connection released [route: {}->unix://localhost:2375][total available: 0; route allocated: 0 of 2147483647; total allocated: 0 of 2147483647]
17:33:41.934 [Test worker] DEBUG org.testcontainers.utility.CommandLine - Executing shell command: `docker-machine ls -q`
17:33:41.981 [Test worker] DEBUG org.testcontainers.shaded.org.zeroturnaround.exec.ProcessExecutor - Executing [docker-machine, ls, -q].
17:33:41.998 [Test worker] DEBUG org.testcontainers.shaded.org.zeroturnaround.exec.ProcessExecutor - Started Process[pid=15977, exitValue="not exited"]
17:33:42.097 [Test worker] DEBUG org.testcontainers.shaded.org.zeroturnaround.exec.WaitForProcess - Process[pid=15977, exitValue=0] stopped with exit code 0
17:33:42.102 [Test worker] DEBUG org.testcontainers.utility.DockerMachineClient - DOCKER_MACHINE_NAME is not set and no machine named 'default' found; Using first machine found with `docker-machine ls`:
17:33:42.102 [Test worker] DEBUG org.testcontainers.dockerclient.DockerClientProviderStrategy - Trying out strategy: DockerMachineClientProviderStrategy
17:33:42.103 [Test worker] DEBUG org.testcontainers.utility.CommandLine - Executing shell command: `docker-machine ls -q`
17:33:42.103 [Test worker] DEBUG org.testcontainers.shaded.org.zeroturnaround.exec.ProcessExecutor - Executing [docker-machine, ls, -q].
17:33:42.117 [Test worker] DEBUG org.testcontainers.shaded.org.zeroturnaround.exec.ProcessExecutor - Started Process[pid=15978, exitValue="not exited"]
17:33:42.135 [Test worker] DEBUG org.testcontainers.shaded.org.zeroturnaround.exec.WaitForProcess - Process[pid=15978, exitValue=0] stopped with exit code 0
17:33:42.135 [Test worker] DEBUG org.testcontainers.utility.DockerMachineClient - DOCKER_MACHINE_NAME is not set and no machine named 'default' found; Using first machine found with `docker-machine ls`:
17:33:42.135 [Test worker] INFO org.testcontainers.dockerclient.DockerMachineClientProviderStrategy - Found docker-machine, and will use machine named
17:33:42.135 [Test worker] DEBUG org.testcontainers.utility.CommandLine - Executing shell command: `docker-machine status `
17:33:42.135 [Test worker] DEBUG org.testcontainers.shaded.org.zeroturnaround.exec.ProcessExecutor - Executing [docker-machine, status, ].
17:33:42.148 [Test worker] DEBUG org.testcontainers.shaded.org.zeroturnaround.exec.ProcessExecutor - Started Process[pid=15979, exitValue="not exited"]
17:33:42.166 [Test worker] DEBUG org.testcontainers.shaded.org.zeroturnaround.exec.WaitForProcess - Process[pid=15979, exitValue=1] stopped with exit code 1
17:33:42.168 [Test worker] DEBUG org.testcontainers.dockerclient.DockerClientProviderStrategy - DockerMachineClientProviderStrategy: failed with exception ShellCommandException (Exception when executing docker-machine status ). Root cause InvalidExitValueException (Unexpected exit value: 1, allowed exit values: [0], executed command [docker-machine, status, ], output was 122 bytes:
Docker machine "" does not exist. Use "docker-machine ls" to list machines. Use "docker-machine create" to add a new one.)
17:33:42.168 [Test worker] ERROR org.testcontainers.dockerclient.DockerClientProviderStrategy - Could not find a valid Docker environment. Please check configuration. Attempted configurations were:
17:33:42.169 [Test worker] ERROR org.testcontainers.dockerclient.DockerClientProviderStrategy -     UnixSocketClientProviderStrategy: failed with exception TimeoutException (org.rnorth.ducttape.TimeoutException: java.util.concurrent.TimeoutException). Root cause TimeoutException (null)
17:33:42.169 [Test worker] ERROR org.testcontainers.dockerclient.DockerClientProviderStrategy -     DockerMachineClientProviderStrategy: failed with exception ShellCommandException (Exception when executing docker-machine status ). Root cause InvalidExitValueException (Unexpected exit value: 1, allowed exit values: [0], executed command [docker-machine, status, ], output was 122 bytes:
Docker machine "" does not exist. Use "docker-machine ls" to list machines. Use "docker-machine create" to add a new one.)
17:33:42.169 [Test worker] ERROR org.testcontainers.dockerclient.DockerClientProviderStrategy - As no valid configuration was found, execution cannot continue

please let me know if any help such as additional logs are required. Thanks!
@ashirman ashirman changed the title Error "Could not find a valid Docker environment. Please check configuration." from in testcontainers-java on 1.16.1+ and JVM 17th Error "Could not find a valid Docker environment. Please check configuration." from testcontainers-java on 1.16.1+ and JVM 17th Feb 7, 2022
@AndrejKapusta
Copy link

Try to create new default docker machine by command:
docker-machine create default

If problem still persist, can you provide more information about your Docker configuration?

@kiview
Copy link
Member

kiview commented Feb 8, 2022 •
edited

Hi @ashirman,
this should be unrelated to #4597, since I see the UnixSocketClientProviderStrategy failing. In the logs, we can also see, that DockerClientProviderStrategy is able to ping the Docker daemon and gets a response for the info command. So I have the feeling this is related to the internal use of Apache HTTP client and somehow hanging after getting the response. However, Apache HTTP client is used starting with 1.16.0.

@AndrejKapusta
This should be unrelated to Docker Machine.

@kiview
Copy link
Member

kiview commented Feb 8, 2022

@ashirman After looking at the logs in more detail, it might be the case that you run into a real timeout, since the default ping timeout was reduced in #4386.

Can you please try to configure a higher timeout, e.g. 30s? This is the old default.

client.ping.timeout = 30

@ashirman
Copy link
Author

ashirman commented Feb 9, 2022

well, thanks for suggestion. I tried the following in ~/.testcontainers.properties locally on Mac OS

#Modified by Testcontainers
#Wed Mar 04 17:59:09 MSK 2020
client.ping.timeout=60
docker.client.strategy=org.testcontainers.dockerclient.UnixSocketClientProviderStrategy

so using

openjdk version "17.0.2" 2022-01-18
OpenJDK Runtime Environment Homebrew (build 17.0.2+0)
OpenJDK 64-Bit Server VM Homebrew (build 17.0.2+0, mixed mode, sharing)

build has been successfully passed.

@kiview
Copy link
Member

kiview commented Feb 9, 2022 •
edited

Thanks for letting us know and happy that it works for you like this. I am not sure why your Docker daemon takes a long time to respond, but I guess it could be because of the many stopped containers on your machine:

"Containers":90,"ContainersRunning":11,"ContainersPaused":0,"ContainersStopped":79

Feel free to try out with a smaller timeout after having your system cleaned up, or keep the timeout like this.

@kiview kiview closed this as completed Feb 9, 2022
@cristian-com
Copy link

cristian-com commented Mar 28, 2022 •
edited

Leaving this log for searchability as docker-machine has been deprecated in MacOs and the initial stacktrace in this issue will probably not match. Anyway @kiview suggestions did the trick, thanks.

`
12:20:54.271 [Test worker] DEBUG org.testcontainers.utility.TestcontainersConfiguration - Testcontainers configuration overrides will be loaded from file:/Users/cmorales/.testcontainers.properties
12:20:54.330 [Test worker] INFO org.testcontainers.dockerclient.DockerClientProviderStrategy - Loaded org.testcontainers.dockerclient.UnixSocketClientProviderStrategy from ~/.testcontainers.properties, will try it first
12:20:54.332 [Test worker] DEBUG org.testcontainers.dockerclient.DockerClientProviderStrategy - Trying out strategy: UnixSocketClientProviderStrategy
12:20:54.611 [ducttape-0] DEBUG org.testcontainers.dockerclient.DockerClientProviderStrategy - Pinging docker daemon...
12:20:54.635 [ducttape-0] DEBUG org.testcontainers.shaded.com.github.dockerjava.core.command.AbstrDockerCmd - Cmd:
12:20:54.657 [ducttape-0] DEBUG com.github.dockerjava.zerodep.shaded.org.apache.hc.client5.http.impl.classic.InternalHttpClient - ex-00000001: preparing request execution
12:20:54.663 [ducttape-0] DEBUG com.github.dockerjava.zerodep.shaded.org.apache.hc.client5.http.protocol.RequestAddCookies - Cookie spec selected: strict
12:20:54.668 [ducttape-0] DEBUG com.github.dockerjava.zerodep.shaded.org.apache.hc.client5.http.protocol.RequestAuthCache - Auth cache not set in the context
12:20:54.668 [ducttape-0] DEBUG com.github.dockerjava.zerodep.shaded.org.apache.hc.client5.http.impl.classic.ProtocolExec - ex-00000001: target auth state: UNCHALLENGED
12:20:54.669 [ducttape-0] DEBUG com.github.dockerjava.zerodep.shaded.org.apache.hc.client5.http.impl.classic.ProtocolExec - ex-00000001: proxy auth state: UNCHALLENGED
12:20:54.670 [ducttape-0] DEBUG com.github.dockerjava.zerodep.shaded.org.apache.hc.client5.http.impl.classic.ConnectExec - ex-00000001: acquiring connection with route {}->unix://localhost:2375
12:20:54.670 [ducttape-0] DEBUG com.github.dockerjava.zerodep.shaded.org.apache.hc.client5.http.impl.classic.InternalHttpClient - ex-00000001: acquiring endpoint (3 MINUTES)
12:20:54.672 [ducttape-0] DEBUG com.github.dockerjava.zerodep.shaded.org.apache.hc.client5.http.impl.io.PoolingHttpClientConnectionManager - ex-00000001: endpoint lease request (3 MINUTES) [route: {}->unix://localhost:2375][total available: 0; route allocated: 0 of 2147483647; total allocated: 0 of 2147483647]
12:20:54.676 [ducttape-0] DEBUG com.github.dockerjava.zerodep.shaded.org.apache.hc.client5.http.impl.io.PoolingHttpClientConnectionManager - ex-00000001: endpoint leased [route: {}->unix://localhost:2375][total available: 0; route allocated: 1 of 2147483647; total allocated: 1 of 2147483647]
12:20:54.689 [ducttape-0] DEBUG com.github.dockerjava.zerodep.shaded.org.apache.hc.client5.http.impl.io.PoolingHttpClientConnectionManager - ex-00000001: acquired ep-00000000
12:20:54.689 [ducttape-0] DEBUG com.github.dockerjava.zerodep.shaded.org.apache.hc.client5.http.impl.classic.InternalHttpClient - ex-00000001: acquired endpoint ep-00000000
12:20:54.689 [ducttape-0] DEBUG com.github.dockerjava.zerodep.shaded.org.apache.hc.client5.http.impl.classic.ConnectExec - ex-00000001: opening connection {}->unix://localhost:2375
12:20:54.690 [ducttape-0] DEBUG com.github.dockerjava.zerodep.shaded.org.apache.hc.client5.http.impl.classic.InternalHttpClient - ep-00000000: connecting endpoint (3 MINUTES)
12:20:54.690 [ducttape-0] DEBUG com.github.dockerjava.zerodep.shaded.org.apache.hc.client5.http.impl.io.PoolingHttpClientConnectionManager - ep-00000000: connecting endpoint to unix://localhost:2375 (3 MINUTES)
12:20:56.625 [Test worker] DEBUG com.github.dockerjava.zerodep.shaded.org.apache.hc.client5.http.impl.io.PoolingHttpClientConnectionManager - Shutdown connection pool GRACEFUL
12:20:56.625 [Test worker] DEBUG com.github.dockerjava.zerodep.shaded.org.apache.hc.client5.http.impl.io.DefaultManagedHttpClientConnection - http-outgoing-0: close connection GRACEFUL
12:20:56.626 [Test worker] DEBUG com.github.dockerjava.zerodep.shaded.org.apache.hc.client5.http.impl.io.PoolingHttpClientConnectionManager - Connection pool shut down
12:20:56.628 [Test worker] DEBUG org.testcontainers.dockerclient.DockerClientProviderStrategy - UnixSocketClientProviderStrategy: failed with exception TimeoutException (org.rnorth.ducttape.TimeoutException: java.util.concurrent.TimeoutException). Root cause TimeoutException (null)
12:20:56.634 [Test worker] INFO org.testcontainers.dockerclient.DockerMachineClientProviderStrategy - docker-machine executable was not found on PATH ([/usr/local/opt/tomcat@8/bin, /Users/cmorales/.sdkman/candidates/maven/current/bin, /Users/cmorales/.sdkman/candidates/java/current/bin, /Users/cmorales/.sdkman/candidates/groovy/current/bin, /Users/cmorales/.sdkman/candidates/grails/current/bin, /Users/cmorales/.sdkman/candidates/gradle/current/bin, /Library/Frameworks/Python.framework/Versions/3.9/bin, /usr/local/bin, /usr/bin, /bin, /usr/sbin, /sbin])
12:20:56.635 [Test worker] ERROR org.testcontainers.dockerclient.DockerClientProviderStrategy - Could not find a valid Docker environment. Please check configuration. Attempted configurations were:
12:20:56.636 [Test worker] ERROR org.testcontainers.dockerclient.DockerClientProviderStrategy - UnixSocketClientProviderStrategy: failed with exception TimeoutException (org.rnorth.ducttape.TimeoutException: java.util.concurrent.TimeoutException). Root cause TimeoutException (null)
12:20:56.636 [Test worker] ERROR org.testcontainers.dockerclient.DockerClientProviderStrategy - As no valid configuration was found, execution cannot continue

Could not find a valid Docker environment. Please see logs and check configuration
java.lang.IllegalStateException: Could not find a valid Docker environment. Please see logs and check configuration
at org.testcontainers.dockerclient.DockerClientProviderStrategy.lambda$getFirstValidStrategy$4(DockerClientProviderStrategy.java:156)
at java.util.Optional.orElseThrow(Optional.java:290)
at org.testcontainers.dockerclient.DockerClientProviderStrategy.getFirstValidStrategy(DockerClientProviderStrategy.java:148)
at org.testcontainers.DockerClientFactory.getOrInitializeStrategy(DockerClientFactory.java:146)
at org.testcontainers.DockerClientFactory.client(DockerClientFactory.java:188)
at org.testcontainers.DockerClientFactory$1.getDockerClient(DockerClientFactory.java:101)
at com.github.dockerjava.api.DockerClientDelegate.authConfig(DockerClientDelegate.java:107)
at org.testcontainers.containers.GenericContainer.start(GenericContainer.java:316)
at org.testcontainers.spock.TestcontainersMethodInterceptor.startContainers_closure3(TestcontainersMethodInterceptor.groovy:83)
at groovy.lang.Closure.call(Closure.java:412)
at groovy.lang.Closure.call(Closure.java:428)
at org.testcontainers.spock.TestcontainersMethodInterceptor.startContainers(TestcontainersMethodInterceptor.groovy:80)
at org.testcontainers.spock.TestcontainersMethodInterceptor.interceptSetupSpecMethod(TestcontainersMethodInterceptor.groovy:25)
at org.spockframework.runtime.extension.AbstractMethodInterceptor.intercept(AbstractMethodInterceptor.java:36)
at org.spockframework.runtime.extension.MethodInvocation.proceed(MethodInvocation.java:101)
at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$6(NodeTestTask.java:148)
at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$8(NodeTestTask.java:141)
at org.spockframework.runtime.model.MethodInfo.invoke(MethodInfo.java:148)
at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$9(NodeTestTask.java:139)
at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
at org.junit.platform.engine.support.hierarchical.NodeTestTask.executeRecursively(NodeTestTask.java:138)
at org.junit.platform.engine.support.hierarchical.NodeTestTask.execute(NodeTestTask.java:95)
at java.util.ArrayList.forEach(ArrayList.java:1259)
at org.junit.platform.engine.support.hierarchical.SameThreadHierarchicalTestExecutorService.invokeAll(SameThreadHierarchicalTestExecutorService.java:41)
at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$6(NodeTestTask.java:155)
at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$8(NodeTestTask.java:141)
at org.junit.platform.engine.support.hierarchical.Node.around(Node.java:137)
at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$9(NodeTestTask.java:139)
at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
at org.junit.platform.engine.support.hierarchical.NodeTestTask.executeRecursively(NodeTestTask.java:138)
at org.junit.platform.engine.support.hierarchical.NodeTestTask.execute(NodeTestTask.java:95)
at org.junit.platform.engine.support.hierarchical.SameThreadHierarchicalTestExecutorService.submit(SameThreadHierarchicalTestExecutorService.java:35)
at org.junit.platform.engine.support.hierarchical.HierarchicalTestExecutor.execute(HierarchicalTestExecutor.java:57)
at org.junit.platform.engine.support.hierarchical.HierarchicalTestEngine.execute(HierarchicalTestEngine.java:54)
at org.junit.platform.launcher.core.EngineExecutionOrchestrator.execute(EngineExecutionOrchestrator.java:107)
at org.junit.platform.launcher.core.EngineExecutionOrchestrator.execute(EngineExecutionOrchestrator.java:88)
at org.junit.platform.launcher.core.EngineExecutionOrchestrator.lambda$execute$0(EngineExecutionOrchestrator.java:54)
at org.junit.platform.launcher.core.EngineExecutionOrchestrator.withInterceptedStreams(EngineExecutionOrchestrator.java:67)
at org.junit.platform.launcher.core.EngineExecutionOrchestrator.execute(EngineExecutionOrchestrator.java:52)
at org.junit.platform.launcher.core.DefaultLauncher.execute(DefaultLauncher.java:114)
at org.junit.platform.launcher.core.DefaultLauncher.execute(DefaultLauncher.java:86)
at org.junit.platform.launcher.core.DefaultLauncherSession$DelegatingLauncher.execute(DefaultLauncherSession.java:86)
at org.junit.platform.launcher.core.SessionPerRequestLauncher.execute(SessionPerRequestLauncher.java:53)
at org.gradle.api.internal.tasks.testing.junitplatform.JUnitPlatformTestClassProcessor$CollectAllTestClassesExecutor.processAllTestClasses(JUnitPlatformTestClassProcessor.java:99)
at org.gradle.api.internal.tasks.testing.junitplatform.JUnitPlatformTestClassProcessor$CollectAllTestClassesExecutor.access$000(JUnitPlatformTestClassProcessor.java:79)
at org.gradle.api.internal.tasks.testing.junitplatform.JUnitPlatformTestClassProcessor.stop(JUnitPlatformTestClassProcessor.java:75)
at org.gradle.api.internal.tasks.testing.SuiteTestClassProcessor.stop(SuiteTestClassProcessor.java:61)
at org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:36)
at org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
at org.gradle.internal.dispatch.ContextClassLoaderDispatch.dispatch(ContextClassLoaderDispatch.java:33)
at org.gradle.internal.dispatch.ProxyDispatchAdapter$DispatchingInvocationHandler.invoke(ProxyDispatchAdapter.java:94)
at org.gradle.api.internal.tasks.testing.worker.TestWorker$3.run(TestWorker.java:193)
at org.gradle.api.internal.tasks.testing.worker.TestWorker.executeAndMaintainThreadName(TestWorker.java:129)
at org.gradle.api.internal.tasks.testing.worker.TestWorker.execute(TestWorker.java:100)
at org.gradle.api.internal.tasks.testing.worker.TestWorker.execute(TestWorker.java:60)
at org.gradle.process.internal.worker.child.ActionExecutionWorker.execute(ActionExecutionWorker.java:56)
at org.gradle.process.internal.worker.child.SystemApplicationClassLoaderWorker.call(SystemApplicationClassLoaderWorker.java:133)
at org.gradle.process.internal.worker.child.SystemApplicationClassLoaderWorker.call(SystemApplicationClassLoaderWorker.java:71)
at worker.org.gradle.process.internal.worker.GradleWorkerMain.run(GradleWorkerMain.java:69)
at worker.org.gradle.process.internal.worker.GradleWorkerMain.main(GradleWorkerMain.java:74)
`

@mshima mshima mentioned this issue Aug 9, 2022
Merged
apupier added a commit to apupier/kaoto-backend that referenced this issue Jun 14, 2023
@apupier
Increase timeout to connect to Docker client
70bd7a9 
it was not enough for Windows. The default value was decreased during
upgrade in TestContainers. see
testcontainers/testcontainers-java#5030 (comment)

part of KaotoIO#644

Signed-off-by: Aurélien Pupier <apupier@redhat.com>
apupier added a commit to apupier/kaoto-backend that referenced this issue Jun 14, 2023
@apupier
Increase timeout to connect to Docker client
b8934e1 
it was not enough for Windows. The default value was decreased during
upgrade in TestContainers. see
testcontainers/testcontainers-java#5030 (comment)

part of KaotoIO#644

Signed-off-by: Aurélien Pupier <apupier@redhat.com>
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
4 participants
@ashirman @kiview @AndrejKapusta @cristian-com