time="2021-11-22T15:25:59-05:00" level=info msg="podman filtering at log level debug" time="2021-11-22T15:25:59-05:00" level=debug msg="Called run.PersistentPreRunE(podman run --log-level=debug --rm --init ubuntu:focal sleep 5)" time="2021-11-22T15:25:59-05:00" level=debug msg="overlay storage already configured with a mount-program" time="2021-11-22T15:25:59-05:00" level=debug msg="Merged system config \"/usr/share/containers/containers.conf\"" time="2021-11-22T15:25:59-05:00" level=debug msg="Merged system config \"/etc/containers/containers.conf\"" time="2021-11-22T15:25:59-05:00" level=debug msg="overlay storage already configured with a mount-program" time="2021-11-22T15:25:59-05:00" level=debug msg="Using conmon: \"/usr/libexec/podman/conmon\"" time="2021-11-22T15:25:59-05:00" level=debug msg="Initializing boltdb state at /home/asottile/.local/share/containers/storage/libpod/bolt_state.db" time="2021-11-22T15:25:59-05:00" level=debug msg="Using graph driver overlay" time="2021-11-22T15:25:59-05:00" level=debug msg="Using graph root /home/asottile/.local/share/containers/storage" time="2021-11-22T15:25:59-05:00" level=debug msg="Using run root /run/user/1000/containers" time="2021-11-22T15:25:59-05:00" level=debug msg="Using static dir /home/asottile/.local/share/containers/storage/libpod" time="2021-11-22T15:25:59-05:00" level=debug msg="Using tmp dir /run/user/1000/libpod/tmp" time="2021-11-22T15:25:59-05:00" level=debug msg="Using volume path /home/asottile/.local/share/containers/storage/volumes" time="2021-11-22T15:25:59-05:00" level=debug msg="overlay storage already configured with a mount-program" time="2021-11-22T15:25:59-05:00" level=debug msg="Set libpod namespace to \"\"" time="2021-11-22T15:25:59-05:00" level=debug msg="[graphdriver] trying provided driver \"overlay\"" time="2021-11-22T15:25:59-05:00" level=debug msg="overlay: mount_program=/usr/bin/fuse-overlayfs" time="2021-11-22T15:25:59-05:00" level=debug msg="overlay: mount_program=/usr/bin/fuse-overlayfs" time="2021-11-22T15:25:59-05:00" level=debug msg="backingFs=extfs, projectQuotaSupported=false, useNativeDiff=false, usingMetacopy=false" time="2021-11-22T15:25:59-05:00" level=debug msg="Initializing event backend journald" time="2021-11-22T15:25:59-05:00" level=debug msg="configured OCI runtime kata initialization failed: no valid executable found for OCI runtime kata: invalid argument" time="2021-11-22T15:25:59-05:00" level=debug msg="configured OCI runtime runsc initialization failed: no valid executable found for OCI runtime runsc: invalid argument" time="2021-11-22T15:25:59-05:00" level=debug msg="configured OCI runtime runc initialization failed: no valid executable found for OCI runtime runc: invalid argument" time="2021-11-22T15:25:59-05:00" level=debug msg="Using OCI runtime \"/usr/bin/crun\"" time="2021-11-22T15:25:59-05:00" level=info msg="Found CNI network podman (type=bridge) at /home/asottile/.config/cni/net.d/87-podman.conflist" time="2021-11-22T15:25:59-05:00" level=debug msg="Default CNI network name podman is unchangeable" time="2021-11-22T15:25:59-05:00" level=info msg="Setting parallel job count to 16" time="2021-11-22T15:25:59-05:00" level=debug msg="Pulling image ubuntu:focal (policy: missing)" time="2021-11-22T15:25:59-05:00" level=debug msg="Looking up image \"ubuntu:focal\" in local containers storage" time="2021-11-22T15:25:59-05:00" level=debug msg="Trying \"ubuntu:focal\" ..." time="2021-11-22T15:25:59-05:00" level=debug msg="Loading registries configuration \"/etc/containers/registries.conf\"" time="2021-11-22T15:25:59-05:00" level=debug msg="Loading registries configuration \"/etc/containers/registries.conf.d/000-shortnames.conf\"" time="2021-11-22T15:25:59-05:00" level=debug msg="Loading registries configuration \"/etc/containers/registries.conf.d/shortnames.conf\"" time="2021-11-22T15:25:59-05:00" level=debug msg="Trying \"docker.io/library/ubuntu:focal\" ..." time="2021-11-22T15:25:59-05:00" level=debug msg="parsed reference into \"[overlay@/home/asottile/.local/share/containers/storage+/run/user/1000/containers:overlay.mount_program=/usr/bin/fuse-overlayfs,overlay.mount_program=/usr/bin/fuse-overlayfs]@fb52e22af1b01869e23e75089c368a1130fa538946d0411d47f964f8b1076180\"" time="2021-11-22T15:25:59-05:00" level=debug msg="Found image \"ubuntu:focal\" as \"docker.io/library/ubuntu:focal\" in local containers storage" time="2021-11-22T15:25:59-05:00" level=debug msg="Found image \"ubuntu:focal\" as \"docker.io/library/ubuntu:focal\" in local containers storage ([overlay@/home/asottile/.local/share/containers/storage+/run/user/1000/containers:overlay.mount_program=/usr/bin/fuse-overlayfs,overlay.mount_program=/usr/bin/fuse-overlayfs]@fb52e22af1b01869e23e75089c368a1130fa538946d0411d47f964f8b1076180)" time="2021-11-22T15:25:59-05:00" level=debug msg="Looking up image \"docker.io/library/ubuntu:focal\" in local containers storage" time="2021-11-22T15:25:59-05:00" level=debug msg="Trying \"docker.io/library/ubuntu:focal\" ..." time="2021-11-22T15:25:59-05:00" level=debug msg="parsed reference into \"[overlay@/home/asottile/.local/share/containers/storage+/run/user/1000/containers:overlay.mount_program=/usr/bin/fuse-overlayfs,overlay.mount_program=/usr/bin/fuse-overlayfs]@fb52e22af1b01869e23e75089c368a1130fa538946d0411d47f964f8b1076180\"" time="2021-11-22T15:25:59-05:00" level=debug msg="Found image \"docker.io/library/ubuntu:focal\" as \"docker.io/library/ubuntu:focal\" in local containers storage" time="2021-11-22T15:25:59-05:00" level=debug msg="Found image \"docker.io/library/ubuntu:focal\" as \"docker.io/library/ubuntu:focal\" in local containers storage ([overlay@/home/asottile/.local/share/containers/storage+/run/user/1000/containers:overlay.mount_program=/usr/bin/fuse-overlayfs,overlay.mount_program=/usr/bin/fuse-overlayfs]@fb52e22af1b01869e23e75089c368a1130fa538946d0411d47f964f8b1076180)" time="2021-11-22T15:25:59-05:00" level=debug msg="Looking up image \"ubuntu:focal\" in local containers storage" time="2021-11-22T15:25:59-05:00" level=debug msg="Trying \"ubuntu:focal\" ..." time="2021-11-22T15:25:59-05:00" level=debug msg="Trying \"docker.io/library/ubuntu:focal\" ..." time="2021-11-22T15:25:59-05:00" level=debug msg="parsed reference into \"[overlay@/home/asottile/.local/share/containers/storage+/run/user/1000/containers:overlay.mount_program=/usr/bin/fuse-overlayfs,overlay.mount_program=/usr/bin/fuse-overlayfs]@fb52e22af1b01869e23e75089c368a1130fa538946d0411d47f964f8b1076180\"" time="2021-11-22T15:25:59-05:00" level=debug msg="Found image \"ubuntu:focal\" as \"docker.io/library/ubuntu:focal\" in local containers storage" time="2021-11-22T15:25:59-05:00" level=debug msg="Found image \"ubuntu:focal\" as \"docker.io/library/ubuntu:focal\" in local containers storage ([overlay@/home/asottile/.local/share/containers/storage+/run/user/1000/containers:overlay.mount_program=/usr/bin/fuse-overlayfs,overlay.mount_program=/usr/bin/fuse-overlayfs]@fb52e22af1b01869e23e75089c368a1130fa538946d0411d47f964f8b1076180)" time="2021-11-22T15:25:59-05:00" level=debug msg="Inspecting image fb52e22af1b01869e23e75089c368a1130fa538946d0411d47f964f8b1076180" time="2021-11-22T15:25:59-05:00" level=debug msg="exporting opaque data as blob \"sha256:fb52e22af1b01869e23e75089c368a1130fa538946d0411d47f964f8b1076180\"" time="2021-11-22T15:25:59-05:00" level=debug msg="exporting opaque data as blob \"sha256:fb52e22af1b01869e23e75089c368a1130fa538946d0411d47f964f8b1076180\"" time="2021-11-22T15:25:59-05:00" level=debug msg="exporting opaque data as blob \"sha256:fb52e22af1b01869e23e75089c368a1130fa538946d0411d47f964f8b1076180\"" time="2021-11-22T15:25:59-05:00" level=debug msg="exporting opaque data as blob \"sha256:fb52e22af1b01869e23e75089c368a1130fa538946d0411d47f964f8b1076180\"" time="2021-11-22T15:25:59-05:00" level=debug msg="Looking up image \"ubuntu:focal\" in local containers storage" time="2021-11-22T15:25:59-05:00" level=debug msg="Trying \"ubuntu:focal\" ..." time="2021-11-22T15:25:59-05:00" level=debug msg="Trying \"docker.io/library/ubuntu:focal\" ..." time="2021-11-22T15:25:59-05:00" level=debug msg="parsed reference into \"[overlay@/home/asottile/.local/share/containers/storage+/run/user/1000/containers:overlay.mount_program=/usr/bin/fuse-overlayfs,overlay.mount_program=/usr/bin/fuse-overlayfs]@fb52e22af1b01869e23e75089c368a1130fa538946d0411d47f964f8b1076180\"" time="2021-11-22T15:25:59-05:00" level=debug msg="Found image \"ubuntu:focal\" as \"docker.io/library/ubuntu:focal\" in local containers storage" time="2021-11-22T15:25:59-05:00" level=debug msg="Found image \"ubuntu:focal\" as \"docker.io/library/ubuntu:focal\" in local containers storage ([overlay@/home/asottile/.local/share/containers/storage+/run/user/1000/containers:overlay.mount_program=/usr/bin/fuse-overlayfs,overlay.mount_program=/usr/bin/fuse-overlayfs]@fb52e22af1b01869e23e75089c368a1130fa538946d0411d47f964f8b1076180)" time="2021-11-22T15:25:59-05:00" level=debug msg="Inspecting image fb52e22af1b01869e23e75089c368a1130fa538946d0411d47f964f8b1076180" time="2021-11-22T15:25:59-05:00" level=debug msg="exporting opaque data as blob \"sha256:fb52e22af1b01869e23e75089c368a1130fa538946d0411d47f964f8b1076180\"" time="2021-11-22T15:25:59-05:00" level=debug msg="exporting opaque data as blob \"sha256:fb52e22af1b01869e23e75089c368a1130fa538946d0411d47f964f8b1076180\"" time="2021-11-22T15:25:59-05:00" level=debug msg="exporting opaque data as blob \"sha256:fb52e22af1b01869e23e75089c368a1130fa538946d0411d47f964f8b1076180\"" time="2021-11-22T15:25:59-05:00" level=debug msg="exporting opaque data as blob \"sha256:fb52e22af1b01869e23e75089c368a1130fa538946d0411d47f964f8b1076180\"" time="2021-11-22T15:25:59-05:00" level=debug msg="Inspecting image fb52e22af1b01869e23e75089c368a1130fa538946d0411d47f964f8b1076180" time="2021-11-22T15:25:59-05:00" level=debug msg="using systemd mode: false" time="2021-11-22T15:25:59-05:00" level=debug msg="Adding exposed ports" time="2021-11-22T15:25:59-05:00" level=debug msg="No hostname set; container's hostname will default to runtime default" time="2021-11-22T15:25:59-05:00" level=debug msg="Loading seccomp profile from \"/usr/share/containers/seccomp.json\"" time="2021-11-22T15:25:59-05:00" level=debug msg="Adding mount /proc" time="2021-11-22T15:25:59-05:00" level=debug msg="Adding mount /dev" time="2021-11-22T15:25:59-05:00" level=debug msg="Adding mount /dev/pts" time="2021-11-22T15:25:59-05:00" level=debug msg="Adding mount /dev/mqueue" time="2021-11-22T15:25:59-05:00" level=debug msg="Adding mount /sys" time="2021-11-22T15:25:59-05:00" level=debug msg="Adding mount /sys/fs/cgroup" time="2021-11-22T15:25:59-05:00" level=debug msg="Allocated lock 8 for container 4c3d34ee81c8c39210f52cb846401dc84723493d415dee844b47afb6f851fc0f" time="2021-11-22T15:25:59-05:00" level=debug msg="parsed reference into \"[overlay@/home/asottile/.local/share/containers/storage+/run/user/1000/containers:overlay.mount_program=/usr/bin/fuse-overlayfs,overlay.mount_program=/usr/bin/fuse-overlayfs]@fb52e22af1b01869e23e75089c368a1130fa538946d0411d47f964f8b1076180\"" time="2021-11-22T15:25:59-05:00" level=debug msg="exporting opaque data as blob \"sha256:fb52e22af1b01869e23e75089c368a1130fa538946d0411d47f964f8b1076180\"" time="2021-11-22T15:25:59-05:00" level=debug msg="created container \"4c3d34ee81c8c39210f52cb846401dc84723493d415dee844b47afb6f851fc0f\"" time="2021-11-22T15:25:59-05:00" level=debug msg="container \"4c3d34ee81c8c39210f52cb846401dc84723493d415dee844b47afb6f851fc0f\" has work directory \"/home/asottile/.local/share/containers/storage/overlay-containers/4c3d34ee81c8c39210f52cb846401dc84723493d415dee844b47afb6f851fc0f/userdata\"" time="2021-11-22T15:25:59-05:00" level=debug msg="container \"4c3d34ee81c8c39210f52cb846401dc84723493d415dee844b47afb6f851fc0f\" has run directory \"/run/user/1000/containers/overlay-containers/4c3d34ee81c8c39210f52cb846401dc84723493d415dee844b47afb6f851fc0f/userdata\"" time="2021-11-22T15:25:59-05:00" level=debug msg="Not attaching to stdin" time="2021-11-22T15:25:59-05:00" level=debug msg="Made network namespace at /run/user/1000/netns/cni-6c56462b-9452-4cf8-d577-eac25b1b295c for container 4c3d34ee81c8c39210f52cb846401dc84723493d415dee844b47afb6f851fc0f" time="2021-11-22T15:25:59-05:00" level=debug msg="[graphdriver] trying provided driver \"overlay\"" time="2021-11-22T15:25:59-05:00" level=debug msg="overlay: mount_program=/usr/bin/fuse-overlayfs" time="2021-11-22T15:25:59-05:00" level=debug msg="overlay: mount_program=/usr/bin/fuse-overlayfs" time="2021-11-22T15:25:59-05:00" level=debug msg="backingFs=extfs, projectQuotaSupported=false, useNativeDiff=false, usingMetacopy=false" time="2021-11-22T15:25:59-05:00" level=debug msg="overlay: mount_data=,lowerdir=/home/asottile/.local/share/containers/storage/overlay/l/5ZZDTU2W5CORG7MA2IOCTEUHKO,upperdir=/home/asottile/.local/share/containers/storage/overlay/e3e34dcaca92c002be5928ea02cfd57cc814060dc5b736638ef479c216efa0bb/diff,workdir=/home/asottile/.local/share/containers/storage/overlay/e3e34dcaca92c002be5928ea02cfd57cc814060dc5b736638ef479c216efa0bb/work,volatile" time="2021-11-22T15:25:59-05:00" level=debug msg="slirp4netns command: /usr/bin/slirp4netns --disable-host-loopback --mtu=65520 --enable-sandbox --enable-seccomp -c -e 3 -r 4 --netns-type=path /run/user/1000/netns/cni-6c56462b-9452-4cf8-d577-eac25b1b295c tap0" time="2021-11-22T15:25:59-05:00" level=debug msg="mounted container \"4c3d34ee81c8c39210f52cb846401dc84723493d415dee844b47afb6f851fc0f\" at \"/home/asottile/.local/share/containers/storage/overlay/e3e34dcaca92c002be5928ea02cfd57cc814060dc5b736638ef479c216efa0bb/merged\"" time="2021-11-22T15:25:59-05:00" level=debug msg="Created root filesystem for container 4c3d34ee81c8c39210f52cb846401dc84723493d415dee844b47afb6f851fc0f at /home/asottile/.local/share/containers/storage/overlay/e3e34dcaca92c002be5928ea02cfd57cc814060dc5b736638ef479c216efa0bb/merged" time="2021-11-22T15:25:59-05:00" level=debug msg="/etc/system-fips does not exist on host, not mounting FIPS mode subscription" time="2021-11-22T15:25:59-05:00" level=debug msg="reading hooks from /usr/share/containers/oci/hooks.d" time="2021-11-22T15:25:59-05:00" level=debug msg="Workdir \"/\" resolved to host path \"/home/asottile/.local/share/containers/storage/overlay/e3e34dcaca92c002be5928ea02cfd57cc814060dc5b736638ef479c216efa0bb/merged\"" time="2021-11-22T15:25:59-05:00" level=debug msg="Created OCI spec for container 4c3d34ee81c8c39210f52cb846401dc84723493d415dee844b47afb6f851fc0f at /home/asottile/.local/share/containers/storage/overlay-containers/4c3d34ee81c8c39210f52cb846401dc84723493d415dee844b47afb6f851fc0f/userdata/config.json" time="2021-11-22T15:25:59-05:00" level=debug msg="/usr/libexec/podman/conmon messages will be logged to syslog" time="2021-11-22T15:25:59-05:00" level=debug msg="running conmon: /usr/libexec/podman/conmon" args="[--api-version 1 -c 4c3d34ee81c8c39210f52cb846401dc84723493d415dee844b47afb6f851fc0f -u 4c3d34ee81c8c39210f52cb846401dc84723493d415dee844b47afb6f851fc0f -r /usr/bin/crun -b /home/asottile/.local/share/containers/storage/overlay-containers/4c3d34ee81c8c39210f52cb846401dc84723493d415dee844b47afb6f851fc0f/userdata -p /run/user/1000/containers/overlay-containers/4c3d34ee81c8c39210f52cb846401dc84723493d415dee844b47afb6f851fc0f/userdata/pidfile -n affectionate_goldwasser --exit-dir /run/user/1000/libpod/tmp/exits --full-attach -l journald --log-level debug --syslog --conmon-pidfile /run/user/1000/containers/overlay-containers/4c3d34ee81c8c39210f52cb846401dc84723493d415dee844b47afb6f851fc0f/userdata/conmon.pid --exit-command /usr/bin/podman --exit-command-arg --root --exit-command-arg /home/asottile/.local/share/containers/storage --exit-command-arg --runroot --exit-command-arg /run/user/1000/containers --exit-command-arg --log-level --exit-command-arg debug --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 crun --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 --storage-opt --exit-command-arg overlay.mount_program=/usr/bin/fuse-overlayfs --exit-command-arg --events-backend --exit-command-arg journald --exit-command-arg --syslog --exit-command-arg container --exit-command-arg cleanup --exit-command-arg --rm --exit-command-arg 4c3d34ee81c8c39210f52cb846401dc84723493d415dee844b47afb6f851fc0f]" [conmon:d]: failed to write to /proc/self/oom_score_adj: Permission denied time="2021-11-22T15:25:59-05:00" level=debug msg="Received: 30304" time="2021-11-22T15:25:59-05:00" level=info msg="Got Conmon PID as 30301" time="2021-11-22T15:25:59-05:00" level=debug msg="Created container 4c3d34ee81c8c39210f52cb846401dc84723493d415dee844b47afb6f851fc0f in OCI runtime" time="2021-11-22T15:25:59-05:00" level=debug msg="Attaching to container 4c3d34ee81c8c39210f52cb846401dc84723493d415dee844b47afb6f851fc0f" time="2021-11-22T15:25:59-05:00" level=debug msg="Starting container 4c3d34ee81c8c39210f52cb846401dc84723493d415dee844b47afb6f851fc0f with command [/dev/init -- sleep 5]" time="2021-11-22T15:25:59-05:00" level=debug msg="Started container 4c3d34ee81c8c39210f52cb846401dc84723493d415dee844b47afb6f851fc0f" time="2021-11-22T15:25:59-05:00" level=debug msg="Enabling signal proxying" time="2021-11-22T15:26:01-05:00" level=debug msg="Sending signal 15 to container 4c3d34ee81c8c39210f52cb846401dc84723493d415dee844b47afb6f851fc0f" time="2021-11-22T15:26:01-05:00" level=debug msg="Sending signal 18 to container 4c3d34ee81c8c39210f52cb846401dc84723493d415dee844b47afb6f851fc0f" open pidfd: No such process time="2021-11-22T15:26:01-05:00" level=error msg="Error forwarding signal 18 to container 4c3d34ee81c8c39210f52cb846401dc84723493d415dee844b47afb6f851fc0f: error sending signal to container 4c3d34ee81c8c39210f52cb846401dc84723493d415dee844b47afb6f851fc0f: `/usr/bin/crun kill 4c3d34ee81c8c39210f52cb846401dc84723493d415dee844b47afb6f851fc0f 18` failed: exit status 1" time="2021-11-22T15:26:01-05:00" level=debug msg="Checking if container 4c3d34ee81c8c39210f52cb846401dc84723493d415dee844b47afb6f851fc0f should restart" time="2021-11-22T15:26:01-05:00" level=debug msg="Removing container 4c3d34ee81c8c39210f52cb846401dc84723493d415dee844b47afb6f851fc0f" time="2021-11-22T15:26:01-05:00" level=debug msg="Removing all exec sessions for container 4c3d34ee81c8c39210f52cb846401dc84723493d415dee844b47afb6f851fc0f" time="2021-11-22T15:26:01-05:00" level=debug msg="Cleaning up container 4c3d34ee81c8c39210f52cb846401dc84723493d415dee844b47afb6f851fc0f" time="2021-11-22T15:26:01-05:00" level=debug msg="Tearing down network namespace at /run/user/1000/netns/cni-6c56462b-9452-4cf8-d577-eac25b1b295c for container 4c3d34ee81c8c39210f52cb846401dc84723493d415dee844b47afb6f851fc0f" time="2021-11-22T15:26:01-05:00" level=debug msg="Successfully cleaned up container 4c3d34ee81c8c39210f52cb846401dc84723493d415dee844b47afb6f851fc0f" time="2021-11-22T15:26:01-05:00" level=debug msg="unmounted container \"4c3d34ee81c8c39210f52cb846401dc84723493d415dee844b47afb6f851fc0f\"" time="2021-11-22T15:26:01-05:00" level=debug msg="Container 4c3d34ee81c8c39210f52cb846401dc84723493d415dee844b47afb6f851fc0f storage is already unmounted, skipping..." time="2021-11-22T15:26:01-05:00" level=debug msg="Called run.PersistentPostRunE(podman run --log-level=debug --rm --init ubuntu:focal sleep 5)"