Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Downgrade the default mount flag for bind mounts from 'rw' to 'ro' if the source is mounted read-only #4061

Closed
debarshiray opened this issue Sep 19, 2019 · 48 comments
Assignees
Labels
do-not-close kind/bug Categorizes issue or PR as related to a bug. locked - please file new issue/PR Assist humans wanting to comment on an old issue or PR with locked comments. stale-issue

Comments

@debarshiray
Copy link
Member

Is this a BUG REPORT or FEATURE REQUEST? (leave only one on its own line)

/kind bug

Description

I updated to the new Podman 1.6.0 build for Fedora 30, rebooted, wiped out ~/.local/share/containers and ~/.config/containers, rebooted again, and created a new Toolbox container. The multiple reboots were to ensure a clean slate.

However it refuses to start. It looks Podman is somehow trying to use crun as the OCI runtime, even though this is a Cgroups v1 system, and of course there's no crun installed.

podman start when called by toolbox enter fails as:

$ toolbox --verbose enter
toolbox: resolved absolute path for /usr/bin/toolbox to /usr/bin/toolbox
toolbox: checking if /etc/subgid and /etc/subuid have entries for user rishi
toolbox: TOOLBOX_PATH is /usr/bin/toolbox
toolbox: checking if 'podman system migrate' exists
WARN[0000] Error initializing configured OCI runtime crun: no valid executable found for OCI runtime crun: invalid argument 
toolbox: migration not needed: 1.6.0-rc1 is unchanged
toolbox: Fedora generational core is f30
toolbox: base image is fedora-toolbox:30
toolbox: container is fedora-toolbox-30
toolbox: checking if container fedora-toolbox-30 exists
WARN[0000] Error initializing configured OCI runtime crun: no valid executable found for OCI runtime crun: invalid argument 
toolbox: calling org.freedesktop.Flatpak.SessionHelper.RequestSession
toolbox: starting container fedora-toolbox-30
WARN[0000] Error initializing configured OCI runtime crun: no valid executable found for OCI runtime crun: invalid argument 
toolbox: /etc/profile.d/toolbox.sh already mounted in container fedora-toolbox-30
WARN[0000] Error initializing configured OCI runtime crun: no valid executable found for OCI runtime crun: invalid argument 
Error: unable to start container "fedora-toolbox-30": container_linux.go:346: starting container process caused "process_linux.go:446: container init caused \"rootfs_linux.go:58: mounting \\\"/usr\\\" to rootfs \\\"/var/home/rishi/.local/share/containers/storage/overlay/8fd8c139b64d5f3fe9e52d87e4bb416193713234f96041cde0ad84bf5d5283f9/merged\\\" at \\\"/var/home/rishi/.local/share/containers/storage/overlay/8fd8c139b64d5f3fe9e52d87e4bb416193713234f96041cde0ad84bf5d5283f9/merged/run/host/usr\\\" caused \\\"operation not permitted\\\"\"": OCI runtime permission denied error
toolbox: failed to start container fedora-toolbox-30

A subsequent attempt at calling podman start directly fails as:

