ping timeout of 1s too low in DockerClientProviderStrategy

[kunickiaj]

Wondering if anyone else has experienced the following...

We upgraded from Docker 1.10 / testcontainers 1.0.5 -> Docker 1.12 / testcontainers 1.1.3.

Since then it seems that the DOCKER_HOST environment variable is not always used by the docker client. I've verified with a debugger that it is in fact set.

Generally this results in an error like the following:

2016-08-16 21:18:29,049 INFO  DockerClientProviderStrategy - Looking for Docker environment. Trying Environment variables, system properties and defaults. Resolved: 

2016-08-16 21:18:32,870 INFO  DockerClientProviderStrategy - Looking for Docker environment. Trying local Unix socket (via TCP proxy)
2016-08-16 21:18:32,870 INFO  DockerClientProviderStrategy - Looking for Docker environment. Trying local Unix socket (unix:///var/run/docker.sock)
2016-08-16 21:18:32,898 INFO  DockerClientProviderStrategy - Looking for Docker environment. Trying docker-machine
2016-08-16 21:18:32,908 ERROR DockerClientProviderStrategy - Could not find a valid Docker environment. Please check configuration. Attempted configurations were:
2016-08-16 21:18:32,908 ERROR DockerClientProviderStrategy -     EnvironmentAndSystemPropertyClientProviderStrategy: failed with exception InvalidConfigurationException (ping failed)
2016-08-16 21:18:32,908 ERROR DockerClientProviderStrategy -     ProxiedUnixSocketClientProviderStrategy: failed with exception InvalidConfigurationException (this strategy is only applicable to OS X)
2016-08-16 21:18:32,908 ERROR DockerClientProviderStrategy -     UnixSocketClientProviderStrategy: failed with exception InvalidConfigurationException (ping failed). Root cause NoSuchFileException (/var/run/docker.sock)
2016-08-16 21:18:32,908 ERROR DockerClientProviderStrategy -     DockerMachineClientProviderStrategy: failed with exception InvalidConfigurationException (docker-machine executable was not found on PATH ([/opt/tools/hudson.tasks.Maven_MavenInstallation/maven3/bin, /opt/tools/hudson.model.JDK/Oracle_Java_8/bin, /opt/tools/jenkins.plugins.nodejs.tools.NodeJSInstallation/Node.js_Stable/bin, /opt/tools/hudson.model.JDK/Oracle_Java_8/bin, /usr/local/sbin, /usr/local/bin, /usr/sbin, /usr/bin, /sbin, /bin]))
2016-08-16 21:18:32,908 ERROR DockerClientProviderStrategy - As no valid configuration was found, execution cannot continue

[rnorth]

Gah, that's annoying. Sorry about this.

Is there any chance you could debut what's going on inside
EnvironmentAndSystemPropertyClientProviderStrategy? That basically defers
to docker-java to discover the environment variables, but maybe something
else is going wrong (possibly including the ping timeout being too short)...
On Tue, 16 Aug 2016 at 23:31, Adam Kunicki notifications@github.com wrote:

Wondering if anyone else has experienced the following...

We upgraded from Docker 1.10 / testcontainers 1.0.5 -> Docker 1.12 /
testcontainers 1.1.3.

Since then it seems that the DOCKER_HOST environment variable is not
always used by the docker client. I've verified with a debugger that it is
in fact set.

Generally this results in an error like the following:

2016-08-16 21:18:29,049 INFO DockerClientProviderStrategy - Looking for Docker environment. Trying Environment variables, system properties and defaults. Resolved:

2016-08-16 21:18:32,870 INFO DockerClientProviderStrategy - Looking for Docker environment. Trying local Unix socket (via TCP proxy)
2016-08-16 21:18:32,870 INFO DockerClientProviderStrategy - Looking for Docker environment. Trying local Unix socket (unix:///var/run/docker.sock)
2016-08-16 21:18:32,898 INFO DockerClientProviderStrategy - Looking for Docker environment. Trying docker-machine
2016-08-16 21:18:32,908 ERROR DockerClientProviderStrategy - Could not find a valid Docker environment. Please check configuration. Attempted configurations were:
2016-08-16 21:18:32,908 ERROR DockerClientProviderStrategy - EnvironmentAndSystemPropertyClientProviderStrategy: failed with exception InvalidConfigurationException (ping failed)
2016-08-16 21:18:32,908 ERROR DockerClientProviderStrategy - ProxiedUnixSocketClientProviderStrategy: failed with exception InvalidConfigurationException (this strategy is only applicable to OS X)
2016-08-16 21:18:32,908 ERROR DockerClientProviderStrategy - UnixSocketClientProviderStrategy: failed with exception InvalidConfigurationException (ping failed). Root cause NoSuchFileException (/var/run/docker.sock)
2016-08-16 21:18:32,908 ERROR DockerClientProviderStrategy - DockerMachineClientProviderStrategy: failed with exception InvalidConfigurationException (docker-machine executable was not found on PATH ([/opt/tools/hudson.tasks.Maven_MavenInstallation/maven3/bin, /opt/tools/hudson.model.JDK/Oracle_Java_8/bin, /opt/tools/jenkins.plugins.nodejs.tools.NodeJSInstallation/Node.js_Stable/bin, /opt/tools/hudson.model.JDK/Oracle_Java_8/bin, /usr/local/sbin, /usr/local/bin, /usr/sbin, /usr/bin, /sbin, /bin]))
2016-08-16 21:18:32,908 ERROR DockerClientProviderStrategy - As no valid configuration was found, execution cannot continue

—
You are receiving this because you are subscribed to this thread.
Reply to this email directly, view it on GitHub
#204, or mute
the thread
https://github.com/notifications/unsubscribe-auth/AAIETwv21I9hvLQpE9nRqQhpQafO1zE5ks5qgjpQgaJpZM4Jl6sr
.

Richard

[kunickiaj]

I'll do some deeper digging, at first glance it looks like it may be more of a docker-java issue.

[kunickiaj]

What I've found is that testcontainers < 1.1.0 seems to pick up my env fine, which is a docker container jenkins slave running a debian based container (however I'm running docker 1.12 which doesnt work with < 1.0.x)

However when using testcontainers 1.1.0+ I get the following

Looking for Docker environment. Trying Environment variables, system properties and defaults. Resolved:

Which is strange because a env | grep DOCKER results in this:

DOCKER_HOST=tcp://<the docker host fqdn>:2376
DOCKER_TLS_VERIFY=1
DOCKER_CERT_PATH=/<build user>/.docker
DOCKER_VERSION=1.12.0

These get picked up correctly and displayed in testcontainers 1.0.5 and older.

[kunickiaj]

Seems to coincide with an update from docker-java 2.2 to 3.x will take a look at that project as well.

[kunickiaj]

Good news, I've figured out the problems here. @rnorth

First one is that in the refactoring that happened for 1.1.0+ the DockerClientProviderStrategy logs strategy.getDescription() before the config is initialized, which is why for Environment strategy the values are empty. It was just a coincidence that this happened at the same time the docker-java client was updated.

This is a simple fix to just log this message after strategy.test() or in test() itself if logging is desired in case it fails.

The real issue here is that the hardcoded timeout of 1s for the ping command seems to be too low for our setup (docker host thats generally under a lot of load). In testing increasing this slightly resulted in the ping() command not failing.

I'll try to put together patches for these items, my only question is about how we could make that ping timeout configurable. Is there a way to allow the user to specify that timeout? Otherwise I may just set it to 5 or 10 seconds max.

[rnorth]

@kunickiaj ah that's great - thank you. I'll accept the PRs.

Regarding making the timeout configurable, that's probably a good idea. I think this is the kind of thing we'd want to be configurable via system properties rather than in the test code, though, as it's more a consequence of the environment the tests are being run in.

[kunickiaj]

Agreed. Let me update the patch to allow configuration.

[kunickiaj]

@rnorth looking into this further, it looks like the timeout is different in each of the provider strategies ranging from 10s (unix socket) to 30s (docker-machine).

I'm wondering why the TCP one was set to a low 1s. How do you feel about standardizing all of them to the same max timeout (e.g. 30s) and having that overridable via system property?

[rnorth]

@kunickiaj thanks. To be honest the reason is just that these timeouts have been 'what works' when each of the strategies was added. Docker Machine support was a bit of an outlier at 30s because testcontainers itself can launch the Machine VM - but the VM takes a while to be ready.

We could probably standardise for all to be a long-ish timeout (30s) but only where the strategy will fail fast if it's absent. e.g. if a host doesn't has a unix socket for docker but not TCP, we don't want testcontainers sitting around for 30s waiting for TCP to respond.

It's probably not a big deal, but we need to think about each strategy case-by-case!

[jeantil]

hello,

I have been having this same issue on and off for a while. I investigated deeper today because it prevented a release from going through.

I think a configurable timeout (preferably through a system variable) would be nice.