systemd: improved startup failure detection for simple services

[multi-io]

SUMMARY

The current systemd module doesn't detect early startup failures in services with type=simple, i.e. services whose ExecStart command should be a long-running foreground process. If that process exits with an error immediately, e.g. because of a faulty command line, the systemd module won't detect this and report success. This is due to the fact that the called systemctl start <service>, for type=simple services, just calls systemd to fire off the ExecStart command and then exits successfully (which is reasonable given the fact that systemd cannot know how the started binary will behave and when and how it'll exit, so it only starts it and reports success). This is obviously problematic as your playbook may run successfully and still leave the machine behind with services that failed to start.

Something similar can happen when stopping a service with a failing ExecStop command (if defined) -- the service will enter the "failed" instead of the "inactive" state, but the systemd module will report success.

This PR introduces a module parameter detect_early_failure (bool, default false) and associated early_failure_timeout (float, default 1.0). If detect_early_failure is set to true, the systemd module, after successfully performing the requested state change (start/stop), waits early_failure_timeout seconds and then checks whether the service has entered the failed state, and if so, reports an error.

This is obviously a heuristic approach, but fwiw it's the best we can do to detect startup failures of simple services. In an ideal world, all services would be of type=notify, and notify systemd (via sd_notify(3)) when they've initialized successfully or otherwise exit without notifying systemd. For those types of services, systemd will wait until either the notification or the service exit without notification, and thus the Ansible systemd module will work correctly without detect_early_failure. But as long as not all services have been modified to use sd_notify, this flag is useful.

ISSUE TYPE

• Feature Pull Request

COMPONENT NAME

systemd

ANSIBLE VERSION

ansible 2.4.0 (devel 859729fb01) last updated 2017/05/18 15:23:55 (GMT +200)
  config file = /Users/oklischat/src/ansible/ansible.cfg
  configured module search path = [u'/Users/oklischat/.ansible/plugins/modules', u'/usr/share/ansible/plugins/modules']
  ansible python module location = /Users/oklischat/src/ansible/lib/ansible
  executable location = /Users/oklischat/src/ansible/bin/ansible
  python version = 2.7.10 (default, Oct 23 2015, 19:19:21) [GCC 4.2.1 Compatible Apple LLVM 7.0.0 (clang-700.0.59.5)]

ADDITIONAL INFORMATION

Sample session to reproduce the behaviour:

Test service, type=simple, ExecStart is a command line that fails immediately:

root@ubuntu-xenial:~# cat /etc/systemd/system/earlyfailtest.service
[Unit]
Description=earlyfailtest service
Before=multi-user.target
Conflicts=shutdown.target

[Service]
Type=simple
IgnoreSIGPIPE=no
ExecStart=/bin/ls -wrongparams

[Install]
WantedBy=multi-user.target

root@ubuntu-xenial:~#

Start it:

$ ansible -i inventory -u ubuntu -b testhost -m systemd -a 'name=earlyfailtest.service state=started'
testhost | SUCCESS => {
    "changed": true,
    "name": "earlyfailtest.service",
    "state": "started",
    "status": {
        "ActiveEnterTimestampMonotonic": "0",
        "ActiveExitTimestampMonotonic": "0",
        "ActiveState": "inactive",
....
    }
}
$ 

=> reports success. (the fact that the returned status.ActiveState is inactive is arguably an upstream bug -- it returns the service status from immediately before the change)

However, the service has failed immediately due to the wrong ExecStart command line:

root@ubuntu-xenial:~# systemctl status earlyfailtest.service
● earlyfailtest.service - earlyfailtest service
   Loaded: loaded (/etc/systemd/system/earlyfailtest.service; disabled; vendor preset: enabled)
   Active: failed (Result: exit-code) since Thu 2017-05-18 13:56:42 UTC; 1min 27s ago
  Process: 29887 ExecStart=/bin/ls -wrongparams (code=exited, status=2)
 Main PID: 29887 (code=exited, status=2)

May 18 13:56:42 ubuntu-xenial systemd[1]: Started earlyfailtest service.
May 18 13:56:42 ubuntu-xenial ls[29887]: /bin/ls: invalid line width: ‘rongparams’
May 18 13:56:42 ubuntu-xenial systemd[1]: earlyfailtest.service: Main process exited, code=exited, status=2/INVALIDARGUMENT
May 18 13:56:42 ubuntu-xenial systemd[1]: earlyfailtest.service: Unit entered failed state.
May 18 13:56:42 ubuntu-xenial systemd[1]: earlyfailtest.service: Failed with result 'exit-code'.
root@ubuntu-xenial:~#

With detect_early_failure enabled, the startup failure is detected correctly:

$ ansible -i inventory -u ubuntu -b testhost -m systemd -a 'name=earlyfailtest.service state=started detect_early_failure=yes'
testhost | FAILED! => {
    "changed": false,
    "failed": true,
    "msg": "Failed to start service earlyfailtest.service: Service went into failed state early"
}
(stack2)oklischat@oklischat:~/src/ansible$

[bcoca]

does this make sense with a stop? in most cases 'reload' is just sending a signal to the daemon ... not sure it applies to that action either.

[multi-io]

You can reproduce it for "stop" as well. If ExecStop is defined and fails, the service goes into the "failed" state (the daemon will still be terminated). Question is, do we want to report this as a failure or not.

I agree that it makes little sense for "restart", and neither for non-service units (e.g. mount units). so maybe restrict it to just starting and stopping of service units?

[bcoca]

and restart, of course