diff --git a/CHANGELOG-INTERNAL.md b/CHANGELOG-INTERNAL.md index b8e47ef..7a1a7be 100644 --- a/CHANGELOG-INTERNAL.md +++ b/CHANGELOG-INTERNAL.md @@ -97,6 +97,52 @@ a `### BREAKING` section placed FIRST in that version, and each such line is pre - Help text and the flag tables in both READMEs now state that the flag is valid on its own. - Version bump deliberately NOT taken (convention 34): the owner closes it in `VERSION.txt`. +### Added: the CLI reports a target that stops matching, and what share was in scope (audit F17) + +- **Symptom, measured before writing anything** (2026-07-28, elevated, real WinDivert, probe + narrowed to `--target --dst-ip 8.8.8.8 --dst-port 53 --syn-drop 100`). A process was + targeted BY PID, impaired correctly (1 of 6 connections slipped, the rest timed out), then killed + and restarted under a new pid: **5 of 5 fresh connections untouched**, `scoped_seen` flat, and the + only targeting line in the whole run was the one `apply_targeting` prints at start. `exit=OK`. +- **Same probe, targeting BY NAME**, 3 lives x 4 held connections: `OK FAIL FAIL FAIL` in **3 of 3** + lives. So the name path recovers by itself and the restart costs exactly one connection - the one + opened before the process owns any socket, which is the `_pids` limitation F16 already documents, + not a new one. `drop_syn` cross-checks at exactly 2 per caught connection (SYN + one retransmit + inside the 2.5 s connect timeout). +- **The asymmetry this exposes.** `gui/app.py::_refresh_target` re-reads `targeting.matched` on + every tick and raises `fields.target_no_match`, so the GUI has always shouted about this. The CLI + - the CI/CD interface (convention 18) - resolved once in `apply_targeting(announce=True)` and + never looked again; `_report_loop` did not mention targeting at all. +- **Fix, all in `cli.py`.** `_targeting_state(engine)` returns `(matched, describe())` or `None`, + and `_report_loop` logs only the TRANSITION: `warn` when the target stops matching, `info` when it + comes back. Reading `matched` is a plain bool on the live `ProcessTargeting` - no lock, no + syscall, no socket table - so the loop can ask on every pass. `getattr` on `engine.targeting` + because `run_cli(engine=...)` is a public seam. Sampled, not continuous: a verdict that flips and + flips back between two passes is not seen, and the comment says so rather than implying otherwise. +- **End of run:** a `warn` when a target was set, traffic WAS captured and `scoped_seen` is 0, plus + an `In scope: X of Y captured packets` line in the text summary. Guarded by `stats["seen"]` on + purpose - with nothing captured at all the capture filter is the story and `--min-packets` is the + flag that tells it, so saying both would point at the wrong thing. +- **Deliberately NOT done:** no new exit code and no `--min-scoped` flag. A target with no traffic + of its own is a legitimate run, and making it an assertion would change the exit-code contract + under everyone already running one. The number is in the JSON summary's `counters.scoped_seen` for + a pipeline that wants to assert on it itself. The NDJSON `sample` schema is untouched (the frozen + contract); the new line goes down the TEXT channel only. +- Two new guards in `tests/test_cli_runtime.py`: + `::test_the_run_says_when_the_process_target_stops_matching` (transition reported, reported ONCE, + and silent while the target keeps matching) and + `::test_a_target_that_caught_nothing_is_called_out_at_the_end` (zero scope called out, non-zero + scope not accused, no-traffic-at-all not blamed on the target). Both drive a `_TargetedEngine` + fake: a real engine cannot play this part, since `--target` is stripped under `--simulate` and a + real capture needs WinDivert plus elevation. `winenv.is_admin` is monkeypatched so the pair cannot + become a THIRD environment-dependent result in this file. +- The fake's stats dict is copied from a real `BeanEngine().st`, so a counter added to the engine + cannot leave it answering with a key the CLI reads. +- **Five mutants, all caught** (source rewritten as BYTES - `write_text` would flip the file to CRLF + and trip the changelog hook): transition logging removed; transition logging fired every pass + instead of on change; the zero-scope warning removed; its `stats["seen"]` guard removed; the + `In scope` line removed. Each went red on its intended assertion. + ### Fixed: the first packet of a fresh connection can be in targeting scope (audit F16) - **Symptom, measured end to end before writing anything.** `ProcessTargeting.__contains__` answers diff --git a/CHANGELOG.md b/CHANGELOG.md index c37898c..3d5ba03 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -82,6 +82,26 @@ The format follows [Keep a Changelog](https://keepachangelog.com/); versions fol ### Added +- **The command line now says when the process you aimed at stops matching, instead of running on + in silence.** If your target exits - it crashed, or your test harness restarted it and Windows + gave it a new process id - everything from that moment on is left untouched. The run used to + carry on and finish green, with the only mention of your target being one line printed at the + start. Measured here against a real capture: aiming at a process id and then restarting that + program left five out of five of its new connections completely untouched, and nothing in the + output said so. The run now says it the moment it notices, and says so again if the target comes + back. Worth knowing which form to use: aiming by **name** recovers on its own within about half a + second of the restarted program opening its first connection, and only that first connection + escapes; aiming by **process id** never recovers, because that id no longer exists. If the + program under test restarts, aim by name. + +- **Every run with a process target now ends by saying how much of the captured traffic was + actually yours** - "In scope: 40 of 500 captured packets" - and calls it out when that number is + zero. A run in which your target caught nothing looks exactly like a run in which your + application coped, and those are opposite results. The existing `--min-packets` check cannot see + this: it catches a traffic filter that matched nothing, which is a different mistake. This is a + warning rather than a failure, because aiming at a program that happens to be quiet is a + perfectly ordinary thing to do. + - **The session panel now shows how long packets waited inside the driver before the tool saw them.** This is the one delay the tool adds and counted nowhere: it happens in WinDivert's queue, ahead of the tool's own, so a tester measuring latency puts it down to their application or to diff --git a/beantester/cli.py b/beantester/cli.py index 807f2bd..cf46435 100644 --- a/beantester/cli.py +++ b/beantester/cli.py @@ -387,6 +387,21 @@ def _run_cleanup(log): # -- the session ---------------------------------------------------------------- # +def _targeting_state(engine): + """``(matched, description)`` of the live process target, or ``None``. + + ``matched`` is a plain bool on the live ``ProcessTargeting`` - no lock, no + syscall, no socket table - so the report loop can afford to ask on every + pass. ``getattr`` because ``run_cli(engine=...)`` is a public seam and an + injected engine need not carry targeting at all. + """ + getter = getattr(engine, "targeting", None) + targeting = getter() if callable(getter) else None + if targeting is None: + return None + return bool(targeting.matched), targeting.describe() + + def _report_loop(engine, cfg, log, sleep, clock, t0): """Report every ``interval`` and stop exactly at the deadline. @@ -398,6 +413,16 @@ def _report_loop(engine, cfg, log, sleep, clock, t0): deadline = (t0 + duration) if duration > 0 else None next_report = t0 + interval prev, prev_t = engine.stats_snapshot(), t0 + # The verdict as it stands at the start; apply_settings has already logged + # it. From here only CHANGES are reported. A target that dies mid-run was + # invisible from the CLI: the run kept going, impaired nothing and exited 0, + # which is exactly the "nothing broke" / "everything held up" confusion this + # tool shouts about in the GUI. MEASURED 2026-07-28: targeting a PID, then + # restarting that process, left 5 of 5 fresh connections untouched and the + # only targeting line in the whole run was the one printed at start. + # Sampled, not continuous: a verdict that flips and flips back between two + # passes is not seen, and that is the honest limit of polling here. + verdict = _targeting_state(engine) while True: now = clock() wake = next_report if deadline is None else min(next_report, deadline) @@ -417,6 +442,14 @@ def _report_loop(engine, cfg, log, sleep, clock, t0): prev, prev_t = s, now while next_report <= now: next_report += interval + state = _targeting_state(engine) + if state is not None and verdict is not None and state[0] != verdict[0]: + if state[0]: + log.info(f"the process target matches again: {state[1]}") + else: + log.warn("the process target no longer matches any process - " + "nothing is being impaired from here on") + verdict = state if deadline is not None and now >= deadline - 1e-9: return "duration" if not engine.is_running(): # the engine's own watchdog stopped it @@ -513,6 +546,21 @@ def _run_session(args, cfg, log, sleep, clock, engine): f"{cfg['min_packets']} - the traffic filter matched nothing?") code = exitcodes.ASSERTION + # --min-packets guards the CAPTURE FILTER (`seen`); this guards the TARGET. + # They are different failures: traffic can flow all run while the targeted + # process never matches, and the run then impairs nothing and still exits 0. + # Only when there WAS traffic - with `seen` at 0 the filter is the story and + # --min-packets is the flag that tells it, so saying both would point at the + # wrong thing. Not an assertion: a target with no traffic of its own is a + # legitimate run, and turning that into a failure would break the exit-code + # contract for everyone already running one. + target = str(cfg["settings"].get("target") or "").strip() + scoped = stats.get("scoped_seen", 0) + if target and stats["seen"] and not scoped: + log.warn(f"the process target {target!r} caught nothing: 0 of " + f"{stats['seen']} captured packets were in scope, so this run " + f"impaired nothing") + down_mb, up_mb = bytes_to_mb(stats["bytes_in"]), bytes_to_mb(stats["bytes_out"]) record = dict(event="summary", exit_code=code, exit_name=exitcodes.name_of(code), stop_reason=stop_reason, seed=eff, elapsed_s=elapsed, @@ -524,6 +572,13 @@ def _run_session(args, cfg, log, sleep, clock, engine): record["connections"] = _conn_records(engine) lines = [f"Data usage: downloaded {down_mb} MB, uploaded {up_mb} MB, " f"total {round(down_mb + up_mb, 2)} MB."] + if target: + # Text channel only: the JSON summary already carries `scoped_seen` in + # `counters`, and the NDJSON schema is a frozen contract (see "Public + # contracts"). A human reading the text run had no way to see how much + # of the captured traffic the target actually accounted for. + lines.append(f"In scope: {scoped} of {stats['seen']} captured packets " + f"(process target {target!r}).") if eff is not None: lines += [f"Session seed: {eff}", f"Reproduce: {repro}"] lines.append(f"Finished: {exitcodes.name_of(code).lower()} " diff --git a/tests/test_cli_runtime.py b/tests/test_cli_runtime.py index 0c23108..9feffc8 100644 --- a/tests/test_cli_runtime.py +++ b/tests/test_cli_runtime.py @@ -12,6 +12,7 @@ import json import os +from beantester import cli as cli_module from beantester import exitcodes from beantester.cli import (_Terminated, _print_conns, build_arg_parser, config_from_args, run_cli) @@ -153,6 +154,174 @@ def connections_snapshot(self, limit=30): "1.1.1.1:443" in body and "local:5000" in body, f"({body})") +# --- targeting: a target that stops matching must not be silent ------------- # + + +def _engine_stats(**over): + """A stats dict with the ENGINE's own key set. + + Copied from a real ``BeanEngine`` rather than written out here, so a counter + added to the engine cannot leave this fake answering with a key the CLI + reads. Constructing one starts no threads (they belong to ``start()``). + """ + from beantester.engine import BeanEngine + stats = dict(BeanEngine().st) + stats["queue"] = 0 + stats.update(over) + return stats + + +class _ScriptedTargeting: + """A ``ProcessTargeting`` stand-in whose verdict can move mid-run.""" + + def __init__(self, description="probe.exe"): + self.matched = True + self.description = description + + def refresh(self, *_a, **_k): + return frozenset() + + def describe(self): + return self.description if self.matched else "(none)" + + def pids(self): + return {4242} if self.matched else set() + + def __len__(self): + return 1 if self.matched else 0 + + +class _TargetedEngine: + """Enough engine to run a session that HAS a live process target. + + A real engine cannot play this part: ``--target`` is stripped in + ``--simulate`` (synthetic ports belong to nobody), and a real capture needs + WinDivert and an elevated token - the environment dependence this file + already pays for twice over. ``flip_at`` is which poll of ``targeting()`` + the target stops matching on, i.e. the moment the targeted process exits. + """ + + fault = False + + def __init__(self, flip_at=None, **stats): + self.target = _ScriptedTargeting() + self.flip_at = flip_at + self.polls = 0 + self.stats = _engine_stats(**stats) + + def set_seed(self, *_a, **_k): pass + def set_params(self, *_a, **_k): pass + def set_buffer(self, *_a, **_k): pass + def set_dest(self, *_a, **_k): pass + def set_lan(self, *_a, **_k): pass + def set_block(self, *_a, **_k): pass + def set_advanced(self, *_a, **_k): pass + def set_spike(self, *_a, **_k): pass + def set_nat(self, *_a, **_k): pass + def set_rst(self, *_a, **_k): pass + def set_flap(self, *_a, **_k): pass + def set_schedule(self, *_a, **_k): pass + def set_target(self, *_a, **_k): pass + def start(self, *_a, **_k): pass + def stop(self, *_a, **_k): pass + def is_running(self): return True + def effective_seed(self): return 7 + def connections_snapshot(self, limit=None): return [] + def stats_snapshot(self): return dict(self.stats) + + def target_for(self, _matcher): + return self.target + + def targeting(self): + self.polls += 1 + if self.flip_at is not None and self.polls >= self.flip_at: + self.target.matched = False + return self.target + + +def _targeted_run(monkeypatch, engine, argv): + """One CLI run with a process target, on virtual time. + + ``is_admin`` is forced because a targeted run is by definition not + ``--simulate``: without this the test would pass on an elevated shell and on + Linux CI, and fail on a plain Windows shell - a third environment-dependent + result in a file that already documents two. + """ + monkeypatch.setattr(cli_module.winenv, "is_admin", lambda: True) + clock = FakeClock() + out, err = io.StringIO(), io.StringIO() + code = run_cli(argv, sleep=clock.sleep, clock=clock, engine=engine, + out=out, err=err) + return code, out.getvalue(), err.getvalue() + + +def test_the_run_says_when_the_process_target_stops_matching(monkeypatch): + """A targeted process that exits mid-run used to be invisible from the CLI. + + MEASURED 2026-07-28 against a real capture (elevated, real WinDivert): + targeting a PID and then restarting that process left 5 of 5 fresh + connections untouched, and the only targeting line in the entire run was the + one printed at start - exit code OK, nothing else said. The GUI re-reads that + verdict on every tick and raises a banner; the CLI, which is the CI/CD + interface, said nothing at all. + + Also pins the other half: the message belongs to the CHANGE. Reporting the + verdict every interval would bury it in the sample stream. + """ + lost = _TargetedEngine(flip_at=3, seen=500, scoped_seen=40) + code, _, err = _targeted_run(monkeypatch, lost, + ["--target", "probe.exe", "--duration", "5", + "--interval", "1"]) + check("target: a target that dies does not end the run", code == exitcodes.OK, + f"(code={code})") + check("target: losing the target is reported", "no longer matches" in err, + f"({err!r})") + check("target: it is said once, not every interval", + err.count("no longer matches") == 1, f"({err!r})") + + kept = _TargetedEngine(seen=500, scoped_seen=40) + _, _, quiet = _targeted_run(monkeypatch, kept, + ["--target", "probe.exe", "--duration", "5", + "--interval", "1"]) + check("target: a target that keeps matching says nothing new", + "no longer matches" not in quiet, f"({quiet!r})") + + +def test_a_target_that_caught_nothing_is_called_out_at_the_end(monkeypatch): + """`--min-packets` guards the capture FILTER; this guards the TARGET. + + They fail differently: traffic can flow for the whole run while the targeted + process never matches, and that run impairs nothing and still exits 0. The + engine has always counted it (`scoped_seen`) - it just never left the JSON + summary's `counters`. + """ + caught_nothing = _TargetedEngine(seen=500, scoped_seen=0) + _, _, err = _targeted_run(monkeypatch, caught_nothing, + ["--target", "probe.exe", "--duration", "2"]) + check("scope: a target that caught nothing is called out", + "caught nothing" in err, f"({err!r})") + # In text mode the summary goes down the LOG channel (_emit_summary); in + # --format json it is the counters of the summary record instead. + check("scope: the summary says how much was in scope", + "In scope: 0 of 500" in err, f"({err!r})") + + worked = _TargetedEngine(seen=500, scoped_seen=40) + _, _, err = _targeted_run(monkeypatch, worked, + ["--target", "probe.exe", "--duration", "2"]) + check("scope: a target that DID catch traffic is not accused", + "caught nothing" not in err, f"({err!r})") + check("scope: and its share is still reported", "In scope: 40 of 500" in err, + f"({err!r})") + + # Nothing captured at all is the FILTER's story, and --min-packets is the + # flag that tells it. Saying both would point the user at the wrong thing. + silent = _TargetedEngine(seen=0, scoped_seen=0) + _, _, err = _targeted_run(monkeypatch, silent, + ["--target", "probe.exe", "--duration", "2"]) + check("scope: no traffic at all is not blamed on the target", + "caught nothing" not in err, f"({err!r})") + + def test_fail_on_no_traffic_is_shorthand_for_min_packets_one(): args = build_arg_parser().parse_args(["--simulate", "--fail-on-no-traffic"]) check("--fail-on-no-traffic == --min-packets 1",