bug#36510: confusing mcron logging

[Maxim Cournoyer]

Hi,

Maxim Cournoyer <maxim.cournoyer@gmail.com> writes:

> Dale Mellor <mcron-lsfnyl@rdmp.org> writes:

[...]

>> The output is a little unpredictable.  The script (which is
>>    admittedly somewhat pathological)
>>
>>      (job '(next-second '(0 30)) '(begin (display "test: ")
>>                                          (system "date")))
>>
>>    produces
>>
>>      2022-01-04T11:24:00 (...): running...
>>      2022-01-04T11:24:00 (...): Tue 4 Jan 11:24:00 GMT 2022
>>      2022-01-04T11:24:00 (...): test: completed in 0.022s
>>      2022-01-04T11:24:30 (...): running...
>>      2022-01-04T11:24:30 (...): Tue 4 Jan 11:24:30 GMT 2022
>>      2022-01-04T11:25:00 (...): running...
>>      2022-01-04T11:25:00 (...): Tue 4 Jan 11:25:00 GMT 2022
>>      ...

I tried reproducing this, but couldn't, using the latest GNU Shepherd as
shipped in Guix.

> I've noticed that too, that some jobs somehow escape producing the
> "completed in x..." message.  I'll try looking into that, it's probably
> a subtle bug.

I took some time looking at the issue, and it was more straightforward
than I had hoped: I was using exec in my job, which was basically
hijacking the mcron's forked job process and loosing what it would have
normally done upon completion (print status).  Turning the 'execl' calls
into 'system*' fixed it:

--8<---------------cut here---------------start------------->8---
modified   guix/hurd.scm
@@ -36,14 +36,14 @@
   ;; Run 'updatedb' at 3AM every day.
   #~(job '(next-hour '(3))
          (lambda ()
-           (execl #$(file-append findutils "/bin/updatedb") "updatedb"
-                  (string-append "--prunepaths="
-                                 "/gnu/store "
-                                 "/media "
-                                 "/mnt "
-                                 "/tmp "
-                                 "/var/tmp "
-                                 "/var/lib ")))
+           (system* #$(file-append findutils "/bin/updatedb")
+                    (string-append "--prunepaths="
+                                   "/gnu/store "
+                                   "/media "
+                                   "/mnt "
+                                   "/tmp "
+                                   "/var/tmp "
+                                   "/var/lib ")))
          "updatedb"))
 
 (define btrfs-balance-job
@@ -52,15 +52,15 @@
   ;; low (5%) to minimize wear on the SSD.  Runs at 5 AM every 3 days.
   #~(job '(next-hour-from (next-day (range 1 31 3)) '(5))
          (lambda ()
-           (execl #$(file-append btrfs-progs "/bin/btrfs") "btrfs"
-                  "balance" "start" "-dusage=5" "/"))
+           (system* #$(file-append btrfs-progs "/bin/btrfs")
+                    "balance" "start" "-dusage=5" "/"))
          "btrfs-balance"))
 
 (define btrbk-job
   #~(job '(next-hour)
          (lambda ()
-           (execl #$(file-append btrbk "/bin/btrbk") "btrbk"
-                  "-q" "-c" #$(local-file "btrbk.conf") "run"))
+           (system* #$(file-append btrbk "/bin/btrbk")
+                    "-q" "-c" #$(local-file "btrbk.conf") "run"))
          "btrbk"))
 
--8<---------------cut here---------------end--------------->8---

-- 
Thanks,
Maxim