$ podman start --log-level debug fedora-toolbox-30
WARN[0000] Error initializing configured OCI runtime crun: no valid executable found for OCI runtime crun: invalid argument 
INFO[0000] running as rootless                          
DEBU[0000] using conmon: "/usr/libexec/podman/conmon"   
DEBU[0000] Initializing boltdb state at /var/home/rishi/.local/share/containers/storage/libpod/bolt_state.db 
DEBU[0000] Using graph driver overlay                   
DEBU[0000] Using graph root /var/home/rishi/.local/share/containers/storage 
DEBU[0000] Using run root /run/user/1000                
DEBU[0000] Using static dir /var/home/rishi/.local/share/containers/storage/libpod 
DEBU[0000] Using tmp dir /run/user/1000/libpod/tmp      
DEBU[0000] Using volume path /var/home/rishi/.local/share/containers/storage/volumes 
DEBU[0000] Set libpod namespace to ""                   
DEBU[0000] Initializing event backend journald          
DEBU[0000] using runtime "/usr/bin/runc"                
WARN[0000] Error initializing configured OCI runtime crun: no valid executable found for OCI runtime crun: invalid argument 
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] overlay: mount_data=lowerdir=/var/home/rishi/.local/share/containers/storage/overlay/l/CCB5USKVF7HU5LTK6X2NMAXUUX:/var/home/rishi/.local/share/containers/storage/overlay/l/7AG2BWQUTJCWHNCZ6L7LFR6BUM,upperdir=/var/home/rishi/.local/share/containers/storage/overlay/8fd8c139b64d5f3fe9e52d87e4bb416193713234f96041cde0ad84bf5d5283f9/diff,workdir=/var/home/rishi/.local/share/containers/storage/overlay/8fd8c139b64d5f3fe9e52d87e4bb416193713234f96041cde0ad84bf5d5283f9/work,context="system_u:object_r:container_file_t:s0:c67,c295" 
DEBU[0000] mounted container "8fe5ac70601d51c1ddd5639bff6b7486db5af8a1590b1a691aaa99446b6a0c45" at "/var/home/rishi/.local/share/containers/storage/overlay/8fd8c139b64d5f3fe9e52d87e4bb416193713234f96041cde0ad84bf5d5283f9/merged" 
DEBU[0000] Created root filesystem for container 8fe5ac70601d51c1ddd5639bff6b7486db5af8a1590b1a691aaa99446b6a0c45 at /var/home/rishi/.local/share/containers/storage/overlay/8fd8c139b64d5f3fe9e52d87e4bb416193713234f96041cde0ad84bf5d5283f9/merged 
DEBU[0000] /etc/system-fips does not exist on host, not mounting FIPS mode secret 
DEBU[0000] set root propagation to "rslave"             
DEBU[0000] Created OCI spec for container 8fe5ac70601d51c1ddd5639bff6b7486db5af8a1590b1a691aaa99446b6a0c45 at /var/home/rishi/.local/share/containers/storage/overlay-containers/8fe5ac70601d51c1ddd5639bff6b7486db5af8a1590b1a691aaa99446b6a0c45/userdata/config.json 
DEBU[0000] /usr/libexec/podman/conmon messages will be logged to syslog 
DEBU[0000] running conmon: /usr/libexec/podman/conmon    args="[--api-version 1 -c 8fe5ac70601d51c1ddd5639bff6b7486db5af8a1590b1a691aaa99446b6a0c45 -u 8fe5ac70601d51c1ddd5639bff6b7486db5af8a1590b1a691aaa99446b6a0c45 -r /usr/bin/runc -b /var/home/rishi/.local/share/containers/storage/overlay-containers/8fe5ac70601d51c1ddd5639bff6b7486db5af8a1590b1a691aaa99446b6a0c45/userdata -p /run/user/1000/overlay-containers/8fe5ac70601d51c1ddd5639bff6b7486db5af8a1590b1a691aaa99446b6a0c45/userdata/pidfile -l k8s-file:/var/home/rishi/.local/share/containers/storage/overlay-containers/8fe5ac70601d51c1ddd5639bff6b7486db5af8a1590b1a691aaa99446b6a0c45/userdata/ctr.log --exit-dir /run/user/1000/libpod/tmp/exits --socket-dir-path /run/user/1000/libpod/tmp/socket --log-level debug --syslog --conmon-pidfile /run/user/1000/overlay-containers/8fe5ac70601d51c1ddd5639bff6b7486db5af8a1590b1a691aaa99446b6a0c45/userdata/conmon.pid --exit-command /usr/bin/podman --exit-command-arg --root --exit-command-arg /var/home/rishi/.local/share/containers/storage --exit-command-arg --runroot --exit-command-arg /run/user/1000 --exit-command-arg --log-level --exit-command-arg error --exit-command-arg --cgroup-manager --exit-command-arg cgroupfs --exit-command-arg --tmpdir --exit-command-arg /run/user/1000/libpod/tmp --exit-command-arg --runtime --exit-command-arg runc --exit-command-arg --storage-driver --exit-command-arg overlay --exit-command-arg --storage-opt --exit-command-arg overlay.mount_program=/usr/bin/fuse-overlayfs --exit-command-arg --events-backend --exit-command-arg journald --exit-command-arg container --exit-command-arg cleanup --exit-command-arg 8fe5ac70601d51c1ddd5639bff6b7486db5af8a1590b1a691aaa99446b6a0c45]"
DEBU[0000] disabling SD notify                          
[conmon:d]: failed to write to /proc/self/oom_score_adj: Permission denied

DEBU[0000] Cleaning up container 8fe5ac70601d51c1ddd5639bff6b7486db5af8a1590b1a691aaa99446b6a0c45 
DEBU[0000] Network is already cleaned up, skipping...   
DEBU[0000] unmounted container "8fe5ac70601d51c1ddd5639bff6b7486db5af8a1590b1a691aaa99446b6a0c45" 
ERRO[0000] unable to start container "fedora-toolbox-30": error reading container (probably exited) json message: EOF

