Nut upsdev - Jan 2023 - How verbose should NUT be by default?

Hello all,

  During discussion of https://github.com/networkupstools/nut/issues/1782
me and Greg uncovered a diametral difference of opinion about the verbosity
of NUT programs in general, and of `upsmon -K` (checking for POWERDOWNFLAG
during shutdown integration) in particular.

  To me as a sysadmin type often (in the past at least) having to
troubleshoot the tails and ends of systems' untimely (or unclean) demise,
all info about it feels like useful clues. And often is.

  Also NUT dealing in the business of cutting power to this computer, or to
others, intentionally or by misconfiguration (e.g. by spouting garbage to
serial ports that confuses an UPS that talks a different protocol), is a
bit more "special" than numerous other programs, tools, daemons and
services.

  The opposite opinion is that programs should be quiet until asked to
squeak (e.g. by restarting with higher debug verbosity... "that would help
troubleshooting why the rack went down last week, right!" says the sysadmin
me).

  So here is a shout-out to other practitioners: should NUT programs print
their banner and other info (e.g. competing daemon instance was/wasn't
found and how that was determined) every time they start by default? Or
should they indeed be revised to talk less (and then settings and
init-scripts in packaging can be tweaked to retain current behavior should
distros/users want to)? Note that an alternative is to redirect to
/dev/null the messages in init-scripts and similar integrations instead.

Jim
-------------- next part --------------
An HTML attachment was scrubbed...
URL:
<http://alioth-lists.debian.net/pipermail/nut-upsuser/attachments/20230109/48a26ff5/attachment.htm>

Verbosity is useful. How about adding a -q for quiet operation.

nomad
-------------- next part --------------
An HTML attachment was scrubbed...
URL:
<http://alioth-lists.debian.net/pipermail/nut-upsuser/attachments/20230109/9e644676/attachment-0001.htm>

Thanks,

  A "-q" (or an envvar to same effect) is another way to skin the cat,
as
discussed in that ticket and now followed-up by
https://github.com/networkupstools/nut/issues/1789

  It still leaves open the question of whether default runs of NUT programs
- especially as services or shutdown hooks - should be that quiet (whether
because C code is changed unconditionally, or conditionally with such an
option or envvar, or by redirecting "noise" from scripts to
/dev/null)?..
Say, for `upsmon -K` example, is it useful to know that "power down was NOT
requested" and why (may be misconfig, e.g. flag file left on an unmounted
filesystem) - or is it indeed useless noise for the dozens of
"ordinary"
reboots and shutdowns which happen not because of a power failure?

Jim


On Mon, Jan 9, 2023 at 6:01 PM Lee Damon <lvd at uw.edu> wrote:
> Verbosity is useful. How about adding a -q for quiet operation.
>
> nomad
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL:
<http://alioth-lists.debian.net/pipermail/nut-upsuser/attachments/20230109/fef74c67/attachment.htm>

Jim Klimov via Nut-upsuser <nut-upsuser at alioth-lists.debian.net>
writes:
>   The opposite opinion is that programs should be quiet until asked to
> squeak (e.g. by restarting with higher debug verbosity... "that would
help
> troubleshooting why the rack went down last week, right!" says the
sysadmin
> me).
That's a fair summary but my opinion is:

  daemon-type programs should not by default emit things to
  stdout/stderr, unless the daemon can't run.  Things like "upsd
  2.8.0.1" started are ok in syslog at LOG_INFO and we could probably
  regularize that.

  version is not interesting, because it's easy to tell what version is
  installed, and a well-run system has only one copy of nut.  And -D can
  print it to find out; it will be the same after a failure or before.

  "upsmon -K", documented to return 0/1, should not print by default
    version
    that there is no pidfile
    that a upsmon daemon is or is not running
    the location of POWERDOWNFLAG
    and even that POWERDOWNFLAG is not set
  I'm ok with printing one line to stdout that it is set, because that's
  a big deal.
  I'm -1 but not a big deal on printing that is NOT set, because that's
  normal.
  I think it would be good to stat the dir containing POWERDOWNFLAG and
  print a warning if it is not there.

  All the notable things that lead to shutdown (UPS going on battery,
  lowbatt, decision to shutdown, setting FSD flag, setting killpower,
  calling shutdown) are fair game for syslog.

  syslog should mostly survive for post-mortem analysis

  console output is ephemeral anyway, usually

  extra info is harmful because it makes everything harder to read; a
  bigger haystack to find a needle (which may be not about nut)
  
