Support LIBUSB_DEBUG=NUM setting in ups.conf

[jimklimov]

Addresses part of #2616

A quick hack for that issue, to setenv() the envvar during configuration parsing, so hopefully the library would see it:

:; ./drivers/usbhid-ups -a eco650 -x LIBUSB_DEBUG=qqq -d 1
Network UPS Tools 2.8.2.1082.2-1084-g0520091ac (development iteration after 2.8.2) - Generic HID driver 0.57
USB communication driver (libusb 1.0) 0.49
WARNING : Invalid LIBUSB_DEBUG value found in ups.conf for the driver, defaulting to 4
Enabling LIBUSB_DEBUG=4 from ups.conf
[timestamp] [threadID] facility level [function call] <message>
--------------------------------------------------------------------------------
[ 0.000011] [001a9956] libusb: debug [libusb_init] created default context
[ 0.000019] [001a9956] libusb: debug [libusb_init] libusb v1.0.24.11584
...
ups.timer.shutdown: -1
ups.timer.start: -1
ups.vendorid: 0463
[ 7.381093] [001aa8d0] libusb: debug [libusb_close]
[ 7.381098] [001aa8d0] libusb: debug [usbi_remove_event_source] remove fd 8
[ 7.381120] [001aa8d0] libusb: debug [libusb_exit]
[ 7.381123] [001aa8d0] libusb: debug [libusb_exit] destroying default context
[ 7.381126] [001aa8d0] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 7.381129] [001aa8d0] libusb: debug [handle_events] event sources modified, reallocating event data
[ 7.381134] [001aa8d0] libusb: debug [usbi_wait_for_events] poll() 2 fds with timeout in 0ms
[ 7.381137] [001aa8d0] libusb: debug [usbi_wait_for_events] poll() returned 0
[ 7.381140] [001aa8d0] libusb: debug [libusb_unref_device] destroy device 6.1
[ 7.381143] [001aa8d0] libusb: debug [libusb_unref_device] destroy device 5.1
[ 7.381146] [001aa8d0] libusb: debug [libusb_unref_device] destroy device 4.1
[ 7.381149] [001aa8d0] libusb: debug [libusb_unref_device] destroy device 3.7
[ 7.381153] [001aa8d0] libusb: debug [libusb_unref_device] destroy device 3.6
[ 7.381157] [001aa8d0] libusb: debug [libusb_unref_device] destroy device 3.1
[ 7.381160] [001aa8d0] libusb: debug [libusb_unref_device] destroy device 2.1
[ 7.381165] [001aa8d0] libusb: debug [libusb_unref_device] destroy device 1.4
[ 7.381167] [001aa8d0] libusb: debug [libusb_unref_device] destroy device 1.1
[ 7.381170] [001aa8d0] libusb: debug [usbi_remove_event_source] remove fd 7
[ 7.381177] [001aa8d0] libusb: debug [usbi_remove_event_source] remove fd 6
[ 7.381198] [001aa8d1] libusb: debug [linux_udev_event_thread_main] udev event thread exiting

A cleaner solution would be to call libusb_set_debug() specifically, when initializing a context for device communications, but needs some more careful coding :) so can be a follow-up sometime later.

FYI : CC @masterwishx @tormodvolden

UPDATE: Checked that you can change it at run-time by setting a value in driver configuration, e.g. LIBUSB_DEBUG=4 for max verbosity, and reloading the driver. Note that unlike debug_min setting, commenting away the line does not work to tone it down -- you would have to set it to 0 explicitly and reload again (or let NDE take care of it on some platforms).

[masterwishx]

checked , working fine for nut plugin in Unraid.
the question is libusbdebug should work only befor?

usbhid-ups[29172]: Startup successful

[jimklimov]

Good question. The current implementation sets the environment variable for this process while reading configuration from ups.conf or CLI arguments.

Maybe it can also change the value during a reload signal/command processing (if it changed in ups.conf), that would be nice but I did not specifically code for that. I also did not add protocol commands to manipulate this at run-time like debug can be changed. I would not object to PRs with such exercises, but not likely would have time to make them myself (inspiration can be taken from earlier PRs that added reload and socket-protocol modification support for debug/debug_min settings - explore the trail from approx #1914).

I also see now I've only tested it with a dump mode, which does not fork(). So if you don't see the libusb debug output in a normally running driver (which forks), that may be a bug of this PR and we need to have an equivalent of export VARNAME somewhere here.

[jimklimov]

Per https://stackoverflow.com/a/17929641/4715872 discussion,

Child processes created with fork, will inherit the current processes environment definitions, thus your changes and additions as well.

So there should be no need for a separate export equivalent - this is rather shells' construct to prepare the env when they fork off each process vs. whatever the shell interpreter uses itself.

[masterwishx]

Good question. The current implementation sets the environment variable for this process while reading configuration from ups.conf or CLI arguments.

Maybe it can also change the value during a reload signal/command processing (if it changed in ups.conf), that would be nice but I did not specifically code for that. I also did not add protocol commands to manipulate this at run-time like debug can be changed. I would not object to PRs with such exercises, but not likely would have time to make them myself (inspiration can be taken from earlier PRs that added reload and socket-protocol modification support for debug/debug_min settings - explore the trail from approx #1914).

I also see now I've only tested it with a dump mode, which does not fork(). So if you don't see the libusb debug output in a normally running driver (which forks), that may be a bug of this PR and we need to have an equivalent of export VARNAME somewhere here.

Using nut plugin for Unraid, i added LIBUSB_DEBUG = 4 in ups.conf .

[masterwishx]

asl ofound some libusb debug present after line i wrote above...

[jimklimov]

So to be clear, you've added the setting and it had effect all the lifetime of the driver (regular update loop and all)?

Then it works as it should :) (run-time modification improvements speculated above being separate goals)

[masterwishx]

So to be clear, you've added the setting and it had effect all the lifetime of the driver (regular update loop and all)?

Then it works as it should :) (run-time modification improvements speculated above being separate goals)

No not at all lifetime , when debugmin = default also soemtime when =6 :

only befor usbhid-ups[10044]: Startup successful

but today i found it was also debug + libusb debug but then is gone from list . i can send debug file if you interested

[masterwishx]

nut debug log 9.10.24.txt

[jimklimov]

Maybe I got it: when we fork, stderr is normally detached (this can be maybe tweaked when dev/testing), and usbdebugx posts to syslog. But libusb's own debug probably does not, or needs more settings if it can?

I can suggest avoiding forking, e.g. -D by default keeps NUT daemons not detaching from foreground...

[tormodvolden]

Generally when you fork, the stderr fd is inherited. libusb logs to stderr by default, unless built with --enable-system-log.

[jimklimov]

Added this feature to https://github.com/networkupstools/nut/wiki/Changing-NUT-daemon-debug-verbosity

[tormodvolden]

Note that the libusb API link on the that wiki page is broken.

[jimklimov]

Thanks, fixed! Wringing it through GitHub renderer took a while (double underscores treated as HTML <em> tags even if part of link: markup otherwise (facepalm).