Subject: bug#77401: [Shepherd] Timer spawns too many commands

From: Ludovic Courtès <[email-masked]>
Date: Mon, 31 Mar 2025 09:54:56 +0200

Something went wrong on berlin (Shepherd 1.0.3):

--8<---------------cut here---------------start------------->8---
2025-03-29 22:15:00 localhost shepherd[1]: Timer 'update-guix.gnu.org' spawned process 45159.
2025-03-29 22:15:00 localhost shepherd[1]: Registering new logger for update-guix.gnu.org.
2025-03-29 22:15:04 localhost shepherd[1]: Process 45159 of timer 'update-guix.gnu.org' terminated with status 0 after 4 seconds.
[...]
2025-03-29 23:15:00 localhost shepherd[1]: Timer 'update-guix.gnu.org' spawned process 38952.
2025-03-29 23:15:00 localhost shepherd[1]: Registering new logger for update-guix.gnu.org.
2025-03-29 23:15:03 localhost shepherd[1]: Process 38952 of timer 'update-guix.gnu.org' terminated with status 0 after 3 seconds.
[...]
2025-03-30 00:15:00 localhost shepherd[1]: Timer 'update-guix.gnu.org' spawned process 32759.
2025-03-30 00:15:00 localhost shepherd[1]: Registering new logger for update-guix.gnu.org.
2025-03-30 00:15:04 localhost shepherd[1]: Process 32759 of timer 'update-guix.gnu.org' terminated with status 0 after 4 seconds.
[...]
2025-03-30 01:14:12 localhost ntpd[1829]: Soliciting pool server 185.197.135.21
2025-03-30 01:15:00 localhost shepherd[1]: Timer 'update-guix.gnu.org' spawned process 51571.
2025-03-30 01:15:00 localhost shepherd[1]: Registering new logger for update-guix.gnu.org.
2025-03-30 01:15:00 localhost shepherd[1]: Timer 'update-guix.gnu.org' spawned process 51572.
2025-03-30 01:15:00 localhost shepherd[1]: Registering new logger for update-guix.gnu.org.
2025-03-30 01:15:00 localhost shepherd[1]: Timer 'update-guix.gnu.org' spawned process 51579.
2025-03-30 01:15:00 localhost shepherd[1]: Registering new logger for update-guix.gnu.org.
2025-03-30 01:15:00 localhost shepherd[1]: Timer 'update-guix.gnu.org' spawned process 51605.
2025-03-30 01:15:00 localhost shepherd[1]: Registering new logger for update-guix.gnu.org.
2025-03-30 01:15:00 localhost shepherd[1]: Timer 'update-guix.gnu.org' spawned process 51622.
2025-03-30 01:15:00 localhost shepherd[1]: Registering new logger for update-guix.gnu.org.
2025-03-30 01:15:00 localhost shepherd[1]: Timer 'update-guix.gnu.org' spawned process 51639.
2025-03-30 01:15:00 localhost shepherd[1]: Registering new logger for update-guix.gnu.org.
2025-03-30 01:15:00 localhost shepherd[1]: Timer 'update-guix.gnu.org' spawned process 51650.
2025-03-30 01:15:00 localhost shepherd[1]: Registering new logger for update-guix.gnu.org.
2025-03-30 01:15:00 localhost shepherd[1]: Timer 'update-guix.gnu.org' spawned process 51673.
2025-03-30 01:15:00 localhost shepherd[1]: Registering new logger for update-guix.gnu.org.
2025-03-30 01:15:00 localhost shepherd[1]: Timer 'update-guix.gnu.org' spawned process 51690.
2025-03-30 01:15:00 localhost shepherd[1]: Registering new logger for update-guix.gnu.org.
2025-03-30 01:15:00 localhost shepherd[1]: Timer 'update-guix.gnu.org' spawned process 51707.
2025-03-30 01:15:00 localhost shepherd[1]: Registering new logger for update-guix.gnu.org.
2025-03-30 01:15:00 localhost shepherd[1]: Timer 'update-guix.gnu.org' spawned process 51725.
2025-03-30 01:15:00 localhost shepherd[1]: Registering new logger for update-guix.gnu.org.
2025-03-30 01:15:00 localhost shepherd[1]: Timer 'update-guix.gnu.org' spawned process 51728.
2025-03-30 01:15:00 localhost shepherd[1]: Registering new logger for update-guix.gnu.org.
2025-03-30 01:15:00 localhost shepherd[1]: Timer 'update-guix.gnu.org' spawned process 51760.
2025-03-30 01:15:00 localhost shepherd[1]: Registering new logger for update-guix.gnu.org.
2025-03-30 01:15:00 localhost shepherd[1]: Timer 'update-guix.gnu.org' spawned process 51778.
2025-03-30 01:15:00 localhost shepherd[1]: Registering new logger for update-guix.gnu.org.
2025-03-30 01:15:00 localhost shepherd[1]: Timer 'update-guix.gnu.org' spawned process 51795.
2025-03-30 01:15:00 localhost shepherd[1]: Registering new logger for update-guix.gnu.org.
2025-03-30 01:15:00 localhost shepherd[1]: Timer 'update-guix.gnu.org' spawned process 51798.
2025-03-30 01:15:00 localhost shepherd[1]: Registering new logger for update-guix.gnu.org.
2025-03-30 01:15:00 localhost shepherd[1]: Timer 'update-guix.gnu.org' spawned process 51830.
2025-03-30 01:15:00 localhost shepherd[1]: Registering new logger for update-guix.gnu.org.
[...]
2025-03-30 01:15:01 localhost shepherd[1]: Registering new logger for update-guix.gnu.org.
2025-03-30 03:00:00 localhost shepherd[1]: Timer 'update-guix.gnu.org' spawned process 53303.
2025-03-30 03:00:00 localhost shepherd[1]: Registering new logger for update-guix.gnu.org.
[...]
2025-03-30 03:00:06 localhost shepherd[1]: Timer 'update-guix.gnu.org' spawned process 53334.
2025-03-30 03:00:07 localhost shepherd[1]: Registering new logger for update-guix.gnu.org.
2025-03-30 03:00:07 localhost shepherd[1]: Timer 'update-guix.gnu.org' spawned process 53351.
2025-03-30 03:00:07 localhost shepherd[1]: Waiting anew for timer 'update-guix.gnu.org' (resuming from sleep state?).
2025-03-30 03:00:07 localhost shepherd[1]: Waiting anew for timer 'update-guix.gnu.org' (resuming from sleep state?).
2025-03-30 03:00:09 localhost shepherd[1]: Waiting anew for timer 'update-guix.gnu.org' (resuming from sleep state?).
2025-03-30 03:00:09 localhost shepherd[1]: Waiting anew for timer 'update-guix.gnu.org' (resuming from sleep state?).
2025-03-30 03:00:10 localhost shepherd[1]: Waiting anew for timer 'update-guix.gnu.org' (resuming from sleep state?).
2025-03-30 03:00:10 localhost shepherd[1]: Waiting anew for timer 'update-guix.gnu.org' (resuming from sleep state?).
2025-03-30 03:00:10 localhost shepherd[1]: Waiting anew for timer 'update-guix.gnu.org' (resuming from sleep state?).
[...]
2025-03-30 03:01:23 localhost shepherd[1]: Waiting anew for timer 'update-guix.gnu.org' (resuming from sleep state?).Waiting anew for timer 'update-guix.gnu.org' (resuming from sleep state?).Waiting anew for timer 'update-guix.gnu.org' (resuming from sleep state?).Waiting anew for timer 'update-guix.gnu.org' (resuming from sleep state?).Waiting anew for timer 'update-guix.gnu.org' (resuming from sleep state?).Waiting anew for timer 'update-guix.gnu.org' (resuming from sleep state?).Waiting anew for timer 'update-guix.gnu.org' (resuming from sleep st
2025-03-30 03:01:23 localhost shepherd[1]: ate?).Waiting anew for timer 'update-guix.gnu.org' (resuming from sleep state?).Waiting anew for timer 'update-guix.gnu.org' (resuming from sleep state?).Waiting anew for timer 'update-guix.gnu.org' (resuming from sleep state?).Waiting anew for timer 'update-guix.gnu.org' (resuming from sleep state?).Waiting anew for timer 'update-guix.gnu.org' (resuming from sleep state?).Waiting anew for timer 'update-guix.gnu.org' (resuming from sleep state?).Waiting anew for timer 'update-guix.gnu.org' (resuming from sl
2025-03-30 03:01:23 localhost shepherd[1]: eep state?).Waiting anew for timer 'update-guix.gnu.org' (resuming from sleep state?).Waiting anew for timer 'update-guix.gnu.org' (resuming from sleep state?).Waiting anew for timer 'update-guix.gnu.org' (resuming from sleep state?).Waiting anew for timer 'update-guix.gnu.org' (resuming from sleep state?).Waiting anew for timer 'update-guix.gnu.org' (resuming from sleep state?).Waiting anew for timer 'update-guix.gnu.org' (resuming from sleep state?).Waiting anew for timer 'update-guix.gnu.org' (resuming f
2025-03-30 03:01:23 localhost shepherd[1]: rom sleep state?).Waiting anew for timer 'update-guix.gnu.org' (resuming from sleep state?).Waiting anew for timer 'update-guix.gnu.org' (resuming from sleep state?).Waiting anew for timer 'update-guix.gnu.org' (resuming from sleep state?).Waiting anew for timer 'update-guix.gnu.org' (resuming from sleep state?).Waiting anew for timer 'update-guix.gnu.org' (resuming from sleep state?).Waiting anew for timer 'update-guix.gnu.org' (resuming from sleep state?).Waiting anew for timer 'update-guix.gnu.org' (resu
--8<---------------cut here---------------end--------------->8---

The “waiting anew” bit could be related to the DST change, but things
went wrong before the DST change, at 1:15AM.

FWIW, the service had #:wait-for-termination? #false.

Ludo’.