Specifically, I find all of this to be noise:

  Network UPS Tools upsmon 2.8.0.1
  Note: A previous upsmon instance is already running!
  Usually it should not be running during OS shutdown,
  which is when checking POWERDOWNFLAG makes most sense.
  UPS: foo at localhost (primary) (power value 1)
  Using power down flag file /etc/killpower
  Power down flag is not set

as the man page says "retrrns 0 or 1" and this is replacing

  if [ -f /etc/killpower ]; then

upsmon startup:

  Network UPS Tools upsmon 2.8.0.1
  kill: No such process
  UPS: foo at localhost (primary) (power value 1)
  Using power down flag file /etc/killpower

again, all knowable statically from config.

upsd:

  Network UPS Tools upsd 2.8.0.1
  fopen /var/db/nut/upsd.pid: No such file or directory
  Could not find PID file '/var/db/nut/upsd.pid' to see if previous upsd
instance is already running!
  listening on 127.0.0.1 port 3493
  listening on ::1 port 3493
  Connected to UPS [foo]: bestfortress-foo
  Found 1 UPS defined in ups.conf

again, all what was configured.
>   So here is a shout-out to other practitioners: should NUT programs print
> their banner and other info (e.g. competing daemon instance was/wasn't
> found and how that was determined) every time they start by default? Or
> should they indeed be revised to talk less (and then settings and
> init-scripts in packaging can be tweaked to retain current behavior should
> distros/users want to)? Note that an alternative is to redirect to
> /dev/null the messages in init-scripts and similar integrations instead.
It's not, because redirecting to /dev/null loses the ability for output
that is notable to appear.


And a question from me:

  Have you ever had a situation where the above verbose info, printed on
  stdout/stderr, was useful in diagnosing a previous problematic
  shutdown (a real one, not a testing one)?  If so please describe.

