Podman: Error messages with rootless "podman run hello-world"

[MrTomRod]

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

/kind bug

Description

Steps to reproduce the issue:

System: Fedora 31, completely up-to-date (date: 2020.03.16, kernel: 5.5.8-200.fc31.x86_64)

podman run hello-world

Describe the results you received:

ERRO[0000] unable to write pod event: "open : no such file or directory" 
ERRO[0000] unable to write pod event: "open : no such file or directory" 
ERRO[0000] unable to write pod event: "open : no such file or directory" 

Hello from Docker!
This message shows that your installation appears to be working correctly.

To generate this message, Docker took the following steps:
 1. The Docker client contacted the Docker daemon.
 2. The Docker daemon pulled the "hello-world" image from the Docker Hub.
    (amd64)
 3. The Docker daemon created a new container from that image which runs the
    executable that produces the output you are currently reading.
 4. The Docker daemon streamed that output to the Docker client, which sent it
    to your terminal.

To try something more ambitious, you can run an Ubuntu container with:
 $ docker run -it ubuntu bash

Share images, automate workflows, and more with a free Docker ID:
 https://hub.docker.com/

For more examples and ideas, visit:
 https://docs.docker.com/get-started/

ERRO[0000] unable to write pod event: "open : no such file or directory" 
ERRO[0000] unable to write pod event: "open : no such file or directory" 

Describe the results you expected:

The same, withouth the ERRO-messages.

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

If I run sudo podman run hello-world, I don't get these messages.

Output of podman version:

❯ podman version
Version:            1.8.1
RemoteAPI Version:  1
Go Version:         go1.13.6
OS/Arch:            linux/amd64

Output of podman info --debug:

❯ podman info --debug
debug:
  compiler: gc
  git commit: ""
  go version: go1.13.6
  podman version: 1.8.1
host:
  BuildahVersion: 1.14.2
  CgroupVersion: v2
  Conmon:
    package: conmon-2.0.11-1.fc31.x86_64
    path: /usr/libexec/crio/conmon
    version: 'conmon version 2.0.11, commit: 235027b49c7d27a65a2c51a7c1f5caff876f7ecd'
  Distribution:
    distribution: fedora
    version: "31"
  IDMappings:
    gidmap:
    - container_id: 0
      host_id: 1000
      size: 1
    - container_id: 1
      host_id: 100000
      size: 65536
    uidmap:
    - container_id: 0
      host_id: 1000
      size: 1
    - container_id: 1
      host_id: 100000
      size: 65536
  MemFree: 9104248832
  MemTotal: 16378007552
  OCIRuntime:
    name: crun
    package: crun-0.13-1.fc31.x86_64
    path: /usr/bin/crun
    version: |-
      crun version 0.13
      commit: e79e4de4ac16da0ce48777afb72c6241de870525
      spec: 1.0.0
      +SYSTEMD +SELINUX +APPARMOR +CAP +SECCOMP +EBPF +YAJL
  SwapFree: 11263799296
  SwapTotal: 11263799296
  arch: amd64
  cpus: 8
  eventlogger: file
  hostname: linux.fritz.box
  kernel: 5.5.8-200.fc31.x86_64
  os: linux
  rootless: true
  slirp4netns:
    Executable: /usr/bin/slirp4netns
    Package: slirp4netns-0.4.0-20.1.dev.gitbbd6f25.fc31.x86_64
    Version: |-
      slirp4netns version 0.4.0-beta.3+dev
      commit: bbd6f25c70d5db2a1cd3bfb0416a8db99a75ed7e
  uptime: 14m 57.92s
registries:
  search:
  - docker.io
  - registry.fedoraproject.org
  - registry.access.redhat.com
  - registry.centos.org
  - quay.io
store:
  ConfigFile: /home/user/.config/containers/storage.conf
  ContainerStore:
    number: 44
  GraphDriverName: overlay
  GraphOptions:
    overlay.mount_program:
      Executable: /usr/bin/fuse-overlayfs
      Package: fuse-overlayfs-0.7.5-2.fc31.x86_64
      Version: |-
        fusermount3 version: 3.6.2
        fuse-overlayfs: version 0.7.5
        FUSE library version 3.6.2
        using FUSE kernel interface version 7.29
  GraphRoot: /home/user/.local/share/containers/storage
  GraphStatus:
    Backing Filesystem: extfs
    Native Overlay Diff: "false"
    Supports d_type: "true"
    Using metacopy: "false"
  ImageStore:
    number: 86
  RunRoot: /tmp/1000
  VolumePath: /home/user/.local/share/containers/storage/volumes

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

❯ rpm -q podman
podman-1.8.1-2.fc31.x86_64

Additional environment details (AWS, VirtualBox, physical, etc.):
Running on a laptop.

