apc_modbus: three fixes for the #3414 read-retry loop - #3571
Open
d01 wants to merge 5 commits into
Open
Conversation
The read retry loop added in networkupstools#3414 does not check exit_flag, so a driver asked to stop keeps working through its remaining retries: up to retries * response_timeout, which with non-default settings comfortably exceeds the 5 seconds upsdrvctl allows for SIGTERM before it escalates to SIGKILL (drivers/upsdrvctl.c, the "retrying harder" path). On some hardware that escalation is not merely untidy: an APC Smart-UPS X1500 (051d:0003, FW "UPS 16.0") killed mid-exchange stops serving Modbus altogether -- it accepts writes and answers nothing -- and only physically reseating the USB cable recovers it. Every clean shutdown then wedges the UPS. Break out of the loop as soon as exit_flag is set. Verified on that hardware: shutdowns now log "Signal 15: exiting" and deactivate cleanly where they previously hit "Stopping ... failed, retrying harder" followed by status=9/KILL. Signed-off-by: d01 <d01@users.noreply.github.com> Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
The retry loop from networkupstools#3414 retries only on ETIMEDOUT and gives up on every other error. That leaves out the one case where a retry is most obviously correct: a reply arrived, but it is not the reply to this request. libmodbus reports those as EMBBADSLAVE, EMBBADCRC or EMBBADDATA. On a packetised transport such as rtu_usb this is common, because a reply the device deferred past our timeout stays queued on the endpoint rather than ageing off the wire as it would on an idle serial line. The next read then collects the previous request's answer. Reading it has consumed it, so the very next attempt can succeed -- but the loop breaks out instead of making it. On an APC Smart-UPS X1500 this is exactly what happens on the first driver start after a host reboot (the self-powered UPS keeps its queue across the host's power cycle): the initial read times out, the retry collects the stale reply, and the loop gives up, so startup fails with "Can't read inventory information from the UPS". systemd then restarts the driver, and each failed start abandons further exchanges, degrading the device until only reseating the USB cable recovers it. Genuine Modbus exception responses still break out of the loop immediately: the device answering properly will not improve on a retry. Signed-off-by: d01 <d01@users.noreply.github.com> Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
The retry loop from networkupstools#3414 kept the pre-retry code's LOG_ERR inside the new loop, so every attempt is logged as an error -- including the ones the very next retry recovers, which is the exact case the loop was added to handle. On a device that needs retries routinely this floods the system log with errors the driver does not have. Measured on an APC Smart-UPS X1500 in a degraded state: ~310 LOG_ERR/min while the connection was never closed once and every read ultimately succeeded -- about 890k lines/day and 42% of the journal, doubled again by upsdrvctl forwarding the driver's stderr alongside its own syslog write. Log attempts with upsdebugx(1), and the error once, after the loop, where the read has really failed and the connection is about to be closed. Both lines carry the attempt count. Nothing is logged when exit_flag broke the loop: the driver is stopping, not failing. Signed-off-by: d01 <d01@users.noreply.github.com> Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
|
A ZIP file with standard source tarball and another tarball with pre-built docs for commit 9544af8 is temporarily available: NUT-tarballs-PR-3571.zip. |
jimklimov
added
bug
APC
modbus
service/daemon start/stop
…upstools#3571] Signed-off-by: Jim Klimov <jimklimov+nut@gmail.com>
jimklimov
added
the
AI
|
✅ Build nut 2.8.5.5063-master completed (commit f377459c07 by @d01)
|
Member
|
Great catches, thanks! |
|
✅ Build nut 2.8.5.5064-master completed (commit 955241d6e6 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 defects in the register-read retry loop added by #3414, found while
getting
apc_modbusrunning reliably on an APC Smart-UPS X1500 (051d:0003,FW "UPS 16.0") over USB. Each is device-independent; the X1500 is just the
hardware that makes all three visible at once. Compile-tested on master and
running in production (backported) on 2.8.4.
1. The loop ignores
exit_flagA driver asked to stop keeps working through its remaining retries — up to
retries × response_timeout, which with non-default settings comfortablyexceeds the 5 s upsdrvctl allows for SIGTERM before escalating to SIGKILL.
On the X1500 a SIGKILL mid-exchange leaves the device unable to serve Modbus
until its USB cable is physically reseated, so every clean shutdown wedged
the UPS. Journal signature before the fix:
2. The loop retries only ETIMEDOUT
It gives up on
EMBBADSLAVE/EMBBADCRC/EMBBADDATA— the one case where aretry is most obviously right, because a reply arrived that belongs to an
earlier request, and reading it has already consumed it. On packetised
transports (rtu_usb) a deferred reply stays queued on the endpoint rather
than ageing off the wire, so this is routine: the first driver start after a
host reboot collects a reply queued before the reboot (the self-powered UPS
keeps its state), fails, and systemd restart-loops the driver, degrading the
device further with every failed start.
3. Every attempt is logged at LOG_ERR
The pre-#3414 error log was left inside the new loop, so attempts the next
retry recovers are still reported as errors — the exact case the loop was
added for. Measured here in a degraded state: ~310 LOG_ERR/min while the
connection was never closed once and every read succeeded; ~890k lines/day,
42% of the journal (doubled by upsdrvctl forwarding driver stderr alongside
the syslog write). Attempts now log at
upsdebugx(1); the error logs once,after the loop, with the attempt count.
Context
The wider investigation (the X1500's post-reset behaviour, its reply
queueing, and the transport-level fixes in networkupstools/libmodbus#12) is
written up separately; these three fixes stand on their own and are the
device-independent part. Related: #2609, #3414.
Note on authorship
Developed with assistance from Claude (Anthropic); commits carry a
Co-Authored-By trailer to that effect. All findings were verified on real
hardware.