My take is virtually silent in normal operation. A brief startup message, and
then nothing more that critical/fatal errors and major events/state changes. If
something happens, the user/admin can turn up debug to capture the next fault
(and if there isn't, then nothing to debug). Horrific amounts of jibberish
and spew to logs under normal operation serve no purpose, make logs harder to
parse, and consume disk space. Oh, and one other option may be to be able to
alter the debug level while running, as is the case in a lot of other system
level software.

Just my $.02 . . . 

- Tim

On January 9, 2023 10:56:58 AM CST, Jim Klimov via Nut-upsdev <nut-upsdev at
alioth-lists.debian.net> wrote:
>Hello all,
>
>  During discussion of https://github.com/networkupstools/nut/issues/1782
>me and Greg uncovered a diametral difference of opinion about the verbosity
>of NUT programs in general, and of `upsmon -K` (checking for POWERDOWNFLAG
>during shutdown integration) in particular.
>
>  To me as a sysadmin type often (in the past at least) having to
>troubleshoot the tails and ends of systems' untimely (or unclean)
demise,
>all info about it feels like useful clues. And often is.
>
>  Also NUT dealing in the business of cutting power to this computer, or to
>others, intentionally or by misconfiguration (e.g. by spouting garbage to
>serial ports that confuses an UPS that talks a different protocol), is a
>bit more "special" than numerous other programs, tools, daemons
and
>services.
>
>  The opposite opinion is that programs should be quiet until asked to
>squeak (e.g. by restarting with higher debug verbosity... "that would
help
>troubleshooting why the rack went down last week, right!" says the
sysadmin
>me).
>
>  So here is a shout-out to other practitioners: should NUT programs print
>their banner and other info (e.g. competing daemon instance was/wasn't
>found and how that was determined) every time they start by default? Or
>should they indeed be revised to talk less (and then settings and
>init-scripts in packaging can be tweaked to retain current behavior should
>distros/users want to)? Note that an alternative is to redirect to
>/dev/null the messages in init-scripts and similar integrations instead.
>
>Jim
-- 
Sent from my Android device with K-9 Mail. Please excuse my brevity.
-------------- next part --------------
An HTML attachment was scrubbed...
URL:
<http://alioth-lists.debian.net/pipermail/nut-upsuser/attachments/20230109/b505c863/attachment.htm>

On Mon, 9 Jan 2023, Greg Troxel wrote:
> Specifically, I find all of this to be noise:
> upsmon startup:
>  Network UPS Tools upsmon 2.8.0.1
> again, all knowable statically from config.
>
> upsd:
>  Network UPS Tools upsd 2.8.0.1
>  listening on 127.0.0.1 port 3493
>  listening on ::1 port 3493
>  Connected to UPS [foo]: bestfortress-foo
>  Found 1 UPS defined in ups.conf
> again, all what was configured.
> And a question from me:
>  Have you ever had a situation where the above verbose info, printed on
>  stdout/stderr, was useful in diagnosing a previous problematic
>  shutdown (a real one, not a testing one)?  If so please describe.
1. There is a difference between once-only verbiage and once every hour 
verbiage.  Its the every-hour stuff that should not appear by default.

2. The once-only lines confirm that the configuration is correctly set up.

3. Its not just the problematic shutdowns that need help, but also the broken 
set-ups.

Cars are required to have indicators that left/right turn signals are operating.
One can argue that they are "noise" since the driver is supposed to
know that
he/she is turning left/right.  But a confirmation is deemed essential for safe 
driving.  It seems to me that logging ? Network UPS Tools upsd 2.8.0.1 listening
on 127.0.0.1 port 3493 listening on ::1 port 3493 ? is also essential for safe 
shutdown management.

Roger

On 1/9/23 10:56, Jim Klimov via Nut-upsdev wrote:
>  ? So here is a shout-out to other practitioners: should NUT programs print
> their banner and other info (e.g. competing daemon instance was/wasn't
found
> and how that was determined) every time they start by default? Or should
they
> indeed be revised to talk less (and then settings and init-scripts in 
> packaging can be tweaked to retain current behavior should distros/users
want
> to)? Note that an alternative is to redirect to /dev/null the messages in 
> init-scripts and similar integrations instead.
Great work and great question Jim,

   The me the question is where the additional information gets written. The 
current terse line-power lost at ... and power returned at ... or shutdown 
commanded at ... has been the norm forever. That said, I wouldn't mind an 
additional line of journal entry or syslog including what was sent in the 
event a shutdown was commanded.

   Rather that worry about a change to the current output, why not add an 
additional option like --logshutdowncmd that would cause the additional output 
to be written to the syslog facility or journal as the case may be as well as 
output on terminals like the line-power messages.

   By having an additional option, there is no change to the current default 
behavior, but for those that want the additional info, a simple option is all 
that is needed.

   Glad to see the flurry of activity with NUT in the recent past. It is a 
wonderful package and well worth the development activity.

-- 
David C. Rankin, J.D.,P.E.

> extra info is harmful because it makes everything harder to read; a
> bigger haystack to find a needle (which may be not about nut)
Yes. No news is good news. I probably count as a BSD greybeard.
> version is not interesting, because it's easy to tell what version is
> installed, and a well-run system has only one copy of nut.
I would say that in syslog, version may be interesting in case you are debugging
with different versions. You would need to write down which version ran at which
point in time otherwise.
> Have you ever had a situation where the above verbose info, printed on
> stdout/stderr, was useful in diagnosing a previous problematic
> shutdown (a real one, not a testing one)?
I can't comment on that because automatic shutdown has been on my to-do list
for ~15 years. At least "re-write the masterguard driver and submit
it" no longer is (for ~half a year).