diff --git a/docs/observability/relay-shared-metrics.md b/docs/observability/relay-shared-metrics.md index b538011675..cb3ea2197a 100644 --- a/docs/observability/relay-shared-metrics.md +++ b/docs/observability/relay-shared-metrics.md @@ -403,12 +403,23 @@ Turning sending off also **closes the consent window** — at the last moment consent was actually observed, not at the wall clock. Packages whose periods fall between one window and the next are never transmitted, even if sending is later re-enabled, and this holds for any number of on/off cycles, across -hand-edits with no process running, and under a clock that jumps backwards -(window opens are clamped above every timestamp already in the store). +hand-edits with no process running, and under a clock that jumps in either +direction (window opens are clamped above every timestamp already in the +store; observation marks advance by a bounded step per call, so one glitched +forward sample cannot drag the confirmation horizon years ahead; a close +never lands after the closing observation's own clock). Unlike the earlier single moving opt-in date, closing and reopening does NOT discard the still-undelivered backlog from a previous consented window — those packages stay inside their own interval and remain eligible. +One deliberate upgrade-path consequence: packages exported under the +pre-interval consent model (before `send_consent_windows` existed) predate +the first recorded window and are therefore never transmitted after an +upgrade. This is the fail-closed direction — re-importing the old moving +day-stamp to release them would re-import the semantics five review rounds +showed to be unsound — and it costs at most the undelivered backlog, never +collected data. + ### A.5 Retention - **Local:** unchanged — 30 days for successfully exported history, and pending diff --git a/hermes_cli/observability/relay_shared_metrics.py b/hermes_cli/observability/relay_shared_metrics.py index 978497945d..5a97c8a18d 100644 --- a/hermes_cli/observability/relay_shared_metrics.py +++ b/hermes_cli/observability/relay_shared_metrics.py @@ -1256,11 +1256,19 @@ def _reconcile_send_consent_once() -> None: reconcile_send_consent, ) from hermes_cli.sqlite_util import write_txn + from hermes_constants import get_hermes_home resolved = resolve_send_config(read_raw_config_readonly() or {}) - store = SharedMetricsStore() - if not resolved.send and not store.database_path.exists(): + # Probe for an existing store WITHOUT constructing one: the + # constructor creates the directory and schema as a side effect, + # which round 6 caught making this skip dead code — every + # fully-disabled user was getting a ~/.hermes/telemetry directory. + default_path = ( + get_hermes_home() / "telemetry" / "shared_metrics" / "metrics.sqlite3" + ) + if not resolved.send and not default_path.exists(): return + store = SharedMetricsStore() with store._connection() as connection: with write_txn(connection): reconcile_send_consent(connection, resolved.send) diff --git a/hermes_cli/observability/shared_metrics_sender.py b/hermes_cli/observability/shared_metrics_sender.py index 389611ed37..8a01a44790 100644 --- a/hermes_cli/observability/shared_metrics_sender.py +++ b/hermes_cli/observability/shared_metrics_sender.py @@ -100,6 +100,13 @@ def _isoformat(value: datetime) -> str: return value.astimezone(timezone.utc).isoformat().replace("+00:00", "Z") +def _parse_stamp(value: str) -> datetime: + """Parse a stamp this module itself wrote (Z-suffixed ISO-8601, UTC).""" + return datetime.fromisoformat(value.replace("Z", "+00:00")).astimezone( + timezone.utc + ) + + @dataclass class SendOutcome: """What one pass did. Returned for tests and diagnostics.""" @@ -164,6 +171,18 @@ def _retry_after_seconds(value: str | None, default: int) -> int: return default +#: Maximum distance one reconcile call can advance the 'obs' mark. Honest +#: heartbeats arrive hours apart at most, so the cap never binds in normal +#: operation; a machine legitimately off for months catches up in a few +#: hook fires (fail-closed latency only). What it bounds is FORWARD clock +#: poison: without it, a single glitched sample (NTP flap reading 2099) +#: permanently drags the mark — and with it every window open and every +#: confirmation horizon — decades ahead, which round 6 reproduced as a +#: refused-data leak. Capped, one insane sample moves the mark at most +#: this far, and real time overtakes it again. +MAX_OBS_ADVANCE_SECONDS = 30 * 24 * 3600 + + def reconcile_send_consent( connection: sqlite3.Connection, send_enabled: bool, @@ -182,9 +201,15 @@ def reconcile_send_consent( Timestamp discipline (each rule is load-bearing; see the validation harness in tests/hermes_cli/test_shared_metrics_consent_windows.py): - - The 'obs' mark advances to every observation stamp, monotonically. - An open window's ``last_confirmed_at`` follows it: consent is asserted - only for time that was actually observed. + - The 'obs' mark advances to every observation stamp, monotonically — + but by at most ``MAX_OBS_ADVANCE_SECONDS`` per call. Unbounded, the + mark is monotonic in the LEAK direction: one glitched-forward sample + would drag ``last_confirmed_at`` decades ahead, a later close would + stamp that horizon, and the closed window would contain every future + refused period (reproduced in round 6). Bounded, a poisoned sample + costs at most one cap's width, and real time overtakes it. + An open window's ``last_confirmed_at`` follows the mark: consent is + asserted only for time that was actually observed. - A close is stamped at ``last_confirmed_at`` — never "now" — so an unobserved gap (hand-edited config, machine off for 90 days) is never inside a window and fails closed. @@ -193,6 +218,16 @@ def reconcile_send_consent( make the new window adjacent to the previous close. """ stamp = _isoformat(now or _utc_now()) + raw_stamp = stamp # pre-cap observation time, used to clamp closes + previous_obs = connection.execute( + "SELECT stamp FROM consent_marks WHERE name = 'obs'" + ).fetchone() + if previous_obs is not None: + ceiling = _isoformat( + _parse_stamp(str(previous_obs[0])) + + timedelta(seconds=MAX_OBS_ADVANCE_SECONDS) + ) + stamp = min(stamp, ceiling) connection.execute( """ INSERT INTO consent_marks(name, stamp) VALUES ('obs', ?) @@ -226,10 +261,22 @@ def reconcile_send_consent( (obs, open_row[0]), ) elif open_row is not None: + # Close at the last CONFIRMED moment, but never after the closing + # observation's own raw stamp. The two clamps serve different + # adversaries and both are load-bearing: + # - min with last_confirmed_at: an unobserved gap (machine off, + # hand-edited config) is never asserted as consented (v1's leak). + # - min with the RAW stamp (pre-cap, pre-MAX): if last_confirmed_at + # was poisoned by a glitched-forward sample, an honest clock at + # revoke time pulls the close back to the true revoke moment, so + # the refused era that follows falls OUTSIDE the closed window + # (round 6's D1 leak). A rolled-back clock at close time only + # closes EARLIER — fail-closed. connection.execute( - "UPDATE send_consent_windows SET closed_at = last_confirmed_at" + "UPDATE send_consent_windows" + " SET closed_at = MIN(last_confirmed_at, ?)" " WHERE rowid = ?", - (open_row[0],), + (raw_stamp, open_row[0]), ) diff --git a/tests/hermes_cli/test_shared_metrics_consent_windows.py b/tests/hermes_cli/test_shared_metrics_consent_windows.py index 83da1a4749..66b58d5dd3 100644 --- a/tests/hermes_cli/test_shared_metrics_consent_windows.py +++ b/tests/hermes_cli/test_shared_metrics_consent_windows.py @@ -131,6 +131,62 @@ class TestRefusedWindowIsNeverReleased: class TestClockAdversaries: + def test_forward_poison_then_revoke_releases_nothing(self, store): + """Round 6 D1: one glitched-forward sample must not defeat a close. + + Unfixed, the poisoned obs mark dragged last_confirmed_at to 2099, a + later revoke stamped closed_at = 2099, and the closed window then + CONTAINED every refused period that followed — all 8 refused + packages became eligible. The close now clamps to the closing + observation's own raw stamp, so an honest clock at revoke time pulls + the window back to the true revoke moment. + """ + _observe(store, True, dt(0)) + _observe(store, True, datetime(2099, 1, 1, tzinfo=timezone.utc)) + _observe(store, False, dt(1)) # honest clock at revoke + for n in range(2, 10): + _add(store, f"REFUSED-{n}", ts(days=n), ts(days=n, hours=2)) + + leaked = [p for p in _eligible(store) if p.startswith("REFUSED")] + assert not leaked, f"poisoned horizon released refused data: {leaked}" + + def test_forward_poison_cannot_wedge_consent_forever(self, store): + """The obs-advance cap bounds the damage of one insane sample. + + Uncapped, a 2099 sample would clamp every future window open at + 2099, suppressing consented data for decades (fail-closed but + permanent). Capped, the mark moves at most MAX_OBS_ADVANCE_SECONDS + past its previous value, so honest time overtakes it. + """ + from hermes_cli.observability.shared_metrics_sender import ( + MAX_OBS_ADVANCE_SECONDS, + ) + + _observe(store, True, dt(0)) + _observe(store, True, datetime(2099, 1, 1, tzinfo=timezone.utc)) + with store._connection() as connection: + stamp = connection.execute( + "SELECT stamp FROM consent_marks WHERE name = 'obs'" + ).fetchone()[0] + ceiling = ts(days=MAX_OBS_ADVANCE_SECONDS // 86_400) + assert stamp <= ceiling, ( + f"one glitched sample advanced the mark unboundedly: {stamp}" + ) + + # Consented data from shortly after the cap horizon still flows once + # honest observations catch the marks up. + horizon_days = MAX_OBS_ADVANCE_SECONDS // 86_400 + _add( + store, + "post-glitch", + ts(days=horizon_days + 1), + ts(days=horizon_days + 1, hours=4), + ) + _observe(store, True, dt(days=horizon_days + 2)) + assert "post-glitch" in _eligible(store), ( + "consent wedged after a forward glitch" + ) + def test_rollback_at_re_enable_releases_nothing(self, store): """Round 5 D2: the data mark clamps opens above existing packages.""" _observe(store, True, dt(0)) @@ -201,6 +257,39 @@ class TestReconcilerProperties: ).fetchone()[0] assert stamp == ts(5), f"obs mark moved backwards: {stamp}" + def test_the_real_package_writer_advances_the_data_mark(self, store): + """Round 6 D2: the harness's _add re-implements the data-mark insert, + so deleting the advance from the REAL writer survived 314 tests. + This drives the production exporter instead. + """ + from datetime import date, timedelta as _td + + yesterday = (date.today() - _td(days=1)).isoformat() + with store._connection() as connection: + with write_txn(connection): + connection.execute( + "INSERT INTO counter_aggregates(" + " period_start, metric_name, hermes_version, os_family," + " architecture, install_method, dimensions_json, value," + " packaged_value" + ") VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?)", + ( + yesterday, "hermes.client.active", "0.0.0-test", + "macos", "arm64", "git", "{}", 1, 0, + ), + ) + + exported = store.create_and_export_package_if_due() + assert exported, "the generator was expected to export yesterday's period" + + with store._connection() as connection: + row = connection.execute( + "SELECT stamp FROM consent_marks WHERE name = 'data'" + ).fetchone() + assert row is not None and row[0] >= yesterday, ( + "the production package writer did not advance the data mark" + ) + def test_the_gate_is_read_only(self, store): _observe(store, True, dt(0)) before = _windows(store) diff --git a/tests/hermes_cli/test_shared_metrics_send_wiring.py b/tests/hermes_cli/test_shared_metrics_send_wiring.py index 8ed7724b1e..29f572c697 100644 --- a/tests/hermes_cli/test_shared_metrics_send_wiring.py +++ b/tests/hermes_cli/test_shared_metrics_send_wiring.py @@ -315,8 +315,18 @@ class TestConsentWindows: ) from hermes_cli.sqlite_util import write_txn + # Lay the store out exactly as production does, under a redirected + # HERMES_HOME: the boot reconciler probes the default path (without + # constructing the store — the constructor creates directories), so + # the probe and the store must agree the way they do in production. + home = tmp_path / "home" + monkeypatch.setattr( + "hermes_constants.get_hermes_home", lambda: home + ) + root = home / "telemetry" / "shared_metrics" store = SharedMetricsStore( - database_path=tmp_path / "m.db", outbox_directory=tmp_path / "o" + database_path=root / "metrics.sqlite3", + outbox_directory=root / "outbox", ) # A consent window is open from an earlier consented era. with store._connection() as connection: