Search code examples
linuxsystemdsystemd-timer

systemd timer running at unspecified time

I am running sync.timer and sync.service unit files on systemd 245 (245.4-4ubuntu3.13). The service runs a simple curl script (/bin/sync.sh) and is scheduled to run nightly at some time between 1AM - 3AM EST via the timer.

These has been set up for the last couple days like the following:

# sync.service
[Unit]
Description=Run sync
Requires=another.service

[Service]
TimeoutStartSec=1200
Type=oneshot
ExecStart=/bin/sync.sh
User=auto
RemainAfterExit=yes

# sync.timer
[Unit]
Description=Run sync daily between 1am - 3am EST

[Timer]
OnCalendar=*-*-* 01:00:00 America/New_York
Unit=sync.service
RandomizedDelaySec=2hr

[Install]
WantedBy=timers.target

When I initially created these unit files, it ran at 07:45:14 UTC (02:45 AM EST) on the next day as expected. However, the service has been somehow running at 00:02:xx UTC since day 2 instead of the specified time frame (notice how timer's LAST is at 06:42:14 UTC (01:42 AM EST) which is correct, but journalctl of the service unit says it ran at 00:02:26 UTC for the latest run)

# systemctl list-timers
NEXT                        LEFT          LAST                        PASSED        UNIT                         ACTIVATES
...
n/a                         n/a           Tue 2021-11-16 06:42:14 UTC 17h ago       sync.timer       sync.service

# journalctl -u sync.service
-- Logs begin at Thu 2021-11-11 21:02:16 UTC, end at Wed 2021-11-17 00:06:30 UTC. --
Nov 13 07:45:14 host-16core systemd[1]: Starting sync 
...
Nov 16 00:02:26 host-16core systemd[1]: Starting sync
...
Nov 17 00:02:03 host-16core systemd[1]: Starting sync

# timer status
 sync.timer - Run sync daily between 1am - 3am EST
     Loaded: loaded (/etc/systemd/system/sync.timer; enabled; vendor preset: enabled)
     Active: active (waiting) since Fri 2021-11-12 18:20:23 UTC; 4 days ago
    Trigger: n/a
    Triggers: ● sync.service

Nov 12 18:20:23 host-16core systemd[1]: Started Run sync daily between 1am - 3am EST.

# service status
● sync.service - Run sync
     Loaded: loaded (/etc/systemd/system/sync.service; static; vendor preset: enabled)
     Active: active (exited) since Wed 2021-11-17 00:02:04 UTC; 15min ago
TriggeredBy: ● sync.timer
    Process: 440319 ExecStart=/bin/sync.sh (code=exited, status=0/SUCCESS)
   Main PID: 440319 (code=exited, status=0/SUCCESS)

Nov 17 00:02:03 host-16core systemd[1]: Starting Run sync

I have couple questions:

  1. Why does ACTIVATE and LEFT columns have n/a value when the timer still runs on schedule?
  2. Why does sync service log's timestamp (00:02 AM UTC) doesn't match with timer's LAST column (06:42 AM UTC)?
  3. Why does sync service runs at 2AM UTC repeatedly?

edit: Updated timer's config to the following but still seeing the same behaviour:

[Timer]
OnCalendar=
OnCalendar=*-*-* 06:00:00
Unit=sync.service
RandomizedDelaySec=7200
Solution
    1. timer will have n/a tigger if the target service is still running. In this case sync.service had RemainAfterExit=yes setting so when it finished running it remained as active (exited). Removing this setting will ensure that the service will exit in inactive (dead) state and allows the timer to restart it
    2. Look at answer #3
    3. We had a separate script that restarted another.service (dependency of sync.service) at midnight. This triggered sync.service to restart as well