From a06ad1dd8d81633f1cb0dd80e4f819490eb957c3 Mon Sep 17 00:00:00 2001 From: Lien Chen Date: Thu, 27 Aug 2026 13:13:59 +0900 Subject: [PATCH 1/4] perf(CC-364): collapse trace tail to a single streaming jq pass pmctl trace tail spawned two jq processes per event during the scan phase plus one more per row in the human emitter, making --all O(n) with a high constant (~20s / 338 events). Rework the scan as one jq -R streaming pass over the concatenated archive+active stream: it classifies each line (malformed / filtered-out / kept) and emits kept rows as "\t\t", using jq's cumulative input_line_number as the global read-order tiebreaker for equal timestamps. Both emit helpers now stream through a single jq via cut -f3. Behavior is unchanged: same filters, inclusive lexicographic time window, malformed-row tolerance + "skipped N" warning, archive/active chronological merge, limit/--all semantics, compact-JSON byte identity. Drops the five module-global _PMCTL_TRACE_* vars and three now-dead scan helpers. New regression: 120+120 archive/active events with interleaved bands and two malformed rows, asserting count, non-decreasing merge order and the skip warning at a scale above the other cases (awk-generated fixtures). Co-Authored-By: Claude Sonnet 5 Claude-Session: https://claude.ai/code/session_01KFPwSUfmLGh6KJLYFBArTS --- runtime/lib/pmctl-run-stats.sh | 13 +-- runtime/lib/pmctl-trace.sh | 172 +++++++++++++++----------------- tests/shell/test-pmctl-trace.sh | 43 ++++++++ 3 files changed, 129 insertions(+), 99 deletions(-) diff --git a/runtime/lib/pmctl-run-stats.sh b/runtime/lib/pmctl-run-stats.sh index e3908643..d5bc6ae3 100644 --- a/runtime/lib/pmctl-run-stats.sh +++ b/runtime/lib/pmctl-run-stats.sh @@ -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 @@ -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 ' diff --git a/runtime/lib/pmctl-trace.sh b/runtime/lib/pmctl-trace.sh index 8140ad37..952a639e 100644 --- a/runtime/lib/pmctl-trace.sh +++ b/runtime/lib/pmctl-trace.sh @@ -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\t\t" -> line matched all active filters +# (nothing) -> valid object that a filter excluded +# +# 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 "\t\t" 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() { @@ -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 @@ -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 diff --git a/tests/shell/test-pmctl-trace.sh b/tests/shell/test-pmctl-trace.sh index 3491eb15..8642fe22 100755 --- a/tests/shell/test-pmctl-trace.sh +++ b/tests/shell/test-pmctl-trace.sh @@ -280,6 +280,48 @@ case_trace_active_archive_merge() { fi } +case_trace_large_partition_streaming() { + local name="pmctl trace tail: large archive+active partition stays ordered in one pass" + should_run "$name" || return 0 + local store proj out err status=0 count ordered malformed + if ! command -v gzip >/dev/null 2>&1; then + pass "$name" + return 0 + fi + store="$tmp_root/large-store" + proj="$(trace_project_dir "$store")" + # 120 archived + 120 active events, disjoint timestamp bands so a correct + # merge must order across both sources; two malformed rows exercise the + # streaming skip path at a scale well above the other cases. Fixtures are + # built in one awk pass, not per-event jq spawns (per-item-subprocess-class). + large_events() { + local band="$1" prefix="$2" n="$3" + awk -v band="$band" -v prefix="$prefix" -v n="$n" 'BEGIN { + for (i = 1; i <= n; i++) { + printf "{\"schema_version\":1,\"id\":\"%s-%03d\",\"ts\":\"2026-06-06T%s:%02d:00Z\",\"kind\":\"run.completed\",\"subject_type\":\"run\",\"subject_id\":\"%s-%d\",\"actor\":\"pmctl\",\"payload\":{}}\n", prefix, i, band, i % 60, prefix, i + } + }' + } + large_events 01 evt-large-a 120 | gzip -c > "$proj/archive/events-202606a.jsonl.gz" + { + printf '%s\n' '{"id":' + large_events 02 evt-large-b 120 + printf '%s\n' 'not json at all' + } > "$proj/events.jsonl" + out="$tmp_root/large.out" + err="$tmp_root/large.err" + run_trace "$store" "$out" "$err" --all --json || status=$? + count="$(line_count "$out")" + # timestamps must be non-decreasing across the merged stream + ordered="$(jq -r '.ts' "$out" | LC_ALL=C sort -c 2>&1 && echo OK)" + malformed="$(grep -c 'trace: skipped 2 malformed row(s)' "$err" || true)" + if [[ "$status" -eq 0 && "$count" == "240" && "$ordered" == "OK" && "$malformed" == "1" ]]; then + pass "$name" + else + fail "$name" "status=$status count=$count ordered=$ordered malformed=$malformed err=$(<"$err")" + fi +} + case_trace_empty_missing_store() { local name="pmctl trace tail: missing store exits 0 with empty stdout" should_run "$name" || return 0 @@ -322,6 +364,7 @@ case_trace_human_format case_trace_equal_ts_append_order case_trace_corrupt_row_tolerance case_trace_active_archive_merge +case_trace_large_partition_streaming case_trace_empty_missing_store case_trace_unknown_flag_usage From 33a92fd34ca17cad3c0a777a2312021850842e05 Mon Sep 17 00:00:00 2001 From: Lien Chen Date: Thu, 27 Aug 2026 13:22:46 +0900 Subject: [PATCH 2/4] test(CC-364): make the large trace-tail regression always executable pr-gate (qa-tester, 2x high/block) on the first draft of case_trace_large_partition_streaming: - F001: the "gzip unavailable -> pass; return 0" guard let a runner without gzip record the case as verified without running its archive coverage. Reworked the case to an active-file-only partition (240 events across three disjoint timestamp bands + two malformed rows), so it always executes; archive+active merge correctness stays covered by case_trace_active_archive_merge. - F002: added the harness-required Behavior/Steps docstring above the case; observable assertions unchanged. Focused: test-pmctl-trace.sh (13 passed), test-lint-test-docstrings.sh, shellcheck clean. Co-Authored-By: Claude Sonnet 5 Claude-Session: https://claude.ai/code/session_01KFPwSUfmLGh6KJLYFBArTS --- tests/shell/test-pmctl-trace.sh | 43 ++++++++++++++++++--------------- 1 file changed, 23 insertions(+), 20 deletions(-) diff --git a/tests/shell/test-pmctl-trace.sh b/tests/shell/test-pmctl-trace.sh index 8642fe22..08d4bcdd 100755 --- a/tests/shell/test-pmctl-trace.sh +++ b/tests/shell/test-pmctl-trace.sh @@ -280,39 +280,42 @@ case_trace_active_archive_merge() { fi } +# Behavior: the single streaming jq pass introduced for CC-364 still emits +# every event once, in non-decreasing timestamp order, and skips exactly the +# malformed rows, at a partition size well above the other cases (so an +# accidental return to per-event jq spawning or a broken sort/tiebreak shows +# up here). Archive+active merge correctness is covered separately by +# case_trace_active_archive_merge; this case is active-only so it always +# executes regardless of gzip availability. +# Steps: write 240 well-formed run.completed events spread across three +# disjoint HH timestamp bands, interleaved with two malformed lines, all in +# one awk pass (no per-event jq spawn). Run `trace tail --all --json`, then +# assert: exit 0, 240 emitted rows, `sort -c` accepts the emitted timestamp +# sequence, and stderr reports "skipped 2 malformed row(s)". case_trace_large_partition_streaming() { - local name="pmctl trace tail: large archive+active partition stays ordered in one pass" + local name="pmctl trace tail: large partition stays ordered in one streaming pass" should_run "$name" || return 0 local store proj out err status=0 count ordered malformed - if ! command -v gzip >/dev/null 2>&1; then - pass "$name" - return 0 - fi store="$tmp_root/large-store" proj="$(trace_project_dir "$store")" - # 120 archived + 120 active events, disjoint timestamp bands so a correct - # merge must order across both sources; two malformed rows exercise the - # streaming skip path at a scale well above the other cases. Fixtures are - # built in one awk pass, not per-event jq spawns (per-item-subprocess-class). - large_events() { - local band="$1" prefix="$2" n="$3" - awk -v band="$band" -v prefix="$prefix" -v n="$n" 'BEGIN { - for (i = 1; i <= n; i++) { - printf "{\"schema_version\":1,\"id\":\"%s-%03d\",\"ts\":\"2026-06-06T%s:%02d:00Z\",\"kind\":\"run.completed\",\"subject_type\":\"run\",\"subject_id\":\"%s-%d\",\"actor\":\"pmctl\",\"payload\":{}}\n", prefix, i, band, i % 60, prefix, i - } - }' - } - large_events 01 evt-large-a 120 | gzip -c > "$proj/archive/events-202606a.jsonl.gz" { printf '%s\n' '{"id":' - large_events 02 evt-large-b 120 + awk 'BEGIN { + n = 80 + split("01 02 03", band, " ") + for (b = 1; b <= 3; b++) { + for (i = 1; i <= n; i++) { + printf "{\"schema_version\":1,\"id\":\"evt-large-%s-%03d\",\"ts\":\"2026-06-06T%s:%02d:00Z\",\"kind\":\"run.completed\",\"subject_type\":\"run\",\"subject_id\":\"RUN-%s-%d\",\"actor\":\"pmctl\",\"payload\":{}}\n", band[b], i, band[b], i % 60, band[b], i + } + } + }' printf '%s\n' 'not json at all' } > "$proj/events.jsonl" out="$tmp_root/large.out" err="$tmp_root/large.err" run_trace "$store" "$out" "$err" --all --json || status=$? count="$(line_count "$out")" - # timestamps must be non-decreasing across the merged stream + # emitted timestamps must be non-decreasing across the whole stream ordered="$(jq -r '.ts' "$out" | LC_ALL=C sort -c 2>&1 && echo OK)" malformed="$(grep -c 'trace: skipped 2 malformed row(s)' "$err" || true)" if [[ "$status" -eq 0 && "$count" == "240" && "$ordered" == "OK" && "$malformed" == "1" ]]; then From ca0b3d5e823411d9d6e591fd883f0c4c0ff65dcf Mon Sep 17 00:00:00 2001 From: Lien Chen Date: Thu, 27 Aug 2026 13:35:09 +0900 Subject: [PATCH 3/4] test(CC-364): add fault-sensitive oracle for the single-jq-pass contract pr-gate round 2 was GO with one critic advisory (critic-F001, low): the scaled regression proves output correctness but nothing fails if per-event jq spawning returns. Add case_trace_tail_single_jq_pass: a counting jq shim on PATH tallies invocations across a 20-event and a 200-event run of `trace tail --all --json`; the test asserts the tallies are equal and non-zero (O(1) in event count). Streaming impl invokes jq once per run regardless of size; a per-event regression would make the 200-event tally ~10x the 20-event one. test-pmctl-trace.sh: 14 passed. shellcheck clean. Co-Authored-By: Claude Sonnet 5 Claude-Session: https://claude.ai/code/session_01KFPwSUfmLGh6KJLYFBArTS --- tests/shell/test-pmctl-trace.sh | 55 +++++++++++++++++++++++++++++++++ 1 file changed, 55 insertions(+) diff --git a/tests/shell/test-pmctl-trace.sh b/tests/shell/test-pmctl-trace.sh index 08d4bcdd..e6c345e9 100755 --- a/tests/shell/test-pmctl-trace.sh +++ b/tests/shell/test-pmctl-trace.sh @@ -325,6 +325,60 @@ case_trace_large_partition_streaming() { fi } +# Behavior: the CC-364 performance contract holds -- `trace tail` invokes jq a +# fixed number of times for a whole event partition, not once per event, so a +# future return to per-event jq spawning is caught even though output stays +# byte-identical. +# Steps: shim a counting `jq` wrapper onto PATH (it tallies invocations then +# exec's the real jq), run `trace tail --all --json` once over a 20-event +# partition and once over a 200-event partition, and assert the invocation +# tally is identical for both (O(1) in event count) and non-zero. A per-event +# implementation would make the 200-event tally ~10x the 20-event one. +case_trace_tail_single_jq_pass() { + local name="pmctl trace tail: jq invocation count is O(1) in event count" + should_run "$name" || return 0 + local store proj shimdir real_jq tally small large status=0 + real_jq="$(type -P jq)" + store="$tmp_root/jqcount-store" + proj="$(trace_project_dir "$store")" + shimdir="$tmp_root/jqcount-shim" + tally="$tmp_root/jqcount.tally" + mkdir -p "$shimdir" + { + printf '%s\n' '#!/usr/bin/env bash' + printf 'printf x >> %q\n' "$tally" + printf 'exec %q "$@"\n' "$real_jq" + } > "$shimdir/jq" + chmod +x "$shimdir/jq" + + gen_events() { + awk -v n="$1" 'BEGIN { + for (i = 1; i <= n; i++) { + printf "{\"schema_version\":1,\"id\":\"evt-%04d\",\"ts\":\"2026-06-06T00:%02d:00Z\",\"kind\":\"run.completed\",\"subject_type\":\"run\",\"subject_id\":\"RUN-%d\",\"actor\":\"pmctl\",\"payload\":{}}\n", i, i % 60, i + } + }' + } + + gen_events 20 > "$proj/events.jsonl" + : > "$tally" + PATH="$shimdir:$PATH" PM_DISPATCH_STATE_ROOT="$store" "$PMCTL" trace tail --all --json \ + > "$tmp_root/jqcount-small.out" 2>/dev/null || status=$? + small="$(wc -c < "$tally" | tr -d ' ')" + + gen_events 200 > "$proj/events.jsonl" + : > "$tally" + PATH="$shimdir:$PATH" PM_DISPATCH_STATE_ROOT="$store" "$PMCTL" trace tail --all --json \ + > "$tmp_root/jqcount-large.out" 2>/dev/null || status=$? + large="$(wc -c < "$tally" | tr -d ' ')" + + if [[ "$status" -eq 0 && "$small" -gt 0 && "$small" == "$large" && + "$(line_count "$tmp_root/jqcount-large.out")" == "200" ]]; then + pass "$name" + else + fail "$name" "status=$status small=$small large=$large large_lines=$(line_count "$tmp_root/jqcount-large.out")" + fi +} + case_trace_empty_missing_store() { local name="pmctl trace tail: missing store exits 0 with empty stdout" should_run "$name" || return 0 @@ -368,6 +422,7 @@ case_trace_equal_ts_append_order case_trace_corrupt_row_tolerance case_trace_active_archive_merge case_trace_large_partition_streaming +case_trace_tail_single_jq_pass case_trace_empty_missing_store case_trace_unknown_flag_usage From d48461e8fa1fe5e217e74ee40f83da29ba2528c8 Mon Sep 17 00:00:00 2001 From: Lien Chen Date: Thu, 27 Aug 2026 15:00:56 +0900 Subject: [PATCH 4/4] docs(BACKLOG): mark CC-364 done Index row -> done, body section gets a Closure 2026-08-27 (pr:#546) note and perf/parity evidence summary. validate.sh, test-pmctl-backlog, test-archive-closed-backlog, test-schema-task-mirrors-backlog all pass. Co-Authored-By: Claude Sonnet 5 Claude-Session: https://claude.ai/code/session_01KFPwSUfmLGh6KJLYFBArTS --- BACKLOG.md | 12 +++++++++--- 1 file changed, 9 insertions(+), 3 deletions(-) diff --git a/BACKLOG.md b/BACKLOG.md index 98d954fd..628c048a 100644 --- a/BACKLOG.md +++ b/BACKLOG.md @@ -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 --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 | @@ -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 --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 `\t\t`, 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 實作完成後與使用者進一步討論了兩個候選防護設計，重新盤點成本效益後決定不排入既定實作。