Closed nocive closed 7 months ago
perhaps also a symptom of https://github.com/compose-spec/compose-go/pull/557 and a corrupted project config?
same problem persists on 2.24.6 :man_shrugging: can someone have a look here? :wave:
FWIW I'm seeing the same behavior with v2.24.3-desktop.1 and v2.24.6 on an Apple M2 laptop
Docker Compose version v2.24.6
Client:
Cloud integration: v1.0.35+desktop.10
Version: 25.0.2
API version: 1.44
Go version: go1.21.6
Git commit: 29cf629
Built: Thu Feb 1 00:18:45 2024
OS/Arch: darwin/arm64
Context: desktop-linux
Server: Docker Desktop 4.27.1 (136059)
Engine:
Version: 25.0.2
API version: 1.44 (minimum version 1.24)
Go version: go1.21.6
Git commit: fce6e0c
Built: Thu Feb 1 00:23:21 2024
OS/Arch: linux/arm64
Experimental: false
containerd:
Version: 1.6.28
GitCommit: ae07eda36dd25f8a1b98dfbf587313b99c0190bb
runc:
Version: 1.1.12
GitCommit: v1.1.12-0-g51d5e94
docker-init:
Version: 0.19.0
GitCommit: de40ad0
This is reproducible with a simple compose.yaml and any docker compose sub-command. The following docker compose config
took 8 seconds. The interesting thing is that it seems to be sleeping or doing whatever it is up to after the output is printed.
$ time docker compose config
name: asdf
services:
nginx:
image: nginx:1.24-alpine
networks:
default: null
ports:
- mode: ingress
target: 80
protocol: tcp
networks:
default:
name: asdf_default
docker compose config 0.08s user 0.03s system 5% cpu 2.106 total
ping @glours @ndeloof
I went a step further in trying to figure this out because having docker compose ps
take ~10s is killing me. I found that ~/.docker/cli-plugins/docker-compose
is considerably faster than ~/.docker/bin/docker-compose
. I have a feeling that the docker command-line is finding the one in ~/.docker/bin
๐คจ
% time (docker compose config>/dev/null)
0.08s user 0.07s system 6% cpu 2.284 total
% time (~/.docker/bin/docker-compose config>/dev/null)
0.08s user 0.07s system 6% cpu 2.276 total
% time (~/.docker/cli-plugins/docker-compose config>/dev/null)
0.03s user 0.01s system 93% cpu 0.048 total
Hopefully this will help narrow down where the problem is.
Hey @nocive @dave-shawley
Can both of you share the result of docker compose version
? I wanted to be sure you don't have a old version of Compose taking precedence to the latest one installed because docker info
tell you the version of the detected Compose plugin but there is not guarantee this is the Compose binary that will be used.
To let you know, I tried to reproduce on my Mac M1 with Desktop in both admin/non-admin mode and with an Unbuntu 23.10 VM without any success
@glours I can confirm the correct version is being used:
$ docker compose version
Docker Compose version v2.24.6
$ ~/.docker/cli-plugins/docker-compose version
Docker Compose version v2.24.6
When stracing the plugin process I see a lot (thousands) of:
rt_sigreturn({mask=[]}) = 1
--- SIGURG {si_signo=SIGURG, si_code=SI_TKILL, si_pid=628483, si_uid=1000} ---
rt_sigreturn({mask=[]}) = 1
--- SIGURG {si_signo=SIGURG, si_code=SI_TKILL, si_pid=628483, si_uid=1000} ---
rt_sigreturn({mask=[]}) = 1
--- SIGURG {si_signo=SIGURG, si_code=SI_TKILL, si_pid=628483, si_uid=1000} ---
rt_sigreturn({mask=[]}) = 1
--- SIGURG {si_signo=SIGURG, si_code=SI_TKILL, si_pid=628483, si_uid=1000} ---
rt_sigreturn({mask=[]}) = 1
--- SIGURG {si_signo=SIGURG, si_code=SI_TKILL, si_pid=628483, si_uid=1000} ---
rt_sigreturn({mask=[]}) = 1
--- SIGURG {si_signo=SIGURG, si_code=SI_TKILL, si_pid=628483, si_uid=1000} ---
rt_sigreturn({mask=[]}) = 1
--- SIGURG {si_signo=SIGURG, si_code=SI_TKILL, si_pid=628483, si_uid=1000} ---
rt_sigreturn({mask=[]}) = 1
--- SIGURG {si_signo=SIGURG, si_code=SI_TKILL, si_pid=628483, si_uid=1000} ---
rt_sigreturn({mask=[]}) = 1
--- SIGURG {si_signo=SIGURG, si_code=SI_TKILL, si_pid=628483, si_uid=1000} ---
rt_sigreturn({mask=[]}) = 1
... where a lot of time seems to be spent, and which I don't see in versions <=2.24.3.
I reverted back to my installed version since I was seeing the same behavior in v2.24.6
% docker compose version
Docker Compose version v2.24.3-desktop.1
% ~/.docker/cli-plugins/docker-compose version
Docker Compose version v2.24.3-desktop.1
% ~/.docker/bin/docker-compose version
Docker Compose version v2.24.3-desktop.1
I upgraded to Docker Desktop v4.27.2 this morning which bumped compose to 2.24.5 and the behavior is unchanged.
% docker compose version
Docker Compose version v2.24.5-desktop.1
% ~/.docker/bin/docker-compose version
Docker Compose version v2.24.5-desktop.1
@nocive you're on linux? No Docker Desktop for Linux installed? Can you try this Compose binary and let me know if you see a difference
@glours yes, I'm on arch running docker & docker-buildx pkgs + docker compose installed from the releases of this repo :penguin:
I gave your binary a run and... it became even slower than before :) Now I see a consistent delay of ~12s instead of ~8s :crying_cat_face:
@nocive strange ๐ค
Can you try to use a sample from the awesome-compose or a very simple compose project with only few services, and re-run the docker compose ps
from the sample directory, I just want to check if the performance issues aren't coming from the new version of compose-go
Can you also try this binary?
@glours sorry for the radio silence, I was pulled away to other work related things :)
Didn't have time to isolate this in a simpler project BUT...
...managed to narrow it down a bit further to the usage of COMPOSE_FILE
env var with 2 compose files, ie:
COMPOSE_FILE=/home/my/workspace/docker-compose.yml:/home/my/workspace/src/code.repo/docker-compose.workspace.yml
When this variable is not set the ps
command (or any other for that matter) performs as I'd expect, otherwise I see the added ~8-12s delay until output is produced.
$ time COMPOSE_FILE=/home/my/workspace/docker-compose.yml:/home/my/workspace/src/code.repo/docker-compose.workspace.yml docker compose ps
(...)
real 0m12.304s
user 0m19.030s
sys 0m0.422s
$ time docker compose ps
(...)
real 0m0.169s
user 0m0.183s
sys 0m0.057s
Does this help paint a better picture? Otherwise I'll try to dig deeper and isolate it with an example project, once time permits.
Possible related/duplicate: https://github.com/docker/compose/issues/11305
In the meantime I've also upgraded to docker 25.0.2 but that made no difference.
More strace findings:
$ (source .envrc; strace docker compose ps)
execve("/usr/bin/docker", ["docker", "compose", "ps"], 0x7ffd23d54a40 /* 82 vars */) = 0
brk(NULL) = 0x563917515000
access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=177219, ...}) = 0
mmap(NULL, 177219, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f9bc818a000
close(3) = 0
openat(AT_FDCWD, "/usr/lib/libc.so.6", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\3\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\220\236\2\0\0\0\0\0"..., 832) = 832
pread64(3, "\6\0\0\0\4\0\0\0@\0\0\0\0\0\0\0@\0\0\0\0\0\0\0@\0\0\0\0\0\0\0"..., 784, 64) = 784
fstat(3, {st_mode=S_IFREG|0755, st_size=1965296, ...}) = 0
mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f9bc8188000
pread64(3, "\6\0\0\0\4\0\0\0@\0\0\0\0\0\0\0@\0\0\0\0\0\0\0@\0\0\0\0\0\0\0"..., 784, 64) = 784
mmap(NULL, 1989488, PROT_READ, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f9bc7fa2000
mmap(0x7f9bc7fca000, 1421312, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x28000) = 0x7f9bc7fca000
mmap(0x7f9bc8125000, 348160, PROT_READ, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x183000) = 0x7f9bc8125000
mmap(0x7f9bc817a000, 24576, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x1d7000) = 0x7f9bc817a000
mmap(0x7f9bc8180000, 31600, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f9bc8180000
close(3) = 0
mmap(NULL, 12288, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f9bc7f9f000
arch_prctl(ARCH_SET_FS, 0x7f9bc7f9f740) = 0
set_tid_address(0x7f9bc7f9fa10) = 63121
set_robust_list(0x7f9bc7f9fa20, 24) = 0
rseq(0x7f9bc7fa0060, 0x20, 0, 0x53053053) = 0
mprotect(0x7f9bc817a000, 16384, PROT_READ) = 0
mprotect(0x563915977000, 10625024, PROT_READ) = 0
mprotect(0x7f9bc81e9000, 8192, PROT_READ) = 0
prlimit64(0, RLIMIT_STACK, NULL, {rlim_cur=8192*1024, rlim_max=RLIM64_INFINITY}) = 0
munmap(0x7f9bc818a000, 177219) = 0
getrandom("\xc4\x69\x5d\x9a\x9c\x21\x69\x44", 8, GRND_NONBLOCK) = 8
brk(NULL) = 0x563917515000
brk(0x563917536000) = 0x563917536000
openat(AT_FDCWD, "/proc/self/maps", O_RDONLY|O_CLOEXEC) = 3
prlimit64(0, RLIMIT_STACK, NULL, {rlim_cur=8192*1024, rlim_max=RLIM64_INFINITY}) = 0
fstat(3, {st_mode=S_IFREG|0444, st_size=0, ...}) = 0
read(3, "563914cda000-563914ce5000 r--p 0"..., 1024) = 1024
read(3, "1db000 00:18 130981267 "..., 1024) = 948
close(3) = 0
sched_getaffinity(63121, 32, [0 1 2 3 4 5 6 7 8 9 10 11]) = 8
sched_getaffinity(0, 8192, [0 1 2 3 4 5 6 7 8 9 10 11]) = 8
openat(AT_FDCWD, "/sys/kernel/mm/transparent_hugepage/hpage_pmd_size", O_RDONLY) = 3
read(3, "2097152\n", 20) = 8
close(3) = 0
mmap(NULL, 262144, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f9bc7f5f000
mmap(NULL, 131072, PROT_NONE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f9bc8196000
mmap(NULL, 1048576, PROT_NONE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f9bc7e5f000
mmap(NULL, 8388608, PROT_NONE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f9bc765f000
mmap(NULL, 67108864, PROT_NONE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f9bc365f000
mmap(NULL, 536870912, PROT_NONE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f9ba365f000
mmap(NULL, 536870912, PROT_NONE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f9b8365f000
mmap(0xc000000000, 67108864, PROT_NONE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xc000000000
mmap(NULL, 33554432, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f9b8165f000
madvise(0x7f9b8165f000, 33554432, MADV_NOHUGEPAGE) = 0
mmap(NULL, 68624, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f9b8164e000
mmap(0xc000000000, 4194304, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xc000000000
mmap(0x7f9bc8196000, 131072, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f9bc8196000
mmap(0x7f9bc7edf000, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f9bc7edf000
mmap(0x7f9bc7a65000, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f9bc7a65000
mmap(0x7f9bc568f000, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f9bc568f000
mmap(0x7f9bb37df000, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f9bb37df000
mmap(0x7f9b937df000, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f9b937df000
mmap(NULL, 1048576, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f9b8154e000
madvise(0x7f9b8154e000, 1048576, MADV_NOHUGEPAGE) = 0
mmap(NULL, 65536, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f9b8153e000
mmap(NULL, 65536, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f9b8152e000
rt_sigprocmask(SIG_SETMASK, NULL, [], 8) = 0
fcntl(0, F_GETFD) = 0
fcntl(1, F_GETFD) = 0
fcntl(2, F_GETFD) = 0
sigaltstack(NULL, {ss_sp=NULL, ss_flags=SS_DISABLE, ss_size=0}) = 0
sigaltstack({ss_sp=0xc000008000, ss_flags=0, ss_size=32768}, NULL) = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
gettid() = 63121
rt_sigaction(SIGHUP, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGHUP, {sa_handler=0x563914d59d80, sa_mask=~[RTMIN RT_1], sa_flags=SA_RESTORER|SA_ONSTACK|SA_RESTART|SA_SIGINFO, sa_restorer=0x7f9bc7fe2770}, NULL, 8) = 0
rt_sigaction(SIGINT, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGINT, {sa_handler=0x563914d59d80, sa_mask=~[RTMIN RT_1], sa_flags=SA_RESTORER|SA_ONSTACK|SA_RESTART|SA_SIGINFO, sa_restorer=0x7f9bc7fe2770}, NULL, 8) = 0
rt_sigaction(SIGQUIT, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGQUIT, {sa_handler=0x563914d59d80, sa_mask=~[RTMIN RT_1], sa_flags=SA_RESTORER|SA_ONSTACK|SA_RESTART|SA_SIGINFO, sa_restorer=0x7f9bc7fe2770}, NULL, 8) = 0
rt_sigaction(SIGILL, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGILL, {sa_handler=0x563914d59d80, sa_mask=~[RTMIN RT_1], sa_flags=SA_RESTORER|SA_ONSTACK|SA_RESTART|SA_SIGINFO, sa_restorer=0x7f9bc7fe2770}, NULL, 8) = 0
rt_sigaction(SIGTRAP, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGTRAP, {sa_handler=0x563914d59d80, sa_mask=~[RTMIN RT_1], sa_flags=SA_RESTORER|SA_ONSTACK|SA_RESTART|SA_SIGINFO, sa_restorer=0x7f9bc7fe2770}, NULL, 8) = 0
rt_sigaction(SIGABRT, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGABRT, {sa_handler=0x563914d59d80, sa_mask=~[RTMIN RT_1], sa_flags=SA_RESTORER|SA_ONSTACK|SA_RESTART|SA_SIGINFO, sa_restorer=0x7f9bc7fe2770}, NULL, 8) = 0
rt_sigaction(SIGBUS, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGBUS, {sa_handler=0x563914d59d80, sa_mask=~[RTMIN RT_1], sa_flags=SA_RESTORER|SA_ONSTACK|SA_RESTART|SA_SIGINFO, sa_restorer=0x7f9bc7fe2770}, NULL, 8) = 0
rt_sigaction(SIGFPE, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGFPE, {sa_handler=0x563914d59d80, sa_mask=~[RTMIN RT_1], sa_flags=SA_RESTORER|SA_ONSTACK|SA_RESTART|SA_SIGINFO, sa_restorer=0x7f9bc7fe2770}, NULL, 8) = 0
rt_sigaction(SIGUSR1, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGUSR1, {sa_handler=0x563914d59d80, sa_mask=~[RTMIN RT_1], sa_flags=SA_RESTORER|SA_ONSTACK|SA_RESTART|SA_SIGINFO, sa_restorer=0x7f9bc7fe2770}, NULL, 8) = 0
rt_sigaction(SIGSEGV, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGSEGV, {sa_handler=0x563914d59d80, sa_mask=~[RTMIN RT_1], sa_flags=SA_RESTORER|SA_ONSTACK|SA_RESTART|SA_SIGINFO, sa_restorer=0x7f9bc7fe2770}, NULL, 8) = 0
rt_sigaction(SIGUSR2, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGUSR2, {sa_handler=0x563914d59d80, sa_mask=~[RTMIN RT_1], sa_flags=SA_RESTORER|SA_ONSTACK|SA_RESTART|SA_SIGINFO, sa_restorer=0x7f9bc7fe2770}, NULL, 8) = 0
rt_sigaction(SIGPIPE, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGPIPE, {sa_handler=0x563914d59d80, sa_mask=~[RTMIN RT_1], sa_flags=SA_RESTORER|SA_ONSTACK|SA_RESTART|SA_SIGINFO, sa_restorer=0x7f9bc7fe2770}, NULL, 8) = 0
rt_sigaction(SIGALRM, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGALRM, {sa_handler=0x563914d59d80, sa_mask=~[RTMIN RT_1], sa_flags=SA_RESTORER|SA_ONSTACK|SA_RESTART|SA_SIGINFO, sa_restorer=0x7f9bc7fe2770}, NULL, 8) = 0
rt_sigaction(SIGTERM, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGTERM, {sa_handler=0x563914d59d80, sa_mask=~[RTMIN RT_1], sa_flags=SA_RESTORER|SA_ONSTACK|SA_RESTART|SA_SIGINFO, sa_restorer=0x7f9bc7fe2770}, NULL, 8) = 0
rt_sigaction(SIGSTKFLT, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGSTKFLT, {sa_handler=0x563914d59d80, sa_mask=~[RTMIN RT_1], sa_flags=SA_RESTORER|SA_ONSTACK|SA_RESTART|SA_SIGINFO, sa_restorer=0x7f9bc7fe2770}, NULL, 8) = 0
rt_sigaction(SIGCHLD, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGCHLD, {sa_handler=0x563914d59d80, sa_mask=~[RTMIN RT_1], sa_flags=SA_RESTORER|SA_ONSTACK|SA_RESTART|SA_SIGINFO, sa_restorer=0x7f9bc7fe2770}, NULL, 8) = 0
rt_sigaction(SIGURG, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGURG, {sa_handler=0x563914d59d80, sa_mask=~[RTMIN RT_1], sa_flags=SA_RESTORER|SA_ONSTACK|SA_RESTART|SA_SIGINFO, sa_restorer=0x7f9bc7fe2770}, NULL, 8) = 0
rt_sigaction(SIGXCPU, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGXCPU, {sa_handler=0x563914d59d80, sa_mask=~[RTMIN RT_1], sa_flags=SA_RESTORER|SA_ONSTACK|SA_RESTART|SA_SIGINFO, sa_restorer=0x7f9bc7fe2770}, NULL, 8) = 0
rt_sigaction(SIGXFSZ, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGXFSZ, {sa_handler=0x563914d59d80, sa_mask=~[RTMIN RT_1], sa_flags=SA_RESTORER|SA_ONSTACK|SA_RESTART|SA_SIGINFO, sa_restorer=0x7f9bc7fe2770}, NULL, 8) = 0
rt_sigaction(SIGVTALRM, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGVTALRM, {sa_handler=0x563914d59d80, sa_mask=~[RTMIN RT_1], sa_flags=SA_RESTORER|SA_ONSTACK|SA_RESTART|SA_SIGINFO, sa_restorer=0x7f9bc7fe2770}, NULL, 8) = 0
rt_sigaction(SIGPROF, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGPROF, {sa_handler=0x563914d59d80, sa_mask=~[RTMIN RT_1], sa_flags=SA_RESTORER|SA_ONSTACK|SA_RESTART|SA_SIGINFO, sa_restorer=0x7f9bc7fe2770}, NULL, 8) = 0
rt_sigaction(SIGWINCH, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGWINCH, {sa_handler=0x563914d59d80, sa_mask=~[RTMIN RT_1], sa_flags=SA_RESTORER|SA_ONSTACK|SA_RESTART|SA_SIGINFO, sa_restorer=0x7f9bc7fe2770}, NULL, 8) = 0
rt_sigaction(SIGIO, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGIO, {sa_handler=0x563914d59d80, sa_mask=~[RTMIN RT_1], sa_flags=SA_RESTORER|SA_ONSTACK|SA_RESTART|SA_SIGINFO, sa_restorer=0x7f9bc7fe2770}, NULL, 8) = 0
rt_sigaction(SIGPWR, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGPWR, {sa_handler=0x563914d59d80, sa_mask=~[RTMIN RT_1], sa_flags=SA_RESTORER|SA_ONSTACK|SA_RESTART|SA_SIGINFO, sa_restorer=0x7f9bc7fe2770}, NULL, 8) = 0
rt_sigaction(SIGSYS, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGSYS, {sa_handler=0x563914d59d80, sa_mask=~[RTMIN RT_1], sa_flags=SA_RESTORER|SA_ONSTACK|SA_RESTART|SA_SIGINFO, sa_restorer=0x7f9bc7fe2770}, NULL, 8) = 0
rt_sigaction(SIGRTMIN, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_1, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_2, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_3, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_3, {sa_handler=0x563914d59d80, sa_mask=~[RTMIN RT_1], sa_flags=SA_RESTORER|SA_ONSTACK|SA_RESTART|SA_SIGINFO, sa_restorer=0x7f9bc7fe2770}, NULL, 8) = 0
rt_sigaction(SIGRT_4, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_4, {sa_handler=0x563914d59d80, sa_mask=~[RTMIN RT_1], sa_flags=SA_RESTORER|SA_ONSTACK|SA_RESTART|SA_SIGINFO, sa_restorer=0x7f9bc7fe2770}, NULL, 8) = 0
rt_sigaction(SIGRT_5, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_5, {sa_handler=0x563914d59d80, sa_mask=~[RTMIN RT_1], sa_flags=SA_RESTORER|SA_ONSTACK|SA_RESTART|SA_SIGINFO, sa_restorer=0x7f9bc7fe2770}, NULL, 8) = 0
rt_sigaction(SIGRT_6, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_6, {sa_handler=0x563914d59d80, sa_mask=~[RTMIN RT_1], sa_flags=SA_RESTORER|SA_ONSTACK|SA_RESTART|SA_SIGINFO, sa_restorer=0x7f9bc7fe2770}, NULL, 8) = 0
rt_sigaction(SIGRT_7, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_7, {sa_handler=0x563914d59d80, sa_mask=~[RTMIN RT_1], sa_flags=SA_RESTORER|SA_ONSTACK|SA_RESTART|SA_SIGINFO, sa_restorer=0x7f9bc7fe2770}, NULL, 8) = 0
rt_sigaction(SIGRT_8, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_8, {sa_handler=0x563914d59d80, sa_mask=~[RTMIN RT_1], sa_flags=SA_RESTORER|SA_ONSTACK|SA_RESTART|SA_SIGINFO, sa_restorer=0x7f9bc7fe2770}, NULL, 8) = 0
rt_sigaction(SIGRT_9, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_9, {sa_handler=0x563914d59d80, sa_mask=~[RTMIN RT_1], sa_flags=SA_RESTORER|SA_ONSTACK|SA_RESTART|SA_SIGINFO, sa_restorer=0x7f9bc7fe2770}, NULL, 8) = 0
rt_sigaction(SIGRT_10, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_10, {sa_handler=0x563914d59d80, sa_mask=~[RTMIN RT_1], sa_flags=SA_RESTORER|SA_ONSTACK|SA_RESTART|SA_SIGINFO, sa_restorer=0x7f9bc7fe2770}, NULL, 8) = 0
rt_sigaction(SIGRT_11, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_11, {sa_handler=0x563914d59d80, sa_mask=~[RTMIN RT_1], sa_flags=SA_RESTORER|SA_ONSTACK|SA_RESTART|SA_SIGINFO, sa_restorer=0x7f9bc7fe2770}, NULL, 8) = 0
rt_sigaction(SIGRT_12, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_12, {sa_handler=0x563914d59d80, sa_mask=~[RTMIN RT_1], sa_flags=SA_RESTORER|SA_ONSTACK|SA_RESTART|SA_SIGINFO, sa_restorer=0x7f9bc7fe2770}, NULL, 8) = 0
rt_sigaction(SIGRT_13, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_13, {sa_handler=0x563914d59d80, sa_mask=~[RTMIN RT_1], sa_flags=SA_RESTORER|SA_ONSTACK|SA_RESTART|SA_SIGINFO, sa_restorer=0x7f9bc7fe2770}, NULL, 8) = 0
rt_sigaction(SIGRT_14, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_14, {sa_handler=0x563914d59d80, sa_mask=~[RTMIN RT_1], sa_flags=SA_RESTORER|SA_ONSTACK|SA_RESTART|SA_SIGINFO, sa_restorer=0x7f9bc7fe2770}, NULL, 8) = 0
rt_sigaction(SIGRT_15, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_15, {sa_handler=0x563914d59d80, sa_mask=~[RTMIN RT_1], sa_flags=SA_RESTORER|SA_ONSTACK|SA_RESTART|SA_SIGINFO, sa_restorer=0x7f9bc7fe2770}, NULL, 8) = 0
rt_sigaction(SIGRT_16, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_16, {sa_handler=0x563914d59d80, sa_mask=~[RTMIN RT_1], sa_flags=SA_RESTORER|SA_ONSTACK|SA_RESTART|SA_SIGINFO, sa_restorer=0x7f9bc7fe2770}, NULL, 8) = 0
rt_sigaction(SIGRT_17, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_17, {sa_handler=0x563914d59d80, sa_mask=~[RTMIN RT_1], sa_flags=SA_RESTORER|SA_ONSTACK|SA_RESTART|SA_SIGINFO, sa_restorer=0x7f9bc7fe2770}, NULL, 8) = 0
rt_sigaction(SIGRT_18, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_18, {sa_handler=0x563914d59d80, sa_mask=~[RTMIN RT_1], sa_flags=SA_RESTORER|SA_ONSTACK|SA_RESTART|SA_SIGINFO, sa_restorer=0x7f9bc7fe2770}, NULL, 8) = 0
rt_sigaction(SIGRT_19, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_19, {sa_handler=0x563914d59d80, sa_mask=~[RTMIN RT_1], sa_flags=SA_RESTORER|SA_ONSTACK|SA_RESTART|SA_SIGINFO, sa_restorer=0x7f9bc7fe2770}, NULL, 8) = 0
rt_sigaction(SIGRT_20, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_20, {sa_handler=0x563914d59d80, sa_mask=~[RTMIN RT_1], sa_flags=SA_RESTORER|SA_ONSTACK|SA_RESTART|SA_SIGINFO, sa_restorer=0x7f9bc7fe2770}, NULL, 8) = 0
rt_sigaction(SIGRT_21, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_21, {sa_handler=0x563914d59d80, sa_mask=~[RTMIN RT_1], sa_flags=SA_RESTORER|SA_ONSTACK|SA_RESTART|SA_SIGINFO, sa_restorer=0x7f9bc7fe2770}, NULL, 8) = 0
rt_sigaction(SIGRT_22, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_22, {sa_handler=0x563914d59d80, sa_mask=~[RTMIN RT_1], sa_flags=SA_RESTORER|SA_ONSTACK|SA_RESTART|SA_SIGINFO, sa_restorer=0x7f9bc7fe2770}, NULL, 8) = 0
rt_sigaction(SIGRT_23, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_23, {sa_handler=0x563914d59d80, sa_mask=~[RTMIN RT_1], sa_flags=SA_RESTORER|SA_ONSTACK|SA_RESTART|SA_SIGINFO, sa_restorer=0x7f9bc7fe2770}, NULL, 8) = 0
rt_sigaction(SIGRT_24, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_24, {sa_handler=0x563914d59d80, sa_mask=~[RTMIN RT_1], sa_flags=SA_RESTORER|SA_ONSTACK|SA_RESTART|SA_SIGINFO, sa_restorer=0x7f9bc7fe2770}, NULL, 8) = 0
rt_sigaction(SIGRT_25, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_25, {sa_handler=0x563914d59d80, sa_mask=~[RTMIN RT_1], sa_flags=SA_RESTORER|SA_ONSTACK|SA_RESTART|SA_SIGINFO, sa_restorer=0x7f9bc7fe2770}, NULL, 8) = 0
rt_sigaction(SIGRT_26, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_26, {sa_handler=0x563914d59d80, sa_mask=~[RTMIN RT_1], sa_flags=SA_RESTORER|SA_ONSTACK|SA_RESTART|SA_SIGINFO, sa_restorer=0x7f9bc7fe2770}, NULL, 8) = 0
rt_sigaction(SIGRT_27, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_27, {sa_handler=0x563914d59d80, sa_mask=~[RTMIN RT_1], sa_flags=SA_RESTORER|SA_ONSTACK|SA_RESTART|SA_SIGINFO, sa_restorer=0x7f9bc7fe2770}, NULL, 8) = 0
rt_sigaction(SIGRT_28, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_28, {sa_handler=0x563914d59d80, sa_mask=~[RTMIN RT_1], sa_flags=SA_RESTORER|SA_ONSTACK|SA_RESTART|SA_SIGINFO, sa_restorer=0x7f9bc7fe2770}, NULL, 8) = 0
rt_sigaction(SIGRT_29, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_29, {sa_handler=0x563914d59d80, sa_mask=~[RTMIN RT_1], sa_flags=SA_RESTORER|SA_ONSTACK|SA_RESTART|SA_SIGINFO, sa_restorer=0x7f9bc7fe2770}, NULL, 8) = 0
rt_sigaction(SIGRT_30, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_30, {sa_handler=0x563914d59d80, sa_mask=~[RTMIN RT_1], sa_flags=SA_RESTORER|SA_ONSTACK|SA_RESTART|SA_SIGINFO, sa_restorer=0x7f9bc7fe2770}, NULL, 8) = 0
rt_sigaction(SIGRT_31, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_31, {sa_handler=0x563914d59d80, sa_mask=~[RTMIN RT_1], sa_flags=SA_RESTORER|SA_ONSTACK|SA_RESTART|SA_SIGINFO, sa_restorer=0x7f9bc7fe2770}, NULL, 8) = 0
rt_sigaction(SIGRT_32, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_32, {sa_handler=0x563914d59d80, sa_mask=~[RTMIN RT_1], sa_flags=SA_RESTORER|SA_ONSTACK|SA_RESTART|SA_SIGINFO, sa_restorer=0x7f9bc7fe2770}, NULL, 8) = 0
rt_sigprocmask(SIG_SETMASK, ~[RTMIN RT_1], [], 8) = 0
rt_sigaction(SIGRT_1, {sa_handler=0x7f9bc802e720, sa_mask=[], sa_flags=SA_RESTORER|SA_ONSTACK|SA_RESTART|SA_SIGINFO, sa_restorer=0x7f9bc7fe2770}, NULL, 8) = 0
rt_sigprocmask(SIG_UNBLOCK, [RTMIN RT_1], NULL, 8) = 0
mmap(NULL, 8392704, PROT_NONE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_STACK, -1, 0) = 0x7f9b80d2d000
mprotect(0x7f9b80d2e000, 8388608, PROT_READ|PROT_WRITE) = 0
rt_sigprocmask(SIG_BLOCK, ~[], ~[KILL STOP RTMIN RT_1], 8) = 0
clone3({flags=CLONE_VM|CLONE_FS|CLONE_FILES|CLONE_SIGHAND|CLONE_THREAD|CLONE_SYSVSEM|CLONE_SETTLS|CLONE_PARENT_SETTID|CLONE_CHILD_CLEARTID, child_tid=0x7f9b8152d990, parent_tid=0x7f9b8152d990, exit_signal=0, stack=0x7f9b80d2d000, stack_size=0x7fff80, tls=0x7f9b8152d6c0} => {parent_tid=[63122]}, 88) = 63122
rt_sigprocmask(SIG_SETMASK, ~[KILL STOP RTMIN RT_1], NULL, 8) = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
rt_sigprocmask(SIG_SETMASK, ~[RTMIN RT_1], [], 8) = 0
mmap(NULL, 8392704, PROT_NONE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_STACK, -1, 0) = 0x7f9b8052c000
mprotect(0x7f9b8052d000, 8388608, PROT_READ|PROT_WRITE) = 0
rt_sigprocmask(SIG_BLOCK, ~[], ~[KILL STOP RTMIN RT_1], 8) = 0
clone3({flags=CLONE_VM|CLONE_FS|CLONE_FILES|CLONE_SIGHAND|CLONE_THREAD|CLONE_SYSVSEM|CLONE_SETTLS|CLONE_PARENT_SETTID|CLONE_CHILD_CLEARTID, child_tid=0x7f9b80d2c990, parent_tid=0x7f9b80d2c990, exit_signal=0, stack=0x7f9b8052c000, stack_size=0x7fff80, tls=0x7f9b80d2c6c0} => {parent_tid=[63123]}, 88) = 63123
rt_sigprocmask(SIG_SETMASK, ~[KILL STOP RTMIN RT_1], NULL, 8) = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
--- SIGURG {si_signo=SIGURG, si_code=SI_TKILL, si_pid=63121, si_uid=1000} ---
rt_sigreturn({mask=[]}) = 0
--- SIGURG {si_signo=SIGURG, si_code=SI_TKILL, si_pid=63121, si_uid=1000} ---
rt_sigreturn({mask=[]}) = 0
--- SIGURG {si_signo=SIGURG, si_code=SI_TKILL, si_pid=63121, si_uid=1000} ---
rt_sigreturn({mask=[]}) = 0
--- SIGURG {si_signo=SIGURG, si_code=SI_TKILL, si_pid=63121, si_uid=1000} ---
rt_sigreturn({mask=[]}) = 0
--- SIGURG {si_signo=SIGURG, si_code=SI_TKILL, si_pid=63121, si_uid=1000} ---
rt_sigreturn({mask=[]}) = 0
--- SIGURG {si_signo=SIGURG, si_code=SI_TKILL, si_pid=63121, si_uid=1000} ---
rt_sigreturn({mask=[]}) = 0
--- SIGURG {si_signo=SIGURG, si_code=SI_TKILL, si_pid=63121, si_uid=1000} ---
rt_sigreturn({mask=[]}) = 824634326800
rt_sigprocmask(SIG_SETMASK, ~[RTMIN RT_1], [], 8) = 0
mmap(NULL, 8392704, PROT_NONE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_STACK, -1, 0) = 0x7f9b7affe000
mprotect(0x7f9b7afff000, 8388608, PROT_READ|PROT_WRITE) = 0
rt_sigprocmask(SIG_BLOCK, ~[], ~[KILL STOP RTMIN RT_1], 8) = 0
clone3({flags=CLONE_VM|CLONE_FS|CLONE_FILES|CLONE_SIGHAND|CLONE_THREAD|CLONE_SYSVSEM|CLONE_SETTLS|CLONE_PARENT_SETTID|CLONE_CHILD_CLEARTID, child_tid=0x7f9b7b7fe990, parent_tid=0x7f9b7b7fe990, exit_signal=0, stack=0x7f9b7affe000, stack_size=0x7fff80, tls=0x7f9b7b7fe6c0} => {parent_tid=[63125]}, 88) = 63125
rt_sigprocmask(SIG_SETMASK, ~[KILL STOP RTMIN RT_1], NULL, 8) = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
futex(0xc000093948, FUTEX_WAKE_PRIVATE, 1) = 1
futex(0xc000100148, FUTEX_WAKE_PRIVATE, 1) = 1
futex(0x563916425780, FUTEX_WAIT_PRIVATE, 0, NULL) = -1 EAGAIN (Resource temporarily unavailable)
rt_sigprocmask(SIG_SETMASK, ~[RTMIN RT_1], [], 8) = 0
mmap(NULL, 8392704, PROT_NONE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_STACK, -1, 0) = 0x7f9b7a7fd000
mprotect(0x7f9b7a7fe000, 8388608, PROT_READ|PROT_WRITE) = 0
rt_sigprocmask(SIG_BLOCK, ~[], ~[KILL STOP RTMIN RT_1], 8) = 0
clone3({flags=CLONE_VM|CLONE_FS|CLONE_FILES|CLONE_SIGHAND|CLONE_THREAD|CLONE_SYSVSEM|CLONE_SETTLS|CLONE_PARENT_SETTID|CLONE_CHILD_CLEARTID, child_tid=0x7f9b7affd990, parent_tid=0x7f9b7affd990, exit_signal=0, stack=0x7f9b7a7fd000, stack_size=0x7fff80, tls=0x7f9b7affd6c0} => {parent_tid=[63126]}, 88) = 63126
rt_sigprocmask(SIG_SETMASK, ~[KILL STOP RTMIN RT_1], NULL, 8) = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
getrlimit(RLIMIT_NOFILE, {rlim_cur=1024, rlim_max=512*1024}) = 0
setrlimit(RLIMIT_NOFILE, {rlim_cur=512*1024, rlim_max=512*1024}) = 0
fcntl(0, F_GETFL) = 0x80402 (flags O_RDWR|O_APPEND|O_CLOEXEC)
futex(0xc000093148, FUTEX_WAKE_PRIVATE, 1) = 1
fcntl(1, F_GETFL) = 0x80402 (flags O_RDWR|O_APPEND|O_CLOEXEC)
fcntl(2, F_GETFL) = 0x80402 (flags O_RDWR|O_APPEND|O_CLOEXEC)
readlinkat(AT_FDCWD, "/proc/self/exe", "/usr/bin/docker", 128) = 15
openat(AT_FDCWD, "/usr/bin/docker", O_RDONLY|O_CLOEXEC) = 3
fcntl(3, F_GETFL) = 0x8000 (flags O_RDONLY|O_LARGEFILE)
fcntl(3, F_SETFL, O_RDONLY|O_NONBLOCK|O_LARGEFILE) = 0
epoll_create1(EPOLL_CLOEXEC) = 4
pipe2([5, 6], O_NONBLOCK|O_CLOEXEC) = 0
epoll_ctl(4, EPOLL_CTL_ADD, 5, {events=EPOLLIN, data={u32=373845192, u64=94803186969800}}) = 0
epoll_ctl(4, EPOLL_CTL_ADD, 3, {events=EPOLLIN|EPOLLOUT|EPOLLRDHUP|EPOLLET, data={u32=1315962881, u64=9195084142313734145}}) = -1 EPERM (Operation not permitted)
fcntl(3, F_GETFL) = 0x8800 (flags O_RDONLY|O_NONBLOCK|O_LARGEFILE)
fcntl(3, F_SETFL, O_RDONLY|O_LARGEFILE) = 0
fstat(3, {st_mode=S_IFREG|0755, st_size=24389624, ...}) = 0
pread64(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0000\260\0\0\0\0\0\0"..., 64, 0) = 64
pread64(3, " @\210t$(\350\266=\331\377H\213D$\10H\213\\$\20H\213L$\30H\213|$ \17"..., 64, 3048703) = 64
pread64(3, "\0\0L\215\244$\320\1\0\0A\275\2\0\0\0A\277\1\0\0\0L\215\234$\340\1\0\0L\211"..., 64, 6097406) = 64
pread64(3, "\211B\30H\213Z\30L\213\204$\300\0\0\0I\213x\30I\213p H\215\5E\32G\0\17\37"..., 64, 9146109) = 64
pread64(3, "(\1(\1 \1\0\0\6\0\0\0\t\0\0\0Z\1R\1B\1B\0\0\0\0\0\f\0\0\0"..., 64, 12194812) = 64
pread64(3, "\0\0\0\0\0\f\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0n\262\230\325\7\4\4\31\210\7\312"..., 64, 15243515) = 64
pread64(3, "\0\0q4\0\0\3525\0\0\377\377\377\377]\244\0\0\377\377\377\377\335\240\0\0\217\323\0\0\206\347"..., 64, 18292218) = 64
pread64(3, "]\1\0&]\1\0\33]\1\0\240%\0\0X%\0\0\377\377\377\377\260\221\t\0\377\377\377\377\275"..., 64, 21340921) = 64
close(3) = 0
mmap(0xc000400000, 4194304, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xc000400000
mmap(NULL, 262144, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f9b804ac000
getpid() = 63121
newfstatat(AT_FDCWD, "/proc", {st_mode=S_IFDIR|0555, st_size=0, ...}, 0) = 0
futex(0xc000093948, FUTEX_WAKE_PRIVATE, 1) = 1
futex(0xc000093148, FUTEX_WAKE_PRIVATE, 1) = 1
futex(0xc000093948, FUTEX_WAKE_PRIVATE, 1) = 1
futex(0xc000093148, FUTEX_WAKE_PRIVATE, 1) = 1
futex(0x563916425780, FUTEX_WAIT_PRIVATE, 0, NULL) = -1 EAGAIN (Resource temporarily unavailable)
futex(0xc000093148, FUTEX_WAKE_PRIVATE, 1) = 1
futex(0xc000093948, FUTEX_WAKE_PRIVATE, 1) = 1
mmap(NULL, 262144, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f9b8046c000
newfstatat(AT_FDCWD, "/usr/lib/libykcs11.so", 0xc0000ca1d8, 0) = -1 ENOENT (No such file or directory)
newfstatat(AT_FDCWD, "/usr/lib/libykcs11.so.1", 0xc0000ca2a8, 0) = -1 ENOENT (No such file or directory)
newfstatat(AT_FDCWD, "/usr/lib64/libykcs11.so", 0xc0000ca378, 0) = -1 ENOENT (No such file or directory)
newfstatat(AT_FDCWD, "/usr/lib64/libykcs11.so.1", 0xc0000ca448, 0) = -1 ENOENT (No such file or directory)
newfstatat(AT_FDCWD, "/usr/lib/x86_64-linux-gnu/libykcs11.so", 0xc0000ca518, 0) = -1 ENOENT (No such file or directory)
newfstatat(AT_FDCWD, "/usr/local/lib/libykcs11.so", 0xc0000ca5e8, 0) = -1 ENOENT (No such file or directory)
futex(0xc000093148, FUTEX_WAKE_PRIVATE, 1) = 1
futex(0xc000093948, FUTEX_WAKE_PRIVATE, 1) = 1
futex(0xc000093948, FUTEX_WAKE_PRIVATE, 1) = 1
futex(0x563916425020, FUTEX_WAIT_PRIVATE, 0, NULL) = -1 EAGAIN (Resource temporarily unavailable)
futex(0xc000093148, FUTEX_WAKE_PRIVATE, 1) = 1
futex(0xc000100148, FUTEX_WAKE_PRIVATE, 1) = 1
futex(0xc000100148, FUTEX_WAKE_PRIVATE, 1) = 1
futex(0xc000093948, FUTEX_WAKE_PRIVATE, 1) = 1
futex(0xc000100148, FUTEX_WAKE_PRIVATE, 1) = 1
futex(0xc000100148, FUTEX_WAKE_PRIVATE, 1) = 1
futex(0xc000100148, FUTEX_WAKE_PRIVATE, 1) = 1
futex(0xc000093148, FUTEX_WAKE_PRIVATE, 1) = 1
futex(0xc000093148, FUTEX_WAKE_PRIVATE, 1) = 1
futex(0xc000100148, FUTEX_WAKE_PRIVATE, 1) = 1
futex(0xc000093148, FUTEX_WAKE_PRIVATE, 1) = 1
futex(0xc000093148, FUTEX_WAKE_PRIVATE, 1) = 1
futex(0xc000093148, FUTEX_WAKE_PRIVATE, 1) = 1
futex(0xc000093148, FUTEX_WAKE_PRIVATE, 1) = 1
epoll_pwait(4, [], 128, 0, NULL, 0) = 0
futex(0xc000093948, FUTEX_WAKE_PRIVATE, 1) = 1
futex(0xc000580148, FUTEX_WAKE_PRIVATE, 1) = 1
--- SIGURG {si_signo=SIGURG, si_code=SI_TKILL, si_pid=63121, si_uid=1000} ---
rt_sigreturn({mask=[]}) = 1
rt_sigprocmask(SIG_SETMASK, ~[RTMIN RT_1], [], 8) = 0
mmap(NULL, 8392704, PROT_NONE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_STACK, -1, 0) = 0x7f9b78ffa000
mprotect(0x7f9b78ffb000, 8388608, PROT_READ|PROT_WRITE) = 0
rt_sigprocmask(SIG_BLOCK, ~[], ~[KILL STOP RTMIN RT_1], 8) = 0
clone3({flags=CLONE_VM|CLONE_FS|CLONE_FILES|CLONE_SIGHAND|CLONE_THREAD|CLONE_SYSVSEM|CLONE_SETTLS|CLONE_PARENT_SETTID|CLONE_CHILD_CLEARTID, child_tid=0x7f9b797fa990, parent_tid=0x7f9b797fa990, exit_signal=0, stack=0x7f9b78ffa000, stack_size=0x7fff80, tls=0x7f9b797fa6c0} => {parent_tid=[63129]}, 88) = 63129
rt_sigprocmask(SIG_SETMASK, ~[KILL STOP RTMIN RT_1], NULL, 8) = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
--- SIGURG {si_signo=SIGURG, si_code=SI_TKILL, si_pid=63121, si_uid=1000} ---
rt_sigreturn({mask=[]}) = 206608041572614
futex(0xc000548148, FUTEX_WAKE_PRIVATE, 1) = 1
futex(0x5639164284d8, FUTEX_WAKE_PRIVATE, 1) = 1
--- SIGURG {si_signo=SIGURG, si_code=SI_TKILL, si_pid=63121, si_uid=1000} ---
rt_sigreturn({mask=[]}) = 6
futex(0xc0004c4148, FUTEX_WAKE_PRIVATE, 1) = 1
futex(0x5639164284d8, FUTEX_WAKE_PRIVATE, 1) = 1
--- SIGURG {si_signo=SIGURG, si_code=SI_TKILL, si_pid=63121, si_uid=1000} ---
rt_sigreturn({mask=[]}) = 11
futex(0xc000548148, FUTEX_WAKE_PRIVATE, 1) = 1
futex(0x563916425780, FUTEX_WAIT_PRIVATE, 0, NULL) = 0
ioctl(0, TCGETS, {c_iflag=ICRNL|IXON|IUTF8, c_oflag=NL0|CR0|TAB0|BS0|VT0|FF0|OPOST|ONLCR, c_cflag=B38400|CS8|CREAD, c_lflag=ISIG|ICANON|ECHO|ECHOE|ECHOK|IEXTEN|ECHOCTL|ECHOKE, ...}) = 0
ioctl(1, TCGETS, {c_iflag=ICRNL|IXON|IUTF8, c_oflag=NL0|CR0|TAB0|BS0|VT0|FF0|OPOST|ONLCR, c_cflag=B38400|CS8|CREAD, c_lflag=ISIG|ICANON|ECHO|ECHOE|ECHOK|IEXTEN|ECHOCTL|ECHOKE, ...}) = 0
mmap(NULL, 262144, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f9b8035c000
openat(AT_FDCWD, "/home/jsaraiva/.docker/config.json", O_RDONLY|O_CLOEXEC) = 3
fcntl(3, F_GETFL) = 0x8000 (flags O_RDONLY|O_LARGEFILE)
fcntl(3, F_SETFL, O_RDONLY|O_NONBLOCK|O_LARGEFILE) = 0
epoll_ctl(4, EPOLL_CTL_ADD, 3, {events=EPOLLIN|EPOLLOUT|EPOLLRDHUP|EPOLLET, data={u32=1315962882, u64=9195084142313734146}}) = -1 EPERM (Operation not permitted)
fcntl(3, F_GETFL) = 0x8800 (flags O_RDONLY|O_NONBLOCK|O_LARGEFILE)
fcntl(3, F_SETFL, O_RDONLY|O_LARGEFILE) = 0
read(3, "{\n\t\"auths\": {\n\t\t\"https://index.d"..., 512) = 146
close(3) = 0
newfstatat(AT_FDCWD, "/home/jsaraiva/.docker/cli-plugins/docker-compose", {st_mode=S_IFREG|0755, st_size=61431093, ...}, 0) = 0
openat(AT_FDCWD, "/dev/null", O_RDONLY|O_CLOEXEC) = 3
fcntl(3, F_GETFL) = 0x8000 (flags O_RDONLY|O_LARGEFILE)
fcntl(3, F_SETFL, O_RDONLY|O_NONBLOCK|O_LARGEFILE) = 0
epoll_ctl(4, EPOLL_CTL_ADD, 3, {events=EPOLLIN|EPOLLOUT|EPOLLRDHUP|EPOLLET, data={u32=1315962883, u64=9195084142313734147}}) = -1 EPERM (Operation not permitted)
fcntl(3, F_GETFL) = 0x8800 (flags O_RDONLY|O_NONBLOCK|O_LARGEFILE)
fcntl(3, F_SETFL, O_RDONLY|O_LARGEFILE) = 0
pipe2([7, 8], O_CLOEXEC) = 0
fcntl(7, F_GETFL) = 0 (flags O_RDONLY)
fcntl(7, F_SETFL, O_RDONLY|O_NONBLOCK) = 0
epoll_ctl(4, EPOLL_CTL_ADD, 7, {events=EPOLLIN|EPOLLOUT|EPOLLRDHUP|EPOLLET, data={u32=1315962884, u64=9195084142313734148}}) = 0
fcntl(8, F_GETFL) = 0x1 (flags O_WRONLY)
fcntl(8, F_SETFL, O_WRONLY|O_NONBLOCK) = 0
epoll_ctl(4, EPOLL_CTL_ADD, 8, {events=EPOLLIN|EPOLLOUT|EPOLLRDHUP|EPOLLET, data={u32=1299709953, u64=9195084142297481217}}) = 0
pipe2([9, 10], O_CLOEXEC) = 0
fcntl(9, F_GETFL) = 0 (flags O_RDONLY)
fcntl(9, F_SETFL, O_RDONLY|O_NONBLOCK) = 0
epoll_ctl(4, EPOLL_CTL_ADD, 9, {events=EPOLLIN|EPOLLOUT|EPOLLRDHUP|EPOLLET, data={u32=1283457025, u64=9195084142281228289}}) = 0
fcntl(10, F_GETFL) = 0x1 (flags O_WRONLY)
fcntl(10, F_SETFL, O_WRONLY|O_NONBLOCK) = 0
epoll_ctl(4, EPOLL_CTL_ADD, 10, {events=EPOLLIN|EPOLLOUT|EPOLLRDHUP|EPOLLET, data={u32=1267204097, u64=9195084142264975361}}) = 0
fcntl(8, F_GETFL) = 0x801 (flags O_WRONLY|O_NONBLOCK)
fcntl(8, F_SETFL, O_WRONLY) = 0
fcntl(10, F_GETFL) = 0x801 (flags O_WRONLY|O_NONBLOCK)
fcntl(10, F_SETFL, O_WRONLY) = 0
pipe2([11, 12], O_CLOEXEC) = 0
getpid() = 63121
rt_sigprocmask(SIG_SETMASK, NULL, [], 8) = 0
rt_sigprocmask(SIG_SETMASK, ~[], NULL, 8) = 0
clone(child_stack=NULL, flags=CLONE_VM|CLONE_VFORK|SIGCHLD) = 63130
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
close(12) = 0
read(11, "", 8) = 0
close(11) = 0
futex(0xc0004c4148, FUTEX_WAKE_PRIVATE, 1) = 1
close(3) = 0
epoll_ctl(4, EPOLL_CTL_DEL, 8, 0xc00063f584) = 0
close(8) = 0
epoll_ctl(4, EPOLL_CTL_DEL, 10, 0xc00063f584) = 0
close(10) = 0
waitid(P_PID, 63130, {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=63130, si_uid=1000, si_status=0, si_utime=0, si_stime=0}, WEXITED|WNOWAIT, NULL) = 0
--- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=63130, si_uid=1000, si_status=0, si_utime=2 /* 0.02 s */, si_stime=1 /* 0.01 s */} ---
rt_sigreturn({mask=[]}) = 0
futex(0x5639164284c0, FUTEX_WAKE_PRIVATE, 1) = 1
wait4(63130, [{WIFEXITED(s) && WEXITSTATUS(s) == 0}], 0, {ru_utime={tv_sec=0, tv_usec=19731}, ru_stime={tv_sec=0, tv_usec=13142}, ...}) = 63130
futex(0xc000580148, FUTEX_WAKE_PRIVATE, 1) = 1
getrandom("\xae\x92\xe5\xd7\x21\x67\x71\xe3\x23\x05\x3e\xf1\x61\x6f\xd1\x32", 16, 0) = 16
socket(AF_UNIX, SOCK_STREAM|SOCK_CLOEXEC|SOCK_NONBLOCK, 0) = 3
openat(AT_FDCWD, "/proc/sys/net/core/somaxconn", O_RDONLY|O_CLOEXEC) = 7
fcntl(7, F_GETFL) = 0x8000 (flags O_RDONLY|O_LARGEFILE)
fcntl(7, F_SETFL, O_RDONLY|O_NONBLOCK|O_LARGEFILE) = 0
epoll_ctl(4, EPOLL_CTL_ADD, 7, {events=EPOLLIN|EPOLLOUT|EPOLLRDHUP|EPOLLET, data={u32=1283457026, u64=9195084142281228290}}) = 0
read(7, "4096\n", 65536) = 5
read(7, "", 65531) = 0
epoll_ctl(4, EPOLL_CTL_DEL, 7, 0xc00063f82c) = 0
close(7) = 0
setsockopt(3, SOL_SOCKET, SO_REUSEADDR, [1], 4) = 0
bind(3, {sa_family=AF_UNIX, sun_path=@"docker_cli_ae92e5d7-2167-41e3-a305-3ef1616fd132"}, 50) = 0
listen(3, 4096) = 0
epoll_ctl(4, EPOLL_CTL_ADD, 3, {events=EPOLLIN|EPOLLOUT|EPOLLRDHUP|EPOLLET, data={u32=1283457027, u64=9195084142281228291}}) = 0
getsockname(3, {sa_family=AF_UNIX, sun_path=@"docker_cli_ae92e5d7-2167-41e3-a305-3ef1616fd132"}, [112 => 50]) = 0
futex(0xc0004c4148, FUTEX_WAKE_PRIVATE, 1) = 1
rt_sigprocmask(SIG_SETMASK, ~[HUP INT QUIT ILL TRAP ABRT BUS FPE SEGV TERM STKFLT CHLD URG PROF SYS RTMIN RT_1 RT_2], NULL, 8) = 0
rt_sigprocmask(SIG_SETMASK, ~[HUP INT QUIT ILL TRAP ABRT BUS FPE SEGV TERM STKFLT CHLD URG PROF SYS RTMIN RT_1 RT_2], NULL, 8) = 0
futex(0xc000093948, FUTEX_WAKE_PRIVATE, 1) = 1
futex(0x563916425780, FUTEX_WAIT_PRIVATE, 0, NULL) = -1 EAGAIN (Resource temporarily unavailable)
futex(0xc000548148, FUTEX_WAKE_PRIVATE, 1) = 1
rt_sigprocmask(SIG_SETMASK, ~[HUP INT QUIT ILL TRAP ABRT BUS FPE SEGV TERM STKFLT CHLD URG PROF SYS RTMIN RT_1 RT_2], NULL, 8) = 0
futex(0xc0004c4148, FUTEX_WAKE_PRIVATE, 1) = 1
futex(0x563916425780, FUTEX_WAIT_PRIVATE, 0, NULL) = 0
futex(0x563916425780, FUTEX_WAIT_PRIVATE, 0, NULL
^^^^^^^ The ~8-12s delay happens here, where it seems to just be waiting on something
NAME IMAGE COMMAND SERVICE CREATED STATUS PORTS
) = ?
+++ exited with 0 +++
Issue persists on 2.24.7.
Does running commands with docker --tls=false compose ...
change anything?
Is there a difference between docker compose ps
and docker ps
?
$ time (source .envrc; docker ps &>/dev/null)
real 0m0.058s
user 0m0.017s
sys 0m0.016s
$ time (source .envrc; docker compose ps &>/dev/null)
real 0m9.797s
user 0m14.592s
sys 0m0.327s
$ time (source .envrc; docker --tls=false compose ps &>/dev/null)
real 0m9.856s
user 0m14.742s
sys 0m0.289s
One more debugging question/hint: do you still have an older (24.0.7) docker cli/server?
Here's what works for me to run the latest docker cli (but this might avoid the potential issue I have in mind):
docker run --rm -v /var/run/docker.sock:/var/run/docker.sock docker:cli env -i /usr/local/bin/docker ps
(after a docker pull docker:cli
just to be sure)
Maybe it's not about compose - it could be ... but between compose 2.24.3 and .4 there are also changes about cli/server libraries it uses. There's a current pull request here: https://github.com/docker-library/docker/pulls where something about a deliberate slowdown is mentioned ... so I thought to give this a try
When skipping docker compose completely the issue never occurs, which I assume is what you were trying to demonstrate?
$ time (source .envrc; docker run --rm -v /var/run/docker.sock:/var/run/docker.sock docker:cli env -i /usr/local/bin/docker version; docker run --rm -v /var/run/docker.sock:/var/run/docker.sock docker:cli env -i /usr/local/bin/docker ps &>/dev/null)
Client:
Version: 25.0.4
API version: 1.44
Go version: go1.21.8
Git commit: 1a576c5
Built: Wed Mar 6 16:32:02 2024
OS/Arch: linux/amd64
Context: default
Server:
Engine:
Version: 25.0.3
API version: 1.44 (minimum version 1.24)
Go version: go1.22.0
Git commit: f417435e5f
Built: Thu Feb 29 20:50:13 2024
OS/Arch: linux/amd64
Experimental: false
containerd:
Version: v1.7.13
GitCommit: 7c3aca7a610df76212171d200ca3811ff6096eb8.m
runc:
Version: 1.1.12
GitCommit:
docker-init:
Version: 0.19.0
GitCommit: de40ad0
real 0m1.558s
user 0m0.025s
sys 0m0.037s
The issue has been introduced by the change: https://github.com/compose-spec/compose-go/pull/546
It can be reproduced with this compose.yaml file.
Running docker compose config
on my machine takes with
I created the custom 2.25.0 build without https://github.com/compose-spec/compose-go/pull/546 in the following way:
go mod vendor
Apply the following change:
diff --git a/vendor/github.com/compose-spec/compose-go/v2/loader/validate.go b/vendor/github.com/compose-spec/compose-go/v2/loader/validate.go
index c5133f963..aa1e67192 100644
--- a/vendor/github.com/compose-spec/compose-go/v2/loader/validate.go
+++ b/vendor/github.com/compose-spec/compose-go/v2/loader/validate.go
@@ -76,12 +76,6 @@ func checkConsistency(project *types.Project) error {
return fmt.Errorf("service %q depends on undefined service %q: %w", s.Name, dependedService, errdefs.ErrInvalid)
}
}
- // Check there isn't a cycle in depends_on declarations
- if err := graph.InDependencyOrder(context.Background(), project, func(ctx context.Context, s string, config types.ServiceConfig) error {
- return nil
- }); err != nil {
- return err
- }
if strings.HasPrefix(s.NetworkMode, types.ServicePrefix) {
serviceName := s.NetworkMode[len(types.ServicePrefix):]
go build -o compose cmd/main.go
I can confirm removing this check has a mass impact on performance. There's something wrong with InDependencyOrder
implementation, I'll look into it
Any chance to get this fix in master soonish? :pray: :innocent:
Fixed in 2.26.0 (although not documented in release notes).
Yeah ๐ Thanks @ndeloof for taking care of this when I was away ๐๐ค
Description
Starting with version 2.24.4 I observe a noticeable and severe performance degradation with all docker compose commands.
We have a pretty sizable project with over 100 containers, in case that helps paint a better picture.
Steps To Reproduce
A big project with all containers stopped (assuming that even matters).
For versions <= 2.24.3
With version >= 2.24.4:
The delay (~8s) is observed before any output is produced and regardless of which command is ran. I cannot reproduce the slowness with a simple test project of a couple of containers.
Happy to provide more information that can help hunt this down.
Compose Version
Docker Environment
Anything else?
No response