The second podman start puts this in the journal:

Sep 19 19:26:26 bollard conmon[7863]: conmon 8fe5ac70601d51c1ddd5 <ndebug>: failed to write to /proc/self/oom_score_adj: Permission denied
Sep 19 19:26:26 bollard conmon[7864]: conmon 8fe5ac70601d51c1ddd5 <ninfo>: attach sock path: /run/user/1000/libpod/tmp/socket/8fe5ac70601d51c1ddd5639bff6b7486db5af8a1590b1a691aaa99446b6a0c45/attach
Sep 19 19:26:26 bollard conmon[7864]: conmon 8fe5ac70601d51c1ddd5 <ninfo>: addr{sun_family=AF_UNIX, sun_path=/run/user/1000/libpod/tmp/socket/8fe5ac70601d51c1ddd5639bff6b7486db5af8a1590b1a691aaa99446b6a0c45/attach}
Sep 19 19:26:26 bollard conmon[7864]: conmon 8fe5ac70601d51c1ddd5 <ninfo>: ctl fifo path: /var/home/rishi/.local/share/containers/storage/overlay-containers/8fe5ac70601d51c1ddd5639bff6b7486db5af8a1590b1a691aaa99446b6a0c45/userdata/ctl
Sep 19 19:26:26 bollard conmon[7864]: conmon 8fe5ac70601d51c1ddd5 <error>: Failed to mkfifo at /var/home/rishi/.local/share/containers/storage/overlay-containers/8fe5ac70601d51c1ddd5639bff6b7486db5af8a1590b1a691aaa99446b6a0c45/userdata/ctl: File exists
Sep 19 19:26:26 bollard podman[7864]: 2019-09-19 19:26:26.446030489 +0200 CEST m=+0.046905001 container cleanup 8fe5ac70601d51c1ddd5639bff6b7486db5af8a1590b1a691aaa99446b6a0c45 (image=registry.fedoraproject.org/f30/fedora-toolbox:30, name=fedora-toolbox-30)

The auto-created ~/.config/containers/libpod.conf looks like:

volume_path = "/var/home/rishi/.local/share/containers/storage/volumes"
image_default_transport = "docker://"
runtime = "runc"
runtime_supports_json = ["crun", "runc"]
runtime_supports_nocgroups = ["crun"]
conmon_path = ["/usr/libexec/podman/conmon", "/usr/local/libexec/podman/conmon", "/usr/local/lib/podman/conmon", "/usr/bin/conmon", "/usr/sbin/conmon", "/usr/local/bin/conmon", "/usr/local/sbin/conmon", "/run/current-system/sw/bin/conmon"]
conmon_env_vars = ["PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin"]
cgroup_manager = "cgroupfs"
init_path = ""
static_dir = "/var/home/rishi/.local/share/containers/storage/libpod"
tmp_dir = "/run/user/1000/libpod/tmp"
max_log_size = -1
no_pivot_root = false
cni_config_dir = "/etc/cni/net.d/"
cni_plugin_dir = ["/usr/libexec/cni", "/usr/lib/cni", "/usr/local/lib/cni", "/opt/cni/bin"]
infra_image = "k8s.gcr.io/pause:3.1"
infra_command = "/pause"
enable_port_reservation = true
label = true
network_cmd_path = ""
num_locks = 2048
lock_type = "shm"
events_logger = "journald"
-events_logfile_path = ""
detach_keys = "ctrl-p,ctrl-q"
SDNotify = true

[runtimes]
  crun = ["/usr/bin/crun", "/usr/local/bin/crun"]
  runc = ["/usr/bin/runc", "/usr/sbin/runc", "/usr/local/bin/runc", "/usr/local/sbin/runc", "/sbin/runc", "/bin/runc", "/usr/lib/cri-o-runc/sbin/runc", "/run/current-system/sw/bin/runc"]

Additional information you deem important (e.g. issue happens only occasionally):

100% reliably reproducible.

Output of podman version:

WARN[0000] Error initializing configured OCI runtime crun: no valid executable found for OCI runtime crun: invalid argument 
Version:            1.6.0-rc1
RemoteAPI Version:  1
Go Version:         go1.12.9
OS/Arch:            linux/amd64

Output of podman info --debug:

WARN[0000] Error initializing configured OCI runtime crun: no valid executable found for OCI runtime crun: invalid argument 
debug:
  compiler: gc
  git commit: ""
  go version: go1.12.9
  podman version: 1.6.0-rc1
