Skip to content

Fix: Prevent UPS Lockup on '0 HID Objects' by Reconnecting on Stale Data - #2671

Merged
jimklimov merged 3 commits into
networkupstools:masterfrom
michal4132:apc-fix
Nov 15, 2024
Merged

jimklimov merged 3 commits into
networkupstools:masterfrom
michal4132:apc-fix

Conversation

@michal4132

Copy link
Copy Markdown
Contributor

This PR addresses an issue where the UPS would stop responding and become "stuck" with a status of "0 HID objects" requiring a driver restart to recover.

Related to #2644

It might be worth looking more into why this happens in the first place. In my opinion, this is just a workaround for the real issue, or maybe there’s actually a firmware bug in the APC BX###M series.

Signed-off-by: Michał Bogdziewicz <michal@bogdziewicz.xyz>
@AppVeyorBot

Copy link
Copy Markdown

@masterwishx

Copy link
Copy Markdown
Contributor

This PR addresses an issue where the UPS would stop responding and become "stuck" with a status of "0 HID objects" requiring a driver restart to recover.

Related to #2644

It might be worth looking more into why this happens in the first place. In my opinion, this is just a workaround for the real issue, or maybe there’s actually a firmware bug in the APC BX###M series.

Interesting how will this fix affect also in my case issue when Connection timed out after every upsdrv_updateinfo... or after upsrw commands ?

Oct 22 15:15:38 server usbhid-ups[10527]: [D5:10527] hu_find_infoval: found on (value: 1)
Oct 22 15:15:38 server usbhid-ups[10527]: [D5:10527] send_to_all: SETINFO driver.state "quiet"
Oct 22 15:15:38 server usbhid-ups[10527]: [D6:10527] send_to_all: write 29 bytes to socket 13 succeeded (ret=29): SETINFO driver.state "quiet"
Oct 22 15:15:38 server usbhid-ups[10527]: [D5:10527] send_to_all: SETINFO driver.state "updateinfo"
Oct 22 15:15:38 server usbhid-ups[10527]: [D6:10527] send_to_all: write 34 bytes to socket 13 succeeded (ret=34): SETINFO driver.state "updateinfo"
Oct 22 15:15:38 server usbhid-ups[10527]: [D1:10527] upsdrv_updateinfo...
Oct 22 15:15:39 server usbhid-ups[10527]: [D2:10527] nut_libusb_get_interrupt: Connection timed out
Oct 22 15:15:39 server usbhid-ups[10527]: [D1:10527] Got 0 HID objects...
Oct 22 15:15:39 server usbhid-ups[10527]: [D1:10527] Quick update...
Oct 22 15:15:39 server usbhid-ups[10527]: [D4:10527] Entering libusb_get_report
Oct 22 15:15:39 server usbhid-ups[10527]: [D3:10527] Report[get]: (3 bytes) => 26 05 01
Oct 22 15:15:39 server usbhid-ups[10527]: [D5:10527] PhyMax = 0, PhyMin = 0, LogMax = 255, LogMin = 0
Oct 22 15:15:39 server usbhid-ups[10527]: [D5:10527] Unit = 00000000, UnitExp = 0
Oct 22 15:15:39 server usbhid-ups[10527]: [D5:10527] Exponent = 0
Oct 22 15:15:39 server usbhid-ups[10527]: [D2:10527] Path: UPS.BatterySystem.Charger.ChargerType, Type: Feature, ReportID: 0x26, Offset: 0, Size: 8, Value: 5
Sep 27 09:33:32 Server usbhid-ups[24218]: [D2:24218] send_to_one: sending TRACKING 2DDC5036-F665-4D29-BE4C-0374D091D263 0
Sep 27 09:33:32 Server usbhid-ups[24218]: [D5:24218] send_to_one: TRACKING 2DDC5036-F665-4D29-BE4C-0374D091D263 0
Sep 27 09:33:32 Server usbhid-ups[24218]: [D6:24218] send_to_one: write 48 bytes to socket 16 succeeded (ret=48): TRACKING 2DDC5036-F665-4D29-BE4C-0374D091D263 0
Sep 27 09:33:32 Server upsd[24710]: tracking ID: 2DDC5036-F665-4D29-BE4C-0374D091D263#011result: SUCCESS
Sep 27 09:33:33 Server usbhid-ups[24218]: [D5:24218] send_to_all: SETINFO driver.state "updateinfo"
Sep 27 09:33:33 Server usbhid-ups[24218]: [D6:24218] send_to_all: write 34 bytes to socket 16 succeeded (ret=34): SETINFO driver.state "updateinfo"
Sep 27 09:33:33 Server usbhid-ups[24218]: [D1:24218] upsdrv_updateinfo...
Sep 27 09:33:34 Server usbhid-ups[24218]: [D2:24218] nut_libusb_get_interrupt: Connection timed out
Sep 27 09:33:34 Server usbhid-ups[24218]: [D1:24218] Got 0 HID objects...
Sep 27 09:33:34 Server usbhid-ups[24218]: [D1:24218] Full update...

@desertwitch

Copy link
Copy Markdown
Contributor

maybe there’s actually a firmware bug in the APC BX###M series.

Wouldn't surprise me with the more recent problems and investigations in #2347.

@AppVeyorBot

Copy link
Copy Markdown

@jimklimov jimklimov added APC USB Connection stability issues Issues about driver<->device and/or networked connections (upsd<->upsmon...) going AWOL over time labels Nov 15, 2024
@jimklimov jimklimov added this to the 2.8.3 milestone Nov 15, 2024
@jimklimov
jimklimov merged commit 0f6ae03 into networkupstools:master Nov 15, 2024
jimklimov added a commit to jimklimov/nut that referenced this pull request Nov 16, 2024
…e the feature with optional `interrupt_pipe_no_events_tolerance` setting [networkupstools#2681]

Signed-off-by: Jim Klimov <jimklimov@gmail.com>
@faluc-dev

faluc-dev commented Aug 11, 2026 •

Copy link
Copy Markdown
Contributor

Field datapoints from two brand-new Back-UPS BX750MI-GR units (051d:0002, mfr date 2025-11) that extend what's described here — including a lockup state that goes beyond the interrupt pipe.

Unit 1, bench-polled via usbhid-ups 2.8.5 (macOS/arm64, libusb 1.0.30, default pollinterval 2 s): from the first minutes, intermittent control-transfer failures every few seconds (nut_libusb_get_report: ... error on various report IDs). Twice, after roughly 200 s of continuous driver runtime, this escalated to a full interface lockup — the device stopped answering string-descriptor requests and then disappeared for the host entirely (the OS's native UPS stack lost it too, so it's not a driver-claim artifact).

  • Lockup 1 cleared with a USB cable replug.
  • Lockup 2 was harder: it survived a cable replug, survived removing/restoring wall power, and notably the front-panel power button stopped working as well (press-and-hold just blinked/clicked, output stayed on) — the hang extended into the front-end controller, not just the USB block. The only thing that recovered it was a battery-disconnect cold start (wall out + battery terminal disconnected ~30 s). Worth knowing operationally, since no software-side watchdog/reconnect logic can reach that state. One more nuance observed while wedged: a freshly-plugged USB connection would not enumerate while the unit was on battery, although established connections survive on-battery transitions normally.

Unit 2, production-monitored via usbhid-ups 2.8.1 (Debian 13, Intel): same error signature at default polling — ~115 nut_libusb_get_report: Input/Output Error entries in its first 10 hours — but the driver recovers every time and no lockup has occurred so far. One tuning datapoint: raising pollinterval from 2 s to 15 s did not reduce the error rate (~15/h before, ~16/h in the first half-hour after — short window, but flat). The error timestamps align with the 30 s pollfreq full-variable sweep rather than the quick status polls, so on this firmware the failures appear to be triggered by the heavier GET_REPORT sweep (or simply time-periodic), not by overall transaction rate.

Minor additional observation from the macOS bench: usbhid-ups 2.8.5 exited with SIGSEGV twice in the device-loss path (immediately after logging Got to reconnect!) — can open a separate issue with logs if useful.

@jimklimov

Copy link
Copy Markdown
Member

Thanks for the analysis, I wonder if hardware-side lock-ups in the "bench test" build up due to reconnections - e.g. controller is busy/leaking/etc., and new connections overwhelm it even further? Or it needs some cooldown time between connection attempts (broken, add "sleep X", reconnect)?..

As for SIGSEGV, there was #3550 fixed recently - may be it.

@faluc-dev

Copy link
Copy Markdown
Contributor

Checked our bench driver logs to answer the buildup question — within a single driver run, causality ran the other way. The log covering one of the lockups shows an established connection with only the intermittent single get_report timeouts for the first ~90 s (each recovered; no reconnection attempts at all), then the device dropped, and only then did the reconnect loop begin: 79 Got to reconnect! attempts at the 2 s poll cadence over the next ~2.5 min, none successful, until we stopped the driver. So the reconnect storm was a consequence of the wedge rather than its trigger.

At the level of the whole bench session, though, the idea is harder to rule out: that evening involved far more connection setups than a production host would ever see (several driver restarts, a full HID descriptor walk, cable replugs), while the production unit sits on one long-lived connection — and only the bench unit ever wedged. If connection/enumeration stress is what accumulates in the controller, that asymmetry fits. A cooldown between reconnect attempts looks harmless-to-useful either way, though on this evidence it wouldn't have prevented the initial hang.

On the SIGSEGV: #3550 matches exactly — the bench ran v2.8.5 (the regression's first release), and both crash logs end precisely at the Got to reconnect! line, i.e. the reopen path against a wedged device, where both report-descriptor length candidates would fail. Consider it explained, thanks — no separate issue needed.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

APC Connection stability issues Issues about driver<->device and/or networked connections (upsd<->upsmon...) going AWOL over time USB

Projects

None yet

Development

Successfully merging this pull request may close these issues.

6 participants