On up-to-date f36, with latest kernel 6.1.7-100.fc36.x86_64.
After receiving a few of these messages
Broadcast message from [email protected] (somewhere)
UPS ups@ups is unavailable
I noticed and ran
sudo systemctl restart [email protected]
which triggered
Broadcast message from [email protected] (somewhere)
Communications with UPS ups@ups established
I now added the restart to rc.local.
Is there a better/correct way to ensure nut starts at boot time?
Below is what I consider relevant to the situation in the boot log.
Looking at the boot log I see
$ sudo journalctl -b 0 -o short-iso --no-hostname | egrep -i
'[^a-zA-Z](ups|nut)'
2023-01-28T09:06:57+1100 kernel: usb 1-5.2: Product: UPS VALUE
2023-01-28T09:06:57+1100 kernel: hid-generic 0003:0764:0501.0003:
hiddev96,hidraw2: USB HID v1.10 Device [CPS UPS VALUE] on
usb-0000:00:14.0-5.2/input0
2023-01-28T09:07:06+1100 kernel: usb 1-5.2: Product: UPS VALUE
2023-01-28T09:07:06+1100 kernel: hid-generic 0003:0764:0501.0008:
hiddev96,hidraw2: USB HID v1.10 Device [CPS UPS VALUE] on
usb-0000:00:14.0-5.2/input0
2023-01-28T09:07:12+1100 systemd[1]: Created slice system-nut\x2ddriver.slice -
Slice /system/nut-driver.
2023-01-28T09:07:12+1100 udevadm[666]: systemd-udev-settle.service is
deprecated. Please fix [email protected], multipathd.service not to pull
it in.
2023-01-28T09:07:15+1100 systemd[1]: Starting [email protected] - Network
UPS Tools - device driver for NUT device 'ups'...
2023-01-28T09:07:15+1100 kernel: usb 1-5.2: Product: UPS VALUE
2023-01-28T09:07:15+1100 kernel: hid-generic 0003:0764:0501.0009:
hiddev96,hidraw2: USB HID v1.10 Device [CPS UPS VALUE] on
usb-0000:00:14.0-5.2/input0
2023-01-28T09:07:15+1100 nut-driver@ups[1289]: Network UPS Tools - Generic HID
driver 0.47 (2.8.0)
2023-01-28T09:07:15+1100 nut-driver@ups[1289]: USB communication driver (libusb
1.0) 0.43
2023-01-28T09:07:15+1100 nut-driver@ups[1289]: libusb1: Could not open any HID
devices: insufficient permissions on everything
2023-01-28T09:07:15+1100 nut-driver@ups[1289]: No matching HID UPS found
2023-01-28T09:07:15+1100 nut-driver@ups[1259]: Driver failed to start (exit
status=1)
2023-01-28T09:07:20+1100 nut-driver@ups[1580]: Network UPS Tools - Generic HID
driver 0.47 (2.8.0)
2023-01-28T09:07:20+1100 nut-driver@ups[1580]: USB communication driver (libusb
1.0) 0.43
2023-01-28T09:07:20+1100 nut-driver@ups[1580]: libusb1: Could not open any HID
devices: insufficient permissions on everything
2023-01-28T09:07:20+1100 nut-driver@ups[1580]: No matching HID UPS found
2023-01-28T09:07:20+1100 nut-driver@ups[1259]: Driver failed to start (exit
status=1)
2023-01-28T09:07:25+1100 nut-driver@ups[2378]: Using subdriver: CyberPower HID
0.6
2023-01-28T09:07:25+1100 nut-driver@ups[2378]: Network UPS Tools - Generic HID
driver 0.47 (2.8.0)
2023-01-28T09:07:25+1100 nut-driver@ups[2378]: USB communication driver (libusb
1.0) 0.43
2023-01-28T09:07:25+1100 nut-driver@ups[2378]: nut_libusb_get_string: Pipe error
2023-01-28T09:07:25+1100 nut-driver@ups[2378]: cps_adjust_battery_scale:
battery readings will be scaled by 2/3
2023-01-28T09:07:25+1100 usbhid-ups[2399]: Startup successful
2023-01-28T09:07:25+1100 nut-driver@ups[1259]: Network UPS Tools - UPS driver
controller 2.8.0
2023-01-28T09:07:25+1100 systemd[1]: Started [email protected] - Network
UPS Tools - device driver for NUT device 'ups'.
2023-01-28T09:07:25+1100 audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295
subj=kernel msg='unit=nut-driver@ups comm="systemd"
exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
2023-01-28T09:07:25+1100 systemd[1]: Reached target nut-driver.target - Network
UPS Tools - target for power device drivers on this system.
2023-01-28T09:07:25+1100 systemd[1]: Started nut-server.service - Network UPS
Tools - power devices information server.
2023-01-28T09:07:25+1100 audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295
subj=kernel msg='unit=nut-server comm="systemd" exe="/usr/lib/systemd/systemd"
hostname=? addr=? terminal=? res=success'
2023-01-28T09:07:25+1100 nut-server[2400]: fopen /run/nut/upsd.pid: No such
file or directory
2023-01-28T09:07:25+1100 nut-server[2400]: Could not find PID file
'/run/nut/upsd.pid' to see if previous upsd instance is already running!
2023-01-28T09:07:25+1100 systemd[1]: Starting nut-monitor.service - Network UPS
Tools - power device monitor and shutdown controller...
2023-01-28T09:07:25+1100 nut-server[2400]: listening on 192.168.3.7 port 3493
2023-01-28T09:07:25+1100 nut-server[2400]: listening on 127.0.0.1 port 3493
2023-01-28T09:07:25+1100 upsd[2400]: listening on 192.168.3.7 port 3493
2023-01-28T09:07:25+1100 upsd[2400]: listening on 127.0.0.1 port 3493
2023-01-28T09:07:25+1100 nut-server[2400]: Connected to UPS [ups]:
usbhid-ups-ups
2023-01-28T09:07:25+1100 upsd[2400]: Connected to UPS [ups]: usbhid-ups-ups
2023-01-28T09:07:25+1100 usbhid-ups[2399]: sock_connect: enabling asynchronous
mode (auto)
2023-01-28T09:07:25+1100 nut-server[2400]: Running as foreground process, not
saving a PID file
2023-01-28T09:07:25+1100 upsd[2400]: Running as foreground process, not saving
a PID file
2023-01-28T09:07:26+1100 systemd[1]: Started nut-monitor.service - Network UPS
Tools - power device monitor and shutdown controller.
2023-01-28T09:07:26+1100 audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295
subj=kernel msg='unit=nut-monitor comm="systemd" exe="/usr/lib/systemd/systemd"
hostname=? addr=? terminal=? res=success'
2023-01-28T09:07:26+1100 nut-monitor[2402]: fopen /run/nut/upsmon.pid: No such
file or directory
2023-01-28T09:07:26+1100 nut-monitor[2402]: Could not find PID file to see if
previous upsmon instance is already running!
2023-01-28T09:07:26+1100 nut-monitor[2402]: UPS: ups@ups (primary) (power value
1)
2023-01-28T09:07:26+1100 nut-monitor[2402]: Using power down flag file
/etc/killpower
2023-01-28T09:07:27+1100 nut-server[2400]: User [email protected] logged into
UPS [ups]
2023-01-28T09:07:27+1100 upsd[2400]: User [email protected] logged into UPS
[ups]
2023-01-28T09:07:57+1100 usbhid-ups[2399]: nut_libusb_get_string: Pipe error
>>> this repeats every minute, probably when my collection script runs
'upsc ups@e7'. Then later
2023-01-28T09:22:19+1100 usbhid-ups[2399]: nut_libusb_get_report: Input/Output
Error
2023-01-28T09:22:19+1100 usbhid-ups[2399]: nut_libusb_get_report: No such
device (it may have been disconnected)
2023-01-28T09:22:21+1100 usbhid-ups[2399]: nut_libusb_get_interrupt: No such
device (it may have been disconnected)
2023-01-28T09:22:23+1100 usbhid-ups[2399]: libusb1: Could not open any HID
devices: insufficient permissions on everything
2023-01-28T09:22:23+1100 upsd[2400]: Data for UPS [ups] is stale - check driver
2023-01-28T09:22:23+1100 nut-server[2400]: Data for UPS [ups] is stale - check
driver
2023-01-28T09:22:25+1100 usbhid-ups[2399]: libusb1: Could not open any HID
devices: insufficient permissions on everything
2023-01-28T09:22:27+1100 nut-monitor[2403]: Poll UPS [ups@ups] failed - Data
stale
2023-01-28T09:22:27+1100 nut-monitor[2403]: Communications with UPS ups@ups lost
2023-01-28T09:22:27+1100 nut-monitor[15991]: Network UPS Tools upsmon 2.8.0
2023-01-28T09:22:27+1100 usbhid-ups[2399]: libusb1: Could not open any HID
devices: insufficient permissions on everything
2023-01-28T09:22:29+1100 kernel: usb 1-5.2: Product: UPS VALUE
2023-01-28T09:22:29+1100 kernel: hid-generic 0003:0764:0501.000A:
hiddev96,hidraw2: USB HID v1.10 Device [CPS UPS VALUE] on
usb-0000:00:14.0-5.2/input0
2023-01-28T09:22:29+1100 mythbackend[2710]: 2023-01-28 09:22:29.246967 I
[2710/2710] CoreContext platforms/mythpowerdbus.cpp:367:DeviceAdded PowerDBus:
Added UPower.Device '/org/freedesktop/UPower/devices/ups_hiddev0'
2023-01-28T09:22:29+1100 usbhid-ups[2399]: libusb1: Could not open any HID
devices: insufficient permissions on everything
2023-01-28T09:22:31+1100 usbhid-ups[2399]: libusb1: Could not open any HID
devices: insufficient permissions on everything
2023-01-28T09:22:32+1100 nut-monitor[2403]: Poll UPS [ups@ups] failed - Data
stale
>>> thiese last 3 lines repeat many times, until I run
2023-01-28T09:55:11+1100 sudo[26694]: eyal : TTY=pts/8 ; PWD=/home/eyal ;
USER=root ; COMMAND=/usr/bin/systemctl restart [email protected]
2023-01-28T09:55:11+1100 systemd[1]: Stopping [email protected] - Network
UPS Tools - device driver for NUT device 'ups'...
2023-01-28T09:55:11+1100 nut-driver@ups[26697]: Network UPS Tools - UPS driver
controller 2.8.0
2023-01-28T09:55:11+1100 nut-server[2400]: Can't connect to UPS [ups]
(usbhid-ups-ups): No such file or directory
2023-01-28T09:55:11+1100 usbhid-ups[2399]: Signal 15: exiting
2023-01-28T09:55:11+1100 upsd[2400]: Can't connect to UPS [ups]
(usbhid-ups-ups): No such file or directory
2023-01-28T09:55:11+1100 systemd[1]: [email protected]: Deactivated
successfully.
2023-01-28T09:55:11+1100 systemd[1]: Stopped [email protected] - Network
UPS Tools - device driver for NUT device 'ups'.
2023-01-28T09:55:11+1100 audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295
subj=kernel msg='unit=nut-driver@ups comm="systemd"
exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
2023-01-28T09:55:11+1100 systemd[1]: [email protected]: Consumed 1.448s
CPU time.
2023-01-28T09:55:11+1100 kernel: audit: type=1131 audit(1674860111.213:973): pid=1 uid=0
auid=4294967295 ses=4294967295 subj=kernel msg='unit=nut-driver@ups comm="systemd"
exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
2023-01-28T09:55:11+1100 systemd[1]: Starting [email protected] - Network
UPS Tools - device driver for NUT device 'ups'...
2023-01-28T09:55:11+1100 mythbackend[2710]: 2023-01-28 09:55:11.295944 I
[2710/2710] CoreContext platforms/mythpowerdbus.cpp:379:DeviceRemoved Removed
UPower.Device '/org/freedesktop/UPower/devices/ups_hiddev0'
2023-01-28T09:55:11+1100 nut-driver@ups[26755]: Using subdriver: CyberPower HID
0.6
2023-01-28T09:55:11+1100 nut-driver@ups[26755]: Network UPS Tools - Generic HID
driver 0.47 (2.8.0)
2023-01-28T09:55:11+1100 nut-driver@ups[26755]: USB communication driver
(libusb 1.0) 0.43
2023-01-28T09:55:11+1100 nut-driver@ups[26755]: cps_adjust_battery_scale:
battery readings will be scaled by 2/3
2023-01-28T09:55:12+1100 usbhid-ups[26758]: Startup successful
2023-01-28T09:55:12+1100 nut-driver@ups[26727]: Network UPS Tools - UPS driver
controller 2.8.0
2023-01-28T09:55:12+1100 systemd[1]: Started [email protected] - Network
UPS Tools - device driver for NUT device 'ups'.
2023-01-28T09:55:12+1100 audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295
subj=kernel msg='unit=nut-driver@ups comm="systemd"
exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
2023-01-28T09:55:12+1100 kernel: audit: type=1130 audit(1674860112.099:974): pid=1 uid=0
auid=4294967295 ses=4294967295 subj=kernel msg='unit=nut-driver@ups comm="systemd"
exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
2023-01-28T09:55:12+1100 nut-server[2400]: Connected to UPS [ups]:
usbhid-ups-ups
2023-01-28T09:55:12+1100 upsd[2400]: Connected to UPS [ups]: usbhid-ups-ups
2023-01-28T09:55:12+1100 nut-monitor[2403]: Poll UPS [ups@ups] failed - Driver
not connected
2023-01-28T09:55:12+1100 usbhid-ups[26758]: sock_connect: enabling asynchronous
mode (auto)
2023-01-28T09:55:17+1100 nut-monitor[2403]: Communications with UPS ups@ups
established
2023-01-28T09:55:17+1100 nut-monitor[26759]: Network UPS Tools upsmon 2.8.0
>>> and I now get readings.
>>> interestingly, I later see
2023-01-28T10:12:46+1100 usbhid-ups[26758]: nut_libusb_get_string: Pipe error
>>> this message is not seen in /var/log/messages...
>>> but I still get readings.
>>> maybe an intermittent error?
--
Eyal Lebedinsky ([email protected])
_______________________________________________
Nut-upsuser mailing list
[email protected]
https://alioth-lists.debian.net/cgi-bin/mailman/listinfo/nut-upsuser
