Skip to content

perf(device): wake the SCPI text exchange on the line, not on a 50ms tick - #666

Merged
tylerkron merged 6 commits into
mainfrom
perf/485-event-driven-text-exchange
Aug 26, 2026
Merged

tylerkron merged 6 commits into
mainfrom
perf/485-event-driven-text-exchange

Conversation

@tylerkron

Copy link
Copy Markdown
Contributor

Every SCPI text exchange — every SD listing, every diagnostics query, every LAN-info call, and the three exchanges a connect makes — decided that the device had finished answering by waking up every 50 ms and comparing line counts. That polling is the smaller half of the ~700 ms of fixed overhead issue #485 describes, but it is the part that is pure waste: an exchange whose inactivity window expired 1 ms after a tick still sat there until the next tick, and a reply that landed 1 ms after a tick was not noticed until the next one. It also woke a thread-pool thread twenty times a second for the whole life of every exchange, on an otherwise idle device.

The wait loop now waits on a signal instead. The parse handler that already appends each line to the collected list raises a TaskCompletionSource under the same lock it appends under, and the loop registers for that signal under the same lock — so a line that arrives between the loop's last look and its next wait either is already visible to it or wakes it, never neither. Both phases, both timeouts and the overall responseTimeoutMs * 5 ceiling are exactly what they were; only the 50 ms quantisation is gone. The loop's deadlines also move from DateTime.UtcNow to the exchange's existing Stopwatch, because they are elapsed-time budgets and a stepping wall clock would otherwise move them under a request already in flight.

What a reviewer should push back on. Two threading assumptions. First, the TaskCompletionSource is deliberately not a SemaphoreSlim: the signal is raised on the text consumer's reader thread, which can outlive the exchange (its stop and its dispose are both time-bounded), so anything needing disposal could be signalled after disposal — a TCS never needs disposing and TrySetResult on a stale one is a no-op. Second, it is constructed with RunContinuationsAsynchronously; without that the reader thread would run the exchange's continuation itself, i.e. resume the exchange — including the consumer stop that joins that very thread — on the thread being joined. Neither the signal nor its absence can hang the exchange: every wait is bounded by the same inactivity window the poll loop used, so a signal that never fires degrades to exactly today's timeout rather than to a deadlock.

