Skip to content

SEP-1827: Make live-log frame decoding cost proportional to the arriving bytes - #1398

Open
marcuscruz-percona wants to merge 2 commits into
mainfrom
SEP-1827
Open

SEP-1827: Make live-log frame decoding cost proportional to the arriving bytes#1398
marcuscruz-percona wants to merge 2 commits into
mainfrom
SEP-1827

Conversation

@marcuscruz-percona

Copy link
Copy Markdown
Contributor

Summary

  • Streaming the live log of an anonymized step re-did work proportional to the whole withheld buffer on every frame. NomadExecutor._decode_live_frame copied the buffer (bytes(pending)) and then scanned all of it twice for a line terminator, even though only the bytes that just arrived can contain one. Under the 1 MiB withholding ceiling a step emitting newline-less output in small frames repeated that copy-and-scan against a buffer growing toward a megabyte, once per frame, for the whole window — quadratic work inside the coroutine that serves the live viewer.
  • Give the live path a WithheldLineBuffer in app/tasks/logs/line_split.py that owns the withheld bytes. Its append is the only way bytes enter, and it releases every line the arriving frame completed, so what stays withheld is terminator-free by construction rather than by three truncation branches that each happen to preserve it. That is what makes a narrowed scan exact: any terminator must lie in the bytes just delivered, so a scan starting at the pre-append length sees everything a whole-buffer scan would. No cursor is stored — the pre-append length, captured locally per call, is the cursor.
  • The ceiling comparison moves into one module-level predicate that both the buffer type and split_complete_lines call, so the live and persisted paths cannot drift apart on a remainder of exactly log_anonymization_max_withheld_bytes. The ceiling is passed per append rather than held on the buffer, so lowering the setting at runtime still releases an over-ceiling buffer on the next frame.
  • Releases are copied out as bytes, never a view onto the live buffer, so no caller can hold a value that changes when the next frame arrives.
  • Pure optimization. The emitted bytes, their order, the emit offsets, the forced-flush ceiling behaviour (including the warning naming allocation, step, and log type) and the persisted _fetch_step_log_delta path are all unchanged; split_complete_lines keeps its signature and behaviour.

Measured over one full ceiling window — 256 newline-less frames of 4 KiB — through the real split_complete_lines and predicate rather than a standalone simulation. Best of five, CPython on an otherwise idle developer workstation:

Strategy Time for the window Average per frame
Copy + two full-buffer scans 106.93 ms 417.68 us
Cursored append 0.99 ms 3.85 us

This is buffer arithmetic in isolation, so read it as the shape of the saving rather than a production figure — the real coroutine also pays base64 decoding, JSON parsing and queue handoff per frame. It covers only the frames that emit nothing, which is where the waste was; the frame that finally releases the megabyte costs the same either way, and is meant to.

The correctness argument is carried by tests rather than by inspection, because the failure mode is silent — a missed terminator withholds a line that was already complete, and the viewer just stalls until the ceiling flushes it. Three kinds, in tests/app/tasks/logs/test_line_split.py: equivalence against an oracle that replays the old copy-and-full-scan loop over 13 chunk sequences (terminator at chunk start/end/middle, \r\n split across frames, empty frames, multibyte splits, runs that trip the ceiling); the terminator-free invariant asserted after every frame; and a whitebox pin, via a bytearray subclass that records rfind start offsets, that every scan starts at the pre-append length — a regression to full scans is otherwise behaviourally invisible.

Live-path coverage in tests/app/tasks/execution/executors/nomad/test_models.py: the existing withholding assertions pass unchanged against the new type, plus a run of newline-less frames followed by a terminating one emitting exactly the accumulated line (the narrowed scan shown correct at the moment of release, not only while growing), a reconnect carrying one buffer through two _consume_nomad_log_stream calls, and a check that no terminator is ever left withheld.

No changelog fragment: no migration, no settings field, no API surface, no user-visible behaviour change.

Tested

  • make test — 10261 passed, 424 skipped
  • make run-pre-commit — 23 hooks, all passed
  • pytest tests/app/tasks — 1452 passed, 22 skipped
  • Benchmarked the two scan strategies over a full ceiling window (table above)
  • Outstanding, not yet run: live smoke against a real allocation — run a task whose script emits a large newline-less chunk followed by a newline, watch the live log page for the line appearing when the terminator arrives and no earlier, then drop log_anonymization_max_withheld_bytes at runtime and confirm the forced-flush warning still names the allocation, step, and log type

Checklist

  • New/modified functions have type hints and rST docstrings
  • New tests added for new features or bug fixes
  • All tests pass locally (make test)
  • Pre-commit hooks pass (make run-pre-commit)
  • Database migrations generated if models changed (make makemigrations)
  • User-facing changes documented (README, inline help, UI text)
  • Configuration changes documented with examples
  • Changelog fragment added under changelog.d/ if the change is user-facing (make changelog-add), or confirmed N/A (internal-only change, or a same-release-cycle fix for an unreleased sibling ticket)

The live-log path withholds the trailing partial line so anonymization
always sees whole lines. Each frame copied the whole withheld buffer and
ran two full-buffer rfind calls over it, so a step emitting newline-less
output in small frames repeated that work against a buffer growing toward
the 1 MiB ceiling.

Move the withheld bytes into a buffer type whose append is the only
mutator: it captures the length before extending and scans only from
there. What stays withheld is terminator-free by construction, so a
narrowed scan returns what a full scan returned. The ceiling comparison
moves into one predicate both shapes call, so the live and persisted
boundaries cannot drift.

Emitted bytes, their order, the emit offsets and the forced-flush
behaviour are unchanged.
Copilot AI balanced review requested due to automatic review settings August 21, 2026 20:03
@github-actions github-actions Bot added python svc:tasks PR touches the tasks service (app/tasks/) labels Aug 21, 2026

Copilot AI left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Pull request overview

Optimizes live-log frame decoding by scanning only newly arrived bytes while preserving buffering and flush semantics.

Changes:

  • Adds WithheldLineBuffer with shared ceiling logic.
  • Integrates it into Nomad live-log streaming.
  • Adds comprehensive equivalence, invariant, reconnect, and offset tests.

Reviewed changes

Copilot reviewed 4 out of 4 changed files in this pull request and generated 1 comment.

File Description
app/tasks/logs/line_split.py Adds efficient stateful line buffering.
app/tasks/execution/executors/nomad/models.py Uses the buffer for live Nomad logs.
tests/app/tasks/logs/test_line_split.py Tests behavior and scan complexity.
tests/app/tasks/execution/executors/nomad/test_models.py Tests live-stream integration and reconnects.
Suppressed comments (1)

app/tasks/logs/line_split.py:152

  • Use an em dash here; reStructuredText renders -- literally rather than substituting typographic punctuation.
        (< 0x80), so neither can appear inside a multi-byte UTF-8 sequence --
        splitting on either is inherently codepoint-safe.

💡 Add a code-review agent skill or configure MCP servers for context-aware, tailored reviews. Learn more in the docs.

Comment thread app/tasks/logs/line_split.py Outdated
Co-authored-by: Copilot Autofix powered by AI <175728472+Copilot@users.noreply.github.com>
@marcuscruz-percona marcuscruz-percona added the qa in progress Someone is currently testing this PR - do not merge it label Aug 21, 2026
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

python qa in progress Someone is currently testing this PR - do not merge it svc:tasks PR touches the tasks service (app/tasks/)

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants