[Nut-upsdev] logging strategy

[Jim Klimov]

> ...if syslog one gets the program name.  So upsdebugx should therefore 1)
not have the driver name...

> I was confused; syslog on my system is printing the program name.

Yes, just to clarify: syslog (protocol and common implementations) normally
add tags regarding whom it received a message from.
There may of course be some code calling upsdebugx and its format string
stating the program name (so in syslog you would see it twice), and
generally that feels like overkill :)

Jim


On Sun, Jan 15, 2023 at 6:46 PM Greg Troxel <gdt at lexort.com> wrote:

> Jim Klimov <jimklimov+nut at gmail.com> writes:
>
> >   I don't think there is any particular strategy, at least not one I'd
> know
> > of either :) So it is mostly ad-hoc, to keep smaller verbosity numbers
> > reasonably quiet, and sufficient info to see the logic progression at a
> > given debug level (e.g. if major milestones of a routine are logged at
> > level N, further traces like "I saw value X here" would be N+1 or more).
> > De-facto verbosities fizzle out at 6, but generally it is an int value,
> > so...
>
> Sounds good - what I wrote down as a plan for bestfortress very much
> matches that, 1 to 5 where 5 is if you want to see every IO byte.
>
> >   Regarding syslog/stdout/stderr, the upsdebugx*() methods are defined
> here
> > and near:
> >
> https://github.com/networkupstools/nut/blob/ad70749f243527e774c3f03a08228430143396e9/common/common.c#L1205
> > and end up calling vupslog() at which can report to stderr (not stdout)
> > and/or syslog, based on settings - see around
> >
> https://github.com/networkupstools/nut/blob/ad70749f243527e774c3f03a08228430143396e9/common/common.c#L1011
> .
> > The UPSLOG_STDERR bit is set by default, but cleared in the background()
> > method, along with raising the UPSLOG_SYSLOG bit. By default enabled
> debug
> > means staying foreground, so the bits are not changed. However "recently"
> > the explicit -F/-B flags were added to manipulate fore-/back-grounding
> > independently of debug (default behavior remains as it was).
>
> ack, makes sense.
>
> >   Note that daemons started under service management frameworks like SMF
> or
> > systemd can remain in "foreground" mode (with backgrounding handled by
> > framework forking itself), so continue logging to stderr with messages
> > landing into systemd journal or SMF service-instance log file.
>
> ok - netbsd doesn't do that (expecting things to daemonize and use
> syslog), but good to know.
>
> >   A few programs are more explicit about this, e.g.:
> > ````
> > :; git grep -n syslogbit_set
> > common/common.c:130:void syslogbit_set(void)
> > include/common.h:234:void syslogbit_set(void);
> >
> > clients/upssched.c:1341:        syslogbit_set();
> > drivers/main.c:1052:            syslogbit_set();
> > server/upsd.c:1827:     syslogbit_set();
> > ````
>
> I did find that in drivers/main.c.
>
> > So upsdebugx should therefore 1) not have the driver name and 2) should
> > have a function, for things that aren't clearly locatable.  Correct?
> >
> > 1) I don't think it prints a driver name (at least not by itself - maybe
> > some drivers or other programs pass format strings which hardcode such
> > stuff).
>
> I was confused; syslog on my system is printing the program name.
>
> > 2) a common incantation is `upsdebugx(NUM, "%s: some text", __func__);`
> to
> > take advantage of modern compilers providing the __func__ macro.
> > Technically also __FILE__ and __LINE__ may be used. Neither is guaranteed
> > across the portability board however, but that is likely to only bite
> very
> > old systems nowadays. The `configure` script tries some fallbacks for
> > __func__ but not for others.
>
> Thanks - I may try that, but I think I'm trying to write debug
> statements that are sort of human readable without code refs and also
> easily findable in the code.
>
> But ack that __func__ is acceptable.
>
> > As for s_upsdebug_ascii() - I do not think it is a perfectly good idea to
> > change it (maybe is - not much used in NUT codebase; but possibly some
> > forks have more use for it).
> > It sounds reasonable however to define and implement a different method
> for
> > this purpose, when you expect that sort of content - and call it where
> > suitable.
> >
> > Maybe makes sense to create a typical hexdump printer along the lines of
> >
> https://gist.github.com/jimklimov/07913a3e30a7d7ec50e9c946117c994f#file-jenkins-credump-L17-L41
> > (that particular code is groovy, but trivial to convert elsewhere).
>
> I want to see mostly-ascii as mostly-ascii with escapes, because that's
> what Fortress output smells like so far, rather than flipping to all
> hex (if I read groovy right).
>
> Totally fair point about not changing s_upsdebug_ascii (but I think we
> shouldn't worry about forks as socially they should contribute back).  I
> will just add a new s_upsdebug_escapedascii and friends -- works for me.
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://alioth-lists.debian.net/pipermail/nut-upsdev/attachments/20230115/2ed32c7a/attachment-0001.htm>