systemd service files as blogged have issues on reboot

[mbaldessari]

** BUG REPORT **

/kind bug

Description

After configuring a service file to start a podman container as documented here - https://podman.io/blogs/2018/09/13/systemd.html we noticed that on reboot all processes inside the container get SIGKILLED and the container has no chance of terminating gracefully.

Steps to reproduce the issue:
sudo podman pull docker.io/redis
sudo podman run -d --name redis -p 6379:6379 redis

/etc/systemd/system/redis.service:
[Unit]
Description=Redis Podman container
Wants=syslog.service

[Service]
Restart=always
ExecStart=/usr/bin/podman start -a redis
ExecStop=/usr/bin/podman stop -t 10 redis

[Install]
WantedBy=multi-user.target

sudo systemctl enable redis.service
sudo systemctl start redis.service
sudo reboot

Describe the results you received:

May 16 10:05:22 podmanreboot systemd[1]: Stopping Restore /run/initramfs on shutdown...
May 16 10:05:22 podmanreboot systemd[1]: libpod-conmon-7bfbd4ae7b10b983bc65c8a55450a2294d6e7d0b659a2d0de0d8ba2f205def55.scope: Killing process 1168 (conmon) with signal SIGKILL.
May 16 10:05:22 podmanreboot systemd[1]: Stopped libpod-conmon-7bfbd4ae7b10b983bc65c8a55450a2294d6e7d0b659a2d0de0d8ba2f205def55.scope.
May 16 10:05:22 podmanreboot systemd[1]: Stopping Authorization Manager...
May 16 10:05:22 podmanreboot systemd[1]: libpod-7bfbd4ae7b10b983bc65c8a55450a2294d6e7d0b659a2d0de0d8ba2f205def55.scope: Killing process 1201 (redis-server) with signal SIGKILL.
May 16 10:05:22 podmanreboot systemd[1]: Stopped libcontainer container 7bfbd4ae7b10b983bc65c8a55450a2294d6e7d0b659a2d0de0d8ba2f205def55.
May 16 10:05:22 podmanreboot systemd[1]: libpod-7bfbd4ae7b10b983bc65c8a55450a2294d6e7d0b659a2d0de0d8ba2f205def55.scope: Consumed 133ms CPU time
May 16 10:05:22 podmanreboot systemd[1]: Removed slice machine.slice.
May 16 10:05:22 podmanreboot systemd[1]: Removed slice system-sshd\x2dkeygen.slice.
May 16 10:05:22 podmanreboot systemd[1]: Stopping irqbalance daemon...
May 16 10:05:22 podmanreboot systemd[1]: Stopped target Login Prompts.
May 16 10:05:22 podmanreboot systemd[1]: Stopping Serial Getty on ttyS0...
May 16 10:05:22 podmanreboot systemd[7088]: Stopped target Default.
May 16 10:05:22 podmanreboot systemd[7088]: Stopped target Basic System.
May 16 10:05:22 podmanreboot systemd[7088]: Stopped target Paths.
May 16 10:05:22 podmanreboot systemd[7088]: Stopped target Sockets.
May 16 10:05:22 podmanreboot systemd[1]: Stopping Redis Podman container...

Notice how the processes in the redis container got a SIGKILL first thing after a reboot was issued and only later system tries to shut down the podman container.

Describe the results you expected:
We expected a graceful sigterm to the processes and then the 'Stopping Redis Podman container'

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

Seems pretty reproducable so far

Output of podman version:

podman version 1.2.0 (and 1.0.0)

Output of podman info --debug:

debug:
  compiler: gc
  git commit: ""
  go version: go1.11.5
  podman version: 1.2.0
host:
  BuildahVersion: 1.7.2
  Conmon:
    package: podman-1.2.0-1.git3bd528e.module+el8+3135+c5113def.x86_64
    path: /usr/libexec/podman/conmon
    version: 'conmon version 1.14.0-dev, commit: f6f8d3c7d46e7cceeb52585acdafaee26991fcb0-dirty'
  Distribution:
    distribution: '"rhel"'
    version: "8.0"
  MemFree: 3270287360
  MemTotal: 3863539712
  OCIRuntime:
    package: runc-1.0.0-54.rc5.dev.git2abd837.module+el8+2769+577ad176.x86_64
    path: /usr/bin/runc
    version: 'runc version spec: 1.0.0'
  SwapFree: 0
  SwapTotal: 0
  arch: amd64
  cpus: 4
  hostname: podmanreboot
  kernel: 4.18.0-80.el8.x86_64
  os: linux
  rootless: false
  uptime: 1h 2m 35.6s (Approximately 0.04 days)
insecure registries:
  registries:
  - brew-pulp-docker01.web.prod.ext.phx2.redhat.com:8888
registries:
  registries:
  - registry.redhat.io
  - quay.io
  - docker.io
store:
  ConfigFile: /etc/containers/storage.conf
  ContainerStore:
    number: 1
  GraphDriverName: overlay
  GraphOptions: null
  GraphRoot: /var/lib/containers/storage
  GraphStatus:
    Backing Filesystem: xfs
    Native Overlay Diff: "true"
    Supports d_type: "true"
    Using metacopy: "false"
  ImageStore:
    number: 1
  RunRoot: /var/run/containers/storage
  VolumePath: /var/lib/containers/storage/volumes

Additional environment details (AWS, VirtualBox, physical, etc.):
Issue first observed with podman from rhel8: podman-1.0.0-2.git921f98f.module+el8+2785+ff8a053f.x86_64

We also observed the problem with podman-1.2.0-1.git3bd528e.module+el8+3135+c5113def.x86_64

[mheon]

On reboot, as in as the system shuts down, or when it comes back up?

[mbaldessari]

As the system shuts down

[mheon]

So ExecStop is specified, but systemd has decided to instead send SIGKILL aggressively to everything.

Could we be talking about https://bugzilla.redhat.com/show_bug.cgi?id=1394937

[mbaldessari]

Potentially, yes I guess. What caught my attention was this 'systemd[1]: libpod-conmon-7bfbd4ae7b10b983bc65c8a55450a2294d6e7d0b659a2d0de0d8ba2f205def55.scope: Killing process 1168 (conmon) with signal SIGKILL.' . I.e. I am wondering if systemd somehow has issues (ignores deps?) with the .scope that podman creates?

[rhatdan]

@mrunalp PTAL
I know that CRI-O had to deal with something here. Mrunal would know more about it.

[cjeanner]

Hello there!
Small note: the .scope units are transient, created via the systemd socket, directly by conmon and/or libpod (at least this makes sense seeing the name of those units). Apparently they are set to be stopped/removed at a really early stage of the shutdown process. I'm pretty sure that's the issue we're hitting right now.

Would love to get @mrunalp feedback if CRI-O already dealt with that issue :).

[haircommander]

There's an upstream fix proposed for runc here: opencontainers/runc#2062

[mrunalp]

Yeah the runc PR should probably help. Could you test with that change and see if it helps?

[mbaldessari]

So I tried with an installed runc with the 2062 applied to no avail. Is updating runc, restarting the box and then rerunning the test sufficient? I left some details around my testing here https://bugzilla.redhat.com/show_bug.cgi?id=1710871#c11

[mheon]

If I'm correct, we also need to teach Podman to take advantage of the new runc feature - correct? @mrunalp

[mbaldessari]

So just an update here. Since I got back from PTO I am unable to reproduce this downstream. I'll try a bit more in the next days, but for sure it is not seen constantly as we did before. Not sure what changed under me though

[baude]

i believe this is fixed and therefore I am closing.

[mheon]

This is not fixed.