Type=idle does not actually wait for all running jobs

[Martin Pitt]

In some cases there are running jobs after the default target is reached (bug 1620780). In this case, commands from Type=idle services are already started after multi-user.target is reached, not after all running jobs are finished. This is contrary to what the manpage says: "execution of the service binary is delayed until all jobs are dispatched".

This is reproducible with a standard images:ubuntu/yakkety/amd64 lxd container; add an idle unit with

# cat <<EOF > /etc/systemd/system/xxx.service
[Unit]
Description=XXX

[Service]
Type=idle
ExecStart=/bin/sh -c 'echo WASHERE; systemctl is-system-running; systemctl list-jobs'

[Install]
WantedBy=multi-user.target
EOF
systemctl enable xxx.service

Then reboot a couple of times until you hit bug 1620780:

● xxx.service - XXX
   Loaded: loaded (/etc/systemd/system/xxx.service; enabled; vendor preset: enabled)
   Active: inactive (dead) since Fri 2016-09-09 11:49:15 UTC; 1s ago
 Main PID: 221 (code=exited, status=0/SUCCESS)

Sep 09 11:49:15 y1 systemd[221]: xxx.service: Executing: /bin/sh -c 'echo WASHERE; systemctl is-system-running; systemctl list-jobs'
Sep 09 11:49:15 y1 sh[221]: WASHERE
Sep 09 11:49:15 y1 sh[221]: starting
Sep 09 11:49:15 y1 sh[221]: JOB UNIT TYPE STATE
Sep 09 11:49:15 y1 sh[221]: 4 dev-sda3.device start running
Sep 09 11:49:15 y1 sh[221]: 1 jobs listed.

So there is still a running job but xxx.service's command already ran. This breaks assumptions like in bug 1576692.

[Martin Pitt (pitti)]

Complete journal with debugging mode. Relevant parts:

Sep 09 11:49:10 y1 systemd[1]: dev-sda3.device: Reinstalled deserialized job dev-sda3.device/start as 4
Sep 09 11:49:11 y1 systemd[1]: dev-sda3.device: Reinstalled deserialized job dev-sda3.device/start as 4

Sep 09 11:49:10 y1 systemd[1]: xxx.service: Failed to reset devices.list: Operation not permitted
Sep 09 11:49:10 y1 systemd[1]: xxx.service: About to execute: /bin/sh -c 'echo WASHERE; systemctl is-system-running; systemctl list-jobs'
Sep 09 11:49:10 y1 systemd[1]: xxx.service: Forked /bin/sh as 221
Sep 09 11:49:10 y1 systemd[1]: xxx.service: Changed dead -> running
Sep 09 11:49:10 y1 systemd[1]: xxx.service: Job xxx.service/start finished, result=done
Sep 09 11:49:10 y1 systemd[1]: Started XXX.

Sep 09 11:49:15 y1 systemd[221]: xxx.service: Executing: /bin/sh -c 'echo WASHERE; systemctl is-system-running; systemctl list-jobs'
Sep 09 11:49:15 y1 systemd[302]: console-getty.service: Executing: /sbin/agetty --noclear --keep-baud console 115200,38400,9600 linux
Sep 09 11:49:15 y1 sh[221]: WASHERE
Sep 09 11:49:15 y1 sh[221]: starting
Sep 09 11:49:15 y1 sh[221]: JOB UNIT TYPE STATE
Sep 09 11:49:15 y1 sh[221]: 4 dev-sda3.device start running
Sep 09 11:49:15 y1 sh[221]: 1 jobs listed.

Sep 09 11:50:30 y1 systemd[1]: dev-sda3.device: Job dev-sda3.device/start timed out.

[Martin Pitt (pitti)]

I can confirm that in nspawn as well, and a more reliable reproducer is to add a bogus device into fstab:

    /dev/bogus /mnt ext4 nofail 0 0

[Martin Pitt (pitti)]

Turns out we misunderstood what Type=idle does, and this is just a documentation bug. Will use a different approach in invoke-rc.d and cloud-init, see bug 1576692.

[dino99 (9d9)]

Per the upstream report: closed this in 6dcda09 on Oct 11, 2016