[giuseppe]

do you have any override configuration in ~/.config/containers/ ?

[MrTomRod]

Thanks for the quick reply! After rm -rf ~/.config/containers it worked. I don't remember having changed anything there, though...

Sorry to bother you.

[cgwalters]

I started getting this too after upgrading podman 2:1.8.0-2.fc31 -> 2:1.8.1-2.fc31.

walters@orion ~> cat ~/.config/containers/storage.conf 
[storage]
  driver = "overlay"
  runroot = "/run/user/1000"
  graphroot = "/var/home/walters/.local/share/containers/storage"
  [storage.options]
    size = ""
    remap-uids = ""
    remap-gids = ""
    remap-user = ""
    remap-group = ""
    ostree_repo = ""
    skip_mount_home = ""
    mount_program = "/usr/bin/fuse-overlayfs"
    mountopt = ""
    [storage.options.thinpool]
      autoextend_percent = ""
      autoextend_threshold = ""
      basesize = ""
      blocksize = ""
      directlvm_device = ""
      directlvm_device_force = ""
      fs = ""
      log_level = ""
      min_free_space = ""
      mkfsarg = ""
      mountopt = ""
      use_deferred_deletion = ""
      use_deferred_removal = ""
      xfs_nospace_max_retries = ""
walters@orion ~> cat ~/.config/containers/libpod.conf 
volume_path = "/var/home/walters/.local/share/containers/storage/volumes"
image_default_transport = "docker://"
runtime = "/usr/bin/crun"
conmon_path = ["/usr/libexec/podman/conmon", "/usr/libexec/crio/conmon", "/usr/local/lib/podman/conmon", "/usr/local/libexec/crio/conmon", "/usr/bin/conmon", "/usr/sbin/conmon", "/usr/lib/podman/bin/conmon", "/usr/lib/crio/bin/conmon"]
conmon_env_vars = ["PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin"]
cgroup_manager = "cgroupfs"
init_path = "/usr/libexec/podman/catatonit"
static_dir = "/var/home/walters/.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
events_logger = "file"
events_logfile_path = ""
detach_keys = ""
SDNotify = false
cgroup_check = true

[runtimes]
  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"]

[mheon]

events_logfile_path = ""

That right there seems rather suspicious... We shouldn't have edited the config file during that upgrade, but if we didn't it probably should not have worked before. If you comment that out, does it go back to working?

[cgwalters]

I never edited that config file obviously. I still think it's quite wrong how podman writes the config file automatically and it definitely creates upgrade hazards like this.

Anyways, I just blew away the config+storage and re-pulled my toolbox and that worked. Oh and hey, I don't have a ~/.config/containers/libpod.conf anymore even after running podman, so that's good!

[mheon]

We no longer automatically create rootless configuration files as of... I want to say 1.8.0, but it could also be 1.7.x

[elmarco]

Same issue here after f32 upgrade, same solution applied. This is going to be recurrent.

[mheon]

Wait, the configuration file recreated itself after you deleted it?

[elmarco]

Only ~/.config/containers/storage.conf so far.

[mheon]

But you're still seeing error messages related to events being unable to be written?

[elmarco]

But you're still seeing error messages related to events being unable to be written?

no, it's gone.

I suggest to give a hint to the user about these errors, because the user didn't do anything but upgrade podman. Iow, it should handle previous default values/state silently, or tell the user what to do imho

[jordanst3wart]

Removing events_logfile_path = "" in libpod.conf removed the error for me. Thanks @mheon

[rhatdan]

I would just remove libpod.conf altogether. If you never customized it, the system should work fine without it.

[mheon]

I do think we're going to need to handle this on the containers.conf side - all the autogenerated rootless libpod.conf files are going to trigger this, and unfortunately our past mistakes are going to continue to haunt us for a while more here.

[rhatdan]

Should we ignore events_logfile_path = ""?

[sallyom]

weird, I also recently upgraded to fedora32

• First, I had a problem because my rootless podman ~/.config/containers/libpod.conf had cgroup_manager = "cgroupfs" instead of cgroup_manager = "systemd" but then once I fixed that I'm hitting this issue
• ERRO[0000] unable to write pod event: "open : no such file or directory"
  I fixed by rm -rf ~/.config/containers altogether (that would've solved the first issue had I known) but why when I podman info is there a reference to a non-existent .config/containers/storage.conf? should I have that file? podman runs now w/out error, but that file doesn't exist on my system.

[rhatdan]

The idea is you could copy the system one to that location and modify it to change your defaults. But I guess we have hard coded this into info to show where rootless looks for the default, it then fails over to /etc/containers/storage.conf

podman 1.9.2 should handle the cgroup_manager=systemd issue.