NUT Package (2.8.1 and above)
-
@dennypage said in NUT Package (2.8.1 and above):
We only care about things that match “kernel” or “usbhid-ups”…
Everything was working fine on March 3rd (after restart) but when I checked afternoon of March 4th, Nut reported: Failed to retrieve status.
(Of course there are many "usbhid-ups: Could not open any HID devices" entries between Mar 4 14:18 and Mar 4 15:03.)
Mar 3 23:15:00 router01 kernel: nd6_dad_timer: called with non-tentative address fe80:c::1:1(mvneta0.4092) Mar 3 23:15:07 router01 usbhid-ups[53729]: using 'battery.charge' to set battery low state Mar 3 23:15:07 router01 usbhid-ups[53729]: using 'battery.runtime' to set battery low state Mar 3 23:15:07 router01 usbhid-ups[54232]: Startup successful Mar 4 14:18:19 router01 usbhid-ups[54232]: libusb1: Could not open any HID devices: insufficient permissions on everything Mar 4 14:18:21 router01 usbhid-ups[54232]: libusb1: Could not open any HID devices: insufficient permissions on everything Mar 4 14:18:23 router01 usbhid-ups[54232]: libusb1: Could not open any HID devices: insufficient permissions on everything ~ ~ ~ Mar 4 15:03:26 router01 usbhid-ups[54232]: libusb1: Could not open any HID devices: insufficient permissions on everything Mar 4 15:03:28 router01 usbhid-ups[54232]: libusb1: Could not open any HID devices: insufficient permissions on everything Mar 4 15:03:28 router01 usbhid-ups[54232]: Failed to init libusb 1.0: Cannot allocate memory Mar 4 15:03:28 router01 kernel: kern.ipc.maxpipekva exceeded; see tuning(7)
-
@ghound If I understood you correctly, you had previously said that you had to physically disconnect the USB cable after the UPS disappeared. However the usbconfig output you posted shows that the UPS is still connected. Also, there are not kernel USB messages. Can you clarify please?
When the UPS stops, have you tried restarting the UPS service?
Lastly, can you please post anything you have in the "Extra Arguments to driver" and "Additional configuration lines for ups.conf" sections?
-
@dennypage said in NUT Package (2.8.1 and above):
@ghound If I understood you correctly, you had previously said that you had to physically disconnect the USB cable after the UPS disappeared. However the usbconfig output you posted shows that the UPS is still connected. Also, there are not kernel USB messages. Can you clarify please?
I had physically disconnected/reconnected the USB earlier that day and and restarted after I lost WAN ISP connection overnight. Here are log entries from that event:
Mar 3 06:39:12 router01 usbhid-ups[33081]: libusb1: Could not open any HID devices: insufficient permissions on everything Mar 3 06:39:13 router01 usbhid-ups[33081]: Failed to init libusb 1.0: Cannot allocate memory Mar 3 06:39:13 router01 kernel: kern.ipc.maxpipekva exceeded; see tuning(7) ~ ~ ~ Mar 3 09:57:34 router01 kernel: ---<<BOOT>>--- Mar 3 09:57:34 router01 kernel: GDB: debug ports: uart Mar 3 09:57:34 router01 kernel: GDB: current port: uart Mar 3 09:57:34 router01 kernel: KDB: debugger backends: ddb gdb Mar 3 09:57:34 router01 kernel: KDB: current backend: ddb Mar 3 09:57:34 router01 kernel: Copyright (c) 1992-2023 The FreeBSD Project. Mar 3 09:57:34 router01 kernel: Copyright (c) 1979, 1980, 1983, 1986, 1988, 1989, 1991, 1992, 1993, 1994 Mar 3 09:57:34 router01 kernel: The Regents of the University of California. All rights reserved. Mar 3 09:57:34 router01 kernel: FreeBSD is a registered trademark of The FreeBSD Foundation. Mar 3 09:57:34 router01 kernel: FreeBSD 14.0-CURRENT aarch64 1400094 #1 plus-RELENG_23_09_1-n256200-3de1e293f3a: Wed Dec 6 20:59:18 UTC 2023 Mar 3 09:57:34 router01 kernel: root@freebsd:/var/jenkins/workspace/pfSense-Plus-snapshots-23_09_1-main/obj/aarch64/8ra4gn87/var/jenkins/workspace/pfSense-Plus-snapshots-23_09_1-main/sources/FreeBSD-src-plus-RELENG_23_09_1/arm64.aarch64/sys/pfSense arm64 Mar 3 09:57:34 router01 kernel: FreeBSD clang version 16.0.6 (https://github.com/llvm/llvm-project.git llvmorg-16.0.6-0-g7cbf1a259152) Mar 3 09:57:34 router01 kernel: VT: init without driver. Mar 3 09:57:34 router01 kernel: module scmi already present! Mar 3 09:57:34 router01 kernel: real memory = 1073680384 (1023 MB) Mar 3 09:57:34 router01 kernel: avail memory = 983601152 (938 MB) Mar 3 09:57:34 router01 kernel: Starting CPU 1 (1) Mar 3 09:57:34 router01 kernel: FreeBSD/SMP: Multiprocessor System Detected: 2 CPUs Mar 3 09:57:34 router01 kernel: arc4random: WARNING: initial seeding bypassed the cryptographic random device because it was not yet seeded and the knob 'bypass_before_seeding' was enabled. Mar 3 09:57:34 router01 kernel: random: entropy device external interface Mar 3 09:57:34 router01 kernel: ipw_bss: You need to read the LICENSE file in /usr/share/doc/legal/intel_ipw.LICENSE. Mar 3 09:57:34 router01 kernel: ipw_bss: If you agree with the license, set legal.intel_ipw.license_ack=1 in /boot/loader.conf. Mar 3 09:57:34 router01 kernel: module_register_init: MOD_LOAD (ipw_bss_fw, 0xffff000000251810, 0) error 1 Mar 3 09:57:34 router01 kernel: ipw_ibss: You need to read the LICENSE file in /usr/share/doc/legal/intel_ipw.LICENSE. Mar 3 09:57:34 router01 kernel: ipw_ibss: If you agree with the license, set legal.intel_ipw.license_ack=1 in /boot/loader.conf. Mar 3 09:57:34 router01 kernel: module_register_init: MOD_LOAD (ipw_ibss_fw, 0xffff0000002518bc, 0) error 1 Mar 3 09:57:34 router01 kernel: ipw_monitor: You need to read the LICENSE file in /usr/share/doc/legal/intel_ipw.LICENSE. Mar 3 09:57:34 router01 kernel: ipw_monitor: If you agree with the license, set legal.intel_ipw.license_ack=1 in /boot/loader.conf. Mar 3 09:57:34 router01 kernel: module_register_init: MOD_LOAD (ipw_monitor_fw, 0xffff000000251968, 0) error 1 Mar 3 09:57:34 router01 kernel: iwi_bss: You need to read the LICENSE file in /usr/share/doc/legal/intel_iwi.LICENSE. Mar 3 09:57:34 router01 kernel: iwi_bss: If you agree with the license, set legal.intel_iwi.license_ack=1 in /boot/loader.conf. Mar 3 09:57:34 router01 kernel: module_register_init: MOD_LOAD (iwi_bss_fw, 0xffff000000251a14, 0) error 1 Mar 3 09:57:34 router01 kernel: iwi_ibss: You need to read the LICENSE file in /usr/share/doc/legal/intel_iwi.LICENSE. Mar 3 09:57:34 router01 kernel: iwi_ibss: If you agree with the license, set legal.intel_iwi.license_ack=1 in /boot/loader.conf. Mar 3 09:57:34 router01 kernel: module_register_init: MOD_LOAD (iwi_ibss_fw, 0xffff000000251ac0, 0) error 1 Mar 3 09:57:34 router01 kernel: wlan: mac acl policy registered Mar 3 09:57:34 router01 kernel: iwi_monitor: You need to read the LICENSE file in /usr/share/doc/legal/intel_iwi.LICENSE. Mar 3 09:57:34 router01 kernel: iwi_monitor: If you agree with the license, set legal.intel_iwi.license_ack=1 in /boot/loader.conf. Mar 3 09:57:34 router01 kernel: module_register_init: MOD_LOAD (iwi_monitor_fw, 0xffff000000251b6c, 0) error 1 Mar 3 09:57:34 router01 kernel: kbd0 at kbdmux0 Mar 3 09:57:34 router01 kernel: ofwbus0: <Open Firmware Device Tree> Mar 3 09:57:34 router01 kernel: simplebus0: <Flattened device tree simple bus> on ofwbus0 Mar 3 09:57:34 router01 kernel: simplebus1: <Flattened device tree simple bus> on simplebus0 Mar 3 09:57:34 router01 kernel: ofw_firmware0: <OFW Firmware Group> on ofwbus0 Mar 3 09:57:34 router01 kernel: simple_mfd0: <Simple MFD (Multi-Functions Device)> mem 0x13800-0x138ff,0x13c00-0x13c1f on simplebus1 Mar 3 09:57:34 router01 kernel: simple_mfd1: <Simple MFD (Multi-Functions Device)> mem 0x18800-0x188ff,0x18c00-0x18c1f on simplebus1 Mar 3 09:57:34 router01 kernel: psci0: <ARM Power State Co-ordination Interface Driver> on ofwbus0 Mar 3 09:57:34 router01 kernel: netgate0: <Netgate 1100> Mar 3 09:57:34 router01 kernel: gic0: <ARM Generic Interrupt Controller v3.0> mem 0x1d00000-0x1d0ffff,0x1d40000-0x1d7ffff,0x1d80000-0x1d81fff,0x1d90000-0x1d91fff,0x1da0000-0x1dbffff irq 28 on simplebus1 Mar 3 09:57:34 router01 kernel: gpio0: <Armada 37x0 North Bridge GPIO Controller> mem 0x13800-0x138ff,0x13c00-0x13c1f irq 29,30,31,32,33,34,35,36,37,38,39,40 on simple_mfd0 Mar 3 09:57:34 router01 kernel: gpiobus0: <OFW GPIO bus> on gpio0 Mar 3 09:57:34 router01 kernel: gpio1: <Armada 37x0 South Bridge GPIO Controller> mem 0x18800-0x188ff,0x18c00-0x18c1f irq 41,42,43,44,45 on simple_mfd1 Mar 3 09:57:34 router01 kernel: gpiobus1: <OFW GPIO bus> on gpio1 Mar 3 09:57:34 router01 kernel: gpioregulator0: <GPIO controlled regulator> on ofwbus0 Mar 3 09:57:34 router01 kernel: a37x0-xtal0: <Marvell Armada 3700 Oscillator> mem 0x13800-0x138ff,0x13c00-0x13c1f on simple_mfd0 Mar 3 09:57:34 router01 kernel: generic_timer0: <ARMv8 Generic Timer> irq 0,1,2,3 on ofwbus0 Mar 3 09:57:34 router01 kernel: Timecounter "ARM MPCore Timecounter" frequency 12500000 Hz quality 1000 Mar 3 09:57:34 router01 kernel: Event timer "ARM MPCore Eventtimer" frequency 12500000 Hz quality 1000 Mar 3 09:57:34 router01 kernel: a37x0_tbg0: <Marvell Armada 3700 time base generators> mem 0x13200-0x132ff on simplebus1 Mar 3 09:57:34 router01 kernel: a37x0_nb_periph_driver0: <marvell,armada-3700-nb-periph-clock> mem 0x13000-0x130ff on simplebus1 Mar 3 09:57:34 router01 kernel: a37x0_sb_periph_driver0: <marvell,armada-3700-sb-periph-clock> mem 0x18000-0x180ff on simplebus1 Mar 3 09:57:34 router01 kernel: cpulist0: <Open Firmware CPU Group> on ofwbus0 Mar 3 09:57:34 router01 kernel: cpu0: <Open Firmware CPU> on cpulist0 Mar 3 09:57:34 router01 kernel: pmu0: <Performance Monitoring Unit> irq 4 on ofwbus0 Mar 3 09:57:34 router01 kernel: spi0: <Armada 37x0 SPI controller> mem 0x10600-0x10fff irq 6 on simplebus1 Mar 3 09:57:34 router01 kernel: iichb0: <Marvell Armada 37x0 IIC controller> mem 0x11000-0x11023 irq 7 on simplebus1 Mar 3 09:57:34 router01 kernel: iicbus0: <OFW I2C bus> on iichb0 Mar 3 09:57:34 router01 kernel: iic0: <I2C generic I/O> on iicbus0 Mar 3 09:57:34 router01 kernel: uart0: <Marvell Armada 3700 UART> mem 0x12000-0x12017 irq 9,10,11 on simplebus1 Mar 3 09:57:34 router01 kernel: uart0: console (115200,n,8,1) Mar 3 09:57:34 router01 kernel: gpioc0: <GPIO controller> on gpio0 Mar 3 09:57:34 router01 kernel: gpioc1: <GPIO controller> on gpio1 Mar 3 09:57:34 router01 kernel: mvneta0: <NETA controller> mem 0x30000-0x33fff irq 14 on simplebus1 Mar 3 09:57:34 router01 kernel: mvneta0: version is 10 Mar 3 09:57:34 router01 kernel: mdio0: <MDIO> on mvneta0 Mar 3 09:57:34 router01 kernel: mdioproxy0: <MII/MDIO proxy, MDIO side> on mdio0 Mar 3 09:57:34 router01 kernel: e6000sw0: <Marvell 88E6341> on mdio0 Mar 3 09:57:34 router01 kernel: e6000sw0: multi-chip addressing mode (0x1) Mar 3 09:57:34 router01 kernel: e6000sw0: CPU port at 0 Mar 3 09:57:34 router01 kernel: e6000sw0: fixed port at 0 Mar 3 09:57:34 router01 kernel: e6000sw0: PHY at port 1 Mar 3 09:57:34 router01 kernel: miibus0: <MII bus> on e6000sw0 Mar 3 09:57:34 router01 kernel: e1000phy0: <Marvell 88E1000 Gigabit PHY> PHY 17 on miibus0 Mar 3 09:57:34 router01 kernel: e1000phy0: none, 10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, 1000baseT, 1000baseT-master, 1000baseT-FDX, 1000baseT-FDX-master, auto Mar 3 09:57:34 router01 kernel: e6000sw0: PHY at port 2 Mar 3 09:57:34 router01 kernel: miibus1: <MII bus> on e6000sw0 Mar 3 09:57:34 router01 kernel: e1000phy1: <Marvell 88E1000 Gigabit PHY> PHY 18 on miibus1 Mar 3 09:57:34 router01 kernel: e1000phy1: none, 10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, 1000baseT, 1000baseT-master, 1000baseT-FDX, 1000baseT-FDX-master, auto Mar 3 09:57:34 router01 kernel: e6000sw0: PHY at port 3 Mar 3 09:57:34 router01 kernel: miibus2: <MII bus> on e6000sw0 Mar 3 09:57:34 router01 kernel: e1000phy2: <Marvell 88E1000 Gigabit PHY> PHY 19 on miibus2 Mar 3 09:57:34 router01 kernel: e1000phy2: none, 10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, 1000baseT, 1000baseT-master, 1000baseT-FDX, 1000baseT-FDX-master, auto Mar 3 09:57:34 router01 kernel: e6000sw0: switch is ready. Mar 3 09:57:34 router01 kernel: etherswitch0: <Switch controller> on e6000sw0 Mar 3 09:57:34 router01 kernel: mvneta0: Ethernet address: f0:ad:4e:1b:e5:a6 Mar 3 09:57:34 router01 kernel: xhci0: <Generic USB 3.0 controller> mem 0x58000-0x5bfff irq 16 on simplebus1 Mar 3 09:57:34 router01 kernel: xhci0: 32 bytes context size, 32-bit DMA Mar 3 09:57:34 router01 kernel: usbus0 on xhci0 Mar 3 09:57:34 router01 kernel: ehci0: <Marvell Integrated USB 2.0 controller> mem 0x5e000-0x5efff irq 17 on simplebus1 Mar 3 09:57:34 router01 kernel: usbus1: EHCI version 1.0 Mar 3 09:57:34 router01 kernel: usbus1 on ehci0 Mar 3 09:57:34 router01 kernel: sdhci_xenon0: <Armada Xenon SDHCI controller> mem 0xd0000-0xd02ff,0x1e808-0x1e80b irq 25 on simplebus1 Mar 3 09:57:34 router01 kernel: sdhci_xenon1: <Armada Xenon SDHCI controller> mem 0xd8000-0xd82ff,0x17808-0x1780b irq 26 on simplebus1 Mar 3 09:57:34 router01 kernel: mmc0: <MMC/SD bus> on sdhci_xenon1 Mar 3 09:57:34 router01 kernel: ahci0: <AHCI SATA controller> mem 0xe0000-0xe0177 irq 27 on simplebus1 Mar 3 09:57:34 router01 kernel: ahci0: AHCI v1.30 with 1 6Gbps ports, Port Multiplier supported with FBS Mar 3 09:57:34 router01 kernel: ahcich0: <AHCI channel> at channel 0 on ahci0 Mar 3 09:57:34 router01 kernel: device_attach: ahcich0 attach returned 6 Mar 3 09:57:34 router01 kernel: pcib0: <Marvell Armada 3700 PCIe Bus Controller> mem 0xd0070000-0xd008ffff irq 5 on simplebus0 Mar 3 09:57:34 router01 kernel: pcib0: link never came up Mar 3 09:57:34 router01 kernel: pci0: <OFW PCI bus> on pcib0 Mar 3 09:57:34 router01 kernel: gpioled0: <GPIO LEDs> on ofwbus0 Mar 3 09:57:34 router01 kernel: armv8crypto0: <AES-CBC,AES-XTS,AES-GCM> Mar 3 09:57:34 router01 kernel: Timecounters tick every 1.000 msec Mar 3 09:57:34 router01 kernel: mvneta0: link state changed to UP Mar 3 09:57:34 router01 kernel: spibus0: <OFW SPI bus> on spi0 Mar 3 09:57:34 router01 kernel: mx25l0: <M25Pxx Flash Family> at cs 0 mode 0 on spibus0 Mar 3 09:57:34 router01 kernel: mx25l0: device type mx25u3235f, size 4096K in 64 sectors of 64K, erase size 4K Mar 3 09:57:34 router01 kernel: usbus0: 5.0Gbps Super Speed USB v3.0 Mar 3 09:57:34 router01 kernel: usbus1: 480Mbps High Speed USB v2.0 Mar 3 09:57:34 router01 kernel: ugen0.1: <Generic XHCI root HUB> at usbus0 Mar 3 09:57:34 router01 kernel: uhub0 on usbus0 Mar 3 09:57:34 router01 kernel: uhub0: <Generic XHCI root HUB, class 9/0, rev 3.00/1.00, addr 1> on usbus0 Mar 3 09:57:34 router01 kernel: ugen1.1: <Marvell EHCI root HUB> at usbus1 Mar 3 09:57:34 router01 kernel: uhub1 on usbus1 Mar 3 09:57:34 router01 kernel: uhub1: <Marvell EHCI root HUB, class 9/0, rev 2.00/1.00, addr 1> on usbus1 Mar 3 09:57:34 router01 kernel: mmc0: Failed to set VCCQ for card at relative address 2 Mar 3 09:57:34 router01 kernel: mmcsd0: 8GB <MMCHC DG4008 0.1 SN 223D1804 MFG 03/2018 by 69 0x0000> at mmc0 50.0MHz/8bit/65535-block Mar 3 09:57:34 router01 kernel: mmcsd0boot0: 4MB partition 1 at mmcsd0 Mar 3 09:57:34 router01 kernel: mmcsd0boot1: 4MB partition 2 at mmcsd0 Mar 3 09:57:34 router01 kernel: mmcsd0rpmb: 4MB partition 3 at mmcsd0 Mar 3 09:57:34 router01 kernel: CPU 0: ARM Cortex-A53 r0p4 affinity: 0 Mar 3 09:57:34 router01 kernel: Cache Type = <64 byte D-cacheline,64 byte I-cacheline,VIPT ICache,64 byte ERG,64 byte CWG> Mar 3 09:57:34 router01 kernel: Instruction Set Attributes 0 = <CRC32,SHA2,SHA1,AES+PMULL> Mar 3 09:57:34 router01 kernel: Instruction Set Attributes 1 = <> Mar 3 09:57:34 router01 kernel: Instruction Set Attributes 2 = <> Mar 3 09:57:34 router01 kernel: Processor Features 0 = <GIC,AdvSIMD,FP,EL3 32,EL2 32,EL1 32,EL0 32> Mar 3 09:57:34 router01 kernel: Processor Features 1 = <> Mar 3 09:57:34 router01 kernel: Memory Model Features 0 = <TGran4,TGran64,SNSMem,BigEnd,16bit ASID,1TB PA> Mar 3 09:57:34 router01 kernel: Memory Model Features 1 = <8bit VMID> Mar 3 09:57:34 router01 kernel: Memory Model Features 2 = <32bit CCIDX,48bit VA> Mar 3 09:57:34 router01 kernel: Debug Features 0 = <DoubleLock,2 CTX BKPTs,4 Watchpoints,6 Breakpoints,PMUv3,Debugv8> Mar 3 09:57:34 router01 kernel: Debug Features 1 = <> Mar 3 09:57:34 router01 kernel: Auxiliary Features 0 = <> Mar 3 09:57:34 router01 kernel: Auxiliary Features 1 = <> Mar 3 09:57:34 router01 kernel: AArch32 Instruction Set Attributes 5 = <CRC32,SHA2,SHA1,AES+VMULL,SEVL> Mar 3 09:57:34 router01 kernel: AArch32 Media and VFP Features 0 = <FPRound,FPSqrt,FPDivide,DP VFPv3+v4,SP VFPv3+v4,AdvSIMD> Mar 3 09:57:34 router01 kernel: AArch32 Media and VFP Features 1 = <SIMDFMAC,FPHP DP Conv,SIMDHP SP Conv,SIMDSP,SIMDInt,SIMDLS,FPDNaN,FPFtZ> Mar 3 09:57:34 router01 kernel: CPU 1: ARM Cortex-A53 r0p4 affinity: 1 Mar 3 09:57:34 router01 kernel: Release APs...done Mar 3 09:57:34 router01 kernel: TCP_ratelimit: Is now initialized Mar 3 09:57:34 router01 kernel: Trying to mount root from ufs:/dev/diskid/DISK-223D1804s3 [rw,noatime]... Mar 3 09:57:34 router01 kernel: uhub0: 2 ports with 2 removable, self powered Mar 3 09:57:34 router01 kernel: Warning: no time-of-day clock registered, system time will not be set accurately Mar 3 09:57:34 router01 kernel: Dual Console: Serial Primary, Video Secondary Mar 3 09:57:34 router01 kernel: uhub1: 1 port with 1 removable, self powered Mar 3 09:57:34 router01 kernel: e6000sw0port1: link state changed to DOWN Mar 3 09:57:34 router01 kernel: e6000sw0port2: link state changed to DOWN Mar 3 09:57:34 router01 kernel: e6000sw0port3: link state changed to DOWN Mar 3 09:57:34 router01 kernel: ugen1.2: <Tripp Lite ECO850LCD> at usbus1 Mar 3 09:57:34 router01 kernel: uhid0 on uhub1 Mar 3 09:57:34 router01 kernel: uhid0: <Tripp Lite ECO850LCD, class 0/0, rev 2.00/0.02, addr 2> on usbus1 Mar 3 09:57:34 router01 kernel: e6000sw0port3: link state changed to UP Mar 3 09:57:34 router01 kernel: random: unblocking device. Mar 3 09:57:34 router01 kernel: safexcel0: <SafeXcel EIP-97 crypto accelerator> mem 0x90000-0xaffff irq 18,19,20,21,22,23 on simplebus1 Mar 3 09:57:34 router01 kernel: lo0: link state changed to UP Mar 3 09:57:34 router01 kernel: e6000sw0port3: link state changed to DOWN Mar 3 09:57:34 router01 kernel: vlan0: changing name to 'mvneta0.4090' Mar 3 09:57:37 router01 kernel: e6000sw0port1: link state changed to UP Mar 3 09:57:37 router01 kernel: e6000sw0port3: link state changed to UP Mar 3 09:57:42 router01 kernel: vlan1: changing name to 'mvneta0.4091' Mar 3 09:57:42 router01 kernel: vlan2: changing name to 'mvneta0.4092' Mar 3 09:57:42 router01 kernel: vlan3: changing name to 'mvneta0.30' Mar 3 09:57:43 router01 kernel: vlan4: changing name to 'mvneta0.40' Mar 3 09:57:43 router01 kernel: [fib_algo] inet.0 (bsearch4#27) rebuild_fd_flm: switching algo to radix4_lockless Mar 3 09:57:43 router01 kernel: vlan5: changing name to 'mvneta0.50' Mar 3 09:57:44 router01 kernel: done. Mar 3 09:57:44 router01 kernel: done. Mar 3 09:57:45 router01 kernel: done. Mar 3 09:57:45 router01 kernel: done. Mar 3 09:57:45 router01 kernel: pflog0: promiscuous mode enabled Mar 3 09:57:48 router01 kernel: . Mar 3 09:57:48 router01 kernel: done. Mar 3 09:57:48 router01 kernel: done. Mar 3 09:57:49 router01 kernel: done. Mar 3 09:57:51 router01 kernel: done. Mar 3 09:57:52 router01 kernel: done. Mar 3 09:58:33 router01 kernel: done. Mar 3 09:58:33 router01 kernel: done. Mar 3 09:58:34 router01 kernel: done. Mar 3 09:58:35 router01 kernel: done. Mar 3 09:58:36 router01 kernel: .... Mar 3 09:58:39 router01 kernel: . Mar 3 09:58:39 router01 kernel: done. Mar 3 09:58:44 router01 kernel: done. Mar 3 09:58:46 router01 kernel: done. Mar 3 09:58:46 router01 kernel: done. Mar 3 09:58:50 router01 usbhid-ups[79600]: using 'battery.charge' to set battery low state Mar 3 09:58:50 router01 kernel: uhid0: at uhub1, port 1, addr 2 (disconnected) Mar 3 09:58:50 router01 kernel: uhid0: detached Mar 3 09:58:50 router01 usbhid-ups[79600]: using 'battery.runtime' to set battery low state Mar 3 09:58:50 router01 usbhid-ups[80230]: Startup successful Mar 3 09:58:54 router01 usbhid-ups[86506]: using 'battery.charge' to set battery low state Mar 3 09:58:54 router01 usbhid-ups[86506]: using 'battery.runtime' to set battery low state Mar 3 09:58:54 router01 usbhid-ups[92987]: Startup successful
When the UPS stops, have you tried restarting the UPS service?
Yes, restarting the service alone is unsuccessful. I stop the service, disconnect/reconnect the UPS USB, restart the service - that procedure is successful.
Lastly, can you please post anything you have in the "Extra Arguments to driver" and "Additional configuration lines for ups.conf" sections?
Only using "Extra Arguments to driver":
ignorelb override.battery.charge.low = 20 override.battery.runtime.low = 61
-
@dennypage said in NUT Package (2.8.1 and above):
@ghound If I understood you correctly, you had previously said that you had to physically disconnect the USB cable after the UPS disappeared. However the usbconfig output you posted shows that the UPS is still connected. Also, there are not kernel USB messages. Can you clarify please?
When the UPS stops, have you tried restarting the UPS service?
Lastly, can you please post anything you have in the "Extra Arguments to driver" and "Additional configuration lines for ups.conf" sections?
This is a clean log of being in the failed condition, trying service restart - still in failed condition, stop-nut/disconnect/reconnect/start-nut - connection restored sequence:
~ ~ ~ Nut Service Restart ~ ~ ~ Mar 5 15:06:16 router01 upsmon[54708]: Poll UPS [TrippLite] failed - Driver not connected Mar 5 15:06:19 router01 upsmon[54708]: Signal 15: exiting Mar 5 15:06:19 router01 upsd[53855]: User local-monitor@::1 logged out from UPS [TrippLite] Mar 5 15:06:19 router01 upsd[53855]: mainloop: Interrupted system call Mar 5 15:06:19 router01 upsd[53855]: Signal 15: exiting Mar 5 15:06:19 router01 upsd[54022]: listening on 127.0.0.1 port 3493 Mar 5 15:06:19 router01 upsd[54022]: listening on ::1 port 3493 Mar 5 15:06:19 router01 upsd[54022]: Can't connect to UPS [TrippLite] (usbhid-ups-TrippLite): No such file or directory Mar 5 15:06:19 router01 upsd[54022]: Found 1 UPS defined in ups.conf Mar 5 15:06:19 router01 upsd[54239]: Startup successful Mar 5 15:06:20 router01 upsmon[54725]: Startup successful Mar 5 15:06:20 router01 upsd[54239]: User local-monitor@::1 logged into UPS [TrippLite] Mar 5 15:06:20 router01 upsmon[55048]: Poll UPS [TrippLite] failed - Driver not connected Mar 5 15:06:20 router01 upsmon[55048]: Communications with UPS TrippLite lost Mar 5 15:06:25 router01 upsmon[55048]: Poll UPS [TrippLite] failed - Driver not connected Mar 5 15:06:25 router01 upsmon[55048]: UPS TrippLite is unavailable Mar 5 15:06:30 router01 upsmon[55048]: Poll UPS [TrippLite] failed - Driver not connected Mar 5 15:08:05 router01 upsmon[55048]: Poll UPS [TrippLite] failed - Driver not connected ~ ~ ~ Nut Service Stoped / USB disconnect-reconnect/Nut Service Started ~ ~ ~ Mar 5 15:08:08 router01 upsmon[55048]: Signal 15: exiting Mar 5 15:08:08 router01 upsd[54239]: User local-monitor@::1 logged out from UPS [TrippLite] Mar 5 15:08:08 router01 upsd[54239]: mainloop: Interrupted system call Mar 5 15:08:08 router01 upsd[54239]: Signal 15: exiting Mar 5 15:08:30 router01 kernel: ugen1.2: <Tripp Lite ECO850LCD> at usbus1 (disconnected) Mar 5 15:08:44 router01 kernel: ugen1.2: <Tripp Lite ECO850LCD> at usbus1 Mar 5 15:08:44 router01 kernel: uhid0 on uhub1 Mar 5 15:08:44 router01 kernel: uhid0: <Tripp Lite ECO850LCD, class 0/0, rev 2.00/0.02, addr 2> on usbus1 Mar 5 15:09:04 router01 upsd[98800]: listening on 127.0.0.1 port 3493 Mar 5 15:09:04 router01 upsd[98800]: listening on ::1 port 3493 Mar 5 15:09:04 router01 upsd[98800]: Can't connect to UPS [TrippLite] (usbhid-ups-TrippLite): No such file or directory Mar 5 15:09:04 router01 upsd[98800]: Found 1 UPS defined in ups.conf Mar 5 15:09:04 router01 upsd[643]: Startup successful Mar 5 15:09:05 router01 usbhid-ups[99491]: using 'battery.charge' to set battery low state Mar 5 15:09:05 router01 kernel: uhid0: at uhub1, port 1, addr 2 (disconnected) Mar 5 15:09:05 router01 kernel: uhid0: detached Mar 5 15:09:05 router01 usbhid-ups[99491]: using 'battery.runtime' to set battery low state Mar 5 15:09:05 router01 usbhid-ups[962]: Startup successful Mar 5 15:09:05 router01 upsmon[2297]: Startup successful Mar 5 15:09:05 router01 upsd[643]: Connected to UPS [TrippLite]: usbhid-ups-TrippLite Mar 5 15:09:05 router01 upsd[643]: User local-monitor@::1 logged into UPS [TrippLite]
-
@ghound I don't see any error entries from usbhid-ups suggesting a reason for exit.
Can you run the driver by hand in debug mode via ssh please?
First start the service, and then kill the driver:
killall usbhid-ups
Then, run the driver with debug:
/usr/local/libexec/nut/usbhid-ups -DDDDDD -a TrippLite
And post the output. This may be lengthy, so it's okay to eliminate duplicated line in the middle.
-
@dennypage said in NUT Package (2.8.1 and above):
Can you run the driver by hand in debug mode via ssh please?
First start the service, and then kill the driver:
killall usbhid-ups
Then, run the driver with debug:/usr/local/libexec/nut/usbhid-ups -DDDDDD -a TrippLite
And post the output. This may be lengthy, so it's okay to eliminate duplicated line in the middle.I have the driver running by hand as requested. Output is to the console, should I redirect it to a file or will I be able to capture what you are looking for from console scrollback? Here is one frame of output while the driver seems to be running successfully.
524.757599 [D5] send_to_all: SETINFO driver.state "updateinfo" 524.757772 [D6] send_to_all: write 34 bytes to socket 9 succeeded (ret=34): SETINFO driver.state "updateinfo" 524.757789 [D1] upsdrv_updateinfo... 524.782403 [D2] file_report_buffer: expected 4 bytes, but got 512 instead 524.782484 [D3] Report[err]: (512 bytes) => 32 00 00 09 00 00 00 00 f0 9f 6a 80 00 00 00 00 524.782515 [D3] 00 00 00 00 00 00 00 00 98 ea f4 45 48 49 3a c1 80 a0 6a 80 ff ff ff ff 40 524.782544 [D3] 9e 6a 80 00 00 00 00 14 b1 b6 83 00 00 00 00 26 06 ee 65 00 00 00 00 00 50 524.782574 [D3] 27 00 00 00 00 00 00 00 00 00 00 00 00 00 00 60 27 00 00 00 00 00 02 00 00 524.782603 [D3] 00 00 00 00 00 00 60 27 00 00 00 00 00 41 3c 21 00 00 00 00 00 5c 8d 20 00 524.782632 [D3] 00 00 00 00 78 9f 6a 80 00 00 00 00 00 02 00 00 00 00 00 00 f0 a1 6a 80 00 524.782661 [D3] 00 00 00 30 9f 6a 80 00 00 00 00 f0 9e 6a 80 00 00 00 00 d8 ff ff ff 80 ff 524.782689 [D3] ff ff 3f 9f 6a 80 00 00 00 00 b8 c3 c2 83 00 00 00 00 9a 9f 6a 80 00 00 00 524.782719 [D3] 00 00 00 00 00 dd 01 00 00 08 02 ff ff 00 00 00 00 78 9f 6a 80 00 00 00 00 524.782748 [D3] ff 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 524.782777 [D3] 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 524.782806 [D3] 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 524.782835 [D3] 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 524.782863 [D3] 4d 19 bd 83 98 ea f4 45 48 49 3a c1 00 9e 6a 80 00 00 00 00 cc 63 b7 83 00 524.782893 [D3] 00 00 00 00 00 00 00 00 00 00 00 00 60 27 00 00 00 00 00 02 00 00 00 00 00 524.782922 [D3] 00 00 00 70 27 00 00 00 00 00 41 3c 21 00 00 00 00 00 0d 00 00 00 00 00 00 524.782951 [D3] 00 0d 00 00 00 00 00 00 00 68 9e 6a 80 00 00 00 00 26 06 ee 65 00 00 00 00 524.782979 [D3] 2d ee 9c 21 5f d5 5e 68 00 00 00 00 00 00 00 00 98 ea f4 45 48 49 3a c1 30 524.783008 [D3] 9e 6a 80 00 00 00 00 9c 5f b7 83 00 00 00 00 0d 00 00 00 00 00 00 00 00 00 524.783037 [D3] 00 00 00 00 00 00 68 9e 6a 80 00 00 00 00 a0 9e 6a 80 00 00 00 00 80 9e 6a 524.783063 [D3] 80 00 00 00 00 8c 61 b0 83 00 00 00 00 5c 8d 20 00 00 00 00 00 524.783737 [D1] Got 9 HID objects... 524.783796 [D3] Report[buf]: (4 bytes) => 32 00 00 09 524.783812 [D5] PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0 524.783826 [D5] Unit = 00000000, UnitExp = 0 524.783838 [D5] Exponent = 0 524.783854 [D5] hid_lookup_path: 00840004 -> UPS 524.783870 [D5] hid_lookup_path: 00840024 -> PowerSummary 524.783884 [D5] hid_lookup_path: 00840002 -> PresentStatus 524.783898 [D5] hid_lookup_path: 00840062 -> InternalFailure 524.783915 [D2] Path: UPS.PowerSummary.PresentStatus.InternalFailure, Type: Input, ReportID: 0x32, Offset: 7, Size: 1, Value: 0 524.784119 [D5] hu_find_infoval: found !commfault (value: 0) 524.784149 [D5] process_boolean_info: !commfault 524.784179 [D3] Report[buf]: (4 bytes) => 32 00 00 09 524.784195 [D5] PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0 524.784207 [D5] Unit = 00000000, UnitExp = 0 524.784219 [D5] Exponent = 0 524.784233 [D5] hid_lookup_path: 00840004 -> UPS 524.784247 [D5] hid_lookup_path: 00840024 -> PowerSummary 524.784261 [D5] hid_lookup_path: 00840002 -> PresentStatus 524.784275 [D5] hid_lookup_path: 00840069 -> ShutdownImminent 524.784291 [D2] Path: UPS.PowerSummary.PresentStatus.ShutdownImminent, Type: Input, ReportID: 0x32, Offset: 9, Size: 1, Value: 0 524.784307 [D5] hu_find_infoval: found !shutdownimm (value: 0) 524.784336 [D5] process_boolean_info: !shutdownimm 524.784357 [D3] Report[buf]: (4 bytes) => 32 00 00 09 524.784371 [D5] PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0 524.784383 [D5] Unit = 00000000, UnitExp = 0 524.784394 [D5] Exponent = 0 524.784407 [D5] hid_lookup_path: 00840004 -> UPS 524.784421 [D5] hid_lookup_path: 00840024 -> PowerSummary 524.784434 [D5] hid_lookup_path: 00840002 -> PresentStatus 524.784449 [D5] hid_lookup_path: 008500d0 -> ACPresent 524.784465 [D2] Path: UPS.PowerSummary.PresentStatus.ACPresent, Type: Input, ReportID: 0x32, Offset: 16, Size: 1, Value: 1 524.785177 [D5] hu_find_infoval: found online (value: 1) 524.785224 [D5] process_boolean_info: online 524.785252 [D3] Report[buf]: (4 bytes) => 32 00 00 09 524.785268 [D5] PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0 524.785282 [D5] Unit = 00000000, UnitExp = 0 524.785294 [D5] Exponent = 0 524.785309 [D5] hid_lookup_path: 00840004 -> UPS 524.785335 [D5] hid_lookup_path: 00840024 -> PowerSummary 524.785350 [D5] hid_lookup_path: 00840002 -> PresentStatus 524.785365 [D5] hid_lookup_path: 00850042 -> BelowRemainingCapacityLimit 524.785381 [D2] Path: UPS.PowerSummary.PresentStatus.BelowRemainingCapacityLimit, Type: Input, ReportID: 0x32, Offset: 18, Size: 1, Value: 0 524.785399 [D5] hu_find_infoval: found !lowbatt (value: 0) 524.785412 [D5] process_boolean_info: !lowbatt 524.785433 [D3] Report[buf]: (4 bytes) => 32 00 00 09 524.785446 [D5] PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0 524.785459 [D5] Unit = 00000000, UnitExp = 0 524.785470 [D5] Exponent = 0 524.785482 [D5] hid_lookup_path: 00840004 -> UPS 524.785496 [D5] hid_lookup_path: 00840024 -> PowerSummary 524.785509 [D5] hid_lookup_path: 00840002 -> PresentStatus 524.785524 [D5] hid_lookup_path: 00850046 -> FullyCharged 524.785539 [D2] Path: UPS.PowerSummary.PresentStatus.FullyCharged, Type: Input, ReportID: 0x32, Offset: 19, Size: 1, Value: 1 524.785556 [D5] hu_find_infoval: found fullycharged (value: 1) 524.785568 [D5] process_boolean_info: fullycharged 524.785591 [D3] Report[buf]: (4 bytes) => 32 00 00 09 524.785604 [D5] PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0 524.785616 [D5] Unit = 00000000, UnitExp = 0 524.785627 [D5] Exponent = 0 524.785640 [D5] hid_lookup_path: 00840004 -> UPS 524.785653 [D5] hid_lookup_path: 00840024 -> PowerSummary 524.785666 [D5] hid_lookup_path: 00840002 -> PresentStatus 524.785681 [D5] hid_lookup_path: 00850044 -> Charging 524.785695 [D2] Path: UPS.PowerSummary.PresentStatus.Charging, Type: Input, ReportID: 0x32, Offset: 20, Size: 1, Value: 0 524.785711 [D5] hu_find_infoval: found !chrg (value: 0) 524.785723 [D5] process_boolean_info: !chrg 524.785740 [D3] Report[buf]: (4 bytes) => 32 00 00 09 524.785754 [D5] PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0 524.785766 [D5] Unit = 00000000, UnitExp = 0 524.785777 [D5] Exponent = 0 524.785789 [D5] hid_lookup_path: 00840004 -> UPS 524.785802 [D5] hid_lookup_path: 00840024 -> PowerSummary 524.785816 [D5] hid_lookup_path: 00840002 -> PresentStatus 524.785830 [D5] hid_lookup_path: 00850045 -> Discharging 524.785845 [D2] Path: UPS.PowerSummary.PresentStatus.Discharging, Type: Input, ReportID: 0x32, Offset: 21, Size: 1, Value: 0 524.785861 [D5] hu_find_infoval: found !dischrg (value: 0) 524.785872 [D5] process_boolean_info: !dischrg 524.785891 [D3] Report[buf]: (4 bytes) => 32 00 00 09 524.785904 [D5] PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0 524.785916 [D5] Unit = 00000000, UnitExp = 0 524.785928 [D5] Exponent = 0 524.785940 [D5] hid_lookup_path: 00840004 -> UPS 524.785953 [D5] hid_lookup_path: 00840024 -> PowerSummary 524.785967 [D5] hid_lookup_path: 00840002 -> PresentStatus 524.785981 [D5] hid_lookup_path: 00850047 -> FullyDischarged 524.785996 [D2] Path: UPS.PowerSummary.PresentStatus.FullyDischarged, Type: Input, ReportID: 0x32, Offset: 22, Size: 1, Value: 0 524.786011 [D5] hu_find_infoval: found !depleted (value: 0) 524.786023 [D5] process_boolean_info: !depleted 524.786044 [D3] Report[buf]: (4 bytes) => 32 00 00 09 524.786058 [D5] PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0 524.786070 [D5] Unit = 00000000, UnitExp = 0 524.786082 [D5] Exponent = 0 524.786094 [D5] hid_lookup_path: 00840004 -> UPS 524.786107 [D5] hid_lookup_path: 00840024 -> PowerSummary 524.786120 [D5] hid_lookup_path: 00840002 -> PresentStatus 524.786134 [D5] hid_lookup_path: 0085004b -> NeedReplacement 524.786149 [D2] Path: UPS.PowerSummary.PresentStatus.NeedReplacement, Type: Input, ReportID: 0x32, Offset: 23, Size: 1, Value: 0 524.786165 [D5] hu_find_infoval: found !replacebatt (value: 0) 524.786176 [D5] process_boolean_info: !replacebatt 524.786195 [D1] Quick update... 524.786210 [D4] Entering libusb_get_report 524.787372 [D3] Report[get]: (3 bytes) => 61 ff ff 524.787461 [D5] PhyMax = 0, PhyMin = 0, LogMax = 65535, LogMin = 0 524.787478 [D5] Unit = 00001001, UnitExp = 0 524.787491 [D5] Exponent = 0 524.787508 [D2] Path: UPS.OutletSystem.Outlet.DelayBeforeStartup, Type: Feature, ReportID: 0x61, Offset: 0, Size: 16, Value: 65535 524.787540 [D4] Entering libusb_get_report 524.788372 [D3] Report[get]: (3 bytes) => 15 ff ff 524.788461 [D5] PhyMax = 0, PhyMin = 0, LogMax = 65535, LogMin = 0 524.788485 [D5] Unit = 00001001, UnitExp = 0 524.788507 [D5] Exponent = 0 524.788537 [D2] Path: UPS.OutletSystem.Outlet.DelayBeforeShutdown, Type: Feature, ReportID: 0x15, Offset: 0, Size: 16, Value: 65535 524.788580 [D4] Entering libusb_get_report 524.789535 [D3] Report[get]: (3 bytes) => 17 ff ff 524.789623 [D5] PhyMax = 0, PhyMin = 0, LogMax = 65535, LogMin = 0 524.789639 [D5] Unit = 00001001, UnitExp = 0 524.789651 [D5] Exponent = 0 524.789669 [D2] Path: UPS.OutletSystem.Outlet.DelayBeforeReboot, Type: Feature, ReportID: 0x17, Offset: 0, Size: 16, Value: 65535 524.789869 [D3] Report[buf]: (4 bytes) => 32 00 00 09 524.789896 [D5] PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0 524.789910 [D5] Unit = 00000000, UnitExp = 0 524.789922 [D5] Exponent = 0 524.789938 [D2] Path: UPS.PowerSummary.PresentStatus.ACPresent, Type: Feature, ReportID: 0x32, Offset: 16, Size: 1, Value: 1 524.789952 [D5] hu_find_infoval: found online (value: 1) 524.789965 [D5] process_boolean_info: online 524.789984 [D3] Report[buf]: (4 bytes) => 32 00 00 09 524.789998 [D5] PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0 524.790010 [D5] Unit = 00000000, UnitExp = 0 524.790021 [D5] Exponent = 0 524.790036 [D2] Path: UPS.PowerSummary.PresentStatus.BelowRemainingCapacityLimit, Type: Feature, ReportID: 0x32, Offset: 18, Size: 1, Value: 0 524.790049 [D5] hu_find_infoval: found !lowbatt (value: 0) 524.790061 [D5] process_boolean_info: !lowbatt 524.790079 [D3] Report[buf]: (4 bytes) => 32 00 00 09 524.790092 [D5] PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0 524.790104 [D5] Unit = 00000000, UnitExp = 0 524.790115 [D5] Exponent = 0 524.790130 [D2] Path: UPS.PowerSummary.PresentStatus.FullyCharged, Type: Feature, ReportID: 0x32, Offset: 19, Size: 1, Value: 1 524.790142 [D5] hu_find_infoval: found fullycharged (value: 1) 524.790154 [D5] process_boolean_info: fullycharged 524.790175 [D3] Report[buf]: (4 bytes) => 32 00 00 09 524.790189 [D5] PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0 524.790201 [D5] Unit = 00000000, UnitExp = 0 524.790212 [D5] Exponent = 0 524.790226 [D2] Path: UPS.PowerSummary.PresentStatus.Charging, Type: Feature, ReportID: 0x32, Offset: 20, Size: 1, Value: 0 524.790832 [D5] hu_find_infoval: found !chrg (value: 0) 524.790875 [D5] process_boolean_info: !chrg 524.790903 [D3] Report[buf]: (4 bytes) => 32 00 00 09 524.790919 [D5] PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0 524.790932 [D5] Unit = 00000000, UnitExp = 0 524.790945 [D5] Exponent = 0 524.790960 [D2] Path: UPS.PowerSummary.PresentStatus.Discharging, Type: Feature, ReportID: 0x32, Offset: 21, Size: 1, Value: 0 524.790973 [D5] hu_find_infoval: found !dischrg (value: 0) 524.790984 [D5] process_boolean_info: !dischrg 524.791002 [D3] Report[buf]: (4 bytes) => 32 00 00 09 524.791015 [D5] PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0 524.791027 [D5] Unit = 00000000, UnitExp = 0 524.791038 [D5] Exponent = 0 524.791053 [D2] Path: UPS.PowerSummary.PresentStatus.FullyDischarged, Type: Feature, ReportID: 0x32, Offset: 22, Size: 1, Value: 0 524.791066 [D5] hu_find_infoval: found !depleted (value: 0) 524.791077 [D5] process_boolean_info: !depleted 524.791151 [D5] send_to_all: SETINFO driver.state "quiet" 524.791401 [D6] send_to_all: write 29 bytes to socket 9 succeeded (ret=29): SETINFO driver.state "quiet"
-
@ghound said in NUT Package (2.8.1 and above):
Output is to the console, should I redirect it to a file or will I be able to capture what you are looking for from console scrollback?
I expect that you will want to direct it to a file so you don't loose it due to scrolling or other issues.
-
@dennypage said in NUT Package (2.8.1 and above):
Can you run the driver by hand in debug mode via ssh please?
First start the service, and then kill the driver:
killall usbhid-ups
Then, run the driver with debug:/usr/local/libexec/nut/usbhid-ups -DDDDDD -a TrippLite
This is the result around the point when connection to the UPS was lost (around one day after the process was started):
72245.572443 [D1] upsdrv_updateinfo... 72245.599003 [D2] file_report_buffer: expected 4 bytes, but got 512 instead 72245.599080 [D3] Report[err]: (512 bytes) => 32 00 00 09 00 00 00 00 f0 9f 6a 80 00 00 00 00 72245.599112 [D3] 00 00 00 00 00 00 00 00 98 ea f4 45 48 49 3a c1 80 a0 6a 80 ff ff ff ff 40 72245.599141 [D3] 9e 6a 80 00 00 00 00 14 b1 b6 83 00 00 00 00 4f 1e ef 65 00 00 00 00 00 50 72245.599171 [D3] 27 00 00 00 00 00 00 00 00 00 00 00 00 00 00 60 27 00 00 00 00 00 02 00 00 72245.599201 [D3] 00 00 00 00 00 00 60 27 00 00 00 00 00 41 3c 21 00 00 00 00 00 5c 8d 20 00 72245.599230 [D3] 00 00 00 00 78 9f 6a 80 00 00 00 00 00 02 00 00 00 00 00 00 f0 a1 6a 80 00 72245.599259 [D3] 00 00 00 30 9f 6a 80 00 00 00 00 f0 9e 6a 80 00 00 00 00 d8 ff ff ff 80 ff 72245.599288 [D3] ff ff 3f 9f 6a 80 00 00 00 00 b8 c3 c2 83 00 00 00 00 9a 9f 6a 80 00 00 00 72245.599317 [D3] 00 00 00 00 00 dd 01 00 00 08 02 ff ff 00 00 00 00 78 9f 6a 80 00 00 00 00 72245.599346 [D3] ff 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 72245.599414 [D3] 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 72245.599446 [D3] 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 72245.599476 [D3] 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 72245.599504 [D3] 52 25 8a 3f 98 ea f4 45 48 49 3a c1 00 9e 6a 80 00 00 00 00 cc 63 b7 83 00 72245.599533 [D3] 00 00 00 00 00 00 00 00 00 00 00 00 60 27 00 00 00 00 00 02 00 00 00 00 00 72245.599562 [D3] 00 00 00 70 27 00 00 00 00 00 41 3c 21 00 00 00 00 00 0d 00 00 00 00 00 00 72245.599591 [D3] 00 0d 00 00 00 00 00 00 00 68 9e 6a 80 00 00 00 00 4f 1e ef 65 00 00 00 00 72245.599620 [D3] f9 65 6b 7b 2f e6 eb 38 00 00 00 00 00 00 00 00 98 ea f4 45 48 49 3a c1 30 72245.599649 [D3] 9e 6a 80 00 00 00 00 9c 5f b7 83 00 00 00 00 0d 00 00 00 00 00 00 00 00 00 72245.599678 [D3] 00 00 00 00 00 00 68 9e 6a 80 00 00 00 00 a0 9e 6a 80 00 00 00 00 80 9e 6a 72245.599704 [D3] 80 00 00 00 00 8c 61 b0 83 00 00 00 00 5c 8d 20 00 00 00 00 00 72245.599732 [D1] Got 9 HID objects... 72245.599752 [D3] Report[buf]: (4 bytes) => 32 00 00 09 72245.599768 [D5] PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0 72245.599781 [D5] Unit = 00000000, UnitExp = 0 72245.599793 [D5] Exponent = 0 72245.599808 [D5] hid_lookup_path: 00840004 -> UPS 72245.599823 [D5] hid_lookup_path: 00840024 -> PowerSummary 72245.599837 [D5] hid_lookup_path: 00840002 -> PresentStatus 72245.599850 [D5] hid_lookup_path: 00840062 -> InternalFailure 72245.599866 [D2] Path: UPS.PowerSummary.PresentStatus.InternalFailure, Type: Input, ReportID: 0x32, Offset: 7, Size: 1, Value: 0 72245.599884 [D5] hu_find_infoval: found !commfault (value: 0) 72245.599897 [D5] process_boolean_info: !commfault 72245.599924 [D3] Report[buf]: (4 bytes) => 32 00 00 09 72245.599938 [D5] PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0 72245.599950 [D5] Unit = 00000000, UnitExp = 0 72245.599961 [D5] Exponent = 0 72245.599973 [D5] hid_lookup_path: 00840004 -> UPS 72245.599986 [D5] hid_lookup_path: 00840024 -> PowerSummary 72245.600000 [D5] hid_lookup_path: 00840002 -> PresentStatus 72245.600013 [D5] hid_lookup_path: 00840069 -> ShutdownImminent 72245.600028 [D2] Path: UPS.PowerSummary.PresentStatus.ShutdownImminent, Type: Input, ReportID: 0x32, Offset: 9, Size: 1, Value: 0 72245.600044 [D5] hu_find_infoval: found !shutdownimm (value: 0) 72245.600056 [D5] process_boolean_info: !shutdownimm 72245.600076 [D3] Report[buf]: (4 bytes) => 32 00 00 09 72245.600089 [D5] PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0 72245.600101 [D5] Unit = 00000000, UnitExp = 0 72245.600112 [D5] Exponent = 0 72245.600124 [D5] hid_lookup_path: 00840004 -> UPS 72245.600138 [D5] hid_lookup_path: 00840024 -> PowerSummary 72245.600151 [D5] hid_lookup_path: 00840002 -> PresentStatus 72245.600167 [D5] hid_lookup_path: 008500d0 -> ACPresent 72245.600183 [D2] Path: UPS.PowerSummary.PresentStatus.ACPresent, Type: Input, ReportID: 0x32, Offset: 16, Size: 1, Value: 1 72245.600197 [D5] hu_find_infoval: found online (value: 1) 72245.600209 [D5] process_boolean_info: online 72245.600227 [D3] Report[buf]: (4 bytes) => 32 00 00 09 72245.600240 [D5] PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0 72245.600252 [D5] Unit = 00000000, UnitExp = 0 72245.600263 [D5] Exponent = 0 72245.600275 [D5] hid_lookup_path: 00840004 -> UPS 72245.600288 [D5] hid_lookup_path: 00840024 -> PowerSummary 72245.600301 [D5] hid_lookup_path: 00840002 -> PresentStatus 72245.600315 [D5] hid_lookup_path: 00850042 -> BelowRemainingCapacityLimit 72245.600330 [D2] Path: UPS.PowerSummary.PresentStatus.BelowRemainingCapacityLimit, Type: Input, ReportID: 0x32, Offset: 18, Size: 1, Value: 0 72245.600345 [D5] hu_find_infoval: found !lowbatt (value: 0) 72245.600356 [D5] process_boolean_info: !lowbatt 72245.600374 [D3] Report[buf]: (4 bytes) => 32 00 00 09 72245.600394 [D5] PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0 72245.600407 [D5] Unit = 00000000, UnitExp = 0 72245.600418 [D5] Exponent = 0 72245.600430 [D5] hid_lookup_path: 00840004 -> UPS 72245.600444 [D5] hid_lookup_path: 00840024 -> PowerSummary 72245.600457 [D5] hid_lookup_path: 00840002 -> PresentStatus 72245.600470 [D5] hid_lookup_path: 00850046 -> FullyCharged 72245.600486 [D2] Path: UPS.PowerSummary.PresentStatus.FullyCharged, Type: Input, ReportID: 0x32, Offset: 19, Size: 1, Value: 1 72245.600501 [D5] hu_find_infoval: found fullycharged (value: 1) 72245.600513 [D5] process_boolean_info: fullycharged 72245.600535 [D3] Report[buf]: (4 bytes) => 32 00 00 09 72245.600548 [D5] PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0 72245.600560 [D5] Unit = 00000000, UnitExp = 0 72245.600571 [D5] Exponent = 0 72245.600583 [D5] hid_lookup_path: 00840004 -> UPS 72245.600596 [D5] hid_lookup_path: 00840024 -> PowerSummary 72245.600609 [D5] hid_lookup_path: 00840002 -> PresentStatus 72245.600623 [D5] hid_lookup_path: 00850044 -> Charging 72245.600637 [D2] Path: UPS.PowerSummary.PresentStatus.Charging, Type: Input, ReportID: 0x32, Offset: 20, Size: 1, Value: 0 72245.600652 [D5] hu_find_infoval: found !chrg (value: 0) 72245.600664 [D5] process_boolean_info: !chrg 72245.600682 [D3] Report[buf]: (4 bytes) => 32 00 00 09 72245.600695 [D5] PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0 72245.600707 [D5] Unit = 00000000, UnitExp = 0 72245.600718 [D5] Exponent = 0 72245.600730 [D5] hid_lookup_path: 00840004 -> UPS 72245.600744 [D5] hid_lookup_path: 00840024 -> PowerSummary 72245.600757 [D5] hid_lookup_path: 00840002 -> PresentStatus 72245.600770 [D5] hid_lookup_path: 00850045 -> Discharging 72245.600785 [D2] Path: UPS.PowerSummary.PresentStatus.Discharging, Type: Input, ReportID: 0x32, Offset: 21, Size: 1, Value: 0 72245.600800 [D5] hu_find_infoval: found !dischrg (value: 0) 72245.600811 [D5] process_boolean_info: !dischrg 72245.600829 [D3] Report[buf]: (4 bytes) => 32 00 00 09 72245.600842 [D5] PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0 72245.600854 [D5] Unit = 00000000, UnitExp = 0 72245.600865 [D5] Exponent = 0 72245.600877 [D5] hid_lookup_path: 00840004 -> UPS 72245.600890 [D5] hid_lookup_path: 00840024 -> PowerSummary 72245.600903 [D5] hid_lookup_path: 00840002 -> PresentStatus 72245.600917 [D5] hid_lookup_path: 00850047 -> FullyDischarged 72245.600931 [D2] Path: UPS.PowerSummary.PresentStatus.FullyDischarged, Type: Input, ReportID: 0x32, Offset: 22, Size: 1, Value: 0 72245.600946 [D5] hu_find_infoval: found !depleted (value: 0) 72245.600958 [D5] process_boolean_info: !depleted 72245.600979 [D3] Report[buf]: (4 bytes) => 32 00 00 09 72245.600993 [D5] PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0 72245.601005 [D5] Unit = 00000000, UnitExp = 0 72245.601017 [D5] Exponent = 0 72245.601029 [D5] hid_lookup_path: 00840004 -> UPS 72245.601042 [D5] hid_lookup_path: 00840024 -> PowerSummary 72245.601055 [D5] hid_lookup_path: 00840002 -> PresentStatus 72245.601069 [D5] hid_lookup_path: 0085004b -> NeedReplacement 72245.601084 [D2] Path: UPS.PowerSummary.PresentStatus.NeedReplacement, Type: Input, ReportID: 0x32, Offset: 23, Size: 1, Value: 0 72245.601099 [D5] hu_find_infoval: found !replacebatt (value: 0) 72245.601111 [D5] process_boolean_info: !replacebatt 72245.601129 [D1] Quick update... 72245.601144 [D4] Entering libusb_get_report 72245.601911 [D3] Report[get]: (3 bytes) => 61 ff ff 72245.601975 [D5] PhyMax = 0, PhyMin = 0, LogMax = 65535, LogMin = 0 72245.601991 [D5] Unit = 00001001, UnitExp = 0 72245.602004 [D5] Exponent = 0 72245.602021 [D2] Path: UPS.OutletSystem.Outlet.DelayBeforeStartup, Type: Feature, ReportID: 0x61, Offset: 0, Size: 16, Value: 65535 72245.602051 [D4] Entering libusb_get_report 72245.602892 [D3] Report[get]: (3 bytes) => 15 ff ff 72245.602944 [D5] PhyMax = 0, PhyMin = 0, LogMax = 65535, LogMin = 0 72245.602958 [D5] Unit = 00001001, UnitExp = 0 72245.602972 [D5] Exponent = 0 72245.602988 [D2] Path: UPS.OutletSystem.Outlet.DelayBeforeShutdown, Type: Feature, ReportID: 0x15, Offset: 0, Size: 16, Value: 65535 72245.603016 [D4] Entering libusb_get_report 72245.603890 [D3] Report[get]: (3 bytes) => 17 ff ff 72245.603934 [D5] PhyMax = 0, PhyMin = 0, LogMax = 65535, LogMin = 0 72245.603948 [D5] Unit = 00001001, UnitExp = 0 72245.603961 [D5] Exponent = 0 72245.603978 [D2] Path: UPS.OutletSystem.Outlet.DelayBeforeReboot, Type: Feature, ReportID: 0x17, Offset: 0, Size: 16, Value: 65535 72245.604013 [D3] Report[buf]: (4 bytes) => 32 00 00 09 72245.604027 [D5] PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0 72245.604040 [D5] Unit = 00000000, UnitExp = 0 72245.604051 [D5] Exponent = 0 72245.604067 [D2] Path: UPS.PowerSummary.PresentStatus.ACPresent, Type: Feature, ReportID: 0x32, Offset: 16, Size: 1, Value: 1 72245.604080 [D5] hu_find_infoval: found online (value: 1) 72245.604092 [D5] process_boolean_info: online 72245.604111 [D3] Report[buf]: (4 bytes) => 32 00 00 09 72245.604124 [D5] PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0 72245.604136 [D5] Unit = 00000000, UnitExp = 0 72245.604148 [D5] Exponent = 0 72245.604162 [D2] Path: UPS.PowerSummary.PresentStatus.BelowRemainingCapacityLimit, Type: Feature, ReportID: 0x32, Offset: 18, Size: 1, Value: 0 72245.604175 [D5] hu_find_infoval: found !lowbatt (value: 0) 72245.604187 [D5] process_boolean_info: !lowbatt 72245.604205 [D3] Report[buf]: (4 bytes) => 32 00 00 09 72245.604218 [D5] PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0 72245.604230 [D5] Unit = 00000000, UnitExp = 0 72245.604241 [D5] Exponent = 0 72245.604256 [D2] Path: UPS.PowerSummary.PresentStatus.FullyCharged, Type: Feature, ReportID: 0x32, Offset: 19, Size: 1, Value: 1 72245.604268 [D5] hu_find_infoval: found fullycharged (value: 1) 72245.604280 [D5] process_boolean_info: fullycharged 72245.604302 [D3] Report[buf]: (4 bytes) => 32 00 00 09 72245.604315 [D5] PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0 72245.604327 [D5] Unit = 00000000, UnitExp = 0 72245.604339 [D5] Exponent = 0 72245.604353 [D2] Path: UPS.PowerSummary.PresentStatus.Charging, Type: Feature, ReportID: 0x32, Offset: 20, Size: 1, Value: 0 72245.604366 [D5] hu_find_infoval: found !chrg (value: 0) 72245.604392 [D5] process_boolean_info: !chrg 72245.604409 [D3] Report[buf]: (4 bytes) => 32 00 00 09 72245.604423 [D5] PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0 72245.604435 [D5] Unit = 00000000, UnitExp = 0 72245.604446 [D5] Exponent = 0 72245.604460 [D2] Path: UPS.PowerSummary.PresentStatus.Discharging, Type: Feature, ReportID: 0x32, Offset: 21, Size: 1, Value: 0 72245.604473 [D5] hu_find_infoval: found !dischrg (value: 0) 72245.604484 [D5] process_boolean_info: !dischrg 72245.604502 [D3] Report[buf]: (4 bytes) => 32 00 00 09 72245.604515 [D5] PhyMax = 0, PhyMin = 0, LogMax = 1, LogMin = 0 72245.604527 [D5] Unit = 00000000, UnitExp = 0 72245.604538 [D5] Exponent = 0 72245.604552 [D2] Path: UPS.PowerSummary.PresentStatus.FullyDischarged, Type: Feature, ReportID: 0x32, Offset: 22, Size: 1, Value: 0 72245.604565 [D5] hu_find_infoval: found !depleted (value: 0) 72245.604576 [D5] process_boolean_info: !depleted 72245.604640 [D5] send_to_all: SETINFO driver.state "quiet" 72245.604783 [D6] send_to_all: write 29 bytes to socket 9 succeeded (ret=29): SETINFO driver.state "quiet" 72247.581943 [D5] send_to_all: SETINFO driver.state "updateinfo" 72247.582155 [D6] send_to_all: write 34 bytes to socket 9 succeeded (ret=34): SETINFO driver.state "updateinfo" 72247.582177 [D1] upsdrv_updateinfo... 72247.647068 [D2] file_report_buffer: expected 2 bytes, but got 512 instead 72247.647148 [D3] Report[err]: (512 bytes) => 34 64 00 00 00 00 00 00 f0 9f 6a 80 00 00 00 00 72247.647180 [D3] 00 00 00 00 00 00 00 00 98 ea f4 45 48 49 3a c1 80 a0 6a 80 ff ff ff ff 40 72247.647210 [D3] 9e 6a 80 00 00 00 00 14 b1 b6 83 00 00 00 00 51 1e ef 65 00 00 00 00 00 50 72247.647239 [D3] 27 00 00 00 00 00 00 00 00 00 00 00 00 00 00 60 27 00 00 00 00 00 02 00 00 72247.647268 [D3] 00 00 00 00 00 00 60 27 00 00 00 00 00 41 3c 21 00 00 00 00 00 5c 8d 20 00 72247.647297 [D3] 00 00 00 00 78 9f 6a 80 00 00 00 00 00 02 00 00 00 00 00 00 f0 a1 6a 80 00 72247.647326 [D3] 00 00 00 30 9f 6a 80 00 00 00 00 f0 9e 6a 80 00 00 00 00 d8 ff ff ff 80 ff 72247.647355 [D3] ff ff 3f 9f 6a 80 00 00 00 00 b8 c3 c2 83 00 00 00 00 9a 9f 6a 80 00 00 00 72247.647388 [D3] 00 00 00 00 00 dd 01 00 00 08 02 ff ff 00 00 00 00 78 9f 6a 80 00 00 00 00 72247.647418 [D3] ff 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 72247.647448 [D3] 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 72247.647477 [D3] 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 72247.647506 [D3] 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 72247.647534 [D3] 3f 78 09 41 98 ea f4 45 48 49 3a c1 00 9e 6a 80 00 00 00 00 cc 63 b7 83 00 72247.647564 [D3] 00 00 00 00 00 00 00 00 00 00 00 00 60 27 00 00 00 00 00 02 00 00 00 00 00 72247.647593 [D3] 00 00 00 70 27 00 00 00 00 00 41 3c 21 00 00 00 00 00 0d 00 00 00 00 00 00 72247.647622 [D3] 00 0d 00 00 00 00 00 00 00 68 9e 6a 80 00 00 00 00 51 1e ef 65 00 00 00 00 72247.647653 [D3] 93 e8 dc 78 a4 e7 69 3b 00 00 00 00 00 00 00 00 98 ea f4 45 48 49 3a c1 30 72247.647682 [D3] 9e 6a 80 00 00 00 00 9c 5f b7 83 00 00 00 00 0d 00 00 00 00 00 00 00 00 00 72247.647710 [D3] 00 00 00 00 00 00 68 9e 6a 80 00 00 00 00 a0 9e 6a 80 00 00 00 00 80 9e 6a 72247.647737 [D3] 80 00 00 00 00 8c 61 b0 83 00 00 00 00 5c 8d 20 00 00 00 00 00 72247.647764 [D1] Got 1 HID objects... 72247.647781 [D3] Report[buf]: (2 bytes) => 34 64 72247.647797 [D5] PhyMax = 0, PhyMin = 0, LogMax = 255, LogMin = 0 72247.647810 [D5] Unit = 00000000, UnitExp = 0 72247.647822 [D5] Exponent = 0 72247.647837 [D5] hid_lookup_path: 00840004 -> UPS 72247.647852 [D5] hid_lookup_path: 00840024 -> PowerSummary 72247.647867 [D5] hid_lookup_path: 00850066 -> RemainingCapacity 72247.647884 [D2] Path: UPS.PowerSummary.RemainingCapacity, Type: Input, ReportID: 0x34, Offset: 0, Size: 8, Value: 100 72247.647919 [D1] Quick update... 72247.647935 [D4] Entering libusb_get_report 72247.648925 [D3] Report[get]: (3 bytes) => 61 ff ff 72247.648983 [D5] PhyMax = 0, PhyMin = 0, LogMax = 65535, LogMin = 0 72247.649032 [D5] Unit = 00001001, UnitExp = 0 72247.649047 [D5] Exponent = 0 72247.649064 [D2] Path: UPS.OutletSystem.Outlet.DelayBeforeStartup, Type: Feature, ReportID: 0x61, Offset: 0, Size: 16, Value: 65535 72247.649095 [D4] Entering libusb_get_report 72247.649932 [D3] Report[get]: (3 bytes) => 15 ff ff 72247.649995 [D5] PhyMax = 0, PhyMin = 0, LogMax = 65535, LogMin = 0 72247.650010 [D5] Unit = 00001001, UnitExp = 0 72247.650023 [D5] Exponent = 0 72247.650041 [D2] Path: UPS.OutletSystem.Outlet.DelayBeforeShutdown, Type: Feature, ReportID: 0x15, Offset: 0, Size: 16, Value: 65535 72247.650072 [D4] Entering libusb_get_report 72247.727371 nut_libusb_get_report: No device 72247.727469 [D1] Can't retrieve Report 17: Interrupted system call 72247.727532 [D5] send_to_all: SETINFO driver.state "reconnect.trying" 72247.727733 [D6] send_to_all: write 40 bytes to socket 9 succeeded (ret=40): SETINFO driver.state "reconnect.trying" 72247.727777 [D5] send_to_all: SETINFO driver.state "quiet" 72247.727879 [D6] send_to_all: write 29 bytes to socket 9 succeeded (ret=29): SETINFO driver.state "quiet" 72249.583257 [D5] send_to_all: SETINFO driver.state "updateinfo" 72249.583466 [D6] send_to_all: write 34 bytes to socket 9 succeeded (ret=34): SETINFO driver.state "updateinfo" 72249.583501 [D1] upsdrv_updateinfo... 72249.583516 [D1] Got to reconnect! 72249.583543 [D5] send_to_all: SETINFO driver.state "reconnect.trying" 72249.583569 [D6] send_to_all: write 40 bytes to socket 9 succeeded (ret=40): SETINFO driver.state "reconnect.trying" 72249.583596 [D4] Closing comm_driver previous handle 72249.586916 [D4] =================================================================== 72249.586973 [D4] device has been disconnected, try to reconnect 72249.586987 [D4] =================================================================== 72249.586999 [D4] Opening comm_driver ... 72249.587552 [D2] Checking device 1 of 3 (0000/0000) 72249.587798 [D1] nut_libusb_open: invalid libusb bus number 0 72249.587882 [D2] - VendorID: 0000 72249.587897 [D2] - ProductID: 0000 72249.587910 [D2] - Manufacturer: Generic 72249.587922 [D2] - Product: XHCI root HUB 72249.587934 [D2] - Serial Number: unknown 72249.587946 [D2] - Bus: 000 72249.587957 [D2] - Bus Port: unknown 72249.587968 [D2] - Device: 001 72249.587980 [D2] - Device release number: 0100 72249.587991 [D2] Trying to match device 72249.588013 [D2] match_function_subdriver (non-SHUT mode): matching a device... 72249.588048 [D2] match_function_subdriver (non-SHUT mode): failed to match a subdriver to vendor and/or product ID 72249.588062 [D2] Device does not match - skipping 72249.588150 [D2] Checking device 2 of 3 (0000/0000) 72249.588301 [D1] nut_libusb_open: invalid libusb bus number 0 72249.588361 [D2] - VendorID: 0000 72249.588384 [D2] - ProductID: 0000 72249.588397 [D2] - Manufacturer: Marvell 72249.588409 [D2] - Product: EHCI root HUB 72249.588421 [D2] - Serial Number: unknown 72249.588432 [D2] - Bus: 001 72249.588443 [D2] - Bus Port: unknown 72249.588454 [D2] - Device: 001 72249.588466 [D2] - Device release number: 0100 72249.588477 [D2] Trying to match device 72249.588496 [D2] match_function_subdriver (non-SHUT mode): matching a device... 72249.588525 [D2] match_function_subdriver (non-SHUT mode): failed to match a subdriver to vendor and/or product ID 72249.588539 [D2] Device does not match - skipping 72249.588619 [D2] Checking device 3 of 3 (09AE/3024) 72249.743398 [D1] nut_libusb_open get iManufacturer failed, retrying... 72249.893627 [D1] nut_libusb_open get iManufacturer failed, retrying... 72250.048371 [D1] nut_libusb_open get iManufacturer failed, retrying... 72250.198508 [D1] nut_libusb_open get iProduct failed, retrying... 72250.347839 [D1] nut_libusb_open get iProduct failed, retrying... 72250.499443 [D1] nut_libusb_open get iProduct failed, retrying... 72250.649305 [D1] nut_libusb_open get iSerialNumber failed, retrying... 72250.803444 [D1] nut_libusb_open get iSerialNumber failed, retrying... 72250.955470 [D1] nut_libusb_open get iSerialNumber failed, retrying... 72250.955570 [D2] - VendorID: 09ae 72250.955585 [D2] - ProductID: 3024 72250.955597 [D2] - Manufacturer: unknown 72250.955609 [D2] - Product: unknown 72250.955621 [D2] - Serial Number: unknown 72250.955633 [D2] - Bus: 001 72250.955644 [D2] - Bus Port: 001 72250.955655 [D2] - Device: 002 72250.955667 [D2] - Device release number: 0002 72250.955679 [D2] Trying to match device 72250.955704 [D2] match_function_subdriver (non-SHUT mode): matching a device... 72250.955744 [D3] match_function_regex: matching a device... 72250.955766 [D3] match_function_exact: matching a device... 72250.955782 [D2] match_function_exact: failed match of Vendor: (null) != Tripp Lite 72250.955795 [D2] Device does not match - skipping 72250.955954 [D2] libusb1: No appropriate HID device found 72250.955978 libusb1: Could not open any HID devices: insufficient permissions on everything 72250.955994 [D4] Opening comm_driver returns ret=-1 72250.956021 [D5] send_to_all: SETINFO driver.state "quiet" 72250.956052 [D6] send_to_all: write 29 bytes to socket 9 succeeded (ret=29): SETINFO driver.state "quiet" 72250.956067 [D5] send_to_all: DATASTALE 72250.956086 [D6] send_to_all: write 10 bytes to socket 9 succeeded (ret=10): DATASTALE 72251.588983 [D5] send_to_all: SETINFO driver.state "updateinfo" 72251.589141 [D6] send_to_all: write 34 bytes to socket 9 succeeded (ret=34): SETINFO driver.state "updateinfo" 72251.589165 [D1] upsdrv_updateinfo... 72251.589179 [D1] Got to reconnect! 72251.589201 [D5] send_to_all: SETINFO driver.state "reconnect.trying" 72251.589225 [D6] send_to_all: write 40 bytes to socket 9 succeeded (ret=40): SETINFO driver.state "reconnect.trying" 72251.589247 [D4] Not closing comm_driver previous handle: already closed 72251.589260 [D4] =================================================================== 72251.589272 [D4] device has been disconnected, try to reconnect 72251.589284 [D4] =================================================================== 72251.589296 [D4] Opening comm_driver ... 72251.589870 [D2] Checking device 1 of 3 (0000/0000) 72251.590057 [D1] nut_libusb_open: invalid libusb bus number 0 72251.590139 [D2] - VendorID: 0000 72251.590154 [D2] - ProductID: 0000 72251.590166 [D2] - Manufacturer: Generic 72251.590178 [D2] - Product: XHCI root HUB 72251.590190 [D2] - Serial Number: unknown 72251.590203 [D2] - Bus: 000 72251.590214 [D2] - Bus Port: unknown 72251.590226 [D2] - Device: 001 72251.590237 [D2] - Device release number: 0100 72251.590249 [D2] Trying to match device 72251.590271 [D2] match_function_subdriver (non-SHUT mode): matching a device... 72251.590307 [D2] match_function_subdriver (non-SHUT mode): failed to match a subdriver to vendor and/or product ID 72251.590322 [D2] Device does not match - skipping 72251.590444 [D2] Checking device 2 of 3 (0000/0000) 72251.590658 [D1] nut_libusb_open: invalid libusb bus number 0 72251.590755 [D2] - VendorID: 0000 72251.590771 [D2] - ProductID: 0000 72251.590785 [D2] - Manufacturer: Marvell 72251.590797 [D2] - Product: EHCI root HUB 72251.590809 [D2] - Serial Number: unknown 72251.590821 [D2] - Bus: 001 72251.590832 [D2] - Bus Port: unknown 72251.590843 [D2] - Device: 001 72251.590855 [D2] - Device release number: 0100 72251.590867 [D2] Trying to match device 72251.590886 [D2] match_function_subdriver (non-SHUT mode): matching a device... 72251.590918 [D2] match_function_subdriver (non-SHUT mode): failed to match a subdriver to vendor and/or product ID 72251.590932 [D2] Device does not match - skipping 72251.591030 [D2] Checking device 3 of 3 (09AE/3024) 72251.745371 [D1] nut_libusb_open get iManufacturer failed, retrying... 72251.895872 [D1] nut_libusb_open get iManufacturer failed, retrying... 72252.050367 [D1] nut_libusb_open get iManufacturer failed, retrying... 72252.205384 [D1] nut_libusb_open get iProduct failed, retrying... 72252.359364 [D1] nut_libusb_open get iProduct failed, retrying... 72252.513419 [D1] nut_libusb_open get iProduct failed, retrying... 72252.667482 [D1] nut_libusb_open get iSerialNumber failed, retrying... 72252.820954 [D1] nut_libusb_open get iSerialNumber failed, retrying... 72252.971389 [D1] nut_libusb_open get iSerialNumber failed, retrying... 72252.971473 [D2] - VendorID: 09ae 72252.971489 [D2] - ProductID: 3024 72252.971501 [D2] - Manufacturer: unknown 72252.971516 [D2] - Product: unknown 72252.971528 [D2] - Serial Number: unknown 72252.971540 [D2] - Bus: 001 72252.971551 [D2] - Bus Port: 001 72252.971563 [D2] - Device: 002 72252.971574 [D2] - Device release number: 0002 72252.971586 [D2] Trying to match device 72252.971609 [D2] match_function_subdriver (non-SHUT mode): matching a device... 72252.971645 [D3] match_function_regex: matching a device... 72252.971663 [D3] match_function_exact: matching a device... 72252.971678 [D2] match_function_exact: failed match of Vendor: (null) != Tripp Lite 72252.971690 [D2] Device does not match - skipping 72252.971846 [D2] libusb1: No appropriate HID device found 72252.971869 libusb1: Could not open any HID devices: insufficient permissions on everything 72252.971885 [D4] Opening comm_driver returns ret=-1 72252.971912 [D5] send_to_all: SETINFO driver.state "quiet" 72252.972008 [D6] send_to_all: write 29 bytes to socket 9 succeeded (ret=29): SETINFO driver.state "quiet"
-
@dennypage said in NUT Package (2.8.1 and above):
Can you run the driver by hand in debug mode via ssh please?
First start the service, and then kill the driver:
killall usbhid-ups
Then, run the driver with debug:/usr/local/libexec/nut/usbhid-ups -DDDDDD -a TrippLite
FYI - this is the output when I tried to manually restart the driver after connection was lost:
0.002954 [D2] Initializing an USB-connected UPS with library libusb-1.0.0 (API: 0x1000102) (NUT subdriver name='USB communication driver (libusb 1.0)' ver='0.46') 0.003874 [D2] Checking device 1 of 3 (0000/0000) 0.004670 [D1] nut_libusb_open: invalid libusb bus number 0 0.004804 [D2] - VendorID: 0000 0.004821 [D2] - ProductID: 0000 0.004833 [D2] - Manufacturer: Generic 0.004845 [D2] - Product: XHCI root HUB 0.004856 [D2] - Serial Number: unknown 0.004868 [D2] - Bus: 000 0.004878 [D2] - Bus Port: unknown 0.004889 [D2] - Device: 001 0.004901 [D2] - Device release number: 0100 0.004912 [D2] Trying to match device 0.004934 [D2] match_function_subdriver (non-SHUT mode): matching a device... 0.004978 [D2] match_function_subdriver (non-SHUT mode): failed to match a subdriver to vendor and/or product ID 0.004991 [D2] Device does not match - skipping 0.005115 [D2] Checking device 2 of 3 (0000/0000) 0.005340 [D1] nut_libusb_open: invalid libusb bus number 0 0.005432 [D2] - VendorID: 0000 0.005447 [D2] - ProductID: 0000 0.005458 [D2] - Manufacturer: Marvell 0.005470 [D2] - Product: EHCI root HUB 0.005481 [D2] - Serial Number: unknown 0.005492 [D2] - Bus: 001 0.005502 [D2] - Bus Port: unknown 0.005513 [D2] - Device: 001 0.005525 [D2] - Device release number: 0100 0.005535 [D2] Trying to match device 0.005554 [D2] match_function_subdriver (non-SHUT mode): matching a device... 0.005596 [D2] match_function_subdriver (non-SHUT mode): failed to match a subdriver to vendor and/or product ID 0.005610 [D2] Device does not match - skipping 0.005713 [D2] Checking device 3 of 3 (09AE/3024) 0.156567 [D1] nut_libusb_open get iManufacturer failed, retrying... 0.310568 [D1] nut_libusb_open get iManufacturer failed, retrying... 0.461572 [D1] nut_libusb_open get iManufacturer failed, retrying... 0.608445 [D1] nut_libusb_open get iProduct failed, retrying... 0.762543 [D1] nut_libusb_open get iProduct failed, retrying... 0.912962 [D1] nut_libusb_open get iProduct failed, retrying... 1.066550 [D1] nut_libusb_open get iSerialNumber failed, retrying... 1.218542 [D1] nut_libusb_open get iSerialNumber failed, retrying... 1.369116 [D1] nut_libusb_open get iSerialNumber failed, retrying... 1.369185 [D2] - VendorID: 09ae 1.369200 [D2] - ProductID: 3024 1.369214 [D2] - Manufacturer: unknown 1.369226 [D2] - Product: unknown 1.369238 [D2] - Serial Number: unknown 1.369249 [D2] - Bus: 001 1.369261 [D2] - Bus Port: 001 1.369273 [D2] - Device: 002 1.369285 [D2] - Device release number: 0002 1.369296 [D2] Trying to match device 1.369319 [D2] match_function_subdriver (non-SHUT mode): matching a device... 1.369424 [D3] match_function_regex: matching a device... 1.369447 [D2] Device matches 1.369460 [D2] Reading configuration descriptor 1 of 1 1.369848 [D3] libusb_kernel_driver_active() returned 0: Success 1.369919 [D2] Claimed interface 0 successfully 1.369944 [D3] nut_usb_set_altinterface: skipped libusb_set_interface_alt_setting(udev, 0, 0) 1.446624 [D2] Unable to get HID descriptor (No device) 1.446696 [D3] HID descriptor length (method 1) -1 1.446713 [D4] i=0, extra[i]=09, extra[i+1]=21 1.446736 [D3] HID descriptor, method 2: (9 bytes) => 09 21 11 01 21 01 22 75 03 1.446775 [D3] HID descriptor length (method 2) 885 1.446789 [D2] HID descriptor length 885 1.523598 [D2] Unable to get Report descriptor: Input/output error 1.523845 [D2] libusb1: No appropriate HID device found 1.524098 libusb1: Could not open any HID devices: insufficient permissions on everything 1.524142 No matching HID UPS found 1.524226 [D5] send_to_all: SETINFO driver.state "cleanup.exit" 1.524248 upsnotify: failed to notify about state 4: no notification tech defined, will not spam more about it
And this was the initial good manual startup:
0.002990 [D2] Initializing an USB-connected UPS with library libusb-1.0.0 (API: 0x1000102) (NUT subdriver name='USB communication driver (libusb 1.0)' ver='0.46') 0.003801 [D2] Checking device 1 of 3 (0000/0000) 0.004569 [D1] nut_libusb_open: invalid libusb bus number 0 0.004704 [D2] - VendorID: 0000 0.004723 [D2] - ProductID: 0000 0.004734 [D2] - Manufacturer: Generic 0.004745 [D2] - Product: XHCI root HUB 0.004757 [D2] - Serial Number: unknown 0.004768 [D2] - Bus: 000 0.004778 [D2] - Bus Port: unknown 0.004789 [D2] - Device: 001 0.004800 [D2] - Device release number: 0100 0.004810 [D2] Trying to match device 0.004832 [D2] match_function_subdriver (non-SHUT mode): matching a device... 0.004876 [D2] match_function_subdriver (non-SHUT mode): failed to match a subdriver to vendor and/or product ID 0.004888 [D2] Device does not match - skipping 0.005006 [D2] Checking device 2 of 3 (0000/0000) 0.005231 [D1] nut_libusb_open: invalid libusb bus number 0 0.005323 [D2] - VendorID: 0000 0.005337 [D2] - ProductID: 0000 0.005349 [D2] - Manufacturer: Marvell 0.005360 [D2] - Product: EHCI root HUB 0.005371 [D2] - Serial Number: unknown 0.005381 [D2] - Bus: 001 0.005391 [D2] - Bus Port: unknown 0.005402 [D2] - Device: 001 0.005412 [D2] - Device release number: 0100 0.005422 [D2] Trying to match device 0.005442 [D2] match_function_subdriver (non-SHUT mode): matching a device... 0.005476 [D2] match_function_subdriver (non-SHUT mode): failed to match a subdriver to vendor and/or product ID 0.005489 [D2] Device does not match - skipping 0.005585 [D2] Checking device 3 of 3 (09AE/3024) 0.018725 [D2] - VendorID: 09ae 0.018775 [D2] - ProductID: 3024 0.018789 [D2] - Manufacturer: Tripp Lite 0.018800 [D2] - Product: ECO850LCD 0.018811 [D2] - Serial Number: 3216CV4BC87F303175 0.018822 [D2] - Bus: 001 0.018832 [D2] - Bus Port: 001 0.018843 [D2] - Device: 002 0.018853 [D2] - Device release number: 0002 0.018864 [D2] Trying to match device 0.018884 [D2] match_function_subdriver (non-SHUT mode): matching a device... 0.018983 [D3] match_function_regex: matching a device... 0.019006 [D2] Device matches
-
@dennypage said in NUT Package (2.8.1 and above):
First start the service, and then kill the driver:
killall usbhid-ups
Then, run the driver with debug:/usr/local/libexec/nut/usbhid-ups -DDDDDD -a TrippLite
Here is system log after disconnecting / reconnecting USB cable:
Mar 11 11:40:04 upsmon 8414 Poll UPS [TrippLite] failed - Driver not connected Mar 11 11:40:01 kernel uhid0: <Tripp Lite ECO850LCD, class 0/0, rev 2.00/0.02, addr 2> on usbus1 Mar 11 11:40:01 kernel uhid0 on uhub1 Mar 11 11:40:01 kernel ugen1.2: <Tripp Lite ECO850LCD> at usbus1 Mar 11 11:39:59 upsmon 8414 Poll UPS [TrippLite] failed - Driver not connected Mar 11 11:39:54 upsmon 8414 Poll UPS [TrippLite] failed - Driver not connected Mar 11 11:39:49 upsmon 8414 Poll UPS [TrippLite] failed - Driver not connected Mar 11 11:39:48 kernel ugen1.2: <Tripp Lite ECO850LCD> at usbus1 (disconnected) Mar 11 11:39:44 upsmon 8414 Poll UPS [TrippLite] failed - Driver not connected
After disconnecting / reconnecting USB cable and manual driver start, UPS is available again:
0.002865 [D2] Initializing an USB-connected UPS with library libusb-1.0.0 (API: 0x1000102) (NUT subdriver name='USB communication driver (libusb 1.0)' ver='0.46') 0.003797 [D2] Checking device 1 of 3 (0000/0000) 0.004739 [D1] nut_libusb_open: invalid libusb bus number 0 0.004878 [D2] - VendorID: 0000 0.004897 [D2] - ProductID: 0000 0.004909 [D2] - Manufacturer: Generic 0.004920 [D2] - Product: XHCI root HUB 0.004932 [D2] - Serial Number: unknown 0.004943 [D2] - Bus: 000 0.004953 [D2] - Bus Port: unknown 0.004963 [D2] - Device: 001 0.004974 [D2] - Device release number: 0100 0.004985 [D2] Trying to match device 0.005008 [D2] match_function_subdriver (non-SHUT mode): matching a device... 0.005052 [D2] match_function_subdriver (non-SHUT mode): failed to match a subdriver to vendor and/or product ID 0.005065 [D2] Device does not match - skipping 0.005194 [D2] Checking device 2 of 3 (0000/0000) 0.005421 [D1] nut_libusb_open: invalid libusb bus number 0 0.005517 [D2] - VendorID: 0000 0.005532 [D2] - ProductID: 0000 0.005543 [D2] - Manufacturer: Marvell 0.005554 [D2] - Product: EHCI root HUB 0.005565 [D2] - Serial Number: unknown 0.005576 [D2] - Bus: 001 0.005586 [D2] - Bus Port: unknown 0.005596 [D2] - Device: 001 0.005607 [D2] - Device release number: 0100 0.005617 [D2] Trying to match device 0.005637 [D2] match_function_subdriver (non-SHUT mode): matching a device... 0.005669 [D2] match_function_subdriver (non-SHUT mode): failed to match a subdriver to vendor and/or product ID 0.005682 [D2] Device does not match - skipping 0.005775 [D2] Checking device 3 of 3 (09AE/3024) 0.018671 [D2] - VendorID: 09ae 0.018723 [D2] - ProductID: 3024 0.018736 [D2] - Manufacturer: Tripp Lite 0.018748 [D2] - Product: ECO850LCD 0.018762 [D2] - Serial Number: 3216CV4BC87F303175 0.018774 [D2] - Bus: 001 0.018784 [D2] - Bus Port: 001 0.018794 [D2] - Device: 002 0.018805 [D2] - Device release number: 0002 0.018816 [D2] Trying to match device 0.018843 [D2] match_function_subdriver (non-SHUT mode): matching a device... 0.018946 [D3] match_function_regex: matching a device... 0.018967 [D2] Device matches
-
@ghound said in NUT Package (2.8.1 and above):
72251.591030 [D2] Checking device 3 of 3 (09AE/3024)
72251.745371 [D1] nut_libusb_open get iManufacturer failed, retrying...
72251.895872 [D1] nut_libusb_open get iManufacturer failed, retrying...
72252.050367 [D1] nut_libusb_open get iManufacturer failed, retrying...
72252.205384 [D1] nut_libusb_open get iProduct failed, retrying...
72252.359364 [D1] nut_libusb_open get iProduct failed, retrying...
72252.513419 [D1] nut_libusb_open get iProduct failed, retrying...
72252.667482 [D1] nut_libusb_open get iSerialNumber failed, retrying...
72252.820954 [D1] nut_libusb_open get iSerialNumber failed, retrying...
72252.971389 [D1] nut_libusb_open get iSerialNumber failed, retrying...
72252.971473 [D2] - VendorID: 09ae
72252.971489 [D2] - ProductID: 3024
72252.971501 [D2] - Manufacturer: unknown
72252.971516 [D2] - Product: unknown
72252.971528 [D2] - Serial Number: unknown
72252.971540 [D2] - Bus: 001
72252.971551 [D2] - Bus Port: 001
72252.971563 [D2] - Device: 002
72252.971574 [D2] - Device release number: 0002
72252.971586 [D2] Trying to match device
72252.971609 [D2] match_function_subdriver (non-SHUT mode): matching a device...
72252.971645 [D3] match_function_regex: matching a device...
72252.971663 [D3] match_function_exact: matching a device...
72252.971678 [D2] match_function_exact: failed match of Vendor: (null) != Tripp Lite
72252.971690 [D2] Device does not match - skipping@ghound said in NUT Package (2.8.1 and above):
0.005713 [D2] Checking device 3 of 3 (09AE/3024)
0.156567 [D1] nut_libusb_open get iManufacturer failed, retrying...
0.310568 [D1] nut_libusb_open get iManufacturer failed, retrying...
0.461572 [D1] nut_libusb_open get iManufacturer failed, retrying...
0.608445 [D1] nut_libusb_open get iProduct failed, retrying...
0.762543 [D1] nut_libusb_open get iProduct failed, retrying...
0.912962 [D1] nut_libusb_open get iProduct failed, retrying...
1.066550 [D1] nut_libusb_open get iSerialNumber failed, retrying...
1.218542 [D1] nut_libusb_open get iSerialNumber failed, retrying...
1.369116 [D1] nut_libusb_open get iSerialNumber failed, retrying...
1.369185 [D2] - VendorID: 09ae
1.369200 [D2] - ProductID: 3024
1.369214 [D2] - Manufacturer: unknown
1.369226 [D2] - Product: unknown
1.369238 [D2] - Serial Number: unknown
1.369249 [D2] - Bus: 001
1.369261 [D2] - Bus Port: 001
1.369273 [D2] - Device: 002
1.369285 [D2] - Device release number: 0002For some reason we are loosing the ability to query device manufacturer and product. That it is persistent indicates that there is a problem in the kernel's USB drivers or the hardware itself. Unfortunately this is well outside of NUT's control.
Looking at your usbconfig output, the one thing I would recommend is to try a different USB port on the host. Something that connects to bus0 (generic XHCI) rather than bus1 (Marvell EHCI).
-
@dennypage said in NUT Package (2.8.1 and above):
For some reason we are loosing the ability to query device manufacturer and product. That it is persistent indicates that there is a problem in the kernel's USB drivers or the hardware itself. Unfortunately this is well outside of NUT's control.
Looking at your usbconfig output, the one thing I would recommend is to try a different USB port on the host. Something that connects to bus0 (generic XHCI) rather than bus1 (Marvell EHCI).
Thank you for looking at all the logs. This is a Netgate SG1100 box, so I connected to the USB3 port at ugen0.1: <Generic XHCI root HUB> at usbus0 – Bus:000 Bus Port: 002; vice my original connection to the USB2 port at ugen1.1: <Marvell EHCI root HUB> at usbus1 – Bus:001 Bus Port: 001. Again, connection was lost after around one day of operation. I do have another SG1100 I can try. Any other troubleshooting ideas? Thank you.
Log USB3 port connection:
0.007864 [D2] Checking device 3 of 3 (09AE/3024) 0.010883 [D2] - VendorID: 09ae 0.010949 [D2] - ProductID: 3024 0.010964 [D2] - Manufacturer: Tripp Lite 0.010976 [D2] - Product: ECO850LCD 0.010987 [D2] - Serial Number: 3216CV4BC87F303175 0.010998 [D2] - Bus: 000 0.011009 [D2] - Bus Port: 002 0.011019 [D2] - Device: 002 0.011030 [D2] - Device release number: 0002 0.011041 [D2] Trying to match device 0.011062 [D2] match_function_subdriver (non-SHUT mode): matching a device... 0.011164 [D3] match_function_regex: matching a device... 0.011185 [D2] Device matches
-
@ghound said in NUT Package (2.8.1 and above):
0.007864 [D2] Checking device 3 of 3 (09AE/3024)
0.010883 [D2] - VendorID: 09ae
0.010949 [D2] - ProductID: 3024
0.010964 [D2] - Manufacturer: Tripp Lite
0.010976 [D2] - Product: ECO850LCD
0.010987 [D2] - Serial Number: 3216CV4BC87F303175
0.010998 [D2] - Bus: 000
0.011009 [D2] - Bus Port: 002
0.011019 [D2] - Device: 002
0.011030 [D2] - Device release number: 0002This looks correct (working). Manufacturer and Product are identifiable. If this subsequently fails, to confirm that the issue is the same as experienced on the other port, I would need to see what the driver says when it isn't working. Also interested to see the output of "usbconfig -v" when it isn't working.
-
@dennypage said in NUT Package (2.8.1 and above):
This looks correct (working). Manufacturer and Product are identifiable. If this subsequently fails, to confirm that the issue is the same as experienced on the other port, I would need to see what the driver says when it isn't working. Also interested to see the output of "usbconfig -v" when it isn't working.
Below is result of usbconfig -v when the connection is not working (on USB3 port):
[23.09.1-RELEASE][admin@router01.localr01]/dev/usb: usbconfig -v ugen0.1: <Generic XHCI root HUB> at usbus0, cfg=0 md=HOST spd=SUPER (5.0Gbps) pwr=SAVE (0mA) ugen0.1.0: uhub0: <Generic XHCI root HUB, class 9/0, rev 3.00/1.00, addr 1> bLength = 0x0012 bDescriptorType = 0x0001 bcdUSB = 0x0300 bDeviceClass = 0x0009 <HUB> bDeviceSubClass = 0x0000 bDeviceProtocol = 0x0003 bMaxPacketSize0 = 0x0009 idVendor = 0x0000 idProduct = 0x0000 bcdDevice = 0x0100 iManufacturer = 0x0001 <Generic> iProduct = 0x0002 <XHCI root HUB> iSerialNumber = 0x0000 <no string> bNumConfigurations = 0x0001 Configuration index 0 bLength = 0x0009 bDescriptorType = 0x0002 wTotalLength = 0x001f bNumInterfaces = 0x0001 bConfigurationValue = 0x0001 iConfiguration = 0x0000 <no string> bmAttributes = 0x0040 bMaxPower = 0x0000 Interface 0 bLength = 0x0009 bDescriptorType = 0x0004 bInterfaceNumber = 0x0000 bAlternateSetting = 0x0000 bNumEndpoints = 0x0001 bInterfaceClass = 0x0009 <HUB> bInterfaceSubClass = 0x0000 bInterfaceProtocol = 0x0000 iInterface = 0x0000 <no string> Endpoint 0 bLength = 0x0007 bDescriptorType = 0x0005 bEndpointAddress = 0x0081 <IN> bmAttributes = 0x0003 <INTERRUPT> wMaxPacketSize = 0x0002 bInterval = 0x00ff bRefresh = 0x0000 bSynchAddress = 0x0000 Additional Descriptor bLength = 0x06 bDescriptorType = 0x30 bDescriptorSubType = 0x00 RAW dump: 0x00 | 0x06, 0x30, 0x00, 0x00, 0x00, 0x00 ugen1.1: <Marvell EHCI root HUB> at usbus1, cfg=0 md=HOST spd=HIGH (480Mbps) pwr=SAVE (0mA) ugen1.1.0: uhub1: <Marvell EHCI root HUB, class 9/0, rev 2.00/1.00, addr 1> bLength = 0x0012 bDescriptorType = 0x0001 bcdUSB = 0x0200 bDeviceClass = 0x0009 <HUB> bDeviceSubClass = 0x0000 bDeviceProtocol = 0x0001 bMaxPacketSize0 = 0x0040 idVendor = 0x0000 idProduct = 0x0000 bcdDevice = 0x0100 iManufacturer = 0x0001 <Marvell> iProduct = 0x0002 <EHCI root HUB> iSerialNumber = 0x0000 <no string> bNumConfigurations = 0x0001 Configuration index 0 bLength = 0x0009 bDescriptorType = 0x0002 wTotalLength = 0x0019 bNumInterfaces = 0x0001 bConfigurationValue = 0x0001 iConfiguration = 0x0000 <no string> bmAttributes = 0x0040 bMaxPower = 0x0000 Interface 0 bLength = 0x0009 bDescriptorType = 0x0004 bInterfaceNumber = 0x0000 bAlternateSetting = 0x0000 bNumEndpoints = 0x0001 bInterfaceClass = 0x0009 <HUB> bInterfaceSubClass = 0x0000 bInterfaceProtocol = 0x0000 iInterface = 0x0000 <no string> Endpoint 0 bLength = 0x0007 bDescriptorType = 0x0005 bEndpointAddress = 0x0081 <IN> bmAttributes = 0x0003 <INTERRUPT> wMaxPacketSize = 0x0008 bInterval = 0x00ff bRefresh = 0x0000 bSynchAddress = 0x0000 ugen0.2: <Tripp Lite ECO850LCD> at usbus0, cfg=0 md=HOST spd=FULL (12Mbps) pwr=ON (100mA) bLength = 0x0012 bDescriptorType = 0x0001 bcdUSB = 0x0200 bDeviceClass = 0x0000 <Probed by interface class> bDeviceSubClass = 0x0000 bDeviceProtocol = 0x0000 bMaxPacketSize0 = 0x0040 idVendor = 0x09ae idProduct = 0x3024 bcdDevice = 0x0002 iManufacturer = 0x0003 <retrieving string failed> iProduct = 0x0001 <retrieving string failed> iSerialNumber = 0x0005 <retrieving string failed> bNumConfigurations = 0x0001 Configuration index 0 bLength = 0x0009 bDescriptorType = 0x0002 wTotalLength = 0x0022 bNumInterfaces = 0x0001 bConfigurationValue = 0x0001 iConfiguration = 0x0000 <no string> bmAttributes = 0x00a0 bMaxPower = 0x0032 Interface 0 bLength = 0x0009 bDescriptorType = 0x0004 bInterfaceNumber = 0x0000 bAlternateSetting = 0x0000 bNumEndpoints = 0x0001 bInterfaceClass = 0x0003 <HID device> bInterfaceSubClass = 0x0000 bInterfaceProtocol = 0x0000 iInterface = 0x0000 <no string> Additional Descriptor bLength = 0x09 bDescriptorType = 0x21 bDescriptorSubType = 0x11 RAW dump: 0x00 | 0x09, 0x21, 0x11, 0x01, 0x21, 0x01, 0x22, 0x75, 0x08 | 0x03 Endpoint 0 bLength = 0x0007 bDescriptorType = 0x0005 bEndpointAddress = 0x0081 <IN> bmAttributes = 0x0003 <INTERRUPT> wMaxPacketSize = 0x0040 bInterval = 0x00ff bRefresh = 0x0000 bSynchAddress = 0x0000 Broadcast Message from root@router01.localr01 (no tty) at 16:01 EDT... UPS TrippLite is unavailable
-
@ghound said in NUT Package (2.8.1 and above):
iManufacturer = 0x0003 <retrieving string failed>
iProduct = 0x0001 <retrieving string failed>
iSerialNumber = 0x0005 <retrieving string failed>It was worth a shot.
Can you confirm that this behavior started following an upgrade of pfSense?
-
@dennypage said in NUT Package (2.8.1 and above):
Can you confirm that this behavior started following an upgrade of pfSense?
Behavior has persisted through several updates. (In fact, UPS has never not had this issue from its first day out of the box.)
-
@ghound said in NUT Package (2.8.1 and above):
Behavior has persisted through several updates. (In fact, UPS has never not had this issue from its first day out of the box.)
Okay, I'm confused. Please detail what previous version/date that the problem did not occur, and what version/date began to occurr.
-
@dennypage said in NUT Package (2.8.1 and above):
Okay, I'm confused. Please detail what previous version/date that the problem did not occur, and what version/date began to occurr.
TrippLite UPS was purchased new in May '23 and connected to SG-1100 (23.05 / 2.8.0_2). You gave me a few tips to properly load usbhid-ups. Once usbhid-ups loaded correctly, after a few days, UPS lost connection (so the UPS has never operated without the lost connection problem every few days). At the time, I believed this was the "lost connection" problem mentioned in the thread. The problem has persisted from first connection to today. SG-1100 is currently 23.09.1 and Nut 2.8.2_1.
-
@ghound said in NUT Package (2.8.1 and above):
TrippLite UPS was purchased new in May '23 and connected to SG-1100 (23.05 / 2.8.0_2). You gave me a few tips to properly load usbhid-ups. Once usbhid-ups loaded correctly, after a few days, UPS lost connection (so the UPS has never operated without the lost connection problem every few days). At the time, I believed this was the "lost connection" problem mentioned in the thread. The problem has persisted from first connection to today. SG-1100 is currently 23.09.1 and Nut 2.8.2_1.
Ah, okay. It's never operated correctly. I had misunderstood that it was a regression.
-
@dennypage Sorry if this is the wrong place. I migrated the configuration to a Netgate 4200. I have NUT package 2.8.2_1. It had permission errors. After including user=root in the ups.conf section (as suggested by you in the previous track) it started working. It also worked on the previous system.