search

containers / podman

Podman: A tool for managing OCI containers and pods.
https://podman.io
Apache License 2.0
23.11k stars 2.36k forks source link

rawhide rootless: unable to cleanup network: [...] failed to unmount NS #4158

Closed edsantiago closed 4 years ago

edsantiago commented 4 years ago

Trying to find the what's-next problem after conmon gets fixed, running into:

$ podman run alpine true
ERRO[0000] unable to cleanup network for container fdf58446caddfa976244af1c2a63e9bf88c57c01f6e27800889acecf5b880b66: "error unmounting network namespace for container fdf58446caddfa976244af1c2a63e9bf88c57c01f6e27800889acecf5b880b66: failed to unmount NS: at /tmp/run-1000/netns/cni-2222cefb-1758-3495-9bd9-2ddd29906625: invalid argument"
Error: error reading container (probably exited) json message: EOF

This IS NOT the git6.1 kernel regression:

$ uname -r
5.4.0-0.rc0.git3.1.fc32.x86_64
$ unshare -rm mount -t tmpfs tmpfs /tmp -o 'context="system_u:object_r:container_file_t:s0:c475,c690"'
$ echo $?
0

It is also not the conmon regression: I'm testing with 2.0.0:

$ rpm -qa|egrep 'podman|conmon|slirp|iptab'|sort
conmon-2.0.0-2.fc32.x86_64
iptables-1.8.3-5.fc31.x86_64
iptables-libs-1.8.3-5.fc31.x86_64
podman-1.6.0-0.41.dev.git5702dd7.fc32.x86_64
podman-manpages-1.5.2-0.59.dev.git7312811.fc32.noarch
podman-tests-1.6.0-0.41.dev.git5702dd7.fc32.x86_64
slirp4netns-0.4.0-22.1.dev.git4e51172.fc32.x86_64
mheon commented 4 years ago

I think there's a fix in https://github.com/containers/libpod/pull/4139

mheon commented 4 years ago

Nevermind, that's just the cleanup network part.

edsantiago commented 4 years ago

With debug:

$ podman --log-level=debug run alpine true
DEBU[0000] using conmon: "/usr/bin/conmon"
DEBU[0000] Initializing boltdb state at /home/fedora/.local/share/containers/storage/libpod/bolt_state.db
DEBU[0000] Using graph driver overlay
DEBU[0000] Using graph root /home/fedora/.local/share/containers/storage
DEBU[0000] Using run root /tmp/run-1000
DEBU[0000] Using static dir /home/fedora/.local/share/containers/storage/libpod
DEBU[0000] Using tmp dir /tmp/run-1000/libpod/tmp
DEBU[0000] Using volume path /home/fedora/.local/share/containers/storage/volumes
DEBU[0000] Set libpod namespace to ""
DEBU[0000] Not configuring container store
DEBU[0000] Initializing event backend journald
WARN[0000] Error initializing configured OCI runtime runc: no valid executable found for OCI runtime runc: invalid argument
DEBU[0000] using runtime "/usr/bin/crun"
DEBU[0000] using conmon: "/usr/bin/conmon"
DEBU[0000] Initializing boltdb state at /home/fedora/.local/share/containers/storage/libpod/bolt_state.db
DEBU[0000] Using graph driver overlay
DEBU[0000] Using graph root /home/fedora/.local/share/containers/storage
DEBU[0000] Using run root /tmp/run-1000
DEBU[0000] Using static dir /home/fedora/.local/share/containers/storage/libpod
DEBU[0000] Using tmp dir /tmp/run-1000/libpod/tmp
DEBU[0000] Using volume path /home/fedora/.local/share/containers/storage/volumes
DEBU[0000] Set libpod namespace to ""
DEBU[0000] [graphdriver] trying provided driver "overlay"
DEBU[0000] overlay: mount_program=/usr/bin/fuse-overlayfs
DEBU[0000] backingFs=extfs, projectQuotaSupported=false, useNativeDiff=false, usingMetacopy=false
DEBU[0000] Initializing event backend journald
WARN[0000] Error initializing configured OCI runtime runc: no valid executable found for OCI runtime runc: invalid argument
DEBU[0000] using runtime "/usr/bin/crun"
WARN[0000] Failed to add podman to systemd sandbox cgroup: dial unix /run/user/0/bus: connect: permission denied
INFO[0000] running as rootless
DEBU[0000] using conmon: "/usr/bin/conmon"
DEBU[0000] Initializing boltdb state at /home/fedora/.local/share/containers/storage/libpod/bolt_state.db
DEBU[0000] Using graph driver overlay
DEBU[0000] Using graph root /home/fedora/.local/share/containers/storage
DEBU[0000] Using run root /tmp/run-1000
DEBU[0000] Using static dir /home/fedora/.local/share/containers/storage/libpod
DEBU[0000] Using tmp dir /tmp/run-1000/libpod/tmp
DEBU[0000] Using volume path /home/fedora/.local/share/containers/storage/volumes
DEBU[0000] Set libpod namespace to ""
DEBU[0000] Initializing event backend journald
WARN[0000] Error initializing configured OCI runtime runc: no valid executable found for OCI runtime runc: invalid argument
DEBU[0000] using runtime "/usr/bin/crun"
DEBU[0000] parsed reference into "[overlay@/home/fedora/.local/share/containers/storage+/tmp/run-1000:overlay.mount_program=/usr/bin/fuse-overlayfs]docker.io/li
brary/alpine:latest"
DEBU[0000] parsed reference into "[overlay@/home/fedora/.local/share/containers/storage+/tmp/run-1000:overlay.mount_program=/usr/bin/fuse-overlayfs]@96176967641
1f082461f9ef46626dd7a2d1e2b2a38e6a44364bcbecf51e66dd4"
DEBU[0000] [graphdriver] trying provided driver "overlay"
DEBU[0000] overlay: mount_program=/usr/bin/fuse-overlayfs
DEBU[0000] backingFs=extfs, projectQuotaSupported=false, useNativeDiff=false, usingMetacopy=false
DEBU[0000] exporting opaque data as blob "sha256:961769676411f082461f9ef46626dd7a2d1e2b2a38e6a44364bcbecf51e66dd4"
DEBU[0000] parsed reference into "[overlay@/home/fedora/.local/share/containers/storage+/tmp/run-1000:overlay.mount_program=/usr/bin/fuse-overlayfs]@96176967641
1f082461f9ef46626dd7a2d1e2b2a38e6a44364bcbecf51e66dd4"
DEBU[0000] exporting opaque data as blob "sha256:961769676411f082461f9ef46626dd7a2d1e2b2a38e6a44364bcbecf51e66dd4"
DEBU[0000] parsed reference into "[overlay@/home/fedora/.local/share/containers/storage+/tmp/run-1000:overlay.mount_program=/usr/bin/fuse-overlayfs]@96176967641
1f082461f9ef46626dd7a2d1e2b2a38e6a44364bcbecf51e66dd4"
DEBU[0000] No hostname set; container's hostname will default to runtime default
DEBU[0000] Using slirp4netns netmode
DEBU[0000] created OCI spec and options for new container
DEBU[0000] Allocated lock 4 for container 1d0a0a62393d4f613f758edf08cd6a70623fb61f96fbb951e945f3c5808820dd
DEBU[0000] parsed reference into "[overlay@/home/fedora/.local/share/containers/storage+/tmp/run-1000:overlay.mount_program=/usr/bin/fuse-overlayfs]@96176967641
1f082461f9ef46626dd7a2d1e2b2a38e6a44364bcbecf51e66dd4"
DEBU[0000] exporting opaque data as blob "sha256:961769676411f082461f9ef46626dd7a2d1e2b2a38e6a44364bcbecf51e66dd4"
DEBU[0000] created container "1d0a0a62393d4f613f758edf08cd6a70623fb61f96fbb951e945f3c5808820dd"
DEBU[0000] container "1d0a0a62393d4f613f758edf08cd6a70623fb61f96fbb951e945f3c5808820dd" has work directory "/home/fedora/.local/share/containers/storage/overlay
-containers/1d0a0a62393d4f613f758edf08cd6a70623fb61f96fbb951e945f3c5808820dd/userdata"
DEBU[0000] container "1d0a0a62393d4f613f758edf08cd6a70623fb61f96fbb951e945f3c5808820dd" has run directory "/tmp/run-1000/overlay-containers/1d0a0a62393d4f613f75
8edf08cd6a70623fb61f96fbb951e945f3c5808820dd/userdata"
DEBU[0000] New container created "1d0a0a62393d4f613f758edf08cd6a70623fb61f96fbb951e945f3c5808820dd"
DEBU[0000] container "1d0a0a62393d4f613f758edf08cd6a70623fb61f96fbb951e945f3c5808820dd" has CgroupParent "user.slice/user-1000.slice/user@1000.service/user.slic
e/libpod-1d0a0a62393d4f613f758edf08cd6a70623fb61f96fbb951e945f3c5808820dd.scope"
DEBU[0000] Not attaching to stdin
DEBU[0000] overlay: mount_data=lowerdir=/home/fedora/.local/share/containers/storage/overlay/l/2FPB2ARMLRRSNW56BDJVXXVDLA,upperdir=/home/fedora/.local/share/con
tainers/storage/overlay/a6f26a9817a25a32e3410856fd86fa54df5deae548d5d7895c869d4efe9b0b19/diff,workdir=/home/fedora/.local/share/containers/storage/overlay/a6f26
a9817a25a32e3410856fd86fa54df5deae548d5d7895c869d4efe9b0b19/work,context="system_u:object_r:container_file_t:s0:c356,c606"
WARN[0000] unable to set namespace: "Error switching to ns /proc/41572/task/41582/ns/net: operation not permitted"
DEBU[0000] Made network namespace at /tmp/run-1000/netns/cni-2a15bb51-25b3-8c14-d2fb-ef34b50759b8 for container 1d0a0a62393d4f613f758edf08cd6a70623fb61f96fbb951
e945f3c5808820dd
DEBU[0000] mounted container "1d0a0a62393d4f613f758edf08cd6a70623fb61f96fbb951e945f3c5808820dd" at "/home/fedora/.local/share/containers/storage/overlay/a6f26a9
817a25a32e3410856fd86fa54df5deae548d5d7895c869d4efe9b0b19/merged"
DEBU[0000] slirp4netns command: /usr/bin/slirp4netns --disable-host-loopback --mtu 65520 --enable-sandbox -c -e 3 -r 4 --netns-type=path /tmp/run-1000/netns/cni
-2a15bb51-25b3-8c14-d2fb-ef34b50759b8 tap0
DEBU[0000] Created root filesystem for container 1d0a0a62393d4f613f758edf08cd6a70623fb61f96fbb951e945f3c5808820dd at /home/fedora/.local/share/containers/storag
e/overlay/a6f26a9817a25a32e3410856fd86fa54df5deae548d5d7895c869d4efe9b0b19/merged
DEBU[0000] /etc/system-fips does not exist on host, not mounting FIPS mode secret
DEBU[0000] Setting CGroups for container 1d0a0a62393d4f613f758edf08cd6a70623fb61f96fbb951e945f3c5808820dd to user.slice:libpod:1d0a0a62393d4f613f758edf08cd6a706
23fb61f96fbb951e945f3c5808820dd
DEBU[0000] Created OCI spec for container 1d0a0a62393d4f613f758edf08cd6a70623fb61f96fbb951e945f3c5808820dd at /home/fedora/.local/share/containers/storage/overl
ay-containers/1d0a0a62393d4f613f758edf08cd6a70623fb61f96fbb951e945f3c5808820dd/userdata/config.json
DEBU[0000] /usr/bin/conmon messages will be logged to syslog
DEBU[0000] running conmon: /usr/bin/conmon               args="[--api-version 1 -s -c 1d0a0a62393d4f613f758edf08cd6a70623fb61f96fbb951e945f3c5808820dd -u 1d0a0a
62393d4f613f758edf08cd6a70623fb61f96fbb951e945f3c5808820dd -r /usr/bin/crun -b /home/fedora/.local/share/containers/storage/overlay-containers/1d0a0a62393d4f613
f758edf08cd6a70623fb61f96fbb951e945f3c5808820dd/userdata -p /tmp/run-1000/overlay-containers/1d0a0a62393d4f613f758edf08cd6a70623fb61f96fbb951e945f3c5808820dd/us
erdata/pidfile -l k8s-file:/home/fedora/.local/share/containers/storage/overlay-containers/1d0a0a62393d4f613f758edf08cd6a70623fb61f96fbb951e945f3c5808820dd/user
data/ctr.log --exit-dir /tmp/run-1000/libpod/tmp/exits --socket-dir-path /tmp/run-1000/libpod/tmp/socket --log-level debug --syslog --conmon-pidfile /tmp/run-10
00/overlay-containers/1d0a0a62393d4f613f758edf08cd6a70623fb61f96fbb951e945f3c5808820dd/userdata/conmon.pid --exit-command /usr/bin/podman --exit-command-arg --r
oot --exit-command-arg /home/fedora/.local/share/containers/storage --exit-command-arg --runroot --exit-command-arg /tmp/run-1000 --exit-command-arg --log-level
 --exit-command-arg debug --exit-command-arg --cgroup-manager --exit-command-arg systemd --exit-command-arg --tmpdir --exit-command-arg /tmp/run-1000/libpod/tmp
 --exit-command-arg --runtime --exit-command-arg crun --exit-command-arg --storage-driver --exit-command-arg overlay --exit-command-arg --storage-opt --exit-com
