Skip to content

Commit e8762b7

Browse files
committed
fix(0.5.9): bounded log queries, tool-loop budgets, remove over-promises
Closes the four second-review blockers per owner dispositions. F-4 (implemented): adds airlock/log_query.py as the single bounded reader. slow/analyzer._load_logs read every record from every daily file, and advisor/tools.get_recent_errors passed limit=1000000 -- a limit in name only that materialized every row before filtering. Both are reachable from the CLI and TUI, so enough accumulated history would exhaust memory and OOM-kill the proxy under the unit's MemoryMax. The reader filters while scanning (a rare match stays cheap), walks days newest-first (a truncated result keeps the most recent records), and reports truncation rather than returning partial data silently. That last property matters most: an analysis that scanned half the window and presents itself as complete yields confident wrong conclusions about traffic it never saw. Consumers now surface LogPage.truncated. F-1 Part A (implemented): _run_tool_loop returns a ToolLoopOutcome carrying an explicit stop_reason, under a ToolLoopBudget bounding rounds, wall-clock, total tool calls, and per-result bytes. Previously the only bound was a round count -- three rounds against a slow model is unbounded in the dimension that hurts -- and every failure path returned a bare None, making "aborted on a disallowed tool" indistinguishable from "nothing to say". Part B (parameterized tool arguments) is deferred to 0.5.10: it should be served by the F-4 reader, and adding arguments first would let a model request an arbitrarily large slice. F-2 (re-scoped): behavior unchanged; the claim is corrected. Airlock does not manage, verify, or retrieve results from a sandbox -- it declares the provider's code_execution tool on a Messages API call. The opt-in controls whether derived aggregates leave the machine and is not a security boundary. Documented in docs/guide/guardrails.md. F-3 (out of scope): code inspection stays observational. The hardcoded "enforcement_weight": 0.0 is removed with owner approval -- a field of that name in persisted evidence advertised wiring that does not exist, the same over-promise as F-2. Wiring it to enforcement needs its own observe window: resource_access matches any open( or requests. in a code block. Suite: 2986 passed.
1 parent 4dd3893 commit e8762b7

11 files changed

Lines changed: 820 additions & 69 deletions

File tree

airlock/advisor/tools.py

Lines changed: 41 additions & 26 deletions
Original file line numberDiff line numberDiff line change
@@ -20,12 +20,15 @@
2020
import json
2121
import logging
2222
from collections import Counter
23-
from datetime import datetime, timedelta
2423
from pathlib import Path
2524
from typing import Any, Callable
2625

27-
from airlock.fast.state import StateStore
2826
from airlock.api.queries import get_request_logs
27+
from airlock.fast.state import StateStore
28+
from airlock.log_query import LogPage, LogQuery, query_logs
29+
30+
#: Upper bound on rows pulled from the datastore in one advisor query.
31+
DATASTORE_QUERY_LIMIT = 50_000
2932

3033
logger = logging.getLogger("airlock.advisor.tools")
3134

@@ -35,28 +38,23 @@
3538
# ---------------------------------------------------------------------------
3639

3740

38-
def _load_logs(log_dir: str, days: int = 7) -> list[dict[str, Any]]:
39-
"""Load JSONL records from the last *days* days."""
40-
records: list[dict[str, Any]] = []
41-
today = datetime.utcnow().date()
42-
log_path = Path(log_dir)
43-
44-
for i in range(days):
45-
day = today - timedelta(days=i)
46-
file_path = log_path / f"airlock-{day.isoformat()}.jsonl"
47-
if not file_path.exists():
48-
continue
49-
with open(file_path, encoding="utf-8") as f:
50-
for line in f:
51-
line = line.strip()
52-
if not line:
53-
continue
54-
try:
55-
records.append(json.loads(line))
56-
except json.JSONDecodeError:
57-
continue
41+
def _load_page(
42+
log_dir: str,
43+
days: int = 7,
44+
predicate: Callable[[dict[str, Any]], bool] | None = None,
45+
) -> LogPage:
46+
"""Bounded log scan. Callers should surface ``page.truncated``.
47+
48+
Previously an unbounded read of every record in the window. Advisor tools
49+
are reachable from the CLI and TUI, so an operator with enough accumulated
50+
history could exhaust memory simply by asking a question.
51+
"""
52+
return query_logs(LogQuery(days=days, predicate=predicate, directory=Path(log_dir)))
5853

59-
return records
54+
55+
def _load_logs(log_dir: str, days: int = 7) -> list[dict[str, Any]]:
56+
"""Backwards-compatible record list. Prefer :func:`_load_page`."""
57+
return _load_page(log_dir, days=days).records
6058

6159

6260
# ---------------------------------------------------------------------------
@@ -145,17 +143,31 @@ def get_recent_errors(log_dir: str, days: int = 2) -> dict:
145143
except Exception:
146144
engine = None
147145

146+
truncated: dict[str, Any] = {"truncated": False, "limit_hit": None}
148147
if engine is not None:
149-
nodes = get_request_logs(engine, limit=1000000)
148+
# Was limit=1000000 — a limit in name only, and every row was
149+
# materialized before filtering.
150+
nodes = get_request_logs(engine, limit=DATASTORE_QUERY_LIMIT)
150151
records = [n.properties if hasattr(n, "properties") else n for n in nodes]
151152
failures = [
152153
r
153154
for r in records
154155
if (r.get("success") is False) or bool(r.get("error_flag"))
155156
]
157+
if len(records) >= DATASTORE_QUERY_LIMIT:
158+
truncated = {"truncated": True, "limit_hit": "datastore_limit"}
156159
else:
157-
records = _load_logs(log_dir, days=days)
158-
failures = [r for r in records if not r.get("success")]
160+
# Filter during the scan so a quiet window never materializes the
161+
# successful traffic it is dominated by.
162+
page = _load_page(
163+
log_dir,
164+
days=days,
165+
predicate=lambda r: (
166+
(r.get("success") is False) or bool(r.get("error_flag"))
167+
),
168+
)
169+
failures = page.records
170+
truncated = {"truncated": page.truncated, "limit_hit": page.limit_hit}
159171

160172
by_model: Counter = Counter()
161173
by_error_type: Counter = Counter()
@@ -182,6 +194,9 @@ def get_recent_errors(log_dir: str, days: int = 2) -> dict:
182194
"by_error_type": dict(by_error_type),
183195
"by_client": dict(by_client),
184196
"recent_samples": recent_samples,
197+
# The advisor must be able to say "based on a partial window" rather
198+
# than presenting a truncated scan as the whole picture.
199+
"window": truncated,
185200
}
186201

