Systemd Service Ordering Cycle Broke Podman

Ask Fedora
, ,
1

Issue was apparently related to a service ordering cycle error which did not prevent boot but prevented some services from starting properly.

Original Post

Do some labels need to be adjusted for rootless podman to function after updating the selinux-policy from 42.12-1.fc43 to 42.22-1.fc43?

After the policy updated I’ve been unable to run any podman containers as my user due to the following error:

Error: pasta failed with exit code 1:
Failed to mount empty tmpfs for pivot_root(): Permission denied
Failed to sandbox process, exiting

What’s odd is that SELinux Troubleshooter is not throwing any error and after a rollback things seem to just work.

  • container-selinux: 4:2.242.0-1.fc43 - 4:2.245.0-1.fc43
  • selinux-policy: 42.12-1.fc43 - 42.22-1.fc43
  • selinux-policy-targeted: 42.12-1.fc43 - 42.22-1.fc43

Debug output":

INFO[0000] podman filtering at log level debug
DEBU[0000] Called run.PersistentPreRunE(podman run --log-level=debug --rm -it alpine:latest)
INFO[0000] Setting parallel job count to 49
DEBU[0000] Using conmon: "/usr/bin/conmon"
INFO[0000] Using sqlite as database backend
DEBU[0000] Overriding graph root "/var/home/fedora/.local/share/containers/storage" with "/home/fedora/.local/share/containers/storage" from database
DEBU[0000] Using graph driver overlay
DEBU[0000] Using graph root /home/fedora/.local/share/containers/storage
DEBU[0000] Using run root /run/user/1000/containers
DEBU[0000] Using static dir /var/home/fedora/.local/share/containers/storage/libpod
DEBU[0000] Using tmp dir /run/user/1000/libpod/tmp
DEBU[0000] Using volume path /var/home/fedora/.local/share/containers/storage/volumes
DEBU[0000] Using transient store: false
DEBU[0000] [graphdriver] trying provided driver "overlay"
DEBU[0000] Cached value indicated that overlay is supported
DEBU[0000] Cached value indicated that overlay is supported
DEBU[0000] Cached value indicated that metacopy is not being used
DEBU[0000] Cached value indicated that native-diff is usable
DEBU[0000] backingFs=btrfs, projectQuotaSupported=false, useNativeDiff=true, usingMetacopy=false
DEBU[0000] Initializing event backend journald
DEBU[0000] Configured OCI runtime crun-vm initialization failed: no valid executable found for OCI runtime crun-vm: invalid argument
DEBU[0000] Configured OCI runtime crun-wasm initialization failed: no valid executable found for OCI runtime crun-wasm: invalid argument
DEBU[0000] Configured OCI runtime runj initialization failed: no valid executable found for OCI runtime runj: invalid argument
DEBU[0000] Configured OCI runtime kata initialization failed: no valid executable found for OCI runtime kata: invalid argument
DEBU[0000] Configured OCI runtime runsc initialization failed: no valid executable found for OCI runtime runsc: invalid argument
DEBU[0000] Configured OCI runtime youki initialization failed: no valid executable found for OCI runtime youki: invalid argument
DEBU[0000] Configured OCI runtime ocijail initialization failed: no valid executable found for OCI runtime ocijail: invalid argument
DEBU[0000] Configured OCI runtime krun initialization failed: no valid executable found for OCI runtime krun: invalid argument
DEBU[0000] Using OCI runtime "/usr/bin/crun"
DEBU[0000] Pulling image alpine:latest (policy: missing)
DEBU[0000] Looking up image "alpine:latest" in local containers storage
DEBU[0000] Normalized platform linux/amd64 to {amd64 linux  [] }
DEBU[0000] Loading registries configuration "/etc/containers/registries.conf"
DEBU[0000] Loading registries configuration "/etc/containers/registries.conf.d/000-shortnames.conf"
DEBU[0000] Trying "docker.io/library/alpine:latest" ...
DEBU[0000] parsed reference into "[overlay@/home/fedora/.local/share/containers/storage+/run/user/1000/containers]@a40c03cbb81c59bfb0e0887ab0b1859727075da7b9cc576a1cec2c771f38c5fb"
DEBU[0000] Found image "alpine:latest" as "docker.io/library/alpine:latest" in local containers storage
DEBU[0000] Found image "alpine:latest" as "docker.io/library/alpine:latest" in local containers storage ([overlay@/home/fedora/.local/share/containers/storage+/run/user/1000/containers]@a40c03cbb81c59bfb0e0887ab0b1859727075da7b9cc576a1cec2c771f38c5fb)
DEBU[0000] exporting opaque data as blob "sha256:a40c03cbb81c59bfb0e0887ab0b1859727075da7b9cc576a1cec2c771f38c5fb"
DEBU[0000] Looking up image "alpine:latest" in local containers storage
DEBU[0000] Normalized platform linux/amd64 to {amd64 linux  [] }
DEBU[0000] Trying "docker.io/library/alpine:latest" ...
DEBU[0000] parsed reference into "[overlay@/home/fedora/.local/share/containers/storage+/run/user/1000/containers]@a40c03cbb81c59bfb0e0887ab0b1859727075da7b9cc576a1cec2c771f38c5fb"
DEBU[0000] Found image "alpine:latest" as "docker.io/library/alpine:latest" in local containers storage
DEBU[0000] Found image "alpine:latest" as "docker.io/library/alpine:latest" in local containers storage ([overlay@/home/fedora/.local/share/containers/storage+/run/user/1000/containers]@a40c03cbb81c59bfb0e0887ab0b1859727075da7b9cc576a1cec2c771f38c5fb)
DEBU[0000] exporting opaque data as blob "sha256:a40c03cbb81c59bfb0e0887ab0b1859727075da7b9cc576a1cec2c771f38c5fb"
DEBU[0000] Inspecting image a40c03cbb81c59bfb0e0887ab0b1859727075da7b9cc576a1cec2c771f38c5fb
DEBU[0000] exporting opaque data as blob "sha256:a40c03cbb81c59bfb0e0887ab0b1859727075da7b9cc576a1cec2c771f38c5fb"
DEBU[0000] Inspecting image a40c03cbb81c59bfb0e0887ab0b1859727075da7b9cc576a1cec2c771f38c5fb
DEBU[0000] Inspecting image a40c03cbb81c59bfb0e0887ab0b1859727075da7b9cc576a1cec2c771f38c5fb
DEBU[0000] Inspecting image a40c03cbb81c59bfb0e0887ab0b1859727075da7b9cc576a1cec2c771f38c5fb
DEBU[0000] using systemd mode: false
DEBU[0000] No hostname set; container's hostname will default to runtime default
DEBU[0000] Loading seccomp profile from "/usr/share/containers/seccomp.json"
DEBU[0000] Allocated lock 0 for container 4eef715b4dddd20f3dc85755a1214b96da1123a07ce15c21f6b86b43fa83e9ba
DEBU[0000] exporting opaque data as blob "sha256:a40c03cbb81c59bfb0e0887ab0b1859727075da7b9cc576a1cec2c771f38c5fb"
DEBU[0000] Cached value indicated that idmapped mounts for overlay are not supported
DEBU[0000] Check for idmapped mounts support
DEBU[0000] Created container "4eef715b4dddd20f3dc85755a1214b96da1123a07ce15c21f6b86b43fa83e9ba"
DEBU[0000] Container "4eef715b4dddd20f3dc85755a1214b96da1123a07ce15c21f6b86b43fa83e9ba" has work directory "/home/fedora/.local/share/containers/storage/overlay-containers/4eef715b4dddd20f3dc85755a1214b96da1123a07ce15c21f6b86b43fa83e9ba/userdata"
DEBU[0000] Container "4eef715b4dddd20f3dc85755a1214b96da1123a07ce15c21f6b86b43fa83e9ba" has run directory "/run/user/1000/containers/overlay-containers/4eef715b4dddd20f3dc85755a1214b96da1123a07ce15c21f6b86b43fa83e9ba/userdata"
DEBU[0000] Handling terminal attach
INFO[0000] Received shutdown.Stop(), terminating!        PID=12213
DEBU[0000] Enabling signal proxying
DEBU[0000] Cached value indicated that volatile is being used
DEBU[0000] overlay: mount_data=lowerdir=/home/fedora/.local/share/containers/storage/overlay/l/XKFVWXV5AMM5IRPXU7MKBHR2PF,upperdir=/home/fedora/.local/share/containers/storage/overlay/004eadc55e6d4d581f50d67a9cc79b01deffcd0b9211f98cf727cf826dc5c83d/diff,workdir=/home/fedora/.local/share/containers/storage/overlay/004eadc55e6d4d581f50d67a9cc79b01deffcd0b9211f98cf727cf826dc5c83d/work,userxattr,volatile,context="system_u:object_r:container_file_t:s0:c513,c795"
DEBU[0000] Made network namespace at /run/user/1000/netns/netns-98afa6e1-785a-4bc2-e19e-c8107c7d1e5c for container 4eef715b4dddd20f3dc85755a1214b96da1123a07ce15c21f6b86b43fa83e9ba
DEBU[0000] pasta arguments: --config-net --dns-forward 169.254.1.1 -t none -u none -T none -U none --no-map-gw --quiet --netns /run/user/1000/netns/netns-98afa6e1-785a-4bc2-e19e-c8107c7d1e5c --map-guest-addr 169.254.1.2
DEBU[0000] Mounted container "4eef715b4dddd20f3dc85755a1214b96da1123a07ce15c21f6b86b43fa83e9ba" at "/home/fedora/.local/share/containers/storage/overlay/004eadc55e6d4d581f50d67a9cc79b01deffcd0b9211f98cf727cf826dc5c83d/merged"
DEBU[0000] Created root filesystem for container 4eef715b4dddd20f3dc85755a1214b96da1123a07ce15c21f6b86b43fa83e9ba at /var/home/fedora/.local/share/containers/storage/overlay/004eadc55e6d4d581f50d67a9cc79b01deffcd0b9211f98cf727cf826dc5c83d/merged
DEBU[0000] Unmounted container "4eef715b4dddd20f3dc85755a1214b96da1123a07ce15c21f6b86b43fa83e9ba"
DEBU[0000] Network is already cleaned up, skipping...
DEBU[0000] Cleaning up container 4eef715b4dddd20f3dc85755a1214b96da1123a07ce15c21f6b86b43fa83e9ba
DEBU[0000] Network is already cleaned up, skipping...
DEBU[0000] Container 4eef715b4dddd20f3dc85755a1214b96da1123a07ce15c21f6b86b43fa83e9ba storage is already unmounted, skipping...
DEBU[0000] Removing container 4eef715b4dddd20f3dc85755a1214b96da1123a07ce15c21f6b86b43fa83e9ba
DEBU[0000] Cleaning up container 4eef715b4dddd20f3dc85755a1214b96da1123a07ce15c21f6b86b43fa83e9ba
DEBU[0000] Network is already cleaned up, skipping...
DEBU[0000] Container 4eef715b4dddd20f3dc85755a1214b96da1123a07ce15c21f6b86b43fa83e9ba storage is already unmounted, skipping...
DEBU[0000] Removing all exec sessions for container 4eef715b4dddd20f3dc85755a1214b96da1123a07ce15c21f6b86b43fa83e9ba
DEBU[0000] Container 4eef715b4dddd20f3dc85755a1214b96da1123a07ce15c21f6b86b43fa83e9ba storage is already unmounted, skipping...
DEBU[0000] Temp dir already cleaned up
DEBU[0000] ExitCode msg: "pasta failed with exit code 1:\nfailed to mount empty tmpfs for pivot_root(): permission denied\nfailed to sandbox process, exiting\n"
Error: pasta failed with exit code 1:
Failed to mount empty tmpfs for pivot_root(): Permission denied
Failed to sandbox process, exiting
3

Can you boot once and then just log in and provoke this problem, and then immediately get the output of journalctl --no-hostname --boot=0 ? That way we would have a “dedicated journal” that only contains the data that is interesting, and nothing more. Feel free to remove any IP address or MAC address or UUID etc if you consider them private.

Please do this once with the broken state (which I assume is up to date as of today) and once in the rolled back state that worked out. Please provide this type of journal for both (broken and working state), each a dedicated boot. Also, please document the exact time you attempt the action (run container), and let us know for both boots.

Please also let us know the output of cat /proc/sys/kernel/tainted.

4

Looks like this might have been related to a service ordering cycle issue on my system. It didn’t lock up the boot, but this morning it prevented NetworkManager from starting putting it on my radar. Fixing that, updating the selinux policy, and rebooting I’m not having any other issues.

1 Like