[Nut-upsdev] logging strategy

[Jim Klimov]

Cheers,

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

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

  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.

  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();
````

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

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

Jim


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

> I am looking at bestfortress and trying to figure out and fix some
> things, which is causing me to try to improve logging first.  A few
> questions:
>
> 0) The developer guide doesn't seem to address any of this, or did I
> miss it?
>
> 1) It seems upsdebugx prints to stdout instead of syslog if in
> foreground.  That's great but I didn't figure it out from docs.
>
> 2) I didn't find a plan for debug levels, so I made one up for
> bestfortress and put it in comments.  Did I miss a plan?  Should there
> be on in common.h?  someplace else?   Probably it's ok for each driver
> to have its own plan.
>
> 3) It looks like upsdebugx either prints (if foreground) or syslog, and
> if syslog one gets the program name.  So upsdebugx should therefore 1)
> not have the driver name and 2) should have a function, for things that
> aren't clearly locatable.  Correct?
>
> 4) I want to print mostly-ASCII strings with non-ASCII escaped.  Is
> there a routine to convert strings?  s_upsdebug_ascii output is
> difficult for mostly-ascii.  There is a log of a read string "\nOK" that
> is messy (and there's a real bug lurking that this exposes).
>
> I think I want (actually I want octal because I was raised PDP-11, but
> not trying to rock that boat):
>
>   ABCD\{LF}EFG\[89]\\
>
> or similar for printf("ABCD\nEFG%c\\", 0x89).  The point is to be
>   - compact for mostly ascii
>   - unambigous
>   - guaranteed printable only
>   - otherwise as simple as possible
>
> How would people feel about adjusting upsdebug_ascii to do this?  I
> would consider a PR if it is ok, and skip the effort if not.
>
>
>
> _______________________________________________
> Nut-upsdev mailing list
> Nut-upsdev at alioth-lists.debian.net
> https://alioth-lists.debian.net/cgi-bin/mailman/listinfo/nut-upsdev
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://alioth-lists.debian.net/pipermail/nut-upsdev/attachments/20230115/aa2a6752/attachment.htm>