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.

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

Command-based port check in HostPortWaitStrategy in case of Docker for Mac #236

Merged

Conversation

bsideup
Copy link
Member

@bsideup bsideup commented Oct 25, 2016

Fixes #160

I did a test run on my Mac with Docker for Mac, everything is green :)

Consider it as a temporary hack until the issue with port forwarding is fixed on Docker's side

if (DockerClientFactory.instance().isUsing(ProxiedUnixSocketClientProviderStrategy.class)) {
List<Integer> exposedPorts = container.getExposedPorts();

Integer exposedPort = exposedPorts.stream()
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

unfortunately, we have to do some reverse engineering to find the port originally exposed since it's not private (protected, in fact)

return;
}

String[][] commands = {
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

two strategies at this moment - one without BASH because it's not available in Alpine linux for example, and another one with BASH

public class HostPortWaitStrategy extends GenericContainer.AbstractWaitStrategy {

private static final String SUCCESS_MARKER = "TESTCONTAINERS_SUCCESS";
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

we have to use string-based success marker because exit code is not available

@rnorth
Copy link
Member

rnorth commented Nov 7, 2016

Sorry for being slow to respond to this. It seems like a neat idea - while it is a little 'hacky' it would insulate our users from this nasty issue, so is a good thing in the short term.

I'm having some issues with tests running locally, though - not quite sure why, though I've not done much digging yet.

Any ideas?

Running org.testcontainers.junit.DockerComposeContainerScalingTest
20:28:51.319 DEBUG org.testcontainers.dockerclient.DockerClientProviderStrategy - EnvironmentAndSystemPropertyClientProviderStrategy: failed with exception ExceptionInInitializerError (null). Root cause IllegalStateException (Only supported on Linux)
20:28:52.085 DEBUG org.testcontainers.dockerclient.DockerClientProviderStrategy - Pinging docker daemon...
20:28:52.444 INFO  org.testcontainers.dockerclient.DockerClientProviderStrategy - Accessing Docker for Mac unix domain socket via TCP proxy (/var/run/docker.sock via localhost:56135)
20:28:52.447 INFO  org.testcontainers.dockerclient.DockerClientProviderStrategy - Looking for Docker environment. Tried local Unix socket (via TCP proxy)
20:28:52.786 INFO  org.testcontainers.DockerClientFactory - Connected to docker:
  Server Version: 1.12.2-rc1
  API Version: 1.24
  Operating System: Alpine Linux v3.4
  Total Memory: 1999 MB
20:28:54.488 INFO  org.testcontainers.DockerClientFactory - Disk utilization in Docker environment is 11% (51149 MB available )
20:28:54.618 DEBUG 🐳 [docker/compose:1.8.0] - Set env COMPOSE_FILE=/Users/rnorth/projects/testcontainers-java/core/src/test/resources/scaled-compose-test.yml
20:28:54.621 DEBUG 🐳 [docker/compose:1.8.0] - Starting container: docker/compose:1.8.0
20:28:54.621 DEBUG 🐳 [docker/compose:1.8.0] - Trying to start container: docker/compose:1.8.0
20:28:54.623 DEBUG 🐳 [docker/compose:1.8.0] - Trying to start container: docker/compose:1.8.0 (attempt 1/1)
20:28:54.624 DEBUG 🐳 [docker/compose:1.8.0] - Starting container: docker/compose:1.8.0
20:28:54.624 INFO  🐳 [docker/compose:1.8.0] - Creating container for image: docker/compose:1.8.0
20:28:54.960 INFO  🐳 [docker/compose:1.8.0] - Starting container with ID: f224d35a8713d20264927956c9bdc541729ab4ace518ea1a6a2760a260d6603c
20:28:55.492 INFO  🐳 [docker/compose:1.8.0] - Container docker/compose:1.8.0 is starting: f224d35a8713d20264927956c9bdc541729ab4ace518ea1a6a2760a260d6603c
20:29:34.659 DEBUG org.testcontainers.containers.wait.HostPortWaitStrategy - Liveness check port of /determined_leavitt is empty. Not waiting.
20:29:34.661 INFO  🐳 [docker/compose:1.8.0] - Container docker/compose:1.8.0 started
20:29:34.672 INFO  🐳 [docker/compose:1.8.0] - Docker Compose container is running for command: pull
20:29:34.685 INFO  🐳 [docker/compose:1.8.0] - STDERR: Pulling redis (redis:latest)...
20:29:34.686 INFO  🐳 [docker/compose:1.8.0] - STDOUT: latest: Pulling from library/redis
20:29:34.687 INFO  🐳 [docker/compose:1.8.0] - STDOUT: Digest: sha256:0fe5a7afa2c2154f37c8ab56a9a6c5023cb0405cc0e85b34d8dcc1de6c3f143e
20:29:34.691 INFO  🐳 [docker/compose:1.8.0] - STDOUT: Status: Downloaded newer image for redis:latest
20:29:34.701 INFO  🐳 [docker/compose:1.8.0] - Docker Compose has finished running
20:29:34.709 DEBUG 🐳 [docker/compose:1.8.0] - Set env COMPOSE_FILE=/Users/rnorth/projects/testcontainers-java/core/src/test/resources/scaled-compose-test.yml
20:29:34.711 DEBUG 🐳 [docker/compose:1.8.0] - Starting container: docker/compose:1.8.0
20:29:34.711 DEBUG 🐳 [docker/compose:1.8.0] - Trying to start container: docker/compose:1.8.0
20:29:34.712 DEBUG 🐳 [docker/compose:1.8.0] - Trying to start container: docker/compose:1.8.0 (attempt 1/1)
20:29:34.713 DEBUG 🐳 [docker/compose:1.8.0] - Starting container: docker/compose:1.8.0
20:29:34.714 INFO  🐳 [docker/compose:1.8.0] - Creating container for image: docker/compose:1.8.0
20:29:35.058 INFO  🐳 [docker/compose:1.8.0] - Starting container with ID: e6e108309397070e55c122d96d17a8616db77938c383f41aab3c00e3e8d70901
20:29:35.673 INFO  🐳 [docker/compose:1.8.0] - Container docker/compose:1.8.0 is starting: e6e108309397070e55c122d96d17a8616db77938c383f41aab3c00e3e8d70901
20:29:38.461 DEBUG org.testcontainers.containers.wait.HostPortWaitStrategy - Liveness check port of /clever_kalam is empty. Not waiting.
20:29:38.462 INFO  🐳 [docker/compose:1.8.0] - Container docker/compose:1.8.0 started
20:29:38.464 INFO  🐳 [docker/compose:1.8.0] - Docker Compose container is running for command: scale redis=3
20:29:38.471 INFO  🐳 [docker/compose:1.8.0] - STDERR: Creating and starting vi5fon_redis_1 ...
20:29:38.472 INFO  🐳 [docker/compose:1.8.0] - STDERR: Creating and starting vi5fon_redis_2 ...
20:29:38.473 INFO  🐳 [docker/compose:1.8.0] - STDERR: Creating and starting vi5fon_redis_3 ...
Creating and starting vi5fon_redis_3 ... done STDERR: [2A
20:29:38.476 INFO  🐳 [docker/compose:1.8.0] - Docker Compose has finished running
20:29:38.476 DEBUG 🐳 [docker/compose:1.8.0] - Set env COMPOSE_FILE=/Users/rnorth/projects/testcontainers-java/core/src/test/resources/scaled-compose-test.yml
20:29:38.478 DEBUG 🐳 [docker/compose:1.8.0] - Starting container: docker/compose:1.8.0
20:29:38.478 DEBUG 🐳 [docker/compose:1.8.0] - Trying to start container: docker/compose:1.8.0
20:29:38.479 DEBUG 🐳 [docker/compose:1.8.0] - Trying to start container: docker/compose:1.8.0 (attempt 1/1)
20:29:38.479 DEBUG 🐳 [docker/compose:1.8.0] - Starting container: docker/compose:1.8.0
20:29:38.480 INFO  🐳 [docker/compose:1.8.0] - Creating container for image: docker/compose:1.8.0
20:29:38.765 INFO  🐳 [docker/compose:1.8.0] - Starting container with ID: 31ff7846a65f7916a164851affaf772a6e32da92bb44cb7d350ca401c1da194d
20:29:39.344 INFO  🐳 [docker/compose:1.8.0] - Container docker/compose:1.8.0 is starting: 31ff7846a65f7916a164851affaf772a6e32da92bb44cb7d350ca401c1da194d
20:29:40.426 DEBUG org.testcontainers.containers.wait.HostPortWaitStrategy - Liveness check port of /pensive_engelbart is empty. Not waiting.
20:29:40.427 INFO  🐳 [docker/compose:1.8.0] - Container docker/compose:1.8.0 started
20:29:40.429 INFO  🐳 [docker/compose:1.8.0] - Docker Compose container is running for command: up -d
20:29:40.436 INFO  🐳 [docker/compose:1.8.0] - STDERR: vi5fon_redis_3 is up-to-date
20:29:40.437 INFO  🐳 [docker/compose:1.8.0] - STDERR: vi5fon_redis_2 is up-to-date
20:29:40.437 INFO  🐳 [docker/compose:1.8.0] - STDERR: vi5fon_redis_1 is up-to-date
20:29:40.440 INFO  🐳 [docker/compose:1.8.0] - Docker Compose has finished running
20:29:40.585 DEBUG 🐳 [richnorth/ambassador:latest] - Starting container: richnorth/ambassador:latest
20:29:40.586 DEBUG 🐳 [richnorth/ambassador:latest] - Trying to start container: richnorth/ambassador:latest
20:29:40.586 DEBUG 🐳 [richnorth/ambassador:latest] - Trying to start container: richnorth/ambassador:latest (attempt 1/1)
20:29:40.587 DEBUG 🐳 [richnorth/ambassador:latest] - Starting container: richnorth/ambassador:latest
20:29:40.588 INFO  🐳 [richnorth/ambassador:latest] - Creating container for image: richnorth/ambassador:latest
20:29:40.969 INFO  🐳 [richnorth/ambassador:latest] - Starting container with ID: 01668db7e7c054633838c3ec6f19255a3a029af9e5794a2db445a5d8b766904b
20:29:41.579 INFO  🐳 [richnorth/ambassador:latest] - Container richnorth/ambassador:latest is starting: 01668db7e7c054633838c3ec6f19255a3a029af9e5794a2db445a5d8b766904b
20:29:41.632 INFO  🐳 [richnorth/ambassador:latest] - Running "exec" command: /bin/sh -c nc -vz -w 1 localhost 32768 && echo TESTCONTAINERS_SUCCESS
20:29:41.754 INFO  🐳 [richnorth/ambassador:latest] - Running "exec" command: /bin/bash -c </dev/tcp/localhost/32768 && echo TESTCONTAINERS_SUCCESS

... snip ...

20:30:39.435 INFO  🐳 [richnorth/ambassador:latest] - Running "exec" command: /bin/sh -c nc -vz -w 1 localhost 32768 && echo TESTCONTAINERS_SUCCESS
20:30:39.582 INFO  🐳 [richnorth/ambassador:latest] - Running "exec" command: /bin/bash -c </dev/tcp/localhost/32768 && echo TESTCONTAINERS_SUCCESS
20:30:41.646 ERROR 🐳 [richnorth/ambassador:latest] - Could not start container
org.testcontainers.containers.ContainerLaunchException: Timed out waiting for container port to open (localhost:32768 should be listening)
    at org.testcontainers.containers.wait.HostPortWaitStrategy.waitUntilReady(HostPortWaitStrategy.java:91) ~[classes/:na]
    at org.testcontainers.containers.GenericContainer$AbstractWaitStrategy.waitUntilReady(GenericContainer.java:882) ~[classes/:na]
    at org.testcontainers.containers.GenericContainer.waitUntilContainerStarted(GenericContainer.java:444) [classes/:na]
    at org.testcontainers.containers.GenericContainer.tryStart(GenericContainer.java:222) [classes/:na]
    at org.testcontainers.containers.GenericContainer.lambda$start$0(GenericContainer.java:172) [classes/:na]
    at org.rnorth.ducttape.unreliables.Unreliables.retryUntilSuccess(Unreliables.java:76) ~[duct-tape-1.0.6.jar:na]
    at org.testcontainers.containers.GenericContainer.start(GenericContainer.java:170) [classes/:na]
    at org.testcontainers.containers.DockerComposeContainer.lambda$null$2(DockerComposeContainer.java:193) ~[classes/:na]
    at org.rnorth.ducttape.ratelimits.RateLimiter.doWhenReady(RateLimiter.java:27) ~[duct-tape-1.0.6.jar:na]
    at org.testcontainers.containers.DockerComposeContainer.lambda$startAmbassadorContainers$3(DockerComposeContainer.java:188) ~[classes/:na]
    at org.rnorth.ducttape.unreliables.Unreliables.lambda$retryUntilSuccess$0(Unreliables.java:41) ~[duct-tape-1.0.6.jar:na]
    at java.util.concurrent.FutureTask.run(FutureTask.java:266) ~[na:1.8.0_102]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) ~[na:1.8.0_102]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) ~[na:1.8.0_102]
    at java.lang.Thread.run(Thread.java:745) ~[na:1.8.0_102]
20:30:41.656 ERROR 🐳 [richnorth/ambassador:latest] - Container log output (if any) will follow:
20:30:41.693 INFO  🐳 [richnorth/ambassador:latest] - Running "exec" command: /bin/sh -c nc -vz -w 1 localhost 32768 && echo TESTCONTAINERS_SUCCESS
20:30:41.871 INFO  🐳 [richnorth/ambassador:latest] - Running "exec" command: /bin/bash -c </dev/tcp/localhost/32768 && echo TESTCONTAINERS_SUCCESS

... snip ...

20:31:40.384 INFO  🐳 [richnorth/ambassador:latest] - Running "exec" command: /bin/sh -c nc -vz -w 1 localhost 32769 && echo TESTCONTAINERS_SUCCESS
20:31:40.496 INFO  🐳 [richnorth/ambassador:latest] - Running "exec" command: /bin/bash -c </dev/tcp/localhost/32769 && echo TESTCONTAINERS_SUCCESS
20:31:40.574 WARN  org.testcontainers.containers.DockerComposeContainer - Exception during ambassador container startup!
org.rnorth.ducttape.TimeoutException: Timeout waiting for result with exception
    at org.rnorth.ducttape.unreliables.Unreliables.retryUntilSuccess(Unreliables.java:51) ~[duct-tape-1.0.6.jar:na]
    at org.testcontainers.containers.DockerComposeContainer.startAmbassadorContainers(DockerComposeContainer.java:186) [classes/:na]
    at org.testcontainers.containers.DockerComposeContainer.starting(DockerComposeContainer.java:106) [classes/:na]
    at org.testcontainers.containers.FailureDetectingExternalResource$1.evaluate(FailureDetectingExternalResource.java:28) [classes/:na]
    at org.junit.rules.RunRules.evaluate(RunRules.java:20) [junit-4.12.jar:4.12]
    at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325) [junit-4.12.jar:4.12]
    at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78) [junit-4.12.jar:4.12]
    at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57) [junit-4.12.jar:4.12]
    at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290) [junit-4.12.jar:4.12]
    at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71) [junit-4.12.jar:4.12]
    at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288) [junit-4.12.jar:4.12]
    at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58) [junit-4.12.jar:4.12]
    at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268) [junit-4.12.jar:4.12]
    at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26) [junit-4.12.jar:4.12]
    at org.junit.runners.ParentRunner.run(ParentRunner.java:363) [junit-4.12.jar:4.12]
    at org.apache.maven.surefire.junit4.JUnit4Provider.execute(JUnit4Provider.java:252) [surefire-junit4-2.12.4.jar:2.12.4]
    at org.apache.maven.surefire.junit4.JUnit4Provider.executeTestSet(JUnit4Provider.java:141) [surefire-junit4-2.12.4.jar:2.12.4]
    at org.apache.maven.surefire.junit4.JUnit4Provider.invoke(JUnit4Provider.java:112) [surefire-junit4-2.12.4.jar:2.12.4]
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0_102]
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0_102]
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_102]
    at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_102]
    at org.apache.maven.surefire.util.ReflectionUtils.invokeMethodWithArray(ReflectionUtils.java:189) [surefire-api-2.12.4.jar:2.12.4]
    at org.apache.maven.surefire.booter.ProviderFactory$ProviderProxy.invoke(ProviderFactory.java:165) [surefire-booter-2.12.4.jar:2.12.4]
    at org.apache.maven.surefire.booter.ProviderFactory.invokeProvider(ProviderFactory.java:85) [surefire-booter-2.12.4.jar:2.12.4]
    at org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:115) [surefire-booter-2.12.4.jar:2.12.4]
    at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:75) [surefire-booter-2.12.4.jar:2.12.4]
