compose: All docker-compose (but not docker) commands time out: "An http request took too long to complete."

It needs to be before the subcommand (ie docker-compose --verbose up instead of docker-compose up --verbose)

@su-narthur @shin- I think this was closed too hastily. I’ve been getting this off and on since January of this year. But not on Mac, on Ubuntu. First on 16.04, then on 17.04, 17.10 and now on 18.04 - and my verbose output hangs at the exact same spot as @su-narthur 's, during container inspection.

docker-compose --verbose run playbook -i inventory/global/ playbooks/dev-jasper-reports.yml
compose.config.config.find: Using configuration files: ./docker-compose.yml
docker.utils.config.find_config_file: Trying paths: ['/home/crouth/.docker/config.json', '/home/crouth/.dockercfg']
docker.utils.config.find_config_file: Found file at path: /home/crouth/.docker/config.json
docker.auth.load_config: Found 'auths' section
urllib3.connectionpool._make_request: http://localhost:None "GET /v1.24/version HTTP/1.1" 200 543
compose.cli.command.get_client: docker-compose version 1.21.2, build a133471
docker-py version: 3.3.0
CPython version: 3.6.5
OpenSSL version: OpenSSL 1.0.1t  3 May 2016
compose.cli.command.get_client: Docker base_url: http+docker://localhost
compose.cli.command.get_client: Docker version: Platform={'Name': ''}, Components=[{'Name': 'Engine', 'Version': '18.06.0-ce', 'Details': {'ApiVersion': '1.38', 'Arch': 'amd64', 'BuildTime': '2018-07-18T19:07:56.000000000+00:00', 'Experimental': 'false', 'GitCommit': '0ffa825', 'GoVersion': 'go1.10.3', 'KernelVersion': '4.15.0-30-generic', 'MinAPIVersion': '1.12', 'Os': 'linux'}}], Version=18.06.0-ce, ApiVersion=1.38, MinAPIVersion=1.12, GitCommit=0ffa825, GoVersion=go1.10.3, Os=linux, Arch=amd64, KernelVersion=4.15.0-30-generic, BuildTime=2018-07-18T19:07:56.000000000+00:00
compose.cli.verbose_proxy.proxy_callable: docker inspect_network <- ('jasperreportsservers_default')
urllib3.connectionpool._make_request: http://localhost:None "GET /v1.24/networks/jasperreportsservers_default HTTP/1.1" 404 61
compose.cli.verbose_proxy.proxy_callable: docker inspect_network <- ('jasperreports-servers_default')
urllib3.connectionpool._make_request: http://localhost:None "GET /v1.24/networks/jasperreports-servers_default HTTP/1.1" 200 862
compose.cli.verbose_proxy.proxy_callable: docker inspect_network -> {'Attachable': True,
 'ConfigFrom': {'Network': ''},
 'ConfigOnly': False,
 'Containers': {'35ef0763b3a38a776409ef8d426f9fd1eb71549cb13c4166c638d33b7c77bd34': {'EndpointID': '46aaa4306520341b9d1f3f238ceebca2d1aa9f9b00bf9c2b221fa6313439ebc7',
                                                                                     'IPv4Address': '172.18.0.2/16',
                                                                                     'IPv6Address': '',
                                                                                     'MacAddress': '02:42:ac:12:00:02',
                                                                                     'Name': 'jasperreports-servers_playbook_run_112'}},
 'Created': '2018-06-27T13:27:42.910819198-07:00',
 'Driver': 'bridge',
...
compose.cli.verbose_proxy.proxy_callable: docker inspect_image <- ('dockerhub.alea.ca/docker/ansible')
urllib3.connectionpool._make_request: http://localhost:None "GET /v1.24/images/dockerhub.alea.ca/docker/ansible/json HTTP/1.1" 200 None
compose.cli.verbose_proxy.proxy_callable: docker inspect_image -> {'Architecture': 'amd64',
 'Author': '',
 'Comment': '',
 'Config': {'ArgsEscaped': True,
            'AttachStderr': False,
            'AttachStdin': False,
            'AttachStdout': False,
            'Cmd': None,
            'Domainname': '',
            'Entrypoint': ['ansible-playbook'],
...
compose.cli.verbose_proxy.proxy_callable: docker containers <- (all=True, filters={'label': ['com.docker.compose.project=jasperreports-servers', 'com.docker.compose.service=playbook', 'com.docker.compose.oneoff=True']})
urllib3.connectionpool._make_request: http://localhost:None "GET /v1.24/containers/json?limit=-1&all=1&size=0&trunc_cmd=0&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Djasperreports-servers%22%2C+%22com.docker.compose.service%3Dplaybook%22%2C+%22com.docker.compose.oneoff%3DTrue%22%5D%7D HTTP/1.1" 200 None
compose.cli.verbose_proxy.proxy_callable: docker containers -> (list with 112 items)
compose.cli.verbose_proxy.proxy_callable: docker inspect_container <- ('35ef0763b3a38a776409ef8d426f9fd1eb71549cb13c4166c638d33b7c77bd34')
ERROR: compose.cli.errors.log_timeout_error: An HTTP request took too long to complete. Retry with --verbose to obtain debug information.
If you encounter this issue regularly because of slow network conditions, consider setting COMPOSE_HTTP_TIMEOUT to a higher value (current value: 60).

In case anyone else faces this : restarting docker for mac resolved this for me.

@Anushkasharma Yes, restarting Docker for Mac does resolve it temporarily, but that can really slow you down if you have containers that take a while to start up.

@shin- Same as when there isn’t an issue and you add the --verbose argument–it gives you the command’s usage since docker-compose commands don’t seem to support that argument.

Hey folks, sorry for the late follow-up. Given that the docker container inspect command hangs identically, all signs point to this being an engine issue. I see that a report has been made here https://github.com/docker/for-linux/issues/397 (thanks @Routhinator ), which people should follow and contribute to in order to see it resolved.

I’m going to close this again as this is not a Compose issue.

By simply restarting the docker service via sudo service docker restart I was able to get the aforementioned error to go away when running docker-compose up.

Note: I did not touch the tty=true parameter as suggested, as I wanted to avoid a quick fix.

@su-narthur Sounds like this is an issue with Docker For Mac in this case. Do you mind creating an issue on the docker/for-mac repo with the information you provided here? It might be worth running another diagnostic with the latest info as well.

@su-narthur Thanks! If you run docker container inspect 6c927f8d3ce359352f193a0d85b7bafc8d9a2ab3f83fd590e2617c6c010a65bd, do you see any lag / slowdown or error show up?

@shin- Ok, it happened again, and here is the verbose version:

$ docker-compose --verbose logs
compose.config.config.find: Using configuration files: ./docker-compose.yml
docker.auth.find_config_file: Trying paths: ['/Users/narthur/.docker/config.json', '/Users/narthur/.dockercfg']
docker.auth.find_config_file: Found file at path: /Users/narthur/.docker/config.json
docker.auth.load_config: Couldn't find 'auths' or 'HttpHeaders' sections
docker.auth.parse_auth: Auth data for {0} is absent. Client might be using a credentials store instead.
urllib3.connectionpool._make_request: http://localhost:None "GET /v1.25/version HTTP/1.1" 200 566
compose.cli.command.get_client: docker-compose version 1.18.0, build 8dd22a9
docker-py version: 2.6.1
CPython version: 2.7.12
OpenSSL version: OpenSSL 1.0.2j  26 Sep 2016
compose.cli.command.get_client: Docker base_url: http+docker://localunixsocket
compose.cli.command.get_client: Docker version: KernelVersion=4.9.60-linuxkit-aufs, Components=[{u'Version': u'17.12.0-ce', u'Name': u'Engine', u'Details': {u'KernelVersion': u'4.9.60-linuxkit-aufs', u'Os': u'linux', u'BuildTime': u'2017-12-27T20:12:29.000000000+00:00', u'ApiVersion': u'1.35', u'MinAPIVersion': u'1.12', u'GitCommit': u'c97c6d6', u'Arch': u'amd64', u'Experimental': u'true', u'GoVersion': u'go1.9.2'}}], Arch=amd64, BuildTime=2017-12-27T20:12:29.000000000+00:00, ApiVersion=1.35, Platform={u'Name': u''}, Version=17.12.0-ce, MinAPIVersion=1.12, GitCommit=c97c6d6, Os=linux, Experimental=True, GoVersion=go1.9.2
compose.cli.verbose_proxy.proxy_callable: docker containers <- (all=True, filters={u'label': [u'com.docker.compose.project=sudocker', u'com.docker.compose.oneoff=False']})
urllib3.connectionpool._make_request: http://localhost:None "GET /v1.25/containers/json?all=1&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dsudocker%22%2C+%22com.docker.compose.oneoff%3DFalse%22%5D%7D&trunc_cmd=0&size=0 HTTP/1.1" 200 4338
compose.cli.verbose_proxy.proxy_callable: docker containers -> (list with 3 items)
compose.cli.verbose_proxy.proxy_callable: docker inspect_container <- (u'6c927f8d3ce359352f193a0d85b7bafc8d9a2ab3f83fd590e2617c6c010a65bd')
ERROR: compose.cli.errors.log_timeout_error: An HTTP request took too long to complete. Retry with --verbose to obtain debug information.
If you encounter this issue regularly because of slow network conditions, consider setting COMPOSE_HTTP_TIMEOUT to a higher value (current value: 60).

Retry with --verbose to obtain debug information.

Did you do this? If so, can you share the output?