mand-arg overlay.mount_program=/usr/bin/fuse-overlayfs --exit-command-arg --events-backend --exit-command-arg journald --exit-command-arg container --exit-comma
nd-arg cleanup --exit-command-arg 1d0a0a62393d4f613f758edf08cd6a70623fb61f96fbb951e945f3c5808820dd]"
INFO[0000] Running conmon under slice user.slice and unitName libpod-conmon-1d0a0a62393d4f613f758edf08cd6a70623fb61f96fbb951e945f3c5808820dd.scope
WARN[0000] Failed to add conmon to systemd sandbox cgroup: dial unix /run/user/0/bus: connect: permission denied
[conmon:d]: failed to write to /proc/self/oom_score_adj: Permission denied

DEBU[0000] Received: -1
DEBU[0000] Cleaning up container 1d0a0a62393d4f613f758edf08cd6a70623fb61f96fbb951e945f3c5808820dd
DEBU[0000] Tearing down network namespace at /tmp/run-1000/netns/cni-2a15bb51-25b3-8c14-d2fb-ef34b50759b8 for container 1d0a0a62393d4f613f758edf08cd6a70623fb61f
96fbb951e945f3c5808820dd
ERRO[0000] unable to cleanup network for container 1d0a0a62393d4f613f758edf08cd6a70623fb61f96fbb951e945f3c5808820dd: "error unmounting network namespace for con
tainer 1d0a0a62393d4f613f758edf08cd6a70623fb61f96fbb951e945f3c5808820dd: failed to unmount NS: at /tmp/run-1000/netns/cni-2a15bb51-25b3-8c14-d2fb-ef34b50759b8:
invalid argument"
DEBU[0000] unmounted container "1d0a0a62393d4f613f758edf08cd6a70623fb61f96fbb951e945f3c5808820dd"
DEBU[0000] ExitCode msg: "cannot setns '/tmp/run-1000/netns/cni-2a15bb51-25b3-8c14-d2fb-ef34b50759b8': invalid argument\nsd-bus call: permission denied: oci run
time permission denied error"
ERRO[0000] cannot setns '/tmp/run-1000/netns/cni-2a15bb51-25b3-8c14-d2fb-ef34b50759b8': Invalid argument
sd-bus call: Permission denied: OCI runtime permission denied error

Corresponding output from journalctl:

Oct 01 09:51:47 host-10-0-138-32 conmon[41591]: conmon 1d0a0a62393d4f613f75 <ndebug>: failed to write to /proc/self/oom_score_adj: Permission denied
Oct 01 09:51:47 host-10-0-138-32 conmon[41592]: conmon 1d0a0a62393d4f613f75 <ninfo>: attach sock path: /tmp/run-1000/libpod/tmp/socket/1d0a0a62393d4f613f758edf0
8cd6a70623fb61f96fbb951e945f3c5808820dd/attach
Oct 01 09:51:47 host-10-0-138-32 conmon[41592]: conmon 1d0a0a62393d4f613f75 <ninfo>: addr{sun_family=AF_UNIX, sun_path=/tmp/run-1000/libpod/tmp/socket/1d0a0a623
93d4f613f758edf08cd6a70623fb61f96fbb951e945f3c5808820dd/attach}
Oct 01 09:51:47 host-10-0-138-32 conmon[41592]: conmon 1d0a0a62393d4f613f75 <ninfo>: ctl fifo path: /home/fedora/.local/share/containers/storage/overlay-contain
ers/1d0a0a62393d4f613f758edf08cd6a70623fb61f96fbb951e945f3c5808820dd/userdata/ctl
Oct 01 09:51:47 host-10-0-138-32 conmon[41592]: conmon 1d0a0a62393d4f613f75 <ninfo>: terminal_ctrl_fd: 13
Oct 01 09:51:47 host-10-0-138-32 conmon[41592]: conmon 1d0a0a62393d4f613f75 <error>: Failed to create container: exit status 1
Oct 01 09:51:47 host-10-0-138-32 podman[41592]: 2019-10-01 09:51:47.636917099 -0400 EDT m=+0.126501641 container cleanup 1d0a0a62393d4f613f758edf08cd6a70623fb61
f96fbb951e945f3c5808820dd (image=docker.io/library/alpine:latest, name=hopeful_shaw)
giuseppe commented 4 years ago

fix here: https://github.com/containers/libpod/pull/4157

rhatdan commented 4 years ago

Since that is merged, I am closing.