Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

"failed to claim USB device: Permission denied" error #2266

Closed
jlg89 opened this issue Jan 16, 2024 · 12 comments
Closed

"failed to claim USB device: Permission denied" error #2266

jlg89 opened this issue Jan 16, 2024 · 12 comments
Labels
impacts-release-2.7.4 Issues reported against NUT release 2.7.4 (maybe vanilla or with minor packaging tweaks) impacts-release-2.8.1 Issues reported against NUT release 2.8.1 (maybe vanilla or with minor packaging tweaks) macOS Qx protocol driver Driver based on Megatec Q<number> such as new nutdrv_qx, or obsoleted blazer and some others USB

Comments

@jlg89
Copy link

jlg89 commented Jan 16, 2024

Note: this UPS was previously connected & working with NUT on an RPi using nutdrv_qx, and I set up the same config on macOS 14.2.1. I tried NUT 2.7.4 via MacPorts and NUT 2.8.1 via Homebrew.

The driver obviously sees the device, as does macOS System Profiler, and although macOS has no built-in capability for this particular UPS, for some reason the kernel isn't releasing it.

# sudo nutdrv_qx -DDD -a myups

Network UPS Tools - Generic Q* USB driver 0.28 (2.7.4)
USB communication driver 0.33
   0.000000	debug level is '3'
   0.002868	upsdrv_initups...
   0.020903	Checking device (06DA/0201) (020/004)
   0.024206	- VendorID: 06da
   0.024227	- ProductID: 0201
   0.024235	- Manufacturer: PPC
   0.024243	- Product: USB Card
   0.024250	- Serial Number: unknown
   0.024257	- Bus: 020
   0.024265	- Device release number: 0001
   0.024272	Trying to match device
   0.024281	Device matches
   0.025573	failed to claim USB device: Permission denied
   0.025653	failed to detach kernel driver from USB device: Permission denied
   0.027185	failed to claim USB device: Permission denied
   0.027265	failed to detach kernel driver from USB device: Permission denied
   0.028315	failed to claim USB device: Permission denied
   0.028357	failed to detach kernel driver from USB device: Permission denied
   0.029724	failed to claim USB device: Permission denied
   0.030187	failed to detach kernel driver from USB device: Permission denied
   0.030203	Can't claim USB device [06da:0201]: Permission denied

NUT 2.8.1 via Homebrew has the same issue.

Network UPS Tools - Generic Q* USB/Serial driver 0.36 (2.8.1)
USB communication driver (libusb 1.0) 0.46
   0.000000	[D3] do_global_args: var='maxretry' val='5'
   0.000020	[D3] do_global_args: var='maxstartdelay' val='90'
   0.000028	[D3] main_arg: var='driver' val='nutdrv_qx'
   0.000035	[D3] main_arg: var='port' val='auto'
   0.000043	[D3] main_arg: var='desc' val='Maruson UPS'
   0.000049	[D3] main_arg: var='override.battery.packs' val='18'
   0.000064	[D3] main_arg: var='runtimecal' val='270,100,4680,13'
   0.000072	[D3] main_arg: var='chargetime' val='36000'
   0.000081	[D3] main_arg: var='default.battery.voltage.high' val='40.95'
   0.000091	[D3] main_arg: var='default.battery.voltage.low' val='31.5'
   0.000101	[D3] main_arg: var='default.battery.voltage.nominal' val='39.0'
   0.000110	[D3] main_arg: var='pollinterval' val='10'
   0.000114	[D1] testval_reloadable: setting 'pollinterval' exists and differs: new value '10' vs. '2'
   0.000127	[D1] Network UPS Tools version 2.8.1 (release/snapshot of 2.8.1) built with Apple clang version 15.0.0 (clang-1500.0.40.1); Target: x86_64-apple-darwin23.0.0; Thread model: posix and configured with flags: --disable-dependency-tracking --prefix=/usr/local/Cellar/nut/2.8.1 --localstatedir=/usr/local/var --sysconfdir=/usr/local/etc/nut --with-statepath=/usr/local/var/state/ups --with-pidpath=/usr/local/var/run --with-systemdtmpfilesdir=/usr/local/Cellar/nut/2.8.1/share/nut --with-openssl --with-serial --with-usb --without-avahi --without-cgi --without-dev --without-doc --without-ipmi --without-libltdl --without-neon --without-nss --without-nut_monitor --without-powerman --without-pynut --without-snmp --without-wrap --with-macosx_ups
   0.000136	[D1] debug level is '3'
   0.003776	[D1] Succeeded to become_user(nobody): now UID=4294967294 GID=4294967294
   0.003850	[D1] upsdrv_initups...
   0.020027	[D2] Checking device 1 of 5 (06DA/0201)
   0.024021	[D2] - VendorID: 06da
   0.024043	[D2] - ProductID: 0201
   0.024047	[D2] - Manufacturer: PPC
   0.024051	[D2] - Product: USB Card
   0.024054	[D2] - Serial Number: unknown
   0.024057	[D2] - Bus: 020
   0.024060	[D2] - Bus Port: 003
   0.024063	[D2] - Device: 004
   0.024067	[D2] - Device release number: 0001
   0.024070	[D2] Trying to match device
   0.024074	[D3] match_function_regex: matching a device...
   0.024078	[D2] Device matches
   0.024083	[D2] Reading first configuration descriptor
   0.024273	[D3] libusb_kernel_driver_active() returned 1 (driver active)
   0.024287	[D2] successfully set kernel driver auto-detach flag
   0.025528	[D2] failed to claim USB device: Access denied (insufficient permissions)
   0.025558	[D1] failed to detach kernel driver from USB device: Access denied (insufficient permissions)
   0.026269	[D2] failed to claim USB device: Access denied (insufficient permissions)
   0.026296	[D1] failed to detach kernel driver from USB device: Access denied (insufficient permissions)
   0.026979	[D2] failed to claim USB device: Access denied (insufficient permissions)
   0.027006	[D1] failed to detach kernel driver from USB device: Access denied (insufficient permissions)
   0.027691	[D2] failed to claim USB device: Access denied (insufficient permissions)
   0.027717	[D1] failed to detach kernel driver from USB device: Access denied (insufficient permissions)
   0.027724	Can't claim USB device [06da:0201]@0/0: Access denied (insufficient permissions)
   0.027734	upsnotify: failed to notify about state 4: no notification tech defined, will not spam more about it
@jlg89
Copy link
Author

jlg89 commented Jan 16, 2024

So I got a little smarter and found out there's a macosx-ups driver, so I tried that one in the homebrew install. It initially complained about the runtimecal and chargetime parameters in the config (since it doesn't support them). I commented those out, but the macosx-ups driver just doesn't even see the UPS.

So nutdrv_qx can see and ID the UPS, but can't connect to it, and macosx-ups could probably connect to it, but can't see or ID it.

Network UPS Tools - Mac OS X UPS meta-driver 1.40 (2.8.1)
Warning: This is an experimental driver.
Some features may not function correctly.

   0.000000	[D3] do_global_args: var='maxretry' val='5'
   0.000020	[D3] do_global_args: var='maxstartdelay' val='90'
   0.000032	[D3] main_arg: var='driver' val='macosx-ups'
   0.000050	[D3] main_arg: var='port' val='auto'
   0.000064	[D3] main_arg: var='desc' val='Maruson UPS'
   0.000075	[D3] main_arg: var='override.battery.packs' val='18'
   0.000101	[D3] main_arg: var='default.battery.voltage.high' val='40.95'
   0.000117	[D3] main_arg: var='default.battery.voltage.low' val='31.5'
   0.000135	[D3] main_arg: var='default.battery.voltage.nominal' val='39.0'
   0.000148	[D3] main_arg: var='pollinterval' val='10'
   0.000156	[D1] testval_reloadable: setting 'pollinterval' exists and differs: new value '10' vs. '2'
   0.000176	[D1] Network UPS Tools version 2.8.1 (release/snapshot of 2.8.1) built with Apple clang version 15.0.0 (clang-1500.0.40.1); Target: x86_64-apple-darwin23.0.0; Thread model: posix and configured with flags: --disable-dependency-tracking --prefix=/usr/local/Cellar/nut/2.8.1 --localstatedir=/usr/local/var --sysconfdir=/usr/local/etc/nut --with-statepath=/usr/local/var/state/ups --with-pidpath=/usr/local/var/run --with-systemdtmpfilesdir=/usr/local/Cellar/nut/2.8.1/share/nut --with-openssl --with-serial --with-usb --without-avahi --without-cgi --without-dev --without-doc --without-ipmi --without-libltdl --without-neon --without-nss --without-nut_monitor --without-powerman --without-pynut --without-snmp --without-wrap --with-macosx_ups
   0.000210	[D1] debug level is '3'
   0.009348	[D1] Succeeded to become_user(nobody): now UID=4294967294 GID=4294967294
   0.009409	[D3] upsdrv_initups(): Power Sources blob:
(
)
   0.010027	[D1] Number of power supplies found: 0
(
)
   0.010064	Couldn't find any UPS or battery. Is your UPS shown in the 'Energy Saver' control panel?
   0.010079	upsnotify: failed to notify about state 4: no notification tech defined, will not spam more about it

@jlg89
Copy link
Author

jlg89 commented Jan 16, 2024

The Mac does "see" the UPS, but has no ability to control it; i.e. the standard UPS controls don't appear in System Settings. So it doesn't appear to be a cable issue.

@jimklimov jimklimov added USB macOS Qx protocol driver Driver based on Megatec Q<number> such as new nutdrv_qx, or obsoleted blazer and some others impacts-release-2.7.4 Issues reported against NUT release 2.7.4 (maybe vanilla or with minor packaging tweaks) impacts-release-2.8.1 Issues reported against NUT release 2.8.1 (maybe vanilla or with minor packaging tweaks) labels Jan 20, 2024
@jimklimov
Copy link
Member

I believe macosx-ups driver taps into the OS handling of power devices as its data source, and does not talk to UPSes directly.

In the "real" driver logs, I am concerned by Succeeded to become_user(nobody): now UID=4294967294 GID=4294967294 - apparently the package was not built to define and use a dedicated user account for NUT-owned processes and files?