Caused by: org.testcontainers.containers.ContainerLaunchException: Container startup failed
    at org.testcontainers.containers.GenericContainer.start(GenericContainer.java:177) ~[classes/:na]
    at org.testcontainers.containers.DockerComposeContainer.lambda$null$2(DockerComposeContainer.java:193) [classes/:na]
    at org.rnorth.ducttape.ratelimits.RateLimiter.doWhenReady(RateLimiter.java:27) ~[duct-tape-1.0.6.jar:na]
    at org.testcontainers.containers.DockerComposeContainer.lambda$startAmbassadorContainers$3(DockerComposeContainer.java:188) [classes/:na]
    at org.rnorth.ducttape.unreliables.Unreliables.lambda$retryUntilSuccess$0(Unreliables.java:41) ~[duct-tape-1.0.6.jar:na]
    at java.util.concurrent.FutureTask.run(FutureTask.java:266) ~[na:1.8.0_102]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) ~[na:1.8.0_102]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) ~[na:1.8.0_102]
    at java.lang.Thread.run(Thread.java:745) ~[na:1.8.0_102]
Caused by: org.rnorth.ducttape.RetryCountExceededException: Retry limit hit with exception
    at org.rnorth.ducttape.unreliables.Unreliables.retryUntilSuccess(Unreliables.java:83) ~[duct-tape-1.0.6.jar:na]
    at org.testcontainers.containers.GenericContainer.start(GenericContainer.java:170) ~[classes/:na]
    ... 8 common frames omitted
