You are not logged in.
I've had persistent problems related to NUT and the changes that occurred at v. 2.8.0.
I believe that the wiki may have incomplete or misleading information and I'm having trouble applying the basic steps to my system.
https://wiki.archlinux.org/title/Network_UPS_Tools
The steps as I am understanding them...
1. Detect your specific UPS and add it to your /etc/nut/ups.conf.
This seems to be working properly.
2. Start the driver as root with upsdrvctl start.
This seems to be working correctly.
3. Start/enable nut-driver-enumerator.service which will automatically create nut-driver@<ups name> systemd service instance and start it.
This isn't working.
The enumerator does start the nut-driver@<ups name>, however the nut-driver exits with an error code.
I see this in systemd:
nut-driver@mycomputer-TL-UPS.service - Network UPS Tools - device driver for NUT device 'mycomputer-TL-UPS'
Loaded: loaded (/usr/lib/systemd/system/nut-driver@.service; enabled; preset: disabled)
Drop-In: /etc/systemd/system/nut-driver@mycomputer-TL-UPS.service.d
└─nut-driver-enumerator-generated-checksum.conf, nut-driver-enumerator-generated.conf
Active: activating (auto-restart) (Result: exit-code) since Sat 2023-12-02 10:52:08 PST; 9s ago
Process: 39010 ExecStartPre=/usr/bin/systemd-tmpfiles --create /usr/lib/tmpfiles.d/nut-common-tmpfiles.conf (code=exited, status=0/SUCCESS)
Process: 39012 ExecStart=/bin/sh -c NUTDEV="`/usr/libexec/nut-driver-enumerator.sh --get-device-for-service mycomputer-TL-UPS`" && [ -n "$NUTDEV" ] || { echo "FATAL: Could not find a NUT device section for service unit mycomputer-TL-UPS" >&2 ; exit 1 ; } ; exec /usr/bin/upsdrvctl -FF start "$NUTDEV" (code=exited, status=1/FAILURE)
Main PID: 39012 (code=exited, status=1/FAILURE)
Status: "exit_cleanup()"
CPU: 103msI haven't found anything on the internet by searching for "FATAL: Could not find a NUT device section for service unit."
Checking the journal with "journalctl -xeu nut-driver@mycomputer-TL-UPS.service"
Dec 02 10:59:45 mycomputer2.1 nut-driver@mycomputer-TL-UPS[40056]: Debug level is 0, dump data count is off, but backgrounding mode requested as off
Dec 02 10:59:45 mycomputer2.1 nut-driver@mycomputer-TL-UPS[40056]: Can't claim USB device [09ae:3016]@0/0/0: Entity not found
Dec 02 10:59:45 mycomputer2.1 nut-driver@mycomputer-TL-UPS[40056]: Network UPS Tools - Generic HID driver 0.52 (2.8.1-249-g0ea95a760)
Dec 02 10:59:45 mycomputer2.1 nut-driver@mycomputer-TL-UPS[40056]: USB communication driver (libusb 1.0) 0.46
Dec 02 10:59:45 mycomputer2.1 systemd[1]: nut-driver@mycomputer-TL-UPS.service: Main process exited, code=exited, status=1/FAILURE
░░ Subject: Unit process exited
░░ Defined-By: systemd
░░ Support: https://lists.freedesktop.org/mailman/listinfo/systemd-devel
░░
░░ An ExecStart= process belonging to unit nut-driver@mycomputer-TL-UPS.service has exited.
░░
░░ The process' exit code is 'exited' and its exit status is 1.
Dec 02 10:59:45 mycomputer2.1 systemd[1]: nut-driver@mycomputer-TL-UPS.service: Failed with result 'exit-code'.
░░ Subject: Unit failed
░░ Defined-By: systemd
░░ Support: https://lists.freedesktop.org/mailman/listinfo/systemd-devel
░░
░░ The unit nut-driver@mycomputer-TL-UPS.service has entered the 'failed' state with result 'exit-code'.
Dec 02 10:59:45 mycomputer2.1 systemd[1]: Failed to start Network UPS Tools - device driver for NUT device 'mycomputer-TL-UPS'.
░░ Subject: A start job for unit nut-driver@mycomputer-TL-UPS.service has failed
░░ Defined-By: systemd
░░ Support: https://lists.freedesktop.org/mailman/listinfo/systemd-devel
░░
░░ A start job for unit nut-driver@mycomputer-TL-UPS.service has finished with a failure.
░░
░░ The job identifier is 34621 and the job result is failed.
lines 4474-4559/4559 (END)The statement "Can't claim USB device [09ae:3016]@0/0/0: Entity not found" sounds suspiciously like the notes on the wiki page at 2.2.1, however I do have the udev rule and it's loaded.
I'm probably doing something wrong or misunderstanding the process and I'm hoping someone can help steer me in the right direction.
I'm also wondering if the @0/0/0 after the vendor/product IDs is correct.
Thanks!
[Edited the title for clarity.]
Last edited by heidegger (2023-12-10 15:45:59)
Offline
Note that I am attempting to follow the directions exactly, so my rule looks like this:
SUBSYSTEM=="usb", ATTR{idVendor}=="09ae", ATTR{idProduct}=="3016", GROUP="nut"I am concerned about everything using a double equal sign "==" except GROUP.
My gut tells me they should all use the same operation.
Edit: I tried using a "==", reloading the udev rule and restarting the nut-driver@ service but it didn't correct the problem so I have reverted to the rule as shown in the wiki.
Edit: grammar
Edit: == is used to check for equality, while = is used to assign a value as mentioned here: https://www.reactivated.net/writing_udev_rules.html
Last edited by heidegger (2023-12-09 17:10:49)
Offline
I've continued my search for a solution to this problem, and I'm going to document my progress here.
In order to get a clearer understanding of what is happening with the UPS, I've tried monitoring udevadm and journalctl while connecting the UPS to a USB port on my computer.
Here's the output of "sudo udevadm monitor|grep 3016"
KERNEL[54749.801495] add /devices/pci0000:00/0000:00:08.1/0000:0b:00.3/usb5/5-2/5-2:1.0/0003:09AE:3016.000C (hid)
KERNEL[54749.802418] add /devices/pci0000:00/0000:00:08.1/0000:0b:00.3/usb5/5-2/5-2:1.0/0003:09AE:3016.000C/hidraw/hidraw0 (hidraw)
KERNEL[54749.802455] bind /devices/pci0000:00/0000:00:08.1/0000:0b:00.3/usb5/5-2/5-2:1.0/0003:09AE:3016.000C (hid)
UDEV [54749.840944] add /devices/pci0000:00/0000:00:08.1/0000:0b:00.3/usb5/5-2/5-2:1.0/0003:09AE:3016.000C (hid)
UDEV [54749.851661] add /devices/pci0000:00/0000:00:08.1/0000:0b:00.3/usb5/5-2/5-2:1.0/0003:09AE:3016.000C/hidraw/hidraw0 (hidraw)
UDEV [54749.854707] bind /devices/pci0000:00/0000:00:08.1/0000:0b:00.3/usb5/5-2/5-2:1.0/0003:09AE:3016.000C (hid)
KERNEL[54750.878881] remove /devices/pci0000:00/0000:00:08.1/0000:0b:00.3/usb5/5-2/5-2:1.0/0003:09AE:3016.000C/hidraw/hidraw0 (hidraw)
KERNEL[54750.878930] unbind /devices/pci0000:00/0000:00:08.1/0000:0b:00.3/usb5/5-2/5-2:1.0/0003:09AE:3016.000C (hid)
KERNEL[54750.878950] remove /devices/pci0000:00/0000:00:08.1/0000:0b:00.3/usb5/5-2/5-2:1.0/0003:09AE:3016.000C (hid)
UDEV [54750.882751] remove /devices/pci0000:00/0000:00:08.1/0000:0b:00.3/usb5/5-2/5-2:1.0/0003:09AE:3016.000C/hidraw/hidraw0 (hidraw)
UDEV [54750.885561] unbind /devices/pci0000:00/0000:00:08.1/0000:0b:00.3/usb5/5-2/5-2:1.0/0003:09AE:3016.000C (hid)
UDEV [54750.888162] remove /devices/pci0000:00/0000:00:08.1/0000:0b:00.3/usb5/5-2/5-2:1.0/0003:09AE:3016.000C (hid)And the output of "sudo journalctl -f"
Dec 09 09:18:33 mycomputer2.1 kernel: usb 5-2: USB disconnect, device number 5
Dec 09 09:18:33 mycomputer2.1 systemd-udevd[447]: 5-2:1.0: Device ready for processing (SEQNUM=5740, ACTION=unbind)
Dec 09 09:18:33 mycomputer2.1 systemd-udevd[447]: Successfully forked off '(udev-worker)' as PID 133727.
Dec 09 09:18:33 mycomputer2.1 systemd-udevd[447]: 5-2:1.0: Worker [133727] is forked for processing SEQNUM=5740.
Dec 09 09:18:33 mycomputer2.1 systemd-udevd[447]: 5-2:1.0: Device is queued (SEQNUM=5741, ACTION=remove)
Dec 09 09:18:33 mycomputer2.1 systemd-udevd[447]: 5-2:1.0: SEQNUM=5741 blocked by SEQNUM=5740
Dec 09 09:18:33 mycomputer2.1 (udev-worker)[133727]: 5-2:1.0: Processing device (SEQNUM=5740, ACTION=unbind)
Dec 09 09:18:33 mycomputer2.1 (udev-worker)[133727]: 5-2:1.0: /usr/lib/udev/rules.d/50-udev-default.rules:27 Importing properties from results of builtin command 'path_id'
Dec 09 09:18:33 mycomputer2.1 (udev-worker)[133727]: 5-2:1.0: sd-device: Created db file '/run/udev/data/+usb:5-2:1.0' for '/devices/pci0000:00/0000:00:08.1/0000:0b:00.3/usb5/5-2/5-2:1.0'
Dec 09 09:18:33 mycomputer2.1 (udev-worker)[133727]: 5-2:1.0: Device processed (SEQNUM=5740, ACTION=unbind)
Dec 09 09:18:33 mycomputer2.1 (udev-worker)[133727]: 5-2:1.0: sd-device-monitor(worker): Passed 407 byte to netlink monitor.
Dec 09 09:18:33 mycomputer2.1 systemd-udevd[447]: 5-2:1.0: Device ready for processing (SEQNUM=5741, ACTION=remove)
Dec 09 09:18:33 mycomputer2.1 systemd-udevd[447]: 5-2:1.0: sd-device-monitor(manager): Passed 331 byte to netlink monitor.
Dec 09 09:18:33 mycomputer2.1 (udev-worker)[133727]: 5-2:1.0: Processing device (SEQNUM=5741, ACTION=remove)
Dec 09 09:18:33 mycomputer2.1 (udev-worker)[133727]: 5-2:1.0: Device processed (SEQNUM=5741, ACTION=remove)
Dec 09 09:18:33 mycomputer2.1 (udev-worker)[133727]: 5-2:1.0: sd-device-monitor(worker): Passed 466 byte to netlink monitor.
Dec 09 09:18:33 mycomputer2.1 systemd-udevd[447]: No events are queued, removing /run/udev/queue.
Dec 09 09:18:33 mycomputer2.1 nut-driver@mycomputer-TL-UPS[822]: nut_libusb_get_interrupt: No such device (it may have been disconnected)
Dec 09 09:18:33 mycomputer2.1 usbhid-ups[822]: nut_libusb_get_interrupt: No such device (it may have been disconnected)
Dec 09 09:18:33 mycomputer2.1 systemd-udevd[447]: 5-2: Device is queued (SEQNUM=5742, ACTION=unbind)
Dec 09 09:18:33 mycomputer2.1 systemd-udevd[447]: 5-2: Device ready for processing (SEQNUM=5742, ACTION=unbind)
Dec 09 09:18:33 mycomputer2.1 systemd-udevd[447]: 5-2: sd-device-monitor(manager): Passed 316 byte to netlink monitor.
Dec 09 09:18:33 mycomputer2.1 systemd-udevd[447]: 5-2: Device is queued (SEQNUM=5743, ACTION=remove)
Dec 09 09:18:33 mycomputer2.1 systemd-udevd[447]: 5-2: SEQNUM=5743 blocked by SEQNUM=5742
Dec 09 09:18:33 mycomputer2.1 (udev-worker)[133727]: 5-2: Processing device (SEQNUM=5742, ACTION=unbind)
Dec 09 09:18:33 mycomputer2.1 (udev-worker)[133727]: 5-2: Removing watch handle -1.
Dec 09 09:18:33 mycomputer2.1 (udev-worker)[133727]: 5-2: /usr/lib/udev/rules.d/50-udev-default.rules:17 Importing properties from results of builtin command 'usb_id'
Dec 09 09:18:33 mycomputer2.1 (udev-worker)[133727]: 5-2: Failed to open "/sys/devices/pci0000:00/0000:00:08.1/0000:0b:00.3/usb5/5-2/descriptors": No such file or directory
Dec 09 09:18:33 mycomputer2.1 (udev-worker)[133727]: 5-2: Failed to get idVendor attribute: No such file or directory
Dec 09 09:18:33 mycomputer2.1 (udev-worker)[133727]: 5-2: /usr/lib/udev/rules.d/50-udev-default.rules:17 Failed to run builtin 'usb_id': No such file or directory
Dec 09 09:18:33 mycomputer2.1 (udev-worker)[133727]: 5-2: /usr/lib/udev/rules.d/50-udev-default.rules:27 Importing properties from results of builtin command 'path_id'
Dec 09 09:18:33 mycomputer2.1 (udev-worker)[133727]: 5-2: Device node /dev/bus/usb/005/005 is missing, skipping handling.
Dec 09 09:18:33 mycomputer2.1 (udev-worker)[133727]: 5-2: Successfully created symlink '/dev/char/189:516' to '/dev/bus/usb/005/005'
Dec 09 09:18:33 mycomputer2.1 (udev-worker)[133727]: 5-2: sd-device: Created db file '/run/udev/data/c189:516' for '/devices/pci0000:00/0000:00:08.1/0000:0b:00.3/usb5/5-2'
Dec 09 09:18:33 mycomputer2.1 (udev-worker)[133727]: 5-2: Device processed (SEQNUM=5742, ACTION=unbind)
Dec 09 09:18:33 mycomputer2.1 (udev-worker)[133727]: 5-2: sd-device-monitor(worker): Passed 451 byte to netlink monitor.
Dec 09 09:18:33 mycomputer2.1 systemd-udevd[447]: 5-2: Device ready for processing (SEQNUM=5743, ACTION=remove)
Dec 09 09:18:33 mycomputer2.1 systemd-udevd[447]: 5-2: sd-device-monitor(manager): Passed 316 byte to netlink monitor.
Dec 09 09:18:33 mycomputer2.1 (udev-worker)[133727]: 5-2: Processing device (SEQNUM=5743, ACTION=remove)
Dec 09 09:18:33 mycomputer2.1 (udev-worker)[133727]: 5-2: Removing watch handle -1.
Dec 09 09:18:33 mycomputer2.1 (udev-worker)[133727]: 5-2: /usr/lib/udev/rules.d/60-vboxdrv.rules:8 RUN '/usr/share/virtualbox/VBoxCreateUSBNode.sh --remove $major $minor'
Dec 09 09:18:33 mycomputer2.1 (udev-worker)[133727]: 5-2: Running command "/usr/share/virtualbox/VBoxCreateUSBNode.sh --remove 189 516"
Dec 09 09:18:33 mycomputer2.1 (udev-worker)[133727]: 5-2: Starting '/usr/share/virtualbox/VBoxCreateUSBNode.sh --remove 189 516'
Dec 09 09:18:33 mycomputer2.1 (udev-worker)[133727]: Successfully forked off '(spawn)' as PID 133728.
Dec 09 09:18:33 mycomputer2.1 (udev-worker)[133727]: 5-2: Process '/usr/share/virtualbox/VBoxCreateUSBNode.sh --remove 189 516' succeeded.
Dec 09 09:18:33 mycomputer2.1 (udev-worker)[133727]: 5-2: Device processed (SEQNUM=5743, ACTION=remove)
Dec 09 09:18:33 mycomputer2.1 (udev-worker)[133727]: 5-2: sd-device-monitor(worker): Passed 451 byte to netlink monitor.
Dec 09 09:18:33 mycomputer2.1 systemd-udevd[447]: No events are queued, removing /run/udev/queue.
Dec 09 09:18:35 mycomputer2.1 nut-driver@mycomputer-TL-UPS[822]: libusb1: Could not open any HID devices: insufficient permissions on everything
Dec 09 09:18:35 mycomputer2.1 usbhid-ups[822]: libusb1: Could not open any HID devices: insufficient permissions on everything
Dec 09 09:18:35 mycomputer2.1 nut-server[937]: Data for UPS [mycomputer-TL-UPS] is stale - check driver
Dec 09 09:18:35 mycomputer2.1 upsd[937]: Data for UPS [mycomputer-TL-UPS] is stale - check driver
Dec 09 09:18:37 mycomputer2.1 systemd-udevd[447]: Cleanup idle workers
Dec 09 09:18:37 mycomputer2.1 systemd-udevd[447]: Worker [133727] exited.
Dec 09 09:18:37 mycomputer2.1 nut-driver@mycomputer-TL-UPS[822]: libusb1: Could not open any HID devices: insufficient permissions on everything
Dec 09 09:18:37 mycomputer2.1 usbhid-ups[822]: libusb1: Could not open any HID devices: insufficient permissions on everything
Dec 09 09:18:38 mycomputer2.1 kernel: usb 5-2: new full-speed USB device number 6 using xhci_hcd
Dec 09 09:18:38 mycomputer2.1 systemd-udevd[447]: 5-2: Device is queued (SEQNUM=5744, ACTION=add)
Dec 09 09:18:38 mycomputer2.1 kernel: usb 5-2: New USB device found, idVendor=09ae, idProduct=3016, bcdDevice= 0.02
Dec 09 09:18:38 mycomputer2.1 kernel: usb 5-2: New USB device strings: Mfr=3, Product=1, SerialNumber=5
Dec 09 09:18:38 mycomputer2.1 kernel: usb 5-2: Product: TRIPP LITE UPS
Dec 09 09:18:38 mycomputer2.1 kernel: usb 5-2: Manufacturer: Tripp Lite
Dec 09 09:18:38 mycomputer2.1 kernel: usb 5-2: SerialNumber: 3139GVLOM87C502145
Dec 09 09:18:38 mycomputer2.1 systemd-udevd[447]: 5-2: Device ready for processing (SEQNUM=5744, ACTION=add)
Dec 09 09:18:38 mycomputer2.1 systemd-udevd[447]: Successfully forked off '(udev-worker)' as PID 133735.
Dec 09 09:18:38 mycomputer2.1 systemd-udevd[447]: 5-2: Worker [133735] is forked for processing SEQNUM=5744.
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: 5-2: Processing device (SEQNUM=5744, ACTION=add)
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: 5-2: Removing watch handle -1.
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: 5-2: /usr/lib/udev/rules.d/40-gphoto.rules:9 Importing properties from results of builtin command 'usb_id'
Dec 09 09:18:38 mycomputer2.1 systemd-udevd[447]: 5-2: Device is queued (SEQNUM=5745, ACTION=change)
Dec 09 09:18:38 mycomputer2.1 systemd-udevd[447]: 5-2: SEQNUM=5745 blocked by SEQNUM=5744
Dec 09 09:18:38 mycomputer2.1 systemd-udevd[447]: 5-2:1.0: Device is queued (SEQNUM=5746, ACTION=add)
Dec 09 09:18:38 mycomputer2.1 systemd-udevd[447]: 5-2:1.0: SEQNUM=5746 blocked by SEQNUM=5744
Dec 09 09:18:38 mycomputer2.1 systemd-udevd[447]: 0003:09AE:3016.000C: Device is queued (SEQNUM=5747, ACTION=add)
Dec 09 09:18:38 mycomputer2.1 systemd-udevd[447]: 0003:09AE:3016.000C: SEQNUM=5747 blocked by SEQNUM=5744
Dec 09 09:18:38 mycomputer2.1 systemd-udevd[447]: hiddev0: Device is queued (SEQNUM=5748, ACTION=add)
Dec 09 09:18:38 mycomputer2.1 systemd-udevd[447]: hiddev0: SEQNUM=5748 blocked by SEQNUM=5744
Dec 09 09:18:38 mycomputer2.1 systemd-udevd[447]: hidraw0: Device is queued (SEQNUM=5749, ACTION=add)
Dec 09 09:18:38 mycomputer2.1 systemd-udevd[447]: hidraw0: SEQNUM=5749 blocked by SEQNUM=5744
Dec 09 09:18:38 mycomputer2.1 systemd-udevd[447]: 0003:09AE:3016.000C: Device is queued (SEQNUM=5750, ACTION=bind)
Dec 09 09:18:38 mycomputer2.1 systemd-udevd[447]: 0003:09AE:3016.000C: SEQNUM=5750 blocked by SEQNUM=5744
Dec 09 09:18:38 mycomputer2.1 systemd-udevd[447]: 5-2:1.0: Device is queued (SEQNUM=5751, ACTION=bind)
Dec 09 09:18:38 mycomputer2.1 systemd-udevd[447]: 5-2:1.0: SEQNUM=5751 blocked by SEQNUM=5744
Dec 09 09:18:38 mycomputer2.1 systemd-udevd[447]: 5-2: Device is queued (SEQNUM=5752, ACTION=bind)
Dec 09 09:18:38 mycomputer2.1 systemd-udevd[447]: 5-2: SEQNUM=5752 blocked by SEQNUM=5744
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: 5-2: /usr/lib/udev/rules.d/50-udev-default.rules:17 Skipping builtin 'usb_id' in IMPORT key
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: 5-2: /usr/lib/udev/rules.d/50-udev-default.rules:17 Importing properties from results of builtin command 'hwdb --subsystem=usb'
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: 5-2: hwdb modalias key: "usb:v09AEp3016:TRIPP LITE UPS "
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: 5-2: /usr/lib/udev/rules.d/50-udev-default.rules:27 Importing properties from results of builtin command 'path_id'
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: 5-2: /usr/lib/udev/rules.d/50-udev-default.rules:67 MODE 0664
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: 5-2: /etc/udev/rules.d/50-ups.rules:1 GROUP 965
Dec 09 09:18:38 mycomputer2.1 kernel: hid-generic 0003:09AE:3016.000C: hiddev96,hidraw0: USB HID v1.11 Device [Tripp Lite TRIPP LITE UPS ] on usb-0000:0b:00.3-2/input0
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: 5-2: /usr/lib/udev/rules.d/60-vboxdrv.rules:6 RUN '/usr/share/virtualbox/VBoxCreateUSBNode.sh $major $minor $attr{bDeviceClass} vboxusers'
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: 5-2: /usr/lib/udev/rules.d/62-nut-usbups.rules:204 GROUP 965
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: 5-2: /usr/lib/udev/rules.d/62-nut-usbups.rules:204 MODE 0664
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: 5-2: /usr/lib/udev/rules.d/69-libmtp.rules:39 Running PROGRAM '/usr/lib/udev/mtp-probe /sys/devices/pci0000:00/0000:00:08.1/0000:0b:00.3/usb5/5-2 5 6'
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: 5-2: Starting '/usr/lib/udev/mtp-probe /sys/devices/pci0000:00/0000:00:08.1/0000:0b:00.3/usb5/5-2 5 6'
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: Successfully forked off '(spawn)' as PID 133736.
Dec 09 09:18:38 mycomputer2.1 mtp-probe[133736]: checking bus 5, device 6: "/sys/devices/pci0000:00/0000:00:08.1/0000:0b:00.3/usb5/5-2"
Dec 09 09:18:38 mycomputer2.1 mtp-probe[133736]: bus: 5, device: 6 was not an MTP device
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: 5-2: '/usr/lib/udev/mtp-probe /sys/devices/pci0000:00/0000:00:08.1/0000:0b:00.3/usb5/5-2 5 6'(out) '0'
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: 5-2: Process '/usr/lib/udev/mtp-probe /sys/devices/pci0000:00/0000:00:08.1/0000:0b:00.3/usb5/5-2 5 6' succeeded.
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: 5-2: Setting permissions /dev/bus/usb/005/006, uid=0, gid=965, mode=0664
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: 5-2: Successfully created symlink '/dev/char/189:517' to '/dev/bus/usb/005/006'
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: 5-2: sd-device: Created db file '/run/udev/data/c189:517' for '/devices/pci0000:00/0000:00:08.1/0000:0b:00.3/usb5/5-2'
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: 5-2: Running command "/usr/share/virtualbox/VBoxCreateUSBNode.sh 189 517 00 vboxusers"
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: 5-2: Starting '/usr/share/virtualbox/VBoxCreateUSBNode.sh 189 517 00 vboxusers'
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: Successfully forked off '(spawn)' as PID 133737.
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: 5-2: Process '/usr/share/virtualbox/VBoxCreateUSBNode.sh 189 517 00 vboxusers' succeeded.
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: 5-2: Device processed (SEQNUM=5744, ACTION=add)
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: 5-2: sd-device-monitor(worker): Passed 1191 byte to netlink monitor.
Dec 09 09:18:38 mycomputer2.1 systemd-udevd[447]: 5-2: Device ready for processing (SEQNUM=5745, ACTION=change)
Dec 09 09:18:38 mycomputer2.1 systemd-udevd[447]: 5-2: sd-device-monitor(manager): Passed 327 byte to netlink monitor.
Dec 09 09:18:38 mycomputer2.1 systemd-udevd[447]: 5-2:1.0: SEQNUM=5746 blocked by SEQNUM=5745
Dec 09 09:18:38 mycomputer2.1 systemd-udevd[447]: 0003:09AE:3016.000C: SEQNUM=5747 blocked by SEQNUM=5745
Dec 09 09:18:38 mycomputer2.1 systemd-udevd[447]: hiddev0: SEQNUM=5748 blocked by SEQNUM=5745
Dec 09 09:18:38 mycomputer2.1 systemd-udevd[447]: hidraw0: SEQNUM=5749 blocked by SEQNUM=5745
Dec 09 09:18:38 mycomputer2.1 systemd-udevd[447]: 0003:09AE:3016.000C: SEQNUM=5750 blocked by SEQNUM=5745
Dec 09 09:18:38 mycomputer2.1 systemd-udevd[447]: 5-2:1.0: SEQNUM=5751 blocked by SEQNUM=5745
Dec 09 09:18:38 mycomputer2.1 systemd-udevd[447]: 5-2: SEQNUM=5752 blocked by SEQNUM=5745
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: 5-2: Processing device (SEQNUM=5745, ACTION=change)
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: 5-2: Removing watch handle -1.
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: 5-2: /usr/lib/udev/rules.d/50-udev-default.rules:17 Importing properties from results of builtin command 'usb_id'
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: 5-2: /usr/lib/udev/rules.d/50-udev-default.rules:17 Importing properties from results of builtin command 'hwdb --subsystem=usb'
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: 5-2: hwdb modalias key: "usb:v09AEp3016:TRIPP LITE UPS "
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: 5-2: /usr/lib/udev/rules.d/50-udev-default.rules:27 Importing properties from results of builtin command 'path_id'
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: 5-2: /etc/udev/rules.d/50-ups.rules:1 GROUP 965
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: 5-2: /usr/lib/udev/rules.d/62-nut-usbups.rules:204 GROUP 965
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: 5-2: /usr/lib/udev/rules.d/62-nut-usbups.rules:204 MODE 0664
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: 5-2: Successfully created symlink '/dev/char/189:517' to '/dev/bus/usb/005/006'
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: 5-2: sd-device: Created db file '/run/udev/data/c189:517' for '/devices/pci0000:00/0000:00:08.1/0000:0b:00.3/usb5/5-2'
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: 5-2: Device processed (SEQNUM=5745, ACTION=change)
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: 5-2: sd-device-monitor(worker): Passed 1215 byte to netlink monitor.
Dec 09 09:18:38 mycomputer2.1 systemd-udevd[447]: 5-2:1.0: Device ready for processing (SEQNUM=5746, ACTION=add)
Dec 09 09:18:38 mycomputer2.1 systemd-udevd[447]: 5-2:1.0: sd-device-monitor(manager): Passed 342 byte to netlink monitor.
Dec 09 09:18:38 mycomputer2.1 systemd-udevd[447]: 0003:09AE:3016.000C: SEQNUM=5747 blocked by SEQNUM=5746
Dec 09 09:18:38 mycomputer2.1 systemd-udevd[447]: hiddev0: SEQNUM=5748 blocked by SEQNUM=5746
Dec 09 09:18:38 mycomputer2.1 systemd-udevd[447]: hidraw0: SEQNUM=5749 blocked by SEQNUM=5746
Dec 09 09:18:38 mycomputer2.1 systemd-udevd[447]: 0003:09AE:3016.000C: SEQNUM=5750 blocked by SEQNUM=5746
Dec 09 09:18:38 mycomputer2.1 systemd-udevd[447]: 5-2:1.0: SEQNUM=5751 blocked by SEQNUM=5746
Dec 09 09:18:38 mycomputer2.1 systemd-udevd[447]: 5-2: SEQNUM=5752 blocked by SEQNUM=5746
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: 5-2:1.0: Processing device (SEQNUM=5746, ACTION=add)
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: 5-2:1.0: /usr/lib/udev/rules.d/40-gphoto.rules:9 Importing properties from results of builtin command 'usb_id'
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: 5-2:1.0: Failed to access usb_interface: No such file or directory
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: 5-2:1.0: /usr/lib/udev/rules.d/40-gphoto.rules:9 Failed to run builtin 'usb_id': No such file or directory
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: 5-2:1.0: /usr/lib/udev/rules.d/50-udev-default.rules:18 Importing properties from results of builtin command 'hwdb --subsystem=usb'
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: 5-2:1.0: hwdb modalias key: "usb:v09AEp3016d0002dc00dsc00dp00ic03isc00ip00in00"
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: 5-2:1.0: /usr/lib/udev/rules.d/50-udev-default.rules:27 Importing properties from results of builtin command 'path_id'
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: 5-2:1.0: /usr/lib/udev/rules.d/80-drivers.rules:5 RUN 'kmod load'
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: 5-2:1.0: sd-device: Created db file '/run/udev/data/+usb:5-2:1.0' for '/devices/pci0000:00/0000:00:08.1/0000:0b:00.3/usb5/5-2/5-2:1.0'
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: 5-2:1.0: Running built-in command "kmod load"
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: Loading module: usb:v09AEp3016d0002dc00dsc00dp00ic03isc00ip00in00
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: Module 'usbhid' is already loaded
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: 5-2:1.0: Device processed (SEQNUM=5746, ACTION=add)
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: 5-2:1.0: sd-device-monitor(worker): Passed 560 byte to netlink monitor.
Dec 09 09:18:38 mycomputer2.1 systemd-udevd[447]: 0003:09AE:3016.000C: Device ready for processing (SEQNUM=5747, ACTION=add)
Dec 09 09:18:38 mycomputer2.1 systemd-udevd[447]: 0003:09AE:3016.000C: sd-device-monitor(manager): Passed 412 byte to netlink monitor.
Dec 09 09:18:38 mycomputer2.1 systemd-udevd[447]: hiddev0: Device ready for processing (SEQNUM=5748, ACTION=add)
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: 0003:09AE:3016.000C: Processing device (SEQNUM=5747, ACTION=add)
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: 0003:09AE:3016.000C: /usr/lib/udev/rules.d/50-udev-default.rules:18 Importing properties from results of builtin command 'hwdb --subsystem=hid'
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: 0003:09AE:3016.000C: hwdb modalias key: "hid:b0003g0001v000009AEp00003016"
Dec 09 09:18:38 mycomputer2.1 systemd-udevd[447]: Successfully forked off '(udev-worker)' as PID 133748.
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: 0003:09AE:3016.000C: No entry found from hwdb.
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: 0003:09AE:3016.000C: /usr/lib/udev/rules.d/50-udev-default.rules:18 Failed to run builtin 'hwdb --subsystem=hid': No data available
Dec 09 09:18:38 mycomputer2.1 systemd-udevd[447]: hiddev0: Worker [133748] is forked for processing SEQNUM=5748.
Dec 09 09:18:38 mycomputer2.1 systemd-udevd[447]: hidraw0: SEQNUM=5749 blocked by SEQNUM=5747
Dec 09 09:18:38 mycomputer2.1 systemd-udevd[447]: 0003:09AE:3016.000C: SEQNUM=5750 blocked by SEQNUM=5747
Dec 09 09:18:38 mycomputer2.1 systemd-udevd[447]: 5-2:1.0: SEQNUM=5751 blocked by SEQNUM=5747
Dec 09 09:18:38 mycomputer2.1 systemd-udevd[447]: 5-2: SEQNUM=5752 blocked by SEQNUM=5747
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133748]: hiddev0: Processing device (SEQNUM=5748, ACTION=add)
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133748]: hiddev0: Removing watch handle -1.
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133748]: hiddev0: /usr/lib/udev/rules.d/60-ddcutil-usb.rules:8 Running PROGRAM '/usr/bin/ddcutil chkusbmon /dev/usb/hiddev0 -v'
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133748]: hiddev0: Starting '/usr/bin/ddcutil chkusbmon /dev/usb/hiddev0 -v'
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133748]: Successfully forked off '(spawn)' as PID 133749.
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: 0003:09AE:3016.000C: /usr/lib/udev/rules.d/80-drivers.rules:5 RUN 'kmod load'
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: 0003:09AE:3016.000C: Running built-in command "kmod load"
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: Loading module: hid:b0003g0001v000009AEp00003016
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: Failed to find module 'hid:b0003g0001v000009AEp00003016'
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: 0003:09AE:3016.000C: Device processed (SEQNUM=5747, ACTION=add)
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: 0003:09AE:3016.000C: sd-device-monitor(worker): Passed 412 byte to netlink monitor.
Dec 09 09:18:38 mycomputer2.1 systemd-udevd[447]: hidraw0: Device ready for processing (SEQNUM=5749, ACTION=add)
Dec 09 09:18:38 mycomputer2.1 systemd-udevd[447]: hidraw0: sd-device-monitor(manager): Passed 278 byte to netlink monitor.
Dec 09 09:18:38 mycomputer2.1 systemd-udevd[447]: 0003:09AE:3016.000C: SEQNUM=5750 blocked by SEQNUM=5749
Dec 09 09:18:38 mycomputer2.1 systemd-udevd[447]: 5-2:1.0: SEQNUM=5751 blocked by SEQNUM=5748
Dec 09 09:18:38 mycomputer2.1 systemd-udevd[447]: 5-2: SEQNUM=5752 blocked by SEQNUM=5748
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: hidraw0: Processing device (SEQNUM=5749, ACTION=add)
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: hidraw0: Removing watch handle -1.
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: hidraw0: /usr/lib/udev/rules.d/60-fido-id.rules:5 Importing properties from results of 'fido_id'
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: hidraw0: Starting 'fido_id'
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: Successfully forked off '(spawn)' as PID 133750.
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: hidraw0: Process 'fido_id' succeeded.
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: hidraw0: Preserve permissions of /dev/hidraw0, uid=0, gid=0, mode=0600
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: hidraw0: Successfully created symlink '/dev/char/240:0' to '/dev/hidraw0'
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: hidraw0: sd-device: Created empty file '/run/udev/data/c240:0' for '/devices/pci0000:00/0000:00:08.1/0000:0b:00.3/usb5/5-2/5-2:1.0/0003:09AE:3016.000C/hidraw/hidraw0'
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: hidraw0: Device processed (SEQNUM=5749, ACTION=add)
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: hidraw0: sd-device-monitor(worker): Passed 278 byte to netlink monitor.
Dec 09 09:18:38 mycomputer2.1 systemd-udevd[447]: 0003:09AE:3016.000C: Device ready for processing (SEQNUM=5750, ACTION=bind)
Dec 09 09:18:38 mycomputer2.1 systemd-udevd[447]: 0003:09AE:3016.000C: sd-device-monitor(manager): Passed 413 byte to netlink monitor.
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: 0003:09AE:3016.000C: Processing device (SEQNUM=5750, ACTION=bind)
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: 0003:09AE:3016.000C: /usr/lib/udev/rules.d/50-udev-default.rules:18 Importing properties from results of builtin command 'hwdb --subsystem=hid'
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: 0003:09AE:3016.000C: hwdb modalias key: "hid:b0003g0001v000009AEp00003016"
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: 0003:09AE:3016.000C: No entry found from hwdb.
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: 0003:09AE:3016.000C: /usr/lib/udev/rules.d/50-udev-default.rules:18 Failed to run builtin 'hwdb --subsystem=hid': No data available
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: 0003:09AE:3016.000C: Device processed (SEQNUM=5750, ACTION=bind)
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: 0003:09AE:3016.000C: sd-device-monitor(worker): Passed 413 byte to netlink monitor.
Dec 09 09:18:39 mycomputer2.1 (udev-worker)[133748]: hiddev0: '/usr/bin/ddcutil chkusbmon /dev/usb/hiddev0 -v'(out) 'Device /dev/usb/hiddev0 may be a USB HID compliant monitor.'
Dec 09 09:18:39 mycomputer2.1 (udev-worker)[133748]: hiddev0: Process '/usr/bin/ddcutil chkusbmon /dev/usb/hiddev0 -v' succeeded.
Dec 09 09:18:39 mycomputer2.1 (udev-worker)[133748]: hiddev0: /usr/lib/udev/rules.d/69-mixxx-usb-uaccess.rules:57 GROUP 4294967295
Dec 09 09:18:39 mycomputer2.1 (udev-worker)[133748]: hiddev0: /usr/lib/udev/rules.d/69-mixxx-usb-uaccess.rules:57 Only network interfaces can be renamed, ignoring NAME="usb/%k".
Dec 09 09:18:39 mycomputer2.1 (udev-worker)[133748]: hiddev0: /usr/lib/udev/rules.d/71-seat.rules:74 Importing properties from results of builtin command 'path_id'
Dec 09 09:18:39 mycomputer2.1 (udev-worker)[133748]: hiddev0: /usr/lib/udev/rules.d/73-seat-late.rules:16 RUN 'uaccess'
Dec 09 09:18:39 mycomputer2.1 (udev-worker)[133748]: hiddev0: Preserve permissions of /dev/usb/hiddev0, uid=0, gid=0, mode=0600
Dec 09 09:18:39 mycomputer2.1 (udev-worker)[133748]: hiddev0: Successfully created symlink '/dev/char/180:96' to '/dev/usb/hiddev0'
Dec 09 09:18:39 mycomputer2.1 (udev-worker)[133748]: hiddev0: sd-device: Created db file '/run/udev/data/c180:96' for '/devices/pci0000:00/0000:00:08.1/0000:0b:00.3/usb5/5-2/5-2:1.0/usbmisc/hiddev0'
Dec 09 09:18:39 mycomputer2.1 (udev-worker)[133748]: hiddev0: Running built-in command "uaccess"
Dec 09 09:18:39 mycomputer2.1 (udev-worker)[133748]: hiddev0: Device processed (SEQNUM=5748, ACTION=add)
Dec 09 09:18:39 mycomputer2.1 (udev-worker)[133748]: hiddev0: sd-device-monitor(worker): Passed 545 byte to netlink monitor.
Dec 09 09:18:39 mycomputer2.1 systemd-udevd[447]: 5-2:1.0: Device ready for processing (SEQNUM=5751, ACTION=bind)
Dec 09 09:18:39 mycomputer2.1 systemd-udevd[447]: 5-2:1.0: sd-device-monitor(manager): Passed 343 byte to netlink monitor.
Dec 09 09:18:39 mycomputer2.1 systemd-udevd[447]: 5-2: SEQNUM=5752 blocked by SEQNUM=5751
Dec 09 09:18:39 mycomputer2.1 (udev-worker)[133748]: 5-2:1.0: Processing device (SEQNUM=5751, ACTION=bind)
Dec 09 09:18:39 mycomputer2.1 (udev-worker)[133748]: 5-2:1.0: /usr/lib/udev/rules.d/40-gphoto.rules:9 Importing properties from results of builtin command 'usb_id'
Dec 09 09:18:39 mycomputer2.1 (udev-worker)[133748]: 5-2:1.0: Failed to access usb_interface: No such file or directory
Dec 09 09:18:39 mycomputer2.1 (udev-worker)[133748]: 5-2:1.0: /usr/lib/udev/rules.d/40-gphoto.rules:9 Failed to run builtin 'usb_id': No such file or directory
Dec 09 09:18:39 mycomputer2.1 (udev-worker)[133748]: 5-2:1.0: /usr/lib/udev/rules.d/50-udev-default.rules:18 Importing properties from results of builtin command 'hwdb --subsystem=usb'
Dec 09 09:18:39 mycomputer2.1 (udev-worker)[133748]: 5-2:1.0: hwdb modalias key: "usb:v09AEp3016d0002dc00dsc00dp00ic03isc00ip00in00"
Dec 09 09:18:39 mycomputer2.1 (udev-worker)[133748]: 5-2:1.0: /usr/lib/udev/rules.d/50-udev-default.rules:27 Importing properties from results of builtin command 'path_id'
Dec 09 09:18:39 mycomputer2.1 (udev-worker)[133748]: 5-2:1.0: sd-device: Created db file '/run/udev/data/+usb:5-2:1.0' for '/devices/pci0000:00/0000:00:08.1/0000:0b:00.3/usb5/5-2/5-2:1.0'
Dec 09 09:18:39 mycomputer2.1 (udev-worker)[133748]: 5-2:1.0: Device processed (SEQNUM=5751, ACTION=bind)
Dec 09 09:18:39 mycomputer2.1 (udev-worker)[133748]: 5-2:1.0: sd-device-monitor(worker): Passed 561 byte to netlink monitor.
Dec 09 09:18:39 mycomputer2.1 systemd-udevd[447]: 5-2: Device ready for processing (SEQNUM=5752, ACTION=bind)
Dec 09 09:18:39 mycomputer2.1 systemd-udevd[447]: 5-2: sd-device-monitor(manager): Passed 325 byte to netlink monitor.
Dec 09 09:18:39 mycomputer2.1 (udev-worker)[133748]: 5-2: Processing device (SEQNUM=5752, ACTION=bind)
Dec 09 09:18:39 mycomputer2.1 (udev-worker)[133748]: 5-2: Removing watch handle -1.
Dec 09 09:18:39 mycomputer2.1 (udev-worker)[133748]: 5-2: /usr/lib/udev/rules.d/40-gphoto.rules:9 Importing properties from results of builtin command 'usb_id'
Dec 09 09:18:39 mycomputer2.1 (udev-worker)[133748]: 5-2: /usr/lib/udev/rules.d/50-udev-default.rules:17 Skipping builtin 'usb_id' in IMPORT key
Dec 09 09:18:39 mycomputer2.1 (udev-worker)[133748]: 5-2: /usr/lib/udev/rules.d/50-udev-default.rules:17 Importing properties from results of builtin command 'hwdb --subsystem=usb'
Dec 09 09:18:39 mycomputer2.1 (udev-worker)[133748]: 5-2: hwdb modalias key: "usb:v09AEp3016:TRIPP LITE UPS "
Dec 09 09:18:39 mycomputer2.1 (udev-worker)[133748]: 5-2: /usr/lib/udev/rules.d/50-udev-default.rules:27 Importing properties from results of builtin command 'path_id'
Dec 09 09:18:39 mycomputer2.1 (udev-worker)[133748]: 5-2: /etc/udev/rules.d/50-ups.rules:1 GROUP 965
Dec 09 09:18:39 mycomputer2.1 (udev-worker)[133748]: 5-2: /usr/lib/udev/rules.d/62-nut-usbups.rules:204 GROUP 965
Dec 09 09:18:39 mycomputer2.1 (udev-worker)[133748]: 5-2: /usr/lib/udev/rules.d/62-nut-usbups.rules:204 MODE 0664
Dec 09 09:18:39 mycomputer2.1 (udev-worker)[133748]: 5-2: /usr/lib/udev/rules.d/69-libmtp.rules:39 Running PROGRAM '/usr/lib/udev/mtp-probe /sys/devices/pci0000:00/0000:00:08.1/0000:0b:00.3/usb5/5-2 5 6'
Dec 09 09:18:39 mycomputer2.1 (udev-worker)[133748]: 5-2: Starting '/usr/lib/udev/mtp-probe /sys/devices/pci0000:00/0000:00:08.1/0000:0b:00.3/usb5/5-2 5 6'
Dec 09 09:18:39 mycomputer2.1 (udev-worker)[133748]: Successfully forked off '(spawn)' as PID 133751.
Dec 09 09:18:39 mycomputer2.1 mtp-probe[133751]: checking bus 5, device 6: "/sys/devices/pci0000:00/0000:00:08.1/0000:0b:00.3/usb5/5-2"
Dec 09 09:18:39 mycomputer2.1 mtp-probe[133751]: bus: 5, device: 6 was not an MTP device
Dec 09 09:18:39 mycomputer2.1 (udev-worker)[133748]: 5-2: '/usr/lib/udev/mtp-probe /sys/devices/pci0000:00/0000:00:08.1/0000:0b:00.3/usb5/5-2 5 6'(out) '0'
Dec 09 09:18:39 mycomputer2.1 (udev-worker)[133748]: 5-2: Process '/usr/lib/udev/mtp-probe /sys/devices/pci0000:00/0000:00:08.1/0000:0b:00.3/usb5/5-2 5 6' succeeded.
Dec 09 09:18:39 mycomputer2.1 (udev-worker)[133748]: 5-2: Successfully created symlink '/dev/char/189:517' to '/dev/bus/usb/005/006'
Dec 09 09:18:39 mycomputer2.1 (udev-worker)[133748]: 5-2: sd-device: Created db file '/run/udev/data/c189:517' for '/devices/pci0000:00/0000:00:08.1/0000:0b:00.3/usb5/5-2'
Dec 09 09:18:39 mycomputer2.1 (udev-worker)[133748]: 5-2: Device processed (SEQNUM=5752, ACTION=bind)
Dec 09 09:18:39 mycomputer2.1 (udev-worker)[133748]: 5-2: sd-device-monitor(worker): Passed 1192 byte to netlink monitor.
Dec 09 09:18:39 mycomputer2.1 systemd-udevd[447]: No events are queued, removing /run/udev/queue.
Dec 09 09:18:39 mycomputer2.1 systemd-udevd[447]: hiddev0: Device is queued (SEQNUM=5753, ACTION=remove)
Dec 09 09:18:39 mycomputer2.1 systemd-udevd[447]: hiddev0: Device ready for processing (SEQNUM=5753, ACTION=remove)
Dec 09 09:18:39 mycomputer2.1 systemd-udevd[447]: hiddev0: sd-device-monitor(manager): Passed 268 byte to netlink monitor.
Dec 09 09:18:39 mycomputer2.1 systemd-udevd[447]: hidraw0: Device is queued (SEQNUM=5754, ACTION=remove)
Dec 09 09:18:39 mycomputer2.1 systemd-udevd[447]: hidraw0: Device ready for processing (SEQNUM=5754, ACTION=remove)
Dec 09 09:18:39 mycomputer2.1 systemd-udevd[447]: hidraw0: sd-device-monitor(manager): Passed 281 byte to netlink monitor.
Dec 09 09:18:39 mycomputer2.1 (udev-worker)[133748]: hiddev0: Processing device (SEQNUM=5753, ACTION=remove)
Dec 09 09:18:39 mycomputer2.1 systemd-udevd[447]: 0003:09AE:3016.000C: Device is queued (SEQNUM=5755, ACTION=unbind)
Dec 09 09:18:39 mycomputer2.1 systemd-udevd[447]: 0003:09AE:3016.000C: SEQNUM=5755 blocked by SEQNUM=5754
Dec 09 09:18:39 mycomputer2.1 systemd-udevd[447]: 0003:09AE:3016.000C: Device is queued (SEQNUM=5756, ACTION=remove)
Dec 09 09:18:39 mycomputer2.1 systemd-udevd[447]: 0003:09AE:3016.000C: SEQNUM=5756 blocked by SEQNUM=5754
Dec 09 09:18:39 mycomputer2.1 (udev-worker)[133735]: hidraw0: Processing device (SEQNUM=5754, ACTION=remove)
Dec 09 09:18:39 mycomputer2.1 (udev-worker)[133748]: hiddev0: Removing watch handle -1.
Dec 09 09:18:39 mycomputer2.1 systemd-udevd[447]: 5-2:1.0: Device is queued (SEQNUM=5757, ACTION=unbind)
Dec 09 09:18:39 mycomputer2.1 systemd-udevd[447]: 5-2:1.0: SEQNUM=5757 blocked by SEQNUM=5753
Dec 09 09:18:39 mycomputer2.1 (udev-worker)[133735]: hidraw0: Removing watch handle -1.
Dec 09 09:18:39 mycomputer2.1 (udev-worker)[133748]: hiddev0: /usr/lib/udev/rules.d/60-ddcutil-usb.rules:8 Running PROGRAM '/usr/bin/ddcutil chkusbmon /dev/usb/hiddev0 -v'
Dec 09 09:18:39 mycomputer2.1 (udev-worker)[133748]: hiddev0: Starting '/usr/bin/ddcutil chkusbmon /dev/usb/hiddev0 -v'
Dec 09 09:18:39 mycomputer2.1 (udev-worker)[133735]: sd-device: Failed to chase symlinks in "/sys/devices/pci0000:00/0000:00:08.1/0000:0b:00.3/usb5/5-2/5-2:1.0/0003:09AE:3016.000C/hidraw".
Dec 09 09:18:39 mycomputer2.1 (udev-worker)[133735]: sd-device: Failed to chase symlinks in "/sys/devices/pci0000:00/0000:00:08.1/0000:0b:00.3/usb5/5-2/5-2:1.0/0003:09AE:3016.000C".
Dec 09 09:18:39 mycomputer2.1 (udev-worker)[133748]: Successfully forked off '(spawn)' as PID 133752.
Dec 09 09:18:39 mycomputer2.1 (udev-worker)[133735]: hidraw0: Device processed (SEQNUM=5754, ACTION=remove)
Dec 09 09:18:39 mycomputer2.1 (udev-worker)[133735]: hidraw0: sd-device-monitor(worker): Passed 281 byte to netlink monitor.
Dec 09 09:18:39 mycomputer2.1 systemd-udevd[447]: 0003:09AE:3016.000C: Device ready for processing (SEQNUM=5755, ACTION=unbind)
Dec 09 09:18:39 mycomputer2.1 systemd-udevd[447]: 0003:09AE:3016.000C: sd-device-monitor(manager): Passed 354 byte to netlink monitor.
Dec 09 09:18:39 mycomputer2.1 systemd-udevd[447]: 0003:09AE:3016.000C: SEQNUM=5756 blocked by SEQNUM=5755
Dec 09 09:18:39 mycomputer2.1 (udev-worker)[133735]: 0003:09AE:3016.000C: Processing device (SEQNUM=5755, ACTION=unbind)
Dec 09 09:18:39 mycomputer2.1 (udev-worker)[133735]: 0003:09AE:3016.000C: Device processed (SEQNUM=5755, ACTION=unbind)
Dec 09 09:18:39 mycomputer2.1 (udev-worker)[133735]: 0003:09AE:3016.000C: sd-device-monitor(worker): Passed 354 byte to netlink monitor.
Dec 09 09:18:39 mycomputer2.1 systemd-udevd[447]: 0003:09AE:3016.000C: Device ready for processing (SEQNUM=5756, ACTION=remove)
Dec 09 09:18:39 mycomputer2.1 systemd-udevd[447]: 0003:09AE:3016.000C: sd-device-monitor(manager): Passed 396 byte to netlink monitor.
Dec 09 09:18:39 mycomputer2.1 (udev-worker)[133735]: 0003:09AE:3016.000C: Processing device (SEQNUM=5756, ACTION=remove)
Dec 09 09:18:39 mycomputer2.1 (udev-worker)[133735]: 0003:09AE:3016.000C: Device processed (SEQNUM=5756, ACTION=remove)
Dec 09 09:18:39 mycomputer2.1 (udev-worker)[133735]: 0003:09AE:3016.000C: sd-device-monitor(worker): Passed 396 byte to netlink monitor.
Dec 09 09:18:40 mycomputer2.1 (udev-worker)[133748]: hiddev0: '/usr/bin/ddcutil chkusbmon /dev/usb/hiddev0 -v'(out) '(lookup_udev_usb_device_by_devname) Unexpectedly found 0 matching devices for /dev/usb/hiddev0'
Dec 09 09:18:40 mycomputer2.1 (udev-worker)[133748]: hiddev0: '/usr/bin/ddcutil chkusbmon /dev/usb/hiddev0 -v'(out) 'Device /dev/usb/hiddev0 is not a USB HID compliant monitor.'
Dec 09 09:18:40 mycomputer2.1 (udev-worker)[133748]: hiddev0: Process '/usr/bin/ddcutil chkusbmon /dev/usb/hiddev0 -v' failed with exit code 1.
Dec 09 09:18:40 mycomputer2.1 (udev-worker)[133748]: hiddev0: /usr/lib/udev/rules.d/60-ddcutil-usb.rules:8 Command "/usr/bin/ddcutil chkusbmon /dev/usb/hiddev0 -v" returned 1 (error)
Dec 09 09:18:40 mycomputer2.1 (udev-worker)[133748]: sd-device: Failed to chase symlinks in "/sys/devices/pci0000:00/0000:00:08.1/0000:0b:00.3/usb5/5-2/5-2:1.0/usbmisc".
Dec 09 09:18:40 mycomputer2.1 (udev-worker)[133748]: hiddev0: Device processed (SEQNUM=5753, ACTION=remove)
Dec 09 09:18:40 mycomputer2.1 (udev-worker)[133748]: hiddev0: sd-device-monitor(worker): Passed 548 byte to netlink monitor.
Dec 09 09:18:40 mycomputer2.1 systemd-udevd[447]: 5-2:1.0: Device ready for processing (SEQNUM=5757, ACTION=unbind)
Dec 09 09:18:40 mycomputer2.1 systemd-udevd[447]: 5-2:1.0: sd-device-monitor(manager): Passed 285 byte to netlink monitor.
Dec 09 09:18:40 mycomputer2.1 (udev-worker)[133748]: 5-2:1.0: Processing device (SEQNUM=5757, ACTION=unbind)
Dec 09 09:18:40 mycomputer2.1 (udev-worker)[133748]: 5-2:1.0: /usr/lib/udev/rules.d/50-udev-default.rules:27 Importing properties from results of builtin command 'path_id'
Dec 09 09:18:40 mycomputer2.1 org_kde_powerdevil[12183]: QObject::disconnect: Unexpected nullptr parameter
Dec 09 09:18:40 mycomputer2.1 org_kde_powerdevil[1297]: QObject::disconnect: Unexpected nullptr parameter
Dec 09 09:18:40 mycomputer2.1 org_kde_powerdevil[1297]: QObject::disconnect: Unexpected nullptr parameter
Dec 09 09:18:40 mycomputer2.1 org_kde_powerdevil[12183]: QObject::disconnect: Unexpected nullptr parameter
Dec 09 09:18:40 mycomputer2.1 (udev-worker)[133748]: 5-2:1.0: sd-device: Created db file '/run/udev/data/+usb:5-2:1.0' for '/devices/pci0000:00/0000:00:08.1/0000:0b:00.3/usb5/5-2/5-2:1.0'
Dec 09 09:18:40 mycomputer2.1 (udev-worker)[133748]: 5-2:1.0: Device processed (SEQNUM=5757, ACTION=unbind)
Dec 09 09:18:40 mycomputer2.1 (udev-worker)[133748]: 5-2:1.0: sd-device-monitor(worker): Passed 420 byte to netlink monitor.
Dec 09 09:18:40 mycomputer2.1 systemd-udevd[447]: No events are queued, removing /run/udev/queue.
Dec 09 09:18:40 mycomputer2.1 nut-server[937]: UPS [mycomputer-TL-UPS] data is no longer stale
Dec 09 09:18:40 mycomputer2.1 upsd[937]: UPS [mycomputer-TL-UPS] data is no longer stale
Dec 09 09:18:44 mycomputer2.1 systemd-udevd[447]: Cleanup idle workers
Dec 09 09:18:44 mycomputer2.1 systemd-udevd[447]: Worker [133748] exited.
Dec 09 09:18:44 mycomputer2.1 systemd-udevd[447]: Worker [133735] exited.
Dec 09 09:18:44 mycomputer2.1 systemd[1]: nut-driver@mycomputer2ups.service: Scheduled restart job, restart counter is at 3589.
Dec 09 09:18:44 mycomputer2.1 systemd[1]: Starting Network UPS Tools - device driver for NUT device 'mycomputer2ups'...
Dec 09 09:18:44 mycomputer2.1 nut-driver@mycomputer2ups[133754]: FATAL: Could not find a NUT device section for service unit mycomputer2ups
Dec 09 09:18:44 mycomputer2.1 systemd[1]: nut-driver@mycomputer2ups.service: Main process exited, code=exited, status=1/FAILURE
Dec 09 09:18:44 mycomputer2.1 systemd[1]: nut-driver@mycomputer2ups.service: Failed with result 'exit-code'.
Dec 09 09:18:44 mycomputer2.1 systemd[1]: Failed to start Network UPS Tools - device driver for NUT device 'mycomputer2ups'.
Dec 09 09:18:48 mycomputer2.1 systemd-udevd[447]: Cleanup idle workersI'm seeing a lot of 'failed' and 'exit' but they're mostly associated with unrelated rules, so that doesn't seem strange to me.
This seems to be where it fails:
EDIT: In hindsight, I believe this isn't where it failed, but indicating that the UPS USB cable had been removed.
Dec 09 09:18:33 mycomputer2.1 nut-driver@mycomputer-TL-UPS[822]: nut_libusb_get_interrupt: No such device (it may have been disconnected)
Dec 09 09:18:33 mycomputer2.1 usbhid-ups[822]: nut_libusb_get_interrupt: No such device (it may have been disconnected)Then followed by:
Dec 09 09:18:35 mycomputer2.1 nut-driver@mycomputer-TL-UPS[822]: libusb1: Could not open any HID devices: insufficient permissions on everything
Dec 09 09:18:35 mycomputer2.1 usbhid-ups[822]: libusb1: Could not open any HID devices: insufficient permissions on everything
Dec 09 09:18:35 mycomputer2.1 nut-server[937]: Data for UPS [mycomputer-TL-UPS] is stale - check driver
Dec 09 09:18:35 mycomputer2.1 upsd[937]: Data for UPS [mycomputer-TL-UPS] is stale - check driverI do see the udev rule being loaded:
Dec 09 09:18:38 mycomputer2.1 (udev-worker)[133735]: 5-2: /etc/udev/rules.d/50-ups.rules:1 GROUP 965However this occurs after the permissions error.
I may need to lower the number in the rule name to get it to load earlier, but I don't know if that would make a difference.
Maybe someone here can see anything obvious in these outputs to point me in the right direction.
I previously had this UPS working correctly before NUT changed to now use the nut-driver-enumerator.service, and it may be possible that I have an old udev rule that is conflicting with the new method.
Thanks.
Edit: Correction to the first failure and formatting.
Last edited by heidegger (2023-12-10 15:44:16)
Offline
I was able to solve this.
I did two things and was able to get past the problem.
1st was to reboot the UPS.
2nd was to uninstall mixxx due to the following error:
Dec 09 09:18:39 camus2.1 (udev-worker)[133748]: hiddev0: /usr/lib/udev/rules.d/69-mixxx-usb-uaccess.rules:57 GROUP 4294967295
Dec 09 09:18:39 camus2.1 (udev-worker)[133748]: hiddev0: /usr/lib/udev/rules.d/69-mixxx-usb-uaccess.rules:57 Only network interfaces can be renamed, ignoring NAME="usb/%k".I don't use this app and I uninstalled it just in case.
I'm thinking the UPS reboot fixed it.
Offline