host:
  BuildahVersion: 1.11.2
  Conmon:
    package: podman-1.6.0-2.fc30.x86_64
    path: /usr/libexec/podman/conmon
    version: 'conmon version 2.0.0, commit: 2232e62e6fad8623734b385548274a92497cd1b4-dirty'
  Distribution:
    distribution: fedora
    version: "30"
  MemFree: 12669358080
  MemTotal: 16529977344
  OCIRuntime:
    package: runc-1.0.0-93.dev.gitb9b6cc6.fc30.x86_64
    path: /usr/bin/runc
    version: |-
      runc version 1.0.0-rc8+dev
      commit: e3b4c1108f7d1bf0d09ab612ea09927d9b59b4e3
      spec: 1.0.1-dev
  SwapFree: 8414818304
  SwapTotal: 8414818304
  arch: amd64
  cpus: 4
  eventlogger: journald
  hostname: bollard
  kernel: 5.2.15-200.fc30.x86_64
  os: linux
  rootless: true
  slirp4netns:
    Executable: /usr/bin/slirp4netns
    Package: slirp4netns-0.4.0-4.git19d199a.fc30.x86_64
    Version: |-
      slirp4netns version 0.4.0-beta.2
      commit: 19d199a6ca424fcf9516320a327cedad85cf4dfb
  uptime: 4m 29.65s
registries:
  blocked: null
  insecure: null
  search:
  - docker.io
  - registry.fedoraproject.org
  - quay.io
  - registry.access.redhat.com
  - registry.centos.org
store:
  ConfigFile: /var/home/rishi/.config/containers/storage.conf
  ContainerStore:
    number: 1
  GraphDriverName: overlay
  GraphOptions:
    overlay.mount_program:
      Executable: /usr/bin/fuse-overlayfs
      Package: fuse-overlayfs-0.6.2-2.git67a4afe.fc30.x86_64
      Version: |-
        fuse-overlayfs: version 0.6.2
        FUSE library version 3.6.2
        using FUSE kernel interface version 7.29
  GraphRoot: /var/home/rishi/.local/share/containers/storage
  GraphStatus:
    Backing Filesystem: extfs
    Native Overlay Diff: "false"
    Supports d_type: "true"
    Using metacopy: "false"
  ImageStore:
    number: 1
  RunRoot: /run/user/1000
  VolumePath: /var/home/rishi/.local/share/containers/storage/volumes

Package info (e.g. output of rpm -q podman or apt list podman):

podman-1.6.0-2.fc30.x86_64

Additional environment details (AWS, VirtualBox, physical, etc.):

This is happening on Silverblue 30, but not on Workstation 29.

@openshift-ci-robot openshift-ci-robot added the kind/bug Categorizes issue or PR as related to a bug. label Sep 19, 2019
@TomSweeneyRedHat
Copy link
Member

