-
-
Notifications
You must be signed in to change notification settings - Fork 118
fix(hl2): bound and log the DSP-setup phase (refs #5413) #5415
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
Merged
Merged
Changes from all commits
Commits
Show all changes
5 commits
Select commit
Hold shift + click to select a range
3a3c17e
fix(hl2): bound and log the DSP-setup phase (fixes #5413)
on8st 21a4820
fix(hl2): watchdog must not reset m_pendingConnect. Principle VIII.
on8st d0d6bb9
fix(hl2): DSP-setup bound 90 s to 600 s, warn repeats. Principle VIII.
on8st a4db2f3
docs(hl2): narrow the multi-receiver caveat to what is reachable. Pri…
on8st 18b49e6
test(hl2): name what the measurement assertions depend on. Principle X.
on8st File filter
Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
There are no files selected for viewing
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
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
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
| Original file line number | Diff line number | Diff line change |
|---|---|---|
| @@ -0,0 +1,158 @@ | ||
| #pragma once | ||
|
|
||
| // How long the DSP-setup phase may run before it is worth saying something, and | ||
| // before it is worth giving up — as a pure decision. | ||
| // | ||
| // THE PHASE HAS NO TIMEOUT AT ALL TODAY, and that is the defect (#5413). | ||
| // beginDspSetup() hands the WDSP opens to the I/O thread and returns to the | ||
| // event loop; finishDspSetup() is posted back when they finish. Between those | ||
| // two points nothing in Hl2Backend is watching. The only connect watchdog lives | ||
| // in MetisClient::start(), which is reached AFTER this phase, so a stall here is | ||
| // outside every guard in the path — the caller sees the same reply a successful | ||
| // connect gives and then silence. | ||
| // | ||
| // TWO STAGES, NOT ONE NUMBER, and the reason is that a slow first open is | ||
| // legitimate rather than broken. A machine's first WDSP/FFTW open measures its | ||
| // plans instead of loading them, which is genuinely expensive (#5052; | ||
| // MetisClient.cpp cites ~19 s), and a single tight timeout would turn a working | ||
| // first launch into a failed connect. So: warn early and keep going, fail only | ||
| // far out. | ||
| // | ||
| // WHERE "FAR OUT" IS, MEASURED. The first bound here was 90 s, chosen against a | ||
| // single observation that an uncached open was "still running at 150 s". It was | ||
| // wrong, and wrong in the direction that fails working connects. On an IDLE | ||
| // machine — 21 load samples between 3.3 and 4.1 — a cold first open measured | ||
| // 98269 ms, against HERMES §22.3's documented 18865 ms | ||
| // (streams/hl2-telemetry/runs/d57_bench_quiet_result.txt). So 90 s failed a | ||
| // connect that was working, on a quiet machine, every time. | ||
| // | ||
| // The same series measured that load roughly doubles it: 188128 ms for the open | ||
| // at one-minute load 38-40, and four cold CONNECTS at load 31-44 came in at | ||
| // 193 / 195 / 214 / 219 s (streams/hl2-telemetry/runs/d57_quiet_connect.py). | ||
| // 98.3 s is therefore a FLOOR from one sample on one machine, not a typical | ||
| // case — and the cost being measured is FFTW timing candidate plans, which | ||
| // varies several-fold across hardware. A laptop or a CI runner will be slower. | ||
| // | ||
| // AND THE LARGEST DOCUMENTED FIGURE IS NOT OURS. #4877 -- closed, titled "every | ||
| // run re-measures 190 s of PATIENT plans" -- reports 178.7 s on an i9-13980HX | ||
| // and 188-190 s across four consecutive CI runs. So ~190 s is an EXPECTED cold | ||
| // cost in at least one shipped configuration, independently of this bench, and | ||
| // the 188.1 s above reproduces it rather than discovering it. Read the range as | ||
| // 19 s to 190 s across binaries and platforms before a slower CPU is counted — | ||
| // with the low end as the outlier rather than an equal member: three | ||
| // independent cold measurements sit between 98 and 190 s (this bench's 98.3 s, | ||
| // wdsp_channel_test's 165.1 s, #4877's 178.7 s and its 188-190 s CI runs), | ||
| // while HERMES §22.3's 18.9 s and its 22.4 s companion stand alone. | ||
| // | ||
| // One caveat on treating those as one number: HERMES.md notes that the app's | ||
| // plan set and the tests' plan set are different FFTW problems, so #4877's | ||
| // figure and a connect are not strictly the same measurement. That cuts toward | ||
| // a wider bound, not a narrower one. | ||
| // | ||
| // WHAT NONE OF THOSE FIGURES COVER: MORE THAN ONE RECEIVER — and the exposure | ||
| // is much narrower than "the board reports four". beginDspSetup() opens one | ||
| // chain per receiver, `for (int i = 0; i < actualNumRx; ++i)`, and the transmit | ||
| // path opens none, so the cost does scale with actualNumRx. But three things | ||
| // bound how it can exceed 1 inside this window: | ||
| // | ||
| // * connectRadio() sets `m_requestedNumRx = 1` unconditionally and raises it | ||
| // only for an explicit `numRx` CONNECT PARAM. A saved count is deliberately | ||
| // not re-imposed (see the comment there). Nothing in RadioModel passes the | ||
| // param, so an ordinary app connect opens exactly one chain. | ||
| // * A receiver added later is outside this timer entirely: createPanadapter() | ||
| // refuses before m_connected, so its chain opens after the phase this | ||
| // watchdog measures. | ||
| // * receiverCeiling() is min(board, maxReceiversAtRate(rate, board)), so at | ||
| // 384 kHz — the rate every measurement above used — a 4-receiver board is | ||
| // honestly 3. A four-receiver run would have to change the rate, and would | ||
| // then not be comparable to the figures above at all. | ||
| // | ||
| // So the reachable case is an automation or embedder caller that passes numRx>1 | ||
| // at connect: the same class of entry point as #5402's lnaGainDb. Plan sets | ||
| // overlap heavily (this bench's second, third and fourth cold opens, at other | ||
| // rates, cost 1862 / 1223 / 739 ms after that first 98 s), so chains 2..N at | ||
| // one rate are probably nearly free — an expectation, not a measurement. If | ||
| // such a connect ever fails this bound, that is the number to go and measure. | ||
| // | ||
| // Hence 600 s: an order of magnitude over the quiet floor, ~3x over the largest | ||
| // documented cold cost, ~2.7x over the worst measured working connect, and | ||
| // still finite. The asymmetry justifies the | ||
| // generosity — failing a connect that would have succeeded loses the session, | ||
| // while a late error on a true hang only delays a message the operator can | ||
| // already see coming from the warn line. | ||
| // | ||
| // WHICH IS WHY THE WARN REPEATS. A single line at 10 s followed by ten minutes | ||
| // of silence is barely better than the unbounded phase this replaces, so after | ||
| // the first warning the watchdog re-warns on a fixed cadence until it either | ||
| // finishes or fails. The schedule below is what produces that. | ||
| // | ||
| // A pure function so the timing behaviour is testable without a radio, a socket | ||
| // or a running event loop — the layer #5358 asks for. | ||
|
|
||
| #include <cstdint> | ||
|
|
||
| namespace AetherSDR::hl2 { | ||
|
|
||
| enum class DspSetupAction { | ||
| None, // still inside the expected window; say nothing | ||
| Warn, // slow enough to be worth a log line, NOT a failure | ||
| Fail, // long enough that the caller deserves an error instead of silence | ||
| }; | ||
|
|
||
| // Default stages. Deliberately far apart: the gap between them is where a | ||
| // legitimately slow first open lives — measured at 98.3 s quiet and 188 s under | ||
| // load, so the gap is the working case, not the pathological one. | ||
| inline constexpr std::int64_t kDspSetupWarnMs = 10'000; | ||
| inline constexpr std::int64_t kDspSetupFailMs = 600'000; | ||
|
|
||
| // How often to repeat the warning once the phase is past the warn point. Not a | ||
| // stage: it changes nothing about what dspSetupAction() decides, only how often | ||
| // the caller wakes up to hear the same Warn again. | ||
| inline constexpr std::int64_t kDspSetupWarnRepeatMs = 30'000; | ||
|
|
||
| inline DspSetupAction dspSetupAction(std::int64_t elapsedMs, | ||
| std::int64_t warnMs = kDspSetupWarnMs, | ||
| std::int64_t failMs = kDspSetupFailMs) | ||
| { | ||
| // Fail is checked FIRST so a misconfigured pair (fail <= warn) still fails | ||
| // rather than warning forever. The ordering is the guard, not an assert: | ||
| // this runs on a timer in a connect path and must not abort a session. | ||
| if (elapsedMs >= failMs) { | ||
| return DspSetupAction::Fail; | ||
| } | ||
| if (elapsedMs >= warnMs) { | ||
| return DspSetupAction::Warn; | ||
| } | ||
| return DspSetupAction::None; | ||
| } | ||
|
|
||
| // How long to wait before looking again, given that `elapsedMs` has just been | ||
| // judged. | ||
| // | ||
| // Before the warn point this is the exact REMAINDER, not a poll: a connect that | ||
| // is going to finish in four seconds costs zero wake-ups. After it, the cadence | ||
| // is what keeps the ten-minute window from being silent — but the last wait is | ||
| // clamped to the remainder so the fail point is hit exactly rather than | ||
| // overshot by up to a repeat interval. | ||
| inline std::int64_t dspSetupNextCheckMs(std::int64_t elapsedMs, | ||
| std::int64_t warnMs = kDspSetupWarnMs, | ||
| std::int64_t failMs = kDspSetupFailMs, | ||
| std::int64_t repeatMs = kDspSetupWarnRepeatMs) | ||
| { | ||
| if (elapsedMs < warnMs) { | ||
| return warnMs - elapsedMs; | ||
| } | ||
| if (elapsedMs >= failMs) { | ||
| return 0; // nothing further to wait for | ||
| } | ||
| const std::int64_t remaining = failMs - elapsedMs; | ||
| // A non-positive cadence would arm a zero-delay timer and spin the event | ||
| // loop for the rest of the phase. Fall back to the old single-shot | ||
| // behaviour rather than doing that. | ||
| if (repeatMs <= 0) { | ||
| return remaining; | ||
| } | ||
| return remaining < repeatMs ? remaining : repeatMs; | ||
| } | ||
|
|
||
| } // namespace AetherSDR::hl2 |
Oops, something went wrong.
Oops, something went wrong.
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.
Uh oh!
There was an error while loading. Please reload this page.