1

We have a server running a bunch of cron jobs which we wanted to move to systemd timers. In the process of creating the .service and .timer files, I came across this bug on CentOS (which we are using). To ensure we would not experience the same issues, I opted to point my .service files to a simple Python script that just printed the time and the value of an environment variable. I let it run for a few days, and I found that while the timers themselves fire on time, sometimes the actual service does not run. Here's my journalctl result for the unit file:

Feb 03 15:52:28 li681-190 python3[12230]: Service "Business Script" ran at 2020-02-03 15:52:28.483885
Feb 03 15:52:28 li681-190 systemd[1]: Started business_script.py runner.
Feb 03 15:53:46 li681-190 systemd[1]: Starting business_script.py runner...
Feb 03 15:53:46 li681-190 python3[12296]: Service "Business Script" ran at 2020-02-03 15:53:46.299353
Feb 03 15:53:46 li681-190 systemd[1]: Started business_script.py runner.
Feb 03 15:55:01 li681-190 systemd[1]: Starting business_script.py runner...
Feb 03 15:55:01 li681-190 systemd[1]: Started business_script.py runner.
Feb 03 15:56:01 li681-190 systemd[1]: Starting business_script.py runner...
Feb 03 15:56:01 li681-190 python3[12427]: Service "Business Script" ran at 2020-02-03 15:56:01.952895
Feb 03 15:56:01 li681-190 systemd[1]: Started business_script.py runner.
Feb 03 15:57:02 li681-190 systemd[1]: Starting business_script.py runner...
Feb 03 15:57:02 li681-190 python3[12539]: Service "Business Script" ran at 2020-02-03 15:57:02.790428
Feb 03 15:57:02 li681-190 systemd[1]: Started business_script.py runner.

As you can see, sometimes the service runs the test script, other times it does not. I am aware that using oneshot with OnUnitActiveSec can be problematic as described in this systemd issue 6680 comment, which is weird since it's still running somewhat fine for me. As an aside, I have some OnCalendar scripts which also do not always start their service when the timer fires. Why aren't my services always running? We're running CentOS 7-6.1810.

My .timer file looks like this:

[Unit]
Description=Run business-script.py script every minute.
Requires=business-script.service

[Timer]
Unit=business-script.service
OnBootSec=1min
OnUnitActiveSec=1min

[Install]
WantedBy=timers.target

My .service file looks like this:

[Unit]
Description=timer_test.py runner
After=network.target

[Service]
User=business-script-user
Group=business-script-user
Type=oneshot

WorkingDirectory=/usr/local/bin/
ExecStart=/usr/bin/python3 timer-test.py
Environment='SERVICE_NAME="Business Script"'

[Install]
WantedBy=multi-user.target

The Python script I wrote is as follows:

import datetime
import os


def main():
    service_name = os.getenv('SERVICE_NAME')
    now = datetime.datetime.now()
    print('Service {} ran at {}'.format(service_name, now))


if __name__ == '__main__':
    main()
1

So I decided to check out the system-wide journalctl and I discovered that the script actually does fire, but it didn't log into the unit file. I suppose my original question is now incorrect and needs more investigation into a different problem.

To anyone experiencing this, check out journalctl instead of journalctl -u your-unit.service. Proof your service is running may be in there instead.

| improve this answer | |
  • 1
    There's a race condition when a process logs and exits, at that time journald tries to look at the process by its PID to find which service it belongs to (which cgroup it's in) but if the process is no longer around, it's not able to. So you end up with log entries without the unit information, as you've experienced. – filbranden Feb 13 at 4:15

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.