@debarshiray as a quick test, can you try this? (Assuming you've a /usr/bin/runc)

podman --runtime=/usr/bin/runc start --log-level debug fedora-toolbox-30

@debarshiray
Copy link
Member Author

$ podman --runtime=/usr/bin/runc start --log-level debug fedora-toolbox-30
WARN[0000] Error initializing configured OCI runtime crun: no valid executable found for OCI runtime crun: invalid argument 
INFO[0000] running as rootless                          
DEBU[0000] using conmon: "/usr/libexec/podman/conmon"   
DEBU[0000] Initializing boltdb state at /var/home/rishi/.local/share/containers/storage/libpod/bolt_state.db 
DEBU[0000] Using graph driver overlay                   
DEBU[0000] Using graph root /var/home/rishi/.local/share/containers/storage 
DEBU[0000] Using run root /run/user/1000                
DEBU[0000] Using static dir /var/home/rishi/.local/share/containers/storage/libpod 
DEBU[0000] Using tmp dir /run/user/1000/libpod/tmp      
DEBU[0000] Using volume path /var/home/rishi/.local/share/containers/storage/volumes 
DEBU[0000] Set libpod namespace to ""                   
DEBU[0000] Initializing event backend journald          
DEBU[0000] using runtime "/usr/bin/runc"                
WARN[0000] Error initializing configured OCI runtime crun: no valid executable found for OCI runtime crun: invalid argument 
DEBU[0000] using runtime "/usr/bin/runc"                
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] overlay: mount_data=lowerdir=/var/home/rishi/.local/share/containers/storage/overlay/l/CCB5USKVF7HU5LTK6X2NMAXUUX:/var/home/rishi/.local/share/containers/storage/overlay/l/7AG2BWQUTJCWHNCZ6L7LFR6BUM,upperdir=/var/home/rishi/.local/share/containers/storage/overlay/8fd8c139b64d5f3fe9e52d87e4bb416193713234f96041cde0ad84bf5d5283f9/diff,workdir=/var/home/rishi/.local/share/containers/storage/overlay/8fd8c139b64d5f3fe9e52d87e4bb416193713234f96041cde0ad84bf5d5283f9/work,context="system_u:object_r:container_file_t:s0:c67,c295" 
DEBU[0000] mounted container "8fe5ac70601d51c1ddd5639bff6b7486db5af8a1590b1a691aaa99446b6a0c45" at "/var/home/rishi/.local/share/containers/storage/overlay/8fd8c139b64d5f3fe9e52d87e4bb416193713234f96041cde0ad84bf5d5283f9/merged" 
DEBU[0000] Created root filesystem for container 8fe5ac70601d51c1ddd5639bff6b7486db5af8a1590b1a691aaa99446b6a0c45 at /var/home/rishi/.local/share/containers/storage/overlay/8fd8c139b64d5f3fe9e52d87e4bb416193713234f96041cde0ad84bf5d5283f9/merged 
DEBU[0000] /etc/system-fips does not exist on host, not mounting FIPS mode secret 
DEBU[0000] set root propagation to "rslave"             
DEBU[0000] Created OCI spec for container 8fe5ac70601d51c1ddd5639bff6b7486db5af8a1590b1a691aaa99446b6a0c45 at /var/home/rishi/.local/share/containers/storage/overlay-containers/8fe5ac70601d51c1ddd5639bff6b7486db5af8a1590b1a691aaa99446b6a0c45/userdata/config.json 
DEBU[0000] /usr/libexec/podman/conmon messages will be logged to syslog 
DEBU[0000] running conmon: /usr/libexec/podman/conmon    args="[--api-version 1 -c 8fe5ac70601d51c1ddd5639bff6b7486db5af8a1590b1a691aaa99446b6a0c45 -u 8fe5ac70601d51c1ddd5639bff6b7486db5af8a1590b1a691aaa99446b6a0c45 -r /usr/bin/runc -b /var/home/rishi/.local/share/containers/storage/overlay-containers/8fe5ac70601d51c1ddd5639bff6b7486db5af8a1590b1a691aaa99446b6a0c45/userdata -p /run/user/1000/overlay-containers/8fe5ac70601d51c1ddd5639bff6b7486db5af8a1590b1a691aaa99446b6a0c45/userdata/pidfile -l k8s-file:/var/home/rishi/.local/share/containers/storage/overlay-containers/8fe5ac70601d51c1ddd5639bff6b7486db5af8a1590b1a691aaa99446b6a0c45/userdata/ctr.log --exit-dir /run/user/1000/libpod/tmp/exits --socket-dir-path /run/user/1000/libpod/tmp/socket --log-level debug --syslog --conmon-pidfile /run/user/1000/overlay-containers/8fe5ac70601d51c1ddd5639bff6b7486db5af8a1590b1a691aaa99446b6a0c45/userdata/conmon.pid --exit-command /usr/bin/podman --exit-command-arg --root --exit-command-arg /var/home/rishi/.local/share/containers/storage --exit-command-arg --runroot --exit-command-arg /run/user/1000 --exit-command-arg --log-level --exit-command-arg error --exit-command-arg --cgroup-manager --exit-command-arg cgroupfs --exit-command-arg --tmpdir --exit-command-arg /run/user/1000/libpod/tmp --exit-command-arg --runtime --exit-command-arg runc --exit-command-arg --storage-driver --exit-command-arg overlay --exit-command-arg --storage-opt --exit-command-arg overlay.mount_program=/usr/bin/fuse-overlayfs --exit-command-arg --events-backend --exit-command-arg journald --exit-command-arg container --exit-command-arg cleanup --exit-command-arg 8fe5ac70601d51c1ddd5639bff6b7486db5af8a1590b1a691aaa99446b6a0c45]"
DEBU[0000] disabling SD notify                          
[conmon:d]: failed to write to /proc/self/oom_score_adj: Permission denied

DEBU[0000] Cleaning up container 8fe5ac70601d51c1ddd5639bff6b7486db5af8a1590b1a691aaa99446b6a0c45 
DEBU[0000] Network is already cleaned up, skipping...   
DEBU[0000] unmounted container "8fe5ac70601d51c1ddd5639bff6b7486db5af8a1590b1a691aaa99446b6a0c45" 
ERRO[0000] unable to start container "fedora-toolbox-30": error reading container (probably exited) json message: EOF 