Caused by: org.testcontainers.containers.ContainerLaunchException: Could not create/start container
    at org.testcontainers.containers.GenericContainer.tryStart(GenericContainer.java:243) ~[classes/:na]
    at org.testcontainers.containers.GenericContainer.lambda$start$0(GenericContainer.java:172) ~[classes/:na]
    at org.rnorth.ducttape.unreliables.Unreliables.retryUntilSuccess(Unreliables.java:76) ~[duct-tape-1.0.6.jar:na]
    ... 9 common frames omitted
Caused by: org.testcontainers.containers.ContainerLaunchException: Timed out waiting for container port to open (localhost:32768 should be listening)
    at org.testcontainers.containers.wait.HostPortWaitStrategy.waitUntilReady(HostPortWaitStrategy.java:91) ~[classes/:na]
    at org.testcontainers.containers.GenericContainer$AbstractWaitStrategy.waitUntilReady(GenericContainer.java:882) ~[classes/:na]
    at org.testcontainers.containers.GenericContainer.waitUntilContainerStarted(GenericContainer.java:444) ~[classes/:na]
    at org.testcontainers.containers.GenericContainer.tryStart(GenericContainer.java:222) ~[classes/:na]
    ... 11 common frames omitted
20:31:40.612 DEBUG 🐳 [richnorth/ambassador:latest] - Starting container: richnorth/ambassador:latest
20:31:40.612 DEBUG 🐳 [richnorth/ambassador:latest] - Trying to start container: richnorth/ambassador:latest
20:31:40.613 DEBUG 🐳 [richnorth/ambassador:latest] - Trying to start container: richnorth/ambassador:latest (attempt 1/1)
20:31:40.613 DEBUG 🐳 [richnorth/ambassador:latest] - Starting container: richnorth/ambassador:latest
20:31:40.614 INFO  🐳 [richnorth/ambassador:latest] - Creating container for image: richnorth/ambassador:latest
20:31:41.121 INFO  🐳 [richnorth/ambassador:latest] - Starting container with ID: 6a895261f263cf56c34ab28b712ad16549c65c83156d07420db3b1141baed126
20:31:41.125 INFO  🐳 [richnorth/ambassador:latest] - Running "exec" command: /bin/sh -c nc -vz -w 1 localhost 32768 && echo TESTCONTAINERS_SUCCESS
20:31:41.253 INFO  🐳 [richnorth/ambassador:latest] - Running "exec" command: /bin/bash -c </dev/tcp/localhost/32768 && echo TESTCONTAINERS_SUCCESS
20:31:41.659 INFO  🐳 [richnorth/ambassador:latest] - Running "exec" command: /bin/sh -c nc -vz -w 1 localhost 32769 && echo TESTCONTAINERS_SUCCESS
20:31:41.852 INFO  🐳 [richnorth/ambassador:latest] - Container richnorth/ambassador:latest is starting: 6a895261f263cf56c34ab28b712ad16549c65c83156d07420db3b1141baed126
20:31:41.869 INFO  🐳 [richnorth/ambassador:latest] - Running "exec" command: /bin/bash -c </dev/tcp/localhost/32769 && echo TESTCONTAINERS_SUCCESS
20:31:42.411 INFO  🐳 [richnorth/ambassador:latest] - Running "exec" command: /bin/sh -c nc -vz -w 1 localhost 32768 && echo TESTCONTAINERS_SUCCESS

