Search code examples
dockerubuntudocker-composecron

Running "docker-compose run" hangs when it's run in cron


Environments

▶ uname -a
Linux ubuntu 5.4.0-66-generic #74-Ubuntu SMP Wed Jan 27 22:54:38 UTC 2021 x86_64 x86_64 x86_64 GNU/Linux

▶ docker -v
Docker version 20.10.4, build d3cb89e

▶ docker-compose -v
docker-compose version 1.28.4, build cabd5cfb

▶ lsb_release -a
No LSB modules are available.
Distributor ID: Ubuntu
Description: Ubuntu 20.04.2 LTS
Release: 20.04
Codename: focal

Problem

I had been using ubuntu version 18.04 and my docker and docker-compose were running just fine. I didn't periodically update the server, but just 2 days ago, I did sudo apt-get update && apt-get upgrade. Then it all started acting wierd.

I used to call docker-compose services from the host's cron like this.

0 * * * * cd /project/folder && docker-compose run --rm service_name

However, after the update and upgrade, these cron jobs started to hanging.

  • I could see processes dangling when I checked top command
  • I could see the container program (command) was not even starting

So every time the cron jobs tried to call those services, processes were stacking up.

Things I did

I uninstalled docker, docker-compose, reboot and reinstall them again, but it didn't help. I even upgraded the OS from 18.04 to 20.04, and it didn't help either.

https://docs.docker.com/engine/install/ubuntu/#install-using-the-repository
https://docs.docker.com/compose/install/

do-release-upgrade # to upgrade from v18 to v20

To investigate even further, I added --verbose like this and logged it.

0 * * * * cd /project/folder && docker-compose run --rm --verbose service_name >> /project/folder/cron.log 2>&1

It seems it's hanging at /usr/bin/docker start --attach --interactive and nothing really happens.

When I run the same command cd /project/folder && docker-compose run --rm --verbose service_name >> /project/folder/cron.log 2>&1 just from the terminal, it runs as expected.

I made everything simple like below, but running it by cron still hangs in the middle.

Anybody has an idea what is causing this?

docker-compose.yml

services:

  test:
    build:
      context: ./test
    command: ash -c "date"

Dockerfile

FROM alpine:latest

Logs

compose.config.config.find: Using configuration files: ./docker-compose.yml
compose.cli.docker_client.get_client: docker-compose version 1.28.4, build cabd5cfb
docker-py version: 4.4.3
CPython version: 3.7.10
OpenSSL version: OpenSSL 1.1.0l  10 Sep 2019
compose.cli.docker_client.get_client: Docker base_url: http+docker://localhost
compose.cli.docker_client.get_client: Docker version: Platform={'Name': 'Docker Engine - Community'}, Components=[{'Name': 'Engine', 'Version': '20.10.4', 'Details': {'ApiVersion': '1.41', 'Arch': 'amd64', 'BuildTime': '2021-02-25T07:03:23.000000000+00:00', 'Experimental': 'false', 'GitCommit': '363e9a8', 'GoVersion': 'go1.13.15', 'KernelVersion': '5.4.0-66-generic', 'MinAPIVersion': '1.12', 'Os': 'linux'}}, {'Name': 'containerd', 'Version': '1.4.3', 'Details': {'GitCommit': '269548fa27e0089a8b8278fc4fc781d7f65a939b'}}, {'Name': 'runc', 'Version': '1.0.0-rc92', 'Details': {'GitCommit': 'ff819c7e9184c13b7c2607fe6c30ae19403a7aff'}}, {'Name': 'docker-init', 'Version': '0.19.0', 'Details': {'GitCommit': 'de40ad0'}}], Version=20.10.4, ApiVersion=1.41, MinAPIVersion=1.12, GitCommit=363e9a8, GoVersion=go1.13.15, Os=linux, Arch=amd64, KernelVersion=5.4.0-66-generic, BuildTime=2021-02-25T07:03:23.000000000+00:00
compose.cli.verbose_proxy.proxy_callable: docker inspect_network <- ('aaa_default')
compose.cli.verbose_proxy.proxy_callable: docker inspect_network -> {'Attachable': True,
 'ConfigFrom': {'Network': ''},
 'ConfigOnly': False,
 'Containers': {},
 'Created': '2020-07-19T12:11:28.401034027+09:00',
 'Driver': 'bridge',
 'EnableIPv6': False,
 'IPAM': {'Config': [{'Gateway': '192.168.80.1', 'Subnet': '192.168.80.0/20'}],
          'Driver': 'default',
          'Options': None},
...
compose.cli.verbose_proxy.proxy_callable: docker inspect_network <- ('aaa_default')
compose.cli.verbose_proxy.proxy_callable: docker inspect_network -> {'Attachable': True,
 'ConfigFrom': {'Network': ''},
 'ConfigOnly': False,
 'Containers': {},
 'Created': '2020-07-19T12:11:28.401034027+09:00',
 'Driver': 'bridge',
 'EnableIPv6': False,
 'IPAM': {'Config': [{'Gateway': '192.168.80.1', 'Subnet': '192.168.80.0/20'}],
          'Driver': 'default',
          'Options': None},
...
compose.cli.verbose_proxy.proxy_callable: docker containers <- (all=False, filters={'label': ['com.docker.compose.project=aaa', 'com.docker.compose.oneoff=False']})
compose.cli.verbose_proxy.proxy_callable: docker containers -> (list with 0 items)
compose.cli.verbose_proxy.proxy_callable: docker containers <- (all=False, filters={'label': ['com.docker.compose.project=aaa', 'com.docker.compose.oneoff=False']})
compose.cli.verbose_proxy.proxy_callable: docker containers -> (list with 0 items)
compose.cli.verbose_proxy.proxy_callable: docker containers <- (all=True, filters={'label': ['com.docker.compose.project=aaa', 'com.docker.compose.oneoff=False']})
compose.cli.verbose_proxy.proxy_callable: docker containers -> (list with 0 items)
compose.cli.verbose_proxy.proxy_callable: docker containers <- (all=True, filters={'label': ['com.docker.compose.project=aaa', 'com.docker.compose.oneoff=False']})
compose.cli.verbose_proxy.proxy_callable: docker containers -> (list with 0 items)
compose.cli.verbose_proxy.proxy_callable: docker containers <- (all=True, filters={'label': ['com.docker.compose.project=aaa', 'com.docker.compose.service=test', 'com.docker.compose.oneoff=False']})
compose.cli.verbose_proxy.proxy_callable: docker containers -> (list with 0 items)
compose.cli.verbose_proxy.proxy_callable: docker containers <- (all=True, filters={'label': ['com.docker.compose.project=aaa', 'com.docker.compose.service=test', 'com.docker.compose.oneoff=False']})
compose.cli.verbose_proxy.proxy_callable: docker containers -> (list with 0 items)
compose.cli.verbose_proxy.proxy_callable: docker inspect_image <- ('aaa_test')
compose.cli.verbose_proxy.proxy_callable: docker inspect_image -> {'Architecture': 'amd64',
 'Author': '',
 'Comment': '',
 'Config': {'AttachStderr': False,
            'AttachStdin': False,
            'AttachStdout': False,
            'Cmd': ['/bin/sh'],
            'Domainname': '',
            'Entrypoint': None,
            'Env': ['PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin'],
...
compose.cli.verbose_proxy.proxy_callable: docker containers <- (all=True, filters={'label': ['com.docker.compose.project=aaa', 'com.docker.compose.service=test', 'com.docker.compose.oneoff=False']})
compose.cli.verbose_proxy.proxy_callable: docker containers -> (list with 0 items)
compose.cli.verbose_proxy.proxy_callable: docker containers <- (all=True, filters={'label': ['com.docker.compose.project=aaa', 'com.docker.compose.service=test', 'com.docker.compose.oneoff=False']})
compose.cli.verbose_proxy.proxy_callable: docker containers -> (list with 0 items)
compose.parallel.feed_queue: Pending: {<Service: test>}
compose.parallel.feed_queue: Starting producer thread for <Service: test>
compose.cli.verbose_proxy.proxy_callable: docker containers <- (all=True, filters={'label': ['com.docker.compose.project=aaa', 'com.docker.compose.service=test', 'com.docker.compose.oneoff=False']})
compose.cli.verbose_proxy.proxy_callable: docker containers -> (list with 0 items)
compose.cli.verbose_proxy.proxy_callable: docker containers <- (all=True, filters={'label': ['com.docker.compose.project=aaa', 'com.docker.compose.service=test', 'com.docker.compose.oneoff=False']})
compose.cli.verbose_proxy.proxy_callable: docker containers -> (list with 0 items)
Creating aaa_test_run ... 
compose.parallel.feed_queue: Pending: {ServiceName(project='aaa', service='test', number=1)}
compose.parallel.feed_queue: Starting producer thread for ServiceName(project='aaa', service='test', number=1)
compose.cli.verbose_proxy.proxy_callable: docker inspect_image <- ('aaa_test')
compose.cli.verbose_proxy.proxy_callable: docker inspect_image -> {'Architecture': 'amd64',
 'Author': '',
 'Comment': '',
 'Config': {'AttachStderr': False,
            'AttachStdin': False,
            'AttachStdout': False,
            'Cmd': ['/bin/sh'],
            'Domainname': '',
            'Entrypoint': None,
            'Env': ['PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin'],
...
compose.cli.verbose_proxy.proxy_callable: docker containers <- (all=False, filters={'label': ['com.docker.compose.project=aaa', 'com.docker.compose.service=test', 'com.docker.compose.oneoff=False']})
compose.cli.verbose_proxy.proxy_callable: docker containers -> (list with 0 items)
compose.cli.verbose_proxy.proxy_callable: docker containers <- (all=False, filters={'label': ['com.docker.compose.project=aaa', 'com.docker.compose.service=test', 'com.docker.compose.oneoff=False']})
compose.cli.verbose_proxy.proxy_callable: docker containers -> (list with 0 items)
compose.cli.verbose_proxy.proxy_callable: docker create_host_config <- (links=[], port_bindings={}, binds=[], volumes_from=[], privileged=False, network_mode='aaa_default', devices=None, device_requests=None, dns=None, dns_opt=None, dns_search=None, restart_policy=None, runtime=None, cap_add=None, cap_drop=None, mem_limit=None, mem_reservation=None, memswap_limit=None, ulimits=None, log_config={'Type': '', 'Config': {}}, extra_hosts=None, read_only=None, pid_mode=None, security_opt=None, ipc_mode=None, cgroup_parent=None, cpu_quota=None, shm_size=None, sysctls=None, pids_limit=None, tmpfs=None, oom_kill_disable=None, oom_score_adj=None, mem_swappiness=None, group_add=None, userns_mode=None, init=None, init_path=None, isolation=None, cpu_count=None, cpu_percent=None, nano_cpus=None, volume_driver=None, cpuset_cpus=None, cpu_shares=None, storage_opt=None, blkio_weight=None, blkio_weight_device=None, device_read_bps=None, device_read_iops=None, device_write_bps=None, device_write_iops=None, mounts=None, device_cgroup_rules=None, cpu_period=None, cpu_rt_period=None, cpu_rt_runtime=None)
compose.cli.verbose_proxy.proxy_callable: docker create_host_config -> {'Binds': [],
 'Links': [],
 'LogConfig': {'Config': {}, 'Type': ''},
 'NetworkMode': 'aaa_default',
 'PortBindings': {},
 'VolumesFrom': []}
compose.cli.verbose_proxy.proxy_callable: docker create_container <- (command='ash -c "date"', volumes={}, tty=False, stdin_open=True, detach=False, ports=[], name='aaa_test_run_b01e0a8c11e3', environment=[], labels={'com.docker.compose.project': 'aaa', 'com.docker.compose.service': 'test', 'com.docker.compose.oneoff': 'True', 'com.docker.compose.project.working_dir': '/home/ac/projects/playground/aaa', 'com.docker.compose.project.config_files': 'docker-compose.yml', 'com.docker.compose.slug': 'b01e0a8c11e319685038ac27761c14b08d5fa025dee67abab9da546afadc28f', 'com.docker.compose.version': '1.28.4'}, image='aaa_test', host_config={'NetworkMode': 'aaa_default', 'VolumesFrom': [], 'Binds': [], 'PortBindings': {}, 'Links': [], 'LogConfig': {'Type': '', 'Config': {}}}, networking_config={'EndpointsConfig': {'aaa_default': {'Aliases': ['test'], 'IPAMConfig': {}}}})
compose.parallel.feed_queue: Pending: set()
compose.parallel.feed_queue: Pending: set()
compose.cli.verbose_proxy.proxy_callable: docker create_container -> {'Id': 'c743a18406c5ac561f808086b84a8bf867c89f0b07526ca0c60b17fa527d6b1b',
 'Warnings': []}
compose.cli.verbose_proxy.proxy_callable: docker inspect_container <- ('c743a18406c5ac561f808086b84a8bf867c89f0b07526ca0c60b17fa527d6b1b')
compose.cli.verbose_proxy.proxy_callable: docker inspect_container -> {'AppArmorProfile': '',
 'Args': ['-c', 'date'],
 'Config': {'AttachStderr': True,
            'AttachStdin': True,
            'AttachStdout': True,
            'Cmd': ['ash', '-c', 'date'],
            'Domainname': '',
            'Entrypoint': None,
            'Env': ['PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin'],
            'Hostname': 'c743a18406c5',
...
compose.parallel.parallel_execute_iter: Finished processing: ServiceName(project='aaa', service='test', number=1)
Creating aaa_test_run ... done
compose.parallel.feed_queue: Pending: set()
compose.parallel.parallel_execute_iter: Finished processing: <Service: test>
compose.parallel.feed_queue: Pending: set()
compose.cli.verbose_proxy.proxy_callable: docker disconnect_container_from_network <- ('c743a18406c5ac561f808086b84a8bf867c89f0b07526ca0c60b17fa527d6b1b', 'aaa_default')
compose.cli.verbose_proxy.proxy_callable: docker disconnect_container_from_network -> None
compose.cli.verbose_proxy.proxy_callable: docker connect_container_to_network <- ('c743a18406c5ac561f808086b84a8bf867c89f0b07526ca0c60b17fa527d6b1b', 'aaa_default', aliases=[], ipv4_address=None, ipv6_address=None, links=[], link_local_ips=None)
compose.cli.verbose_proxy.proxy_callable: docker connect_container_to_network -> None
compose.cli.main.call_docker: /usr/bin/docker start --attach --interactive c743a18406c5ac561f808086b84a8bf867c89f0b07526ca0c60b17fa527d6b1b

Solution

  • UPDATE: this should be fixed in Docker 20.10.5 so upgrading may be preferable to downgrading!

    If you downgrade to Docker 20.10.3 the issue should be resolved. I believe it is a bug introduced in this version as discussed here: https://github.com/moby/moby/issues/42093

    Nasty issue! Hoping a fix is released soon...

    And if downgrading isn't an option for you, you can try setting the COMPOSE_INTERACTIVE_NO_CLI environment variable (to 1) as discussed here -- e.g. prepend:

    COMPOSE_INTERACTIVE_NO_CLI=1
    

    to your crontab config so that docker-compose tasks launched via cron should bypass this bug as a short-term workaround