I am puzzled why I am not hitting this on legacy Workstation 29. I cannot spot any delta in the RPMs for F30 and F29 that can justify this.

@debarshiray
Copy link
Member Author

$ which runc
/usr/bin/runc

@debarshiray
Copy link
Member Author

Aha, I am getting the crun warnings on Workstation 29 too:

WARN[0000] Error initializing configured OCI runtime crun: no valid executable found for OCI runtime crun: invalid argument 

However, for some reason podman start doesn't fail and things appear to work. I wonder if there's a timing problem or race somewhere. The failing Silverblue system has an SSD while the working Workstation has a HDD.

@rhatdan
Copy link
Member

rhatdan commented Sep 20, 2019

Why are these warnings showing up? The default way of running podman is not supposed to show warnings? Basically podman is going through the libpod.conf file looking for the OCI Runtimes and printing out that a runtime is not installed, even if it is not using the runtime. Usually no one sees these messages unless you are running with a --log-level=debug. At least this is the way I believe it should be working. @mheon WDYT?

@mheon
Copy link
Member

mheon commented Sep 20, 2019

Yeah I'm really curious here - either the default logging level changed (I don't remember merging any PRs to do it, but maybe it was Go toolchain stuff?), or something weird is going on.

@mheon
Copy link
Member

mheon commented Sep 20, 2019

I think part of the solution here, though, is to make removing conmon files an unconditional part of start()

@mheon
Copy link
Member

mheon commented Sep 20, 2019

#4065 may help here - I think a lot of the problem is lingering Conmon files. I'm not sure why they're lingering, though. Cleanup processes might not be running?

@debarshiray
Copy link
Member Author

#4065 now broke starting containers on my Workstation 29 laptop, albeit in an entirely different way.

$ /opt/bin/podman --log-level debug start fedora-toolbox-29
ERRO[0000] could not get runtime: eventer creation: No support for journald logging

@rhatdan
Copy link
Member

rhatdan commented Sep 20, 2019

@giuseppe PTAL

mheon added a commit to mheon/libpod that referenced this issue Sep 20, 2019
We've been seeing a lot of issues (ref: containers#4061, but there are
others) where Podman hiccups on trying to start a container,
because some temporary files have been retained and Conmon will
not overwrite them.

If we're calling start() we can safely assume that we really want
those files gone so the container starts without error, so invoke
the cleanup routine. It's relatively cheap (four file removes) so
it shouldn't hurt us that much.

Also contains a small simplification to the removeConmonFiles
logic - we don't need to stat-then-remove when ignoring ENOENT is
fine.

Signed-off-by: Matthew Heon <[email protected]>
@debarshiray
Copy link
Member Author

With the updated #4065, my Workstation 29 is back to being as it used to be.

However, podman start continues to be broken on my Silverblue 30 with the same spew from podman start about not being able to mount /usr:

Error: unable to start container "fedora-toolbox-30": container_linux.go:346: starting container process caused "process_linux.go:446: container init caused \"rootfs_linux.go:58: mounting \\\"/usr\\\" to rootfs \\\"/var/home/rishi/.local/share/containers/storage/overlay/25d8867e47b79ef5a590bb748eb0feecd6fbdf12de930d1114f531218c0fac45/merged\\\" at \\\"/var/home/rishi/.local/share/containers/storage/overlay/25d8867e47b79ef5a590bb748eb0feecd6fbdf12de930d1114f531218c0fac45/merged/run/host/usr\\\" caused \\\"operation not permitted\\\"\"": OCI runtime permission denied error

As before, the first failed podman start doesn't put anything in the journal, but the second attempt puts a slightly different set of logs than before. It's no longer about a failed mkfifo but Failed to create container: exit status 1:

