Docker commands (rm/kill/inspect/...) hangs on a said running but already exited container #42894
Comments
|
I had similar issue, some running container shows up in |
|
👋 ah good to know! I'll attach it here if it happens again, thanks! |
|
I looked at bit more at your description: given the containerd task is gone but the containerd container and the netns are still there, I believe Docker is stuck somewhere here ( Lines 27 to 63 in 4283e93 I see you're using fluentd in async mode, do you know if the fluentd server was still running when you tried to stop/kill/rm the container? There's a bug that prevents fluentd logger to stop because it's blocked in an exponential backoff retry loop when there're logs to send but the fluentd server is down. This bug manifests the same symptoms (eg. hanging docker commands, etc...). |
|
Indeed, I suspected flutend at start, but found no clue. IIRC there were some issues with fluentd! I'm going to wait for it to happen again and get the stack trace then! Thanks! |
|
Hello from AWS ECS, we believe we have also seen this issue, and as the original opener mentioned, it seems rare and hard to reproduce. We have also noted the relationship to the fluentd log driver, and we have some reason to believe that recent fixes in the fluent-logger-golang library may have fixed it. These fixes were pulled into moby master and backported to docker 20.10.13 here: #43147 Has anyone seen this issue using docker 20.10.13+ ? |
|
I see this or similar issue with following docker logging config "fluentd-async": "true", problem does not appear |
Description
Context:
A running container (launched with docker-compose) and a
restart: nopolicy, with a process that exit with a status code of 0.Here is the docker-compose file (docker-compose version 1.25.4, build 8d51620a) (just anonymized some info with
***):When seeing this,
restart: neveris not a valid policy yet docker-compose does not mind, so I guess it's thenodefault restart policy that is in use (fixed with later docker-compose release).Issue:
When trying to stop/kill/inspect/rm this container, all the
docker <action> <container_id>hangs.I've found #30927 which is kind of old and #40817 (see below but I don't have any hung runc processes)
The stuck container ID here is 1c71de80ad77d3b39579833bd61b80ae51c313ad7d629e1f658f3d6aeeb28602 and the process linked to this container, is non existant.
What I've seen:
ctr -n moby task ls-> nothingctr -n moby c ls-> I can see the containerctr -n moby containers info 1c71de80ad77d3b39579833bd61b80ae51c313ad7d629e1f658f3d6aeeb28602Click to see
{ "ID": "1c71de80ad77d3b39579833bd61b80ae51c313ad7d629e1f658f3d6aeeb28602", "Labels": { "com.docker/engine.bundle.path": "/var/run/docker/containerd/1c71de80ad77d3b39579833bd61b80ae51c313ad7d629e1f658f3d6aeeb28602" }, "Image": "", "Runtime": { "Name": "io.containerd.runc.v2", "Options": { "type_url": "containerd.runc.v1.Options", "value": "MgRydW5jOhwvdmFyL3J1bi9kb2NrZXIvcnVudGltZS1ydW5j" } }, "SnapshotKey": "", "Snapshotter": "", "CreatedAt": "2021-09-28T12:49:45.578665569Z", "UpdatedAt": "2021-09-28T12:49:45.578665569Z", "Extensions": null, "Spec": { "ociVersion": "1.0.2-dev", "process": { "user": { "uid": 101, "gid": 101, "additionalGids": [ 101 ] }, "args": [ "***", "***" ], "env": [ "PATH=/opt/venv/bin:/usr/local/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin", "HOSTNAME=***", "LANG=C.UTF-8" ], "cwd": "/", "capabilities": { "bounding": [ "CAP_CHOWN", "CAP_DAC_OVERRIDE", "CAP_FSETID", "CAP_FOWNER", "CAP_MKNOD", "CAP_NET_RAW", "CAP_SETGID", "CAP_SETUID", "CAP_SETFCAP", "CAP_SETPCAP", "CAP_NET_BIND_SERVICE", "CAP_SYS_CHROOT", "CAP_KILL", "CAP_AUDIT_WRITE" ], "inheritable": [ "CAP_CHOWN", "CAP_DAC_OVERRIDE", "CAP_FSETID", "CAP_FOWNER", "CAP_MKNOD", "CAP_NET_RAW", "CAP_SETGID", "CAP_SETUID", "CAP_SETFCAP", "CAP_SETPCAP", "CAP_NET_BIND_SERVICE", "CAP_SYS_CHROOT", "CAP_KILL", "CAP_AUDIT_WRITE" ] }, "apparmorProfile": "docker-default", "oomScoreAdj": 0 }, "root": { "path": "/var/lib/docker/overlay2/0ddc2295cbbe3affd23cfd474488f88d715ae4413f8f655830fbaf0274441002/merged" }, "hostname": "***", "mounts": [ { "destination": "/proc", "type": "proc", "source": "proc", "options": [ "nosuid", "noexec", "nodev" ] }, { "destination": "/dev", "type": "tmpfs", "source": "tmpfs", "options": [ "nosuid", "strictatime", "mode=755", "size=65536k" ] }, { "destination": "/dev/pts", "type": "devpts", "source": "devpts", "options": [ "nosuid", "noexec", "newinstance", "ptmxmode=0666", "mode=0620", "gid=5" ] }, { "destination": "/sys", "type": "sysfs", "source": "sysfs", "options": [ "nosuid", "noexec", "nodev", "ro" ] }, { "destination": "/sys/fs/cgroup", "type": "cgroup", "source": "cgroup", "options": [ "ro", "nosuid", "noexec", "nodev" ] }, { "destination": "/dev/mqueue", "type": "mqueue", "source": "mqueue", "options": [ "nosuid", "noexec", "nodev" ] }, { "destination": "/data", "type": "bind", "source": "***", "options": [ "rbind", "rprivate" ] }, { "destination": "/etc/resolv.conf", "type": "bind", "source": "/var/lib/docker/containers/1c71de80ad77d3b39579833bd61b80ae51c313ad7d629e1f658f3d6aeeb28602/resolv.conf", "options": [ "rbind", "rprivate" ] }, { "destination": "/etc/hostname", "type": "bind", "source": "/var/lib/docker/containers/1c71de80ad77d3b39579833bd61b80ae51c313ad7d629e1f658f3d6aeeb28602/hostname", "options": [ "rbind", "rprivate" ] }, { "destination": "/etc/hosts", "type": "bind", "source": "/var/lib/docker/containers/1c71de80ad77d3b39579833bd61b80ae51c313ad7d629e1f658f3d6aeeb28602/hosts", "options": [ "rbind", "rprivate" ] }, { "destination": "/dev/shm", "type": "bind", "source": "/var/lib/docker/containers/1c71de80ad77d3b39579833bd61b80ae51c313ad7d629e1f658f3d6aeeb28602/mounts/shm", "options": [ "rbind", "rprivate" ] }, { "destination": "/etc/ssl/certs", "type": "bind", "source": "/etc/ssl/certs", "options": [ "rbind", "ro", "rprivate" ] } ], "hooks": { "prestart": [ { "path": "/proc/5754/exe", "args": [ "libnetwork-setkey", "-exec-root=/var/run/docker", "1c71de80ad77d3b39579833bd61b80ae51c313ad7d629e1f658f3d6aeeb28602", "8d348b5ac848" ] } ] }, "linux": { "sysctl": { "net.ipv4.ip_unprivileged_port_start": "0" }, "resources": { "devices": [ { "allow": false, "access": "rwm" }, { "allow": true, "type": "c", "major": 1, "minor": 5, "access": "rwm" }, { "allow": true, "type": "c", "major": 1, "minor": 3, "access": "rwm" }, { "allow": true, "type": "c", "major": 1, "minor": 9, "access": "rwm" }, { "allow": true, "type": "c", "major": 1, "minor": 8, "access": "rwm" }, { "allow": true, "type": "c", "major": 5, "minor": 0, "access": "rwm" }, { "allow": true, "type": "c", "major": 5, "minor": 1, "access": "rwm" }, { "allow": false, "type": "c", "major": 10, "minor": 229, "access": "rwm" } ], "memory": { "disableOOMKiller": false }, "cpu": { "shares": 0 }, "blockIO": { "weight": 0 } }, "cgroupsPath": "/docker/1c71de80ad77d3b39579833bd61b80ae51c313ad7d629e1f658f3d6aeeb28602", "namespaces": [ { "type": "mount" }, { "type": "network" }, { "type": "uts" }, { "type": "pid" }, { "type": "ipc" } ], "seccomp": { "defaultAction": "SCMP_ACT_ERRNO", "architectures": [ "SCMP_ARCH_X86_64", "SCMP_ARCH_X86", "SCMP_ARCH_X32" ], "syscalls": [ { "names": [ "accept", "accept4", "access", "adjtimex", "alarm", "bind", "brk", "capget", "capset", "chdir", "chmod", "chown", "chown32", "clock_adjtime", "clock_adjtime64", "clock_getres", "clock_getres_time64", "clock_gettime", "clock_gettime64", "clock_nanosleep", "clock_nanosleep_time64", "close", "close_range", "connect", "copy_file_range", "creat", "dup", "dup2", "dup3", "epoll_create", "epoll_create1", "epoll_ctl", "epoll_ctl_old", "epoll_pwait", "epoll_pwait2", "epoll_wait", "epoll_wait_old", "eventfd", "eventfd2", "execve", "execveat", "exit", "exit_group", "faccessat", "faccessat2", "fadvise64", "fadvise64_64", "fallocate", "fanotify_mark", "fchdir", "fchmod", "fchmodat", "fchown", "fchown32", "fchownat", "fcntl", "fcntl64", "fdatasync", "fgetxattr", "flistxattr", "flock", "fork", "fremovexattr", "fsetxattr", "fstat", "fstat64", "fstatat64", "fstatfs", "fstatfs64", "fsync", "ftruncate", "ftruncate64", "futex", "futex_time64", "futimesat", "getcpu", "getcwd", "getdents", "getdents64", "getegid", "getegid32", "geteuid", "geteuid32", "getgid", "getgid32", "getgroups", "getgroups32", "getitimer", "getpeername", "getpgid", "getpgrp", "getpid", "getppid", "getpriority", "getrandom", "getresgid", "getresgid32", "getresuid", "getresuid32", "getrlimit", "get_robust_list", "getrusage", "getsid", "getsockname", "getsockopt", "get_thread_area", "gettid", "gettimeofday", "getuid", "getuid32", "getxattr", "inotify_add_watch", "inotify_init", "inotify_init1", "inotify_rm_watch", "io_cancel", "ioctl", "io_destroy", "io_getevents", "io_pgetevents", "io_pgetevents_time64", "ioprio_get", "ioprio_set", "io_setup", "io_submit", "io_uring_enter", "io_uring_register", "io_uring_setup", "ipc", "kill", "lchown", "lchown32", "lgetxattr", "link", "linkat", "listen", "listxattr", "llistxattr", "_llseek", "lremovexattr", "lseek", "lsetxattr", "lstat", "lstat64", "madvise", "membarrier", "memfd_create", "mincore", "mkdir", "mkdirat", "mknod", "mknodat", "mlock", "mlock2", "mlockall", "mmap", "mmap2", "mprotect", "mq_getsetattr", "mq_notify", "mq_open", "mq_timedreceive", "mq_timedreceive_time64", "mq_timedsend", "mq_timedsend_time64", "mq_unlink", "mremap", "msgctl", "msgget", "msgrcv", "msgsnd", "msync", "munlock", "munlockall", "munmap", "nanosleep", "newfstatat", "_newselect", "open", "openat", "openat2", "pause", "pidfd_open", "pidfd_send_signal", "pipe", "pipe2", "poll", "ppoll", "ppoll_time64", "prctl", "pread64", "preadv", "preadv2", "prlimit64", "pselect6", "pselect6_time64", "pwrite64", "pwritev", "pwritev2", "read", "readahead", "readlink", "readlinkat", "readv", "recv", "recvfrom", "recvmmsg", "recvmmsg_time64", "recvmsg", "remap_file_pages", "removexattr", "rename", "renameat", "renameat2", "restart_syscall", "rmdir", "rseq", "rt_sigaction", "rt_sigpending", "rt_sigprocmask", "rt_sigqueueinfo", "rt_sigreturn", "rt_sigsuspend", "rt_sigtimedwait", "rt_sigtimedwait_time64", "rt_tgsigqueueinfo", "sched_getaffinity", "sched_getattr", "sched_getparam", "sched_get_priority_max", "sched_get_priority_min", "sched_getscheduler", "sched_rr_get_interval", "sched_rr_get_interval_time64", "sched_setaffinity", "sched_setattr", "sched_setparam", "sched_setscheduler", "sched_yield", "seccomp", "select", "semctl", "semget", "semop", "semtimedop", "semtimedop_time64", "send", "sendfile", "sendfile64", "sendmmsg", "sendmsg", "sendto", "setfsgid", "setfsgid32", "setfsuid", "setfsuid32", "setgid", "setgid32", "setgroups", "setgroups32", "setitimer", "setpgid", "setpriority", "setregid", "setregid32", "setresgid", "setresgid32", "setresuid", "setresuid32", "setreuid", "setreuid32", "setrlimit", "set_robust_list", "setsid", "setsockopt", "set_thread_area", "set_tid_address", "setuid", "setuid32", "setxattr", "shmat", "shmctl", "shmdt", "shmget", "shutdown", "sigaltstack", "signalfd", "signalfd4", "sigprocmask", "sigreturn", "socket", "socketcall", "socketpair", "splice", "stat", "stat64", "statfs", "statfs64", "statx", "symlink", "symlinkat", "sync", "sync_file_range", "syncfs", "sysinfo", "tee", "tgkill", "time", "timer_create", "timer_delete", "timer_getoverrun", "timer_gettime", "timer_gettime64", "timer_settime", "timer_settime64", "timerfd_create", "timerfd_gettime", "timerfd_gettime64", "timerfd_settime", "timerfd_settime64", "times", "tkill", "truncate", "truncate64", "ugetrlimit", "umask", "uname", "unlink", "unlinkat", "utime", "utimensat", "utimensat_time64", "utimes", "vfork", "vmsplice", "wait4", "waitid", "waitpid", "write", "writev" ], "action": "SCMP_ACT_ALLOW" }, { "names": [ "ptrace" ], "action": "SCMP_ACT_ALLOW" }, { "names": [ "personality" ], "action": "SCMP_ACT_ALLOW", "args": [ { "index": 0, "value": 0, "op": "SCMP_CMP_EQ" } ] }, { "names": [ "personality" ], "action": "SCMP_ACT_ALLOW", "args": [ { "index": 0, "value": 8, "op": "SCMP_CMP_EQ" } ] }, { "names": [ "personality" ], "action": "SCMP_ACT_ALLOW", "args": [ { "index": 0, "value": 131072, "op": "SCMP_CMP_EQ" } ] }, { "names": [ "personality" ], "action": "SCMP_ACT_ALLOW", "args": [ { "index": 0, "value": 131080, "op": "SCMP_CMP_EQ" } ] }, { "names": [ "personality" ], "action": "SCMP_ACT_ALLOW", "args": [ { "index": 0, "value": 4294967295, "op": "SCMP_CMP_EQ" } ] }, { "names": [ "arch_prctl" ], "action": "SCMP_ACT_ALLOW" }, { "names": [ "modify_ldt" ], "action": "SCMP_ACT_ALLOW" }, { "names": [ "clone" ], "action": "SCMP_ACT_ALLOW", "args": [ { "index": 0, "value": 2114060288, "op": "SCMP_CMP_MASKED_EQ" } ] }, { "names": [ "chroot" ], "action": "SCMP_ACT_ALLOW" } ] }, "maskedPaths": [ "/proc/asound", "/proc/acpi", "/proc/kcore", "/proc/keys", "/proc/latency_stats", "/proc/timer_list", "/proc/timer_stats", "/proc/sched_debug", "/proc/scsi", "/sys/firmware" ], "readonlyPaths": [ "/proc/bus", "/proc/fs", "/proc/irq", "/proc/sys", "/proc/sysrq-trigger" ] } } }find / -name "*1c71de80*"/var/run/docker/containerd/1c71de80ad77d3b39579833bd61b80ae51c313ad7d629e1f658f3d6aeeb28602/there is two named pipes ->init-stdoutandinit-stderrtree /var/lib/docker/containers/1c71de80ad77d3b39579833bd61b80ae51c313ad7d629e1f658f3d6aeeb28602cat /var/lib/docker/containers/1c71de80ad77d3b39579833bd61b80ae51c313ad7d629e1f658f3d6aeeb28602/config.v2.jsonClick to see
{ "StreamConfig": {}, "State": { "Running": true, "Paused": false, "Restarting": false, "OOMKilled": false, "RemovalInProgress": false, "Dead": false, "Pid": 6108, "ExitCode": 0, "Error": "", "StartedAt": "2021-09-28T12:49:45.945753185Z", "FinishedAt": "2021-09-28T12:49:44.593011751Z", "Health": null }, "ID": "1c71de80ad77d3b39579833bd61b80ae51c313ad7d629e1f658f3d6aeeb28602", "Created": "2021-09-07T12:27:41.549873025Z", "Managed": false, "Path": "***", "Args": [ "***" ], "Config": { "Hostname": "***", "Domainname": "", "User": "***", "AttachStdin": false, "AttachStdout": false, "AttachStderr": false, "Tty": false, "OpenStdin": false, "StdinOnce": false, "Env": [ "PATH=/opt/venv/bin:/usr/local/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin", "LANG=C.UTF-8" ], "Cmd": [ "***", "***" ], "Image": "***", "Volumes": { "/data": {}, "/etc/ssl/certs": {} }, "WorkingDir": "", "Entrypoint": null, "OnBuild": null, "Labels": { "com.docker.compose.config-hash": "318cec37934e0aa3669251c5d0c65762842db6aa7221a07df941f247529fb92d", "com.docker.compose.container-number": "1", "com.docker.compose.oneoff": "False", "com.docker.compose.project": "***", "com.docker.compose.project.config_files": "***", "com.docker.compose.project.working_dir": "***", "com.docker.compose.service": "***", "com.docker.compose.version": "1.25.4" } }, "Image": "sha256:88efb1b4c07c8e691f504779ba534e7d079171a67a30ce4d90b6e894833e8da4", "NetworkSettings": { "Bridge": "", "SandboxID": "06dbfe1d245992abf3f075ecd893b1b6a44957519cbee8b77e3acaca579dc625", "HairpinMode": false, "LinkLocalIPv6Address": "", "LinkLocalIPv6PrefixLen": 0, "Networks": { "bridge": { "IPAMConfig": null, "Links": null, "Aliases": null, "NetworkID": "8b71e7a01854df19d6bf23ecbf76c1379317f39d34965d0c1992df62b40ed2e7", "EndpointID": "4395f7f3b45e21fd5b7516a771265d6ce81d9e93b01fd1c0d30767f642e98c6a", "Gateway": "100.64.0.1", "IPAddress": "100.64.0.4", "IPPrefixLen": 24, "IPv6Gateway": "", "GlobalIPv6Address": "", "GlobalIPv6PrefixLen": 0, "MacAddress": "02:42:64:40:00:04", "DriverOpts": null, "IPAMOperational": false } }, "Service": null, "Ports": {}, "SandboxKey": "/var/run/docker/netns/06dbfe1d2459", "SecondaryIPAddresses": null, "SecondaryIPv6Addresses": null, "IsAnonymousEndpoint": false, "HasSwarmEndpoint": false }, "LogPath": "", "Name": "***", "Driver": "overlay2", "OS": "linux", "MountLabel": "", "ProcessLabel": "", "RestartCount": 0, "HasBeenStartedBefore": true, "HasBeenManuallyStopped": false, "MountPoints": { "/data": { "Source": "***", "Destination": "/data", "RW": true, "Name": "", "Driver": "", "Type": "bind", "Relabel": "rw", "Propagation": "rprivate", "Spec": { "Type": "bind", "Source": "***", "Target": "/data" }, "SkipMountpointCreation": false }, "/etc/ssl/certs": { "Source": "/etc/ssl/certs", "Destination": "/etc/ssl/certs", "RW": false, "Name": "", "Driver": "", "Type": "bind", "Relabel": "ro", "Propagation": "rprivate", "Spec": { "Type": "bind", "Source": "/etc/ssl/certs", "Target": "/etc/ssl/certs", "ReadOnly": true }, "SkipMountpointCreation": false } }, "SecretReferences": null, "ConfigReferences": null, "AppArmorProfile": "docker-default", "HostnamePath": "/var/lib/docker/containers/1c71de80ad77d3b39579833bd61b80ae51c313ad7d629e1f658f3d6aeeb28602/hostname", "HostsPath": "/var/lib/docker/containers/1c71de80ad77d3b39579833bd61b80ae51c313ad7d629e1f658f3d6aeeb28602/hosts", "ShmPath": "/var/lib/docker/containers/1c71de80ad77d3b39579833bd61b80ae51c313ad7d629e1f658f3d6aeeb28602/mounts/shm", "ResolvConfPath": "/var/lib/docker/containers/1c71de80ad77d3b39579833bd61b80ae51c313ad7d629e1f658f3d6aeeb28602/resolv.conf", "SeccompProfile": "", "NoNewPrivileges": false, "LocalLogCacheMeta": { "HaveNotifyEnabled": true } }file /var/run/docker/netns/06dbfe1d2459Then I tried:
ctr -n moby c kill 1c71de80ad77d3b39579833bd61b80ae51c313ad7d629e1f658f3d6aeeb28602-> ok, container is gone withctr c lsbutdocker rmstill hangsrm -Rf /var/run/docker/containerd/1c71de80ad77d3b39579833bd61b80ae51c313ad7d629e1f658f3d6aeeb28602/-> ok butdocker rmstill hangsstrace docker rm -f 1c71de80ad77d3b39579833bd61b80ae51c313ad7d629e1f658f3d6aeeb28602Then I fixed it with a known fix (had to fix the issue):
systemctl stop docker-> a bit long, in the logs :rm -Rf /var/lib/docker/containers/1c71de80ad77d3b39579833bd61b80ae51c313ad7d629e1f658f3d6aeeb28602umount /var/lib/docker/containers/1c71de80ad77d3b39579833bd61b80ae51c313ad7d629e1f658f3d6aeeb28602/mounts/shmokrm -Rf /var/lib/docker/containers/1c71de80ad77d3b39579833bd61b80ae51c313ad7d629e1f658f3d6aeeb28602oksystemctl start dockerSteps to reproduce the issue:
Seems pretty random and kind of rare 😅
Output of
docker version:Output of
docker info:Additional environment details (AWS, VirtualBox, physical, etc.):
VMs with libvirt on a physical hypervisor
The text was updated successfully, but these errors were encountered: