apcmicrolink: async USB reads, session stability, page 0 fix - #3591
Open
nmbro wants to merge 12 commits into
Open
apcmicrolink: async USB reads, session stability, page 0 fix#3591nmbro wants to merge 12 commits into
nmbro wants to merge 12 commits into
Conversation
Long-run testing of the USB HID tunnel transport against an SCL500RMI1UC found the driver dropping the session after an inconsistent interval and then failing to recover. Several distinct causes, fixed together here: * The interrupt-IN read was issued per call, so the driver only listened while it happened to be blocked waiting for a reply. This device can go several seconds between replies, and pushes unrelated HID reports on the same pipe meanwhile, so replies arriving outside that window were lost. Reads are now served by a permanently outstanding asynchronous transfer serviced by a dedicated pump thread; only that thread touches libusb's event loop, and everything else takes a lock to drain the queue it fills. Builds without libusb-1.0 or pthreads, and any failure to start the listener, still use the previous synchronous per-call read. This needs the libusb-1.0 context, exposed as nut_libusb_get_context(). * A USB bus reset was triggered off a retry count, which fired just as often for a live-but-stalled device that a reset never helped. It is now triggered only when a read, write or transfer completion has actually reported NO_DEVICE, i.e. a genuine unplug or power cycle. * The cached page 0 contents were wiped on every session (re)start, and the read queue was flushed on every session retry - the latter discarding genuine replies that had already arrived. Neither is done any more. * The authentication challenge was a fixed 0x00 0x00, making the exchange trivially predictable; it is now randomized, as APC's own client does. * When the kernel's usbhid driver reclaims the interface, every submission fails instantly with EBUSY and nothing paced the retries - one observed incident spun at roughly 14,000 failed submissions per second for over half an hour. That case now backs off and logs, rate-limited. * Warn once when built against libusb-0.1, whose interrupt-IN read did not honor its timeout on at least one tested system, hanging the driver. Also maps two further descriptor usages that were previously visible only as microlink.unmapped.*: experimental.battery.serial (the battery pack's own serial, confirmed against the compartment label on a real unit) and microlink.diag.slave_password_echo (the register the auth challenge is written to, echoed back - useful for troubleshooting, but not by itself proof that authentication was accepted). The apcmicrolink(8) USB MODE section is updated to match: it described a periodic reset attempt whenever the tunnel stayed unresponsive, which is no longer what happens, and now also notes the usbhid/EBUSY backoff. It gains a "libusb backend" subsection recording that USB mode is tested only against libusb-1.0, what goes wrong on libusb-0.1, and that the always-listening reader needs libusb-1.0 plus pthreads. Comments in apcmicrolink-usb.c were trimmed throughout: design history, references to material outside this repository, and restatements of what the code already says are gone. Use of coding helper tools and AI disclosed: Claude Code was used for development assistance. Signed-off-by: nmbro <nmbro@users.noreply.github.com>
Page 0 announces the frame width that every later frame is parsed with, and microlink_cache_object() accepted any checksum-valid copy of it. A corrupt copy is therefore unrecoverable: the bogus width becomes the length microlink_try_extract_frame_at() demands, no frame checksum- validates again, and the session dies with the device having done nothing wrong. Seen live on a Smart-UPS X 1500 (FW 03.8) in issue networkupstools#3587. The device served 60 populated pages, then emitted STOP-filled pages and restarted its page index. The wrapped page 0 was checksum-valid and announced a width of 247 inside a 16-byte frame, which replaced the correct width=16/pages=154 header decoded a second earlier. From that point the parser needed 250 contiguous valid bytes out of 19-byte records, so it never extracted another frame. A genuine page 0 always arrives in a frame of exactly the width it announces: on the first read the frame length is derived from that byte, and on every later read the frame length is the established width. So require the two to agree, and keep the previous page 0 when they do not. This is in the shared framing layer, so it applies to the serial transport as well. Use of coding helper tools and AI disclosed: Claude Code was used for development assistance. Signed-off-by: nmbro <nmbro@users.noreply.github.com>
Page 0 bit 1 (MLINK_PAGE0_FLAG_IMPLICIT_STUFFING) asks for implicit byte stuffing on the wire. Nothing in the parser implements it; the bit was only published as microlink.flag.implicit_stuffing and otherwise ignored, so a device that set it would have its frames read as if stuffing were disabled and would fail with checksum errors that point nowhere near the actual cause. No device seen so far sets the bit - both an SCL500RMI1UC and an SMX1500RM2U report flags 0x09, i.e. AUTH_REQUIRED and DESCRIPTOR_PRESENT with stuffing clear - so rather than ship an unstuffing routine that cannot be exercised or tested, say plainly what the driver is doing and ask for a report. Logged once per process at LOG_WARNING, since it is invisible at the default debug level otherwise and describes a condition the user cannot work around. Use of coding helper tools and AI disclosed: Claude Code was used for development assistance. Signed-off-by: nmbro <nmbro@users.noreply.github.com>
|
A ZIP file with standard source tarball and another tarball with pre-built docs for commit 9ec01d9 is temporarily available: NUT-tarballs-PR-3591.zip. |
Contributor
Author
|
got a fix for the "missing enum cases" ready, I'm just waiting for the CI pipeline to run through before I push it - in case I need to touch up some more things |
|
✅ Build nut 2.8.5.5143-master completed (commit 5eb9e8dfdb by @nmbro)
|
Member
|
A CI run across so many systems can take about half a day (and now competes with some other PRs), so perhaps better you push the fix and I cancel the earlier build as it had started "just recently", relatively speaking. |
Contributor
Author
|
I'm investigating my unit going into a locked out state again. it's a special kind of lock out this time - I'm getting all of the static data from the microlink tunnel, but the dynamic data: ie. battery status, ups status on the microlink are just all 0 and it looks like my AUTH is not getting accepted by the UPS for some reason. microlink sure is a fun and fantastic proprietary protocol |
CodeQL flagged the switch on transfer->status as handling only two of the enum's values by name. Behaviour is unchanged - everything not cancelled or gone still falls through to the resubmit below - but the remaining states are now listed explicitly so the intent is readable and a future libusb addition shows up as a warning rather than silently joining the default. Use of coding helper tools and AI disclosed: Claude Code was used for development assistance. Signed-off-by: nmbro <nmbro@users.noreply.github.com>
The standard-HID-PDC fallback existed but could not engage in the case it was written for. Found on an SCL500RMI1UC that answered every poll while reporting an all-zero state: ups.status stayed empty for over two days with usable HID PDC reports arriving on the same endpoint the whole time, and upsmon therefore had nothing to act on. Four separate reasons it never took over, each fixed here: * microlink_start_session() refreshed last_poll_success on a bare handshake, so a device that answered the handshake but sent no data looked freshly polled forever. Data freshness is now tracked separately, and only real polled frames advance it. * upsdrv_updateinfo() treated a successful reconnect as good data. A handshake proves the device answers, not that the tunnel delivers. * Startup called fatalx() when no fallback snapshot had been decoded yet, even where the device clearly exposes the usages - they simply had not arrived in the startup window. It now starts and publishes them when they do. The old message also claimed no fallback was available on a device whose descriptor advertised one. * Staleness alone was not enough: this device answers on time and reports zeroes, so the data is fresh and useless. A poll that yields no ups.status flag at all now hands over too. MLINK_HID_FALLBACK_MAX_AGE_SEC goes from 10s to 30s. A usbmon capture showed the two streams are not concurrent: PDC reports arrive every 6.0s while the tunnel is idle, then stop for 19.2s whenever the device services tunnel traffic. A 10s window expired inside that gap, so the fallback became unpublishable exactly when the tunnel was also producing nothing, and ups.status went empty once per cycle. MLINK_DATA_STALE_SEC moves to 45s to stay above it. Handover is deliberately asymmetric. The fallback takes over immediately but only hands back after the Microlink source has looked plausible for 30s continuously; without that the two swapped on alternate polls, measured at 56 handovers in 3 minutes, and a status that flips every 2s is worse than one that lags a recovery. Plausibility is judged only from ups.status, which is rewritten every poll - testing battery.charge made the fallback read back a value it had published itself and hand over to a dead source. microlink_publish_hid_fallback() now writes its measurements before committing status, and states the charging condition explicitly. dstate's status_commit() infers CHRG/DISCHRG from battery.charge movement when the driver reports neither, and it was comparing the degenerate Microlink value against the previous fallback one and synthesizing a DISCHRG that contradicted the OL being set in the same breath. Handovers are logged with their reason at debug level 1, once per transition. A device that answers normally while reporting nothing usable also warns at LOG_WARNING, hourly, and publishes microlink.diag.status_degenerate: a USB bus reset does not clear that state (tested, along with deauthorize and driver unbind - none re-enumerate the device), so the user needs to know the UPS itself likely needs a power cycle. Use of coding helper tools and AI disclosed: Claude Code was used for development assistance. Signed-off-by: nmbro <nmbro@users.noreply.github.com>
Root cause: this driver fetched one tunnel record per pollinterval. The device answers requests roughly every 2-3 ms when asked continuously (as PowerChute does), but gates its live-measurement pages behind a slave-password handshake it does not acknowledge until about 20 further exchanges after the response goes out. At one record per pollinterval the handshake's acknowledgement was never collected, and the driver's own readiness check treated sending the response as "done" - so every measurement read 0 indefinitely on a device that was answering normally the whole time. microlink_poll_burst() now drives the tunnel like APC's own client: keep requesting the next record until the device stops answering, once per upsdrv_updateinfo(), budgeted to one full pass over page0.count (bounded by MLINK_POLL_BURST_MIN/MAX and an MLINK_POLL_BURST_MAX_SEC wall-clock ceiling so a slow-answering device cannot hold updateinfo() open indefinitely). The burst also keeps going past its budget while a handshake is in flight (microlink_auth_pending(), MLINK_AUTH_GRACE_SEC), so a session re-established mid-updateinfo() does not send its auth response on the burst's last record and then go quiet before collecting the answer. microlink_check_auth_result() diagnoses the handshake explicitly: experimental.microlink.diag.auth_status / .auth_refused, an hourly LOG_WARNING while refused, and a one-time warning if AUTH_STATUS ever sets a bit this driver does not know about. Readiness still accepts authentication_sent on its own once the grace window closes - a refused handshake still leaves identity data and the standard-HID fallback worth publishing. upsdrv_cleanup() now sends STOP before closing the session. Seen live on an SCL500RMI1UC: exiting mid-burst left the device answering a later client's INIT with whatever page its cursor had reached instead of page 0, and it would not resync until re-enumerated. Also, a batch of descriptor-map corrections gathered while chasing the above (each verified against a live SCL500RMI1UC, several by watching PowerChute write or read the same usage): * 2:4.7.28 and 2:4.7.49 are percentages of nominal, not absolute power - they were mapped straight onto ups.realpower/ups.power, so both read two orders of magnitude low and ups.load then divided one of them by its nominal rating a second time. 2:4.7.28 now feeds ups.load directly, and microlink_publish_derived_power()/microlink_publish_scaled_percent() derive ups.realpower and ups.power (the apparent-power side kept as experimental.ups.load.apparent, since NUT has no standard name for it) by scaling against the nominal ratings, matching PowerChute's own numbers. * ups.test.result now comes from 2:4.5.11 (the battery-scope test, which actually stepped Pending -> InProgress -> Passed during a PowerChute- triggered self test) rather than 2:11 (UPS-scope, never moved off None on this hardware). 2:11 stays mapped under an experimental name and microlink_publish_test_result() promotes it to ups.test.result on any device that lacks the battery-scope usage - descriptor attribute IDs are scope-relative, so a differently built model could populate the other one. * 2:4.5.18 is a self-test *schedule* enum, not the interval-in-seconds ups.test.interval calls for (two of its members have no interval at all). It is now experimental.microlink.battery.test.schedule, and microlink_publish_test_interval() derives ups.test.interval from the members that do imply a recurring period, matched on the raw bits rather than the label text. * New mappings: input.sensitivity (3:25, values confirmed against PowerChute's dropdown), ups.beeper.status (2:4.B.3A, both values round- tripped by writing them from PowerChute), experimental.battery.firmware (2:4.5.9.4A) and experimental.statistics.battery.transfers (2:4.5.F.59, PowerChute's "Number Of Times On Battery"). * Dropped the duplicate device-status publish at 2:4.A: it used the same apc_status_map already consumed via microlink_desc_publish_map into ups.status/alarms, so the second copy was strictly worse (missing LB and the charger flags) rather than a distinct value. * Renamed for consistency: experimental.device.sku and experimental.battery.sku to device.part / experimental.battery.part (they are part numbers, not SKUs); the microlink.* diagnostic namespace to experimental.microlink.* throughout, since none of it is a settled name; and 2:4.9.42 from experimental.device.sku to device.part directly (an existing standard name this driver had not picked up). Use of coding helper tools and AI disclosed: Claude Code was used for development assistance. Signed-off-by: nmbro <nmbro@users.noreply.github.com>
Adds docs/apcmicrolink-descriptors.txt, covering the frame/page/descriptor structure this driver parses: frames as [page id][width data bytes][2 byte checksum], the flat-blob assembly from page N at offset N * width, and the descriptor table that maps this wire structure to descriptor paths - themselves MIB-like, with attribute IDs that are scope-relative (the same .11 means "test result" whether it hangs off the battery, UPS, or another collection). Everything in it was derived from a live APC SCL500RMI1UC, for anyone extending drivers/apcmicrolink-maps.c to cover more of a device. Wired into the developer guide's build via docs/Makefile.am and docs/new-drivers.txt. Use of coding helper tools and AI disclosed: Claude Code was used for development assistance. Signed-off-by: nmbro <nmbro@users.noreply.github.com>
|
✅ Build nut 2.8.5.5145-master completed (commit e91d8e2b53 by @nmbro)
|
Contributor
Author
|
Pushed a follow-up fixing the CI failures and the lockout I mentioned above. CI: two The lockout was our polling cadence, not the UPS. The driver fetched one Also: the HID-PDC fallback now engages when the tunnel answers but reports One question: Use of coding helper tools and AI disclosed: Claude Code was used for |
libusb_transfer_status already had every enumerator listed as an explicit case, so a trailing default was dead code under Clang's -Wcovered-switch-default (-Werror). Dropping the default then broke the fightwarn build instead: -Wswitch-default demands a default on every switch regardless of enumeration coverage. The two rules cannot both be satisfied by the source text, so suppress -Wswitch-default for this switch via the guarded-pragma pattern already used in apcmicrolink.c, matching m4/ax_c_pragmas.m4's per-warning detection. Signed-off-by: nmbro <nmbro@users.noreply.github.com>
|
❌ Build nut 2.8.5.5146-master failed (commit 9a42516a54 by @nmbro) |
|
❌ Build nut 2.8.5.5146-master failed (commit 9a42516a54 by @nmbro) |
jimklimov
added
APC
USB
Incorrect or missing readings
…upstools#3591] Signed-off-by: Jim Klimov <jimklimov+nut@gmail.com>
|
✅ Build nut 2.8.5.5147-master completed (commit ce297f1ce1 by @jimklimov)
|
|
✅ Build nut 2.8.5.5147-master completed (commit ce297f1ce1 by @jimklimov) |
nmbro
force-pushed
the
apcmicrolink-usb-pr
branch
from
August 30, 2026 11:42
1c18566 to
c753e96
Compare
|
❌ Build nut 2.8.5.5148-master failed (commit 6203c48399 by @nmbro) |
|
❌ Build nut 2.8.5.5148-master failed (commit 6203c48399 by @nmbro) |
|
✅ Build nut 2.8.5.5149-master completed (commit 29efc51250 by @jimklimov)
|
|
✅ Build nut 2.8.5.5149-master completed (commit 29efc51250 by @jimklimov) |
|
✅ Build nut 2.8.5.5154-master completed (commit 5b4c9a5f9b by @nmbro)
|
Member
|
I'll have to check precedents in other drivers about |
…sults [networkupstools#3591] Signed-off-by: Jim Klimov <jimklimov+nut@gmail.com>
|
✅ Build nut 2.8.5.5155-master completed (commit cbc317b8f5 by @jimklimov)
|
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
3 participants
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Three commits against the existing experimental
apcmicrolinkdriver: a reworkof how USB reads are done, a set of long-run session-stability fixes that came
out of it, and one framing bug found via issue #3587.
Why
The USB HID tunnel transport added in #3579 worked, but a session would drop
after an inconsistent interval and then fail to recover. Running it against an
APC Smart-UPS 500 (SCL500RMI1UC) over multi-day sessions turned up several
distinct causes rather than one.
What changed
Reads are no longer issued per call. The driver used to start a fresh
interrupt-IN transfer each time it wanted a byte, so it was only listening while
it happened to be blocked waiting for a reply. This device can go several
seconds between replies and pushes unrelated HID reports on the same pipe in the
meantime, so replies arriving outside that window were simply lost. A single
transfer is now kept permanently outstanding, serviced by a dedicated pump
thread; only that thread touches libusb's event loop, and everything else takes
a lock to drain the queue it fills. Builds without libusb-1.0 or pthreads, and
any failure to start the listener, fall back to the previous synchronous read.
This needs the libusb-1.0 context, which is exposed as
nut_libusb_get_context()indrivers/libusb1.c(guarded byWITH_LIBUSB_1_0;libusb-0.1 has no equivalent object to hand out).
A USB bus reset is now triggered only on a genuine disconnect. It used to
fire off a retry count, which hit just as often for a live-but-stalled device
that a reset never helped. It now fires only when a read, write or transfer
completion has actually reported
NO_DEVICE.Three smaller session fixes: the cached page 0 contents are no longer wiped
on every session (re)start; the read queue is no longer flushed on every session
retry (that was discarding replies that had already arrived -- an isolated test
put it at roughly half of otherwise-valid replies); and the authentication
challenge is randomized instead of being a fixed
0x00 0x00.A page 0 that contradicts itself is now rejected. Page 0 announces the frame
width every later frame is parsed with, and any checksum-valid copy of it was
accepted. A corrupt copy is therefore unrecoverable: the bogus width becomes the
length the frame parser demands, nothing checksum-validates again, and the
session dies with the device having done nothing wrong. A genuine page 0 always
arrives in a frame of exactly the width it announces, so the two are now
required to agree. This is in the shared framing layer, so it applies to the
serial transport too.
Diagnostics: warn once when built against libusb-0.1 (untested for this
driver, and on one system its interrupt-IN read did not honor its timeout and
hung the driver); back off and log, rate-limited, when the kernel's
usbhiddriver has reclaimed the interface and every submission fails instantly with
EBUSY(one observed incident spun at roughly 14,000 failed submissions/sec forover half an hour); and warn once if a device ever sets the page 0 implicit
byte-stuffing bit, which this parser does not implement and previously ignored
silently.
Two further descriptor usages mapped:
experimental.battery.serial(thebattery pack's own serial, distinct from
ups.serial; confirmed against thecompartment label on a real unit) and
microlink.diag.slave_password_echo(theregister the auth challenge is written to and echoed back -- troubleshooting
visibility only, and explicitly not proof that authentication was accepted,
since a device that blindly echoes any register write would look identical).
Hardware
Developed and tested against an APC Smart-UPS 500 (SCL500RMI1UC) over USB, by a
single tester, including deliberate fault injection: USB replug, power cycles,
driver restarts mid-handshake, and forced fallback. No other USB Microlink model
has been tested, and USB mode remains experimental relative to the rest of this
already-experimental driver.
Limitations, and what this does not fix
The page 0 fix came out of issue #3587 (
apcmicrolinkfailing to start on anSMX1500RM2U). It does not make that device work. It removes a
self-inflicted unrecoverable state -- the driver no longer wedges its own parser
-- but that device stops serving pages at 0x3C while its descriptor does not
begin until page 0x48, so startup still will not complete there. I do not have
that hardware; the fix was derived from the debug log in that issue and verified
by checking the guard against the two captured page 0 frames (the good one is
accepted, the corrupt one rejected). Discussion continues in #3587.
experimental.battery.serialis in theexperimental.*namespace asdocs/nut-names.txtprescribes. Happy to raise it on nut-upsdev to standardizeif that seems worthwhile.
Use of coding helper tools and AI disclosed: Claude Code was used for
development assistance. The code and documentation were reviewed against the
NUT style guide, specifically for non-ASCII punctuation and for compiler pragmas
(none are introduced here).
Checklist
General points:
tools/check-source-nonascii.plclean)Driver PRs:
DRIVER_VERSION(0.02 -> 0.03)scripts/upower/95-upower-hid.hwdbanddata/driver.list.indocs/nut-names.txt; non-standard points useexperimental.*or the driver's existingmicrolink.*namespaceGeneral C code:
size_tused where the language or libraries expect it
upsdebugx()/upslogx()/fatalx()and NUT allocation helpers throughoutMakefile.amrecipe changes were neededDocumentation:
NEWS.adocbullets addeddocs/man/apcmicrolink.txtupdated: the USB MODE section described aperiodic reset on an unresponsive tunnel, which is no longer what happens,
and it gains a "libusb backend" subsection
make spellcheckpasses, nodocs/nut.dictchanges neededUPGRADING.adocnot touched -- nothing here is breakingdocs/acknowledgements.txtnot touched -- not vendor-backed workVerification on this branch:
make distcheckpasses (with real asciidoc manpage generation, test suite 10/10),
make spellcheckpasses, and the driverbuilds without warnings.