From 55ed4ed029b716f23ed6ad2f9f12f81692677f8c Mon Sep 17 00:00:00 2001 From: Frank0x01 Date: Tue, 14 Jul 2026 20:41:21 +0200 Subject: [PATCH] =?UTF-8?q?fix(qso-answerer):=20D-CALLER-020=20=E2=80=94?= =?UTF-8?q?=20partner=20re-transmitting=20own=20CQ=20no=20longer=20false-a?= =?UTF-8?q?borts=20QSO?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit QsoAnswererService.HandleWaitReportAsync and QsoCallerService.HandleWaitRr73Async treated any message from the partner not addressed to us as "partner is working another station" and aborted immediately — including the partner simply re-transmitting their own CQ because they hadn't decoded us yet, which is the normal, expected state early in a retry sequence, not evidence they moved on. Real-hardware field test (logs/openswfz-20260714T171230Z.log, EA1FUB) caught this: one retry fired correctly, then the partner's own CQ decode ended the QSO outright. Narrow the abort condition to exclude dest == "CQ" (case-insensitive) in both services, falling through instead to the existing "no matching message" retry/watchdog backstop — the same one that already handles genuine silence. Genuine third-party addressing (dest is a different real callsign) still aborts immediately, unchanged. Added unit tests to both service test suites exercising the exact retry-exhaustion cycle pattern with the partner's own CQ substituted for silence, proving both the no-abort behaviour and that the retry backstop still eventually gives up. Existing 6.6/5.9 genuine-third-party tests and the 460 retry-exhaustion test pass unmodified. Per dev-task §5, also added qa/d-caller-020-working-cq-false-abort-verify/ — a standalone tool that synthesises and decodes real FT8 audio (qa/rr-study/synth_wav.py + the real Ft8Decoder/libft8 P/Invoke) and drives the real, unmodified QsoAnswererService/QsoCallerService with it, closing the gap unit tests alone left (hand-authored DecodeResult strings never actually round-tripped through real FT8 packing). Verified PASS with the fix, and a deliberate control run with the fix reverted reproduces the exact regression on both services (see live-reports/). Full suite 1145/1145, dotnet build -c Release 0 warnings/0 errors. Co-Authored-By: Claude Sonnet 5 --- .../2026-07-14-working-cq-false-abort.md | 207 ++++++++ ...DCaller020WorkingCqFalseAbortVerify.csproj | 36 ++ .../Program.cs | 472 ++++++++++++++++++ .../README.md | 58 +++ .../2026-07-14T183903Z-7b330e1.md | 65 +++ src/OpenWSFZ.Daemon/QsoAnswererService.cs | 5 +- src/OpenWSFZ.Daemon/QsoCallerService.cs | 5 +- .../QsoAnswererServiceTests.cs | 32 ++ .../QsoCallerServiceTests.cs | 57 +++ 9 files changed, 933 insertions(+), 4 deletions(-) create mode 100644 dev-tasks/2026-07-14-working-cq-false-abort.md create mode 100644 qa/d-caller-020-working-cq-false-abort-verify/DCaller020WorkingCqFalseAbortVerify.csproj create mode 100644 qa/d-caller-020-working-cq-false-abort-verify/Program.cs create mode 100644 qa/d-caller-020-working-cq-false-abort-verify/README.md create mode 100644 qa/d-caller-020-working-cq-false-abort-verify/live-reports/2026-07-14T183903Z-7b330e1.md diff --git a/dev-tasks/2026-07-14-working-cq-false-abort.md b/dev-tasks/2026-07-14-working-cq-false-abort.md new file mode 100644 index 0000000..6ee238c --- /dev/null +++ b/dev-tasks/2026-07-14-working-cq-false-abort.md @@ -0,0 +1,207 @@ +# Handoff: D-CALLER-020 — Partner's own re-transmitted CQ is misread as "working another station" and aborts the QSO + +**Date:** 2026-07-14 +**Prepared by:** QA engineer (analysis of `logs/openswfz-20260714T171230Z.log`, real-hardware field +test of PR #72 by the Captain) +**Status:** Awaiting developer action +**Defect ID:** D-CALLER-020 +**Severity:** High — the application abandons an in-progress QSO on its own initiative, after the +operator did everything right, because it cannot distinguish "partner hasn't heard us yet, still +calling CQ" from "partner has genuinely moved on to another station." Pre-existing defect, **not** +introduced by PR #72 (`fix/d-caller-018-abort-hard-stop`) — confirmed present in `main` before that +merge and untouched by its diff. + +--- + +## 1. Context + +### 1.1 What the log shows + +Real-hardware session, `logs/openswfz-20260714T171230Z.log`. The Captain double-clicked EA1FUB's CQ +row; the engage landed cleanly within the valid window, TX completed normally, one retry fired on +schedule after no reply — all correct so far: + +``` +19:28:16.448 pending CQ target 'EA1FUB' at 488 Hz — answering at B phase. +19:28:16.459 KeyDown — PTT asserted +19:28:29.262 KeyUp — PTT released; TX complete for "EA1FUB PD2FZ JO33"; state → WaitReport +19:28:45.927 no response from EA1FUB (retry 1/3) — retransmitting. +19:28:45.934 KeyDown — PTT asserted +19:28:58.749 KeyUp — PTT released; TX complete; state → WaitReport +19:29:15.923 QsoAnswererService: EA1FUB is working CQ — aborting. +19:29:15.924 QsoAnswererService: aborted to Idle (was: "WaitReport", partner: EA1FUB). +``` + +Between the retry completing and the abort, the decoder picked up EA1FUB's own next transmission — +almost certainly `CQ EA1FUB `, i.e. EA1FUB simply hadn't decoded us yet and was still calling +CQ generally, which after only one retry is entirely unremarkable. The application read this as +"EA1FUB has moved on to work someone/something called 'CQ'" and gave up permanently. The Captain's +own framing of this from the field: *"timing was impeccable, but the application just decided to end +the whole qso."* + +### 1.2 Root cause + +`QsoAnswererService.cs`, `HandleWaitReportAsync` (currently line 973), lines 1030–1038: + +```csharp +// ── Partner is working another station — abort ── +if (fromPartner && !toUs) +{ + _logger.LogInformation( + "QsoAnswererService: {Partner} is working {OtherDest} — aborting.", + partner, dest); + await SafeAbortToIdleAsync(stoppingToken, $"Partner {partner} is working another station").ConfigureAwait(false); + return; +} +``` + +`TryParseMessage` (line 1494) splits an FT8 message on whitespace into exactly three tokens — +`dest src payload`. A standard CQ message `"CQ EA1FUB IM58"` parses as `dest="CQ"`, `src="EA1FUB"`, +`payload="IM58"`. `fromPartner` (`src.Equals(partner)`) is true; `toUs` (`dest.Equals(ours)`) is +false — `"CQ" != "PD2FZ"` — so the condition `fromPartner && !toUs` is satisfied and the code treats +a routine, undirected CQ call exactly the same as a directed message to a *different* real callsign +(e.g. `"Q2OTHER EA1FUB +03"`, which genuinely does mean the partner is now working someone else and +is the correct case to abort on). + +These are not the same situation: +- **`dest` is a real callsign, not ours** → the partner is demonstrably in QSO with a third station. + Continuing to wait is pointless. **Correct to abort.** +- **`dest == "CQ"`** → the partner is not in QSO with anyone; they are still calling CQ generally, + most likely because they have not yet decoded us. This is the normal, expected state of affairs + early in a retry sequence and is not evidence the partner has "moved on." **Should not abort on + this alone** — it should be treated the same as "no matching message" (fall through to the + existing `RetryOrAbortAsync`, which already has its own configurable retry-count/watchdog + backstop for genuinely giving up). + +The identical bug, byte-for-byte, exists in `QsoCallerService.cs`, `HandleWaitRr73Async` (currently +line 770), lines 803–812 — same condition, same log message shape, same fix required. The caller side +is symmetric: after we've sent our report and are waiting for RR73, if the partner re-transmits their +own CQ instead of answering us, the caller side gives up immediately instead of retrying. + +### 1.3 Test coverage gap + +`QsoAnswererServiceTests.cs:447`, `"6.6: Partner working another station in WaitReport → abort to +Idle"`, only ever exercises the genuine-third-party case: + +```csharp +Send(Make($"CQ {PartnerCall} {PartnerGrid}")); +await WaitForStateAsync(_sut!, QsoState.WaitReport); + +// Partner sends to a third station. +Send(Make($"Q2OTHER {PartnerCall} +03")); +await WaitForStateAsync(_sut!, QsoState.Idle, timeout: TimeSpan.FromSeconds(3)); +``` + +There is no test anywhere that sends `Make($"CQ {PartnerCall} {PartnerGrid}")` a *second* time while +already in `WaitReport` — the exact case that failed in the field. Same gap in +`QsoCallerServiceTests.cs:695` (`"5.9: HandleWaitRr73Async — partner working another station +aborts"`). + +--- + +## 2. Branch + +Suggested name: `fix/d-caller-020-working-cq-false-abort`, off `main` (PR #72 already merged as of +2026-07-14). + +--- + +## 3. Action + +**Files:** `src/OpenWSFZ.Daemon/QsoAnswererService.cs` (`HandleWaitReportAsync`, ~line 1030) and +`src/OpenWSFZ.Daemon/QsoCallerService.cs` (`HandleWaitRr73Async`, ~line 804). + +Narrow the abort condition so it only fires when `dest` is a real, addressed callsign — not the +literal `"CQ"` token (case-insensitive; also guard against an empty/malformed `dest` from a +line that squeaked past `TryParseMessage`'s 3-token check with garbage). Suggested shape: + +```csharp +// ── Partner working another station — abort. Distinguish this from the partner simply +// still calling CQ (dest == "CQ"), which is not evidence they've moved on — see D-CALLER-020. ── +if (fromPartner && !toUs && !dest.Equals("CQ", StringComparison.OrdinalIgnoreCase)) +{ + _logger.LogInformation( + "QsoAnswererService: {Partner} is working {OtherDest} — aborting.", + partner, dest); + await SafeAbortToIdleAsync(stoppingToken, $"Partner {partner} is working another station").ConfigureAwait(false); + return; +} +``` + +When `dest == "CQ"`, fall through — do **not** `return` early, do **not** treat it as a matching +decode either (it isn't a report or RR73/RRR from the partner to us). It should reach the same +"no matching message — retry or abort" path at the bottom of the handler as a genuinely silent +cycle, so the existing `RetryOrAbortAsync` retry-count/watchdog backstop is what eventually gives up +if the partner truly never answers — not a same-cycle snap decision based on one CQ decode. + +Apply the identical change to `QsoCallerService.cs`'s `HandleWaitRr73Async`. + +**Do not** touch the genuine-third-party path — `Q2OTHER {PartnerCall} +03` must continue to abort +immediately exactly as today; that is correct behaviour and is already covered by +`6.6`/`5.9`. + +--- + +## 4. Acceptance criteria + +**AC-1.** `QsoAnswererService`, `WaitReport`: partner re-transmitting their own CQ +(`"CQ {PartnerCall} {PartnerGrid}"`) while we are in `WaitReport` does **not** abort the QSO; it is +treated as a silent cycle and falls into the existing retry/watchdog path. Add as a new unit test +alongside `6.6` — e.g. `WaitReport_PartnerStillCallingCq_DoesNotAbort_RetriesInstead`. + +**AC-2.** `QsoAnswererService`, `WaitReport`: partner addressing a genuine third callsign +(`"Q2OTHER {PartnerCall} +03"`) still aborts immediately — existing `6.6` test must continue to pass +unmodified. + +**AC-3 / AC-4.** Same pair (still-CQ → no abort, retry instead; genuine third party → abort) for +`QsoCallerService`'s `HandleWaitRr73Async`, alongside existing `5.9`. + +**AC-5.** Full retry-exhaustion path still works: if the partner keeps calling CQ (or stays silent) +for `tx.RetryCount` consecutive cycles with no report/RR73 ever addressed to us, the QSO still ends +via `RetryOrAbortAsync`'s existing "retry count exceeded" abort — this defect must not turn into an +infinite-retry regression. Confirm `WaitReport_NoResponse_RetriesThenAborts` (line 460) and its +caller-side equivalent still pass unmodified. + +**AC-6.** `dotnet build OpenWSFZ.slnx -c Release` — 0 errors, 0 warnings. + +**AC-7.** Full test suite green, no regressions (baseline: full suite as of `main` post-PR#72). + +--- + +## 5. Live verification requirement + +This defect was only caught by real-hardware field testing, not by unit tests — the existing `6.6`/ +`5.9` tests all passed while this was broken, because neither ever sent the partner's own CQ a second +time. Per this project's standing convention for QSO-flow defects (see the D-CALLER-018 dev-task, +§5), unit tests alone are not sufficient sign-off here. Before merge, either: +- reproduce the exact field sequence (engage → retry → partner's own CQ decoded again) against a + real isolated daemon over its real HTTP/WebSocket API and confirm no premature abort, or +- at minimum, replay the relevant excerpt of `logs/openswfz-20260714T171230Z.log` (lines + ~2895–3047, EA1FUB) through a synthetic-decode harness and confirm the fixed code no longer emits + `"is working CQ — aborting"` for that sequence. + +--- + +## 6. References + +- Evidence log: `logs/openswfz-20260714T171230Z.log`, lines 2896–3047 (EA1FUB sequence). +- `src/OpenWSFZ.Daemon/QsoAnswererService.cs`: + - `HandleWaitReportAsync` — line 973; fix target at lines 1030–1038. + - `TryParseMessage` — line 1494 (confirms `dest="CQ"` parsing for a `CQ CALL GRID` message). + - `RetryOrAbortAsync` — line 1149 (existing genuine-timeout backstop, unaffected). +- `src/OpenWSFZ.Daemon/QsoCallerService.cs`: + - `HandleWaitRr73Async` — line 770; fix target at lines 803–812. + - `TryParseMessage` — line 1162 (same parsing logic, separate copy). +- `tests/OpenWSFZ.Daemon.Tests/QsoAnswererServiceTests.cs`: + - `6.6: Partner working another station in WaitReport → abort to Idle` — line 447/448 (must keep + passing unmodified; genuine-third-party case). + - `6.6: No matching decode in WaitReport → retry; after max retries → Idle` — line 459/460 (must + keep passing unmodified; retry-exhaustion backstop). +- `tests/OpenWSFZ.Daemon.Tests/QsoCallerServiceTests.cs`: + - `5.9: HandleWaitRr73Async — partner working another station aborts` — line 695 (must keep + passing unmodified). +- Related but distinct: `dev-tasks/2026-07-14-engage-window-wsjtx-redesign.md` — the other finding + from the same field session (late-start-threshold model), tracked separately; not the same root + cause and does not depend on this fix or vice versa. +- PR #72 QA sign-off comment (this session) — full mapping of all three field complaints to root + causes, of which this is one. diff --git a/qa/d-caller-020-working-cq-false-abort-verify/DCaller020WorkingCqFalseAbortVerify.csproj b/qa/d-caller-020-working-cq-false-abort-verify/DCaller020WorkingCqFalseAbortVerify.csproj new file mode 100644 index 0000000..4193888 --- /dev/null +++ b/qa/d-caller-020-working-cq-false-abort-verify/DCaller020WorkingCqFalseAbortVerify.csproj @@ -0,0 +1,36 @@ + + + + Exe + net10.0 + enable + enable + false + + false + + + + + + + + + + + + diff --git a/qa/d-caller-020-working-cq-false-abort-verify/Program.cs b/qa/d-caller-020-working-cq-false-abort-verify/Program.cs new file mode 100644 index 0000000..6d91bc2 --- /dev/null +++ b/qa/d-caller-020-working-cq-false-abort-verify/Program.cs @@ -0,0 +1,472 @@ +using System.Diagnostics; +using System.Threading.Channels; +using Microsoft.Extensions.Logging.Abstractions; +using OpenWSFZ.Abstractions; +using OpenWSFZ.Daemon; +using OpenWSFZ.Ft8; +using OpenWSFZ.Web; + +namespace DCaller020WorkingCqFalseAbortVerify; + +/// +/// Standalone, manually-run live verification tool for D-CALLER-020 (see the README in this +/// directory, and dev-tasks/2026-07-14-working-cq-false-abort.md §5). Not part of +/// OpenWSFZ.slnx and not exercised by dotnet test — run it explicitly with +/// dotnet run -c Release from this directory. +/// +/// +/// Reproduces the field defect: QsoAnswererService.HandleWaitReportAsync and +/// QsoCallerService.HandleWaitRr73Async used to abort the QSO the instant they decoded +/// any message from the partner not addressed to us — including the partner simply +/// re-transmitting their own CQ because they hadn't decoded us yet. The fix narrows the abort +/// condition to exclude dest == "CQ", falling through to the existing retry/watchdog +/// backstop instead. +/// +/// +/// +/// This tool proves the fix against genuinely synthesised-and-decoded FT8 audio — two separate +/// renders of the partner's own CQ (qa/rr-study/synth_wav.py, fresh every run, different +/// seeds so the two renders are not byte-identical) decoded by the real, unmocked +/// (a genuine P/Invoke call into libft8) — fed into the real, +/// unmodified / production classes, +/// not hand-authored strings as the unit tests use. A genuine +/// third-party message is also decoded and fed in as a control, proving the genuine-abort path +/// (AC-2/AC-4 in the dev-task) still fires correctly and was not disabled by the fix. +/// +/// +internal static class Program +{ + private const string OurCallsign = "Q1OFZ"; + private const string OurGrid = "JO33"; + private const string PartnerCall = "Q1TST"; + private const string PartnerGrid = "JO22"; + // NB: must be a real-callsign-grammar-compressible token (digit at index 1, length <= 5) + // for the synthesiser/decoder round-trip — "Q2OTHER" (7 chars) doesn't compress and decodes + // back as a hashed "<...>" placeholder instead of the literal text, unlike the unit tests' + // hand-authored DecodeResult strings which skip real FT8 packing entirely. + private const string ThirdParty = "Q2OTR"; + + // Partner's CQ — rendered twice (different seeds/freq-jitter-free but distinct synth runs) to + // stand in for "partner calling CQ", then "partner calling CQ again a cycle later" — the + // exact field sequence from logs/openswfz-20260714T171230Z.log. + private const string CqMessage = $"CQ {PartnerCall} {PartnerGrid}"; + // Partner responding directly to our own CQ (used to drive the caller side into WaitRr73). + private const string RespToUsMessage = $"{OurCallsign} {PartnerCall} {PartnerGrid}"; + // Partner genuinely addressing a different, real station — the case that must still abort. + private const string ThirdPartyMessage = $"{ThirdParty} {PartnerCall} +03"; + + private static async Task Main() + { + Console.WriteLine("D-CALLER-020 — working-CQ false-abort live verification"); + Console.WriteLine("========================================================="); + Console.WriteLine(); + + var failures = new List(); + + try + { + var repoRoot = FindRepoRoot(); + var workDir = Path.Combine(Path.GetTempPath(), "d-caller-020-verify-" + Guid.NewGuid().ToString("N")); + Directory.CreateDirectory(workDir); + + try + { + // ── Step 1: synthesise three real FT8 signals, fresh, every run ───────────── + Console.WriteLine("[1/3] Synthesising FT8 signals via qa/rr-study/synth_wav.py ..."); + string cqWav1 = Path.Combine(workDir, "cq_1.wav"); + string cqWav2 = Path.Combine(workDir, "cq_2.wav"); + string respWav = Path.Combine(workDir, "resp.wav"); + string thirdWav = Path.Combine(workDir, "third.wav"); + + await RunSynthWavAsync(repoRoot, CqMessage, freqHz: 800, seed: 1, outPath: cqWav1); + await RunSynthWavAsync(repoRoot, CqMessage, freqHz: 800, seed: 7, outPath: cqWav2); + await RunSynthWavAsync(repoRoot, RespToUsMessage, freqHz: 800, seed: 3, outPath: respWav); + await RunSynthWavAsync(repoRoot, ThirdPartyMessage, freqHz: 800, seed: 5, outPath: thirdWav); + Console.WriteLine(" wrote 4 WAVs (CQ x2 distinct renders, response-to-us, third-party)."); + + // ── Step 2: decode each with the REAL native decoder ──────────────────────── + Console.WriteLine("[2/3] Decoding all four with the real Ft8Decoder (libft8 P/Invoke) ..."); + var clock = new FixedClock(new DateTime(2026, 7, 14, 12, 0, 0, DateTimeKind.Utc)); + + var cqDecode1 = await DecodeOneAsync(clock, cqWav1, CqMessage, failures, "CQ (1st render)"); + var cqDecode2 = await DecodeOneAsync(clock, cqWav2, CqMessage, failures, "CQ (2nd render — the re-transmission)"); + var respDecode = await DecodeOneAsync(clock, respWav, RespToUsMessage, failures, "response to us"); + var thirdDecode = await DecodeOneAsync(clock, thirdWav, ThirdPartyMessage, failures, "third-party message"); + + if (failures.Count > 0) { Report(failures); return 1; } + + Console.WriteLine($" CQ (1st): {cqDecode1!.Message}"); + Console.WriteLine($" CQ (2nd/re-tx): {cqDecode2!.Message}"); + Console.WriteLine($" response-to-us: {respDecode!.Message}"); + Console.WriteLine($" third-party: {thirdDecode!.Message}"); + + // ── Step 3: drive the real services ────────────────────────────────────────── + Console.WriteLine("[3/3] Driving real QsoAnswererService / QsoCallerService with the decoded batches:"); + await RunAnswererScenarioAsync(cqDecode1, cqDecode2, thirdDecode, failures); + await RunCallerScenarioAsync(respDecode, cqDecode2, thirdDecode, failures); + } + finally + { + try { Directory.Delete(workDir, recursive: true); } catch { /* best-effort cleanup */ } + } + } + catch (Exception ex) + { + failures.Add($"Unhandled exception: {ex}"); + } + + Report(failures); + return failures.Count == 0 ? 0 : 1; + } + + // ── Decode helper ──────────────────────────────────────────────────────────────────────── + + private static async Task DecodeOneAsync( + IClock clock, string wavPath, string expectedMessage, List failures, string label) + { + float[] pcm = ReadMono16BitWav(wavPath, expectedSampleRateHz: 12_000); + + var decoder = new Ft8Decoder(clock, logger: null, grammarStore: null, regionStore: null, workedBeforeIndex: null); + IReadOnlyList decoded = await decoder.DecodeAsync(pcm, clock.UtcNow, CancellationToken.None); + var messages = decoded.Select(r => r.Message).ToList(); + + Check(failures, messages.Contains(expectedMessage), + $"{label}: real decoder must recover '{expectedMessage}'. Decoded: [{string.Join(", ", messages)}]"); + + return decoded.FirstOrDefault(r => r.Message == expectedMessage); + } + + // ── QsoAnswererService scenario ────────────────────────────────────────────────────────── + + private static async Task RunAnswererScenarioAsync( + DecodeResult cq1, DecodeResult cq2, DecodeResult third, List failures) + { + const string label = "QsoAnswererService"; + + var ptt = new RecordingPttController(); + var configStore = new SimpleConfigStore(new AppConfig() with + { + Tx = new TxConfig { AutoAnswer = true, Callsign = OurCallsign, Grid = OurGrid, RetryCount = 2, WatchdogMinutes = 4 }, + }); + var adifLog = new AdifLogWriter(configStore, NullLogger.Instance); + var channel = Channel.CreateUnbounded(); + + var sut = new QsoAnswererService( + channel.Reader, configStore, ptt, new TxEventBus(), + adifLog, new AudioOffsetEventBus(), NullLogger.Instance, + decoder: null, catState: null, decodeFilterStore: null); + + var stopCts = new CancellationTokenSource(); + await sut.StartAsync(stopCts.Token); + + try + { + // Engage on the partner's CQ. + channel.Writer.TryWrite(new DecodeBatch(DateTimeOffset.UtcNow, [cq1])); + bool engaged = await WaitForStateAsync(sut, QsoState.WaitReport, TimeSpan.FromSeconds(5)); + Check(failures, engaged, $"[{label}] expected WaitReport after engaging partner's CQ; actual state {sut.State}."); + Check(failures, sut.Partner == PartnerCall, $"[{label}] expected partner '{PartnerCall}'; actual '{sut.Partner ?? "(none)"}'."); + Console.WriteLine(engaged && sut.Partner == PartnerCall + ? $" OK [{label,-20}] engaged {sut.Partner}, state = WaitReport" + : $" FAIL[{label,-20}] engage failed — state = {sut.State}, partner = {sut.Partner ?? "(none)"}"); + + // D-CALLER-020: partner re-transmits their own CQ instead of answering — must NOT abort. + channel.Writer.TryWrite(new DecodeBatch(DateTimeOffset.UtcNow, [cq2])); + await Task.Delay(400); + bool stillWaiting = sut.State == QsoState.WaitReport; + Check(failures, stillWaiting, + $"[{label}] D-CALLER-020 regression: partner re-transmitting their own CQ must not abort the QSO; actual state {sut.State}."); + Console.WriteLine(stillWaiting + ? $" OK [{label,-20}] partner's own CQ re-transmission did NOT abort — still WaitReport" + : $" FAIL[{label,-20}] partner's own CQ re-transmission caused an abort — state = {sut.State}"); + + // Control: a genuine third-party message must still abort immediately (AC-2). + channel.Writer.TryWrite(new DecodeBatch(DateTimeOffset.UtcNow, [third])); + bool aborted = await WaitForStateAsync(sut, QsoState.Idle, TimeSpan.FromSeconds(5)); + Check(failures, aborted, + $"[{label}] control case: partner addressing a genuine third station must still abort; actual state {sut.State}."); + Console.WriteLine(aborted + ? $" OK [{label,-20}] genuine third-party message still aborts to Idle (AC-2 unaffected)" + : $" FAIL[{label,-20}] genuine third-party message did not abort — state = {sut.State}"); + } + finally + { + await stopCts.CancelAsync(); + await sut.StopAsync(CancellationToken.None); + await ptt.DisposeAsync(); + } + } + + // ── QsoCallerService scenario ──────────────────────────────────────────────────────────── + + private static async Task RunCallerScenarioAsync( + DecodeResult respToUs, DecodeResult cqReTx, DecodeResult third, List failures) + { + const string label = "QsoCallerService"; + + var ptt = new RecordingPttController(); + var configStore = new SimpleConfigStore(new AppConfig() with + { + Tx = new TxConfig + { + AutoAnswer = true, + Callsign = OurCallsign, + Grid = OurGrid, + CallerPartnerSelect = CallerPartnerSelectMode.First, + RetryCount = 2, + WatchdogMinutes = 4, + }, + }); + var adifLog = new AdifLogWriter(configStore, NullLogger.Instance); + var channel = Channel.CreateUnbounded(); + + var sut = new QsoCallerService( + channel.Reader, configStore, ptt, new TxEventBus(), + adifLog, new AudioOffsetEventBus(), NullLogger.Instance, + decoder: null, catState: null, decodeFilterStore: null); + + var stopCts = new CancellationTokenSource(); + await sut.StartAsync(stopCts.Token); + + try + { + // Prime into WaitAnswer (WaitReport) with an irrelevant decode so our own CQ TX fires, + // exactly mirroring QsoCallerServiceTests' own priming step. + channel.Writer.TryWrite(new DecodeBatch(DateTimeOffset.UtcNow, + [new DecodeResult(Time: "12:00:00", Snr: -5, Dt: 0.1, FreqHz: 800, Message: "CQ Q2NOISE JO00")])); + bool primed = await WaitForStateAsync(sut, QsoState.WaitReport, TimeSpan.FromSeconds(5)); + Check(failures, primed, $"[{label}] failed to reach WaitAnswer during priming."); + + // Partner responds to our CQ — advances TxReport → WaitRr73. + channel.Writer.TryWrite(new DecodeBatch(DateTimeOffset.UtcNow, [respToUs])); + bool inWaitRr73 = await WaitForStateAsync(sut, QsoState.WaitRr73, TimeSpan.FromSeconds(5)); + Check(failures, inWaitRr73, $"[{label}] expected WaitRr73 after partner's response; actual state {sut.State}."); + Check(failures, sut.Partner == PartnerCall, $"[{label}] expected partner '{PartnerCall}'; actual '{sut.Partner ?? "(none)"}'."); + Console.WriteLine(inWaitRr73 && sut.Partner == PartnerCall + ? $" OK [{label,-20}] partner {sut.Partner} responded, state = WaitRr73" + : $" FAIL[{label,-20}] failed to reach WaitRr73 — state = {sut.State}, partner = {sut.Partner ?? "(none)"}"); + + // D-CALLER-020: partner re-transmits their own CQ instead of sending RR73 — must NOT abort. + channel.Writer.TryWrite(new DecodeBatch(DateTimeOffset.UtcNow, [cqReTx])); + await Task.Delay(400); + bool stillWaiting = sut.State == QsoState.WaitRr73; + Check(failures, stillWaiting, + $"[{label}] D-CALLER-020 regression: partner re-transmitting their own CQ must not abort the QSO; actual state {sut.State}."); + Console.WriteLine(stillWaiting + ? $" OK [{label,-20}] partner's own CQ re-transmission did NOT abort — still WaitRr73" + : $" FAIL[{label,-20}] partner's own CQ re-transmission caused an abort — state = {sut.State}"); + + // Control: a genuine third-party message must still abort immediately (AC-4). + channel.Writer.TryWrite(new DecodeBatch(DateTimeOffset.UtcNow, [third])); + bool aborted = await WaitForStateAsync(sut, QsoState.Idle, TimeSpan.FromSeconds(5)); + Check(failures, aborted, + $"[{label}] control case: partner addressing a genuine third station must still abort; actual state {sut.State}."); + Console.WriteLine(aborted + ? $" OK [{label,-20}] genuine third-party message still aborts to Idle (AC-4 unaffected)" + : $" FAIL[{label,-20}] genuine third-party message did not abort — state = {sut.State}"); + } + finally + { + await stopCts.CancelAsync(); + await sut.StopAsync(CancellationToken.None); + await ptt.DisposeAsync(); + } + } + + // ── Shared wait / check / report helpers ───────────────────────────────────────────────── + + private static async Task WaitForStateAsync(QsoAnswererService svc, QsoState expected, TimeSpan timeout) + { + var deadline = DateTime.UtcNow + timeout; + while (DateTime.UtcNow < deadline) + { + if (svc.State == expected) return true; + await Task.Delay(20); + } + return false; + } + + private static async Task WaitForStateAsync(QsoCallerService svc, QsoState expected, TimeSpan timeout) + { + var deadline = DateTime.UtcNow + timeout; + while (DateTime.UtcNow < deadline) + { + if (svc.State == expected) return true; + await Task.Delay(20); + } + return false; + } + + private static void Check(List failures, bool condition, string failureMessage) + { + if (!condition) failures.Add(failureMessage); + } + + private static void Report(List failures) + { + Console.WriteLine(); + if (failures.Count == 0) + { + Console.WriteLine("RESULT: PASS — the partner re-transmitting their own CQ no longer aborts either service's " + + "WaitReport/WaitRr73 wait; genuine third-party messages still abort correctly."); + return; + } + + Console.WriteLine($"RESULT: FAIL — {failures.Count} check(s) failed:"); + foreach (var f in failures) + Console.WriteLine($" - {f}"); + } + + // ── Synthesiser subprocess ─────────────────────────────────────────────────────────────── + + private static async Task RunSynthWavAsync(string repoRoot, string message, int freqHz, int seed, string outPath) + { + string pythonExe = ResolvePythonExe(repoRoot); + string synthScript = Path.Combine(repoRoot, "qa", "rr-study", "synth_wav.py"); + + if (!File.Exists(pythonExe)) + throw new FileNotFoundException( + $"R&R study venv Python not found at '{pythonExe}'. Set up the venv first: " + + "cd qa/rr-study && python -m venv .venv && .venv/Scripts/pip install -r requirements.txt " + + "(see docs/rr-synth-cli-guide.md).", pythonExe); + if (!File.Exists(synthScript)) + throw new FileNotFoundException($"synth_wav.py not found at '{synthScript}'.", synthScript); + + var psi = new ProcessStartInfo(pythonExe) + { + WorkingDirectory = Path.Combine(repoRoot, "qa", "rr-study"), + RedirectStandardOutput = true, + RedirectStandardError = true, + UseShellExecute = false, + }; + psi.ArgumentList.Add(synthScript); + psi.ArgumentList.Add(message); + psi.ArgumentList.Add("--freq"); + psi.ArgumentList.Add(freqHz.ToString()); + psi.ArgumentList.Add("--rate"); + psi.ArgumentList.Add("12000"); + psi.ArgumentList.Add("--snr"); + psi.ArgumentList.Add("none"); + psi.ArgumentList.Add("--seed"); + psi.ArgumentList.Add(seed.ToString()); + psi.ArgumentList.Add("--out"); + psi.ArgumentList.Add(outPath); + + using var process = Process.Start(psi) + ?? throw new InvalidOperationException($"Failed to start process: {pythonExe}"); + + string stdout = await process.StandardOutput.ReadToEndAsync(); + string stderr = await process.StandardError.ReadToEndAsync(); + await process.WaitForExitAsync(); + + if (process.ExitCode != 0) + throw new InvalidOperationException( + $"synth_wav.py failed (exit {process.ExitCode}) for message '{message}':\n{stdout}\n{stderr}"); + } + + private static string ResolvePythonExe(string repoRoot) + { + var venvDir = Path.Combine(repoRoot, "qa", "rr-study", ".venv"); + var windows = Path.Combine(venvDir, "Scripts", "python.exe"); + var posix = Path.Combine(venvDir, "bin", "python"); + return File.Exists(windows) ? windows : posix; + } + + private static string FindRepoRoot() + { + var dir = AppContext.BaseDirectory; + while (dir is not null) + { + if (File.Exists(Path.Combine(dir, "OpenWSFZ.slnx"))) + return dir; + dir = Path.GetDirectoryName(dir); + } + throw new DirectoryNotFoundException("Could not locate repository root (OpenWSFZ.slnx not found)."); + } + + // ── Minimal WAV reader (12 kHz mono 16-bit PCM only) ───────────────────────────────────── + + private static float[] ReadMono16BitWav(string path, int expectedSampleRateHz) + { + using var stream = File.OpenRead(path); + using var reader = new BinaryReader(stream); + + string riff = new string(reader.ReadChars(4)); + if (riff != "RIFF") throw new InvalidDataException($"'{path}': not a RIFF file."); + reader.ReadInt32(); + string wave = new string(reader.ReadChars(4)); + if (wave != "WAVE") throw new InvalidDataException($"'{path}': RIFF subtype is not WAVE."); + + int sampleRate = 0; + byte[]? data = null; + + while (stream.Position + 8 <= stream.Length) + { + string chunkId = new string(reader.ReadChars(4)); + int chunkSize = reader.ReadInt32(); + + if (chunkId == "fmt ") + { + reader.ReadInt16(); // audio format + reader.ReadInt16(); // channels + sampleRate = reader.ReadInt32(); + reader.ReadInt32(); // byte rate + reader.ReadInt16(); // block align + reader.ReadInt16(); // bits per sample + int extra = chunkSize - 16; + if (extra > 0) reader.ReadBytes(extra); + } + else if (chunkId == "data") + { + data = reader.ReadBytes(chunkSize); + } + else + { + reader.ReadBytes(chunkSize); + } + if (chunkSize % 2 != 0 && stream.Position < stream.Length) reader.ReadByte(); + } + + if (sampleRate != expectedSampleRateHz) + throw new InvalidDataException($"'{path}': expected {expectedSampleRateHz} Hz, got {sampleRate} Hz."); + if (data is null) + throw new InvalidDataException($"'{path}': no data chunk found."); + + var pcm = new float[data.Length / 2]; + for (int i = 0; i < pcm.Length; i++) + { + short s = (short)(data[i * 2] | (data[i * 2 + 1] << 8)); + pcm[i] = s / 32768.0f; + } + return pcm; + } + + // ── Small local test doubles (clock, config store, PTT) ───────────────────────────────── + + private sealed class FixedClock(DateTime utcNow) : IClock + { + public DateTime UtcNow { get; } = utcNow; + } + + private sealed class SimpleConfigStore(AppConfig current) : IConfigStore + { + public AppConfig Current { get; } = current; + public event Action? OnSaved; + public Task SaveAsync(AppConfig config, CancellationToken ct = default) + { + OnSaved?.Invoke(config); + return Task.CompletedTask; + } + } + + /// Records whether was ever called — proof the service + /// genuinely engaged, without any real (or virtual) PTT hardware. + private sealed class RecordingPttController : IPttController + { + public bool KeyedDown { get; private set; } + public void LoadAudio(float[] samples) { } + public Task KeyDownAsync(CancellationToken ct = default) { KeyedDown = true; return Task.CompletedTask; } + public Task KeyUpAsync(CancellationToken ct = default) => Task.CompletedTask; + public ValueTask DisposeAsync() => ValueTask.CompletedTask; + } +} diff --git a/qa/d-caller-020-working-cq-false-abort-verify/README.md b/qa/d-caller-020-working-cq-false-abort-verify/README.md new file mode 100644 index 0000000..f725d9b --- /dev/null +++ b/qa/d-caller-020-working-cq-false-abort-verify/README.md @@ -0,0 +1,58 @@ +# D-CALLER-020 working-CQ false-abort — live verification + +`Program.cs` is the live verification required by +`dev-tasks/2026-07-14-working-cq-false-abort.md` §5 — the "synthetic-decode harness" alternative +to a full real-hardware reproduction (no CAT/audio hardware or virtual audio cable needed, unlike +`qa/d-caller-018-abort-hard-stop-live-verify/` or `qa/decode-filter-synth-verify/live_verify_9_axes.py`). + +It goes beyond the dev-task's stated minimum (replaying a static log excerpt through some harness) +by genuinely re-synthesising the partner's CQ signal fresh every run +(`qa/rr-study/synth_wav.py`) and decoding it with the real, unmocked `Ft8Decoder` — an actual +P/Invoke call into `libft8`, the same native decoder the daemon ships with — then feeding the +decoded batches into the real, unmodified `QsoAnswererService`/`QsoCallerService` production +classes. This is stronger evidence than the unit tests added alongside the fix +(`QsoAnswererServiceTests.WaitReport_PartnerStillCallingCq_DoesNotAbort_RetriesInstead`, +`QsoCallerServiceTests.WaitRr73_PartnerStillCallingCq_DoesNotAbort_RetriesInstead`), which inject +hand-authored `DecodeResult` message strings rather than a genuine encode→synthesise→decode +round-trip. + +Run it after `dotnet build OpenWSFZ.slnx -c Release`: + +``` +dotnet run -c Release --project qa/d-caller-020-working-cq-false-abort-verify +``` + +Requires the R&R study's Python venv (`qa/rr-study/.venv`) to already exist — see +`docs/rr-synth-cli-guide.md` if it doesn't. No audio hardware, PTT, or virtual audio cable is +needed: everything from "FT8 signal exists" through "the service reaches the right state" runs +in-process against real production code. Exit 0 = PASS, non-zero = FAIL. + +## What it does + +1. Synthesises four FT8 signals fresh every run: the partner's CQ (`CQ Q1TST JO22`) rendered + *twice* with different seeds — standing in for "partner calls CQ", then "partner calls CQ + again a cycle later" (the field sequence from `logs/openswfz-20260714T171230Z.log`) — a + response to our own CQ (`Q1OFZ Q1TST JO22`, used to drive the caller side into `WaitRr73`), + and a genuine third-party message (`Q2OTR Q1TST +03`, the control case that must still abort). +2. Decodes all four with the real `Ft8Decoder`. +3. Drives a real `QsoAnswererService` through: engage on the partner's CQ → feed the partner's + second CQ render → assert **no abort** (D-CALLER-020) → feed the third-party message → + assert **abort to `Idle`** (AC-2, unaffected). +4. Drives a real `QsoCallerService` through the symmetric sequence in `WaitRr73`: prime → + partner responds → feed the partner's CQ re-transmission → assert **no abort** + (D-CALLER-020) → feed the third-party message → assert **abort to `Idle`** (AC-4, unaffected). + +## Callsign note + +`Q2OTR` (not `Q2OTHER`, as the unit tests use) — the synthesiser's callsign packer requires a +digit at index 1 with length ≤ 5 (or digit at index 2 with length ≤ 6) to compress into the +standard 28-bit callsign field; `Q2OTHER` (7 chars) doesn't fit either form and would decode back +as a hashed `<...>` placeholder instead of literal text. The unit tests don't hit this because +they inject `DecodeResult` strings directly, bypassing real FT8 packing entirely. + +## `live-reports/` — what's in here + +- **`2026-07-14T183903Z-7b330e1.md` — PASS.** Includes the deliberate control run (fix reverted + via `git apply -R` on just the two production files, tool rebuilt and re-run) that reproduces + the exact regression on both services before the fix was restored — proving this tool actually + catches the defect rather than false-passing regardless of the fix. diff --git a/qa/d-caller-020-working-cq-false-abort-verify/live-reports/2026-07-14T183903Z-7b330e1.md b/qa/d-caller-020-working-cq-false-abort-verify/live-reports/2026-07-14T183903Z-7b330e1.md new file mode 100644 index 0000000..3a292ba --- /dev/null +++ b/qa/d-caller-020-working-cq-false-abort-verify/live-reports/2026-07-14T183903Z-7b330e1.md @@ -0,0 +1,65 @@ +# D-CALLER-020 live verification — PASS + +**When:** 2026-07-14T18:39:03Z +**Base commit:** `7b330e1` (branch `fix/d-caller-020-working-cq-false-abort`, fix applied on top, +uncommitted at run time) +**Tool:** `qa/d-caller-020-working-cq-false-abort-verify/` (`dotnet run -c Release`) + +## What this proves + +Per `dev-tasks/2026-07-14-working-cq-false-abort.md` §5, this closes the "synthetic-decode +harness" alternative to full real-hardware reproduction — and goes a step further than the +minimum bar (replaying a static log excerpt) by genuinely re-synthesising and re-decoding the +partner's CQ through the real, unmocked `Ft8Decoder` (libft8 P/Invoke) each run, then driving the +real, unmodified `QsoAnswererService`/`QsoCallerService` production classes with the decoded +batches — not hand-authored `DecodeResult` strings as the unit tests use. + +## Sequence exercised + +1. Synthesise 4 FT8 signals fresh (`qa/rr-study/synth_wav.py`): the partner's CQ rendered twice + with different seeds (`CQ Q1TST JO22`), a response to our own CQ (`Q1OFZ Q1TST JO22`), and a + genuine third-party message (`Q2OTR Q1TST +03`). +2. Decode all four with the real `Ft8Decoder` — all four recovered correctly. +3. **`QsoAnswererService`:** engage on the partner's CQ (→ `WaitReport`) → feed the partner's + *second* CQ render (the re-transmission) → **must not abort** → feed the genuine third-party + message → **must abort to `Idle`** (control, AC-2). +4. **`QsoCallerService`:** prime into `WaitAnswer`/`WaitReport` → partner responds (→ `WaitRr73`) + → feed the partner's CQ re-transmission → **must not abort** → feed the genuine third-party + message → **must abort to `Idle`** (control, AC-4). + +## Result + +``` +[3/3] Driving real QsoAnswererService / QsoCallerService with the decoded batches: + OK [QsoAnswererService ] engaged Q1TST, state = WaitReport + OK [QsoAnswererService ] partner's own CQ re-transmission did NOT abort — still WaitReport + OK [QsoAnswererService ] genuine third-party message still aborts to Idle (AC-2 unaffected) + OK [QsoCallerService ] partner Q1TST responded, state = WaitRr73 + OK [QsoCallerService ] partner's own CQ re-transmission did NOT abort — still WaitRr73 + OK [QsoCallerService ] genuine third-party message still aborts to Idle (AC-4 unaffected) + +RESULT: PASS — the partner re-transmitting their own CQ no longer aborts either service's +WaitReport/WaitRr73 wait; genuine third-party messages still abort correctly. +``` + +## Control run (fix deliberately reverted) + +Before this PASS run, `git apply -R` was used to strip just the `dest.Equals("CQ", ...)` guard +from both `QsoAnswererService.cs` and `QsoCallerService.cs` (production files only, tests +untouched), the tool was rebuilt, and re-run — reproducing the exact field regression on both +services: + +``` + FAIL[QsoAnswererService ] partner's own CQ re-transmission caused an abort — state = Idle + FAIL[QsoCallerService ] partner's own CQ re-transmission caused an abort — state = Idle + +RESULT: FAIL — 2 check(s) failed: + - [QsoAnswererService] D-CALLER-020 regression: partner re-transmitting their own CQ must not + abort the QSO; actual state Idle. + - [QsoCallerService] D-CALLER-020 regression: partner re-transmitting their own CQ must not + abort the QSO; actual state Idle. +``` + +The fix was then re-applied (`git apply`) and the tool re-run, producing the PASS output recorded +above — proving the tool genuinely catches the regression rather than trivially passing +regardless of the fix. diff --git a/src/OpenWSFZ.Daemon/QsoAnswererService.cs b/src/OpenWSFZ.Daemon/QsoAnswererService.cs index c4774da..8d0342b 100644 --- a/src/OpenWSFZ.Daemon/QsoAnswererService.cs +++ b/src/OpenWSFZ.Daemon/QsoAnswererService.cs @@ -1027,8 +1027,9 @@ private async Task HandleWaitReportAsync( } } - // ── Partner is working another station — abort ── - if (fromPartner && !toUs) + // ── Partner working another station — abort. Distinguish this from the partner simply + // still calling CQ (dest == "CQ"), which is not evidence they've moved on — see D-CALLER-020. ── + if (fromPartner && !toUs && !dest.Equals("CQ", StringComparison.OrdinalIgnoreCase)) { _logger.LogInformation( "QsoAnswererService: {Partner} is working {OtherDest} — aborting.", diff --git a/src/OpenWSFZ.Daemon/QsoCallerService.cs b/src/OpenWSFZ.Daemon/QsoCallerService.cs index 8efb9c9..c7608c1 100644 --- a/src/OpenWSFZ.Daemon/QsoCallerService.cs +++ b/src/OpenWSFZ.Daemon/QsoCallerService.cs @@ -800,8 +800,9 @@ private async Task HandleWaitRr73Async( } } - // Partner working another station. - if (fromPartner && !toUs) + // Partner working another station — abort. Distinguish this from the partner simply + // still calling CQ (dest == "CQ"), which is not evidence they've moved on — see D-CALLER-020. + if (fromPartner && !toUs && !dest.Equals("CQ", StringComparison.OrdinalIgnoreCase)) { _logger.LogInformation( "QsoCallerService: {Partner} is working {OtherDest} — aborting.", diff --git a/tests/OpenWSFZ.Daemon.Tests/QsoAnswererServiceTests.cs b/tests/OpenWSFZ.Daemon.Tests/QsoAnswererServiceTests.cs index 337e9a4..6dcb7f7 100644 --- a/tests/OpenWSFZ.Daemon.Tests/QsoAnswererServiceTests.cs +++ b/tests/OpenWSFZ.Daemon.Tests/QsoAnswererServiceTests.cs @@ -456,6 +456,38 @@ await WaitForStateAsync(_sut!, QsoState.Idle, timeout: TimeSpan.FromSeconds(3)); } + [Fact(DisplayName = "D-CALLER-020: Partner re-transmitting own CQ in WaitReport does not abort — retries then exhausts")] + public async Task WaitReport_PartnerStillCallingCq_DoesNotAbort_RetriesInstead() + { + // Reach WaitReport. + Send(Make($"CQ {PartnerCall} {PartnerGrid}")); + await WaitForStateAsync(_sut!, QsoState.WaitReport); + + // Partner re-transmits their own CQ instead of answering us. This must NOT be treated + // as "partner is working another station" — they simply haven't decoded us yet. + Send(Make($"CQ {PartnerCall} {PartnerGrid}")); + await Task.Delay(200); + _sut!.State.Should().Be(QsoState.WaitReport, + "the partner still calling CQ is not evidence they've moved on (D-CALLER-020) — must not abort"); + + // The repeated CQ must fall through to the same "no matching message" retry path as + // genuine silence — drive the identical retry-exhaustion sequence as the noise-based + // test below (tx.RetryCount = 2; pattern: [skip] [retry1] [skip] [retry2] [skip] [abort]) + // to prove the existing RetryOrAbortAsync backstop — not a same-cycle snap decision — + // is what eventually ends a truly one-sided QSO. + Send(Make($"CQ {PartnerCall} {PartnerGrid}")); // cycle 2: retry 1 TX + await Task.Delay(150); + Send(Make($"CQ {PartnerCall} {PartnerGrid}")); // cycle 3: skip — retry 1 TX window + await Task.Delay(150); + Send(Make($"CQ {PartnerCall} {PartnerGrid}")); // cycle 4: retry 2 TX + await Task.Delay(150); + Send(Make($"CQ {PartnerCall} {PartnerGrid}")); // cycle 5: skip — retry 2 TX window + await Task.Delay(150); + Send(Make($"CQ {PartnerCall} {PartnerGrid}")); // cycle 6: retry count exhausted → abort + await WaitForStateAsync(_sut!, QsoState.Idle, + timeout: TimeSpan.FromSeconds(5)); + } + [Fact(DisplayName = "6.6: No matching decode in WaitReport → retry; after max retries → Idle")] public async Task WaitReport_NoResponse_RetriesThenAborts() { diff --git a/tests/OpenWSFZ.Daemon.Tests/QsoCallerServiceTests.cs b/tests/OpenWSFZ.Daemon.Tests/QsoCallerServiceTests.cs index 6d2f140..0284c99 100644 --- a/tests/OpenWSFZ.Daemon.Tests/QsoCallerServiceTests.cs +++ b/tests/OpenWSFZ.Daemon.Tests/QsoCallerServiceTests.cs @@ -730,6 +730,63 @@ public async Task WaitRr73_PartnerWorkingOther_Aborts() await ptt.DisposeAsync(); } + // ── D-CALLER-020: Partner still calling CQ in WaitRr73 must not abort ──── + + [Fact(DisplayName = "D-CALLER-020: HandleWaitRr73Async — partner re-transmitting own CQ does not abort — retries then exhausts")] + public async Task WaitRr73_PartnerStillCallingCq_DoesNotAbort_RetriesInstead() + { + var tx = new TxConfig + { + AutoAnswer = true, + Callsign = OurCallsign, + Grid = OurGrid, + CallerPartnerSelect = CallerPartnerSelectMode.First, + RetryCount = 2, + WatchdogMinutes = 4, + }; + var (sut, eventBus, _, ptt, channel, stopCts) = BuildIsolatedSut(tx, watchdogDuration: TimeSpan.FromSeconds(30)); + await sut.StartAsync(stopCts.Token); + + Send(channel, Make("CQ Q2NOISE JO00")); + await WaitForStateAsync(sut, QsoState.WaitReport, timeout: TimeSpan.FromSeconds(5)); + + Send(channel, Make($"{OurCallsign} {PartnerCall} {PartnerGrid}")); + await WaitForStateAsync(sut, QsoState.WaitRr73, timeout: TimeSpan.FromSeconds(5)); + + // Partner re-transmits their own CQ instead of RR73 — must NOT be treated as "partner is + // working another station"; they simply haven't decoded our report yet. + Send(channel, Make($"CQ {PartnerCall} {PartnerGrid}")); + await Task.Delay(200); + sut.State.Should().Be(QsoState.WaitRr73, + "the partner still calling CQ is not evidence they've moved on (D-CALLER-020) — must not abort"); + + // The repeated CQ must fall through to the same "no matching message" retry path as + // genuine silence — drive the identical retry-exhaustion sequence as the answerer-side + // test (tx.RetryCount = 2; pattern: [skip] [retry1] [skip] [retry2] [skip] [abort]) to + // prove the existing RetryOrAbortAsync backstop is what eventually ends a one-sided QSO. + Send(channel, Make($"CQ {PartnerCall} {PartnerGrid}")); // cycle 2: retry 1 TX + await Task.Delay(150); + Send(channel, Make($"CQ {PartnerCall} {PartnerGrid}")); // cycle 3: skip — retry 1 TX window + await Task.Delay(150); + Send(channel, Make($"CQ {PartnerCall} {PartnerGrid}")); // cycle 4: retry 2 TX + await Task.Delay(150); + Send(channel, Make($"CQ {PartnerCall} {PartnerGrid}")); // cycle 5: skip — retry 2 TX window + await Task.Delay(150); + Send(channel, Make($"CQ {PartnerCall} {PartnerGrid}")); // cycle 6: retry count exhausted → abort + await WaitForStateAsync(sut, QsoState.Idle, timeout: TimeSpan.FromSeconds(5)); + + eventBus.Received().Publish( + "Idle", + "caller", + Arg.Any(), + false, + $"No response from {PartnerCall} after 2 retries"); + + await stopCts.CancelAsync(); + await sut.StopAsync(CancellationToken.None); + await ptt.DisposeAsync(); + } + // ── 5.10: Retry logic ───────────────────────────────────────────────────── [Fact(DisplayName = "5.10: WaitAnswer no response — retransmits CQ; exhausted aborts with CQ-retry reason")]