feat(hook,cli): injection log + aelf tail (#321) - #352
Conversation
📝 WalkthroughWalkthroughThis PR introduces live observability for hook-injected audit logs via a new ChangesHook Audit Enrichment & Live-Tail Feature
Sequence DiagramsequenceDiagram
participant U as User/Prompt
participant H as Hook (user_prompt_submit)
participant R as Retrieval System
participant A as Audit File
participant T as aelf tail
participant O as Output
U->>H: Incoming prompt
activate H
H->>R: time.monotonic() start
R->>R: Match beliefs
R-->>H: hits (Belief list)
H->>H: Measure latency_ms
H->>H: Serialize beliefs (lane/locked/hash/posterior)
H->>H: Count tokens from rendered block
H->>A: Write record (ts/hook/beliefs/tokens/latency_ms)
deactivate H
User->>T: aelf tail --filter lane=L0
activate T
T->>A: Open audit file, seek to end (follow=True)
T->>A: Poll for appended lines
A-->>T: New JSON record
T->>T: Parse JSON
T->>T: record_matches_filters(lane=L0)
T->>T: format_record (header + per-belief lines)
T->>O: Write formatted output
T->>O: Flush
Note over T: Detect rotation via inode change<br/>Reset to start, re-read
deactivate T
sequenceDiagram
participant U as User<br/>(aelf tail --since 5m)
participant T as tail_audit()
participant R as Rotated audit.1
participant L as Live audit
participant O as Output
U->>T: tail_audit(since=timedelta(minutes=5), follow=False)
activate T
T->>T: Compute since_cutoff (now - 5m)
T->>R: _read_records(audit_path.1)
R-->>T: [records]
T->>T: Filter by ts >= since_cutoff
T->>L: _read_records(audit_path)
L-->>T: [records]
T->>T: Filter by ts >= since_cutoff
T->>T: Merge & sort records chronologically
T->>T: Apply user filters (hook/lane)
T->>O: _emit_records (format + write)
T-->>U: return 0
deactivate T
Estimated code review effort🎯 3 (Moderate) | ⏱️ ~25 minutes 🚥 Pre-merge checks | ✅ 4 | ❌ 1❌ Failed checks (1 warning)
✅ Passed checks (4 passed)
✏️ Tip: You can configure your own custom pre-merge checks in the settings. ✨ Finishing Touches📝 Generate docstrings
🧪 Generate unit tests (beta)
Thanks for using CodeRabbit! It's free for OSS, and your support helps us grow. If you like it, consider giving us a shout-out. Review rate limit: 0/1 reviews remaining, refill in 60 minutes.Comment |
Reviewer's GuideExtends the hook audit logging to include structured per-belief metadata, latency, and token estimates, and introduces an Sequence diagram for aelf tail CLI reading the hook audit logsequenceDiagram
actor Operator
participant CLI as aelf_cli
participant Tail as HookTailReader
participant Hook as HookAuditWriter
participant FS as FileSystem
Operator->>CLI: invoke aelf tail [--filter] [--since] [--no-blob] [--no-follow]
CLI->>Tail: parse_filter(spec) for each --filter
Tail-->>CLI: (key, value) filters or ValueError
CLI->>Tail: parse_since(spec) for --since (optional)
Tail-->>CLI: timedelta since or ValueError
CLI->>Tail: tail_audit(filters, since, include_blob, follow, out)
alt since provided
Tail->>Hook: _audit_path_for_db(db_path())
Hook-->>Tail: audit_path
Tail->>FS: read rotated + live audit files
FS-->>Tail: JSONL records
Tail->>Tail: _read_records + _parse_record_ts
Tail->>Tail: record_matches_filters(record, filters)
Tail->>Tail: format_record(record, include_blob)
Tail->>CLI: write formatted records to out
end
alt follow is False
Tail-->>CLI: return after one-shot emit
else follow is True
loop poll until interrupted
Tail->>FS: stat audit_path (size, inode)
FS-->>Tail: st_size, st_ino
alt inode changed
Tail->>Tail: reset offset (rotation detected)
end
Tail->>FS: read new bytes from audit_path
FS-->>Tail: new JSONL lines
Tail->>Tail: decode JSON, record_matches_filters
Tail->>Tail: format_record(record, include_blob)
Tail->>CLI: write formatted records to out
end
end
Entity-relationship diagram for extended hook_audit.jsonl schemaerDiagram
AUDIT_RECORD {
string ts
string hook
string prompt
string rendered_block
int n_beliefs
int n_locked
string session_id
int tokens
int latency_ms
}
BELIEF_ENTRY {
string id
string lane
boolean locked
string content_hash
float alpha
float beta
float posterior_mean
string snippet
}
AUDIT_RECORD ||--o{ BELIEF_ENTRY : beliefs
Updated class diagram for hook audit writer and hook_tail reader modulesclassDiagram
class Belief {
string id
string lock_level
string content_hash
float alpha
float beta
string content
}
class HookAuditWriter {
<<module>>
+int AUDIT_BELIEF_SNIPPET_CAP
+_belief_snippet(content str) str
+_serialize_belief_for_audit(b Belief) dict~str, object~
+_audit_tokens_from_block(block str) int
+_write_hook_audit_record(hook str, prompt str, rendered_block str, n_beliefs int, n_locked int, session_id str, beliefs list~Belief~, latency_ms int, config HookAuditConfig, stderr IO_str) void
}
class HookTailReader {
<<module>>
+parse_filter(spec str) tuple~str, str~
+parse_since(spec str) timedelta
+record_matches_filters(record dict~str, object~, filters list~tuple~str, str~~) bool
+format_record(record dict~str, object~, include_blob bool) str
+tail_audit(audit_path Path, filters list~tuple~str, str~~, since timedelta, include_blob bool, follow bool, out IO_str, poll_interval float, max_iters int) int
}
class AelfCLI {
<<module>>
+_cmd_tail(args Namespace, out object) int
+build_parser(show_advanced bool) ArgumentParser
}
class HookAuditConfig {
bool enabled
int max_bytes
}
HookAuditWriter --> Belief : serializes
HookAuditWriter --> HookAuditConfig : uses
HookTailReader --> HookAuditWriter : uses AUDIT_FILENAME, AUDIT_ROTATED_SUFFIX, _audit_path_for_db
AelfCLI --> HookTailReader : calls tail_audit
File-Level Changes
Assessment against linked issues
Possibly linked issues
Tips and commandsInteracting with Sourcery
Customizing Your ExperienceAccess your dashboard to:
Getting Help
|
| from __future__ import annotations | ||
|
|
||
| import json | ||
| import os |
| from aelfrice.hook import ( | ||
| AUDIT_FILENAME, | ||
| AUDIT_ROTATED_SUFFIX, | ||
| _audit_path_for_db, | ||
| ) |
| from aelfrice.hook import ( | ||
| AUDIT_FILENAME, | ||
| AUDIT_ROTATED_SUFFIX, | ||
| _audit_path_for_db, | ||
| _write_hook_audit_record, | ||
| ) |
There was a problem hiding this comment.
Hey - I've found 1 issue, and left some high level feedback:
- There are two separate JSONL parsing paths in
hook_tail(_read_recordsand the follow-mode loop) that implement slightly different but overlapping logic; consider extracting a sharediter_audit_records(path, since_cutoff=None)helper and reusing it in both places to keep behavior and edge-case handling (e.g. malformed lines) consistent and easier to maintain.
Prompt for AI Agents
Please address the comments from this code review:
## Overall Comments
- There are two separate JSONL parsing paths in `hook_tail` (`_read_records` and the follow-mode loop) that implement slightly different but overlapping logic; consider extracting a shared `iter_audit_records(path, since_cutoff=None)` helper and reusing it in both places to keep behavior and edge-case handling (e.g. malformed lines) consistent and easier to maintain.
## Individual Comments
### Comment 1
<location path="src/aelfrice/slash_commands/tail.md" line_range="10" />
<code_context>
+---
+<objective>
+Stream the per-turn hook audit log so the operator can see exactly
+which beliefs each UserPromptSubmit / SessionStart fire injected — id,
+lane (L0 locked / L1 retrieved), token count, latency, and a snippet.
+By default tails forever; pass `--no-follow` for a one-shot dump.
</code_context>
<issue_to_address>
**suggestion (typo):** Consider rephrasing "fire" here to something like "firing" for grammatical clarity.
The construction "each UserPromptSubmit / SessionStart fire injected" is ungrammatical. Consider something like "each UserPromptSubmit / SessionStart firing injected" or "each UserPromptSubmit / SessionStart hook invocation injected" for smoother wording.
```suggestion
which beliefs each UserPromptSubmit / SessionStart hook invocation injected — id,
```
</issue_to_address>Help me be more useful! Please click 👍 or 👎 on each comment and I'll use the feedback to improve your reviews.
| --- | ||
| <objective> | ||
| Stream the per-turn hook audit log so the operator can see exactly | ||
| which beliefs each UserPromptSubmit / SessionStart fire injected — id, |
There was a problem hiding this comment.
suggestion (typo): Consider rephrasing "fire" here to something like "firing" for grammatical clarity.
The construction "each UserPromptSubmit / SessionStart fire injected" is ungrammatical. Consider something like "each UserPromptSubmit / SessionStart firing injected" or "each UserPromptSubmit / SessionStart hook invocation injected" for smoother wording.
| which beliefs each UserPromptSubmit / SessionStart fire injected — id, | |
| which beliefs each UserPromptSubmit / SessionStart hook invocation injected — id, |
|
[claim:review:Kulili:2026-05-02T19:39:47Z] |
|
Reviewed. Diff is clean: discretion grep empty, all 5 required status checks (secrets-scan, pattern-scan, history-scan, pytest 3.12/3.13) green, all 3 commits signed, additive schema with optional fields preserves back-compat for older readers. One blocker on the way to a clean merge:
Minor cosmetic in Will merge once typos goes green. |
|
[release:review:Kulili:2026-05-02T19:41:10Z] |
|
This PR is now behind Auto-rebase was removed because the bot has no signing key; rebasing as the bot strips author signatures and the |
) Additive fields on hook_audit.jsonl per #321 path (a) — extend the existing #280 audit log rather than ship a parallel injections.ndjson. - beliefs[]: per-hit {id, lane (L0/L1), locked, content_hash, alpha, beta, posterior_mean, snippet}. Lane derived from lock_level; score intentionally absent (retrieve() does not propagate per-hit scores). - latency_ms: wall-clock around retrieve+format span on both user_prompt_submit and session_start. - tokens: derived from rendered_block via the same 4-chars-per-token estimator retrieval uses for budgeting. All fields are optional in the writer signature, so callers that don't pass them produce records readable by older readers. test_rotation threshold bumped 500 → 1000 to accommodate the larger record.
`aelf tail` is the reader half of #321: a tail -f-style pretty-printer over the per-turn hook audit log (extended in the previous commit with beliefs[], latency_ms, tokens). New module `hook_tail.py` keeps the formatting helpers out of the import-cheap hook write path. CLI surface: --filter key=value (repeatable, AND-joined): hook=<name>, lane=L0|L1 --since DUR (Ns / Nm / Nh / Nd): backfill from rotated + live --no-blob: suppress per-belief snippet bodies --no-follow: dump current contents and exit (one-shot) Default behaviour (no --since, --follow): start at end-of-file and stream new records. Rotation is detected via inode change so tail survives a single-slot rotation seamlessly. Filter semantics: hook= matches the record-level field; lane= matches iff at least one belief in beliefs[] has that lane. Records missing the queried field never match — falsifying, not best-effort. Records written before #321 (no beliefs[] / tokens / latency_ms) render without those fields and are filtered out by lane= queries. 27 new unit tests in tests/test_hook_tail.py covering parsers, filter semantics, format_record (header + per-belief lines + --no-blob), one-shot tail, follow mode (new-line pickup + rotation survival), --since (rotated + live backfill), and an end-to-end hook-fire-then- tail integration test.
typos flags 'Nd' (placeholder) as a misspelling of 'And'. Rephrasing to concrete examples (30s / 5m / 2h / 1d) clears CI and reads better.
5717d14 to
6480b9f
Compare
|
Fixed via 6480b9f. Picked option (b) — rephrased the help string to use concrete examples ( Rebased onto |
There was a problem hiding this comment.
Actionable comments posted: 2
🤖 Prompt for all review comments with AI agents
Verify each finding against the current code and only fix it if needed.
Inline comments:
In `@src/aelfrice/hook_tail.py`:
- Around line 308-336: When a rotation is detected (st.st_ino != last_ino) we
must drain the rotated file from the previous offset before resetting pos;
locate the rotated file (audit_path.with_name(audit_path.name + ".1")), open it,
seek to the current pos, read remaining bytes, parse and emit those records via
_emit_records(...) (use the same parsing/append logic as for the live file),
then set pos = 0 and continue to read the new live file; update the code paths
that use audit_path, last_ino, pos, _emit_records, include_blob, sink and flt
accordingly and add a regression test that performs append-then-rotate to ensure
the record that triggered rotation is emitted.
- Around line 149-160: When beliefs_obj is missing or not a list, fall back to
legacy counters: read record.get("n_beliefs") and record.get("n_locked") and
compute n_l1 = int(n_locked) if present else 0 and n_l0 = max(0, int(n_beliefs)
- n_l1) if n_beliefs present else 0; otherwise keep the existing computation
from the parsed beliefs list. Update the variables n_l0 and n_l1 (used to build
parts) so they come from parsed beliefs when beliefs_obj is a list of dicts, and
from these legacy fields when beliefs_obj is absent or invalid, ensuring integer
conversion and non-negative results.
🪄 Autofix (Beta)
Fix all unresolved CodeRabbit comments on this PR:
- Push a commit to this branch (recommended)
- Create a new PR with the fixes
ℹ️ Review info
⚙️ Run configuration
Configuration used: Path: .coderabbit.yaml
Review profile: CHILL
Plan: Pro
Run ID: 39945046-aa79-4331-a23a-dbd6a1c9a645
📒 Files selected for processing (7)
src/aelfrice/cli.pysrc/aelfrice/hook.pysrc/aelfrice/hook_tail.pysrc/aelfrice/slash_commands/tail.mdtests/test_hook_audit.pytests/test_hook_tail.pytests/test_slash_commands.py
| beliefs_obj = record.get("beliefs") | ||
| beliefs: list[dict[str, object]] = [] | ||
| if isinstance(beliefs_obj, list): | ||
| beliefs = [b for b in beliefs_obj if isinstance(b, dict)] | ||
| n_l0 = sum(1 for b in beliefs if b.get("lane") == "L0") | ||
| n_l1 = sum(1 for b in beliefs if b.get("lane") == "L1") | ||
| parts: list[str] = [short_ts, hook] | ||
| if isinstance(tokens, int): | ||
| parts.append(f"{tokens} tok") | ||
| if isinstance(latency_ms, int): | ||
| parts.append(f"{latency_ms} ms") | ||
| parts.append(f"L0×{n_l0} L1×{n_l1}") |
There was a problem hiding this comment.
Fall back to legacy counters when beliefs[] is missing.
Pre-#321 audit rows still have n_beliefs / n_locked. Right now those render as L0×0 L1×0, which makes historical injections look empty even when the record says hits were injected. Please derive the header counts from the legacy fields when beliefs is absent.
Suggested adjustment
beliefs_obj = record.get("beliefs")
beliefs: list[dict[str, object]] = []
if isinstance(beliefs_obj, list):
beliefs = [b for b in beliefs_obj if isinstance(b, dict)]
- n_l0 = sum(1 for b in beliefs if b.get("lane") == "L0")
- n_l1 = sum(1 for b in beliefs if b.get("lane") == "L1")
+ n_l0 = sum(1 for b in beliefs if b.get("lane") == "L0")
+ n_l1 = sum(1 for b in beliefs if b.get("lane") == "L1")
+ else:
+ n_locked = record.get("n_locked")
+ n_beliefs = record.get("n_beliefs")
+ if isinstance(n_locked, int) and isinstance(n_beliefs, int):
+ n_l0 = max(0, n_locked)
+ n_l1 = max(0, n_beliefs - n_locked)
+ else:
+ n_l0 = 0
+ n_l1 = 0📝 Committable suggestion
‼️ IMPORTANT
Carefully review the code before committing. Ensure that it accurately replaces the highlighted code, contains no missing lines, and has no issues with indentation. Thoroughly test & benchmark the code to ensure it meets the requirements.
| beliefs_obj = record.get("beliefs") | |
| beliefs: list[dict[str, object]] = [] | |
| if isinstance(beliefs_obj, list): | |
| beliefs = [b for b in beliefs_obj if isinstance(b, dict)] | |
| n_l0 = sum(1 for b in beliefs if b.get("lane") == "L0") | |
| n_l1 = sum(1 for b in beliefs if b.get("lane") == "L1") | |
| parts: list[str] = [short_ts, hook] | |
| if isinstance(tokens, int): | |
| parts.append(f"{tokens} tok") | |
| if isinstance(latency_ms, int): | |
| parts.append(f"{latency_ms} ms") | |
| parts.append(f"L0×{n_l0} L1×{n_l1}") | |
| beliefs_obj = record.get("beliefs") | |
| beliefs: list[dict[str, object]] = [] | |
| if isinstance(beliefs_obj, list): | |
| beliefs = [b for b in beliefs_obj if isinstance(b, dict)] | |
| n_l0 = sum(1 for b in beliefs if b.get("lane") == "L0") | |
| n_l1 = sum(1 for b in beliefs if b.get("lane") == "L1") | |
| else: | |
| n_locked = record.get("n_locked") | |
| n_beliefs = record.get("n_beliefs") | |
| if isinstance(n_locked, int) and isinstance(n_beliefs, int): | |
| n_l0 = max(0, n_locked) | |
| n_l1 = max(0, n_beliefs - n_locked) | |
| else: | |
| n_l0 = 0 | |
| n_l1 = 0 | |
| parts: list[str] = [short_ts, hook] | |
| if isinstance(tokens, int): | |
| parts.append(f"{tokens} tok") | |
| if isinstance(latency_ms, int): | |
| parts.append(f"{latency_ms} ms") | |
| parts.append(f"L0×{n_l0} L1×{n_l1}") |
🧰 Tools
🪛 Ruff (0.15.12)
[warning] 160-160: String contains ambiguous × (MULTIPLICATION SIGN). Did you mean x (LATIN SMALL LETTER X)?
(RUF001)
[warning] 160-160: String contains ambiguous × (MULTIPLICATION SIGN). Did you mean x (LATIN SMALL LETTER X)?
(RUF001)
🤖 Prompt for AI Agents
Verify each finding against the current code and only fix it if needed.
In `@src/aelfrice/hook_tail.py` around lines 149 - 160, When beliefs_obj is
missing or not a list, fall back to legacy counters: read
record.get("n_beliefs") and record.get("n_locked") and compute n_l1 =
int(n_locked) if present else 0 and n_l0 = max(0, int(n_beliefs) - n_l1) if
n_beliefs present else 0; otherwise keep the existing computation from the
parsed beliefs list. Update the variables n_l0 and n_l1 (used to build parts) so
they come from parsed beliefs when beliefs_obj is a list of dicts, and from
these legacy fields when beliefs_obj is absent or invalid, ensuring integer
conversion and non-negative results.
| st = audit_path.stat() | ||
| if last_ino is not None and st.st_ino != last_ino: | ||
| # Rotation detected: live file was renamed to .1 and a new | ||
| # one was created. Reset position to read from the start. | ||
| pos = 0 | ||
| last_ino = st.st_ino | ||
|
|
||
| if st.st_size <= pos: | ||
| time.sleep(poll_interval) | ||
| continue | ||
|
|
||
| with audit_path.open("r", encoding="utf-8") as f: | ||
| f.seek(pos) | ||
| new_text = f.read() | ||
| pos = f.tell() | ||
|
|
||
| new_records: list[dict[str, object]] = [] | ||
| for line in new_text.splitlines(): | ||
| stripped = line.strip() | ||
| if not stripped: | ||
| continue | ||
| try: | ||
| parsed = json.loads(stripped) | ||
| except json.JSONDecodeError: | ||
| continue | ||
| if not isinstance(parsed, dict): | ||
| continue | ||
| new_records.append(parsed) | ||
| _emit_records(new_records, flt, include_blob=include_blob, out=sink) |
There was a problem hiding this comment.
Don't drop the record that triggers rotation.
src/aelfrice/hook.py:_append_audit() writes the new line and only then renames the whole live file to .1. If that happens between polls, this branch sees the inode flip, resets pos, and starts reading only the new live file. Any unread bytes that moved into .1 are never emitted, so aelf tail can miss the exact injection that caused rotation.
Please drain the rotated file from the previous offset before switching to the new live file, and add a regression test for the append-then-rotate case.
🤖 Prompt for AI Agents
Verify each finding against the current code and only fix it if needed.
In `@src/aelfrice/hook_tail.py` around lines 308 - 336, When a rotation is
detected (st.st_ino != last_ino) we must drain the rotated file from the
previous offset before resetting pos; locate the rotated file
(audit_path.with_name(audit_path.name + ".1")), open it, seek to the current
pos, read remaining bytes, parse and emit those records via _emit_records(...)
(use the same parsing/append logic as for the live file), then set pos = 0 and
continue to read the new live file; update the code paths that use audit_path,
last_ino, pos, _emit_records, include_blob, sink and flt accordingly and add a
regression test that performs append-then-rotate to ensure the record that
triggered rotation is emitted.
|
[claim:review:Gylf:2026-05-02T20:02:56Z] |
|
[release:review:Gylf:2026-05-02T20:03:52Z] |
Closes #321.
Approach
Per the pre-implementation comment, this PR takes path (a): extend the existing
hook_audit.jsonl(shipped in #280 mitigation 3) rather than ship a parallelinjections.ndjson. The rationale and three-path breakdown is in the issue thread; the user picked (a).Net result is a single audit log on the file system — same path, same rotation, same writer entry-points — with additive structured fields and a new reader CLI.
Schema additions to
hook_audit.jsonlAll additive and optional, so older readers keep working unchanged:
beliefslist[{id, lane, locked, content_hash, alpha, beta, posterior_mean, snippet}]latency_msinttokensintlaneis derived fromlock_level(LOCK_USER→"L0", else"L1"). Per-hit BM25 / ranking scores are intentionally not included —retrieve()does not propagate per-hit scores through to the hook caller, and adding that plumbing was out of scope for #321 (replay harness over historical logs is explicitly out-of-scope in the issue body too).posterior_meanis computed from the belief'salpha/betaso the user can still see Bayesian confidence at a glance.snippetis the first line ofbelief.contentcapped at 120 chars; the fullrendered_blockis still on the record (existing field), so nothing is lost — the snippet is for at-a-glance scanning inaelf tailoutput.aelf tailHeader line:
<HH:MM:SS> <hook> <tokens> tok <latency> ms L0×N L1×M. Then one indented line per belief frombeliefs[].Default behaviour (no
--since, follow): start at end-of-file and stream new records. Rotation is detected via inode change so tail survives a single-slot rotation. Filter semantics are falsifying (records missing the queried field never match) so the count of matched records is well-defined.The reader lives in a new
aelfrice.hook_tailmodule — splitting it fromaelfrice.hookkeeps the hook write path import-cheap (everyUserPromptSubmitfire pays its import cost).Tests
tests/test_hook_tail.pycovering: filter parser (valid / unknown key / missing value),--sinceparser (s/m/h/d, malformed),record_matches_filters(hook + lane semantics + AND),format_record(header + per-belief +--no-blob+ missing-optional-fields back-compat), one-shot tail, follow mode (new-line pickup + rotation survival),--since(rotated + live backfill), and an end-to-end hook-fire-then-tail integration test.tests/test_hook_audit.py::test_rotation_at_max_bytesthreshold bumped 500 → 1000 to accommodate the larger record (~650B per fire vs. ~250B previously).tests/test_slash_commands.pyupdated: addedtailtoEXPECTED_COMMANDS. Newslash_commands/tail.md.pytest -q→ 2013 passed, 14 skipped (pre-existing skips, unrelated).Out of scope (deferred)
retrieve()→ audit record.aelf statusline-inject(Optional, separate commit per issue body).Discretion
Reserved-vocab grep over the full diff is empty.
Summary by Sourcery
Extend hook injection auditing with richer per-belief metadata and add a CLI subcommand to live-tail and inspect these audit logs.
New Features:
aelf tailCLI subcommand and backinghook_tailmodule to pretty-print and live-tail hook audit logs with filtering and time-based backfill.aelf:tailto expose the tail functionality via slash commands.Enhancements:
Documentation:
aelf tailslash command usage, arguments, and behavior.Tests:
Summary by CodeRabbit
Release Notes
New Features
aelf tailCLI command for live-tailing hook injection audit logs with optional record filtering, time-window filtering, and output control options (--no-followfor one-shot mode,--no-blobto exclude content snippets).Documentation
aelf tailcommand.Tests