187202

airlock/guardrails/code_inspection.py

Lines changed: 11 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -2,6 +2,17 @@
22
33
The result intentionally contains categories and counts, never matched source
44
text. This makes it safe to persist alongside the canonical request record.
5+
6+
**This is observation only — it is not wired to enforcement.** The result
7+
previously carried an ``enforcement_weight`` of ``0.0`` that nothing read; a
8+
field by that name in persisted evidence implied a wiring that did not exist,
9+
so it was removed (0.5.9, owner decision).
10+
11+
Connecting inspection to post-response enforcement would need its own observe
12+
window first: ``resource_access`` matches any ``open(`` or ``requests.`` in a
13+
code block, which is entirely ordinary in code-assistance traffic. Enabling it
14+
as a blocking signal without evidence would generate false positives on normal
15+
work.
516
"""
617

718
from __future__ import annotations
@@ -63,5 +74,4 @@ def inspect_code(text: str) -> dict[str, Any]:
6374
"code_blocks": len(blocks),
6475
"findings": findings,
6576
"score": min(1.0, sum(findings.values()) / 5.0),
66-
"enforcement_weight": 0.0,
6777
}

airlock/log_query.py

Lines changed: 200 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,200 @@
1+
"""Bounded reader for Airlock's JSONL request logs.
2+
3+
Every consumer that reads request logs — the slow analyzer, the advisor tools,
4+
and the TUI log screen — goes through here, so the bounds and the truncation
5+
semantics live in one place.
6+
7+
Why this exists
8+
---------------
9+
The TUI screen was given a record cap in 0.5.9; the other readers were not.
10+
``slow/analyzer._load_logs`` read every record from every daily file into a
11+
list, and ``advisor/tools.get_recent_errors`` passed ``limit=1000000`` — a limit
12+
in name only. Both are reachable from the CLI and the TUI, so a deployment with
13+
enough accumulated history would try to hold its whole log corpus in memory,
14+
with no degradation path: it either fits or the process dies. Under the systemd
15+
unit's ``MemoryMax``, that is an OOM kill of the proxy, not just of the
16+
analysis.
17+
18+
Three properties matter, and the second matters most:
19+
20+
**Filter while scanning.** The predicate runs per line, so a narrow query never
21+
materializes the whole corpus. This is what makes a generous record ceiling
22+
generous rather than restrictive.
23+
24+
**Truncation is reported, never silent.** :attr:`LogPage.truncated` and
25+
:attr:`LogPage.limit_hit` are meant to reach the caller's output. An analysis
26+
that scanned half the window and presents itself as complete is worse than one
27+
that refuses — it yields confident, wrong conclusions about traffic it never
28+
saw.
29+
30+
**Newest-first.** Days are walked backwards from today, so a truncated result
31+
retains the most recent records, which is what every consumer actually wants.
32+
"""
33+
34+
from __future__ import annotations
35+
36+
import json
37+
import os
38+
from dataclasses import dataclass, field
39+
from datetime import datetime, timedelta, timezone
40+
from pathlib import Path
41+
from typing import Any, Callable, Iterator
42+
43+
#: Hard ceiling on retained records. Generous because the predicate filters
44+
#: during the scan; a narrow query will not approach it.
45+
DEFAULT_MAX_RECORDS = 50_000
46+
47+
#: Hard ceiling on bytes read from disk in one query.
48+
DEFAULT_MAX_BYTES = 256 * 1024 * 1024
49+
50+
LIMIT_RECORDS = "max_records"
51+
LIMIT_BYTES = "max_bytes"
52+
53+
54+
def _env_int(name: str, default: int) -> int:
55+
raw = (os.getenv(name) or "").strip()
56+
if not raw:
57+
return default
58+
try:
59+
value = int(raw)
60+
except ValueError:
61+
return default
62+
return value if value > 0 else default
63+
64+
65+
def log_dir() -> Path:
66+
return Path(os.getenv("AIRLOCK_LOG_DIR", "./logs"))
67+
68+
69+
@dataclass(frozen=True)
70+
class LogQuery:
71+
"""A bounded request for log records.
72+
73+
``predicate`` is applied per record during the scan. Returning False costs
74+
only the parse, so callers should filter here rather than afterwards.
75+
"""
76+
77+
days: int = 7
78+
max_records: int = 0 # 0 → resolve from environment/default
79+
max_bytes: int = 0 # 0 → resolve from environment/default
80+
predicate: Callable[[dict[str, Any]], bool] | None = None
81+
directory: Path | None = None
82+
83+
def resolved_max_records(self) -> int:
84+
return self.max_records or _env_int(
85+
"AIRLOCK_LOG_QUERY_MAX_RECORDS", DEFAULT_MAX_RECORDS
86+
)
87+
88+
def resolved_max_bytes(self) -> int:
89+
return self.max_bytes or _env_int(
90+
"AIRLOCK_LOG_QUERY_MAX_BYTES", DEFAULT_MAX_BYTES
91+
)
92+
93+
94+
@dataclass
95+
class LogPage:
96+
"""Result of a bounded scan.
97+
98+
``truncated`` means a limit stopped the scan before the requested window was
99+
exhausted — the caller is holding a partial view and must say so.
100+
"""
101+
102+
records: list[dict[str, Any]] = field(default_factory=list)
103+
scanned: int = 0
104+
bytes_read: int = 0
105+
truncated: bool = False
106+
limit_hit: str | None = None
107+
files_read: list[str] = field(default_factory=list)
108+
oldest_day: str | None = None
109+
110+
def note(self) -> str | None:
111+
"""One-line, human-facing description of truncation, or None."""
112+
if not self.truncated:
113+
return None
114+
if self.limit_hit == LIMIT_RECORDS:
115+
return (
116+
f"Results truncated at {len(self.records):,} records; "
117+
"older records in the requested window were not read."
118+
)
119+
return (
120+
f"Results truncated after reading {self.bytes_read / 1024 / 1024:.0f} MB; "
121+
"older records in the requested window were not read."
122+
)
123+
124+
def as_metadata(self) -> dict[str, Any]:
125+
"""Truncation state for embedding in reports and tool results."""
126+
return {
127+
"records": len(self.records),
128+
"scanned": self.scanned,
129+
"truncated": self.truncated,
130+
"limit_hit": self.limit_hit,
131+
"oldest_day": self.oldest_day,
132+
}
133+
134+
135+
def _day_files(query: LogQuery) -> Iterator[tuple[str, Path]]:
136+
"""Yield ``(iso_day, path)`` newest first for the requested window."""
137+
directory = query.directory or log_dir()
138+
today = datetime.now(timezone.utc).date()
139+
for offset in range(max(1, query.days)):
140+
day = today - timedelta(days=offset)
141+
path = directory / f"airlock-{day.isoformat()}.jsonl"
142+
if path.exists():
143+
yield day.isoformat(), path
144+
145+
146+
def query_logs(query: LogQuery | None = None) -> LogPage:
147+
"""Scan request logs newest-first under explicit bounds."""
148+
query = query or LogQuery()
149+
max_records = query.resolved_max_records()
150+
max_bytes = query.resolved_max_bytes()
151+
page = LogPage()
152+
153+
for day, path in _day_files(query):
154+
page.files_read.append(path.name)
155+
page.oldest_day = day
156+
try:
157+
handle = path.open("r", encoding="utf-8")
158+
except OSError:
159+
continue
160+
with handle:
161+
for line in handle:
162+
page.bytes_read += len(line)
163+
if page.bytes_read > max_bytes:
164+
page.truncated = True
165+
page.limit_hit = LIMIT_BYTES
166+
return page
167+
line = line.strip()
168+
if not line:
169+
continue
170+
page.scanned += 1
171+
try:
172+
record = json.loads(line)
173+
except json.JSONDecodeError:
174+
continue
175+
if query.predicate is not None and not query.predicate(record):
176+
continue
177+
page.records.append(record)
178+
if len(page.records) >= max_records:
179+
page.truncated = True
180+
page.limit_hit = LIMIT_RECORDS
181+
return page
182+
return page
183+
184+
185+
def load_records(
186+
days: int = 7,
187+
*,
188+
directory: Path | str | None = None,
189+
predicate: Callable[[dict[str, Any]], bool] | None = None,
190+
max_records: int = 0,
191+
) -> LogPage:
192+
"""Convenience wrapper returning a :class:`LogPage`."""
193+
return query_logs(
194+
LogQuery(
195+
days=days,
196+
predicate=predicate,
197+
max_records=max_records,
198+
directory=Path(directory) if directory is not None else None,
199+
)
200+
)

0 commit comments

Comments
 (0)