From ab056dba4708fe3306ec00c8f53c9184ffa29b10 Mon Sep 17 00:00:00 2001 From: teknium1 <127238744+teknium1@users.noreply.github.com> Date: Sun, 27 Sep 2026 23:37:51 -0700 Subject: [PATCH] fix(telemetry): feature_disabled skips migrations and ${VAR} templates, diffs outside caller locks (m22, m23, m24) m22: migrations ran save_config -> record_config_saved inside surfaced processes (`hermes config migrate`, console migrate, dashboard/TUI profile create), so e.g. v45 appending `connections` to platform_toolsets read as a user re-enabling a toolset. _persist_migration (the single migration write path) now wraps save_config in hermes_applied_write(), a ContextVar the hook honours. m23: the old side is the raw file (`memory_enabled: ${MEM_ON}`) and the new side the env-expanded config, so any unrelated save reported `disabled` once a day forever. A setting whose value on either side is an unexpanded `${...}` string is now skipped (its value is unknown to the diff). m24: dashboard handlers call save_config inside config_write_scope (_CONFIG_MUTATION_LOCK), and the diff (tools_config._get_platform_tools per platform) + record ran there. record_config_saved now runs only the cheap gate inline (surface, enabled, surface/home resolution) and hands deep copies to a non-daemon thread bound to the owning profile (non-daemon so a CLI command exiting right after its write still records). Test contract change: test_record_config_saved_needs_a_surface_and_collection and test_real_config_writes_report_the_move_away_from_default now join the recording thread before asserting (the record is asynchronous by design). Probes (review/signals/mine): p2_migration.py config|dashboard before: re_enabled toolset connections row; after: p4_envref_configset.py before: memory.memory_enabled disabled after an unrelated save; after: no row (config set curator.enabled false still records) p3_lock_v2.py (times config_transitions, try-acquires the web lock) before (p3_lock.py): record_config_saved 0.047s/0.004s, lock held=True after: diff 0.003-0.008s, lock held=False Tests test_migrations_and_env_templates_are_not_user_disables and test_diff_and_record_run_off_the_callers_lock_in_the_owning_profile are RED on base. --- hermes_cli/config.py | 8 ++- .../observability/shared_metrics_disabled.py | 53 +++++++++++++++-- .../hermes_cli/test_shared_metrics_signals.py | 57 +++++++++++++++++++ .../developer-guide/relay-shared-metrics.md | 2 +- 4 files changed, 111 insertions(+), 9 deletions(-) diff --git a/hermes_cli/config.py b/hermes_cli/config.py index f64c09f6ac..be49461862 100644 --- a/hermes_cli/config.py +++ b/hermes_cli/config.py @@ -1315,8 +1315,12 @@ def _persist_migration(config: Dict[str, Any]) -> None: """Persist a migrated config under THE migration write invariant: a migration may only persist values that DIFFER from the schema default, plus explicit removals/renames of user data. Every migration step MUST write through here (``save_config`` with default-stripping - ON, no ``merge_existing``) so the invariant cannot regress one migration at a time.""" - save_config(config) + ON, no ``merge_existing``) so the invariant cannot regress one migration at a time. A migration + is Hermes' own write, never a user turning a feature off.""" + from hermes_cli.observability.shared_metrics_disabled import hermes_applied_write + + with hermes_applied_write(): + save_config(config) def _prompt_and_save_env(name: str, info: Dict[str, Any], prompt: str, results: Dict[str, Any]) -> bool: diff --git a/hermes_cli/observability/shared_metrics_disabled.py b/hermes_cli/observability/shared_metrics_disabled.py index 36c2eab4e4..ae0fbf3690 100644 --- a/hermes_cli/observability/shared_metrics_disabled.py +++ b/hermes_cli/observability/shared_metrics_disabled.py @@ -9,15 +9,24 @@ each (kind, name, event) at most once per day. The surface is the entry point that is running: ``set_process_surface`` from the ``hermes`` command dispatch (``tools`` / ``config`` / ``skills`` / ``plugins`` / chat slash commands / the web server) and -the TUI gateway. A process with no surface (setup wizard, updates, migrations) records nothing: those -writes are Hermes applying choices, not a user turning something off. +the TUI gateway. A process with no surface (setup wizard, updates) records nothing, nor does a write +Hermes makes itself inside a surfaced process (migrations, under :func:`hermes_applied_write`): those +are Hermes applying choices, not a user turning something off. + +``save_config``'s callers may hold their own write lock (the dashboard's ``_CONFIG_MUTATION_LOCK``), so +the hook only runs the cheap gate inline; the diff and the record run on a thread bound to the owning +profile. """ from __future__ import annotations +import contextlib +import copy import functools import logging -from typing import Any, Iterable +import threading +from contextvars import ContextVar +from typing import Any, Iterable, Iterator logger = logging.getLogger(__name__) @@ -30,6 +39,7 @@ _COMMAND_SURFACES = { _SETTING_KINDS = {"memory": "memory", "curator": "curator", "compression": "compression"} _OFF = frozenset({"false", "off", "no", "0", "none", ""}) _process_surface: str | None = None +_hermes_write: ContextVar[bool] = ContextVar("hermes_feature_disabled_hermes_write", default=False) def set_process_surface(command: Any) -> None: @@ -125,7 +135,10 @@ def _on(value: Any) -> bool: def _setting_transitions(old: dict, new: dict) -> Iterable[tuple[str, str, str]]: for path in sorted(default_on_settings()): - before, after = _on(_get(old, path)), _on(_get(new, path)) + before, after = _get(old, path), _get(new, path) + if any(isinstance(value, str) and "${" in value for value in (before, after)): + continue # an unexpanded ``${VAR}`` template (the raw side): its value is unknown here + before, after = _on(before), _on(after) if before != after: yield _SETTING_KINDS.get(path.split(".", 1)[0], "setting"), path, "re_enabled" if after else "disabled" @@ -211,16 +224,44 @@ def _emit(transitions: Iterable[tuple[str, str, str]], surface: str) -> None: record_process_mark(FEATURE_DISABLED_MARK, {"event": event, "kind": kind, "name": name, "surface": surface}) +@contextlib.contextmanager +def hermes_applied_write() -> Iterator[None]: + """Config writes Hermes makes on its own (migrations) record nothing, whatever the surface.""" + token = _hermes_write.set(True) + try: + yield + finally: + _hermes_write.reset(token) + + +def _record(old: Any, new: Any, surface: str, home: str) -> None: + from hermes_constants import reset_hermes_home_override, set_hermes_home_override + + token = set_hermes_home_override(home) # a thread does not inherit the profile binding + try: + _emit(config_transitions(old, new), surface) + except Exception: + logger.debug("Feature-disabled not recorded", exc_info=True) + finally: + reset_hermes_home_override(token) + + def record_config_saved(old_raw: Any, new_config: Any) -> None: """``save_config``'s hook, after the write and outside its lock. Never raises.""" - if _process_surface is None: + if _process_surface is None or _hermes_write.get(): return try: + from hermes_constants import get_hermes_home + from .relay_shared_metrics import enabled if not enabled() or (surface := current_surface()) is None: return - _emit(config_transitions(old_raw, new_config), surface) + # Not a daemon: a CLI command that exits right after its write still records. + threading.Thread( + target=_record, args=(copy.deepcopy(old_raw), copy.deepcopy(new_config), surface, str(get_hermes_home())), + name="hermes-feature-disabled", + ).start() except Exception: logger.debug("Feature-disabled not recorded", exc_info=True) diff --git a/tests/hermes_cli/test_shared_metrics_signals.py b/tests/hermes_cli/test_shared_metrics_signals.py index 000c7038b8..1dcd12bf1a 100644 --- a/tests/hermes_cli/test_shared_metrics_signals.py +++ b/tests/hermes_cli/test_shared_metrics_signals.py @@ -331,6 +331,15 @@ def test_web_forms_count_only_a_new_provider_key_or_endpoint(marks, monkeypatch) from hermes_cli.observability import shared_metrics_disabled as disabled_metrics # noqa: E402 +def _settle_disabled() -> None: + """feature_disabled diffs and records off the writer's thread (outside any caller lock).""" + import threading + + for thread in threading.enumerate(): + if thread.name == "hermes-feature-disabled": + thread.join(10) + + def test_settings_skills_plugins_transitions_only_count_moves_from_and_back_to_default(): old = {"skills": {"disabled": ["my-private-skill"]}, "plugins": {"disabled": []}} new = { @@ -374,6 +383,7 @@ def test_record_config_saved_needs_a_surface_and_collection(marks, monkeypatch): assert marks.rows == [] marks.policy["on"] = True disabled_metrics.record_config_saved({}, {"memory": {"memory_enabled": False}}) + _settle_disabled() assert marks.rows == [(contract.FEATURE_DISABLED_MARK, { "event": "disabled", "kind": "memory", "name": "memory.memory_enabled", "surface": "cli_config"})] disabled_metrics.set_process_surface(None) @@ -399,11 +409,58 @@ def test_real_config_writes_report_the_move_away_from_default(marks, monkeypatch config = load_config() config.setdefault("memory", {})["memory_enabled"] = False save_config(config) + _settle_disabled() set_config_value("curator.enabled", "false") + _settle_disabled() rows = [(d["kind"], d["name"], d["event"]) for m, d in marks.rows if m == contract.FEATURE_DISABLED_MARK] assert rows == [("memory", "memory.memory_enabled", "disabled"), ("curator", "curator.enabled", "disabled")] +def test_migrations_and_env_templates_are_not_user_disables(marks, monkeypatch): + from hermes_cli.config import _persist_migration, load_config, save_config + + marks.home.mkdir(parents=True, exist_ok=True) + monkeypatch.setattr(disabled_metrics, "_process_surface", "cli_config") + config = load_config() + config.setdefault("memory", {})["memory_enabled"] = False + _persist_migration(config) # e.g. `hermes config migrate` / profile create in the dashboard + # A ``${VAR}`` template on the raw side vs its expanded value: nothing moved. + monkeypatch.setenv("MEM_ON", "false") + (marks.home / "config.yaml").write_text("compression:\n enabled: ${MEM_ON}\n") + config = load_config() + config.setdefault("display", {})["compact"] = True + save_config(config) + _settle_disabled() + assert [d for m, d in marks.rows if m == contract.FEATURE_DISABLED_MARK] == [] + + +def test_diff_and_record_run_off_the_callers_lock_in_the_owning_profile(marks, monkeypatch, tmp_path): + import threading + + from hermes_constants import get_hermes_home, reset_hermes_home_override, set_hermes_home_override + + monkeypatch.setattr(disabled_metrics, "_process_surface", "cli_config") + gate, seen = threading.Event(), [] + real = disabled_metrics.config_transitions + + def slow(old, new): + gate.wait(5) + seen.append(str(get_hermes_home())) + return real(old, new) + + monkeypatch.setattr(disabled_metrics, "config_transitions", slow) + token = set_hermes_home_override(str(tmp_path / "b")) + try: + with threading.Lock(): # the caller's write lock (the dashboard's _CONFIG_MUTATION_LOCK) + disabled_metrics.record_config_saved({}, {"memory": {"memory_enabled": False}}) + assert marks.rows == [] # returned without diffing + finally: + reset_hermes_home_override(token) + gate.set() + _settle_disabled() + assert seen == [str(tmp_path / "b")] and [m for m, _ in marks.rows] == [contract.FEATURE_DISABLED_MARK] + + def test_off_thread_setup_records_in_the_owning_profile(marks, tmp_path, monkeypatch): seen: list[str] = [] monkeypatch.setattr(relay_shared_metrics, "record_process_marks_saved", lambda rows: ( diff --git a/website/docs/developer-guide/relay-shared-metrics.md b/website/docs/developer-guide/relay-shared-metrics.md index 695829f183..a4d0d92a64 100644 --- a/website/docs/developer-guide/relay-shared-metrics.md +++ b/website/docs/developer-guide/relay-shared-metrics.md @@ -445,7 +445,7 @@ database and the count is not reported. | `hermes.tool_unavailable.count` | provider, model, tool name (shipped built-ins only) | Which toolsets should be on by default: the model called a tool Hermes ships that this session did not enable. Any other unknown name (plugin, MCP, hallucinated) stays a `model_tool_quality` `unknown_tool` issue only. A built-in the session enabled but deferred behind `tool_search` (reachable through `tool_call`) is not unavailable. Background reviews, delegated children and cron jobs, whose toolsets are narrowed on purpose, are excluded. | | `hermes.provider_setup.count` | provider (catalog name; custom endpoints read `custom`), surface (`cli_setup`, `cli_model`, `tui`, `desktop`, `dashboard`), event (`started`, `completed`, `failed`, `abandoned`), failure class (`auth`, `network`, `no_models`, `cancelled`, `other`; `none` unless failed) | Where connecting a provider breaks down. `started` counts once a provider is picked; the flow's end is recorded by the surface that ran it. In the CLI pickers Esc ends the flow `failed`/`cancelled`; Back (Left arrow) keeps it open, so picking the same provider again continues it (one `started`), while picking another provider or leaving the command ends it `cancelled`. A flow nobody finished leaves a local marker that the next setup start or Hermes start in the profile reports as `abandoned` (its process is gone, or it has been pending over an hour); an OAuth device code left to expire is also `abandoned`. A new or changed provider API key saved from a form (TUI/Desktop/dashboard) and a newly added custom endpoint start and complete in one action; clearing a key, re-saving the same key, editing an existing endpoint, ecosystem tokens (`GITHUB_TOKEN`, `GH_TOKEN`, `HF_TOKEN`) and keys a tool's settings panel also asks for (e.g. `GEMINI_API_KEY`, `XAI_API_KEY`, `DEEPINFRA_API_KEY`) are not counted from the generic key form. Never a key, token, base URL or error text. Leaving the provider picker before choosing one is not counted. | | `hermes.feature_adoption.count` | feature (`memory`, `skills_created`, `delegation`, `cron`, `gateway_platform`, `desktop`, `tui`, `mcp`, `plugins`, `browser`, `voice`, `kanban`, `projects`, `bot_mode`, `curator`), days since install (`same_day`, `1d_to_7d`, `7d_to_30d`, `30d_to_90d`, `gte_90d`, `unknown`) | How long after install each major feature is first really used. Once per feature per install, latched in the local database, derived from the counters above (a foreground memory write, a skill created at the user's request (not by Hermes' background review), a successful MCP/plugin/browser/TTS/kanban tool call, a Desktop/TUI/gateway task, a cron run, a manual curator run; the scheduled curator pass does not count) plus direct first-use reports for Bot Mode messages and project creation. The age is the owning profile's (its first session). | -| `hermes.feature_disabled.count` | kind (`toolset`, `skill`, `plugin`, `platform`, `setting`, `memory`, `curator`, `compression`), name, surface (`cli_tools`, `cli_config`, `cli_slash`, `tui`, `desktop`, `dashboard`), event (`disabled`, `re_enabled`) | What users turn off. Diffed at the config write itself: a default-on toolset removed, a skill or plugin added to its disabled list, a default-`true` setting set false (and each moved back). Names are public only when shipped — toolset key, bundled/catalog skill, bundled/catalog plugin (messaging-platform plugins report as `platform`), `DEFAULT_CONFIG` key path (never a value) — else `custom`. Uninstalling a catalog skill counts as `disabled`. Only user entry points record (`hermes tools` / `config` / `skills` / `plugins`, chat slash commands, TUI/Desktop, dashboard); setup and migrations do not. At most once per (kind, name, event) per day. | +| `hermes.feature_disabled.count` | kind (`toolset`, `skill`, `plugin`, `platform`, `setting`, `memory`, `curator`, `compression`), name, surface (`cli_tools`, `cli_config`, `cli_slash`, `tui`, `desktop`, `dashboard`), event (`disabled`, `re_enabled`) | What users turn off. Diffed at the config write itself: a default-on toolset removed, a skill or plugin added to its disabled list, a default-`true` setting set false (and each moved back). Names are public only when shipped — toolset key, bundled/catalog skill, bundled/catalog plugin (messaging-platform plugins report as `platform`), `DEFAULT_CONFIG` key path (never a value) — else `custom`. Uninstalling a catalog skill counts as `disabled`. Only user entry points record (`hermes tools` / `config` / `skills` / `plugins`, chat slash commands, TUI/Desktop, dashboard); setup and migrations do not, even when a migration runs inside one of them (`hermes config migrate`, a profile created from the dashboard). A setting whose value is a `${VAR}` template is not compared. The diff and the record run on a background thread after the write, outside every config lock. At most once per (kind, name, event) per day. | Local state is written under: