Skip to content

feat(engine): measure how long packets waited inside the driver - #63

Merged
donislawdev merged 1 commit into
masterfrom
feat/measure-the-driver-queue-wait
Jul 28, 2026
Merged

feat(engine): measure how long packets waited inside the driver#63
donislawdev merged 1 commit into
masterfrom
feat/measure-the-driver-queue-wait

Conversation

@donislawdev

Copy link
Copy Markdown
Owner

Audit finding F10, part b - the measurement. Stacked on #62 (part a, the visibility half).

The audit asked for a heuristic. None was written.

The finding proposed "add an overload heuristic". The dependency already answers the question:
pydivert.Packet.timestamp is the raw QueryPerformanceCounter value WinDivert stamps every packet
with (packet/__init__.py:216), so QPC_now - stamp IS the time that packet spent in the
driver's queue
. Reading the capability surface before building anything (convention 6) turned a
heuristic into a measurement.

That wait is the one delay this tool adds and counts nowhere - it happens in WinDivert's queue,
ahead of the tool's own, so a tester measuring latency attributes it to their application or to
the network.

What changed

  • winenv.qpc_now() / qpc_frequency(), Windows-only. Not time.perf_counter(): it is derived
    from QPC but carries an arbitrary epoch offset, so subtracting a raw stamp from it is meaningless.
  • Sampled on time, not on a packet count. A 1-in-N sample never fires on a quiet link - 24
    packets in 12 seconds would never reach 1-in-256 - and a quiet link is exactly where a 2 s driver
    queue goes unnoticed. 20 samples a second at any rate; the per-packet cost is one float compare
    against a now the loop had already read.
  • driver_wait_peak_ms -> Session tab row, repro report, stats CSV. Warning above 50 ms,
    rate-limited to once per 5 s like the other two, first occurrence into the event log.
  • The threshold is set against a measurement, not a guess: idle on the owner's machine is
    0.049-0.163 ms (median ~0.08), so 50 ms is several hundred times normal.
  • The QPC pair is an injected dependency, like the clock and sleep run_cli takes, so a test can
    drive the capture loop with a known clock.

Verification

  • python -m pytest tests -> 708 passed, 0 failed (elevated shell). python smoke_gui.py -> OK.
  • Hot path, against a worktree of the parent branch (150k packets, median of 5, twice each):
    148.4 / 149.6k -> 154.1 / 154.4k pkt/s. A float compare cannot make anything faster, so that
    spread is noise and the honest reading is no measurable cost. Not covered by this
    benchmark:
    the QPC call itself - synthetic packets have no timestamp, so the sampler returns
    at the getattr. On the real path that call happens 20 times a second regardless of traffic.
  • Five new tests. Five mutants, four caught - and the fifth is recorded rather than papered over:
    • Mutating away if waited_ms <= 0 changes nothing observable: the peak comparison and the
      warn comparison both already reject a negative. So it is a cheap skip of the stats lock, not a
      guard, and its comment now says that instead of claiming it prevents a negative reading. A
      branch whose comment overstates it is the failure mode this project cares most about.
    • Two mutants were caught only after repairs, both worth reading. The direct-call tests said
      nothing about whether the capture loop ever reaches the sampler - deleting the call site left
      them all green. And the new loop test first injected this machine's own 10 MHz, which would
      have hidden a "start() overwrites the injected frequency" bug everywhere except the Linux
      runner; it injects 1 MHz now, so the mutant fails with 20.0 where 200.0 was expected.

Owed: a real-driver run to see the row populated with a genuine sub-millisecond number rather
than an injected one. Asked for separately.

🤖 Generated with Claude Code

The audit asked for an overload heuristic. None was written, because the
dependency already answers the question: pydivert's Packet.timestamp is the raw
QueryPerformanceCounter value WinDivert stamps each packet with, so
QPC_now - stamp IS the time that packet spent in the driver's queue. Reading the
capability surface first turned a heuristic into a measurement.

That wait is the one delay this tool adds and counts nowhere - it happens ahead
of the tool's own queue, so a tester measuring latency attributes it to their
application or to the network. It now has a Session-tab row, a place in the repro
report and the stats CSV, and a warning above 50 ms.

Sampled on TIME, not on a packet count: a 1-in-N sample never fires on a quiet
link, and a quiet link is exactly where a 2 s driver queue goes unnoticed. 20
samples a second at any rate; the per-packet cost is one float compare against a
`now` the loop had already read.

The 50 ms threshold is set against the measured idle value on this machine
(0.049-0.163 ms, median ~0.08), so it is several hundred times normal rather
than a guess at one.

Hot path measured against a worktree of the parent branch: 148.4/149.6k ->
154.1/154.4k pkt/s. A float compare cannot make anything faster, so that is
noise and the honest reading is no measurable cost. Not covered: the QPC call
itself, because synthetic packets have no timestamp - on the real path it happens
20 times a second regardless of traffic.

Five mutants, four caught, and the fifth recorded rather than papered over:
mutating away `if waited_ms <= 0` changes nothing observable, because both
comparisons below already reject a negative. Its comment now says that instead of
claiming it guards the reading. Two others were caught only after repairs - the
direct-call tests never reached the capture loop, and the loop test first
injected this machine's own 10 MHz, which would have hidden an overwrite bug
everywhere except the Linux runner.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Base automatically changed from feat/report-the-driver-queue-parameters to master July 28, 2026 13:24
@donislawdev
donislawdev merged commit 1e2cb10 into master Jul 28, 2026
5 checks passed
@donislawdev
donislawdev deleted the feat/measure-the-driver-queue-wait branch July 28, 2026 13:24
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant