containers / podman

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

SELinux: container exits with code 139 #1118

Closed lukasheinrich closed 6 years ago

lukasheinrich commented 6 years ago

kind bug

Description

podman run busybox echo hello world returns exit code 139. 139 is not part of the listed exit codes in https://github.com/projectatomic/libpod/blob/master/docs/podman-run.1.md

Steps to reproduce the issue:

I'm provisioning a Vagrant Box using the vagrantfile

Vagrant.configure('2') do |config|
  config.vm.box = "fedora/27-cloud-base"

  # Docker
  config.vm.provision :docker

  # Install appc tools & rocket
  config.vm.provision :shell,inline: <<EOF

EOF
end
> vagrant ssh
Last login: Thu Jul 19 20:49:03 2018 from 10.0.2.2
[vagrant@localhost ~]$ sudo -s
[root@localhost vagrant]# podman run busybox echo hello world
[root@localhost vagrant]# echo $?
139

Output of podman version:

podman version 0.7.1

Output of podman info:


host:
  MemFree: 85467136
  MemTotal: 509480960
  SwapFree: 0
  SwapTotal: 0
  arch: amd64
  cpus: 1
  hostname: localhost.localdomain
  kernel: 4.13.9-300.fc27.x86_64
  os: linux
  uptime: 13m 1.36s
insecure registries:
  registries: []
registries:
  registries:
  - docker.io
  - registry.fedoraproject.org
  - registry.access.redhat.com
store:
  ContainerStore:
    number: 2
  GraphDriverName: overlay
  GraphOptions:
  - overlay.override_kernel_check=true
  GraphRoot: /var/lib/containers/storage
  GraphStatus:
    Backing Filesystem: extfs
    Native Overlay Diff: "true"
    Supports d_type: "true"
  ImageStore:
    number: 1
  RunRoot: /var/run/containers/storage```

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

see Vagrantfile above
mheon commented 6 years ago

Error 139 with no output? Interesting.

Can you add a --log-level=debug between podman and run to get debug-level logs and try and see what's going wrong?

rhatdan commented 6 years ago

That is the exit code from the echo command I believe. I am not seeing anything going wrong there?

lukasheinrich commented 6 years ago

@rhatdan why should the echo command error out? I would have expected to just print hello world

@mheon this is the debug output

[root@localhost vagrant]# podman --log-level=debug run busybox echo hello world
DEBU[0000] [graphdriver] trying provided driver "overlay" 
DEBU[0000] overlay: override_kernelcheck=true           
DEBU[0000] overlay test mount with multiple lowers succeeded 
DEBU[0000] backingFs=extfs, projectQuotaSupported=false, useNativeDiff=true 
INFO[0000] CNI network podman (type=bridge) is used from /etc/cni/net.d/87-podman-bridge.conflist 
INFO[0000] Initial CNI setting succeeded                
DEBU[0000] parsed reference into "[overlay@/var/lib/containers/storage+/var/run/containers/storage:overlay.override_kernel_check=true]docker.io/library/busybox:latest" 
DEBU[0000] parsed reference into "[overlay@/var/lib/containers/storage+/var/run/containers/storage:overlay.override_kernel_check=true]@22c2dd5ee85dc01136051800684b0bf30016a3082f97093c806152bf43d4e089" 
DEBU[0000] exporting opaque data as blob "sha256:22c2dd5ee85dc01136051800684b0bf30016a3082f97093c806152bf43d4e089" 
DEBU[0000] parsed reference into "[overlay@/var/lib/containers/storage+/var/run/containers/storage:overlay.override_kernel_check=true]@22c2dd5ee85dc01136051800684b0bf30016a3082f97093c806152bf43d4e089" 
DEBU[0000] exporting opaque data as blob "sha256:22c2dd5ee85dc01136051800684b0bf30016a3082f97093c806152bf43d4e089" 
DEBU[0000] parsed reference into "[overlay@/var/lib/containers/storage+/var/run/containers/storage:overlay.override_kernel_check=true]@22c2dd5ee85dc01136051800684b0bf30016a3082f97093c806152bf43d4e089" 
DEBU[0000] Using bridge netmode                         
DEBU[0000] parsed reference into "[overlay@/var/lib/containers/storage+/var/run/containers/storage:overlay.override_kernel_check=true]@22c2dd5ee85dc01136051800684b0bf30016a3082f97093c806152bf43d4e089" 
DEBU[0000] exporting opaque data as blob "sha256:22c2dd5ee85dc01136051800684b0bf30016a3082f97093c806152bf43d4e089" 
DEBU[0000] created container "fa48e310b2df07a296fd1b6f6725922f9ff15a52b6ceee8b136ced44be16943c" 
DEBU[0000] container "fa48e310b2df07a296fd1b6f6725922f9ff15a52b6ceee8b136ced44be16943c" has work directory "/var/lib/containers/storage/overlay-containers/fa48e310b2df07a296fd1b6f6725922f9ff15a52b6ceee8b136ced44be16943c/userdata" 
DEBU[0000] container "fa48e310b2df07a296fd1b6f6725922f9ff15a52b6ceee8b136ced44be16943c" has run directory "/var/run/containers/storage/overlay-containers/fa48e310b2df07a296fd1b6f6725922f9ff15a52b6ceee8b136ced44be16943c/userdata" 
DEBU[0000] New container created "fa48e310b2df07a296fd1b6f6725922f9ff15a52b6ceee8b136ced44be16943c" 
DEBU[0000] container "fa48e310b2df07a296fd1b6f6725922f9ff15a52b6ceee8b136ced44be16943c" has CgroupParent "/libpod_parent/libpod-fa48e310b2df07a296fd1b6f6725922f9ff15a52b6ceee8b136ced44be16943c" 
DEBU[0000] Not attaching to stdin                       
DEBU[0000] mounted container "fa48e310b2df07a296fd1b6f6725922f9ff15a52b6ceee8b136ced44be16943c" at "/var/lib/containers/storage/overlay/01b815e3799209624f545845955c5c43a5eab6e9943ae99233626eb5ec837812/merged" 
DEBU[0000] Created root filesystem for container fa48e310b2df07a296fd1b6f6725922f9ff15a52b6ceee8b136ced44be16943c at /var/lib/containers/storage/overlay/01b815e3799209624f545845955c5c43a5eab6e9943ae99233626eb5ec837812/merged 
DEBU[0000] Made network namespace at /var/run/netns/cni-b47310e9-54e6-f42f-9b5c-2094af0907a0 for container fa48e310b2df07a296fd1b6f6725922f9ff15a52b6ceee8b136ced44be16943c 
INFO[0000] Got pod network {Name:eager_wozniak Namespace:eager_wozniak ID:fa48e310b2df07a296fd1b6f6725922f9ff15a52b6ceee8b136ced44be16943c NetNS:/var/run/netns/cni-b47310e9-54e6-f42f-9b5c-2094af0907a0 PortMappings:[]} 
INFO[0000] About to add CNI network cni-loopback (type=loopback) 
INFO[0000] Got pod network {Name:eager_wozniak Namespace:eager_wozniak ID:fa48e310b2df07a296fd1b6f6725922f9ff15a52b6ceee8b136ced44be16943c NetNS:/var/run/netns/cni-b47310e9-54e6-f42f-9b5c-2094af0907a0 PortMappings:[]} 
INFO[0000] About to add CNI network podman (type=bridge) 
DEBU[0000] Response from CNI plugins: Interfaces:[{Name:cni0 Mac:0a:58:0a:58:00:01 Sandbox:} {Name:veth2676f778 Mac:ee:6a:bc:32:22:f4 Sandbox:} {Name:eth0 Mac:0a:58:0a:58:00:08 Sandbox:/var/run/netns/cni-b47310e9-54e6-f42f-9b5c-2094af0907a0}], IP:[{Version:4 Interface:0xc4204023e8 Address:{IP:10.88.0.8 Mask:ffff0000} Gateway:10.88.0.1}], Routes:[{Dst:{IP:0.0.0.0 Mask:00000000} GW:<nil>}], DNS:{Nameservers:[] Domain: Search:[] Options:[]} 
DEBU[0000] Running iptables command: -t filter -I FORWARD -s 10.88.0.8 ! -o 10.88.0.8 -j ACCEPT 
DEBU[0000] file "/etc/containers/mounts.conf" not found, skipping... 
DEBU[0000] /etc/system-fips does not exist on host, not mounting FIPS mode secret 
WARN[0000] failed to parse language "en_US.UTF-8": language: tag is not well-formed 
DEBU[0000] reading hooks from /usr/share/containers/oci/hooks.d 
DEBU[0000] added hook /usr/share/containers/oci/hooks.d/oci-systemd-hook.json 
DEBU[0000] added hook /usr/share/containers/oci/hooks.d/oci-umount.json 
DEBU[0000] hook oci-systemd-hook.json did not match     
DEBU[0000] hook oci-umount.json did not match           
DEBU[0000] parsed reference into "[overlay@/var/lib/containers/storage+/var/run/containers/storage:overlay.override_kernel_check=true]@22c2dd5ee85dc01136051800684b0bf30016a3082f97093c806152bf43d4e089" 
DEBU[0000] parsed reference into "[overlay@/var/lib/containers/storage+/var/run/containers/storage:overlay.override_kernel_check=true]@22c2dd5ee85dc01136051800684b0bf30016a3082f97093c806152bf43d4e089" 
DEBU[0000] exporting opaque data as blob "sha256:22c2dd5ee85dc01136051800684b0bf30016a3082f97093c806152bf43d4e089" 
DEBU[0000] parsed reference into "[overlay@/var/lib/containers/storage+/var/run/containers/storage:overlay.override_kernel_check=true]@22c2dd5ee85dc01136051800684b0bf30016a3082f97093c806152bf43d4e089" 
DEBU[0000] exporting opaque data as blob "sha256:22c2dd5ee85dc01136051800684b0bf30016a3082f97093c806152bf43d4e089" 
DEBU[0000] parsed reference into "[overlay@/var/lib/containers/storage+/var/run/containers/storage:overlay.override_kernel_check=true]@22c2dd5ee85dc01136051800684b0bf30016a3082f97093c806152bf43d4e089" 
DEBU[0000] Setting CGroup path for container fa48e310b2df07a296fd1b6f6725922f9ff15a52b6ceee8b136ced44be16943c to /libpod_parent/libpod-fa48e310b2df07a296fd1b6f6725922f9ff15a52b6ceee8b136ced44be16943c 
DEBU[0000] Created OCI spec for container fa48e310b2df07a296fd1b6f6725922f9ff15a52b6ceee8b136ced44be16943c at /var/lib/containers/storage/overlay-containers/fa48e310b2df07a296fd1b6f6725922f9ff15a52b6ceee8b136ced44be16943c/userdata/config.json 
DEBU[0000] %s messages will be logged to syslog/usr/libexec/podman/conmon 
DEBU[0000] running conmon: /usr/libexec/podman/conmon    args=[-c fa48e310b2df07a296fd1b6f6725922f9ff15a52b6ceee8b136ced44be16943c -u fa48e310b2df07a296fd1b6f6725922f9ff15a52b6ceee8b136ced44be16943c -r /usr/bin/runc -b /var/lib/containers/storage/overlay-containers/fa48e310b2df07a296fd1b6f6725922f9ff15a52b6ceee8b136ced44be16943c/userdata -p /var/run/containers/storage/overlay-containers/fa48e310b2df07a296fd1b6f6725922f9ff15a52b6ceee8b136ced44be16943c/userdata/pidfile -l /var/lib/containers/storage/overlay-containers/fa48e310b2df07a296fd1b6f6725922f9ff15a52b6ceee8b136ced44be16943c/userdata/ctr.log --exit-dir /var/run/libpod/exits --socket-dir-path /var/run/libpod/socket --syslog]
option parsing failed: Unknown option --syslog
DEBU[0000] Cleaning up container fa48e310b2df07a296fd1b6f6725922f9ff15a52b6ceee8b136ced44be16943c 
DEBU[0000] Running iptables command: -t filter -D FORWARD -s 10.88.0.8 ! -o 10.88.0.8 -j ACCEPT 
DEBU[0000] Tearing down network namespace at /var/run/netns/cni-b47310e9-54e6-f42f-9b5c-2094af0907a0 for container fa48e310b2df07a296fd1b6f6725922f9ff15a52b6ceee8b136ced44be16943c 
INFO[0000] Got pod network {Name:eager_wozniak Namespace:eager_wozniak ID:fa48e310b2df07a296fd1b6f6725922f9ff15a52b6ceee8b136ced44be16943c NetNS:/var/run/netns/cni-b47310e9-54e6-f42f-9b5c-2094af0907a0 PortMappings:[]} 
INFO[0000] About to del CNI network podman (type=bridge) 
DEBU[0000] unmounted container "fa48e310b2df07a296fd1b6f6725922f9ff15a52b6ceee8b136ced44be16943c" 
ERRO[0000] exit status 1
lukasheinrich commented 6 years ago

is this the culprit?

DEBU[0000] running conmon: /usr/libexec/podman/conmon    args=[-c fa48e310b2df07a296fd1b6f6725922f9ff15a52b6ceee8b136ced44be16943c -u fa48e310b2df07a296fd1b6f6725922f9ff15a52b6ceee8b136ced44be16943c -r /usr/bin/runc -b /var/lib/containers/storage/overlay-containers/fa48e310b2df07a296fd1b6f6725922f9ff15a52b6ceee8b136ced44be16943c/userdata -p /var/run/containers/storage/overlay-containers/fa48e310b2df07a296fd1b6f6725922f9ff15a52b6ceee8b136ced44be16943c/userdata/pidfile -l /var/lib/containers/storage/overlay-containers/fa48e310b2df07a296fd1b6f6725922f9ff15a52b6ceee8b136ced44be16943c/userdata/ctr.log --exit-dir /var/run/libpod/exits --socket-dir-path /var/run/libpod/socket --syslog]
option parsing failed: Unknown option --syslog
rhatdan commented 6 years ago

So the issue is the conmon that you are using is not new enough.

podman is passing conmon --syslog.

rhatdan commented 6 years ago

Did you build this yourself? Or is this a packaged version?

lukasheinrich commented 6 years ago

no this is the packaged version

[root@localhost vagrant]# yum list installed|grep -E "conmon|podman"
conmon.x86_64                              2:1.10.3-1.gite558bd5.fc27  @updates 
podman.x86_64                              0.7.1-1.git802d4f2.fc27     @updates 
rhatdan commented 6 years ago

Update the package to the one in updates-testing.

podman should be using its own internal conmon

rhatdan commented 6 years ago

dnf -y update podman --enablerepo=updates-testing

mheon commented 6 years ago

@rhatdan Might be using a pinned commit for the internal conmon that's too old.

lukasheinrich commented 6 years ago
[root@localhost vagrant]# yum install --enablerepo=updates-testing -y podman conmon^C
[root@localhost vagrant]# yum list installed|grep -E "conmon|podman"
conmon.x86_64                            2:1.10.3-1.gite558bd5.fc27   @updates  
podman.x86_64                            0.7.2-1.git4ca4c5f.fc27      @updates-testing
[root@localhost vagrant]# podman run busybox echo hello world
[root@localhost vagrant]# echo $?
139
lukasheinrich commented 6 years ago

still the same message

DEBU[0000] running conmon: /usr/libexec/podman/conmon    args=[-c 2b71a3625bcb8bd3800fde5aba4f136f518d3575985e5e47766e1be26613d783 -u 2b71a3625bcb8bd3800fde5aba4f136f518d3575985e5e47766e1be26613d783 -r /usr/bin/runc -b /var/lib/containers/storage/overlay-containers/2b71a3625bcb8bd3800fde5aba4f136f518d3575985e5e47766e1be26613d783/userdata -p /var/run/containers/storage/overlay-containers/2b71a3625bcb8bd3800fde5aba4f136f518d3575985e5e47766e1be26613d783/userdata/pidfile -l /var/lib/containers/storage/overlay-containers/2b71a3625bcb8bd3800fde5aba4f136f518d3575985e5e47766e1be26613d783/userdata/ctr.log --exit-dir /var/run/libpod/exits --socket-dir-path /var/run/libpod/socket --syslog]
option parsing failed: Unknown option --syslog
lukasheinrich commented 6 years ago
[root@localhost vagrant]#  /usr/libexec/podman/conmon --version
conmon version 1.11.0-dev
commit: 6a5c1201d97605ab3a0d0f80b5c814e4205ef484
rhatdan commented 6 years ago

/usr/libexec/podman/conmon --help Does it show --syslog?

lukasheinrich commented 6 years ago

no, it doesn't

[root@localhost vagrant]# /usr/libexec/podman/conmon --help
Usage:
  conmon [OPTION?] - conmon utility

Help Options:
  -h, --help                  Show help options

Application Options:
  -t, --terminal              Terminal
  -i, --stdin                 Stdin
  --leave-stdin-open          Leave stdin open when attached client disconnects
  -c, --cid                   Container ID
  -u, --cuuid                 Container UUID
  -r, --runtime               Runtime path
  --restore                   Restore a container from a checkpoint
  --no-new-keyring            Do not create a new session keyring for the container
  --no-pivot                  Do not use pivot_root
  --replace-listen-pid        Replace listen pid if set for oci-runtime pid
  -b, --bundle                Bundle path
  --pidfile                   PID file (DEPRECATED)
  -p, --container-pidfile     Container PID file
  -P, --conmon-pidfile        Conmon daemon PID file
  -s, --systemd-cgroup        Enable systemd cgroup manager
  -e, --exec                  Exec a command in a running container
  --exec-process-spec         Path to the process spec for exec
  --exit-dir                  Path to the directory where exit files are written
  --exit-command              Path to the program to execute when the container terminates its execution
  --exit-command-arg          Additional arg to pass to the exit command.  Can be specified multiple times
  -l, --log-path              Log file path
  -T, --timeout               Timeout in seconds
  --log-size-max              Maximum size of log file
  --socket-dir-path           Location of container attach sockets
  --version        
mheon commented 6 years ago

It's running the packaged conmon, it just seems to be too old. @rhatdan Looks like a packaging issue on F27

mheon commented 6 years ago

This also isn't our root cause, --syslog isn't added to the conmon command line unless --log-level=debug is present - we don't use the extra logging otherwise

rhatdan commented 6 years ago

Yes I screwed up on podman for f27. Building now. I will pull the PR. Thanks @lukasheinrich for finding this.

rhatdan commented 6 years ago

https://koji.fedoraproject.org/koji/taskinfo?taskID=28453605

rhatdan commented 6 years ago

Should be fixed in podman-0.7.2-2.git4ca4c5f.fc27

mheon commented 6 years ago

We really need to add a check for bad Conmon versions. We got the --version flag merged there, but we haven't been keeping it updated, so we can't reliably check it to see if it's a good version.

lukasheinrich commented 6 years ago

@rhatdan when will this be packaged? dnf install -y podman currently still installs 0.7.1-1.git802d4f2.fc27

rhatdan commented 6 years ago

Just moved to batch update

dnf update -y podman --enablerepo=updates-testing

lukasheinrich commented 6 years ago

the syslog thing seems solved, but still it's not working

[root@localhost vagrant]# podman --log-level=debug run --rm -it busybox echo ok
DEBU[0000] [graphdriver] trying provided driver "overlay" 
DEBU[0000] overlay: override_kernelcheck=true           
DEBU[0000] overlay test mount with multiple lowers succeeded 
DEBU[0000] backingFs=extfs, projectQuotaSupported=false, useNativeDiff=true 
INFO[0000] Found CNI network podman (type=bridge) at /etc/cni/net.d/87-podman-bridge.conflist 
DEBU[0000] parsed reference into "[overlay@/var/lib/containers/storage+/var/run/containers/storage:overlay.override_kernel_check=true]docker.io/library/busybox:latest" 
DEBU[0000] parsed reference into "[overlay@/var/lib/containers/storage+/var/run/containers/storage:overlay.override_kernel_check=true]@22c2dd5ee85dc01136051800684b0bf30016a3082f97093c806152bf43d4e089" 
DEBU[0000] exporting opaque data as blob "sha256:22c2dd5ee85dc01136051800684b0bf30016a3082f97093c806152bf43d4e089" 
DEBU[0000] parsed reference into "[overlay@/var/lib/containers/storage+/var/run/containers/storage:overlay.override_kernel_check=true]@22c2dd5ee85dc01136051800684b0bf30016a3082f97093c806152bf43d4e089" 
DEBU[0000] exporting opaque data as blob "sha256:22c2dd5ee85dc01136051800684b0bf30016a3082f97093c806152bf43d4e089" 
DEBU[0000] parsed reference into "[overlay@/var/lib/containers/storage+/var/run/containers/storage:overlay.override_kernel_check=true]@22c2dd5ee85dc01136051800684b0bf30016a3082f97093c806152bf43d4e089" 
DEBU[0000] AppArmor is not supported: setting empty profile 
DEBU[0000] Using bridge netmode                         
DEBU[0000] parsed reference into "[overlay@/var/lib/containers/storage+/var/run/containers/storage:overlay.override_kernel_check=true]@22c2dd5ee85dc01136051800684b0bf30016a3082f97093c806152bf43d4e089" 
DEBU[0000] exporting opaque data as blob "sha256:22c2dd5ee85dc01136051800684b0bf30016a3082f97093c806152bf43d4e089" 
DEBU[0000] created container "74a2479af78c4348e8de40e7cfae9fb68939682a52bce2d36246ece091527961" 
DEBU[0000] container "74a2479af78c4348e8de40e7cfae9fb68939682a52bce2d36246ece091527961" has work directory "/var/lib/containers/storage/overlay-containers/74a2479af78c4348e8de40e7cfae9fb68939682a52bce2d36246ece091527961/userdata" 
DEBU[0000] container "74a2479af78c4348e8de40e7cfae9fb68939682a52bce2d36246ece091527961" has run directory "/var/run/containers/storage/overlay-containers/74a2479af78c4348e8de40e7cfae9fb68939682a52bce2d36246ece091527961/userdata" 
DEBU[0000] New container created "74a2479af78c4348e8de40e7cfae9fb68939682a52bce2d36246ece091527961" 
DEBU[0000] container "74a2479af78c4348e8de40e7cfae9fb68939682a52bce2d36246ece091527961" has CgroupParent "/libpod_parent/libpod-74a2479af78c4348e8de40e7cfae9fb68939682a52bce2d36246ece091527961" 
DEBU[0000] Handling terminal attach                     
DEBU[0000] mounted container "74a2479af78c4348e8de40e7cfae9fb68939682a52bce2d36246ece091527961" at "/var/lib/containers/storage/overlay/aa60a1ee147fb9f30010fff55ebea7e4ec2237aa4768654b52684dc3b9881885/merged" 
DEBU[0000] Created root filesystem for container 74a2479af78c4348e8de40e7cfae9fb68939682a52bce2d36246ece091527961 at /var/lib/containers/storage/overlay/aa60a1ee147fb9f30010fff55ebea7e4ec2237aa4768654b52684dc3b9881885/merged 
DEBU[0000] Made network namespace at /var/run/netns/cni-bd5d4ce5-d2e8-9869-6cc2-ce1034b5c63d for container 74a2479af78c4348e8de40e7cfae9fb68939682a52bce2d36246ece091527961 
INFO[0000] Got pod network &{Name:upbeat_jepsen Namespace:upbeat_jepsen ID:74a2479af78c4348e8de40e7cfae9fb68939682a52bce2d36246ece091527961 NetNS:/var/run/netns/cni-bd5d4ce5-d2e8-9869-6cc2-ce1034b5c63d PortMappings:[] Networks:[]} 
INFO[0000] About to add CNI network cni-loopback (type=loopback) 
INFO[0000] Got pod network &{Name:upbeat_jepsen Namespace:upbeat_jepsen ID:74a2479af78c4348e8de40e7cfae9fb68939682a52bce2d36246ece091527961 NetNS:/var/run/netns/cni-bd5d4ce5-d2e8-9869-6cc2-ce1034b5c63d PortMappings:[] Networks:[]} 
INFO[0000] About to add CNI network podman (type=bridge) 
DEBU[0000] [0] CNI result: Interfaces:[{Name:cni0 Mac:0a:58:0a:58:00:01 Sandbox:} {Name:veth6e0bbce6 Mac:1e:0d:2b:90:92:ab Sandbox:} {Name:eth0 Mac:0a:58:0a:58:00:0b Sandbox:/var/run/netns/cni-bd5d4ce5-d2e8-9869-6cc2-ce1034b5c63d}], IP:[{Version:4 Interface:0xc4204c4108 Address:{IP:10.88.0.11 Mask:ffff0000} Gateway:10.88.0.1}], Routes:[{Dst:{IP:0.0.0.0 Mask:00000000} GW:<nil>}], DNS:{Nameservers:[] Domain: Search:[] Options:[]} 
DEBU[0000] Running iptables command: -t filter -I FORWARD -s 10.88.0.11 ! -o 10.88.0.11 -j ACCEPT 
DEBU[0000] /etc/system-fips does not exist on host, not mounting FIPS mode secret 
WARN[0000] failed to parse language "en_US.UTF-8": language: tag is not well-formed 
DEBU[0000] reading hooks from /usr/share/containers/oci/hooks.d 
DEBU[0000] added hook /usr/share/containers/oci/hooks.d/oci-systemd-hook.json 
DEBU[0000] added hook /usr/share/containers/oci/hooks.d/oci-umount.json 
DEBU[0000] hook oci-systemd-hook.json did not match     
DEBU[0000] hook oci-umount.json did not match           
DEBU[0000] parsed reference into "[overlay@/var/lib/containers/storage+/var/run/containers/storage:overlay.override_kernel_check=true]@22c2dd5ee85dc01136051800684b0bf30016a3082f97093c806152bf43d4e089" 
DEBU[0000] parsed reference into "[overlay@/var/lib/containers/storage+/var/run/containers/storage:overlay.override_kernel_check=true]@22c2dd5ee85dc01136051800684b0bf30016a3082f97093c806152bf43d4e089" 
DEBU[0000] exporting opaque data as blob "sha256:22c2dd5ee85dc01136051800684b0bf30016a3082f97093c806152bf43d4e089" 
DEBU[0000] parsed reference into "[overlay@/var/lib/containers/storage+/var/run/containers/storage:overlay.override_kernel_check=true]@22c2dd5ee85dc01136051800684b0bf30016a3082f97093c806152bf43d4e089" 
DEBU[0000] exporting opaque data as blob "sha256:22c2dd5ee85dc01136051800684b0bf30016a3082f97093c806152bf43d4e089" 
DEBU[0000] parsed reference into "[overlay@/var/lib/containers/storage+/var/run/containers/storage:overlay.override_kernel_check=true]@22c2dd5ee85dc01136051800684b0bf30016a3082f97093c806152bf43d4e089" 
DEBU[0000] Setting CGroup path for container 74a2479af78c4348e8de40e7cfae9fb68939682a52bce2d36246ece091527961 to /libpod_parent/libpod-74a2479af78c4348e8de40e7cfae9fb68939682a52bce2d36246ece091527961 
DEBU[0000] Created OCI spec for container 74a2479af78c4348e8de40e7cfae9fb68939682a52bce2d36246ece091527961 at /var/lib/containers/storage/overlay-containers/74a2479af78c4348e8de40e7cfae9fb68939682a52bce2d36246ece091527961/userdata/config.json 
DEBU[0000] %s messages will be logged to syslog/usr/libexec/podman/conmon 
DEBU[0000] running conmon: /usr/libexec/podman/conmon    args=[-c 74a2479af78c4348e8de40e7cfae9fb68939682a52bce2d36246ece091527961 -u 74a2479af78c4348e8de40e7cfae9fb68939682a52bce2d36246ece091527961 -r /usr/bin/runc -b /var/lib/containers/storage/overlay-containers/74a2479af78c4348e8de40e7cfae9fb68939682a52bce2d36246ece091527961/userdata -p /var/run/containers/storage/overlay-containers/74a2479af78c4348e8de40e7cfae9fb68939682a52bce2d36246ece091527961/userdata/pidfile -l /var/lib/containers/storage/overlay-containers/74a2479af78c4348e8de40e7cfae9fb68939682a52bce2d36246ece091527961/userdata/ctr.log --exit-dir /var/run/libpod/exits --socket-dir-path /var/run/libpod/socket -t --syslog]
DEBU[0000] Received container pid: 6173                 
DEBU[0000] Created container 74a2479af78c4348e8de40e7cfae9fb68939682a52bce2d36246ece091527961 in OCI runtime 
DEBU[0000] Enabling signal proxying                     
DEBU[0000] Attaching to container 74a2479af78c4348e8de40e7cfae9fb68939682a52bce2d36246ece091527961 
DEBU[0000] connecting to socket /var/run/libpod/socket/74a2479af78c4348e8de40e7cfae9fb68939682a52bce2d36246ece091527961/attach 
DEBU[0000] Started container 74a2479af78c4348e8de40e7cfae9fb68939682a52bce2d36246ece091527961 
DEBU[0000] Cleaning up container 74a2479af78c4348e8de40e7cfae9fb68939682a52bce2d36246ece091527961 
DEBU[0000] Running iptables command: -t filter -D FORWARD -s 10.88.0.11 ! -o 10.88.0.11 -j ACCEPT 
DEBU[0000] Tearing down network namespace at /var/run/netns/cni-bd5d4ce5-d2e8-9869-6cc2-ce1034b5c63d for container 74a2479af78c4348e8de40e7cfae9fb68939682a52bce2d36246ece091527961 
INFO[0000] Got pod network &{Name:upbeat_jepsen Namespace:upbeat_jepsen ID:74a2479af78c4348e8de40e7cfae9fb68939682a52bce2d36246ece091527961 NetNS:/var/run/netns/cni-bd5d4ce5-d2e8-9869-6cc2-ce1034b5c63d PortMappings:[] Networks:[]} 
INFO[0000] About to del CNI network podman (type=bridge) 
DEBU[0000] unmounted container "74a2479af78c4348e8de40e7cfae9fb68939682a52bce2d36246ece091527961" 
DEBU[0000] Storage is already unmounted, skipping...    
DEBU[0000] Failed to unmount aa60a1ee147fb9f30010fff55ebea7e4ec2237aa4768654b52684dc3b9881885 overlay: /var/lib/containers/storage/overlay/aa60a1ee147fb9f30010fff55ebea7e4ec2237aa4768654b52684dc3b9881885/merged - invalid argument 
[root@localhost vagrant]# echo $?
139
[root@localhost vagrant]# podman --version
podman version 0.7.3
mheon commented 6 years ago

@lukasheinrich Can you get any messages from conmon out of syslog?

It looks like the container is starting successfully and the application in the container is exiting with a 139, but I'd like the conmon logs to be certain.

rhatdan commented 6 years ago

journalctl -b | grep -i conmon

lukasheinrich commented 6 years ago
Jul 25 00:14:55 localhost.localdomain conmon[7567]: conmon 9d75cbd47d65fbefdd26 <ninfo>: addr{sun_family=AF_UNIX, sun_path=/tmp/conmon-term.F5MMMZ}
Jul 25 00:14:55 localhost.localdomain conmon[7567]: conmon 9d75cbd47d65fbefdd26 <ninfo>: about to waitpid: 7568
Jul 25 00:14:55 localhost.localdomain conmon[7567]: conmon 9d75cbd47d65fbefdd26 <ninfo>: about to accept from console_socket_fd: 9
Jul 25 00:14:55 localhost.localdomain conmon[7567]: conmon 9d75cbd47d65fbefdd26 <ninfo>: about to recvfd from connfd: 15
Jul 25 00:14:55 localhost.localdomain conmon[7567]: [82B blob data]
Jul 25 00:14:55 localhost.localdomain conmon[7567]: conmon 9d75cbd47d65fbefdd26 <ninfo>: container PID: 7576
Jul 25 00:14:55 localhost.localdomain conmon[7567]: conmon 9d75cbd47d65fbefdd26 <ninfo>: attach sock path: /var/run/libpod/socket/9d75cbd47d65fbefdd266d9e9688829d3b99ce526d83b6466664e821c1d6fb35/attach
Jul 25 00:14:55 localhost.localdomain conmon[7567]: conmon 9d75cbd47d65fbefdd26 <ninfo>: addr{sun_family=AF_UNIX, sun_path=/var/run/libpod/socket/9d75cbd47d65fbefdd266d9e9688829d3b99ce526d83b6466664e821c1d6fb35/attach}
Jul 25 00:14:55 localhost.localdomain conmon[7567]: conmon 9d75cbd47d65fbefdd26 <ninfo>: ctl fifo path: /var/lib/containers/storage/overlay-containers/9d75cbd47d65fbefdd266d9e9688829d3b99ce526d83b6466664e821c1d6fb35/userdata/ctl
Jul 25 00:14:55 localhost.localdomain conmon[7567]: conmon 9d75cbd47d65fbefdd26 <ninfo>: terminal_ctrl_fd: 16
Jul 25 00:14:55 localhost.localdomain conmon[7567]: conmon 9d75cbd47d65fbefdd26 <ninfo>: Accepted connection 18
Jul 25 00:14:55 localhost.localdomain conmon[7567]: conmon 9d75cbd47d65fbefdd26 <ninfo>: Got ctl message: 1 51 185
Jul 25 00:14:55 localhost.localdomain conmon[7567]: conmon 9d75cbd47d65fbefdd26 <ninfo>: Message type: 1, Height: 51, Width: 185
Jul 25 00:14:55 localhost.localdomain conmon[7567]: conmon 9d75cbd47d65fbefdd26 <ninfo>: container 7576 exited with status 139
Jul 25 00:14:55 localhost.localdomain conmon[7567]: conmon 9d75cbd47d65fbefdd26 <nwarn>: stdio_input read failed Input/output erro
lukasheinrich commented 6 years ago

I removed -it in case that would cause an issue

podman --log-level=debug run  busybox echo hello world
Jul 25 00:17:15 localhost.localdomain conmon[8032]: conmon 1ac46858ccfc8505e85c <ninfo>: about to waitpid: 8033
Jul 25 00:17:15 localhost.localdomain conmon[8032]: conmon 1ac46858ccfc8505e85c <ninfo>: container PID: 8041
Jul 25 00:17:15 localhost.localdomain conmon[8032]: conmon 1ac46858ccfc8505e85c <ninfo>: attach sock path: /var/run/libpod/socket/1ac46858ccfc8505e85c4fb29e62c013b6d5d3b65044877a0e222fec82da9a96/attach
Jul 25 00:17:15 localhost.localdomain conmon[8032]: conmon 1ac46858ccfc8505e85c <ninfo>: addr{sun_family=AF_UNIX, sun_path=/var/run/libpod/socket/1ac46858ccfc8505e85c4fb29e62c013b6d5d3b65044877a0e222fec82da9a96/attach}
Jul 25 00:17:15 localhost.localdomain conmon[8032]: conmon 1ac46858ccfc8505e85c <ninfo>: ctl fifo path: /var/lib/containers/storage/overlay-containers/1ac46858ccfc8505e85c4fb29e62c013b6d5d3b65044877a0e222fec82da9a96/userdata/ctl
Jul 25 00:17:15 localhost.localdomain conmon[8032]: conmon 1ac46858ccfc8505e85c <ninfo>: terminal_ctrl_fd: 16
Jul 25 00:17:15 localhost.localdomain conmon[8032]: conmon 1ac46858ccfc8505e85c <ninfo>: Accepted connection 18
Jul 25 00:17:15 localhost.localdomain conmon[8032]: conmon 1ac46858ccfc8505e85c <ninfo>: container 8041 exited with status 139
rhatdan commented 6 years ago

Could you run a sh inside of busybox or does this fail also. Do any podman run IMAGES work for you?

lukasheinrich commented 6 years ago

no all images I tried so far fail. See the vagrant box above, with that it should be possible to reproduce the behavior

mheon commented 6 years ago

I think this has to be runc - conmon seems to be working fine. Though, in the first logs, we have:

Jul 25 00:14:55 localhost.localdomain conmon[7567]: conmon 9d75cbd47d65fbefdd26 <nwarn>: stdio_input read failed Input/output erro

And that is a little concerning... but if it's only happening with -t -i and it fails without those it can't be the root cause.

lukasheinrich commented 6 years ago

I installed docker to see if it's an underlying runc problem (in the hope that both would use the runc) and get

[root@localhost vagrant]# docker run --rm -it busybox echo hello world
hello world
[root@localhost vagrant]# podman run --rm -it busybox echo hello world
[root@localhost vagrant]# echo $?
139
mheon commented 6 years ago

Could be specific to how we're using runc, but that's not easy to test. I'll try your Vagrant box later today and see if I can replicate.

rhatdan commented 6 years ago

Docker uses an internal version of runc not the public one. @mrunalp WDYT?

rhatdan commented 6 years ago

Could this be a bad version of runc?

#  podman run --rm -it busybox echo hello world
hello world
# rpm -q podman runc
podman-0.7.3-1.git0791210.fc27.x86_64
runc-1.0.0-36.gitad0f525.fc27.x86_64
lukasheinrich commented 6 years ago

i have the same

[vagrant@localhost ~]$ rpm -q podman runc podman-0.7.3-1.git0791210.fc27.x86_64 runc-1.0.0-36.gitad0f525.fc27.x86_64

[vagrant@localhost ~]$ runc --version runc version 1.0.0-rc5+dev spec: 1.0.0

On Wed, Jul 25, 2018 at 3:41 PM Daniel J Walsh notifications@github.com wrote:

Could this be a bad version of runc?

podman run --rm -it busybox echo hello world

hello world

rpm -q podman runc

podman-0.7.3-1.git0791210.fc27.x86_64 runc-1.0.0-36.gitad0f525.fc27.x86_64

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub, or mute the thread.

mrunalp commented 6 years ago

It looks like the container process is hitting a segmentation fault. If we can gather the runc config.json then it will be easier to figure out why.

mheon commented 6 years ago

podman inspect $ctrid | grep StaticDir should print the path to the container's persistent files directory; inside that directory is config.json

@lukasheinrich Can you pastebin the contents of a container's config.json?

lukasheinrich commented 6 years ago

@mheon here it is: https://gist.github.com/lukasheinrich/585f8348602d21e7e83c522d9809cc35 should we reopen this?

mheon commented 6 years ago

Sure, reopening

mheon commented 6 years ago

@lukasheinrich Sorry for the delay. That looks like the output of podman inspect - you should be looking for the config.json in the folder contained in StaticDir on line 30.

lukasheinrich commented 6 years ago

@mheon here's the config.json

https://gist.github.com/lukasheinrich/271222657b1d007389d26a288e263aac

Is there any Vagrantfile / spec that is known to work with podman? I tried both fedora-27 and fedora-28 without any luck.

lukasheinrich commented 6 years ago

FWIW manual container execution via

works

mheon commented 6 years ago

So this is specific to the way Podman is managing things, and also specific to Vagrant boxes (possible just Fedora vagrant boxes - I have a working podman on a RHEL vagrant box).

lukasheinrich commented 6 years ago

another data point: the podman preinstalled on the fedora/28-atomic-host vagrant box works fine

mheon commented 6 years ago

I am provisioning a vagrant box with the given Vagrantfile to attempt to replicate

mheon commented 6 years ago

Confirmed locally - exit status 139

mheon commented 6 years ago

Aug 06 20:42:06 localhost.localdomain conmon[4747]: conmon 1946512daa05cc22bad2 <ninfo>: container 4755 exited with status 139

The container itself is exiting

mheon commented 6 years ago

Aug 06 20:43:41 localhost.localdomain audit[4892]: AVC avc: denied { read write } for pid=4892 comm="sleep" path="/dev/null" dev="tmpfs" ino=26140 scontext=system_u:system_r:container_t:s

@rhatdan I think we have an SELinux problem here

mheon commented 6 years ago

Confirmed - setenforce 0 allows the container to be started (though I still see an error trying to unmount it)