... snip ...

checkStrategy = () -> {
for (String[] command : commands) {
try {
if (container.execInContainer(command).getStdout().contains(SUCCESS_MARKER)) {
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This will cause a log message to come out at INFO level - might get a bit noisy when the check has to be repeated many times. I'm not quite sure of the best answer really, but maybe we should change the execInContainer method so that it logs at DEBUG instead? What do you think?

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

sounds great! The INFO level is a bit verbose for it. Where should we change it?

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

org/testcontainers/containers/GenericContainer.java:820 would be the place.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I mean, in this PR or as a separate change? :)

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Aha, oops! In this PR is fine I think!

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

changed :)

@rnorth
Copy link
Member

rnorth commented Nov 7, 2016

Ah OK - may have found part of the problem.

final Integer port = getLivenessCheckPort(); is getting the external port number (e.g. 32768+)

            Integer exposedPort = exposedPorts.stream()
                    .map(container::getMappedPort)
                    .filter(port::equals)
                    .findFirst()
                    .orElse(null);

Seems to start off with the internal port numbers, but maps them to the external form before checking quality with port. The net effect seems to be that this ultimately just uses port.

Then the commands:

                     { "/bin/sh", "-c", "nc -vz -w 1 localhost " + exposedPort + " && echo " + SUCCESS_MARKER },
                     { "/bin/bash", "-c", "</dev/tcp/localhost/" + exposedPort + " && echo " + SUCCESS_MARKER }

are picking up the external port number, which is not valid when executed inside the container.

Maybe I've missed something important (!), but it seems to me that commenting out these lines should work:

            Integer exposedPort = exposedPorts.stream()
//                    .map(container::getMappedPort)
//                    .filter(port::equals)
                    .findFirst()
                    .orElse(null);

rnorth added a commit that referenced this pull request Nov 7, 2016
@rnorth
Copy link
Member

rnorth commented Nov 7, 2016

FYI I've put a possible fix on this branch: https://github.com/testcontainers/testcontainers-java/tree/zeroturnaround-160-docker4mac_port_check

If I've completely missed the point please let me know!!!

@bsideup
Copy link
Member Author

bsideup commented Nov 8, 2016

@rnorth see my note on the PR. Yes, ideally, we should use "exposedPorts", BUT. getLivenessCheckPort is protected, it means that user might override id, so we have to do the "reverse engineering" of ports to find it :(

Of course we can ignore it for now and use exposed ports directly

@rnorth
Copy link
Member

rnorth commented Nov 8, 2016

Yeah OK - it's just that container::getMappedPort always converts the internal port number (e.g. 6379 for Redis) to the external (host-relative) port number. For me that's always causing failures, because when executing the shell command port checks inside the container we need to be using the internal port number.

I think I understand how the streams flow maybe should work now... Should it perhaps be this?

For each p in exposedPorts
..If the mappedPort(p) == getLivenessCheckPort()
....Then use p

It's just that right now, it's returning mappedPort(p) rather than p...

@bsideup
Copy link
Member Author

bsideup commented Nov 8, 2016

@rnorth we perform map and then filter(port::equals) to do exactly the same as mappedPort(p) == getLivenessCheckPort() actually :)

@rnorth
Copy link
Member

rnorth commented Nov 8, 2016

But the result of that is that we get mappedPort(p) output, when I think we need p, right?

Basically we need something like inverseMappedPort(getLivenessCheckPort()) don't we? 😀

@bsideup
Copy link
Member Author

bsideup commented Nov 8, 2016

@rnorth actually, you're right. Now is the question - why it passed locally on my machine :D let me take a look :D

@rnorth
Copy link
Member

rnorth commented Nov 8, 2016

Hehe, docker never fails to surprise me! Maybe there's some different port mapping behaviour happening or something...

@bsideup
Copy link
Member Author

bsideup commented Nov 8, 2016

@rnorth fixed :) Sorry, no idea how it happened. Maybe some last minute fix I forgot to test, sorry :)

@rnorth
Copy link
Member

rnorth commented Nov 13, 2016

Great, thanks!

@rnorth rnorth merged commit d1e1978 into testcontainers:master Nov 13, 2016
@bsideup bsideup deleted the 160-docker4mac_port_check branch November 13, 2016 08:30
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

Latest Docker for Mac - apparent change to port forwarding breaks TCP liveness checks
2 participants