NUT Package Logs
-
Ever since the new update I'm getting a lot of these in my logs:
Aug 14 05:57:22 usbhid-ups 26308 Got disconnected by another driver: Device busy Aug 14 05:13:31 usbhid-ups 26308 Got disconnected by another driver: Device busy Aug 14 04:49:34 usbhid-ups 26308 Got disconnected by another driver: Device busy Aug 14 04:47:20 usbhid-ups 26308 Got disconnected by another driver: Device busy Aug 14 04:29:38 usbhid-ups 26308 Got disconnected by another driver: Device busy Aug 14 04:11:48 usbhid-ups 26308 Got disconnected by another driver: Device busy Aug 14 03:02:13 usbhid-ups 26308 Got disconnected by another driver: Device busy … Aug 13 23:21:58 upsd 26496 Data for UPS [CyberPower1] is stale - check driver Aug 13 19:59:22 php-cgi nut_email.php: Message sent to XX@XX.com OK Aug 13 19:59:21 upsmon 26006 Communications with UPS CyberPower1 established Aug 13 19:59:18 php-cgi nut_email.php: Message sent to XX@XX.com OK Aug 13 19:59:16 upsd 26496 UPS [CyberPower1] data is no longer stale Aug 13 19:59:16 upsmon 26006 Communications with UPS CyberPower1 lost Aug 13 19:59:16 upsmon 26006 Poll UPS [CyberPower1] failed - Data stale Aug 13 19:59:14 upsd 26496 Data for UPS [CyberPower1] is stale - check driver Aug 13 19:58:17 upsd 26496 UPS [CyberPower1] data is no longer stale Aug 13 19:58:14 upsd 26496 Data for UPS [CyberPower1] is stale - check driver Aug 13 19:24:42 php-cgi nut_email.php: Message sent to XX@XX.com OK Aug 13 19:24:40 upsmon 26006 Communications with UPS CyberPower1 established Aug 13 19:24:37 upsd 26496 UPS [CyberPower1] data is no longer stale Aug 13 19:24:37 php-cgi nut_email.php: Message sent to XX@XX.com OK Aug 13 19:24:35 upsmon 26006 Communications with UPS CyberPower1 lost Aug 13 19:24:35 upsmon 26006 Poll UPS [CyberPower1] failed - Data stale Aug 13 19:24:33 upsd 26496 Data for UPS [CyberPower1] is stale - check driver Aug 13 17:59:43 usbhid-ups 26308 Got disconnected by another driver: Device busy Aug 13 17:42:54 php-cgi nut_email.php: Message sent to XX@XX.com OK Aug 13 17:42:52 upsmon 26006 Communications with UPS CyberPower1 established Aug 13 17:42:49 php-cgi nut_email.php: Message sent to XX@XX.com OK Aug 13 17:42:48 upsd 26496 UPS [CyberPower1] data is no longer stale Aug 13 17:42:47 upsmon 26006 Communications with UPS CyberPower1 lost Aug 13 17:42:47 upsmon 26006 Poll UPS [CyberPower1] failed - Data stale Aug 13 17:42:46 upsd 26496 Data for UPS [CyberPower1] is stale - check driver Aug 13 17:12:28 usbhid-ups 26308 Got disconnected by another driver: Device busy Aug 13 17:01:28 usbhid-ups 26308 Got disconnected by another driver: Device busySeems like the communication between my UPS and pfSense is lost every so often. Any idea why?
-
The process that talks with the UPS via USB, usbhid-ups, is indicating that there another process attempting to access the UPS via USB at the same time. Is there anything else installed that could be doing that? Maybe check the output of fstat? Look for processes that have USB devices open.
Is this running in a VM?
networkupstools.org/docs/FAQ.html#_what_8217_s_this_about_emphasis_data_stale_emphasisFWIW, Stale data in general isn't a new issue:
-
No, not in a VM. Packages I have running are:
Squid
SquidGuard
Snort
iperf
Lightsquid
nmap
ntop
NUT
Traffic_Status_TotalsIm going to reboot and also switch the USB port to see if that helps..
-
Did the reboot fix or change your problem? If not, did you run fstat?
-
Thanks for checking back dennypage. I was finally able to reboot & switch the usb port this am. So far I am not seeing it in my logs again, but it hasn't been vary long yet. I'll keep an eye on it.
As for fstat, I ran it but honestly I had no idea how to interpret the lengthy list.
-
As for fstat, I ran it but honestly I had no idea how to interpret the lengthy list.
Sorry, I should have explained. fstat shows what processes have what files open. The output of usbhid-ups suggested that there was another process accessing the UPS via USB. So if you run
fstat | grep -i usb
while the problem is occurring, you could see processes that have USB devices open. You are looking for processes using /dev/usb/*. Here is the output from one of my systems:
USER CMD PID FD MOUNT INUM MODE SZ|DV R/W uucp usbhid-ups 1214 text / 10841613 -r-xr-xr-x 175712 r uucp usbhid-ups 1214 wd / 8748129 drwxr-x--- 512 r uucp usbhid-ups 1214 root / 2 drwxr-xr-x 1024 r uucp usbhid-ups 1214 0 /dev 10 crw-rw-rw- null rw uucp usbhid-ups 1214 1 /dev 10 crw-rw-rw- null rw uucp usbhid-ups 1214 2 /dev 10 crw-rw-rw- null rw uucp usbhid-ups 1214 3* local dgram fffff8000b413000 <-> fffff8000b1f8960 uucp usbhid-ups 1214 4 /dev 73 crw-rw---- usb/0.3.0 rw uucp usbhid-ups 1214 5 /dev 73 crw-rw---- usb/0.3.0 rw uucp usbhid-ups 1214 6* local stream fffff801b1ea43c0 uucp usbhid-ups 1214 7* local stream fffff8000b3db1e0 <-> fffff8014705e690 uucp usbhid-ups 1214 10* local stream fffff8000b1f84b0You can see that usbhid-ups has two file descriptors (4 & 5) open on the USB bus accessing node 0.3.0.
We would expect usbhid-ups to have open files for the UPS. But if there were another process with the same USB node open, including a second usbhid-ups process, that would indicate a problem.
-
Thanks for that explanation, learned something new.
I'll check on it tonight and see if its appearing in the logs again as well as re-run the fstat.
Thanks again..
-
Well no further sign of this in my logs since reboot and switch usb port. So seems to have cleared up.
Here is the output from fstat:
uucp usbhid-ups 63113 text / 6345098 -r-xr-xr-x 175712 r uucp usbhid-ups 63113 wd / 80705 drwxr-x--- 512 r uucp usbhid-ups 63113 root / 2 drwxr-xr-x 1024 r uucp usbhid-ups 63113 0 /dev 10 crw-rw-rw- null rw uucp usbhid-ups 63113 1 /dev 10 crw-rw-rw- null rw uucp usbhid-ups 63113 2 /dev 10 crw-rw-rw- null rw uucp usbhid-ups 63113 3* local dgram fffff8000db78e10 <-> fffff8000d845000 uucp usbhid-ups 63113 4 /dev 133 crw-rw---- usb/0.2.0 rw uucp usbhid-ups 63113 5 /dev 133 crw-rw---- usb/0.2.0 rw uucp usbhid-ups 63113 6* local stream fffff8000d7f4960 uucp usbhid-ups 63113 7* local stream fffff8000da853c0 <-> fffff8000da854b0 uucp usbhid-ups 63113 10* local stream fffff8000db97960Seems to be in order I believe.
Thanks for the help and lesson dennypage, much appreciated..
-
No problem. Happy to help.
