Skip to content

perf(CC-364): single streaming jq pass for pmctl trace tail #546

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.

Sign up for GitHub

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
screenleon merged 4 commits into from
Aug 27, 2026
Merged

perf(CC-364): single streaming jq pass for pmctl trace tail #546

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
4 commits
Select commit Hold shift + click to select a range
a06ad1d
perf(CC-364): collapse trace tail to a single streaming jq pass
screenleon Aug 27, 2026
33a92fd
test(CC-364): make the large trace-tail regression always executable
screenleon Aug 27, 2026
ca0b3d5
test(CC-364): add fault-sensitive oracle for the single-jq-pass contract
screenleon Aug 27, 2026
d48461e
docs(BACKLOG): mark CC-364 done
screenleon Aug 27, 2026
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
12 changes: 9 additions & 3 deletions BACKLOG.md
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -92,7 +92,7 @@ CC-001/CC-002 were consumed by PR #24 fix bundle inline, with no standalone entr
| CC-357 | 🟢 someday | **[skill as contract: machine-readable schema for skills]** 現有 skills/ 都是純 markdown prose（SKILL.md），沒有機器可讀的 input schema、output contract、tool_constraints、completion_condition。這使得 skill 無法被驗證、無法被工具自動發現、也無法像 dispatch_handover_v1 那樣由 validator 強制執行契約。本票引入 skill schema（YAML frontmatter 或 JSON sidecar），使 skill 具備：明確的輸入型別、輸出格式、允許/禁止工具清單、完成條件——平行於 brief-validate.sh 對 brief 的驗證角色。 | arch/DX | 2026-06-10 | — | — | design |
| CC-358 | ✅ done | runner telemetry：`pmctl run-stats` per-adapter 成功率/失敗模式/fallback 分析（v1.0 readiness 證據；v0.11.0） | ops/memory | 2026-06-10 | — | P2 | design |
| CC-359 | 🟢 someday | concept: backlog-driven batch dispatch with worktree isolation（PM manages `git worktree` lifecycle；executor-agnostic；human-in-the-loop merge；PR-only output） | arch/ops | 2026-06-11 | — | — | design |
| CC-364 | ⏸ deferred | **[perf: `pmctl trace tail --all` per-event jq spawn]** `pmctl trace tail --kind <k> --all --json` is O(n) with a high per-event constant — ~20s for 338 events (~60ms/event), consistent with spawning a jq/subprocess per event rather than one streaming pass. Surfaced while diagnosing #270 context-telemetry test flakiness; the tests no longer depend on it (telemetry now honors `PM_DISPATCH_STATE_ROOT`, so the suite isolates state). Standalone reader-perf follow-up. **See**: pr:#270 | ops | 2026-06-12 | pr:#270 | P3 | hygiene |
| CC-364 | ✅ done | **[perf: `pmctl trace tail --all` per-event jq spawn]** `trace tail` scan phase reworked from two jq spawns per event (plus one per row in the human emitter) to a single `jq -R` streaming pass over the concatenated archive+active stream; ~24s→0.2s for 400 events, jq invocation count now fixed regardless of event count. Behavior parity preserved (filters, inclusive time window, malformed tolerance, chronological merge, limit/--all, compact-JSON byte identity). **See**: pr:#270, pr:#546 | ops | 2026-06-12 | pr:#270, pr:#546 | P3 | hygiene |
| CC-369 | ⏸ deferred | Windows state store 真實 ACL via icacls（parked: CC-370；border case relative to profile ACL protection） | ops/portability | 2026-06-13 | — | — | hygiene |
| CC-370 | ⏸ deferred | **[native Windows support deferred to post-core platform phase]** 核心功能開發期間正式只支援 Linux + WSL2（WSL2 視為 Linux）；原生 Windows Git Bash 非官方支援，使用者走 WSL2。理由是專注：開發期同時扛多平台會排擠核心功能（CI 只測 Linux，每次碰 Windows 都要人工驗證 + gate churn，見 #272/#273）。已合併的 portability 程式碼保留（綠且成本低），但不再新增 Windows 分支，直到核心定型（v0.5.0+）後的專屬平台階段。Parks: CC-038, CC-104d/e/f/g/j/k/r/s, CC-369。**See**: DECISIONS.md 2026-06-13 defer-native-windows-support-during-core-dev | ops/portability | 2026-06-13 | — | — | design |
| CC-377 | ⏸ deferred | adapter: Google Antigravity（`agy`）executor（DEFERRED：headless CLI 1.0.8 不成熟；resume: newer agy with `--output-format stream-json`；umbrella: CC-333） | arch/portability | 2026-06-13 | — | P2 | design |
Expand Down Expand Up @@ -1530,12 +1530,18 @@ Fix：文件化 `GOPATH=/tmp/gopath go build` 慣例到 brief self_verify go bui

