"""Credential-free tests for source-aware timing and usage evidence.""" from __future__ import annotations import json import os import tempfile import threading import time import unittest from decimal import Decimal from pathlib import Path from typing import Any import scripts.agent_benchmark.measurement as measurement_module from scripts.agent_benchmark.lifecycle import ( CLOCK_CALLER_REPORTED, CLOCK_HARNESS_MONOTONIC, CLOCK_NONE, EVENT_FIRST_OUTPUT, EVENT_SUBMITTED, METRIC_PREFIX, SOURCE_CALLER_OUTPUT, SOURCE_HARNESS, SOURCE_WORKSPACE_POLL, UNIT_NANOSECONDS, CaptureStream, InvocationResult, LifecycleMetricError, LifecycleEvent, ParsedMetric, count_metric, duration_metric, normalize_count, normalize_duration_ns, validate_metric, ) from scripts.agent_benchmark.measurement import ( MEASUREMENT_FILENAME, MeasurementError, WorkspaceWriteObservation, WorkspaceWriteObserver, WorkspaceScan, OBSERVER_MAX_ENTRIES, REASON_NOT_OBSERVED, REASON_OBSERVER_UNAVAILABLE, _scan_workspace, build_measurement, load_measurement, measurement_bytes, measurement_record, observation_record, observed, path_digest, publish_measurement, unavailable, ) def _event(kind: str, monotonic_ns: int, source: str = SOURCE_HARNESS) -> LifecycleEvent: return LifecycleEvent(kind, source, "", monotonic_ns, 0, "2026-08-11T00:00:00+00:00", "") def _capture(stream: str) -> CaptureStream: return CaptureStream(stream, "", 0, 0, False) def _result( metrics: tuple[ParsedMetric, ...] = (), *, events: tuple[LifecycleEvent, ...] | None = None, duration_ns: int = 5_000, terminal_reason: str = "success", ) -> InvocationResult: """Build one frozen lifecycle projection with matching metric events.""" if events is None: events = (_event(EVENT_SUBMITTED, 1_000), _event(EVENT_FIRST_OUTPUT, 2_000)) published = tuple( _event(METRIC_PREFIX + metric.name, 3_000, metric.source) for metric in metrics ) return InvocationResult( success=terminal_reason == "success", terminal_reason=terminal_reason, exit_code=0, signal=None, submitted=True, finish_then_idle_then_quiet=True, cleanup_complete=True, process_group_alive=False, events=events + published, stdout=_capture("stdout"), stderr=_capture("stderr"), journal_path="", result_path="", locator=None, spec_digest="sha256:" + "a" * 64, started_at="2026-08-11T00:00:00+00:00", ended_at="2026-08-11T00:00:01+00:00", duration_ns=duration_ns, metrics=metrics, ) def _observation() -> WorkspaceWriteObservation: """One frozen observer report used by the record-level tests.""" return WorkspaceWriteObservation( True, 4_000, 1_700_000_000_000_000_000, path_digest("out.txt"), 10_000_000, 3 ) class MetricContractTest(unittest.TestCase): def test_duration_decimals_normalize_losslessly_to_nanoseconds(self) -> None: for value, unit, expected in ( (12, "ms", 12_000_000), (12.5, "ms", 12_500_000), ("0.000001", "ms", 1), (Decimal("1.5"), "s", 1_500_000_000), (7, "us", 7_000), (0, "ms", 0), (9, "ns", 9), ): with self.subTest(value=value, unit=unit): self.assertEqual(normalize_duration_ns(value, unit), expected) def test_unrepresentable_and_non_numeric_durations_fail_closed(self) -> None: for value, unit in ( (0.0000001, "ms"), # 0.1 ns cannot be represented without invention (Decimal("0.5"), "ns"), (-1, "ms"), (True, "ms"), (float("inf"), "ms"), ("nan", "ms"), ("not-a-number", "ms"), (None, "ms"), (12, "minutes"), ): with self.subTest(value=value, unit=unit): with self.assertRaises(LifecycleMetricError): normalize_duration_ns(value, unit) def test_counts_admit_only_non_negative_integers(self) -> None: self.assertEqual(normalize_count(0), 0) self.assertEqual(normalize_count(41), 41) for value in (1.5, 2.0, True, -1, "3", None, Decimal("4")): with self.subTest(value=value): with self.assertRaises(LifecycleMetricError): normalize_count(value) def test_metric_vocabulary_clock_and_labels_are_closed(self) -> None: rejected = ( ParsedMetric("unknown_metric", 1, UNIT_NANOSECONDS, CLOCK_CALLER_REPORTED, SOURCE_CALLER_OUTPUT), ParsedMetric("total_duration", 1, "tokens", CLOCK_CALLER_REPORTED, SOURCE_CALLER_OUTPUT), ParsedMetric("total_duration", 1, UNIT_NANOSECONDS, CLOCK_NONE, SOURCE_CALLER_OUTPUT), ParsedMetric("input_tokens", 1, "tokens", CLOCK_CALLER_REPORTED, SOURCE_CALLER_OUTPUT), ParsedMetric("input_tokens", 1, "tokens", CLOCK_NONE, SOURCE_CALLER_OUTPUT, overlap=True), ParsedMetric("input_tokens", 1, "tokens", CLOCK_NONE, "invented_source"), ParsedMetric("input_tokens", -1, "tokens", CLOCK_NONE, SOURCE_CALLER_OUTPUT), ParsedMetric("input_tokens", 1, "tokens", CLOCK_NONE, SOURCE_CALLER_OUTPUT, model="two words"), ParsedMetric("input_tokens", 1, "tokens", CLOCK_NONE, SOURCE_CALLER_OUTPUT, call_id="sk-abcdefgh12345"), "metric:total_duration", ) for metric in rejected: with self.subTest(metric=metric): with self.assertRaises(LifecycleMetricError): validate_metric(metric) accepted = duration_metric( "tool_duration", 3, model="claude-sonnet", call_id="call-1", overlap=True ) self.assertEqual(accepted.value, 3_000_000) self.assertEqual(accepted.clock, CLOCK_CALLER_REPORTED) def test_observed_and_unavailable_projections_stay_distinct(self) -> None: self.assertEqual( observation_record(observed(7, UNIT_NANOSECONDS, CLOCK_HARNESS_MONOTONIC, SOURCE_HARNESS)), { "status": "observed", "value": 7, "unit": UNIT_NANOSECONDS, "clock": CLOCK_HARNESS_MONOTONIC, "source": SOURCE_HARNESS, }, ) # An unavailable value is explicitly null; it is never a zero. self.assertEqual( observation_record(unavailable("not_reported", SOURCE_CALLER_OUTPUT)), { "status": "unavailable", "value": None, "reason": "not_reported", "source": SOURCE_CALLER_OUTPUT, }, ) with self.assertRaises(MeasurementError): unavailable("because", SOURCE_HARNESS) with self.assertRaises(MeasurementError): observed(-1, UNIT_NANOSECONDS, CLOCK_HARNESS_MONOTONIC, SOURCE_HARNESS) class MeasurementRecordTest(unittest.TestCase): def _measurement(self, metrics: tuple[ParsedMetric, ...], **kwargs: Any): return build_measurement( run_id="run-20260811T000000Z-0123456789ab", cell_id="claude-direct", repetition=1, attempt=1, caller="claude", result=_result(metrics, **kwargs), observation=_observation(), ) def test_reported_totals_are_preserved_without_any_synthesis(self) -> None: metrics = ( duration_metric("total_duration", 1000, model="claude-sonnet"), duration_metric("model_duration", 400, model="claude-sonnet", overlap=True), count_metric("input_tokens", 11, model="claude-sonnet"), count_metric("output_tokens", 22, model="claude-sonnet"), ) usage = self._measurement(metrics).usage self.assertEqual(usage["total_duration"].value, 1_000_000_000) self.assertEqual(usage["model_duration"].value, 400_000_000) self.assertEqual(usage["input_tokens"].value, 11) # Nothing is added and nothing is subtracted: the unreported provider # total and the unreported queue time both stay unavailable. for name in ("total_tokens", "queue_duration", "tool_duration", "model_calls"): self.assertEqual(usage[name].status, "unavailable") self.assertIsNone(usage[name].value) self.assertEqual(usage[name].reason, "not_reported") def test_overlapping_and_labelled_intervals_never_become_totals(self) -> None: metrics = ( duration_metric("tool_duration", 30, call_id="call-1", overlap=True), duration_metric("tool_duration", 70, call_id="call-2", overlap=True), ) measurement = self._measurement(metrics) self.assertEqual(measurement.usage["tool_duration"].status, "unavailable") self.assertEqual( [(item.call_id, item.value, item.overlap) for item in measurement.observations], [("call-1", 30_000_000, True), ("call-2", 70_000_000, True)], ) def test_duplicate_total_fails_closed(self) -> None: metrics = ( duration_metric("total_duration", 10, model="claude-sonnet"), duration_metric("total_duration", 20, model="claude-sonnet"), ) with self.assertRaises(MeasurementError): self._measurement(metrics) def test_two_model_totals_stay_ambiguous_instead_of_merging(self) -> None: metrics = ( duration_metric("total_duration", 10, model="claude-sonnet"), duration_metric("total_duration", 20, model="gemini-2.0-flash"), ) measurement = self._measurement(metrics) self.assertEqual(measurement.usage["total_duration"].status, "unavailable") self.assertEqual(measurement.usage["total_duration"].reason, "ambiguous_total") self.assertEqual( [(item.model, item.value) for item in measurement.observations], [("claude-sonnet", 10_000_000), ("gemini-2.0-flash", 20_000_000)], ) def test_timeline_keeps_every_clock_domain_separate(self) -> None: measurement = self._measurement(()) timeline = measurement.timeline self.assertEqual(timeline["submitted_at"].value, 1_000) self.assertEqual(timeline["submitted_at"].clock, CLOCK_HARNESS_MONOTONIC) self.assertEqual(timeline["first_output_at"].value, 2_000) self.assertEqual(timeline["first_output_at"].source, SOURCE_HARNESS) # The observer's own clock and the filesystem clock are reported as two # separate values, so nothing can subtract one from the other. self.assertEqual(timeline["first_write_observed_at"].clock, CLOCK_HARNESS_MONOTONIC) self.assertEqual(timeline["first_write_observed_at"].source, SOURCE_WORKSPACE_POLL) self.assertEqual(timeline["first_write_mtime"].clock, "filesystem_mtime") self.assertEqual(timeline["total_duration"].value, 5_000) def test_missing_first_output_is_unavailable_rather_than_zero(self) -> None: measurement = self._measurement((), events=(_event(EVENT_SUBMITTED, 1_000),)) self.assertEqual(measurement.timeline["first_output_at"].status, "unavailable") self.assertIsNone(measurement.timeline["first_output_at"].value) self.assertEqual(measurement.timeline["first_output_at"].reason, "not_observed") def test_incomplete_identity_is_refused_before_any_publication(self) -> None: base = { "run_id": "run-20260811T000000Z-0123456789ab", "cell_id": "claude-direct", "repetition": 1, "attempt": 1, "caller": "claude", "result": _result(), "observation": _observation(), } for override in ( {"run_id": ""}, {"cell_id": None}, {"caller": ""}, {"repetition": 0}, {"attempt": True}, {"result": _result(terminal_reason="")}, {"observation": None}, ): with self.subTest(override=tuple(override)): with self.assertRaises(MeasurementError): build_measurement(**{**base, **override}) def test_observation_set_must_match_published_events(self) -> None: result = _result((count_metric("input_tokens", 1),)) forged = ParsedMetric("output_tokens", 5, "tokens", CLOCK_NONE, SOURCE_CALLER_OUTPUT) with self.assertRaises(MeasurementError): build_measurement( run_id="run-20260811T000000Z-0123456789ab", cell_id="c", repetition=1, attempt=1, caller="claude", result=InvocationResult(**{**result.__dict__, "metrics": (*result.metrics, forged)}), observation=_observation(), ) class WorkspaceObserverTest(unittest.TestCase): def setUp(self) -> None: self.temp = tempfile.TemporaryDirectory(dir="/tmp", prefix="measurement-") self.root = Path(self.temp.name) self.workspace = self.root / "workspace" self.workspace.mkdir() def tearDown(self) -> None: self.temp.cleanup() def _write(self, name: str, text: str) -> Path: path = self.workspace / name path.write_text(text, encoding="utf-8") return path @staticmethod def _wait_observed(observer: WorkspaceWriteObserver) -> None: deadline = time.monotonic() + 10 while observer._first is None and time.monotonic() < deadline: time.sleep(0.005) def test_first_observed_write_is_reported_with_clock_source_and_precision(self) -> None: observer = WorkspaceWriteObserver( self.workspace, interval_seconds=0.005, ) observer.start() self._write("out.txt", "x") self._wait_observed(observer) observation = observer.stop() self.assertTrue(observer.stopped) self.assertTrue(observation.observed) self.assertEqual(observation.path_digest, path_digest("out.txt")) self.assertEqual(observation.precision_ns, 5_000_000) self.assertGreaterEqual(observation.samples, 2) self.assertEqual( observation.mtime_ns, (self.workspace / "out.txt").stat().st_mtime_ns ) def test_first_observed_order_survives_a_later_final_mtime(self) -> None: observer = WorkspaceWriteObserver( self.workspace, interval_seconds=0.005, ) observer.start() self._write("b.txt", "1") self._wait_observed(observer) observation = observer.stop() # After the observation is frozen, a second file is created and the # first file is rewritten, so the final snapshot now orders a.txt # before b.txt. The observer still reports the write it actually saw. later = self._write("a.txt", "2") os.utime(later, ns=(2_000_000_000_000_000_000, 2_000_000_000_000_000_000)) rewritten = self._write("b.txt", "3") os.utime(rewritten, ns=(3_000_000_000_000_000_000, 3_000_000_000_000_000_000)) snapshot = sorted( (item.stat().st_mtime_ns, item.name) for item in self.workspace.iterdir() ) self.assertEqual(snapshot[0][1], "a.txt") self.assertEqual(observation.path_digest, path_digest("b.txt")) def test_exhausted_scan_is_unavailable_and_never_compared(self) -> None: for index in range(OBSERVER_MAX_ENTRIES + 1): (self.workspace / f"empty-{index:04d}").mkdir() baseline = _scan_workspace(self.workspace) self.assertEqual(baseline.status, "exhausted") self.assertLessEqual(len(baseline.files), OBSERVER_MAX_ENTRIES) observer = WorkspaceWriteObserver(self.workspace, interval_seconds=0.005) observer.start() observation = observer.stop() self.assertFalse(observation.observed) self.assertEqual(observation.reason, REASON_OBSERVER_UNAVAILABLE) self.assertTrue(observer.stopped) def test_detection_clock_runs_after_the_complete_scan(self) -> None: order: list[str] = [] observer = WorkspaceWriteObserver( self.workspace, interval_seconds=0.005, clock=lambda: (order.append("clock") or 123), ) observer._baseline = {} original = _scan_workspace def scan(_root: Path) -> WorkspaceScan: order.append("scan") return WorkspaceScan({"out.txt": (1, 1, 1)}, "complete") try: import scripts.agent_benchmark.measurement as measurement_module measurement_module._scan_workspace = scan self.assertTrue(observer._sample_once()) finally: measurement_module._scan_workspace = original self.assertEqual(order, ["scan", "clock"]) def test_symlink_and_non_regular_entries_are_never_observed(self) -> None: outside = self.root / "outside.txt" outside.write_text("outside", encoding="utf-8") os.symlink(outside, self.workspace / "link.txt") os.mkfifo(self.workspace / "pipe") observer = WorkspaceWriteObserver(self.workspace, interval_seconds=0.005) observer.start() outside.write_text("changed outside", encoding="utf-8") observation = observer.stop() self.assertFalse(observation.observed) self.assertEqual(observation.path_digest, "") def test_no_write_is_unavailable_and_leaves_no_thread(self) -> None: before = set(threading.enumerate()) observer = WorkspaceWriteObserver(self.workspace, interval_seconds=0.005) observer.start() observation = observer.stop() self.assertFalse(observation.observed) self.assertIsNone(observation.monotonic_ns) self.assertTrue(observer.stopped) self.assertEqual(set(threading.enumerate()) - before, set()) with self.assertRaises(MeasurementError): observer.start() def test_stop_closes_the_final_interval_with_one_scan_after_sampler_exit(self) -> None: calls: list[str] = [] sampled = threading.Event() snapshots = iter(( WorkspaceScan({}, "complete"), WorkspaceScan({}, "complete"), WorkspaceScan({"out.txt": (1, 1, 1)}, "complete"), )) original = measurement_module._scan_workspace def scan(_root: Path) -> WorkspaceScan: calls.append("scan") result = next(snapshots) if len(calls) == 2: sampled.set() return result try: measurement_module._scan_workspace = scan observer = WorkspaceWriteObserver( self.workspace, interval_seconds=60, clock=lambda: (calls.append("clock") or 123), ) observer.start() self.assertTrue(sampled.wait(5)) observation = observer.stop() finally: measurement_module._scan_workspace = original self.assertTrue(observer.stopped) self.assertTrue(observation.observed) self.assertEqual(observation.samples, 2) self.assertEqual(calls, ["scan", "scan", "scan", "clock"]) def test_final_exhausted_scan_is_unavailable_and_thread_is_cleaned_up(self) -> None: sampled = threading.Event() calls = 0 snapshots = iter(( WorkspaceScan({}, "complete"), WorkspaceScan({}, "complete"), WorkspaceScan({}, "exhausted"), )) original = measurement_module._scan_workspace def scan(_root: Path) -> WorkspaceScan: nonlocal calls calls += 1 result = next(snapshots) if calls == 2: sampled.set() return result try: measurement_module._scan_workspace = scan observer = WorkspaceWriteObserver(self.workspace, interval_seconds=60) observer.start() self.assertTrue(sampled.wait(5)) observation = observer.stop() finally: measurement_module._scan_workspace = original self.assertTrue(observer.stopped) self.assertFalse(observation.observed) self.assertEqual(observation.reason, REASON_OBSERVER_UNAVAILABLE) self.assertEqual(observation.samples, 2) self.assertEqual(calls, 3) def test_successful_stop_is_idempotent_and_excludes_post_stop_writes(self) -> None: sampled = threading.Event() calls = 0 original = measurement_module._scan_workspace def scan(root: Path) -> WorkspaceScan: nonlocal calls calls += 1 result = original(root) # Signal once the background sampler has completed its own empty # scan so the main thread stops a started, no-write observer. if calls == 2: sampled.set() return result try: measurement_module._scan_workspace = scan observer = WorkspaceWriteObserver(self.workspace, interval_seconds=60) observer.start() self.assertTrue(sampled.wait(5)) first = observer.stop() self._write("post-stop.txt", "after shutdown") second = observer.stop() finally: measurement_module._scan_workspace = original self.assertTrue(observer.stopped) self.assertIs(second, first) self.assertFalse(first.observed) self.assertEqual(first.reason, REASON_NOT_OBSERVED) self.assertEqual(second.samples, first.samples) # Baseline, the background sampler's empty scan, and the one final scan # account for every scan; the cached second stop performs no fourth scan. self.assertEqual(calls, 3) self.assertIsNone(observer._thread) def test_observer_requires_a_real_directory_and_positive_interval(self) -> None: with self.assertRaises(MeasurementError): WorkspaceWriteObserver(self.workspace, interval_seconds=0) with self.assertRaises(MeasurementError): WorkspaceWriteObserver(self.root / "missing").start() os.symlink(self.workspace, self.root / "alias") with self.assertRaises(MeasurementError): WorkspaceWriteObserver(self.root / "alias").start() class MeasurementSidecarTest(unittest.TestCase): def setUp(self) -> None: self.temp = tempfile.TemporaryDirectory(dir="/tmp", prefix="measurement-") self.root = Path(self.temp.name) self.measurement = build_measurement( run_id="run-20260811T000000Z-0123456789ab", cell_id="claude-direct", repetition=1, attempt=1, caller="claude", result=_result(( duration_metric("total_duration", 1000, model="claude-sonnet"), count_metric("input_tokens", 11, model="claude-sonnet"), )), observation=_observation(), ) def tearDown(self) -> None: self.temp.cleanup() def test_publish_then_load_round_trips_every_closed_field(self) -> None: path = publish_measurement(self.root, self.measurement) self.assertEqual(path.name, MEASUREMENT_FILENAME) loaded = load_measurement(self.root) self.assertEqual(measurement_record(loaded), measurement_record(self.measurement)) self.assertEqual(loaded.caller, "claude") self.assertEqual(loaded.usage["input_tokens"].value, 11) self.assertEqual(loaded.observations[0].name, "total_duration") self.assertEqual(loaded.observer.path_digest, path_digest("out.txt")) self.assertEqual(path.stat().st_mode & 0o777, 0o600) def test_publication_is_no_clobber_and_preserves_prior_bytes(self) -> None: prior = b'{"record":"prior"}\n' (self.root / MEASUREMENT_FILENAME).write_bytes(prior) with self.assertRaises(MeasurementError): publish_measurement(self.root, self.measurement) self.assertEqual((self.root / MEASUREMENT_FILENAME).read_bytes(), prior) def test_tampered_and_non_canonical_records_fail_closed(self) -> None: record = measurement_record(self.measurement) cases = { "unknown-field": {**record, "extra": 1}, "wrong-version": {**record, "measurement_version": 2}, "forged-digest": {**record, "spec_digest": "sha256:not-a-digest"}, "zeroed-unavailable": { **record, "usage": { **record["usage"], "total_tokens": { "status": "unavailable", "value": 0, "reason": "not_reported", "source": "harness", }, }, }, "invented-clock": { **record, "timeline": { **record["timeline"], "submitted_at": { **record["timeline"]["submitted_at"], "clock": "wall_clock", }, }, }, "non-temporal-instant": { **record, "timeline": { **record["timeline"], "submitted_at": { **record["timeline"]["submitted_at"], "clock": "none", }, }, }, "wrong-timeline-source": { **record, "timeline": { **record["timeline"], "first_write_observed_at": { **record["timeline"]["first_write_observed_at"], "source": SOURCE_HARNESS, }, }, }, "invented-usage-total": { **record, "usage": { **record["usage"], "total_tokens": { "status": "observed", "value": 11, "unit": "tokens", "clock": "none", "source": "caller_output", }, }, }, "observer-contradiction": { **record, "observer": { **record["observer"], "status": "unavailable", "path_digest": "", }, }, "unbound-observation": { **record, "observations": [ {**record["observations"][0], "name": "unknown_metric"} ], }, } for name, payload in cases.items(): with self.subTest(name=name): target = self.root / name target.mkdir() (target / MEASUREMENT_FILENAME).write_bytes( json.dumps(payload, sort_keys=True, separators=(",", ":")).encode() + b"\n" ) with self.assertRaises(MeasurementError): load_measurement(target) def test_reordered_bytes_are_rejected_as_non_canonical(self) -> None: (self.root / MEASUREMENT_FILENAME).write_bytes( json.dumps(measurement_record(self.measurement), indent=2).encode() + b"\n" ) with self.assertRaises(MeasurementError): load_measurement(self.root) def test_missing_symlinked_and_non_regular_sidecars_fail_closed(self) -> None: with self.assertRaises(MeasurementError): load_measurement(self.root) publish_measurement(self.root, self.measurement) aliased = self.root / "aliased" aliased.mkdir() os.symlink(self.root / MEASUREMENT_FILENAME, aliased / MEASUREMENT_FILENAME) with self.assertRaises(MeasurementError): load_measurement(aliased) piped = self.root / "piped" piped.mkdir() os.mkfifo(piped / MEASUREMENT_FILENAME) with self.assertRaises(MeasurementError): load_measurement(piped) def test_canonical_bytes_are_stable_and_ascii(self) -> None: first = measurement_bytes(self.measurement) self.assertEqual(first, measurement_bytes(self.measurement)) first.decode("ascii") self.assertTrue(first.endswith(b"\n")) if __name__ == "__main__": unittest.main()