Repository navigation
Conversation
Builds on the command-timeout reporting by attempting recovery rather than only reporting the failure. Background: when the debug board stops acknowledging, waitForCompletion() times out on every subsequent command. Logs from a failing bench show that reopening the TACDev handle does not clear this - the handle opens fine because the port still exists, while the transport underneath stays stuck. In that incident the condition persisted for over two hours and was only cleared when the board physically re-enumerated on USB. Changes: - Add TACDriveThread::resetTransport(), a virtual defaulting to false so transports that cannot be reset keep their existing behaviour. - Implement it for TACPIC32CXDriveThread: clear buffers, close, delete and reopen the QSerialPort. The replacement port is a new object, so the readyRead/errorOccurred connections that run() establishes are re-wired, otherwise readyRead would never fire again and every read would time out. - Implement it for TACLiteDriveThread: close and reopen the FTDI chipset to force fresh FT_OpenEx handles. openFTDIDevice() only opens when isOpen() is false, so the close must happen first or the reopen is a no-op. - setPinState() and quickCommand() now reset the transport and retry once before throwing TAC_COMMAND_TIMEOUT. quickCommand() covers bootToEDL and the other button commands. - SetExternalPowerControl: add the missing try/catch. externalPowerControl() can throw, and this export had no handler, so a TACException could escape across the C boundary. Note on naming: the string 'Wait for completion timed out' is emitted by the generic TACDriveThread::waitForCompletion() and is not FTDI-specific, despite how it is referenced downstream. Verified: x64 Debug and Release build clean. Read-only API test against an attached Alpaca Lite board passes 16/16 - load, enumerate, open, property reads, close, and bad-handle rejection with no exception escaping an export. Not verified: that reopening the transport clears the specific wedge seen in production. That state cannot be induced from the host, so it needs a bench where the fault recurs. The new log lines (resetTransport succeeded/failed, retry after reset) report the outcome directly.
Fixes a data race and use-after-free introduced by the previous commit. resetTransport() ran on the thread issuing the command and tore down the transport directly - closing and deleting the QSerialPort, or closing the FTDI chipset. But those objects belong to run() on the drive thread, which reads and writes them continuously: chunk = _serialPort->readAll(); _serialPort->write(framePackage->_codedRequest); _serialPort->waitForReadyRead(10); _ftdiChipset->write(pin, state); Deleting _serialPort from another thread while run() dereferences it is a use after free, and QSerialPort must only be used from its owning thread. This could hang or crash rather than recover. Now resetTransport() only posts a request and waits on a condition variable; the drive thread services it in processPendingTransportReset() and does the work in performTransportReset(). The reset is serviced at the top of the run() loop, before the next frame is picked up, so the transport is never torn down mid-operation. Details: - resetTransport() returns false immediately if the drive thread is not running, rather than waiting for a reset nobody will service. - The wait is bounded at 15s. If the drive thread is itself wedged the caller reports failure and surfaces the original timeout instead of hanging. - On timeout the request is withdrawn, so a later reset is not serviced by a stale flag after the caller has given up. - performTransportReset() disconnects the port signals before teardown, so a queued readyRead cannot be delivered to a destroyed object. - run() wakes a blocked caller on exit, and tolerates a null _serialPort in the idle path, since a failed reopen leaves it null. Verified: x64 Debug and Release build clean. Read-only API test passes for init, bad-handle rejection and exception safety. Device enumeration was not re-tested as the board was disconnected at the time; count=0 was correct for that state. Not verified: recovery behaviour under a real wedge, which needs a bench where the fault recurs.
This fault is intermittent, slow to reproduce and only observable through logs, but the logs did not carry enough to diagnose it. Two investigations so far were spent reconstructing information the code could simply have recorded. What was missing: - 'Wait for completion timed out.' was the entire message. No command, pin, port or elapsed time. On 10/2 there were 177 of these and the command had to be inferred from the following line each time. - A command that took 11 minutes but did eventually complete was only visible as 'elapsed: 666140 (ms)' inside a frame dump, so it read as normal. - The timeout, reset and retry were three separate entries that had to be correlated by hand. Changes: - waitForCompletion() now reports elapsed time, port, drive train and the command that stalled. The leading text stays exactly 'Wait for completion timed out' because TacService matches that substring to trigger a reinitialize; context is appended, not substituted. - Added a 'Slow command completion' warning above 1s, so a degrading transport is visible before it fails outright. - Added setLastCommandDescription(), set by setPinState(), sendCommandSequence() and externalPowerControl() on both transports, so a timeout can name the operation. - Added a single 'TIMEOUT RECOVERY' line reporting command, reset outcome, retry outcome and port together. Noise is not a concern at this volume: the 10/5 session was 2965 lines over 72 minutes, and these lines only appear on a timeout or a slow command. Verified: x64 Debug and Release build clean. Confirmed the emitted literal still begins with the exact string TacService matches on.
The first version of this reset reopened the port and immediately reported
success. Bench logs show why that was not enough: five cycles between 11:43
and 11:56, every one reopening in 30-90 ms and then failing the retry.
11:43:02.991 Wait for completion timed out.
11:43:03.006 performTransportReset: resetting serial transport
11:43:03.057 performTransportReset: succeeded <- 51 ms
11:43:08.724 retry after reset failed
Comparing the two open paths explains it. Normal startup opens the port, then
run() services the queued clearBuffer and a platformID request, and the board
answers about 530 ms later:
19:57:07.946 Com port COM9
19:57:08.477 Request: echo 1 <- handshake
... *IDN?, board identifies itself
The reset path did none of that. openSerialDevice() queues clearBuffer, but
performTransportReset() is called from inside the run() loop, so nothing
drained it before the caller's retry went on the wire. The port was open and
the conversation had never been established.
Changes:
- Discard protocol state on teardown. A partially assembled frame, a pending
frame awaiting a response, or queued commands from the timed-out operation
would otherwise frame the reopened connection against a stale conversation,
which is indistinguishable from an unresponsive board.
- Settle for 500 ms before reopening, rather than reopening in ~50 ms.
- After reopening, issue platformID() and drain the handshake in
drainHandshake(), mirroring what run() does at startup. Bounded at 5s, well
inside the caller's 15s reset timeout.
- Return success only when the board has actually identified itself. Reporting
success on a reopened-but-silent port is what made the earlier attempt look
like the reset had worked when the retry could never succeed.
Recovery is already re-attempted on each subsequent failing command: there is
no suppression flag, so a later command that times out runs the whole sequence
again. The bench log confirms this - five independent attempts across 13
minutes.
Verified: x64 Debug and Release build clean.
Not verified: whether a full reinitialization actually recovers the board. If
the retry still fails with the handshake reported as 'no response', the fault
is below the host transport and the next step is the firmware/USB path rather
than more software recovery.
Resolves conflicts in STM32Device.h/.cpp. develop commit 5d29d99 ('Fix battery pin toggle failure from QTAC UI') removed STM32Device::setPinState() entirely. This branch had changed that same override to return bool so a timeout could propagate. Took develop's deletion. The override only applied pin inversion before delegating to _AlpacaDevice::setPinState(), and inversion is handled in _STM32PlatformConfiguration::getPinInvertedState(), so removing it loses nothing. With the override gone, STM32 callers reach _AlpacaDevice::setPinState() directly and pick up the timeout propagation from this branch without needing a signature change here. Verified: x64 Debug and Release build clean after the merge.
powerOff and bootToEDL could return NO_TAC_ERROR in about a millisecond while
the board never moved. Bench evidence, 2026-10-08 03:21:
QUTS: Entering sendCommand 03:21:29.827
Exiting sendCommand 03:21:29.828 <- 1 ms
Alpaca: ====== powerOff start ====== <- queued, never completed
(no powerOff finish, no on_pinStateChanged)
Cause: waitForCompletion() loops only while _waitForCompletion is set. If the
flag is already clear on entry the loop is never entered and it returns true,
so quickCommand() reports success without the board acknowledging anything.
SendCommand() arms the flag before calling in, via _setCommandState(), which
is why timeouts were detected correctly on that path - including the transport
resets observed recovering at 02:49 and 03:25. _quickCommand() did not, so
powerOn, powerOff, bootToFastboot, bootToUEFI, bootToEDL and
bootToSecondaryEDL could not detect a timeout at all.
This matters most when only the underlying COM port re-enumerates and the TAC
Device protocol handle does not. QUTS emits no protocol-removed callback in
that case, so TacService has no event to react to and the result code is the
only remaining signal - and it was reporting success.
Fix: call setWaitForCompletion() in _quickCommand() before quickCommand(),
matching the pattern _setCommandState() already uses. The SendCommand path is
untouched, so the currently working full re-enumeration case is unaffected.
Logging added so the next occurrence is self-evident rather than inferred from
timing:
- completionArmed=yes|NO when a sequence is queued, with the entry count
- an explicit warning when the flag is not armed and the wait cannot verify
- completion confirmed|timed out after the wait
- the failing result and message in _quickCommand's exception handler
Verified: x64 Debug and Release build clean.
Not verified: whether the transport reset recovers a COM-port-only
re-enumeration. The two observed recoveries followed idle stalls, not a
confirmed port cycle. The new logging will show this on the next occurrence.
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
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.
Summary
Device commands could report success even when the command never completed. This happened when the communication port was not actually open, or when a device did not acknowledge a queued command within the completion timeout.
This change makes command completion status observable, and adds an automatic recovery attempt so that a device which has stopped responding can be brought back without restarting the application.
Issue
The completion wait detected a timeout, logged it, and then cleared the same internal state used to represent successful completion. The wait function returned no status, so callers could not distinguish a completed command from a timed-out command.
The result was discarded at every layer of the command path:
Queued multi-step command sequences had the same problem. They were treated as successful as soon as they were queued, without waiting for or validating completion.
A common trigger is a port that could not be opened, for example because another process already holds it. Opening the device correctly reported a failure, but if an application continued issuing commands anyway, those commands were queued against a port that was never usable and still returned success. An automation script could receive a success result for an operation such as a power or boot-mode request while the device state never changed, and the problem would only surface later through unrelated symptoms.
A second trigger is a debug board that stops acknowledging mid-session, for example after an unexpected USB re-enumeration. In that state every subsequent command times out, and reopening the device handle does not help because the underlying transport object is still the same unusable instance.
Fix Direction
Completion status is propagated through the command stack rather than discarded:
truefor completion andfalsefor timeout.A timed-out command now triggers one transport recovery attempt before failing:
Recovery runs on the thread that owns the transport.
QSerialPortand the FTDI handles must only be used from their owning thread, and the drive thread reads and writes them continuously, so the requesting thread posts a request and waits for the drive thread to perform the work. The wait is bounded, so a wedged drive thread reports failure instead of blocking the caller indefinitely.Diagnostics for this class of failure were improved:
API Changes
TACDEV_COMMAND_TIMEOUT = 7to the public C API.TACDEV_COMMAND_TIMEOUT = 7and its error text to the Python API.Compatibility
Binary and source compatibility are preserved. The new value is additive, existing codes keep their values, and no exported signature changed. Existing binaries do not need to be rebuilt to keep working.
What applications should expect now
0.7(TACDEV_COMMAND_TIMEOUT) instead of0.GetLastTACError()returns a human-readable reason for the failure.RuntimeErrorfor timed-out commands, consistent with other failures.A command that previously appeared to succeed while doing nothing may now take a few seconds longer before returning, because a recovery attempt is made first. Applications that already check result codes need no changes. Applications that ignored result codes may begin to see failures reported for operations that were silently failing before.
Port open failures
Device open behavior is not changed by this PR:
OpenHandleByDescription()already reported failure by returning a bad handle (0) and setting an error message, and it still behaves that way.What changes is the behavior after a failed or unusable open. Commands issued in that state previously returned success; they now return
7with an error message. Checking the result of the open call remains the recommended first step, because it reports the failure immediately rather than after a command timeout.Validation
x64Debug and Release.Known limitations