unofficial mirror of bug-guix@gnu.org 
 help / color / mirror / code / Atom feed
From: Maxim Cournoyer <maxim.cournoyer@gmail.com>
To: Dale Mellor <mcron-lsfnyl@rdmp.org>
Cc: 36510-done@debbugs.gnu.org
Subject: bug#36510: confusing mcron logging
Date: Sun, 20 Nov 2022 20:22:25 -0500	[thread overview]
Message-ID: <874jut2jam.fsf_-_@gmail.com> (raw)
In-Reply-To: <0b026b7cd95151875bf47958fc70b52764816d71.camel@rdmp.org> (Dale Mellor's message of "Tue, 04 Jan 2022 13:21:44 +0000")

Hello Dale,

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

> Hi, sorry for the delay but I've had a bit of time over Christmas
>    to look things over. I've given this a lot of consideration.

Apologies for my lack of reply thus far, it seems your mail had fallen
in cracks.

>
> I am happy to drop compatibility with guile-2.2 and older; I think we
> can make a minor version bump for this break with legacy.
>
>
>
> Does this belong in mcron?  The mcron source code is currently
>    3,000 lines, to which you are bringing over 500 new ones to
>    make a facility which is geared towards debugging in the GUIX
>    system (I am all-in on GUIX myself, but mcron is a generic GNU
>    program with use-cases outside of this system).  I wonder if
>    this is the best place: perhaps it is shepherd, which is
>    responsible for the /var/log/mcron.log file, to be responsible
>    for the amended logging messages?  And then again, isn't this
>    exactly what syslogd does anyway?  Most likely timings will be
>    more accurate if they are generated in mcron.

Since Shepherd 0.9+, it now appends logging information to every output
it handles, so this feature has indeed become less important, but still
useful: I've recently bumped our package of mcron in Guix and I'm using
its annotation facility to prepend the process ID to its output.  I
think the grunt of new lines added must be as documentation and test
code, so that's not so bad as it seems I think.

>    In your use-case, of debugging the system, I would think that
>    more specialized messages placed directly in the cron jobs
>    themselves would be a better aid to your work, as you can
>    target them to the problem at hand.  And you could send those
>    to syslogd if you wanted.

Here's a sample output from the Guix build farm:

--8<---------------cut here---------------start------------->8---
2022-11-21 01:56:15 84005 /gnu/store/ypyz886hd7qaw0g8ba5a595dc0qgnj3q-update-guix.gnu.org: running...
2022-11-21 01:59:24 84005 /gnu/store/ypyz886hd7qaw0g8ba5a595dc0qgnj3q-update-guix.gnu.org: Updating channel 'guix' from Git repository at 'https://git.savannah.gnu.org/git/guix.git'...
2022-11-21 01:59:24 84005 /gnu/store/ypyz886hd7qaw0g8ba5a595dc0qgnj3q-update-guix.gnu.org: Computing Guix derivation for 'x86_64-linux'...  
2022-11-21 01:59:24 84005 /gnu/store/ypyz886hd7qaw0g8ba5a595dc0qgnj3q-update-guix.gnu.org: [2022-11-21T01:56:18+0100] building web site from 'https://git.savannah.gnu.org/git/guix/guix-artwork.git'...
2022-11-21 01:59:24 84005 /gnu/store/ypyz886hd7qaw0g8ba5a595dc0qgnj3q-update-guix.gnu.org: completed in 189.325s
2022-11-21 02:00:00 91665 /gnu/store/xsc4x68avp8nmrf3hgvhd26yl3k90jqz-check-disk-space: running...
2022-11-21 02:00:00 91665 /gnu/store/xsc4x68avp8nmrf3hgvhd26yl3k90jqz-check-disk-space: completed in 0.046s
--8<---------------cut here---------------end--------------->8---

The timestamp is now generated by Shepherd, and mcron adds the PID of
the job, such as 84005 above.  To have some indication of how long the
job ran available at a quick glance is very useful for admin purposes.

>
>
> 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'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.

> But all things considered your changes are generally useful to
>    have, including outside of the GUIX system, and I would very
>    much like to have them there.  But to be sure not to break any
>    existing applications, I would like the changes to be opt-in
>    via a command-line switch -l; the --log-format option can
>    remain to customize this (please also make -L a short option
>    alternative; also -D as short for --date-format).
>
>    I am willing and able to do this work myself in a reasonable
>    time-frame if you would like me to.

Thank you for taking on yourself the above work, Dale!  I was happily
surprise to see this change had landed with your improvement on top.

I think this Guix issue can now be closed :-).

-- 
Thanks,
Maxim




  reply	other threads:[~2022-11-21  1:23 UTC|newest]

Thread overview: 9+ messages / expand[flat|nested]  mbox.gz  Atom feed  top
2019-07-05 13:35 bug#36510: confusing mcron logging Robert Vollmert
2019-07-05 20:37 ` Ludovic Courtès
2019-07-05 20:48   ` Robert Vollmert
2021-08-18  0:53   ` Maxim Cournoyer
2021-08-24 12:32     ` Maxim Cournoyer
2021-08-30  9:49     ` Ludovic Courtès
2022-01-04 13:21 ` bug#36510: [PATCH v3] base: Annotate output with job information Dale Mellor
2022-11-21  1:22   ` Maxim Cournoyer [this message]
2022-11-29  3:31     ` bug#36510: confusing mcron logging Maxim Cournoyer

Reply instructions:

You may reply publicly to this message via plain-text email
using any one of the following methods:

* Save the following mbox file, import it into your mail client,
  and reply-to-all from there: mbox

  Avoid top-posting and favor interleaved quoting:
  https://en.wikipedia.org/wiki/Posting_style#Interleaved_style

  List information: https://guix.gnu.org/

* Reply using the --to, --cc, and --in-reply-to
  switches of git-send-email(1):

  git send-email \
    --in-reply-to=874jut2jam.fsf_-_@gmail.com \
    --to=maxim.cournoyer@gmail.com \
    --cc=36510-done@debbugs.gnu.org \
    --cc=mcron-lsfnyl@rdmp.org \
    /path/to/YOUR_REPLY

  https://kernel.org/pub/software/scm/git/docs/git-send-email.html

* If your mail client supports setting the In-Reply-To header
  via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line before the message body.
Code repositories for project(s) associated with this public inbox

	https://git.savannah.gnu.org/cgit/guix.git

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for read-only IMAP folder(s) and NNTP newsgroup(s).