Sep 20 17:11:31 bollard conmon[8799]: conmon 7f293d9029e04fba2793 <ndebug>: failed to write to /proc/self/oom_score_adj: Permission denied
Sep 20 17:11:31 bollard conmon[8800]: conmon 7f293d9029e04fba2793 <ninfo>: attach sock path: /run/user/1000/libpod/tmp/socket/7f293d9029e04fba27934561472b3293754e5baf22cb4d950b6eafdb87255aac/attach
Sep 20 17:11:31 bollard conmon[8800]: conmon 7f293d9029e04fba2793 <ninfo>: addr{sun_family=AF_UNIX, sun_path=/run/user/1000/libpod/tmp/socket/7f293d9029e04fba27934561472b3293754e5baf22cb4d950b6eafdb87255aac/attach}
Sep 20 17:11:31 bollard conmon[8800]: conmon 7f293d9029e04fba2793 <ninfo>: ctl fifo path: /var/home/rishi/.local/share/containers/storage/overlay-containers/7f293d9029e04fba27934561472b3293754e5baf22cb4d950b6eafdb87255aac/userdata/ctl
Sep 20 17:11:31 bollard conmon[8800]: conmon 7f293d9029e04fba2793 <ninfo>: terminal_ctrl_fd: 12
Sep 20 17:11:31 bollard conmon[8800]: conmon 7f293d9029e04fba2793 <error>: Failed to create container: exit status 1

@mheon
Copy link
Member

mheon commented Sep 20, 2019

Alright, so we've gotten further than before, but now runc is exiting with 1 without giving us an error code

@mheon
Copy link
Member

mheon commented Sep 20, 2019

Error message, rather

@mheon
Copy link
Member

mheon commented Sep 20, 2019

Oh, wait, I see it now. EPERM mounting a directory in the container. Hm.

@debarshiray
Copy link
Member Author

Let's retitle the issue to focus on the EPERM that's failing podman start.

@debarshiray debarshiray changed the title Rootless 'podman start' insists on using crun on Cgroups v1 systems with runtime="runc" Rootless 'podman start' fails to mount /usr with EPERM on Cgroups v1 systems Sep 20, 2019
@debarshiray
Copy link
Member Author

Isn't it peculiar that the first failed podman start doesn't dump anything in the logs?

@mheon
Copy link
Member

mheon commented Sep 24, 2019

DEBU[0000] using runtime "/usr/bin/runc"

I think we are using runc here, not crun.

@mheon
Copy link
Member

mheon commented Sep 24, 2019

Error: unable to start container "fedora-toolbox-30": container_linux.go:346: starting container process caused "process_linux.go:446: container init caused \"rootfs_linux.go:58: mounting \\\"/usr\\\" to rootfs \\\"/var/home/rishi/.local/share/containers/storage/overlay/8fd8c139b64d5f3fe9e52d87e4bb416193713234f96041cde0ad84bf5d5283f9/merged\\\" at \\\"/var/home/rishi/.local/share/containers/storage/overlay/8fd8c139b64d5f3fe9e52d87e4bb416193713234f96041cde0ad84bf5d5283f9/merged/run/host/usr\\\" caused \\\"operation not permitted\\\"\"": OCI runtime permission denied error

That is 100% a runc error

@mheon
Copy link
Member

mheon commented Sep 24, 2019

EPERM mounting in /usr at run/host/usr in the container. That looks like a bind mount, but I don't have one at that location in my toolbox container.
@debarshiray Was this added recently? Or is it only created conditionally?

@debarshiray
Copy link
Member Author

debarshiray commented Sep 24, 2019

Yes, this is definitely using runc because it's a Fedora 30 Cgroups v1 system. It's just confusingly emitting a warning about crun somewhat similar to #4012

@debarshiray
Copy link
Member Author

EPERM mounting in /usr at run/host/usr in the container. That looks like a bind mount,
but I don't have one at that location in my toolbox container.
@debarshiray Was this added recently? Or is it only created conditionally?

Yes, it was added recently in Toolbox 0.0.14.

This seems like something that could totally be due to the way /usr is handled differently on Silverblue versus Workstation.

@debarshiray
Copy link
Member Author

On Silverblue 30, I have:

$ mount | grep usr
/dev/nvme0n1p4 on /usr type ext4 (ro,relatime,seclabel)

It seems that I can mount it ro but not rslave.

@debarshiray
Copy link
Member Author

Anyway, if you think that /usr shouldn't be mounted rslave on Silverblue, feel free to throw this back to me, and I am happy to fix Toolbox.

I am just surprised because @cgwalters has been doing this for a while in his prototype and I believe he uses Silverblue.

@mheon
Copy link
Member

mheon commented Sep 24, 2019

Ummm. So it works without rslave? Interesting.

@rhatdan
Copy link
Member

rhatdan commented Sep 29, 2019

Does it work if you switch to crun?

@rhatdan
Copy link
Member

rhatdan commented Sep 29, 2019

Just to make sure I understand what you are thinking.

$ mount | grep /usr
/dev/mapper/fedora-root on /usr type ext4 (ro,relatime,seclabel)

