4

I have this service:

[Unit]
Description=TimeAgent Recorder
Requires=timeagent.service

[Service]
User=deployer
Group=sudo
WorkingDirectory=/home/deployer/timeagent
Environment=HOME=/home/deployer
Environment=RAILS_ENV=production
Environment=EYE_CLIENT_TIMEOUT=120
Restart=always
RestartSec=15
Nice=1

Type=forking
PIDFile=/home/deployer/.eye/pid
ExecStart=/usr/local/bin/bundle exec eye load recorder.eye
ExecStop=/usr/local/bin/bundle exec eye quit --stop-all -t 600

[Install]
WantedBy=timeagent.service

On reboot, sometimes it does not start:

$ systemctl status timeagent-recorder
● timeagent-recorder.service - TimeAgent Recorder
   Loaded: loaded (/etc/systemd/system/timeagent-recorder.service; enabled; vendor preset: enabled)
   Active: inactive (dead) since Mon 2017-03-20 16:30:17 GMT; 42min ago
  Process: 10929 ExecStop=/usr/local/bin/bundle exec eye quit --stop-all -t 600 (code=exited, status=0/SUCCESS)
  Process: 11409 ExecStart=/usr/local/bin/bundle exec eye load recorder.eye (code=killed, signal=TERM)
 Main PID: 9236 (code=killed, signal=TERM)

Mar 20 16:30:16 Ti systemd[1]: Starting TimeAgent Recorder...
Mar 20 16:30:17 Ti systemd[1]: Stopped TimeAgent Recorder.
Mar 20 16:30:17 Ti systemd[1]: timeagent-recorder.service: Start request repeated too quickly.
Mar 20 16:30:17 Ti systemd[1]: Failed to start TimeAgent Recorder.
Mar 20 16:30:20 Ti systemd[1]: Stopped TimeAgent Recorder.
Mar 20 16:30:20 Ti systemd[1]: timeagent-recorder.service: Start request repeated too quickly.
Mar 20 16:30:20 Ti systemd[1]: Failed to start TimeAgent Recorder.
Mar 20 16:30:20 Ti systemd[1]: Stopped TimeAgent Recorder.
Mar 20 16:30:20 Ti systemd[1]: timeagent-recorder.service: Start request repeated too quickly.
Mar 20 16:30:20 Ti systemd[1]: Failed to start TimeAgent Recorder.

Here is the also some relevant output:

$ systemctl show timeagent-recorder | grep -i restart
Restart=always
RestartUSec=15s

I made sure to enable the service as well as daemon-reload, as you can see above it is enabled and systemd attempt to start it, but completely ignores RestartSec.

I'm on Ubuntu 16.04.1 LTS with systemd version 229-4ubuntu10.

Any ideas why the RestartSec=15 is not being honoured? - I also tried using RestartSec=15s which also made no difference.

EDIT:

I have changed Requires to Wants as suggested and the issue is still happening. Here is the relavant log that shows a bit more what is happening:

# journalctl -f -u timeagent-recorder
Mar 26 20:18:21 Ti bundle[7030]: Config loaded!
Mar 26 20:18:21 Ti systemd[1]: Started TimeAgent Recorder.
Mar 26 22:17:06 Ti systemd[1]: Stopping TimeAgent Recorder...
Mar 26 22:17:08 Ti bundle[22989]: Eye quit ಠ╭╮ಠ (/home/deployer)
Mar 26 22:17:08 Ti systemd[1]: Stopped TimeAgent Recorder.
Mar 26 22:17:08 Ti systemd[1]: Starting TimeAgent Recorder...
Mar 26 22:17:09 Ti bundle[23272]: Eye started! ㋡ (/home/deployer)
Mar 26 22:17:09 Ti systemd[1]: Stopped TimeAgent Recorder.
Mar 26 22:17:09 Ti systemd[1]: Starting TimeAgent Recorder...
Mar 26 22:17:09 Ti systemd[1]: timeagent-recorder.service: Control process exited, code=exited status=1
Mar 26 22:17:09 Ti systemd[1]: Stopped TimeAgent Recorder.
Mar 26 22:17:09 Ti systemd[1]: timeagent-recorder.service: Unit entered failed state.
Mar 26 22:17:09 Ti systemd[1]: timeagent-recorder.service: Failed with result 'exit-code'.
Mar 26 22:17:09 Ti systemd[1]: Starting TimeAgent Recorder...
Mar 26 22:17:09 Ti systemd[1]: Stopped TimeAgent Recorder.
Mar 26 22:17:09 Ti systemd[1]: Starting TimeAgent Recorder...
Mar 26 22:17:10 Ti systemd[1]: Stopped TimeAgent Recorder.
Mar 26 22:17:10 Ti systemd[1]: Starting TimeAgent Recorder...
Mar 26 22:17:10 Ti systemd[1]: Stopped TimeAgent Recorder.
Mar 26 22:17:10 Ti systemd[1]: timeagent-recorder.service: Start request repeated too quickly.
Mar 26 22:17:10 Ti systemd[1]: Failed to start TimeAgent Recorder.
Mar 26 22:17:10 Ti systemd[1]: Stopped TimeAgent Recorder.
Mar 26 22:17:10 Ti systemd[1]: timeagent-recorder.service: Start request repeated too quickly.
Mar 26 22:17:10 Ti systemd[1]: Failed to start TimeAgent Recorder.
  • Perhaps the issue is that your service never properly starts in the first place. Have you checked journalctl or journalctl -u timeagent-recorder to see what's killing your service about 1 second after when start is attempted? – Mark Stosberg Mar 20 '17 at 18:30
  • Yes, I have, all it shows is the same as systemctl status timeagent-recorder, just a few more lines of the starting/stopped/failed to start loop. I know why it is dying, the dependency process is up but not accepting requests yet, so that's expected. The question is why is RestartSec=15s in the [service] section being ignored? – Roman Gaufman Mar 20 '17 at 22:49
2

I believe the behavior you are experiencing is because of your Requires= dependency. According to the section on Requires= from man systemd.unit:

If one of the other units gets deactivated or its activation fails, this unit will be deactivated.

It sounds like that's what happening here. Later in the paragraph, there's this advice, which I think applies in this case:

Often, it is a better choice to use Wants= instead of Requires= in order to achieve a system that is more robust when dealing with failing services.

The documentation for Wants= says:

A weaker version of Requires=. Units listed in this option will be started if the configuring unit is. However, if the listed units fail to start or cannot be added to the transaction, this has no impact on the validity of the transaction as a whole. This is the recommended way to hook start-up of one unit to the start-up of another unit.

To answer another way: I don't think the "RequireSec=" logic is getting a chance to kick in because systemd is taking down the service because the "Require=" condition is not met.

That's my guess.

  • The thing is the process cannot run (it crashes) until the required process is started, so that is pretty accurate in terms of dependencies. If the required process is stopped, this process should also stop. I'll try this as a temporary solution, but really this process should be stopped if the required process is stopped. Is there any solution to get that to happen? - maybe some FulfilRequiredSec or similar option to delay starting/killing the process based on Requires? – Roman Gaufman Mar 23 '17 at 16:54
  • I have changed Requires to Wants and the issue is still present, I updated the question adding the relavant log. – Roman Gaufman Mar 26 '17 at 23:15
  • It seems another process was calling systemctl restart externally which triggers the repeated too quickly error! - trying to figure out why that was being called multiple times. – Roman Gaufman Mar 27 '17 at 14:03

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Not the answer you're looking for? Browse other questions tagged or ask your own question.