palantir/docker-compose-rule

DockerPort.isListeningNow() does not really check container port (should be deprecated/removed)

m4ksio opened this issue · 4 comments

Looks like isListeningNow() always returns true, even if the underlying container port is not open.

docker-compose.yml

version: '2'

services:
  foo:
    image: busybox
    command: sleep 100000
    ports:
      - "11111"

And a simple test:

public class FooTest {

    @ClassRule
    public static DockerComposeRule docker = DockerComposeRule.builder().file("docker-compose.yml")
            .waitingForService("foo", toHaveAllPortsOpen())
            .build();

    @Test
    public void neverRun() {
        fail("Should never run");
    }
}

And in the logs we can clearly see that port 11111 is considered open

10:25:41.706 [main] INFO  c.p.d.c.c.waiting.ClusterWait - Waiting for cluster to be healthy
10:25:41.960 [pool-4-thread-1] TRACE c.p.d.c.e.DefaultDockerCompose - stty: 'standard input': Inappropriate ioctl for device
10:25:41.972 [pool-4-thread-1] TRACE c.p.d.c.e.DefaultDockerCompose -      Name          Command      State            Ports           
10:25:41.972 [pool-4-thread-1] TRACE c.p.d.c.e.DefaultDockerCompose - ----------------------------------------------------------------
10:25:41.972 [pool-4-thread-1] TRACE c.p.d.c.e.DefaultDockerCompose - bbce96e8_foo_1   sleep 100000   Up      0.0.0.0:32867->11111/tcp 
10:25:41.982 [pool-3-thread-1] TRACE c.p.d.compose.connection.DockerPort - External Port '32867' on ip '127.0.0.1' was open
10:25:41.983 [main] DEBUG c.p.docker.compose.DockerComposeRule - docker-compose cluster started
10:25:41.989 [main] DEBUG c.p.d.c.e.GracefulShutdownStrategy - Killing docker-compose cluster
10:25:42.180 [pool-5-thread-1] TRACE c.p.d.c.e.DefaultDockerCompose - Stopping bbce96e8_foo_1 ... 

I assume it's some form of Docker forwarding ports mechanism, but clearly, its misleading.

Docker version 1.12.5, build 7392c3b
docker-compose version 1.7.1, build 0a9ab35

a-k-g commented

I can repro this with Docker for Mac. But using docker-machine on Mac it works as expected and gets stuck at

2017-01-20T13:04:41,251 DEBUG - main com.palantir.docker.compose.execution.DockerComposeExecutable - Using docker-compose found at /usr/local/bin/docker-compose
2017-01-20T13:04:41,254 DEBUG - main com.palantir.docker.compose.execution.DockerExecutable - Using docker found at /usr/local/bin/docker
2017-01-20T13:04:41,267 DEBUG - main com.palantir.docker.compose.DockerComposeRule - Starting docker-compose cluster
2017-01-20T13:04:42,681 DEBUG - main com.palantir.docker.compose.DockerComposeRule - Waiting for services
2017-01-20T13:04:42,682 INFO  - main com.palantir.docker.compose.connection.waiting.ClusterWait - Waiting for cluster to be healthy

Docker for Mac runs a VM, but it wants to appear as though the containers were running locally. So, when you open a port on a container, it opens the port on the VM, and opens the same port on the host.

However, it doesn't do this exactly when the port is opened by the container, but rather, on creation.

Whenever a connection is made to this port, if the port is not opened on the container, it will kill the connection. This is what manifests in the behaviour that you see.

It's usually worth healthchecking via something more concrete - maybe sending an http request or making sure that you can open a Postgres connection, etc.

You'll be able to see this behaviour outside of dcr as well - if you do docker-compose up and:

nc -z localhost 11111

you'll see connection success as well. From the point of view of DCR (and every other app on the host), the port is open!

Yep, this is something we were bitten by in the early stages of writing it. I think a reasonable solution is to remove the isListeningNow helpers as you almost never want to use them.