Automation: a connect stalling in the pre-wire DSP setup reports nothing and never times out

Summary

connect ip <addr> hl2 replies ok:true, deferred:true and schedules the work.
If the connect then stalls in the DSP setup phase — after buildReceivers() and
before the Metis socket is opened — nothing is reported, ever. No error, no
warning, no progress line, and no timeout. A headless caller sees the same
reply a successful connect gives, followed by silence, and cannot distinguish
"still working" from "never going to complete".

Observed as a connect that never completes in 48 s, with the application's own
log showing no diagnostic of any kind.

Why the existing guards do not cover it

There is a connect watchdog — kConnectTimeoutMs = 2000
(src/core/backends/hl2/MetisClient.h:327) — and it reports properly, via
connectFailed → Hl2Backend's handler → RadioModel::onConnectionError,
which logs qCWarning(lcProtocol) << "RadioModel: connection error:".

But it is armed too late. m_connectWatchdog->start() runs inside
MetisClient::start() (MetisClient.cpp:292), and start() is only called at
the end of the connect, from Hl2Backend::finishDspSetup()
(Hl2Backend.cpp:2134) — after every DSP chain is open. A stall before that
point is outside every timeout in the path.

The failure modes that path does cover are both reported: a socket bind failure
returns false and Hl2Backend.cpp:2137 emits
connectionError("HL2: could not open the UDP socket"); and no-IQ-after-start
fires the 2 s watchdog. Neither is what happens here.

Evidence — where it stops, established by absence against a proven instrument

Two runs of the same binary against the same radio, one connecting and one not.

The failing run reaches the end of buildReceivers() and no further:

INF aether.hl2: HL2 restore: freq 1.9e+07 mode "USB" ... lna bands 4 drive bands 6
INF aether.hl2: HL2: board reports 4 receiver(s)
INF aether.hl2: HL2 band filter: "0x50" ... trigger=connect
INF aether.hl2: HL2: running 1 receiver(s)          <-- last line of buildReceivers()
... nothing about the radio for the remaining 40+ seconds ...

HL2: running N receiver(s) is the final statement of buildReceivers()
(Hl2Backend.cpp:690); the wire call is later, in finishDspSetup().

The successful run continues past it:

INF aether.hl2: HL2: running 1 receiver(s)
DBG aether.protocol: RadioModel: connected (family= "hl2" )

The absence is load-bearing, so the instrument was proven first. In the
failing run aether.protocol emits 4 INF lines and the log carries 35 WRN
lines overall — so both the category and the level are demonstrably live, and a
WRN aether.protocol: RadioModel: connection error: would have appeared had
either guard fired. It does not appear. Neither guard fired, which places the
stall before the socket is ever opened.

Independently: the radio's own state was polled every 3 s throughout a failing
run and read state=2 (idle/free) 22 times out of 22 — it never streams, because
MetisClient::start() is never called.

Relationship to #5052

#5052 ("HL2 first connect: the one-time WDSP setup message is drawn behind
the Connect Radio window") is the same phase. That issue made the one-time WDSP
setup visible to a GUI operator by moving its message to a modal dialog.

The automation path has no equivalent. The same phase that a GUI user now
sees explained in a dialog is, to a headless caller, indistinguishable from a
hang. This report is that gap, not a regression of #5052.

What would fix it

Any one of these closes the "cannot tell working from never":

A timeout covering the DSP setup phase, not only the post-start() wire.
The existing connectFailed → connectionError path already reports
correctly; it just needs to be reachable from a stall before start().
A progress line when the phase begins and ends. One qCInfo(lcHl2) before
the DSP opens and one after would make a stall self-evident in the log, which
is what the GUI dialog does for an operator.
A bridge-visible connect state so get radio distinguishes
connecting/opening DSP from idle, rather than only connected: false.

What this report deliberately does NOT claim

It does not say why the phase stalls. In the observed case the trigger was
running with a redirected HOME, and the cause of that is not established —
several plausible explanations were tested and refuted. The defect reported
here is the silence and the missing timeout, which are worth fixing whatever
makes the phase slow: a first-run WDSP open is legitimately expensive (#5052, and
a comment at MetisClient.cpp:178 cites ~19 s on a machine's first open), and a
caller cannot currently tell that apart from a hang.

Environment

AetherSDR at fork/main 2add3555; macOS 26 (Darwin 25.5.0), Qt 6.8.3.
Hermes-Lite 2, gateware 74, reached by unicast at a routed address.
Connect issued through the automation bridge, receive-only, nothing keyed.

🤖 Generated with Claude Code

Triaged: confirmed against main (b9f44f35). The report is accurate, including the line-level claims, and the diagnosis "the only connect watchdog is armed after the phase that stalls" is correct. Details, plus one constraint that shapes the fix.

Confirmed against the tree

The gap is real and is structural, not incidental. connectRadio() builds m_pendingConnect and calls beginDspSetup() (Hl2Backend.cpp:1943-1949). beginDspSetup() (:1952) snapshots the chains and QMetaObject::invokeMethod(..., Qt::QueuedConnection) hands the opens to the I/O thread, then returns to the event loop. The lambda runs chains[i]->configure() serially (:2021-2038 — serial because FFTW's planner is not thread-safe), then posts back to finishDspSetup() (:2050-2052). Between the beginDspSetup() return and the finishDspSetup() entry there is no timer of any kind. Nothing in Hl2Backend is watching that window.

The existing watchdog is downstream of it, as claimed. kConnectTimeoutMs = 2000 (MetisClient.h:327) is armed by m_connectWatchdog->start(kConnectTimeoutMs) inside MetisClient::start() (MetisClient.cpp:292), and start() is reached only at Hl2Backend.cpp:2169-2171 — the blocking invoke under the // ---- and only now, the wire ---- comment, after the full trim/ids loop. Its own comment says why the ordering is deliberate ("the I/O thread is free to pace EP2 without a multi-second WDSP open standing in front of it"), so the ordering is correct and the missing timeout is the defect, not the ordering.

The two covered failure modes are the ones you named, and only those. Bind failure → connectionError("HL2: could not open the UDP socket") at :2174. Receiver-0 DSP failure → connectionError("HL2 DSP: ...") at :2103. Both are return-value failures. Neither is a stall, and configure() returning slowly is invisible to both.

Progress instrumentation exists but is GUI-only — this is precisely the #5052 asymmetry. dspSetupProgress(stage, done, total) (Hl2Backend.h:141) is emitted at :1992 and per-receiver at :2032. Its only consumer in the tree is MainWindow (MainWindow.cpp:6880-6882), feeding the delayed dialog. There is no qCInfo(lcHl2) on that path, so the signal carries the exact information a headless caller needs and drops it on the floor. That is why the log stops dead at qCInfo(lcHl2) << "HL2: running" << count << "receiver(s)" (:697, last statement of buildReceivers()) — your absence evidence lands on the right line.

The bridge cannot express the state. radioSnapshot() (AutomationServer.cpp:1836) exposes connected as a bare r->isConnected() bool. There is no third value, so opening DSP and idle are the same JSON.

One correction to the framing, not to the finding: connect wait (doConnectWait, AutomationServer.cpp:6428) does have its own timeout and would eventually answer "timed out waiting for radio connection" — it is only bare connect ip that gets literal silence. But that path still can't distinguish a slow first-run WDSP open from a hang; it just says "timed out" after the caller's own deadline (#4912 added the connectionError edge at :6462 for exactly this reason, and that edge is unreachable here for the same reason the watchdog is). So the gap you're reporting survives it.

The constraint any fix has to respect

The in-flight build cannot be cancelled. disconnectRadio() states it outright (:2193-2199): "The build itself cannot be cancelled — WDSP's OpenChannel does not return early — so it runs to completion on the I/O thread and finishDspSetup() releases what it built." A watchdog therefore must not call tearDownReceivers() when it fires: the I/O thread may be inside configure() on those very chains, and freeing them from the GUI thread is a use-after-free. The watchdog's job is to report and invalidate, and let the existing supersede machinery do the cleanup — i.e. ++m_connectGeneration (the same one-liner disconnectRadio() uses), which makes the eventual finishDspSetup() take its stale branch at :2065-2072 and release what it built.

Proposed fix

All in src/core/backends/hl2/Hl2Backend.{h,cpp}, except (3).

DSP-phase watchdog. A QTimer* m_dspSetupWatchdog, single-shot, started at the end of beginDspSetup() and stopped on every exit from finishDspSetup() (all four returns) and in disconnectRadio() alongside the existing ++m_connectGeneration. On fire: ++m_connectGeneration, m_pendingConnect.reset(), emit connectionError(...), emit dspSetupFinished() — no teardown, per above. That reuses the proven connectionError → RadioModel::onConnectionError → noteConnectFailure() path, so connect wait and the next connect wait's lastError both light up for free.

The timeout must be generous. A first-run WDSP/FFTW open is legitimately expensive (HL2 first connect: the one-time WDSP setup message is drawn behind the Connect Radio window — move it to a modal dialog #5052; MetisClient.cpp:178 cites ~19 s). Suggest a two-stage shape rather than one number: a ~10 s qCWarning(lcHl2) "DSP setup still running after Ns" that does not fail the connect, and a hard ~90 s failure. That way a slow-but-working first open produces a log line instead of a spurious failed connect, which is the outcome the issue actually asks for.
Log the phase. Mirror dspSetupProgress to qCInfo(lcHl2) at :1992 (phase begin, with total) and once at the top of finishDspSetup() (phase end, with elapsed ms from a QElapsedTimer on PendingConnect). Two lines, and the "nothing about the radio for 40+ seconds" hole closes for every caller — GUI, headless, and support bundles alike.
Bridge-visible connect state. In AutomationServer.cpp:1836, add a connectState string next to connected ("idle" / "connecting" / "connected"), sourced from a RadioModel accessor fed by dspSetupProgress/dspSetupFinished. Keep connected as-is so existing scripts don't break. This is the largest of the three and is independently useful; it could reasonably land separately.

(1) and (2) together are small and fully close the reported defect; (2) alone would have made this run self-diagnosing. Note that this is HL2-specific — the Flex path has its own connect timeout — so the fix does not need to generalize.

Handoff

Known: exact stall window (between Hl2Backend.cpp:1952 return and :2057 entry), exact reason no guard covers it (MetisClient.cpp:292 armed from Hl2Backend.cpp:2169), exact reason nothing is logged (dspSetupProgress has one consumer and it is MainWindow). Unknown and explicitly out of scope per the reporter: why the phase stalls under a redirected HOME. Worth fixing regardless — as filed, a first-run WDSP open and a permanent hang are the same observation.

Not a regression of #5052; it is the same phase's automation-side gap.

_{🤖 aethersdr-agent · cost: $1.8246 · model: claude-opus-5}

_{📍 Citation health check (Foundry Constitution Principle I): 0 resolved, 11 unresolved against /Users/aetherclaude/workspace/AetherSDR at origin/main.}

Unresolved citations (11)

Citation	Reason
`AutomationServer.cpp:1836`	file not found in workspace
`AutomationServer.cpp:6428`	file not found in workspace
`Hl2Backend.cpp:1943-1949`	file not found in workspace
`Hl2Backend.cpp:1952`	file not found in workspace
`Hl2Backend.cpp:2169`	file not found in workspace
`Hl2Backend.cpp:2169-2171`	file not found in workspace
`Hl2Backend.h:141`	file not found in workspace
`MainWindow.cpp:6880-6882`	file not found in workspace
`MetisClient.cpp:178`	file not found in workspace
`MetisClient.cpp:292`	file not found in workspace
`MetisClient.h:327`	file not found in workspace

Where the phase spends its time, from a sample of the process during a connect that had not completed after three minutes (hl2-io thread, 791 of 791 samples in one chain):

Hl2Backend::beginDspSetup()::$_0
  Hl2RxDsp::configure            Hl2RxDsp.cpp:85
    WdspChannel::create          WdspChannel.cpp:309
      WdspChannel::open          WdspChannel.cpp:823
        OpenChannel              channel.c:92
          build_channel          channel.c:71
            create_rxa           RXA.c:219
              create_fmsq / create_eqimp   fmsq.c:43, eq.c:69
                fftw_measure_execution_time, apply_r2hc, r2cf_*

That is FFTW's MEASURE-mode planner timing candidate plans, and successive samples walk steadily down the RXA filter chain (RXA.c:219 → 266–431 → 1034), so the phase is doing real work, not deadlocked; the main thread is idle in its event loop. This supports the framing above: the fix is a progress line and a bound on the DSP-setup phase, not a hang investigation. The same phase is under four seconds on the same machine and binary with the operator's normal profile, and over three minutes with a fresh, empty one; neither has an FFTW wisdom file, so the reason for that spread is still being measured and is not claimed here.

The slow phase is explained, and it makes the two-stage shape above the right one rather than a single timeout.

WdspChannel::wisdomPath (src/core/dsp/WdspChannel.cpp:50) resolves $XDG_CACHE_HOME, else $HOME/.cache, then /aethersdr/wdsp-fftw-wisdom; the file is imported before channels are built (:146) and exported after (:184), and WDSP builds every FFT with FFTW_PATIENT (:43), 35 plans per channel. A profile with no such cache pays the full planning cost on every connect. Two runs identical except one variable, against the same simulator with the same radio profile:

profile	result
fresh (no WDSP wisdom)	not connected after 150 s
fresh + `AETHER_WDSP_WISDOM_DIR` pointed at an existing cache	connected in 4.1 s

Correction to my previous comment: it said neither profile had a wisdom file. That was the wrong file — the "wisdom summary: status=missing" log line is AudioEngine's separate cache under ~/.config/AetherSDR, missing on both sides. WDSP's cache is a different path, present in the normal profile (about 24 KB of accumulated plans) and absent in a fresh one.

So a first connect on a fresh profile is legitimately minutes long, and the defect is exactly as framed: it neither says so nor bounds itself. The ~10 s warning stage will fire in ordinary first-run use, which is the behaviour this issue wants; the hard stage catches a genuine hang. A fix along the lines proposed above is in preparation.

docs(hermes): the recipe above does not delete its HOME, so say what …

Coverage map, so neither PR closes this issue prematurely: #5415 implements items 1 and 2 (a bound on the DSP-setup phase, and the two qCInfo progress lines), and #5416 implements item 3 (a bridge-visible connectState beside the existing bool). Both now say Refs #5413 rather than Fixes; whoever lands the second of the two can add the closing keyword at merge. One correction to my own earlier comment here: the 90 s bound I first proposed was taken from "still running at 150 s", which was the moment an observer stopped watching rather than a measurement of anything. It is 600 s at the current head, chosen to clear five measured cold figures (98.3 s quiet, 188.1 s loaded, and four connects at 193–219 s) plus the 178.7 s and 188–190 s in #4877.

docs(hermes): §10's recipe keeps its HOME; say so. Principle X.

fix(bridge): connectState follows the attempt. Principle XI.

Bound and log HL2 DSP setup (#5415). Principle VIII.

docs(hermes): §10's isolation recipe destroys the WDSP wisdom cache (#…

feat(hl2): a bridge-visible connect state beside the connected bool (#…

Navigation Menu

Repository navigation

Automation: a connect stalling in the pre-wire DSP setup reports nothing and never times out #5413

Summary

Why the existing guards do not cover it

Evidence — where it stops, established by absence against a proven instrument

Relationship to #5052

What would fix it

What this report deliberately does NOT claim

Environment

Confirmed against the tree

The constraint any fix has to respect

Proposed fix

Handoff

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

Automation: a connect stalling in the pre-wire DSP setup reports nothing and never times out #5413

Description

Summary

Why the existing guards do not cover it

Evidence — where it stops, established by absence against a proven instrument

Relationship to #5052

What would fix it

What this report deliberately does NOT claim

Environment

Activity

aethersdr-agent commented on Sep 4, 2026

Confirmed against the tree

The constraint any fix has to respect

Proposed fix

Handoff

on8st commented on Sep 4, 2026

on8st commented on Sep 4, 2026

on8st commented on Sep 5, 2026

Metadata

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

Issue actions