$ podman run -v /usr:/usr1 fedora mount | grep /usr1
/dev/mapper/fedora-root on /usr1 type ext4 (rw,relatime,seclabel)

You would have wanted /usr1 to be mounted
/dev/mapper/fedora-root on /usr1 type ext4 (ro,relatime,seclabel)

@alexlarsson
Copy link
Contributor

@rhatdan That particular example is a very good, because on an ostree-based system the /usr mount is read-only for a reason, its full of hardlinks into the ostree repo, and once you start changing those all sorts of things can break in mysterious ways.

@debarshiray
Copy link
Member Author

Just to make sure I understand what you are thinking.

$ mount | grep /usr
/dev/mapper/fedora-root on /usr type ext4 (ro,relatime,seclabel)

$ podman run -v /usr:/usr1 fedora mount | grep /usr1
/dev/mapper/fedora-root on /usr1 type ext4 (rw,relatime,seclabel)

You would have wanted /usr1 to be mounted
/dev/mapper/fedora-root on /usr1 type ext4 (ro,relatime,seclabel)

Yes. That's what I meant in #4061 (comment)

In fact, the podman run command that you used will currently fail if /usr is read-only mounted as in Silverblue:

$ podman run --rm --volume /usr:/run/host/usr registry.fedoraproject.org/fedora:30 mount | grep host
WARN[0000] Error initializing configured OCI runtime crun: no valid executable found for OCI runtime crun: invalid argument 
WARN[0000] Error initializing configured OCI runtime crun: no valid executable found for OCI runtime crun: invalid argument 
Error: container_linux.go:346: starting container process caused "process_linux.go:446: container init caused \"rootfs_linux.go:58: mounting \\\"/usr\\\" to rootfs \\\"/var/home/rishi/.local/share/containers/storage/overlay/c87652b1ef245196ec58afd79dfec389687e2dbd5c01721a31e8622e13effd7e/merged\\\" at \\\"/var/home/rishi/.local/share/containers/storage/overlay/c87652b1ef245196ec58afd79dfec389687e2dbd5c01721a31e8622e13effd7e/merged/run/host/usr\\\" caused \\\"operation not permitted\\\"\"": OCI runtime permission denied error

You will have to explicitly specify the ro flag for it to work. Thats' what Toolbox does now.

@debarshiray debarshiray changed the title Rootless 'podman start' fails to mount /usr with EPERM on Cgroups v1 systems Downgrade the default mount flag for bind mounts from 'rw' to 'ro' if the source is mounted read-only Sep 30, 2019
@rhatdan
Copy link
Member

rhatdan commented Sep 30, 2019

@vrothberg Could you fix this, basically if the file system is mounted read/only then the volume mounted should also be read/only.

@debarshiray Does this only matter if this is a mount point? Or would the same issue arise if you did

$ podman run --rm --volume /usr/lib:/run/host/usr/lib registry.fedoraproject.org/fedora:30 mount | grep host

@debarshiray
Copy link
Member Author

There's a somewhat related issue, but quite the same, in crun: containers/crun#120

@github-actions
Copy link

github-actions bot commented Nov 3, 2019

This issue had no activity for 30 days. In the absence of activity or the "do-not-close" label, the issue will be automatically closed within 7 days.

@mheon
Copy link
Member

mheon commented Nov 3, 2019

Did we ever get a runc issue filed for this one?

@vrothberg vrothberg removed their assignment Nov 3, 2019
@vrothberg
Copy link
Member

I didn't notice this was assigned to me, apologies. Given I'll be on the road for a while, I unassigned myself.

@rhatdan
Copy link
Member

rhatdan commented Nov 3, 2019

@giuseppe crun is fixed, not sure abour runc.

@github-actions
Copy link

github-actions bot commented Jan 8, 2020

A friendly reminder that this issue had no activity for 30 days.

@rhatdan
Copy link
Member

rhatdan commented Jan 8, 2020

I am going to close this, as I think it is fixed.

@rhatdan rhatdan closed this as completed Jan 8, 2020
@github-actions github-actions bot added the locked - please file new issue/PR Assist humans wanting to comment on an old issue or PR with locked comments. label Sep 23, 2023
@github-actions github-actions bot locked as resolved and limited conversation to collaborators Sep 23, 2023
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
do-not-close kind/bug Categorizes issue or PR as related to a bug. locked - please file new issue/PR Assist humans wanting to comment on an old issue or PR with locked comments. stale-issue
Projects
None yet
Development

No branches or pull requests

8 participants