Measurements. Bench Nq1 on /dev/cu.usbmodem1101, USB serial, Daqifi.Core.Cli --serial /dev/cu.usbmodem1101 --lan-chip-info (connect + InitializeAsync's three exchanges + one LAN-info text exchange + disconnect), Release build against this branch vs. origin/main, timed with time on the whole process:

run 1 run 2
origin/main 6.15 s —
this branch 6.27 s 6.00 s

That is honestly a wash, and it is worth saying so plainly: the saving here is roughly 25–75 ms per exchange (up to one tick of detection latency plus up to one tick of tail), and four exchanges of that is well inside the run-to-run noise of a connect. The costs that would actually move this number are the ones this PR deliberately does not touch — see below. What this change does deliver measurably is the loop's shape: the exchange now ends when its inactivity window ends rather than at the next tick, and an idle device stops paying 20 wakeups/second per in-flight exchange (relevant to #491 item 1, which is not mine and is not otherwise addressed here).

Verification. Full suite green on net9.0 and net10.0 under -warnaserror (3858 + 217 passing). Two guarding tests were added to TextExchangeLineFramingTests before the refactor and confirmed passing against the unchanged polling code: one pins that every arriving line restarts the inactivity window (a device that dribbles five fragments out over more than one completion timeout must still return all five — a loop that measured its deadline from when it started waiting would drop the tail), and one pins that the wait stays cancellable. The fragments are paced by the reader thread's own idle reads rather than by a delay on the test thread, so a starved thread pool cannot stretch a gap into a false completion. The existing OnReplyWaitCompleted seam from #650 is what proves the branch taken is unchanged in every framing case.

Deliberately deferred, and none of it is a claim that it does not matter:

I will open a follow-up issue covering the deferred items.

closes #485

Not merging — for review.

tylerkron and others added 2 commits August 24, 2026 13:14
…lability

Both properties an event-driven rewrite of the loop could silently break, asserted
against the unchanged polling implementation first.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
The reply wait loop polled the collected-line count every 50ms, so an exchange
finished up to a tick after its inactivity window actually expired and noticed
the first reply up to a tick late. It now waits on a signal raised by the parse
handler, registered under the same gate the handler appends under so no arrival
can be missed. Both phases, both timeouts and the overall ceiling are unchanged.

Deadlines move from DateTime.UtcNow to the exchange's Stopwatch: they are
elapsed-time budgets, and a stepping wall clock would move them mid-request.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
@tylerkron
tylerkron requested a review from a team as a code owner August 24, 2026 19:21
@tylerkron

Copy link
Copy Markdown
Contributor Author

/agentic_review

@tylerkron

Copy link
Copy Markdown
Contributor Author

Follow-up for the deferred items opened as #667.

@qodo-code-review

Copy link
Copy Markdown

PR Summary by Qodo

Perf: make SCPI text exchanges wake on line arrival (remove 50ms polling)

✨ Enhancement 🧪 Tests 🕐 40+ Minutes

Grey Divider

AI Description

• Replace 50ms polling with a line-arrival signal in the SCPI reply wait loop.
• Preserve existing two-phase timeouts while removing tick quantization via Stopwatch timing.
• Add tests covering fragmented replies and cancellation while awaiting the first response.
Diagram

graph TD
  A["SCPI caller"] --> B["Text exchange"] --> F["Reply wait loop"] --> H["Return / timeout"]
  E["Reader thread"] --> G["Line parse handler"] --> C["Collected lines (gate)"] --> D["Line signal (TCS)"] --> F
Loading
High-Level Assessment

The following are alternative approaches to this PR:

1. SemaphoreSlim / AsyncAutoResetEvent-style primitive
  • ➕ Models repeated signals naturally if many lines arrive quickly
  • ➕ Familiar synchronization primitive for some reviewers
  • ➖ Requires disposal discipline; reader thread may outlive exchange and signal after dispose
  • ➖ Risk of deadlock if continuations run inline on the reader thread unless carefully configured
2. System.Threading.Channels for line delivery
  • ➕ Clear producer/consumer separation; naturally buffers lines
  • ➕ Can unify “line arrived” and “read line” into one abstraction
  • ➖ More invasive refactor: introduces an additional queue next to collectedLines
  • ➖ Would still need careful lifetime/cancellation handling around consumer thread shutdown
3. Single shared monitor/pulse on collectedLinesGate
  • ➕ No extra allocation per wait; uses the existing lock
  • ➕ No extra Task objects
  • ➖ Harder to implement correctly with timeouts + cancellation without reintroducing polling
  • ➖ More error-prone around missed pulses/spurious wakeups and async waits

Recommendation: The PR’s TaskCompletionSource-based wakeup (with RunContinuationsAsynchronously and lock-coordinated registration) is a strong fit for this problem: it removes quantization while keeping the existing timeout semantics, avoids disposal hazards given the reader thread’s bounded-but-independent lifetime, and prevents the reader thread from running continuations that could join itself. Alternatives exist, but they are either more invasive (Channels) or easier to get subtly wrong (monitor/pulse, disposable primitives).

Files changed (2) +220 / -36

Enhancement (1) +107 / -26
TextExchangeEngine.csReplace 50ms polling with lossless line-arrival signaling in wait loop +107/-26

Replace 50ms polling with lossless line-arrival signaling in wait loop

• Reworks the reply wait loop to block on a TaskCompletionSource signaled by the parse handler when a new line is appended, eliminating the 50ms polling tick while preserving the same two-phase inactivity timeouts and overall ceiling. Uses the exchange Stopwatch (elapsed budgets) instead of DateTime.UtcNow for deadlines, and registers/clears the waiter under the same lock as line appends to prevent missed arrivals; WaitAsync remains bounded and cancellation-aware.

src/Daqifi.Core/Device/Internal/TextExchangeEngine.cs

Tests (1) +113 / -10
TextExchangeLineFramingTests.csAdd tests for fragmented replies and cancellation; extend scripted transport +113/-10

Add tests for fragmented replies and cancellation; extend scripted transport

• Adds coverage to pin two key properties of the reply wait loop: inactivity timeout restarts on every received line, and the wait remains cancellable while awaiting the first response. Extends the test harness transport to release replies in paced fragments driven by the reader thread’s own read cadence, and updates the helper CallAsync to accept custom completion timeouts and cancellation tokens.

src/Daqifi.Core.Tests/Device/TextExchangeLineFramingTests.cs

@qodo-code-review

qodo-code-review Bot commented Aug 24, 2026 •

Copy link
Copy Markdown

Code Review by Qodo

🐞 Bugs (0) 📘 Rule violations (0) 📜 Skill insights (0)

Grey Divider


Remediation recommended

1. Per-line TCS allocation churn ✗ Dismissed 🐞 Bug ➹ Performance
Description
The new wait loop allocates/awaits a TaskCompletionSource-based signal and the parse handler clears
it on every received line, forcing a new TCS to be created on the next wait. Large multi-line
replies (e.g., SD listings) will therefore create many tasks/continuations in a hot path,
potentially offsetting some of the intended perf gains for chatty exchanges.
Code

src/Daqifi.Core/Device/Internal/TextExchangeEngine.cs[R713-714]

+                                lineWaiter ??= new TaskCompletionSource<bool>(TaskCreationOptions.RunContinuationsAsynchronously);
+                                lineArrived = lineWaiter.Task;
Relevance

●● Moderate

Allocation concern is plausible, but the closest performance-allocation precedent rejected analogous
optimization; semantics and hot-path impact remain context-dependent.

PR-#420
PR-#594

ⓘ Recommendations generated based on similar findings in past PRs

Evidence
The wait loop creates a TCS when no new line is present and awaits it; the parser thread clears and
completes the current TCS on every parsed line. SD card listing code uses this text-exchange path
and can produce many lines, making the allocation/continuation rate relevant.

src/Daqifi.Core/Device/Internal/TextExchangeEngine.cs[493-507]
src/Daqifi.Core/Device/Internal/TextExchangeEngine.cs[701-716]
src/Daqifi.Core/Device/SdCard/SdCardOperations.cs[251-264]

Agent prompt
The issue below was found during a code review. Follow the provided context and guidance below and implement a solution

## Issue description
The reply wait loop uses `TaskCompletionSource<bool>` as an auto-reset signal and clears it on each parsed line. This pattern can allocate a new TCS/task frequently during large replies, increasing GC and continuation overhead.

## Issue Context
The exchange can receive very large multi-line outputs (e.g., SD card listings) through `ExecuteTextCommandAsync`, which will hit this wait path repeatedly.

## Fix Focus Areas
- src/Daqifi.Core/Device/Internal/TextExchangeEngine.cs[493-507]
- src/Daqifi.Core/Device/Internal/TextExchangeEngine.cs[701-716]
- src/Daqifi.Core/Device/SdCard/SdCardOperations.cs[251-264]

## What to change
- Replace the per-wait `TaskCompletionSource` allocation pattern with a reusable async signal primitive.
 - One viable approach is to introduce an internal `AsyncAutoResetEvent`/`AsyncSignal` helper that uses a single reusable instance and avoids allocating a new TCS per line.
 - Keep the existing "late signal after exchange" safety property (signals from a stale reader thread must be harmless).
- Add/extend a benchmark or stress test that simulates a large reply (hundreds/thousands of lines) and compare allocations before/after.

ⓘ Copy this prompt and use it to remediate the issue with your preferred AI generation tools



Informational

2. Misleading lock/await comment ✓ Resolved 🐞 Bug ⚙ Maintainability
Description
The comment above await lineArrived.WaitAsync(...) claims "the lock is held", but the lock is
released before the await. This is misleading and increases the risk of a future change incorrectly
moving awaits into the lock (which would actually create deadlock potential).
Code

src/Daqifi.Core/Device/Internal/TextExchangeEngine.cs[R720-723]

+                            // ConfigureAwait(false) for the same reason as every other await here:
+                            // the lock is held, so resuming on a captured sync context would
+                            // deadlock if that thread calls Disconnect().
+                            await lineArrived.WaitAsync(waitFor, cancellationToken).ConfigureAwait(false);
Relevance

●●● Strong

The comment factually contradicts the lock scope; recent review history accepts precise concurrency
documentation corrections in this file.

PR-#435
PR-#506

ⓘ Recommendations generated based on similar findings in past PRs

Evidence
The code exits the lock (collectedLinesGate) block before the await, but the comment explicitly
says the lock is held at the await site.

src/Daqifi.Core/Device/Internal/TextExchangeEngine.cs[701-724]

Agent prompt
The issue below was found during a code review. Follow the provided context and guidance below and implement a solution

## Issue description
A newly added comment states that a lock is held across an `await`, but the code releases the lock before awaiting. This is incorrect documentation and can mislead future maintenance.

## Issue Context
The code correctly avoids awaiting while holding `collectedLinesGate` by leaving the lock scope before `await`.

## Fix Focus Areas
- src/Daqifi.Core/Device/Internal/TextExchangeEngine.cs[701-724]

## What to change
- Update/remove the comment to reflect the actual reason for `ConfigureAwait(false)` (avoid resuming on a captured sync context) without implying the lock is held during the await.
- Optionally add a brief note clarifying that the lock is intentionally released before awaiting to avoid deadlocks/long lock holds.

ⓘ Copy this prompt and use it to remediate the issue with your preferred AI generation tools


Grey Divider

Context sources
Review mode: 🚀 Fast: This latest push only revises comments around an existing bounded await and introduces no runtime or behavioral change, so a lightweight review is sufficient.

Grey Divider

Tip of the day
💡 Did you know, you can start a comment with 'qodo' or '@qodo' to chat about any finding

More tips ↗ | Customize Qodo ↗ | Qodo docs ↗

Grey Divider

Qodo Logo

Comment thread src/Daqifi.Core/Device/Internal/TextExchangeEngine.cs
Comment thread src/Daqifi.Core/Device/Internal/TextExchangeEngine.cs
@tylerkron

Copy link
Copy Markdown
Contributor Author

/agentic_review

@qodo-code-review

Copy link
Copy Markdown

Code review by qodo was updated up to the latest commit f70738d

@tylerkron

Copy link
Copy Markdown
Contributor Author

Ready for review — Qodo loop settled clean on f70738d

Round 2 collected and clean. Qodo re-reviewed up to f70738d and edited its existing
Code Review by Qodo comment in place (round 1 on this same PR posted a new comment instead, so
the body was diffed against round 1 rather than trusted on its headline). Result:
Bugs (0) / Rule violations (0) / Requirement gaps (0) / UX issues (0) / Cross-repo conflicts (0) / Skill insights (0), with round 1's two entries carried forward at their triage — "per-line TCS
allocation churn" dismissed (evidenced rebuttal accepted) and "misleading lock/await comment"
resolved (conceded and fixed in f70738d). No third finding. Inline surface agrees: 2 review
threads, 0 unresolved. Re-checked after a settle interval against the same head SHA; unchanged.

CI green on f70738d. origin/main is still c546abd, so the earlier clean test-merge at that
base still applies to this head: 3904 passed / 2 skipped on net9.0 and net10.0 under -warnaserror.

Thread-pool starvation probe — run, and it passes

The one substantive check still outstanding, given that the known flake shape in this repo is pool
starvation racing a fixed timeout, and that an event which never fires would be worse than a poll
that wastes 50 ms. Harness: blocking in-process work items only (no CPU spinners), min threads pinned
to 1, and the exchange driven from a dedicated thread so the harness cannot starve the thing it
measures. Ran the five-fragment reply case, 5 unstarved control rounds then 5 starved rounds.

starve=off   1377 1344 1346 1410 1444 ms
starve=on    3938 1346 1357 1350 2086 ms

10/10 rounds returned all five lines, in order, with the reply recognised — no exception, no
non-return, no truncation.
Under real pool pressure the exchange degrades in latency only, up to
~2.9x on the first starved round, never in correctness. No lost wakeup and no "event that never
fired".

Worth recording for anyone who repeats this: 4 blocking work items do not actually starve anything
on a modern multi-core box — the pool already holds ~ProcessorCount threads and lowering min does
not destroy them, so the starved and unstarved timings came out identical and an empty-work-item
control measured 0 ms. Pressure only appeared at ProcessorCount + 4. Two earlier attempts at this
probe read as "inconclusive"; that is very likely why.

Two caveats stated plainly: this is a positive result under load, not a proof of absence, and it was
not re-run against main's poll loop under the same load. The old Task.Delay(50) continuation
needed a pool thread exactly as the new TCS continuation does, so the exposure is the same shape —
but that part is reasoning, not measurement.

The headline number is a wash, and stays stated as one

The bench here is inherited from the original implementation run and was deliberately not
re-taken, because nothing but a comment has changed since. Nq1 --lan-chip-info: main 6.15 s vs
branch 6.00–6.27 s — a wash.
The measured saving is ~25–75 ms per exchange, against a ticket that
projected ~700 ms of fixed overhead. The remaining overhead is real but lives elsewhere and is
deferred to #667. The PR body says this rather than burying it, and that framing has been left alone
on purpose.

What this PR does buy on its own terms: the 50 ms quantisation is gone from every reply wait, and
every deadline moved from DateTime.UtcNow to the exchange's Stopwatch, so a stepping wall clock
can no longer move a timeout mid-request. No timeout was widened and no assertion weakened — both
new guarding tests were confirmed mutation-sensitive (drop the inactivity restart, the fragmented
test goes red; drop the token, the cancellation test goes red).

@tylerkron
tylerkron added this pull request to the merge queue Aug 24, 2026
@github-merge-queue
github-merge-queue Bot removed this pull request from the merge queue due to failed status checks Aug 24, 2026
@tylerkron
tylerkron added this pull request to the merge queue Aug 25, 2026
@github-merge-queue
github-merge-queue Bot removed this pull request from the merge queue due to failed status checks Aug 25, 2026
@tylerkron
tylerkron added this pull request to the merge queue Aug 25, 2026
@github-merge-queue
github-merge-queue Bot removed this pull request from the merge queue due to failed status checks Aug 25, 2026
tylerkron and others added 3 commits August 24, 2026 21:32
The new test in this branch was sized so tightly that the merge queue
could not get it through: a 100 ms fragment gap inside a 300 ms
completion window is barely 3x, and on the macOS and Windows runners the
exchange came back with "one" alone -- the first gap by itself had outrun
the window. It is the gap that also pays for JIT-ing the read and parse
path and for the freshly started consumer thread's first scheduling, on a
machine already running the rest of the suite in parallel.

The gap is now 5 idle reads (50 ms nominal, 55 ms measured) inside a
500 ms window, so ~450 ms of cold-start delay has to land in one gap
before the test lies about the exchange. Twelve fragments instead of five
keep the property the test exists for: 11 gaps still outlast one
completion window in total, so a wait loop that never restarts its window
still fails. Both sides hold in the direction a slow machine pushes them.

The elapsed time is asserted now rather than left to that arithmetic. If
the pacing ever collapses, the reply arrives inside a single window and a
loop that never restarted anything would look correct -- the test would
pass while testing nothing. It fails instead, and says so.

Sizing measured rather than assumed: on this 12-core M-series Mac the
pacing is accurate to ~10% and does not degrade at 4x CPU
oversubscription, so the flake does not reproduce locally at all. The
margin is what carries it.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
…ot on sleep counts

The staged reply's gap between fragments was counted in the reader thread's
own idle reads -- five Thread.Sleep(10)s -- which makes the gap the SUM of
five scheduling delays. On the macOS runner each of those sleeps came back at
roughly 100 ms under the load of the rest of the suite, so the nominal 50 ms
gap arrived at ~500 ms, filled the whole completion window, and the exchange
returned six of the twelve lines. Widening the window 300 ms -> 500 ms did not
help, because the stretch scales with it.

The stream now hands the next fragment over on the first read that finds
StageGapMs elapsed on its own Stopwatch since the previous one drained, so a
stretched sleep no longer accumulates: a gap is StageGapMs plus at most ONE
late read. A single 450 ms stall now has to land inside one gap before the
test lies about the exchange, instead of five 90 ms ones. Fragment count goes
12 -> 16 so the nominal span (15 x 50 ms = 750 ms) still outlasts the window.

Reproduced the old failure locally 2/6 with the test process at nice 20
against 48 spinners; the new pacing is 6/6 on the same harness, and 8/8 under
plain CPU oversubscription.

The vacuous elapsed-time guard goes with it. It asserted that the whole call
took longer than one completion window, but the wait loop cannot return until
a completion window has passed with no new line, so that was true however the
pacing behaved. The stream now records the span from its first fragment
draining to its last, and the test asserts on that instead -- the quantity
that actually has to outlast the window.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
@tylerkron
tylerkron added this pull request to the merge queue Aug 26, 2026
Merged via the queue into main with commit 00b40ee Aug 26, 2026
4 checks passed
@tylerkron
tylerkron deleted the perf/485-event-driven-text-exchange branch August 26, 2026 01:47
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

perf(device): every SCPI text exchange pays ~700 ms of fixed polling/teardown overhead — make it event-driven

1 participant