[systemd-devel] Unexplainable unit restart ("Start request repeated too quickly")

[Ulrich Windl]

Hi!

When installing a test package, I noticed that one unit
(iotwatch-generator.service) triggered a restart for an unknown reason. The
status is (note: no reason for restart shown):

# systemctl status iotwatch-generator.service -l
● iotwatch-generator.service - I/O performance monitor instance generator
   Loaded: loaded (/usr/lib/systemd/system/iotwatch-generator.service;
enabled; vendor preset: disabled)
   Active: failed (Result: start-limit) since Mon 2019-06-03 09:41:18 CEST;
5min ago
     Docs: man:iotwatch-generator(8)
           man:iotwatch at .service(8)
  Process: 29133 ExecStart=/usr/lib/iotwatch/iotwatch-generator
/run/systemd/system (code=exited, status=0/SUCCESS)
 Main PID: 29133 (code=exited, status=0/SUCCESS)

Jun 03 09:41:18 v04 systemd[1]: Starting I/O performance monitor instance
generator...
Jun 03 09:41:18 v04 systemd[1]: Started I/O performance monitor instance
generator.
Jun 03 09:41:22 v04 systemd[1]: iotwatch-generator.service: Start request
repeated too quickly.
Jun 03 09:41:22 v04 systemd[1]: Failed to start I/O performance monitor
instance generator.
Jun 03 09:41:22 v04 systemd[1]: iotwatch-generator.service: Unit entered
failed state.
Jun 03 09:41:22 v04 systemd[1]: iotwatch-generator.service: Failed with result
'start-limit'.

So there was a successful start, but then some spurious restart. Why?

Even from the syslog it's not obvious what was happening:

2019-06-03T09:41:17.997724+02:00 v04 systemd[1]: nss-lookup.target: Dependency
Before=nss-lookup.target dropped
2019-06-03T09:41:18.423490+02:00 v04 systemd[1]: Reloading.
2019-06-03T09:41:18.563451+02:00 v04 systemd[1]: nss-lookup.target: Dependency
Before=nss-lookup.target dropped
2019-06-03T09:41:18.629026+02:00 v04 systemd[1]: Starting I/O performance
monitor instance generator...
2019-06-03T09:41:18.920344+02:00 v04 systemd[1]: Started I/O performance
monitor instance generator.
2019-06-03T09:41:18.948167+02:00 v04 systemd[1]: Stopped target iotwatch I/O
performance monitor.
2019-06-03T09:41:18.948777+02:00 v04 systemd[1]: Stopping iotwatch I/O
performance monitor.
2019-06-03T09:41:18.968813+02:00 v04 systemd[1]: Stopping iotwatch I/O
performance monitor instance "NFS1"...
2019-06-03T09:41:18.969288+02:00 v04 systemd[1]: Stopping iotwatch I/O
performance monitor instance "LOC1"...
2019-06-03T09:41:18.983617+02:00 v04 systemd[1]: Stopping iotwatch I/O
performance monitor instance "NFS2"...
2019-06-03T09:41:19.999968+02:00 v04 systemd[1]: Stopped iotwatch I/O
performance monitor instance "LOC1".
2019-06-03T09:41:21.261539+02:00 v04 systemd[1]: Stopped iotwatch I/O
performance monitor instance "NFS2".
2019-06-03T09:41:22.242430+02:00 v04 systemd[1]: Stopped iotwatch I/O
performance monitor instance "NFS1".

???

2019-06-03T09:41:22.245206+02:00 v04 systemd[1]: iotwatch-generator.service:
Start request repeated too quickly.
2019-06-03T09:41:22.245765+02:00 v04 systemd[1]: Failed to start I/O
performance monitor instance generator.
2019-06-03T09:41:22.252361+02:00 v04 systemd[1]: Dependency failed for
iotwatch I/O performance monitor instance "NFS1".
2019-06-03T09:41:22.252938+02:00 v04 systemd[1]: iotwatch at NFS1.service: Job
iotwatch at NFS1.service/start failed with result 'dependency'.
2019-06-03T09:41:22.255010+02:00 v04 systemd[1]: Dependency failed for
iotwatch I/O performance monitor instance "NFS2".
2019-06-03T09:41:22.255437+02:00 v04 systemd[1]: iotwatch at NFS2.service: Job
iotwatch at NFS2.service/start failed with result 'dependency'.
2019-06-03T09:41:22.257206+02:00 v04 systemd[1]: Dependency failed for
iotwatch I/O performance monitor instance "LOC1".
2019-06-03T09:41:22.257624+02:00 v04 systemd[1]: iotwatch at LOC1.service: Job
iotwatch at LOC1.service/start failed with result 'dependency'.
2019-06-03T09:41:22.259280+02:00 v04 systemd[1]: iotwatch-generator.service:
Unit entered failed state.
2019-06-03T09:41:22.262985+02:00 v04 systemd[1]: iotwatch-generator.service:
Failed with result 'start-limit'.
2019-06-03T09:41:22.264438+02:00 v04 systemd[1]: Reached target iotwatch I/O
performance monitor.

iotwatch-generator.service is a "oneshot" service.

Regards,
Ulrich