---

## CC-364 — perf: `pmctl trace tail --all` per-event jq spawn（deferred）
## CC-364 — perf: `pmctl trace tail --all` per-event jq spawn ✅ 2026-08-27

**See**: pr:#270
**See**: pr:#270, pr:#546

`pmctl trace tail --kind <kind> --all --json` is O(n) with a high per-event constant — measured ~20s for 338 events (~60ms/event), consistent with spawning a `jq` (or equivalent subprocess) per event rather than a single streaming pass. Discovered while diagnosing the #270 context-telemetry test flakiness: `context.queried` / `context.reuse_scanned` events accumulate in a partition, and the readback assertions called `trace tail --all`, so reads degraded as the partition grew. The tests were de-coupled from this — context telemetry now honors `PM_DISPATCH_STATE_ROOT`, so the suite isolates all state into a throwaway root — leaving this as a standalone reader-performance follow-up, not a blocker. Fix: rework `trace tail` filtering/serialization as a single `jq` pass (or a streaming reader) over `events.jsonl`.

**Closure 2026-08-27 (pr:#546)**: scan phase is now one `jq -R` streaming pass over the concatenated `archive + active` stream — it classifies each line (malformed / filtered-out / kept) and emits kept rows as `<ts>\t<line_no>\t<compact-json>`, using jq's cumulative `input_line_number` as the global read-order tiebreaker for events sharing a timestamp. Both emit helpers stream through one jq via `cut -f3`. Five module-global `_PMCTL_TRACE_*` vars and three per-line scan helpers removed.

**Perf evidence**: 400 events `--all --json` ~24s → 0.2s (~100x). New `case_trace_tail_single_jq_pass` shims a counting `jq` onto PATH and asserts the invocation tally is equal (and non-zero) for a 20-event and a 200-event run — O(1) in event count; a per-event regression would make the 200-event tally ~10x the 20-event one. Behavior parity (filters, inclusive lexicographic window, malformed tolerance + `skipped N` warning, archive/active merge, limit/`--all`, compact-JSON byte identity) covered by the existing `test-pmctl-trace.sh` cases (14 passed) plus the new `case_trace_large_partition_streaming`.

**Not done here**: `pmctl-run-stats.sh` (CC-358) has the same archive+active scan shape with a per-line jq spawn; deliberately out of scope (different jq program + shell-side aggregation), left a pointer comment. No follow-up ticket filed yet.

## CC-435 — poll→通知機制 single-waiter guard：條件觸發，非既定後續票 🟢 someday

**Problem**：`docs/spikes/CC-433.md` 判定 poll→通知機制遷移為 AMBER——mkfifo blocking read 技術可行且延遲大幅改善，但發現並發 waiter 讀同一個 fifo 會造成 byte-level 資料損毀的正確性風險（輪詢設計沒有這個問題）。CC-434 實作完成後與使用者進一步討論了兩個候選防護設計，重新盤點成本效益後決定不排入既定實作。
Expand Down
13 changes: 7 additions & 6 deletions runtime/lib/pmctl-run-stats.sh
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -1,11 +1,13 @@
#!/usr/bin/env bash
# pmctl run-stats — per-adapter success/failure/fallback analysis over
# events.jsonl (CC-358). Read-only consumer: never calls events_append or any
# state-writer write helper. Reuses the same per-line jq-extraction + ISO-8601
# string comparison approach as pmctl_trace_tail (runtime/lib/pmctl-trace.sh)
# rather than inventing a second parser for the same file format.
# state-writer write helper. Uses the same ISO-8601 lexicographic string
# comparison and archive-inclusive scan model as pmctl trace tail
# (runtime/lib/pmctl-trace.sh) rather than inventing a second parser for the
# same file format. (trace tail itself now does a single streaming jq pass;
# this reader still extracts per line — a standalone follow-up, not CC-364.)
#
# Archive-inclusive by default, matching pmctl_trace_tail's read_archives=1:
# Archive-inclusive by default, matching pmctl trace tail's read_archives=1:
# rotated archive/events-*.jsonl.gz files are scanned alongside the active
# events.jsonl so a --since window reaching past rotation still counts every
# matching run. Falls back to active-file-only (and says so in `_meta`) only
Expand All @@ -31,8 +33,7 @@ pmctl_run_stats_ensure_state_writer() {

# Emits one TSV row per run.* event whose kind matches ^run\. — ts, kind,
# run_id, adapter, note, exit_code, fallback_used(true/false) — or nothing
# when the line isn't a matching run event. One jq invocation per line (same
# per-event subprocess cost as pmctl_trace_scan_line).
# when the line isn't a matching run event. One jq invocation per line.
pmctl_run_stats_extract_line() {
local line="${1:-}"
printf '%s\n' "$line" | jq -r '
Expand Down
172 changes: 79 additions & 93 deletions runtime/lib/pmctl-trace.sh
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -18,85 +18,67 @@ pmctl_trace_ensure_state_writer() {
. "$repo_root/runtime/lib/state-writer.sh"
}

pmctl_trace_scan_line() {
local line="${1:-}" compact fields
local event_id ts kind subject_id

if ! compact="$(printf '%s\n' "$line" | jq -c 'if type == "object" then . else error("not object") end' 2>/dev/null)"; then
_PMCTL_TRACE_SKIPPED=$((_PMCTL_TRACE_SKIPPED + 1))
return 0
fi

# Only the fields used for filtering are extracted into shell vars; the
# emitters re-read subject_type / actor / operation_id from the JSON itself.
if ! fields="$(printf '%s\n' "$compact" | jq -r '[.id // "", .ts // "", .kind // "", .subject_id // ""] | @tsv' 2>/dev/null)"; then
_PMCTL_TRACE_SKIPPED=$((_PMCTL_TRACE_SKIPPED + 1))
return 0
fi
IFS=$'\t' read -r event_id ts kind subject_id <<< "$fields"

if [[ -n "${_PMCTL_TRACE_ID_FILTER:-}" && "$event_id" != "$_PMCTL_TRACE_ID_FILTER" ]]; then
return 0
fi
if [[ -n "${_PMCTL_TRACE_KIND_FILTER:-}" && "$kind" != "$_PMCTL_TRACE_KIND_FILTER" ]]; then
return 0
fi
if [[ -n "${_PMCTL_TRACE_SUBJECT_FILTER:-}" && "$subject_id" != "$_PMCTL_TRACE_SUBJECT_FILTER" ]]; then
return 0
fi
if [[ -n "${_PMCTL_TRACE_SINCE_FILTER:-}" && ( -z "$ts" || "$ts" < "$_PMCTL_TRACE_SINCE_FILTER" ) ]]; then
return 0
fi
if [[ -n "${_PMCTL_TRACE_UNTIL_FILTER:-}" && ( -z "$ts" || "$ts" > "$_PMCTL_TRACE_UNTIL_FILTER" ) ]]; then
return 0
fi

_PMCTL_TRACE_SEQ=$((_PMCTL_TRACE_SEQ + 1))
printf '%s\t%012d\t%s\n' "$ts" "$_PMCTL_TRACE_SEQ" "$compact" >> "$_PMCTL_TRACE_RECORDS"
}

pmctl_trace_scan_path() {
local path="${1:-}" line

[[ -f "$path" ]] || return 0
while IFS= read -r line || [[ -n "$line" ]]; do
pmctl_trace_scan_line "$line"
done < "$path"
}

pmctl_trace_scan_gzip_path() {
local path="${1:-}" line

[[ -f "$path" ]] || return 0
while IFS= read -r line || [[ -n "$line" ]]; do
pmctl_trace_scan_line "$line"
done < <(gzip -dc "$path" 2>/dev/null)
# Single streaming jq program over the concatenated archive+active event stream
# (raw input, one JSON object per line). Replaces the former per-line pair of
# jq spawns: this runs once for the whole partition regardless of event count.
#
# For every input line it prints exactly one control line to stdout:
# "M" -> line is not a JSON object (skip + count)
# "E\t<ts>\t<line_no>\t<compact-json>" -> line matched all active filters
# (nothing) -> valid object that a filter excluded
#
# <line_no> is jq's cumulative input_line_number across the whole concatenated
# stream, so it is a global monotonic read-order sequence: archives first (in
# filename-sorted order), then the active file, each in line order. The caller
# uses it as the stable-sort tiebreaker for events sharing a timestamp.
#
# Filters are passed as --arg strings; an empty string means "no constraint".
# Timestamp comparisons are lexicographic on the ISO-8601 string, matching the
# shell `<` / `>` semantics this previously used, and an empty ts is excluded
# whenever a --since or --until bound is set.
pmctl_trace_filter_program() {
cat <<'JQ'
(try fromjson catch null) as $o
| if ($o | type) != "object" then "M"
else
($o.ts // "") as $ts
| ($o.id // "") as $id
| ($o.kind // "") as $kind
| ($o.subject_id // "") as $sid
| if ($idf != "" and $id != $idf) then empty
elif ($kindf != "" and $kind != $kindf) then empty
elif ($subjf != "" and $sid != $subjf) then empty
elif ($sincef != "" and ($ts == "" or $ts < $sincef)) then empty
elif ($untilf != "" and ($ts == "" or $ts > $untilf)) then empty
else "E\t\($ts)\t\(input_line_number)\t\($o | tojson)"
end
end
JQ
}

# emit helpers consume the sorted "<ts>\t<seq>\t<compact-json>" record file.
# The compact JSON is the third tab field and never contains a literal tab
# (jq -c escapes tabs inside strings), so `cut -f3` recovers it exactly.
pmctl_trace_emit_json() {
local path="${1:-}" ts seq json
local path="${1:-}"

while IFS=$'\t' read -r ts seq json; do
: "$ts" "$seq"
printf '%s\n' "$json"
done < "$path"
[[ -s "$path" ]] || return 0
cut -f3 "$path"
}

pmctl_trace_emit_human() {
local path="${1:-}" ts seq json
local path="${1:-}"

while IFS=$'\t' read -r ts seq json; do
: "$ts" "$seq"
printf '%s\n' "$json" | jq -r '
(.ts // "") as $ts |
(.kind // "") as $kind |
(.subject_type // "") as $subject_type |
(.subject_id // "") as $subject_id |
(if (.actor? == null or .actor == "") then "[no-actor]" else .actor end) as $actor |
(if (.operation_id? == null or .operation_id == "") then "" else " op=\(.operation_id)" end) as $op |
"\($ts) \($kind) \($subject_type)/\($subject_id) \($actor)\($op)"
'
done < "$path"
[[ -s "$path" ]] || return 0
cut -f3 "$path" | jq -r '
(.ts // "") as $ts |
(.kind // "") as $kind |
(.subject_type // "") as $subject_type |
(.subject_id // "") as $subject_id |
(if (.actor? == null or .actor == "") then "[no-actor]" else .actor end) as $actor |
(if (.operation_id? == null or .operation_id == "") then "" else " op=\(.operation_id)" end) as $op |
"\($ts) \($kind) \($subject_type)/\($subject_id) \($actor)\($op)"
'
}

pmctl_trace_tail() {
Expand All @@ -105,6 +87,7 @@ pmctl_trace_tail() {
local limit=20 all=0 json=0
local proj_dir active_file archive_dir read_archives=1
local tmp_dir records sorted limited emit_file rc=0
local skipped=0 program out_line _pmctl_trace_archive
local -a archives=()

if [[ -z "$repo_root" ]]; then
Expand Down Expand Up @@ -225,31 +208,34 @@ pmctl_trace_tail() {
return "$rc"
fi

_PMCTL_TRACE_KIND_FILTER="$kind_filter"
_PMCTL_TRACE_SUBJECT_FILTER="$subject_filter"
_PMCTL_TRACE_ID_FILTER="$id_filter"
_PMCTL_TRACE_SINCE_FILTER="$since_filter"
_PMCTL_TRACE_UNTIL_FILTER="$until_filter"
_PMCTL_TRACE_RECORDS="$records"
_PMCTL_TRACE_SEQ=0
_PMCTL_TRACE_SKIPPED=0

if [[ "$read_archives" -eq 1 ]]; then
for _pmctl_trace_archive in "${archives[@]}"; do
pmctl_trace_scan_gzip_path "$_pmctl_trace_archive"
done
unset _pmctl_trace_archive
fi
pmctl_trace_scan_path "$active_file"
program="$(pmctl_trace_filter_program)"
while IFS= read -r out_line; do
if [[ "$out_line" == "M" ]]; then
skipped=$((skipped + 1))
else
printf '%s\n' "${out_line#E$'\t'}" >> "$records"
fi
done < <(
{
if [[ "$read_archives" -eq 1 ]]; then
for _pmctl_trace_archive in "${archives[@]}"; do
[[ -f "$_pmctl_trace_archive" ]] && gzip -dc "$_pmctl_trace_archive" 2>/dev/null
done
fi
[[ -f "$active_file" ]] && cat "$active_file"
} | jq -R -r \
--arg idf "$id_filter" \
--arg kindf "$kind_filter" \
--arg subjf "$subject_filter" \
--arg sincef "$since_filter" \
--arg untilf "$until_filter" \
"$program"
)

if [[ "$_PMCTL_TRACE_SKIPPED" -gt 0 ]]; then
printf 'trace: skipped %s malformed row(s)\n' "$_PMCTL_TRACE_SKIPPED" >&2
if [[ "$skipped" -gt 0 ]]; then
printf 'trace: skipped %s malformed row(s)\n' "$skipped" >&2
fi

unset _PMCTL_TRACE_KIND_FILTER _PMCTL_TRACE_SUBJECT_FILTER _PMCTL_TRACE_ID_FILTER
unset _PMCTL_TRACE_SINCE_FILTER _PMCTL_TRACE_UNTIL_FILTER _PMCTL_TRACE_RECORDS
unset _PMCTL_TRACE_SEQ _PMCTL_TRACE_SKIPPED

if [[ ! -s "$records" ]]; then
rm -rf "$tmp_dir"
return 0
Expand Down
Loading