Per your log for 2.8.1 it was ...configured with flags: --disable-dependency-tracking --prefix=/usr/local/Cellar/nut/2.8.1 --localstatedir=/usr/local/var --sysconfdir=/usr/local/etc/nut --with-statepath=/usr/local/var/state/ups --with-pidpath=/usr/local/var/run --with-systemdtmpfilesdir=/usr/local/Cellar/nut/2.8.1/share/nut --with-openssl --with-serial --with-usb --without-avahi --without-cgi --without-dev --without-doc --without-ipmi --without-libltdl --without-neon --without-nss --without-nut_monitor --without-powerman --without-pynut --without-snmp --without-wrap --with-macosx_ups -- don't see any --with-user and --with-group here.

Also not sure if some upower or devd or whatever configuration might be needed to auto-assign permissions on device filesystem nodes for the USB device (so the NUT run-time user may actually read it).

What can help at least temporarily is to add user=root to driver options (-x for command-line testing, or as is in ups.conf section) which would tell the driver to not drop privileges after starting initially as root.

@jimklimov
Copy link
Member

CC @clepple : just in case, got any more ideas to add here? :)

@jlg89
Copy link
Author

jlg89 commented Jan 20, 2024

Added user=root to the config, that seems to have helped. Now seeing if I can get upsmon working.

Network UPS Tools - UPS driver controller 2.8.1
   0.000000	[D1] upsdrvctl commanding all drivers (1 found): (null)
   0.000021	[D1] Starting UPS: myups
   0.000046	[D1] WARNING: Requested a debugging level but not explicitly a backgrounding mode - driver may never try to fork away; however the upsdrvctl tool will fork it and not wait.
   0.000054	[D2] 5 remaining attempts
   0.000061	[D2] exec:  /usr/local/Cellar/nut/2.8.1/bin/nutdrv_qx -DDD -a myups
   0.000431	[D2] Starting driver with debug but without explicit backgrounding: will not wait for it to fork and detach, continuing...
   0.000473	[D1] upsdrvctl: successfully finished
   0.000494	[D1] Completed the job of upsdrvctl tool, cleaning up and exiting now
   0.000515	[D1] Completed the job of upsdrvctl tool, clean-up finished, exiting now
Network UPS Tools - Generic Q* USB/Serial driver 0.36 (2.8.1)
USB communication driver (libusb 1.0) 0.46
   0.000000	[D3] do_global_args: var='maxretry' val='5'
   0.000028	[D3] do_global_args: var='maxstartdelay' val='90'
   0.000040	[D3] main_arg: var='user' val='root'
   0.000049	[D1] testval_reloadable: setting 'user' exists and differs: new value 'root' vs. 'nobody'
   0.000057	[D1] Overriding previously specified user 'nobody' with 'root' specified for driver section
   0.000069	[D3] main_arg: var='driver' val='nutdrv_qx'
   0.000080	[D3] main_arg: var='port' val='auto'
   0.000098	[D3] main_arg: var='desc' val='Maruson UPS'
   0.000106	[D3] main_arg: var='override.battery.packs' val='18'
   0.000121	[D3] main_arg: var='runtimecal' val='270,100,4680,13'
   0.000129	[D3] main_arg: var='chargetime' val='36000'
   0.000138	[D3] main_arg: var='default.battery.voltage.high' val='40.95'
   0.000147	[D3] main_arg: var='default.battery.voltage.low' val='31.5'
   0.000157	[D3] main_arg: var='default.battery.voltage.nominal' val='39.0'
   0.000166	[D3] main_arg: var='pollinterval' val='10'
   0.000171	[D1] testval_reloadable: setting 'pollinterval' exists and differs: new value '10' vs. '2'
   0.000187	[D1] Network UPS Tools version 2.8.1 (release/snapshot of 2.8.1) built with Apple clang version 15.0.0 (clang-1500.0.40.1); Target: x86_64-apple-darwin23.0.0; Thread model: posix and configured with flags: --disable-dependency-tracking --prefix=/usr/local/Cellar/nut/2.8.1 --localstatedir=/usr/local/var --sysconfdir=/usr/local/etc/nut --with-statepath=/usr/local/var/state/ups --with-pidpath=/usr/local/var/run --with-systemdtmpfilesdir=/usr/local/Cellar/nut/2.8.1/share/nut --with-openssl --with-serial --with-usb --without-avahi --without-cgi --without-dev --without-doc --without-ipmi --without-libltdl --without-neon --without-nss --without-nut_monitor --without-powerman --without-pynut --without-snmp --without-wrap --with-macosx_ups
   0.000196	[D1] debug level is '3'
   0.002937	[D1] Succeeded to become_user(root): now UID=0 GID=0
   0.003010	[D1] upsdrv_initups...
   0.026331	[D2] Checking device 1 of 5 (06DA/0201)
   0.029608	[D2] - VendorID: 06da
   0.029631	[D2] - ProductID: 0201
   0.029639	[D2] - Manufacturer: PPC
   0.029646	[D2] - Product: USB Card
   0.029652	[D2] - Serial Number: unknown
   0.029657	[D2] - Bus: 020
   0.029663	[D2] - Bus Port: 003
   0.029669	[D2] - Device: 029
   0.029675	[D2] - Device release number: 0001
   0.029681	[D2] Trying to match device
   0.029687	[D3] match_function_regex: matching a device...
   0.029695	[D2] Device matches
   0.029701	[D2] Reading first configuration descriptor
   0.029879	[D3] libusb_kernel_driver_active() returned 1 (driver active)
   0.029893	[D2] successfully set kernel driver auto-detach flag
   0.033444	[D2] Claimed interface 0 successfully
   0.033483	[D3] nut_usb_set_altinterface: skipped libusb_set_interface_alt_setting(udev, 0, 0)
   0.034920	[D3] send: QGS
   0.078701	[D3] read: NAK
   0.078727	[D2] qx_process_answer: short reply (input.voltage)
   1.098993	[D3] send: Input/Output Error (-1)
   1.736270	[D2] Checking device 1 of 5 (06DA/0201)
   1.739741	[D2] - VendorID: 06da
   1.739765	[D2] - ProductID: 0201
   1.739774	[D2] - Manufacturer: PPC
   1.739781	[D2] - Product: USB Card
   1.739787	[D2] - Serial Number: unknown
   1.739793	[D2] - Bus: 020
   1.739799	[D2] - Bus Port: 003
   1.739805	[D2] - Device: 030
   1.739811	[D2] - Device release number: 0001
   1.739817	[D2] Trying to match device
   1.739824	[D3] match_function_exact: matching a device...
   1.739831	[D3] match_function_regex: matching a device...
   1.739839	[D2] Device matches
   1.739845	[D2] Reading first configuration descriptor
   1.740002	[D3] libusb_kernel_driver_active() returned 1 (driver active)
   1.740016	[D2] successfully set kernel driver auto-detach flag
   1.743013	[D2] Claimed interface 0 successfully
   1.743041	[D3] nut_usb_set_altinterface: skipped libusb_set_interface_alt_setting(udev, 0, 0)
   1.744593	[D3] send: QGS
   1.787879	[D3] read: NAK
   1.787952	[D2] qx_process_answer: short reply (input.voltage)
   2.807894	[D3] send: Input/Output Error (-1)
   3.369342	[D2] Checking device 1 of 5 (06DA/0201)
   3.373277	[D2] - VendorID: 06da
   3.373302	[D2] - ProductID: 0201
   3.373312	[D2] - Manufacturer: PPC
   3.373319	[D2] - Product: USB Card
   3.373327	[D2] - Serial Number: unknown
   3.373335	[D2] - Bus: 020
   3.373343	[D2] - Bus Port: 003
   3.373349	[D2] - Device: 031
   3.373357	[D2] - Device release number: 0001
   3.373364	[D2] Trying to match device
   3.373372	[D3] match_function_exact: matching a device...
   3.373383	[D3] match_function_regex: matching a device...
   3.373392	[D2] Device matches
   3.373400	[D2] Reading first configuration descriptor
   3.373574	[D3] libusb_kernel_driver_active() returned 1 (driver active)
   3.373621	[D2] successfully set kernel driver auto-detach flag
   3.376851	[D2] Claimed interface 0 successfully
   3.376881	[D3] nut_usb_set_altinterface: skipped libusb_set_interface_alt_setting(udev, 0, 0)
   3.378578	[D3] send: M
   3.403909	[D3] read: C
   3.403960	[D2] voltronic_qs_protocol: invalid protocol [C]
   4.421269	[D3] send: Input/Output Error (-1)
   4.978203	[D2] Checking device 1 of 5 (06DA/0201)
   4.981749	[D2] - VendorID: 06da
   4.981783	[D2] - ProductID: 0201
   4.981787	[D2] - Manufacturer: PPC
   4.981799	[D2] - Product: USB Card
   4.981803	[D2] - Serial Number: unknown
   4.981807	[D2] - Bus: 020
   4.981810	[D2] - Bus Port: 003
   4.981813	[D2] - Device: 002
   4.981817	[D2] - Device release number: 0001
   4.981820	[D2] Trying to match device
   4.981824	[D3] match_function_exact: matching a device...
   4.981828	[D3] match_function_regex: matching a device...
   4.981832	[D2] Device matches
   4.981836	[D2] Reading first configuration descriptor
   4.982025	[D3] libusb_kernel_driver_active() returned 1 (driver active)
   4.982039	[D2] successfully set kernel driver auto-detach flag
   4.984729	[D2] Claimed interface 0 successfully
   4.984755	[D3] nut_usb_set_altinterface: skipped libusb_set_interface_alt_setting(udev, 0, 0)
   4.986536	[D3] send: M
   5.011187	[D3] read: C
   5.011211	[D2] voltronic_qs_hex_protocol: invalid protocol [C]
   6.027181	[D3] send: Input/Output Error (-1)
   6.387004	[D2] Checking device 1 of 5 (06DA/0201)
   6.390487	[D2] - VendorID: 06da
   6.390506	[D2] - ProductID: 0201
   6.390513	[D2] - Manufacturer: PPC
   6.390517	[D2] - Product: USB Card
   6.390524	[D2] - Serial Number: unknown
   6.390528	[D2] - Bus: 020
   6.390532	[D2] - Bus Port: 003
   6.390535	[D2] - Device: 003
   6.390541	[D2] - Device release number: 0001
   6.390548	[D2] Trying to match device
   6.390556	[D3] match_function_exact: matching a device...
   6.390564	[D3] match_function_regex: matching a device...
   6.390573	[D2] Device matches
   6.390580	[D2] Reading first configuration descriptor
   6.390753	[D3] libusb_kernel_driver_active() returned 1 (driver active)
   6.390767	[D2] successfully set kernel driver auto-detach flag
   6.393043	[D2] Claimed interface 0 successfully
   6.393074	[D3] nut_usb_set_altinterface: skipped libusb_set_interface_alt_setting(udev, 0, 0)
   6.394726	[D3] send: M
   6.418391	[D3] read: C
   6.418416	[D2] voltronic_qs_hex_protocol: invalid protocol [C]
   7.434970	[D3] send: Input/Output Error (-1)
   7.996200	[D2] Checking device 1 of 5 (06DA/0201)
   7.999672	[D2] - VendorID: 06da
   7.999695	[D2] - ProductID: 0201
   7.999703	[D2] - Manufacturer: PPC
   7.999710	[D2] - Product: USB Card
   7.999717	[D2] - Serial Number: unknown
   7.999723	[D2] - Bus: 020
   7.999730	[D2] - Bus Port: 003
   7.999737	[D2] - Device: 004
   7.999743	[D2] - Device release number: 0001
   7.999750	[D2] Trying to match device
   7.999757	[D3] match_function_exact: matching a device...
   7.999764	[D3] match_function_regex: matching a device...
   7.999772	[D2] Device matches
   7.999779	[D2] Reading first configuration descriptor
   7.999963	[D3] libusb_kernel_driver_active() returned 1 (driver active)
   7.999974	[D2] successfully set kernel driver auto-detach flag
   8.003220	[D2] Claimed interface 0 successfully
   8.003249	[D3] nut_usb_set_altinterface: skipped libusb_set_interface_alt_setting(udev, 0, 0)
   8.004743	[D3] send: QS
   8.042801	[D3] read: NAK
   8.042825	[D2] qx_process_answer: short reply (input.voltage)
   9.068099	[D3] send: Input/Output Error (-1)
   9.621214	[D2] Checking device 1 of 5 (06DA/0201)
   9.625363	[D2] - VendorID: 06da
   9.625396	[D2] - ProductID: 0201
   9.625400	[D2] - Manufacturer: PPC
   9.625404	[D2] - Product: USB Card
   9.625407	[D2] - Serial Number: unknown
   9.625410	[D2] - Bus: 020
   9.625414	[D2] - Bus Port: 003
   9.625417	[D2] - Device: 005
   9.625420	[D2] - Device release number: 0001
   9.625424	[D2] Trying to match device
   9.625428	[D3] match_function_exact: matching a device...
   9.625432	[D3] match_function_regex: matching a device...
   9.625436	[D2] Device matches
   9.625449	[D2] Reading first configuration descriptor
   9.625614	[D3] libusb_kernel_driver_active() returned 1 (driver active)
   9.625627	[D2] successfully set kernel driver auto-detach flag
   9.628198	[D2] Claimed interface 0 successfully
   9.628223	[D3] nut_usb_set_altinterface: skipped libusb_set_interface_alt_setting(udev, 0, 0)
   9.629970	[D3] send: D
   9.651540	[D3] read:  
   9.651569	[D2] qx_process_answer: short reply (input.voltage)
  10.668697	[D3] send: Input/Output Error (-1)
  11.222512	[D2] Checking device 1 of 5 (06DA/0201)
  11.226317	[D2] - VendorID: 06da
  11.226341	[D2] - ProductID: 0201
  11.226347	[D2] - Manufacturer: PPC
  11.226354	[D2] - Product: USB Card
  11.226361	[D2] - Serial Number: unknown
  11.226367	[D2] - Bus: 020
  11.226373	[D2] - Bus Port: 003
  11.226380	[D2] - Device: 006
  11.226386	[D2] - Device release number: 0001
  11.226393	[D2] Trying to match device
  11.226400	[D3] match_function_exact: matching a device...
  11.226407	[D3] match_function_regex: matching a device...
  11.226415	[D2] Device matches
  11.226422	[D2] Reading first configuration descriptor
  11.226667	[D3] libusb_kernel_driver_active() returned 1 (driver active)
  11.226685	[D2] successfully set kernel driver auto-detach flag
  11.229320	[D2] Claimed interface 0 successfully
  11.229348	[D3] nut_usb_set_altinterface: skipped libusb_set_interface_alt_setting(udev, 0, 0)
  11.231029	[D3] send: D
  11.259139	[D3] read:  
  11.259164	[D2] qx_process_answer: short reply (input.voltage)
  12.276753	[D3] send: Input/Output Error (-1)
  12.833152	[D2] Checking device 1 of 5 (06DA/0201)
  12.837168	[D2] - VendorID: 06da
  12.837192	[D2] - ProductID: 0201
  12.837200	[D2] - Manufacturer: PPC
  12.837206	[D2] - Product: USB Card
  12.837214	[D2] - Serial Number: unknown
  12.837220	[D2] - Bus: 020
  12.837226	[D2] - Bus Port: 003
  12.837232	[D2] - Device: 007
  12.837237	[D2] - Device release number: 0001
  12.837244	[D2] Trying to match device
  12.837250	[D3] match_function_exact: matching a device...
  12.837257	[D3] match_function_regex: matching a device...
  12.837264	[D2] Device matches
  12.837270	[D2] Reading first configuration descriptor
  12.837441	[D3] libusb_kernel_driver_active() returned 1 (driver active)
  12.837455	[D2] successfully set kernel driver auto-detach flag
  12.840141	[D2] Claimed interface 0 successfully
  12.840171	[D3] nut_usb_set_altinterface: skipped libusb_set_interface_alt_setting(udev, 0, 0)
  12.841770	[D3] send: Q1
  13.067724	[D3] read: (127.8 105.6 119.5 017 60.0 2.32 00.0 00000001
  14.091089	[D3] send: Input/Output Error (-1)
  14.649194	[D2] Checking device 1 of 5 (06DA/0201)
  14.653408	[D2] - VendorID: 06da
  14.653451	[D2] - ProductID: 0201
  14.653456	[D2] - Manufacturer: PPC
  14.653460	[D2] - Product: USB Card
  14.653463	[D2] - Serial Number: unknown
  14.653466	[D2] - Bus: 020
  14.653470	[D2] - Bus Port: 003
  14.653473	[D2] - Device: 008
  14.653476	[D2] - Device release number: 0001
  14.653480	[D2] Trying to match device
  14.653484	[D3] match_function_exact: matching a device...
  14.653488	[D3] match_function_regex: matching a device...
  14.653492	[D2] Device matches
  14.653496	[D2] Reading first configuration descriptor
  14.653674	[D3] libusb_kernel_driver_active() returned 1 (driver active)
  14.653689	[D2] successfully set kernel driver auto-detach flag
  14.656128	[D2] Claimed interface 0 successfully
  14.656153	[D3] nut_usb_set_altinterface: skipped libusb_set_interface_alt_setting(udev, 0, 0)
  14.657966	[D3] send: Q1
  14.876240	[D3] read: (127.8 105.6 120.2 017 60.0 2.32 00.0 00000001
  15.904509	[D3] send: Input/Output Error (-1)
  16.264065	[D2] Checking device 1 of 5 (06DA/0201)
  16.267731	[D2] - VendorID: 06da
  16.267752	[D2] - ProductID: 0201
  16.267759	[D2] - Manufacturer: PPC
  16.267766	[D2] - Product: USB Card
  16.267772	[D2] - Serial Number: unknown
  16.267778	[D2] - Bus: 020
  16.267784	[D2] - Bus Port: 003
  16.267790	[D2] - Device: 009
  16.267797	[D2] - Device release number: 0001
  16.267803	[D2] Trying to match device
  16.267810	[D3] match_function_exact: matching a device...
  16.267817	[D3] match_function_regex: matching a device...
  16.267824	[D2] Device matches
  16.267830	[D2] Reading first configuration descriptor
  16.267989	[D3] libusb_kernel_driver_active() returned 1 (driver active)
  16.268031	[D2] successfully set kernel driver auto-detach flag
  16.270867	[D2] Claimed interface 0 successfully
  16.270893	[D3] nut_usb_set_altinterface: skipped libusb_set_interface_alt_setting(udev, 0, 0)
  16.272301	[D3] send: Q1
  16.499750	[D3] read: (127.8 105.6 119.5 017 60.0 2.32 00.0 00000001
  17.517234	[D3] send: Input/Output Error (-1)
  18.081151	[D2] Checking device 1 of 5 (06DA/0201)
  18.084773	[D2] - VendorID: 06da
  18.084795	[D2] - ProductID: 0201
  18.084876	[D2] - Manufacturer: PPC
  18.084887	[D2] - Product: USB Card
  18.084894	[D2] - Serial Number: unknown
  18.084901	[D2] - Bus: 020
  18.084908	[D2] - Bus Port: 003
  18.084915	[D2] - Device: 010
  18.084922	[D2] - Device release number: 0001
  18.084929	[D2] Trying to match device
  18.084936	[D3] match_function_exact: matching a device...
  18.084942	[D3] match_function_regex: matching a device...
  18.084950	[D2] Device matches
  18.084956	[D2] Reading first configuration descriptor
  18.085160	[D3] libusb_kernel_driver_active() returned 1 (driver active)
  18.085175	[D2] successfully set kernel driver auto-detach flag
  18.088169	[D2] Claimed interface 0 successfully
  18.088196	[D3] nut_usb_set_altinterface: skipped libusb_set_interface_alt_setting(udev, 0, 0)
  18.089802	[D3] send: Q1
  18.308564	[D3] read: (127.8 105.6 119.5 017 60.0 2.32 00.0 00000001
  19.337749	[D3] send: Input/Output Error (-1)
  19.896688	[D2] Checking device 1 of 5 (06DA/0201)
  19.900004	[D2] - VendorID: 06da
  19.900028	[D2] - ProductID: 0201
  19.900037	[D2] - Manufacturer: PPC
  19.900044	[D2] - Product: USB Card
  19.900050	[D2] - Serial Number: unknown
  19.900057	[D2] - Bus: 020
  19.900064	[D2] - Bus Port: 003
  19.900070	[D2] - Device: 011
  19.900077	[D2] - Device release number: 0001
  19.900084	[D2] Trying to match device
  19.900091	[D3] match_function_exact: matching a device...
  19.900099	[D3] match_function_regex: matching a device...
  19.900106	[D2] Device matches
  19.900118	[D2] Reading first configuration descriptor
  19.900287	[D3] libusb_kernel_driver_active() returned 1 (driver active)
  19.900303	[D2] successfully set kernel driver auto-detach flag
  19.902914	[D2] Claimed interface 0 successfully
  19.902945	[D3] nut_usb_set_altinterface: skipped libusb_set_interface_alt_setting(udev, 0, 0)
  19.904854	[D3] send: Q1
  20.124664	[D3] read: (127.8 105.6 120.2 018 60.0 2.32 00.0 00000001
  21.152634	[D3] send: Input/Output Error (-1)

@clepple
Copy link
Member

clepple commented Jan 20, 2024

@jimklimov no idea, sorry. I don't think there is an equivalent of udev or devd to assign permissions. You are correct that macosx-ups only reports what the OS UPS support can see, and I don't know of any Qx UPSes with macOS drivers that would work with that. (Possible that there are Qx user-space UPS control packages; I just haven't looked because I don't have any hardware in that category.)

In general, I don't really know what else to do with random libusb errors on macOS, especially when sending stuff works one minute, yields some data, and stops working seconds later. libusb-0.1 had a LIBUSB_DEBUG environment variable that could sometimes provide additional information. Looks like 1.0 has something similar: https://libusb.sourceforge.io/api-1.0/

@jimklimov
Copy link
Member

A QX driver's I/O error for Q1 request also brings to mind the recent effort to support more nuances about zero-bits vs. end of line, in #2154 and some preceding PRs. I am not sure OTOH if the fix applies only to armac subdriver or was generalized; there was some discussion about it but I can't quickly check at the moment.

In any case, to try this code (merged not long ago) you'd need a build of NUT from git master branch, see https://github.com/networkupstools/nut/wiki/Building-NUT-for-in%E2%80%90place-upgrades-or-non%E2%80%90disruptive-tests - note you don't have to actually install the custom build over existing NUT just for dev/testing. You can later install over that if the result is good :)

@jlg89
Copy link
Author

jlg89 commented Jan 20, 2024

I followed the instructions at the link provided, using the same config flags as the default homebrew install. The result looks pretty similar. From what the driver is spitting out, is this going to cause upsd and upsmon to fail as well? When I fire up everything, neither one is happy, and I want to be sure it's not just a stupid configuration mistake.

% sudo ./nutdrv_qx -DDD -a myups
Network UPS Tools - Generic Q* USB/Serial driver 0.36 (2.8.1-338-gb48a3deba)
USB communication driver (libusb 1.0) 0.46
   0.000000	[D1] upsdrv_makevartable...
   0.000044	[D1] Using USB implementation: libusb-1.0.26 (API: 0x1000109)
   0.000176	[D3] do_global_args: var='maxretry' val='5'
   0.000190	[D3] do_global_args: var='maxstartdelay' val='90'
   0.000202	[D3] main_arg: var='user' val='root'
   0.000211	[D1] testval_reloadable: setting 'user' exists and differs: new value 'root' vs. 'nobody'
   0.000218	[D1] Overriding previously specified user 'nobody' with 'root' specified for driver section
   0.000227	[D3] main_arg: var='driver' val='nutdrv_qx'
   0.000238	[D3] main_arg: var='port' val='auto'
   0.000246	[D3] main_arg: var='desc' val='Maruson UPS'
   0.000253	[D3] main_arg: var='override.battery.packs' val='18'
   0.000264	[D3] main_arg: var='runtimecal' val='270,100,4680,13'
   0.000271	[D3] main_arg: var='chargetime' val='36000'
   0.000279	[D3] main_arg: var='default.battery.voltage.high' val='40.95'
   0.000289	[D3] main_arg: var='default.battery.voltage.low' val='31.5'
   0.000299	[D3] main_arg: var='default.battery.voltage.nominal' val='39.0'
   0.000308	[D3] main_arg: var='pollinterval' val='10'
   0.000313	[D1] testval_reloadable: setting 'pollinterval' exists and differs: new value '10' vs. '2'
   0.000334	[D1] Network UPS Tools version 2.8.1-338-gb48a3deba (release/snapshot of 2.8.1.1) built with Apple clang version 15.0.0 (clang-1500.1.0.2.5); Target: x86_64-apple-darwin23.2.0; Thread model: posix and configured with flags: --disable-dependency-tracking --prefix=/usr/local/Cellar/nut/2.8.1 --localstatedir=/usr/local/var --sysconfdir=/usr/local/etc/nut --with-statepath=/usr/local/var/state/ups --with-pidpath=/usr/local/var/run --with-systemdtmpfilesdir=/usr/local/Cellar/nut/2.8.1/share/nut --with-openssl --with-serial --with-usb --without-avahi --without-cgi --without-dev --without-doc --without-ipmi --without-libltdl --without-neon --without-nss --without-nut_monitor --without-powerman --without-pynut --without-snmp --without-wrap --with-macosx_ups
   0.000372	[D1] debug level is '3'
   0.003030	[D1] Succeeded to become_user(root): now UID=0 GID=0
   0.003083	[D1] upsdrv_initups...
   0.020645	[D2] Checking device 1 of 5 (06DA/0201)
   0.024324	[D2] - VendorID: 06da
   0.024348	[D2] - ProductID: 0201
   0.024353	[D2] - Manufacturer: PPC
   0.024357	[D2] - Product: USB Card
   0.024360	[D2] - Serial Number: unknown
   0.024363	[D2] - Bus: 020
   0.024366	[D2] - Bus Port: 003
   0.024369	[D2] - Device: 031
   0.024373	[D2] - Device release number: 0001
   0.024376	[D2] Trying to match device
   0.024380	[D3] match_function_regex: matching a device...
   0.024395	[D2] Device matches
   0.024400	[D2] Reading configuration descriptor 1 of 1
   0.024567	[D3] libusb_kernel_driver_active() returned 1 (driver active)
   0.024579	[D2] successfully set kernel driver auto-detach flag
   0.027558	[D2] Claimed interface 0 successfully
   0.027584	[D3] nut_usb_set_altinterface: skipped libusb_set_interface_alt_setting(udev, 0, 0)
   0.029154	[D3] send: QGS
   0.070591	[D3] read: NAK
   0.070616	[D2] qx_process_answer: short reply (input.voltage)
   1.092677	[D3] send: Input/Output Error (-1)
   1.657270	[D2] Checking device 1 of 5 (06DA/0201)
   1.660874	[D2] - VendorID: 06da
   1.660897	[D2] - ProductID: 0201
   1.660907	[D2] - Manufacturer: PPC
   1.660914	[D2] - Product: USB Card
   1.660921	[D2] - Serial Number: unknown
   1.660928	[D2] - Bus: 020
   1.660934	[D2] - Bus Port: 003
   1.660940	[D2] - Device: 002
   1.660947	[D2] - Device release number: 0001
   1.660954	[D2] Trying to match device
   1.660961	[D3] match_function_exact: matching a device...
   1.660968	[D3] match_function_regex: matching a device...
   1.660976	[D2] Device matches
   1.660983	[D2] Reading configuration descriptor 1 of 1
   1.661155	[D3] libusb_kernel_driver_active() returned 1 (driver active)
   1.661168	[D2] successfully set kernel driver auto-detach flag
   1.664072	[D2] Claimed interface 0 successfully
   1.664099	[D3] nut_usb_set_altinterface: skipped libusb_set_interface_alt_setting(udev, 0, 0)
   1.665680	[D3] send: QGS
   1.703723	[D3] read: NAK
   1.703796	[D2] qx_process_answer: short reply (input.voltage)
   2.729966	[D3] send: Input/Output Error (-1)
   3.282840	[D2] Checking device 1 of 5 (06DA/0201)
   3.286829	[D2] - VendorID: 06da
   3.286864	[D2] - ProductID: 0201
   3.286868	[D2] - Manufacturer: PPC
   3.286872	[D2] - Product: USB Card
   3.286885	[D2] - Serial Number: unknown
   3.286889	[D2] - Bus: 020
   3.286892	[D2] - Bus Port: 003
   3.286895	[D2] - Device: 003
   3.286898	[D2] - Device release number: 0001
   3.286902	[D2] Trying to match device
   3.286905	[D3] match_function_exact: matching a device...
   3.286910	[D3] match_function_regex: matching a device...
   3.286914	[D2] Device matches
   3.286918	[D2] Reading configuration descriptor 1 of 1
   3.287095	[D3] libusb_kernel_driver_active() returned 1 (driver active)
   3.287107	[D2] successfully set kernel driver auto-detach flag
   3.289674	[D2] Claimed interface 0 successfully
   3.289705	[D3] nut_usb_set_altinterface: skipped libusb_set_interface_alt_setting(udev, 0, 0)
   3.291540	[D3] send: M
   3.314062	[D3] read: C
   3.314101	[D2] voltronic_qs_protocol: invalid protocol [C]
   4.330947	[D3] send: Input/Output Error (-1)
   4.890095	[D2] Checking device 1 of 5 (06DA/0201)
   4.893649	[D2] - VendorID: 06da
   4.893673	[D2] - ProductID: 0201
   4.893681	[D2] - Manufacturer: PPC
   4.893688	[D2] - Product: USB Card
   4.893694	[D2] - Serial Number: unknown
   4.893700	[D2] - Bus: 020
   4.893706	[D2] - Bus Port: 003
   4.893711	[D2] - Device: 004
   4.893717	[D2] - Device release number: 0001
   4.893723	[D2] Trying to match device
   4.893730	[D3] match_function_exact: matching a device...
   4.893736	[D3] match_function_regex: matching a device...
   4.893744	[D2] Device matches
   4.893750	[D2] Reading configuration descriptor 1 of 1
   4.894004	[D3] libusb_kernel_driver_active() returned 1 (driver active)
   4.894050	[D2] successfully set kernel driver auto-detach flag
   4.897373	[D2] Claimed interface 0 successfully
   4.897403	[D3] nut_usb_set_altinterface: skipped libusb_set_interface_alt_setting(udev, 0, 0)
   4.899098	[D3] send: M
   4.923341	[D3] read: C
   4.923368	[D2] voltronic_qs_hex_protocol: invalid protocol [C]
   5.940376	[D3] send: Input/Output Error (-1)
   6.499381	[D2] Checking device 1 of 5 (06DA/0201)
   6.502842	[D2] - VendorID: 06da
   6.502864	[D2] - ProductID: 0201
   6.502872	[D2] - Manufacturer: PPC
   6.502878	[D2] - Product: USB Card
   6.502885	[D2] - Serial Number: unknown
   6.502891	[D2] - Bus: 020
   6.502897	[D2] - Bus Port: 003
   6.502903	[D2] - Device: 005
   6.502910	[D2] - Device release number: 0001
   6.502916	[D2] Trying to match device
   6.502923	[D3] match_function_exact: matching a device...
   6.502930	[D3] match_function_regex: matching a device...
   6.502938	[D2] Device matches
   6.502945	[D2] Reading configuration descriptor 1 of 1
   6.503140	[D3] libusb_kernel_driver_active() returned 1 (driver active)
   6.503157	[D2] successfully set kernel driver auto-detach flag
   6.506831	[D2] Claimed interface 0 successfully
   6.506876	[D3] nut_usb_set_altinterface: skipped libusb_set_interface_alt_setting(udev, 0, 0)
   6.508547	[D3] send: M
   6.532129	[D3] read: C
   6.532156	[D2] voltronic_qs_hex_protocol: invalid protocol [C]
   7.549548	[D3] send: Input/Output Error (-1)
   9.310982	[D2] Checking device 1 of 5 (06DA/0201)
   9.314950	[D2] - VendorID: 06da
   9.314975	[D2] - ProductID: 0201
   9.314984	[D2] - Manufacturer: PPC
   9.314990	[D2] - Product: USB Card
   9.314995	[D2] - Serial Number: unknown
   9.314999	[D2] - Bus: 020
   9.315002	[D2] - Bus Port: 003
   9.315005	[D2] - Device: 008
   9.315011	[D2] - Device release number: 0001
   9.315014	[D2] Trying to match device
   9.315018	[D3] match_function_exact: matching a device...
   9.315022	[D3] match_function_regex: matching a device...
   9.315027	[D2] Device matches
   9.315030	[D2] Reading configuration descriptor 1 of 1
   9.315199	[D3] libusb_kernel_driver_active() returned 1 (driver active)
   9.315211	[D2] successfully set kernel driver auto-detach flag
   9.317823	[D2] Claimed interface 0 successfully
   9.317855	[D3] nut_usb_set_altinterface: skipped libusb_set_interface_alt_setting(udev, 0, 0)
   9.319560	[D3] send: QS
   9.357370	[D3] read: NAK
   9.357408	[D2] qx_process_answer: short reply (input.voltage)
  10.382095	[D3] send: Input/Output Error (-1)
  10.943033	[D2] Checking device 1 of 5 (06DA/0201)
  10.946546	[D2] - VendorID: 06da
  10.946570	[D2] - ProductID: 0201
  10.946578	[D2] - Manufacturer: PPC
  10.946585	[D2] - Product: USB Card
  10.946592	[D2] - Serial Number: unknown
  10.946599	[D2] - Bus: 020
  10.946605	[D2] - Bus Port: 003
  10.946612	[D2] - Device: 009
  10.946618	[D2] - Device release number: 0001
  10.946625	[D2] Trying to match device
  10.946632	[D3] match_function_exact: matching a device...
  10.946640	[D3] match_function_regex: matching a device...
  10.946648	[D2] Device matches
  10.946654	[D2] Reading configuration descriptor 1 of 1
  10.946841	[D3] libusb_kernel_driver_active() returned 1 (driver active)
  10.946858	[D2] successfully set kernel driver auto-detach flag
  10.949640	[D2] Claimed interface 0 successfully
  10.949669	[D3] nut_usb_set_altinterface: skipped libusb_set_interface_alt_setting(udev, 0, 0)
  10.951515	[D3] send: D
  10.975522	[D3] read:  
  10.975550	[D2] qx_process_answer: short reply (input.voltage)
  11.992915	[D3] send: Input/Output Error (-1)
  12.624513	[D2] Checking device 1 of 5 (06DA/0201)
  12.628869	[D2] - VendorID: 06da
  12.628892	[D2] - ProductID: 0201
  12.628900	[D2] - Manufacturer: PPC
  12.628906	[D2] - Product: USB Card
  12.628913	[D2] - Serial Number: unknown
  12.628919	[D2] - Bus: 020
  12.628925	[D2] - Bus Port: 003
  12.628931	[D2] - Device: 010
  12.628937	[D2] - Device release number: 0001
  12.628943	[D2] Trying to match device
  12.628949	[D3] match_function_exact: matching a device...
  12.628956	[D3] match_function_regex: matching a device...
  12.628963	[D2] Device matches
  12.628969	[D2] Reading configuration descriptor 1 of 1
  12.629146	[D3] libusb_kernel_driver_active() returned 1 (driver active)
  12.629160	[D2] successfully set kernel driver auto-detach flag
  12.631899	[D2] Claimed interface 0 successfully
  12.631926	[D3] nut_usb_set_altinterface: skipped libusb_set_interface_alt_setting(udev, 0, 0)
  12.633708	[D3] send: D
  12.660438	[D3] read:  
  12.660483	[D2] qx_process_answer: short reply (input.voltage)
  13.678024	[D3] send: Input/Output Error (-1)
  15.436150	[D2] Checking device 1 of 5 (06DA/0201)
  15.439768	[D2] - VendorID: 06da
  15.439794	[D2] - ProductID: 0201
  15.439802	[D2] - Manufacturer: PPC
  15.439808	[D2] - Product: USB Card
  15.439815	[D2] - Serial Number: unknown
  15.439822	[D2] - Bus: 020
  15.439828	[D2] - Bus Port: 003
  15.439835	[D2] - Device: 013
  15.439842	[D2] - Device release number: 0001
  15.439849	[D2] Trying to match device
  15.439854	[D3] match_function_exact: matching a device...
  15.439861	[D3] match_function_regex: matching a device...
  15.439868	[D2] Device matches
  15.439872	[D2] Reading configuration descriptor 1 of 1
  15.440073	[D3] libusb_kernel_driver_active() returned 1 (driver active)
  15.440085	[D2] successfully set kernel driver auto-detach flag
  15.443000	[D2] Claimed interface 0 successfully
  15.443029	[D3] nut_usb_set_altinterface: skipped libusb_set_interface_alt_setting(udev, 0, 0)
  15.444533	[D3] send: Q1
  15.668356	[D3] read: (125.7 105.6 120.2 016 60.0 2.32 00.0 00000001
  16.705203	[D3] send: Input/Output Error (-1)
  17.264074	[D2] Checking device 1 of 5 (06DA/0201)
  17.267444	[D2] - VendorID: 06da
  17.267466	[D2] - ProductID: 0201
  17.267474	[D2] - Manufacturer: PPC
  17.267480	[D2] - Product: USB Card
  17.267486	[D2] - Serial Number: unknown
  17.267492	[D2] - Bus: 020
  17.267498	[D2] - Bus Port: 003
  17.267504	[D2] - Device: 014
  17.267510	[D2] - Device release number: 0001
  17.267516	[D2] Trying to match device
  17.267523	[D3] match_function_exact: matching a device...
  17.267530	[D3] match_function_regex: matching a device...
  17.267537	[D2] Device matches
  17.267544	[D2] Reading configuration descriptor 1 of 1
  17.267707	[D3] libusb_kernel_driver_active() returned 1 (driver active)
  17.267722	[D2] successfully set kernel driver auto-detach flag
  17.271645	[D2] Claimed interface 0 successfully
  17.271673	[D3] nut_usb_set_altinterface: skipped libusb_set_interface_alt_setting(udev, 0, 0)
  17.273303	[D3] send: Q1
  17.493808	[D3] read: (125.7 105.6 120.2 016 60.0 2.32 00.0 00000001
  18.521884	[D3] send: Input/Output Error (-1)
  19.081469	[D2] Checking device 1 of 5 (06DA/0201)
  19.085332	[D2] - VendorID: 06da
  19.085353	[D2] - ProductID: 0201
  19.085358	[D2] - Manufacturer: PPC
  19.085362	[D2] - Product: USB Card
  19.085365	[D2] - Serial Number: unknown
  19.085368	[D2] - Bus: 020
  19.085372	[D2] - Bus Port: 003
  19.085375	[D2] - Device: 015
  19.085379	[D2] - Device release number: 0001
  19.085382	[D2] Trying to match device
  19.085386	[D3] match_function_exact: matching a device...
  19.085390	[D3] match_function_regex: matching a device...
  19.085394	[D2] Device matches
  19.085398	[D2] Reading configuration descriptor 1 of 1
  19.085539	[D3] libusb_kernel_driver_active() returned 1 (driver active)
  19.085548	[D2] successfully set kernel driver auto-detach flag
  19.088433	[D2] Claimed interface 0 successfully
  19.088461	[D3] nut_usb_set_altinterface: skipped libusb_set_interface_alt_setting(udev, 0, 0)
  19.090031	[D3] send: Q1
  19.311253	[D3] read: (125.7 105.6 120.2 016 60.0 2.32 00.0 00000001
  20.340551	[D3] send: Input/Output Error (-1)
  20.700081	[D2] Checking device 1 of 5 (06DA/0201)
  20.703950	[D2] - VendorID: 06da
  20.703975	[D2] - ProductID: 0201
  20.703983	[D2] - Manufacturer: PPC
  20.703990	[D2] - Product: USB Card
  20.703996	[D2] - Serial Number: unknown
  20.704003	[D2] - Bus: 020
  20.704008	[D2] - Bus Port: 003
  20.704014	[D2] - Device: 016
  20.704019	[D2] - Device release number: 0001
  20.704022	[D2] Trying to match device
  20.704026	[D3] match_function_exact: matching a device...
  20.704032	[D3] match_function_regex: matching a device...
  20.704040	[D2] Device matches
  20.704047	[D2] Reading configuration descriptor 1 of 1
  20.704213	[D3] libusb_kernel_driver_active() returned 1 (driver active)
  20.704224	[D2] successfully set kernel driver auto-detach flag
  20.706880	[D2] Claimed interface 0 successfully
  20.706911	[D3] nut_usb_set_altinterface: skipped libusb_set_interface_alt_setting(udev, 0, 0)
  20.708799	[D3] send: Q1
  20.927272	[D3] read: (125.7 105.6 120.2 016 60.0 2.32 00.0 00000001
  21.958717	[D3] send: Input/Output Error (-1)
  22.513850	[D2] Checking device 1 of 5 (06DA/0201)
  22.517440	[D2] - VendorID: 06da
  22.517456	[D2] - ProductID: 0201
  22.517463	[D2] - Manufacturer: PPC
  22.517468	[D2] - Product: USB Card
  22.517472	[D2] - Serial Number: unknown
  22.517475	[D2] - Bus: 020
  22.517479	[D2] - Bus Port: 003
  22.517482	[D2] - Device: 017
  22.517485	[D2] - Device release number: 0001
  22.517489	[D2] Trying to match device
  22.517493	[D3] match_function_exact: matching a device...
  22.517497	[D3] match_function_regex: matching a device...
  22.517501	[D2] Device matches
  22.517505	[D2] Reading configuration descriptor 1 of 1
  22.517640	[D3] libusb_kernel_driver_active() returned 1 (driver active)
  22.517650	[D2] successfully set kernel driver auto-detach flag
  22.520255	[D2] Claimed interface 0 successfully
  22.520281	[D3] nut_usb_set_altinterface: skipped libusb_set_interface_alt_setting(udev, 0, 0)
  22.521845	[D3] send: Q1
  22.743683	[D3] read: (125.7 105.6 120.2 016 60.0 2.32 00.0 00000001
  23.772712	[D3] send: Input/Output Error (-1)

@jlg89
Copy link
Author

jlg89 commented Jan 20, 2024

Let's make sure I'm doing this right. The script I'm using to start the custom build (and executing via sudo) is:

/Users/brazoslink/nut/drivers/nutdrv_qx -DDD -a myups &
/Users/brazoslink/nut/server/upsd -DDD
/Users/brazoslink/nut/clients/upsmon -DDD

The upsd startup either never completes or doesn't go to background, because upsmon never starts. The output I'm seeing from this is:

Network UPS Tools upsd 2.8.1-338-gb48a3deba
   0.000000	fopen /usr/local/var/state/ups/upsd.pid: No such file or directory
   0.000018	Could not find PID file '/usr/local/var/state/ups/upsd.pid' to see if previous upsd instance is already running!
Network UPS Tools - Generic Q* USB/Serial driver 0.36 (2.8.1-338-gb48a3deba)
USB communication driver (libusb 1.0) 0.46
   0.000001	[D1] upsdrv_makevartable...
   0.000075	[D1] Using USB implementation: libusb-1.0.26 (API: 0x1000109)
   0.000265	[D3] do_global_args: var='maxretry' val='5'
   0.000282	[D3] do_global_args: var='maxstartdelay' val='90'
   0.000295	[D3] main_arg: var='user' val='root'
   0.000304	[D1] testval_reloadable: setting 'user' exists and differs: new value 'root' vs. 'nobody'
   0.000314	[D1] Overriding previously specified user 'nobody' with 'root' specified for driver section
   0.000325	[D3] main_arg: var='driver' val='nutdrv_qx'
   0.000389	[D3] main_arg: var='port' val='auto'
   0.000419	[D3] main_arg: var='desc' val='Maruson UPS'
   0.000549	[D3] main_arg: var='override.battery.packs' val='18'
   0.000572	[D3] main_arg: var='runtimecal' val='270,100,4680,13'
   0.000637	[D3] main_arg: var='chargetime' val='36000'
   0.000680	[D3] main_arg: var='default.battery.voltage.high' val='40.95'
   0.000828	[D3] main_arg: var='default.battery.voltage.low' val='31.5'
   0.000848	[D3] main_arg: var='default.battery.voltage.nominal' val='39.0'
   0.000864	[D3] main_arg: var='pollinterval' val='10'
   0.000872	[D1] testval_reloadable: setting 'pollinterval' exists and differs: new value '10' vs. '2'
   0.000896	[D1] Network UPS Tools version 2.8.1-338-gb48a3deba (release/snapshot of 2.8.1.1) built with Apple clang version 15.0.0 (clang-1500.1.0.2.5); Target: x86_64-apple-darwin23.2.0; Thread model: posix and configured with flags: --disable-dependency-tracking --prefix=/usr/local/Cellar/nut/2.8.1 --localstatedir=/usr/local/var --sysconfdir=/usr/local/etc/nut --with-statepath=/usr/local/var/state/ups --with-pidpath=/usr/local/var/run --with-systemdtmpfilesdir=/usr/local/Cellar/nut/2.8.1/share/nut --with-openssl --with-serial --with-usb --without-avahi --without-cgi --without-dev --without-doc --without-ipmi --without-libltdl --without-neon --without-nss --without-nut_monitor --without-powerman --without-pynut --without-snmp --without-wrap --with-macosx_ups
   0.000909	[D1] debug level is '3'
   0.004404	/usr/local/etc/nut/upsd.conf is world readable
   0.005822	[D1] debug level is '3'
   0.005866	[D1] server_load: No LISTEN configuration provided, will try IPv6 localhost
   0.005882	[D3] listen_add: added ::1:3493
   0.005895	[D1] server_load: No LISTEN configuration provided, will try IPv4 localhost
   0.005907	[D3] listen_add: added 127.0.0.1:3493
   0.005919	[D3] setuptcp: try to bind to ::1 port 3493
   0.006135	listening on ::1 port 3493
   0.006209	[D3] setuptcp: try to bind to 127.0.0.1 port 3493
   0.006341	listening on 127.0.0.1 port 3493
   0.006368	[D1] server_load: tried to set up 2 listening sockets, succeeded with 2
   0.006385	[D3] server_load: ...of those related to localhost: overall: 2 tried, 2 succeeded; by name: 0T/0S; by name(6): 0T/0S; by IPv4 addr: 1T/1S; by IPv6 addr: 1T/1S
   0.007273	[D1] Succeeded to become_user(nobody): now UID=4294967294 GID=4294967294
   0.007318	[D1] chdired into statepath /usr/local/var/state/ups for driver sockets
   0.007351	/usr/local/var/state/ups is world readable
   0.007518	[D2] sstate_connect: preparing UNIX socket nutdrv_qx-myups
   0.007565	[D2] sstate_connect: failed to connect() UNIX socket nutdrv_qx-myups (nutdrv_qx-myups)
   0.007594	Can't connect to UPS [myups] (nutdrv_qx-myups): No such file or directory
   0.007658	Found 1 UPS defined in ups.conf
   0.005098	[D1] Succeeded to become_user(root): now UID=0 GID=0
   0.005163	[D1] upsdrv_initups...
   0.010089	/usr/local/etc/nut/upsd.users is world readable
   0.010182	[D2] user_add_action: adding 'login' for yonder
   0.010194	[D2] user_add_action: adding 'master' for yonder
   0.010231	[D2] user_add_action: adding 'fsd' for yonder
   0.010257	Running as foreground process, not saving a PID file
   0.010274	upsnotify: failed to notify about state 2: no notification tech defined, will not spam more about it
   0.010288	[D1] mainloop: UPS [myups] is not currently connected, trying to reconnect
   0.010300	[D2] sstate_connect: preparing UNIX socket nutdrv_qx-myups
   0.010342	[D2] sstate_connect: failed to connect() UNIX socket nutdrv_qx-myups (nutdrv_qx-myups)
   0.010370	[D1] mainloop: UPS [myups] is still not connected (FD -1)
   0.010383	[D2] mainloop: polling 2 filedescriptors
   0.018581	[D2] Checking device 1 of 5 (06DA/0201)
   0.022769	[D2] - VendorID: 06da
   0.022793	[D2] - ProductID: 0201
   0.022800	[D2] - Manufacturer: PPC
   0.022806	[D2] - Product: USB Card
   0.022812	[D2] - Serial Number: unknown
   0.022817	[D2] - Bus: 020
   0.022823	[D2] - Bus Port: 003
   0.022829	[D2] - Device: 013
   0.022834	[D2] - Device release number: 0001
   0.022840	[D2] Trying to match device
   0.022846	[D3] match_function_regex: matching a device...
   0.022868	[D2] Device matches
   0.022875	[D2] Reading configuration descriptor 1 of 1
   0.023059	[D3] libusb_kernel_driver_active() returned 1 (driver active)
   0.023073	[D2] successfully set kernel driver auto-detach flag
   0.026599	[D2] Claimed interface 0 successfully
   0.026627	[D3] nut_usb_set_altinterface: skipped libusb_set_interface_alt_setting(udev, 0, 0)
   0.028384	[D3] send: QGS
   0.067522	[D3] read: NAK
   0.067546	[D2] qx_process_answer: short reply (input.voltage)
   1.091793	[D3] send: Input/Output Error (-1)
   1.648896	[D2] Checking device 1 of 5 (06DA/0201)
   1.652785	[D2] - VendorID: 06da
   1.652805	[D2] - ProductID: 0201
   1.652809	[D2] - Manufacturer: PPC
   1.652813	[D2] - Product: USB Card
   1.652816	[D2] - Serial Number: unknown
   1.652819	[D2] - Bus: 020
   1.652822	[D2] - Bus Port: 003
   1.652826	[D2] - Device: 014
   1.652829	[D2] - Device release number: 0001
   1.652832	[D2] Trying to match device
   1.652836	[D3] match_function_exact: matching a device...
   1.652840	[D3] match_function_regex: matching a device...
   1.652845	[D2] Device matches
   1.652848	[D2] Reading configuration descriptor 1 of 1
   1.653010	[D3] libusb_kernel_driver_active() returned 1 (driver active)
   1.653021	[D2] successfully set kernel driver auto-detach flag
   1.655828	[D2] Claimed interface 0 successfully
   1.655894	[D3] nut_usb_set_altinterface: skipped libusb_set_interface_alt_setting(udev, 0, 0)
   1.657617	[D3] send: QGS
   1.699894	[D3] read: NAK
   1.699942	[D2] qx_process_answer: short reply (input.voltage)
   2.011158	[D2] mainloop: no data available
   2.011489	[D1] mainloop: UPS [myups] is not currently connected, trying to reconnect
   2.011553	[D2] sstate_connect: preparing UNIX socket nutdrv_qx-myups
   2.011640	[D2] sstate_connect: failed to connect() UNIX socket nutdrv_qx-myups (nutdrv_qx-myups)
   2.011722	[D1] mainloop: UPS [myups] is still not connected (FD -1)
   2.011761	[D2] mainloop: polling 2 filedescriptors
   2.720072	[D3] send: Input/Output Error (-1)
   3.276248	[D2] Checking device 1 of 5 (06DA/0201)
   3.279654	[D2] - VendorID: 06da
   3.279675	[D2] - ProductID: 0201
   3.279679	[D2] - Manufacturer: PPC
   3.279683	[D2] - Product: USB Card
   3.279686	[D2] - Serial Number: unknown
   3.279689	[D2] - Bus: 020
   3.279692	[D2] - Bus Port: 003
   3.279696	[D2] - Device: 015
   3.279699	[D2] - Device release number: 0001
   3.279703	[D2] Trying to match device
   3.279706	[D3] match_function_exact: matching a device...
   3.279710	[D3] match_function_regex: matching a device...
   3.279715	[D2] Device matches
   3.279718	[D2] Reading configuration descriptor 1 of 1
   3.279897	[D3] libusb_kernel_driver_active() returned 1 (driver active)
   3.279912	[D2] successfully set kernel driver auto-detach flag
   3.282738	[D2] Claimed interface 0 successfully
   3.282766	[D3] nut_usb_set_altinterface: skipped libusb_set_interface_alt_setting(udev, 0, 0)
   3.284387	[D3] send: M
   3.309770	[D3] read: C
   3.309802	[D2] voltronic_qs_protocol: invalid protocol [C]
   3.591341	[D2] Connect from ::1
   3.591386	[D1] mainloop: UPS [myups] is not currently connected, trying to reconnect
   3.591401	[D2] sstate_connect: preparing UNIX socket nutdrv_qx-myups
   3.591441	[D2] sstate_connect: failed to connect() UNIX socket nutdrv_qx-myups (nutdrv_qx-myups)
   3.591466	[D1] mainloop: UPS [myups] is still not connected (FD -1)
   3.591478	[D2] mainloop: polling 3 filedescriptors
   3.591991	[D2] write: [destfd=5] [len=3] [OK]
   3.592022	[D1] mainloop: UPS [myups] is not currently connected, trying to reconnect
   3.592037	[D2] sstate_connect: preparing UNIX socket nutdrv_qx-myups
   3.592076	[D2] sstate_connect: failed to connect() UNIX socket nutdrv_qx-myups (nutdrv_qx-myups)
   3.592101	[D1] mainloop: UPS [myups] is still not connected (FD -1)
   3.592116	[D2] mainloop: polling 3 filedescriptors
   4.327645	[D3] send: Input/Output Error (-1)
   4.594185	[D2] write: [destfd=5] [len=3] [OK]
   4.594232	[D1] mainloop: UPS [myups] is not currently connected, trying to reconnect
   4.594246	[D2] sstate_connect: preparing UNIX socket nutdrv_qx-myups
   4.594280	[D2] sstate_connect: failed to connect() UNIX socket nutdrv_qx-myups (nutdrv_qx-myups)
   4.594306	[D1] mainloop: UPS [myups] is still not connected (FD -1)
   4.594319	[D2] mainloop: polling 3 filedescriptors
   4.880197	[D2] Checking device 1 of 5 (06DA/0201)
   4.884041	[D2] - VendorID: 06da
   4.884061	[D2] - ProductID: 0201
   4.884065	[D2] - Manufacturer: PPC
   4.884068	[D2] - Product: USB Card
   4.884071	[D2] - Serial Number: unknown
   4.884075	[D2] - Bus: 020
   4.884078	[D2] - Bus Port: 003
   4.884081	[D2] - Device: 016
   4.884084	[D2] - Device release number: 0001
   4.884091	[D2] Trying to match device
   4.884095	[D3] match_function_exact: matching a device...
   4.884099	[D3] match_function_regex: matching a device...
   4.884103	[D2] Device matches
   4.884109	[D2] Reading configuration descriptor 1 of 1
   4.884327	[D3] libusb_kernel_driver_active() returned 1 (driver active)
   4.884341	[D2] successfully set kernel driver auto-detach flag
   4.887209	[D2] Claimed interface 0 successfully
   4.887235	[D3] nut_usb_set_altinterface: skipped libusb_set_interface_alt_setting(udev, 0, 0)
   4.888878	[D3] send: M
   4.910215	[D3] read: C
   4.910239	[D2] voltronic_qs_hex_protocol: invalid protocol [C]
   5.594922	[D2] write: [destfd=5] [len=15] [BEGIN LIST UPS]
   5.594998	[D2] write: [destfd=5] [len=24] [UPS myups "Maruson UPS"]
   5.595037	[D2] write: [destfd=5] [len=13] [END LIST UPS]
   5.595055	[D1] mainloop: UPS [myups] is not currently connected, trying to reconnect
   5.595068	[D2] sstate_connect: preparing UNIX socket nutdrv_qx-myups
   5.595111	[D2] sstate_connect: failed to connect() UNIX socket nutdrv_qx-myups (nutdrv_qx-myups)
   5.595140	[D1] mainloop: UPS [myups] is still not connected (FD -1)
   5.595154	[D2] mainloop: polling 3 filedescriptors
   5.928873	[D3] send: Input/Output Error (-1)
   6.485457	[D2] Checking device 1 of 5 (06DA/0201)
   6.489805	[D2] - VendorID: 06da
   6.489826	[D2] - ProductID: 0201
   6.489830	[D2] - Manufacturer: PPC
   6.489833	[D2] - Product: USB Card
   6.489836	[D2] - Serial Number: unknown
   6.489840	[D2] - Bus: 020
   6.489844	[D2] - Bus Port: 003
   6.489847	[D2] - Device: 017
   6.489850	[D2] - Device release number: 0001
   6.489853	[D2] Trying to match device
   6.489857	[D3] match_function_exact: matching a device...
   6.489861	[D3] match_function_regex: matching a device...
   6.489865	[D2] Device matches
   6.489869	[D2] Reading configuration descriptor 1 of 1
   6.490041	[D3] libusb_kernel_driver_active() returned 1 (driver active)
   6.490073	[D2] successfully set kernel driver auto-detach flag
   6.492934	[D2] Claimed interface 0 successfully
   6.492971	[D3] nut_usb_set_altinterface: skipped libusb_set_interface_alt_setting(udev, 0, 0)
   6.494588	[D3] send: M
   6.519259	[D3] read: C
   6.519336	[D2] voltronic_qs_hex_protocol: invalid protocol [C]
   7.537113	[D3] send: Input/Output Error (-1)
   7.595389	[D2] mainloop: no data available
   7.595436	[D1] mainloop: UPS [myups] is not currently connected, trying to reconnect
   7.595450	[D2] sstate_connect: preparing UNIX socket nutdrv_qx-myups
   7.595489	[D2] sstate_connect: failed to connect() UNIX socket nutdrv_qx-myups (nutdrv_qx-myups)
   7.595513	[D1] mainloop: UPS [myups] is still not connected (FD -1)
   7.595526	[D2] mainloop: polling 3 filedescriptors
   8.090163	[D2] Checking device 1 of 5 (06DA/0201)
   8.094323	[D2] - VendorID: 06da
   8.094344	[D2] - ProductID: 0201
   8.094349	[D2] - Manufacturer: PPC
   8.094352	[D2] - Product: USB Card
   8.094355	[D2] - Serial Number: unknown
   8.094359	[D2] - Bus: 020
   8.094362	[D2] - Bus Port: 003
   8.094365	[D2] - Device: 018
   8.094369	[D2] - Device release number: 0001
   8.094372	[D2] Trying to match device
   8.094376	[D3] match_function_exact: matching a device...
   8.094380	[D3] match_function_regex: matching a device...
   8.094384	[D2] Device matches
   8.094388	[D2] Reading configuration descriptor 1 of 1
   8.094551	[D3] libusb_kernel_driver_active() returned 1 (driver active)
   8.094563	[D2] successfully set kernel driver auto-detach flag
   8.097257	[D2] Claimed interface 0 successfully
   8.097320	[D3] nut_usb_set_altinterface: skipped libusb_set_interface_alt_setting(udev, 0, 0)
   8.099169	[D3] send: QS
   8.135742	[D3] read: NAK
   8.135785	[D2] qx_process_answer: short reply (input.voltage)
   9.161896	[D3] send: Input/Output Error (-1)
   9.595631	[D2] mainloop: no data available
   9.595718	[D1] mainloop: UPS [myups] is not currently connected, trying to reconnect
   9.595733	[D2] sstate_connect: preparing UNIX socket nutdrv_qx-myups
   9.595778	[D2] sstate_connect: failed to connect() UNIX socket nutdrv_qx-myups (nutdrv_qx-myups)
   9.595822	[D1] mainloop: UPS [myups] is still not connected (FD -1)
   9.595836	[D2] mainloop: polling 3 filedescriptors
   9.724237	[D2] Checking device 1 of 5 (06DA/0201)
   9.727881	[D2] - VendorID: 06da
   9.727903	[D2] - ProductID: 0201
   9.727909	[D2] - Manufacturer: PPC
   9.727913	[D2] - Product: USB Card
   9.727916	[D2] - Serial Number: unknown
   9.727919	[D2] - Bus: 020
   9.727923	[D2] - Bus Port: 003
   9.727926	[D2] - Device: 019
   9.727929	[D2] - Device release number: 0001
   9.727933	[D2] Trying to match device
   9.727937	[D3] match_function_exact: matching a device...
   9.727941	[D3] match_function_regex: matching a device...
   9.727946	[D2] Device matches
   9.727950	[D2] Reading configuration descriptor 1 of 1
   9.728100	[D3] libusb_kernel_driver_active() returned 1 (driver active)
   9.728113	[D2] successfully set kernel driver auto-detach flag
   9.730740	[D2] Claimed interface 0 successfully
   9.730767	[D3] nut_usb_set_altinterface: skipped libusb_set_interface_alt_setting(udev, 0, 0)
   9.732612	[D3] send: D
   9.761526	[D3] read:  
   9.761556	[D2] qx_process_answer: short reply (input.voltage)
  10.779181	[D3] send: Input/Output Error (-1)
  11.596777	[D2] mainloop: no data available
  11.596824	[D1] mainloop: UPS [myups] is not currently connected, trying to reconnect

@jlg89
Copy link
Author

jlg89 commented Jan 20, 2024

Every now and then I see this:

1544.698161	[D2] Trying to match device
1544.698165	[D3] match_function_exact: matching a device...
1544.698169	[D3] match_function_regex: matching a device...
1544.698175	[D2] Device matches
1544.698178	[D2] Reading configuration descriptor 1 of 1
1544.698352	[D3] libusb_kernel_driver_active() returned 1 (driver active)
1544.698367	[D2] successfully set kernel driver auto-detach flag
1544.700910	[D2] Claimed interface 0 successfully
1544.700939	[D3] nut_usb_set_altinterface: skipped libusb_set_interface_alt_setting(udev, 0, 0)
1544.704426	[D2] mainloop: polling 4 filedescriptors
1544.702697	[D3] send: Q1
1544.922144	[D3] read: (125.7 105.6 120.2 018 60.0 2.32 00.0 00000001
1544.925653	[D2] mainloop: polling 4 filedescriptors
1546.926114	[D2] mainloop: no data available
1546.926162	[D2] mainloop: polling 4 filedescriptors
1547.667537	[D2] write: [destfd=5] [len=21] [BEGIN LIST VAR myups]
1547.667671	[D2] write: [destfd=5] [len=29] [VAR myups battery.charge "0"]
1547.667738	[D2] write: [destfd=5] [len=29] [VAR myups battery.packs "18"]
1547.667776	[D2] write: [destfd=5] [len=30] [VAR myups battery.runtime "0"]
1547.667946	[D2] write: [destfd=5] [len=33] [VAR myups battery.voltage "2.32"]
1547.668020	[D2] write: [destfd=5] [len=39] [VAR myups battery.voltage.high "40.95"]
1547.668088	[D2] write: [destfd=5] [len=37] [VAR myups battery.voltage.low "31.5"]
1547.668147	[D2] write: [destfd=5] [len=41] [VAR myups battery.voltage.nominal "39.0"]
1547.668247	[D2] write: [destfd=5] [len=28] [VAR myups device.type "ups"]
1547.668312	[D2] write: [destfd=5] [len=27] [VAR myups driver.debug "3"]
1547.668351	[D2] write: [destfd=5] [len=42] [VAR myups driver.flag.allow_killpower "0"]
1547.668402	[D2] write: [destfd=5] [len=34] [VAR myups driver.name "nutdrv_qx"]
1547.668459	[D2] write: [destfd=5] [len=46] [VAR myups driver.parameter.chargetime "36000"]
1547.668516	[D2] write: [destfd=5] [len=64] [VAR myups driver.parameter.default.battery.voltage.high "40.95"]
1547.668576	[D2] write: [destfd=5] [len=62] [VAR myups driver.parameter.default.battery.voltage.low "31.5"]
1547.668682	[D2] write: [destfd=5] [len=66] [VAR myups driver.parameter.default.battery.voltage.nominal "39.0"]
1547.668762	[D2] write: [destfd=5] [len=55] [VAR myups driver.parameter.override.battery.packs "18"]
1547.668807	[D2] write: [destfd=5] [len=41] [VAR myups driver.parameter.pollfreq "30"]
1547.668843	[D2] write: [destfd=5] [len=45] [VAR myups driver.parameter.pollinterval "10"]
1547.668879	[D2] write: [destfd=5] [len=39] [VAR myups driver.parameter.port "auto"]
1547.668914	[D2] write: [destfd=5] [len=56] [VAR myups driver.parameter.runtimecal "270,100,4680,13"]
1547.668960	[D2] write: [destfd=5] [len=46] [VAR myups driver.parameter.synchronous "auto"]
1547.669000	[D2] write: [destfd=5] [len=31] [VAR myups driver.state "quiet"]
1547.669038	[D2] write: [destfd=5] [len=48] [VAR myups driver.version "2.8.1-338-gb48a3deba"]
1547.669193	[D2] write: [destfd=5] [len=40] [VAR myups driver.version.data "Q1 0.08"]
1547.669240	[D2] write: [destfd=5] [len=41] [VAR myups driver.version.internal "0.36"]
1547.669277	[D2] write: [destfd=5] [len=62] [VAR myups driver.version.usb "libusb-1.0.26 (API: 0x1000109)"]
1547.669302	[D2] write: [destfd=5] [len=33] [VAR myups input.frequency "60.0"]
1547.669322	[D2] write: [destfd=5] [len=32] [VAR myups input.voltage "125.7"]
1547.669342	[D2] write: [destfd=5] [len=33] [VAR myups output.voltage "120.2"]
1547.669362	[D2] write: [destfd=5] [len=38] [VAR myups ups.beeper.status "enabled"]
1547.669382	[D2] write: [destfd=5] [len=34] [VAR myups ups.delay.shutdown "30"]
1547.669416	[D2] write: [destfd=5] [len=32] [VAR myups ups.delay.start "180"]
1547.669447	[D2] write: [destfd=5] [len=24] [VAR myups ups.load "17"]
1547.669491	[D2] write: [destfd=5] [len=31] [VAR myups ups.productid "0201"]
1547.669523	[D2] write: [destfd=5] [len=26] [VAR myups ups.status "OL"]
1547.669598	[D2] write: [destfd=5] [len=32] [VAR myups ups.temperature "0.0"]
1547.669630	[D2] write: [destfd=5] [len=28] [VAR myups ups.type "online"]
1547.669661	[D2] write: [destfd=5] [len=30] [VAR myups ups.vendorid "06da"]
1547.669688	[D2] write: [destfd=5] [len=19] [END LIST VAR myups]
1547.669820	[D2] mainloop: polling 4 filedescriptors
1549.670122	[D2] mainloop: no data available
1549.670184	[D2] mainloop: polling 4 filedescriptors
1551.670824	[D2] mainloop: no data available
1551.670878	[D3] Pinging UPS [myups]
1551.670904	[D2] mainloop: polling 4 filedescriptors
1551.667605	[D2] send_to_one: sending PONG
1551.671064	[D3] Got PONG from UPS [myups]
1551.671253	[D2] mainloop: polling 4 filedescriptors
1553.671457	[D2] mainloop: no data available
1553.671553	[D2] mainloop: polling 4 filedescriptors
1554.699116	[D1] upsdrv_updateinfo...
1554.699205	[D1] Quick update...
1554.702686	[D2] mainloop: polling 4 filedescriptors
1554.699336	[D3] send: No such device (it may have been disconnected) (-4)
1554.702975	[D2] mainloop: polling 4 filedescriptors
1554.699598	[D1] Communications with the UPS lost: status read failed!

@jlg89
Copy link
Author

jlg89 commented Jan 20, 2024

And hang on, but it looks like upsmon is talking too (finally started it separately):

Network UPS Tools upsmon 2.8.1-338-gb48a3deba
kill: No such process
   0.000000	[D1] Just failed to send signal, no daemon was running
   0.001996	Using power down flag file /etc/killpower
   0.002462	UPS: myups@localhost (primary) (power value 1)
   0.002501	[D1] debug level is '3'
   0.006060	[D1] Saving PID 3839 into /usr/local/var/run/upsmon.pid
   0.008226	[D1] Succeeded to become_user(root): now UID=0 GID=0
   0.013080	upsnotify: failed to notify about state 2: no notification tech defined, will not spam more about it
   0.013101	[D1] Trying to connect to UPS [myups@localhost]
   0.016420	[D1] Logged into UPS myups@localhost
   0.016648	[D2] pollups: myups@localhost
   0.016719	[D3] get_var: myups@localhost / status
   0.016927	[D2] parse_status: [OL]
   0.016939	[D3] parsing: [OL]
   0.016947	[D3] ups_on_line: myups@localhost (first time)
   0.016955	[D3] Current power value: 1
   0.016961	[D3] Minimum power value: 1
  10.016844	[D2] pollups: myups@localhost
  10.016977	[D3] get_var: myups@localhost / status
  10.017243	[D2] parse_status: [OL]
  10.017259	[D3] parsing: [OL]
  10.017269	[D3] Current power value: 1
  10.017277	[D3] Minimum power value: 1

@jlg89
Copy link
Author

jlg89 commented Jan 20, 2024

Oddly enough, if I try to start nutdrv_qx using upsdrvctl, it fails, but if I start it directly, it works. At any rate, I have a working setup at this point. The trick seems to be installing the latest build per Jim's link above, but using the same config options as homebrew uses (see https://formulae.brew.sh/formula/nut).

Many, many thanks to @jimklimov and @clepple for the assist.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
impacts-release-2.7.4 Issues reported against NUT release 2.7.4 (maybe vanilla or with minor packaging tweaks) impacts-release-2.8.1 Issues reported against NUT release 2.8.1 (maybe vanilla or with minor packaging tweaks) macOS Qx protocol driver Driver based on Megatec Q<number> such as new nutdrv_qx, or obsoleted blazer and some others USB
Projects
None yet
Development

No branches or pull requests

3 participants