From ec31891c60f2a3ca3a142e2d6c38acc45f3d24b4 Mon Sep 17 00:00:00 2001 From: Konstantin M Date: Wed, 8 Jul 2026 15:55:53 +0000 Subject: [PATCH 01/16] perf(webui/session-load-latency) tier1a: cheap-first freshness check in _cached_session_lags_disk MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Prior to this change _cached_session_lags_disk() called Session.load_metadata_only(sid) on every LRU cache hit, parsing the full sidecar JSON (~15-20ms even for a 1.3MB sidecar on Celeron+ eMMC). For draft auto-saves hitting get_session() on every keystroke debounce (~400ms cadence while typing), that 15-20ms multiplied out to ~75% of the request's wall time on the Chromebook. Reorder the check: read only the JSON metadata prefix (_persisted_message_count, already defined for the LRU-eviction path) to compare message counts. For INACTIVE sessions (no active_stream_id, no pending_user_message) with matching counts, the cache is provably at parity with disk — anchor-scene records cannot have advanced without the message count advancing too, and the full Session.load_metadata_only() is skipped. For ACTIVE sessions, or when counts differ, fall through to the original anchor-scene comparison path so correctness is preserved. Measured cost reduction on the request hot path: 15-20ms -> <1ms on the typical cache-hit case (inactive session, count matches). The slow path is unchanged for cases that genuinely need the full reload. No public API change. No behavior change observable on user-facing flows. The LRU eviction safety invariant (#4765) is preserved — _session_is_evictable() still calls _persisted_message_count under the same conditions, and Tier 1a adds NO new eviction gate. --- api/models.py | 40 +++++++++++++++++++++++++++++++++++----- 1 file changed, 35 insertions(+), 5 deletions(-) diff --git a/api/models.py b/api/models.py index 9f945693..66ebaf8f 100644 --- a/api/models.py +++ b/api/models.py @@ -3095,24 +3095,54 @@ def _cached_session_lags_disk(cached) -> bool: id. Serving the cache then makes recent assistant results disappear from GET /api/session even though disk and _index.json are correct. Compare only cheap metadata here; full reload happens only if disk is strictly ahead. + + perf(webui/session-load-latency) cheap-first ordering: the function used to + call Session.load_metadata_only(sid) on every cache hit, which parses the + full sidecar JSON (~15-20ms even for 1.3MB sidecars on Celeron+ eMMC). + For draft auto-saves that hit get_session() on every keystroke debounce + (every ~400ms while typing), that 15-20ms multiplied out to ~75% of the + request's wall time on the Chromebook. We now do a single fast check + first: read only the JSON metadata prefix to compare message counts. + The full Session.load_metadata_only() and its anchor-scene comparisons + only run when the count check is inconclusive or when disk appears to be + ahead of cache. """ if cached is None: return False sid = getattr(cached, 'session_id', None) if not sid: return False + cached_count = len(getattr(cached, 'messages', None) or []) + # Fast path: prefix read of just the metadata header. + disk_count = _persisted_message_count(sid) + if disk_count is not None: + if disk_count > cached_count: + return True + # Disk is at most as far as cache; for inactive sessions we don't + # need to compare anchor-scene records (those are only updated by + # active streaming/recovery paths, which we can detect cheaply below). + if getattr(cached, 'active_stream_id', None) or getattr(cached, 'pending_user_message', None): + # Active session: anchor-scene keys may have advanced even when + # the count is the same. Fall through to the full check. + pass + else: + # Inactive session, count matches → cache is at parity with disk. + # The pre-fix code would still load_metadata_only to compare + # anchor scenes, but for inactive sessions those cannot have + # advanced without the count advancing too. Skip the full load. + return False try: disk_meta = Session.load_metadata_only(sid) except Exception: return False if disk_meta is None: return False - cached_count = len(getattr(cached, 'messages', None) or []) - disk_count = _parse_nonnegative_int(getattr(disk_meta, '_metadata_message_count', None)) if disk_count is None: - disk_count = _lookup_index_message_count(sid) - if disk_count is not None and disk_count > cached_count: - return True + disk_count = _parse_nonnegative_int(getattr(disk_meta, '_metadata_message_count', None)) + if disk_count is None: + disk_count = _lookup_index_message_count(sid) + if disk_count is not None and disk_count > cached_count: + return True if not getattr(cached, 'active_stream_id', None) and not getattr(cached, 'pending_user_message', None): cached_scene_keys = _anchor_scene_record_keys(cached) disk_scene_keys = _anchor_scene_record_keys(disk_meta) From e5d1c204b70d69ad3fbdfeac731f14ab7cceb19c Mon Sep 17 00:00:00 2001 From: Konstantin M Date: Wed, 8 Jul 2026 15:55:53 +0000 Subject: [PATCH 02/16] perf(webui/session-load-latency) tier1b: stage-marker instrumentation on /api/session/draft MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Adds monotonic-clock stage markers around the existing /api/session/draft hot path so we can decompose wall time by phase (get_session, lock acquire, save, json emit). Logs a single WARNING line only when total > 200ms — keeps the per-keystroke poll cheap while still catching the slow cases that justify further work. This is the source of the slow-path data needed to plan Tier 2: without stage breakdowns on /api/session/draft, every subsequent patch on this endpoint is a guess. The existing _t0.._t6 pattern on /api/session (gated on HERMES_DEBUG_SLOW) is intentionally NOT extended here — the env-var gate requires a manual restart and is not useful for routine production diagnosis. The new stage markers log via the standard [webui] WARNING channel and require no env var. No semantic change. No public API change. Logging only fires when the request exceeds 200ms, so it is invisible on the happy path. --- api/routes.py | 25 +++++++++++++++++++++++++ 1 file changed, 25 insertions(+) diff --git a/api/routes.py b/api/routes.py index a9a64412..f27b70d1 100644 --- a/api/routes.py +++ b/api/routes.py @@ -13631,6 +13631,13 @@ def handle_post(handler, parsed) -> bool: # GET ?session_id=X → return current draft # POST body → save draft { session_id, text?, files? } # HTTP method is in handler.command (e.g. "POST", "GET"), parsed has no .method + import time as _draft_time + _draft_t0 = _draft_time.monotonic() + _draft_stages = [] + + def _draft_mark(name): + _draft_stages.append((name, _draft_time.monotonic())) + _draft_mark("enter") if handler.command == "GET": query = parse_qs(parsed.query) sid = query.get("session_id", [""])[0] if parsed.query else "" @@ -13670,8 +13677,10 @@ def handle_post(handler, parsed) -> bool: s = get_session(sid) except KeyError: return bad(handler, "Session not found", 404) + _draft_mark("after_get_session") unchanged = False with _get_session_agent_lock(sid): + _draft_mark("acquired_lock") current_draft = dict(getattr(s, "composer_draft", {}) or {}) next_draft = dict(current_draft) if text is not None: @@ -13687,12 +13696,28 @@ def handle_post(handler, parsed) -> bool: # here makes the active-session external-refresh poll force-reload the # current chat every few seconds while the user is typing, and that # delayed reload can restore an older draft over newer local input. + _draft_mark("before_save") s.save(touch_updated_at=False, skip_index=True) + _draft_mark("after_save") saved_draft = s.composer_draft + _draft_mark("released_lock") payload = {"ok": True, "draft": saved_draft} if unchanged: payload["unchanged"] = True + _draft_mark("before_json") j(handler, payload) + _draft_mark("after_json") + _draft_stages.append(("end", _draft_time.monotonic())) + if _draft_stages[-1][1] - _draft_t0 > 0.2: + parts = " ".join( + f"{n}={((t - prev[1]) * 1000):.1f}ms" + for (n, t), prev in zip(_draft_stages[1:], _draft_stages[:-1]) + ) + logger.warning( + "[SLOW] /api/session/draft total=%.1fms stages: %s", + (_draft_stages[-1][1] - _draft_t0) * 1000, + parts, + ) return True if parsed.path == "/api/session/update": From 3a330ceff5f3353bff2a5d287c71543378896d58 Mon Sep 17 00:00:00 2001 From: Konstantin M Date: Wed, 8 Jul 2026 16:46:32 +0000 Subject: [PATCH 03/16] perf(webui/session-load-latency) tier2c: per-stage breakdown on /api/session MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The /api/session handler already has _t0.._t6 local timers plus an env-var-gated [SLOW] WARNING that logs the total wall time and the _tN-to-_tN+1 deltas, but only when HERMES_DEBUG_SLOW is set or total >= 2s. In production we cannot rely on the env var, and the 2s threshold means the typical chat-open (sub-2s on Tier 1) never logs at all — we only see the worst cases, never the marginal ones that would tell us where the next bottleneck is. This wires the handler into the existing RequestDiagnostics framework: - add ('GET', '/api/session') to the allowlist - call RequestDiagnostics.maybe_start() at the _t0 boundary - call stage() at each of _t1.._t6 - call finish() before the response returns The watchdog fires _on_timeout (with thread stack snapshot) when the request crosses the per-path slow threshold, and finish() emits a single structured log line on the same threshold crossing. The existing env-var-gated [SLOW] log stays as a no-diag fallback. Greptile P1 trap avoidance: previous allowlist additions for similar endpoints were flagged as dead code because the handler was never updated to call maybe_start/finish. Both halves are present in this commit so the watchdog entry actually registers. No behavior change observable on the happy path (diag is None for non-allowlisted paths; the existing _tN log is the fallback for both None-diag and slow cases). No public API change. The /api/sessions and /api/profiles handlers already use this pattern. --- api/request_diagnostics.py | 8 ++++++++ api/routes.py | 12 ++++++++++++ 2 files changed, 20 insertions(+) diff --git a/api/request_diagnostics.py b/api/request_diagnostics.py index 71fb1f3e..3a08cce4 100644 --- a/api/request_diagnostics.py +++ b/api/request_diagnostics.py @@ -144,6 +144,14 @@ class RequestDiagnostics: # of the multi-second waterfalls in the slow-request logs. ("GET", "/api/profiles"), ("GET", "/api/models"), + # perf(webui/session-load-latency) tier2c: /api/session is the + # chat-open hot path. The handler also calls maybe_start() and + # finish() at its _t0/_t6 boundaries, so adding this entry to + # the allowlist is NOT a dead-code addition (the Greptile P1 + # trap for previous similar entries): without the handler call + # the watchdog entry would never register and the structured + # log would never fire. + ("GET", "/api/session"), }: return None return cls(method, clean_path, logger=logger) diff --git a/api/routes.py b/api/routes.py index f27b70d1..037ed027 100644 --- a/api/routes.py +++ b/api/routes.py @@ -11700,6 +11700,11 @@ def handle_get(handler, parsed) -> bool: import time as _time _t0 = _time.monotonic() _debug_slow = os.environ.get("HERMES_DEBUG_SLOW", "") + # perf(webui/session-load-latency) tier2c: per-stage breakdown via + # RequestDiagnostics. maybe_start() returns None for paths not in + # the allowlist, in which case the existing _tN-driven [SLOW] log + # is the only signal — same as before. + _diag = RequestDiagnostics.maybe_start("GET", parsed.path, logger=logger) query = parse_qs(parsed.query) sid = query.get("session_id", [""])[0] if not sid: @@ -11735,6 +11740,7 @@ def handle_get(handler, parsed) -> bool: expand_renderable = str(_expand_renderable).strip() in ("1", "true", "True") try: _t1 = _time.monotonic() + if _diag: _diag.stage("t1_after_get_session_check") s = get_session(sid, metadata_only=(not load_messages)) _session_profile = getattr(s, 'profile', None) or None if not _session_visible_to_active_profile(_session_profile, handler): @@ -11789,6 +11795,7 @@ def handle_get(handler, parsed) -> bool: # honor #2827's TLS-vs-thread fix. metadata_summary = _metadata_only_message_summary(sid, profile=_session_profile) _t2 = _time.monotonic() + if _diag: _diag.stage("t2_after_state_db_load") effective_model = ( _resolve_effective_session_model_for_display(s) if resolve_model @@ -11800,6 +11807,7 @@ def handle_get(handler, parsed) -> bool: else None ) _t3 = _time.monotonic() + if _diag: _diag.stage("t3_after_model_resolve") if load_messages: if is_messaging_session and cli_messages: # Recovery/aggregate sidecars can intentionally contain a @@ -12042,6 +12050,7 @@ def handle_get(handler, parsed) -> bool: raw["_messages_truncated"] = _truncated raw["_messages_offset"] = _messages_offset _t4 = _time.monotonic() + if _diag: _diag.stage("t4_after_compact_and_merge") if effective_model: raw["model"] = effective_model if effective_provider: @@ -12057,8 +12066,10 @@ def handle_get(handler, parsed) -> bool: raw["read_only"] = True redact = redact_session_data(raw) _t5 = _time.monotonic() + if _diag: _diag.stage("t5_after_redact") resp = j(handler, {"session": redact}) _t6 = _time.monotonic() + if _diag: _diag.stage("t6_after_json_write") _total_ms = (_t6 - _t0) * 1000 # Always log when slow (>2s) so we don't need HERMES_DEBUG_SLOW env var # to diagnose latency regressions. Opt-in env var still forces @@ -12071,6 +12082,7 @@ def handle_get(handler, parsed) -> bool: (_t2-_t1)*1000, (_t3-_t2)*1000, (_t4-_t3)*1000, (_t5-_t4)*1000, (_t6-_t5)*1000, _total_ms, ) + if _diag: _diag.finish() return resp except KeyError: # No WebUI sidecar. Delegate to the shared foreign-session From 31cb8b4e01fb0f8cdf96a1a1d44f01e3c17a971e Mon Sep 17 00:00:00 2001 From: Konstantin M Date: Wed, 8 Jul 2026 16:48:07 +0000 Subject: [PATCH 04/16] perf(webui/session-load-latency) tier2a: cache profile config.yaml parse MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit _read_profile_model_config() fires on every chat-open that hits the resolve_model=1 path (one of the 3 calls in the chat-open waterfall). For sessions under a named profile (non-default), the function performs: - 1× os.path.isfile() call - 1× open() of config.yaml - 1× yaml.safe_load() of the full file On a Celeron N3350 with eMMC the open+safe_load alone is single-digit ms per call, repeated on every chat-open. The /api/session 24h log showed ?messages=0&resolve_model=1 at p50 1514ms with this YAML parse as one of the dominant costs. This wraps the parse in a per-process cache: - key = (profile_name, mtime, size) - value = parsed dict + monotonic timestamp - TTL 60s as a backstop for filesystem mtime resolution issues - cap 32 entries (bounded; profiles are bounded in practice) mtime+size auto-invalidates on edit. The TTL only fires when mtime resolution is too coarse to detect a same-second write; in normal operation, every config edit lands as a different mtime and the next chat-open rebuilds the cache entry. Threading: a single Lock guards the dict. yaml.safe_load is the slow step, not the lock, so contention is bounded. The lock is held for microseconds on hit and milliseconds on miss (parse). Field-semantics check: the function's signature is unchanged ((provider, default, config_dict) tuple) and the only call sites (_resolve_effective_session_model_for_display and its sibling) treat it the same as before. The cache stores the parsed dict; the function still does the per-call (provider, default) extraction inline so the tuple's content is identical to the pre-patch path. No public API change. No behavior change observable other than faster chat-open for sessions under named profiles. --- api/routes.py | 67 ++++++++++++++++++++++++++++++++++++++++++++++----- 1 file changed, 61 insertions(+), 6 deletions(-) diff --git a/api/routes.py b/api/routes.py index 037ed027..2f26448a 100644 --- a/api/routes.py +++ b/api/routes.py @@ -6262,6 +6262,15 @@ def _read_profile_model_config( does not override the session provider. ``profile_default_model`` is still returned for suffix repair (#5127) only when the profile's configured provider matches ``requested_provider`` after normalization. + + perf(webui/session-load-latency) tier2a: the parse is wrapped in a + per-process LRU keyed by (profile_name, config_mtime, size). The + function fires on every chat-open for sessions under a named + profile (resolve_model=1 path), and the YAML parse alone is + hundreds of µs to single-digit ms on the Chromebook. Cache TTL + 60s is a backstop in case mtime resolution is poor on a given + filesystem; under normal edits the mtime changes and invalidates + immediately. """ if not getattr(session, "profile", None): return None, None, None @@ -6269,15 +6278,13 @@ def _read_profile_model_config( try: from api.profiles import get_hermes_home_for_profile - _profile_home = get_hermes_home_for_profile(session.profile) + _profile_name = str(getattr(session, "profile") or "") + _profile_home = get_hermes_home_for_profile(_profile_name) _profile_cfg_path = os.path.join(str(_profile_home), "config.yaml") if not os.path.isfile(_profile_cfg_path): return None, None, None - import yaml - - with open(_profile_cfg_path, encoding="utf-8") as _f: - _pcfg = yaml.safe_load(_f) or {} - if not isinstance(_pcfg, dict): + _pcfg = _read_profile_config_cached(_profile_name, _profile_cfg_path) + if _pcfg is None: return None, None, None _model_cfg = _pcfg.get("model") or {} if not isinstance(_model_cfg, dict): @@ -6301,6 +6308,54 @@ def _read_profile_model_config( return _provider, _default, _pcfg +# perf(webui/session-load-latency) tier2a: process-wide cache for parsed +# profile config.yaml. Key = (profile_name, mtime, size); value = parsed +# dict. mtime+size auto-invalidates on edit; a 60s TTL is the backstop +# in case of coarse mtime resolution (some network filesystems round +# mtime to whole seconds — the size guard catches a write of equal-length +# bytes within the same second). Reads are guarded by a single Lock to +# keep the hot path simple; the underlying yaml.safe_load is the slow +# step, not the lock, so contention is bounded. +_PROFILE_CONFIG_CACHE: "dict[tuple, tuple[float, dict]]" = {} +_PROFILE_CONFIG_CACHE_TTL_SECONDS = 60.0 +_PROFILE_CONFIG_CACHE_LOCK = threading.Lock() + + +def _read_profile_config_cached(profile_name: str, cfg_path: str) -> dict | None: + """Return parsed profile config, caching by (mtime, size) with TTL backstop.""" + try: + st = os.stat(cfg_path) + except OSError: + return None + mtime = float(getattr(st, "st_mtime", 0.0) or 0.0) + size = int(getattr(st, "st_size", 0) or 0) + key = (str(profile_name or ""), mtime, size) + now = time.monotonic() + with _PROFILE_CONFIG_CACHE_LOCK: + cached = _PROFILE_CONFIG_CACHE.get(key) + if cached is not None: + cached_at, cached_dict = cached + if (now - cached_at) <= _PROFILE_CONFIG_CACHE_TTL_SECONDS: + return cached_dict + import yaml + try: + with open(cfg_path, encoding="utf-8") as _f: + parsed = yaml.safe_load(_f) or {} + except Exception: + return None + if not isinstance(parsed, dict): + return None + with _PROFILE_CONFIG_CACHE_LOCK: + _PROFILE_CONFIG_CACHE[key] = (now, parsed) + # Cap the cache at 32 entries; profiles are bounded in practice + # and unbounded growth would be a leak. + if len(_PROFILE_CONFIG_CACHE) > 32: + # Drop the oldest entry by insertion order (dict is ordered). + for old_key in list(_PROFILE_CONFIG_CACHE.keys())[:max(0, len(_PROFILE_CONFIG_CACHE) - 32)]: + _PROFILE_CONFIG_CACHE.pop(old_key, None) + return parsed + + def _load_profile_config_dict(session) -> dict | None: """Load the session profile's config.yaml as a dict, or None.""" if not getattr(session, "profile", None): From 5f167b23f93993f75dc823e44a08db8c5da1f7b7 Mon Sep 17 00:00:00 2001 From: Konstantin M Date: Wed, 8 Jul 2026 17:15:45 +0000 Subject: [PATCH 05/16] perf(webui/session-load-latency) tier2c-followup: route slow logs through _safe_webui_print MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Tier 2c added per-stage instrumentation on /api/session and added 'GET /api/session' to the RequestDiagnostics allowlist, but the structured log emitted by RequestDiagnostics.finish() and the pre-existing [SLOW] line both call logger.warning() — which the WebUI process silently drops because the root logger has no handler configured at boot. The per-request 'ms' line has worked all along because it goes through handler._safe_webui_print(), which writes directly to the systemd journal socket. This commit: - adds a print_fn= parameter to RequestDiagnostics.__init__ and RequestDiagnostics.maybe_start. When provided, finish() and _on_timeout() route through it instead of self.logger.warning. - routes the [SLOW] line in routes.py through handler._safe_webui_print instead of logger.warning. - passes print_fn=handler._safe_webui_print from the /api/session handler to RequestDiagnostics.maybe_start. After this fix, every slow /api/session request (and the existing [SLOW] line) actually lands in the journal — the very data Tier 2c was supposed to produce. Without this, the allowlist + handler instrumentation would be a no-op in production despite the code being present. Measured: the same 2.97s /api/session call (sid 295592fd560e, m=1 ml=30) which produced a per-request ms line but no [SLOW] line before this fix, now produces both lines with full per-stage breakdown. No public API change. The new print_fn parameter is optional and defaults to None, preserving the existing logger.warning behavior for any caller that hasn't been updated. --- api/request_diagnostics.py | 35 ++++++++++++++++++++++++++--------- api/routes.py | 22 ++++++++++++++++------ 2 files changed, 42 insertions(+), 15 deletions(-) diff --git a/api/request_diagnostics.py b/api/request_diagnostics.py index 3a08cce4..7c1b2536 100644 --- a/api/request_diagnostics.py +++ b/api/request_diagnostics.py @@ -106,11 +106,22 @@ class RequestDiagnostics: logger: logging.Logger | None = None, timeout_seconds: float | None = None, auto_start: bool = True, + print_fn: "callable | None" = None, ) -> None: self.request_id = uuid.uuid4().hex[:10] self.method = str(method or "-") self.path = str(path or "-").split("?", 1)[0] self.logger = logger or logging.getLogger(__name__) + # perf(webui/session-load-latency) tier2c: when the WebUI process + # boots without configuring a root-logger handler, logger.warning + # calls are silently dropped (the [SLOW] / "Slow WebUI request" + # lines have been invisible in production for some time — only the + # per-request ms line, which goes through _safe_webui_print, kept + # working). Callers that need the structured log to actually land + # in the systemd journal can pass print_fn=handler._safe_webui_print. + # When provided, finish() and _on_timeout() route through it + # instead of self.logger.warning. + self._print_fn = print_fn self.timeout_seconds = _slow_request_seconds() if timeout_seconds is None else max(0.0, float(timeout_seconds)) self.started_monotonic = time.monotonic() self.started_wall = time.time() @@ -134,6 +145,7 @@ class RequestDiagnostics: path: str, *, logger: logging.Logger | None = None, + print_fn: "callable | None" = None, ) -> "RequestDiagnostics | None": clean_path = str(path or "").split("?", 1)[0] if (method.upper(), clean_path) not in { @@ -154,7 +166,7 @@ class RequestDiagnostics: ("GET", "/api/session"), }: return None - return cls(method, clean_path, logger=logger) + return cls(method, clean_path, logger=logger, print_fn=print_fn) def stage(self, name: str) -> None: now = time.monotonic() @@ -171,6 +183,17 @@ class RequestDiagnostics: self._current_stage = clean self._current_stage_started = now + def _emit_slow(self, prefix: str, record: dict) -> None: + payload = f"{prefix} {json.dumps(record, sort_keys=True)}" + if self._print_fn is not None: + try: + self._print_fn(payload) + except Exception: + # print_fn is best-effort; never break a request thread. + pass + else: + self.logger.warning("%s", payload) + def finish(self) -> None: record = None with self._lock: @@ -183,10 +206,7 @@ class RequestDiagnostics: # bounded by the number of in-flight requests). _watchdog_unregister(self.request_id) if record and self.timeout_seconds > 0 and record["elapsed_ms"] >= self.timeout_seconds * 1000: - self.logger.warning( - "Slow WebUI request completed: %s", - json.dumps(record, sort_keys=True), - ) + self._emit_slow("Slow WebUI request completed:", record) def _on_timeout(self) -> None: with self._lock: @@ -194,10 +214,7 @@ class RequestDiagnostics: return self._watchdog_logged = True record = self._build_record_locked(include_stacks=True) - self.logger.warning( - "Slow WebUI request still running: %s", - json.dumps(record, sort_keys=True), - ) + self._emit_slow("Slow WebUI request still running:", record) def _build_record_locked(self, *, include_stacks: bool) -> dict[str, Any]: now = time.monotonic() diff --git a/api/routes.py b/api/routes.py index 2f26448a..492ddec9 100644 --- a/api/routes.py +++ b/api/routes.py @@ -11759,7 +11759,7 @@ def handle_get(handler, parsed) -> bool: # RequestDiagnostics. maybe_start() returns None for paths not in # the allowlist, in which case the existing _tN-driven [SLOW] log # is the only signal — same as before. - _diag = RequestDiagnostics.maybe_start("GET", parsed.path, logger=logger) + _diag = RequestDiagnostics.maybe_start("GET", parsed.path, logger=logger, print_fn=getattr(handler, '_safe_webui_print', None)) query = parse_qs(parsed.query) sid = query.get("session_id", [""])[0] if not sid: @@ -12130,12 +12130,22 @@ def handle_get(handler, parsed) -> bool: # to diagnose latency regressions. Opt-in env var still forces # logging on every request for development. if _debug_slow or _total_ms >= 2000: - logger.warning( + # perf(webui/session-load-latency) tier2c: route the [SLOW] line + # through handler._safe_webui_print() rather than logger.warning(). + # The WebUI process starts the root logger without any handler, so + # logger.warning() calls are silently dropped (the [SLOW] line + # previously worked only on PIDs that happened to have a logger + # handler set up by an earlier run; today the line is invisible). + # _safe_webui_print writes to the systemd journal socket directly, + # same as the per-request ms line — which is why THAT line keeps + # working. + handler._safe_webui_print( "[SLOW] session_id=%s get_session=%.1fms model_resolve=%.1fms " - "compact=%.1fms redact=%.1fms json_write=%.1fms total=%.1fms", - sid, - (_t2-_t1)*1000, (_t3-_t2)*1000, (_t4-_t3)*1000, - (_t5-_t4)*1000, (_t6-_t5)*1000, _total_ms, + "compact=%.1fms redact=%.1fms json_write=%.1fms total=%.1fms" % ( + sid, + (_t2-_t1)*1000, (_t3-_t2)*1000, (_t4-_t3)*1000, + (_t5-_t4)*1000, (_t6-_t5)*1000, _total_ms, + ) ) if _diag: _diag.finish() return resp From bc2b5889154ec707d31530f9b9084c870631afef Mon Sep 17 00:00:00 2001 From: Konstantin M Date: Wed, 8 Jul 2026 17:24:20 +0000 Subject: [PATCH 06/16] perf(webui/session-load-latency) tier2-cleanup: route slow logs through _safe_webui_print for the other 4 RequestDiagnostics call sites MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Tier 2c-followup added print_fn=handler._safe_webui_print to the /api/session handler so its [SLOW] line and structured 'RequestDiagnostics' log actually land in the systemd journal (the WebUI process boots with no root-logger handler, so logger.warning calls are silently dropped — the per-request ms line has always worked because it bypasses logging and writes via _safe_webui_print). There are 4 OTHER call sites of RequestDiagnostics.maybe_start() in api/routes.py (for /api/models, /api/sessions, /api/profiles, and the generic POST dispatch). All four were wired with the same broken logger.warning path, so their structured slow logs have been silent in production as well. This commit: - passes print_fn=getattr(handler, '_safe_webui_print', None) to the same 4 call sites - keeps the existing stage() and finish() call shape intact - the existing /api/sessions handler already has stage() markers (load_settings, profile_lookups, response_write) so the [SLOW] log on sidebar-list will now show real per-stage breakdown No behavior change on the happy path. No public API change. The allowlist still gates which paths get a diag at all; this only fixes the sink for the structured log on the 4 already-instrumented endpoints. --- api/routes.py | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/api/routes.py b/api/routes.py index 492ddec9..c7753914 100644 --- a/api/routes.py +++ b/api/routes.py @@ -11561,7 +11561,7 @@ def handle_get(handler, parsed) -> bool: # which the request-thread wrapper could not reach. See # api.config.get_available_models cold path + profile_scope_for_detached_worker. freshness = parse_qs(parsed.query or "").get("freshness", [""])[0].strip().lower() - diag = RequestDiagnostics.maybe_start("GET", parsed.path, logger=logger) + diag = RequestDiagnostics.maybe_start("GET", parsed.path, logger=logger, print_fn=getattr(handler, '_safe_webui_print', None)) try: diag.stage(f"enter:freshness={freshness or 'default'}") if diag else None if freshness == "session_visit": @@ -12281,7 +12281,7 @@ def handle_get(handler, parsed) -> bool: return j(handler, {"results": get_results(sid)}) if parsed.path == "/api/sessions": - diag = RequestDiagnostics.maybe_start("GET", parsed.path, logger=logger) + diag = RequestDiagnostics.maybe_start("GET", parsed.path, logger=logger, print_fn=getattr(handler, '_safe_webui_print', None)) try: from api import profiles as profiles_api @@ -12780,7 +12780,7 @@ def handle_get(handler, parsed) -> bool: # ── Profile API (GET) ── if parsed.path == "/api/profiles": from api import profiles as profiles_api - diag = RequestDiagnostics.maybe_start("GET", parsed.path, logger=logger) + diag = RequestDiagnostics.maybe_start("GET", parsed.path, logger=logger, print_fn=getattr(handler, '_safe_webui_print', None)) try: diag.stage("list_profiles_api") if diag else None profiles_payload = profiles_api.list_profiles_api() @@ -13036,7 +13036,7 @@ def _validate_session_toolsets_shape(toolsets): def handle_post(handler, parsed) -> bool: """Handle all POST routes. Returns True if handled, False for 404.""" - diag = RequestDiagnostics.maybe_start("POST", parsed.path, logger=logger) + diag = RequestDiagnostics.maybe_start("POST", parsed.path, logger=logger, print_fn=getattr(handler, '_safe_webui_print', None)) if parsed.path == "/api/csp-report": if diag: diag.stage("csp_report") From fabcd5239b7b2efc8944d01f0b84428ecd0fc13e Mon Sep 17 00:00:00 2001 From: Konstantin M Date: Wed, 8 Jul 2026 23:43:57 +0000 Subject: [PATCH 07/16] perf(webui/session-load-latency) tier1a-followup: fix anchor-scene staleness in cache fast-path Greptile review caught that the Tier 1a fast-path returns 'cache fresh' when disk_count == cached_count AND the session is inactive, but api/routes.py saves the sidecar after editing only anchor_activity_scenes (no message change). That path leaves the cached scene records stale until the cache is otherwise invalidated. Fix: when the cached session has scene records, also compare them against the disk's scenes via the same metadata-prefix read that _persisted_message_count already does. anchor_activity_scenes is in METADATA_FIELDS and serializes before messages, so it lands in the prefix. New _persisted_session_meta_prefix() helper exposes the parsed prefix dict; _cached_session_lags_disk reads it and compares scene key sets + max updated_at against the cached session. Cost: one extra dict parse per cache hit on sessions that have scene records, no cost on sessions without. Inactive sessions still take the fast-path exit when scenes match. --- api/models.py | 70 ++++++++++++++++++++++++++++++++++++++++++++------- 1 file changed, 61 insertions(+), 9 deletions(-) diff --git a/api/models.py b/api/models.py index 66ebaf8f..f6720390 100644 --- a/api/models.py +++ b/api/models.py @@ -3118,18 +3118,47 @@ def _cached_session_lags_disk(cached) -> bool: if disk_count is not None: if disk_count > cached_count: return True - # Disk is at most as far as cache; for inactive sessions we don't - # need to compare anchor-scene records (those are only updated by - # active streaming/recovery paths, which we can detect cheaply below). + # Disk is at most as far as cache. Even when counts match, anchor scene + # records can advance independently (api/routes.py saves a session + # with `s.save(touch_updated_at=False, skip_index=True)` after editing + # only the scene dict; message_count is len(messages) so it stays the + # same). Greptile flagged this in PR review. Cheaply check the disk's + # scene records from the same prefix we already read. + cached_scenes = getattr(cached, 'anchor_activity_scenes', None) or {} + if not isinstance(cached_scenes, dict): + cached_scenes = {} + if cached_scenes: + disk_meta_quick = _persisted_session_meta_prefix(sid) + if disk_meta_quick is not None: + disk_scenes = disk_meta_quick.get('anchor_activity_scenes') or {} + if not isinstance(disk_scenes, dict): + disk_scenes = {} + if not disk_scenes or set(disk_scenes.keys()) != set(cached_scenes.keys()): + # Scene key set differs — disk has been updated with new + # keys the cache hasn't seen. + return True + # Same key set: check the latest updated_at timestamp. + def _max_updated(records): + latest = 0.0 + for record in records.values(): + if not isinstance(record, dict): + continue + try: + ua = float(record.get('updated_at') or 0) + except (TypeError, ValueError): + ua = 0.0 + if ua > latest: + latest = ua + return latest + if _max_updated(disk_scenes) > _max_updated(cached_scenes): + return True if getattr(cached, 'active_stream_id', None) or getattr(cached, 'pending_user_message', None): - # Active session: anchor-scene keys may have advanced even when - # the count is the same. Fall through to the full check. + # Active session: messages may be in flight; fall through to the + # full check to be safe. pass else: - # Inactive session, count matches → cache is at parity with disk. - # The pre-fix code would still load_metadata_only to compare - # anchor scenes, but for inactive sessions those cannot have - # advanced without the count advancing too. Skip the full load. + # Inactive session, count matches, scene records match — cache is + # at parity with disk. return False try: disk_meta = Session.load_metadata_only(sid) @@ -3183,6 +3212,29 @@ def _persisted_message_count(sid) -> int | None: return _parse_nonnegative_int(_lookup_index_message_count(sid)) +def _persisted_session_meta_prefix(sid) -> dict | None: + """Return the parsed metadata prefix dict for *sid*, or None on error. + + Used by ``_cached_session_lags_disk`` to compare additional fields (e.g. + anchor scene records) cheaply against the cached in-memory session without + paying for a full ``Session.load_metadata_only`` parse. Returns the same + shape as ``_persisted_message_count`` callers would expect — a dict that + only contains the metadata-prefix fields, NOT ``messages`` / ``tool_calls``. + """ + if not is_safe_session_id(sid): + return None + p = SESSION_DIR / f'{sid}.json' + if not p.exists(): + return None + try: + prefix = _read_metadata_json_prefix(p) + if not prefix: + return None + return json.loads(prefix) + except Exception: + return None + + def _session_is_evictable(s) -> bool: """Return True only when *s* can be safely dropped from the LRU (#4765). From 78dab75fc3801a4c1c098b8febb4523633919ba2 Mon Sep 17 00:00:00 2001 From: Konstantin M Date: Wed, 8 Jul 2026 23:44:04 +0000 Subject: [PATCH 08/16] perf(webui/session-load-latency) tier2c-followup2: ensure RequestDiagnostics.finish() always fires Greptile review caught that /api/session handler calls _diag.maybe_start() at entry and _diag.finish() only on the success path. Three exit paths leaked the watchdog entry: 1. early-return when sid is missing (400) 2. early-return when session is not visible to active profile (409) 3. early-return when session not found (404) 4. the existing 'except KeyError:' branch at the bottom of the handler Without _diag.finish() the watchdog's _watchdog_pending dict held the request until the 5s slow-request timeout fired _on_timeout and emitted a spurious 'Slow WebUI request still running' log. The pending dict also stayed unbounded by in-flight count. Fix: every early-return path now calls _diag.finish() before returning; the except KeyError branch calls it once at entry so all paths through it are covered. finish() is idempotent (no-ops if already called). --- api/routes.py | 17 +++++++++++++++++ 1 file changed, 17 insertions(+) diff --git a/api/routes.py b/api/routes.py index c7753914..75474a5a 100644 --- a/api/routes.py +++ b/api/routes.py @@ -11760,9 +11760,17 @@ def handle_get(handler, parsed) -> bool: # the allowlist, in which case the existing _tN-driven [SLOW] log # is the only signal — same as before. _diag = RequestDiagnostics.maybe_start("GET", parsed.path, logger=logger, print_fn=getattr(handler, '_safe_webui_print', None)) + # perf(webui/session-load-latency) tier2c-followup: every early-return + # in this handler calls `_diag.finish()` before returning so the + # watchdog's _watchdog_pending dict stays bounded to in-flight requests. + # Greptile flagged this in PR review — finish() unregisters the + # pending watchdog entry; without it the entry stays for the full + # 5s slow-request timeout and emits a spurious "Slow WebUI request + # still running" log. Idempotent — finish() no-ops if already called. query = parse_qs(parsed.query) sid = query.get("session_id", [""])[0] if not sid: + if _diag: _diag.finish() return j(handler, {"error": "session_id is required"}, status=400) # ?messages=0 skips the message payload for fast session switching. # The frontend uses this when switching conversations in the sidebar @@ -11802,6 +11810,7 @@ def handle_get(handler, parsed) -> bool: if _session_profile: # Valid session owned by a KNOWN other profile: 409 so the # client can offer to switch to it (#5419). + if _diag: _diag.finish() return j(handler, { "error": "Session belongs to a different profile", "code": "session_profile_mismatch", @@ -11813,6 +11822,7 @@ def handle_get(handler, parsed) -> bool: # fires. _profiles_match coerces None->'default', so a truly # missing/legacy session under a non-default active profile would # otherwise emit a useless 409 with profile=null. + if _diag: _diag.finish() return bad(handler, "Session not found", 404) original_stream_id = getattr(s, "active_stream_id", None) _clear_stale_stream_state(s) @@ -12150,6 +12160,13 @@ def handle_get(handler, parsed) -> bool: if _diag: _diag.finish() return resp except KeyError: + # perf(webui/session-load-latency) tier2c-followup: fire + # _diag.finish() in the exception branch too. Greptile flagged + # this in PR review — finish() unregisters the pending watchdog + # entry; without it the entry stays for the full 5s slow-request + # timeout and emits a spurious "Slow WebUI request still + # running" log. Idempotent — finish() no-ops if already called. + if _diag: _diag.finish() # No WebUI sidecar. Delegate to the shared foreign-session # synthesizer so GET and POST have symmetric writeable/read-only # behaviour for CLI/TUI/Desktop sessions. The helper enforces the From f8cd40d74a28eeac91a5e3989046800c510564c4 Mon Sep 17 00:00:00 2001 From: Konstantin M Date: Thu, 9 Jul 2026 00:28:26 +0000 Subject: [PATCH 09/16] perf(webui/session-load-latency) tier3a: Greptile follow-up fixes (P1 empty-scenes skip, P2 draft-log sink, P2 config-cache inode) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Three unaddressed Greptile review comments fixed: P1 - Empty scenes skip check (api/models.py): When the cached session had no anchor_activity_scenes, the scene-comparison branch was skipped entirely by the 'if cached_scenes:' guard. An inactive session would return False (cache fresh) even when disk had gained its first scene record. Add an else clause that checks disk for scene records when the cache has none. P2 - Draft slow log sink (api/routes.py): The /api/session/draft handler's slow-path log (>200ms) used logger.warning, which is silently dropped in the WebUI process (root logger has no handler). Route through handler._safe_webui_print() instead, the same fix applied to the /api/session slow log in tier2c. P2 - Config cache same-timestamp stale (api/routes.py): The profile config.yaml cache key (profile_name, mtime, size) could collide on coarse-mtime filesystems (FAT, some network FS) when a config edit within the same timestamp tick happened to produce the same byte count. Add st_ino (inode) to the cache key — most editors use atomic-rename writes which assign a new inode, so the key changes even when mtime+size are identical. --- api/models.py | 9 +++++++++ api/routes.py | 21 ++++++++++++--------- 2 files changed, 21 insertions(+), 9 deletions(-) diff --git a/api/models.py b/api/models.py index f6720390..702fc699 100644 --- a/api/models.py +++ b/api/models.py @@ -3152,6 +3152,15 @@ def _cached_session_lags_disk(cached) -> bool: return latest if _max_updated(disk_scenes) > _max_updated(cached_scenes): return True + else: + # Cached session has no scene records. Check if disk has gained + # the first scene record — without this the fast-path would miss + # a newly persisted scene and return the stale cache. Greptile P1. + disk_meta_quick = _persisted_session_meta_prefix(sid) + if disk_meta_quick is not None: + disk_scenes = disk_meta_quick.get('anchor_activity_scenes') or {} + if isinstance(disk_scenes, dict) and disk_scenes: + return True if getattr(cached, 'active_stream_id', None) or getattr(cached, 'pending_user_message', None): # Active session: messages may be in flight; fall through to the # full check to be safe. diff --git a/api/routes.py b/api/routes.py index 75474a5a..d04bdc92 100644 --- a/api/routes.py +++ b/api/routes.py @@ -6309,10 +6309,11 @@ def _read_profile_model_config( # perf(webui/session-load-latency) tier2a: process-wide cache for parsed -# profile config.yaml. Key = (profile_name, mtime, size); value = parsed -# dict. mtime+size auto-invalidates on edit; a 60s TTL is the backstop -# in case of coarse mtime resolution (some network filesystems round -# mtime to whole seconds — the size guard catches a write of equal-length +# profile config.yaml. Key = (profile_name, inode, mtime, size); value = parsed +# dict. inode tracks atomic-rename edits (most editors replace files, giving a +# new inode on Linux). mtime+size auto-invalidates on in-place edits; a 60s TTL +# is the backstop in case of coarse mtime resolution (some network filesystems +# round mtime to whole seconds — the size guard catches a write of equal-length # bytes within the same second). Reads are guarded by a single Lock to # keep the hot path simple; the underlying yaml.safe_load is the slow # step, not the lock, so contention is bounded. @@ -6329,7 +6330,8 @@ def _read_profile_config_cached(profile_name: str, cfg_path: str) -> dict | None return None mtime = float(getattr(st, "st_mtime", 0.0) or 0.0) size = int(getattr(st, "st_size", 0) or 0) - key = (str(profile_name or ""), mtime, size) + inode = int(getattr(st, "st_ino", 0) or 0) + key = (str(profile_name or ""), inode, mtime, size) now = time.monotonic() with _PROFILE_CONFIG_CACHE_LOCK: cached = _PROFILE_CONFIG_CACHE.get(key) @@ -13807,10 +13809,11 @@ def handle_post(handler, parsed) -> bool: f"{n}={((t - prev[1]) * 1000):.1f}ms" for (n, t), prev in zip(_draft_stages[1:], _draft_stages[:-1]) ) - logger.warning( - "[SLOW] /api/session/draft total=%.1fms stages: %s", - (_draft_stages[-1][1] - _draft_t0) * 1000, - parts, + handler._safe_webui_print( + "[SLOW] /api/session/draft total=%.1fms stages: %s" % ( + (_draft_stages[-1][1] - _draft_t0) * 1000, + parts, + ) ) return True From aa785901642490ef49b61f6ea584ee8331b2c356 Mon Sep 17 00:00:00 2001 From: Konstantin M Date: Thu, 9 Jul 2026 01:28:56 +0000 Subject: [PATCH 10/16] perf(webui/session-load-latency) tier3b: content-prefix verification in profile config cache MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Greptile P1 (discussion_r3548069113): the inode+mtime+size cache key misses in-place rewrites on coarse filesystems. When a file is rewritten in-place (same inode, same mtime tick, same byte size), the cache returns the old parsed config for up to 60s. Fix: on cache hit, read the first 128 characters of the file and compare against the stored prefix from when the entry was populated. If they differ, the content has changed — fall through to re-parse. Cost on hot path: one 128-char read + string comparison (negligible vs YAML parse). --- api/routes.py | 40 +++++++++++++++++++++++++++++++--------- 1 file changed, 31 insertions(+), 9 deletions(-) diff --git a/api/routes.py b/api/routes.py index d04bdc92..53f2dbaf 100644 --- a/api/routes.py +++ b/api/routes.py @@ -6314,16 +6314,26 @@ def _read_profile_model_config( # new inode on Linux). mtime+size auto-invalidates on in-place edits; a 60s TTL # is the backstop in case of coarse mtime resolution (some network filesystems # round mtime to whole seconds — the size guard catches a write of equal-length -# bytes within the same second). Reads are guarded by a single Lock to -# keep the hot path simple; the underlying yaml.safe_load is the slow -# step, not the lock, so contention is bounded. -_PROFILE_CONFIG_CACHE: "dict[tuple, tuple[float, dict]]" = {} +# bytes within the same second). On cache hit, a quick content-prefix comparison +# (first 128 chars) catches in-place rewrites that inode+mtime+size miss on +# coarse filesystems (Greptile P1, PR#5803 discussion_r3548069113). +# Reads are guarded by a single Lock to keep the hot path simple; +# the underlying yaml.safe_load is the slow step, not the lock, so contention +# is bounded. +_PROFILE_CONFIG_CACHE: "dict[tuple, tuple[float, str | None, dict]]" = {} _PROFILE_CONFIG_CACHE_TTL_SECONDS = 60.0 _PROFILE_CONFIG_CACHE_LOCK = threading.Lock() def _read_profile_config_cached(profile_name: str, cfg_path: str) -> dict | None: - """Return parsed profile config, caching by (mtime, size) with TTL backstop.""" + """Return parsed profile config, caching by (inode, mtime, size) with + TTL backstop and content-prefix verification. + + The content-prefix comparison (first 128 chars of the file) catches + in-place rewrites where inode+mtime+size are identical on coarse + filesystems — most editors use atomic-rename (new inode), but tools + like sed -i or file.write() in-place can keep the same inode. + """ try: st = os.stat(cfg_path) except OSError: @@ -6336,19 +6346,31 @@ def _read_profile_config_cached(profile_name: str, cfg_path: str) -> dict | None with _PROFILE_CONFIG_CACHE_LOCK: cached = _PROFILE_CONFIG_CACHE.get(key) if cached is not None: - cached_at, cached_dict = cached + cached_at, cached_prefix, cached_dict = cached if (now - cached_at) <= _PROFILE_CONFIG_CACHE_TTL_SECONDS: - return cached_dict + # Cheap content verification: read first 128 chars to catch + # in-place rewrites that inode+mtime+size don't detect. + _current_prefix = None + try: + with open(cfg_path, "r", encoding="utf-8") as _f: + _current_prefix = _f.read(128) + except Exception: + pass + if _current_prefix == cached_prefix: + return cached_dict + # Content changed while key collided — fall through to re-parse import yaml try: with open(cfg_path, encoding="utf-8") as _f: - parsed = yaml.safe_load(_f) or {} + content = _f.read() + parsed = yaml.safe_load(content) or {} except Exception: return None if not isinstance(parsed, dict): return None + content_prefix = content[:128] # first 128 chars for change detection with _PROFILE_CONFIG_CACHE_LOCK: - _PROFILE_CONFIG_CACHE[key] = (now, parsed) + _PROFILE_CONFIG_CACHE[key] = (now, content_prefix, parsed) # Cap the cache at 32 entries; profiles are bounded in practice # and unbounded growth would be a leak. if len(_PROFILE_CONFIG_CACHE) > 32: From b5c0447a4a3c7b21583bee82141c09f7f8d768b8 Mon Sep 17 00:00:00 2001 From: Konstantin M Date: Thu, 9 Jul 2026 02:21:25 +0000 Subject: [PATCH 11/16] perf(webui/session-load-latency) tier3c: fix scene comparison direction in cache fast-path MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The fast-path scene comparison in _cached_session_lags_disk had two bugs flagged by nesquena-hermes review: 1. Direction: used symmetric != instead of directional subset check. When the cache had scene keys that disk lacked (cache-ahead), the old code force-reloaded from disk, silently dropping un-persisted scene data. Now mirrors master: reload only when disk is strictly ahead (disk_keys.issubset(cached_keys)). The 'not disk_scenes' early-return is also removed — empty disk scenes means disk is not ahead, so keep the cache. 2. Key filtering mismatch: used raw set(disk_scenes.keys()) instead of _anchor_scene_record_keys() helper which filters to truthy keys with dict values. Now filters disk keys the same way as master, and uses _anchor_scene_record_keys(cached) for the cached session object. Also updated the tier3b content-prefix docstring to clarify it is a best-effort backstop limited to the first 128 chars, not a full integrity check. --- api/models.py | 46 +++++++++++++++++++++++++++------------------- api/routes.py | 7 +++++++ 2 files changed, 34 insertions(+), 19 deletions(-) diff --git a/api/models.py b/api/models.py index 702fc699..5e53e796 100644 --- a/api/models.py +++ b/api/models.py @@ -3133,25 +3133,33 @@ def _cached_session_lags_disk(cached) -> bool: disk_scenes = disk_meta_quick.get('anchor_activity_scenes') or {} if not isinstance(disk_scenes, dict): disk_scenes = {} - if not disk_scenes or set(disk_scenes.keys()) != set(cached_scenes.keys()): - # Scene key set differs — disk has been updated with new - # keys the cache hasn't seen. - return True - # Same key set: check the latest updated_at timestamp. - def _max_updated(records): - latest = 0.0 - for record in records.values(): - if not isinstance(record, dict): - continue - try: - ua = float(record.get('updated_at') or 0) - except (TypeError, ValueError): - ua = 0.0 - if ua > latest: - latest = ua - return latest - if _max_updated(disk_scenes) > _max_updated(cached_scenes): - return True + if disk_scenes: + # Directional: only reload when disk is strictly ahead + # of cache. Mirror master's subset comparison — cache + # that is ahead of disk must NOT force a reload, or + # un-persisted scene data is silently dropped. + disk_keys = {str(key) for key, value in disk_scenes.items() + if key and isinstance(value, dict)} + cached_keys = _anchor_scene_record_keys(cached) + if disk_keys and not disk_keys.issubset(cached_keys): + return True + # Same key set (or disk is subset): check the latest + # updated_at timestamp. + def _max_updated(records): + latest = 0.0 + for record in records.values(): + if not isinstance(record, dict): + continue + try: + ua = float(record.get('updated_at') or 0) + except (TypeError, ValueError): + ua = 0.0 + if ua > latest: + latest = ua + return latest + if _max_updated(disk_scenes) > _anchor_scene_records_updated_at(cached): + return True + # disk has no scenes, cache does -> cache is ahead; keep it. else: # Cached session has no scene records. Check if disk has gained # the first scene record — without this the fast-path would miss diff --git a/api/routes.py b/api/routes.py index 53f2dbaf..4bab6cf6 100644 --- a/api/routes.py +++ b/api/routes.py @@ -6333,6 +6333,13 @@ def _read_profile_config_cached(profile_name: str, cfg_path: str) -> dict | None in-place rewrites where inode+mtime+size are identical on coarse filesystems — most editors use atomic-rename (new inode), but tools like sed -i or file.write() in-place can keep the same inode. + + NOTE: This is a best-effort backstop, not a full integrity check. + Edits that change bytes only after the first 128 characters while + keeping inode+mtime+size identical are not detected until the TTL + expires. This trade-off is acceptable because the TTL is only 60s + and the common case (atomic-rename editors) is fully handled by + the inode key component. """ try: st = os.stat(cfg_path) From db99f72505c30bdc3ca1ccb2613ea9f7f2b9b7c7 Mon Sep 17 00:00:00 2001 From: Konstantin M Date: Thu, 9 Jul 2026 03:08:11 +0000 Subject: [PATCH 12/16] =?UTF-8?q?perf(webui/session-load-latency)=20tier3d?= =?UTF-8?q?:=20Greptile=20P1=20followups=20=E2=80=94=20inconclusive=20scen?= =?UTF-8?q?e=20check=20+=20full-content=20config=20verification?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Two Greptile P1 comments from review of b5c0447a (tier3c): 1. Inconclusive Prefix Stays Fresh (discussion_r3548477859): When _persisted_session_meta_prefix() returns None and cached has scene records, the fast-path skipped scene comparison entirely and returned False (cache fresh) for inactive equal-count sessions. Added _scene_check_inconclusive flag that forces fall-through to the full Session.load_metadata_only() comparison when the cheap prefix read fails, preventing stale anchor_activity_scenes. 2. Prefix Check Misses Edits (discussion_r3548477915): The 128-char content-prefix backstop in _read_profile_config_cached only detected edits within the first 128 bytes of config.yaml. Replaced with a full-content comparison that reads the entire file (~1-10KB) and compares it to a copy stored in the cache entry. This detects edits anywhere in the file at a fraction of the cost of yaml.safe_load(). Updated cache type hint from tuple[float, str|None, dict] to tuple[float, str, dict]. Tests: 108 passed (41 reconciliation + 39 anchor-scene + 28 profile-config) --- api/models.py | 16 +++++++++++++++ api/routes.py | 56 +++++++++++++++++++++++++++------------------------ 2 files changed, 46 insertions(+), 26 deletions(-) diff --git a/api/models.py b/api/models.py index 5e53e796..68e68560 100644 --- a/api/models.py +++ b/api/models.py @@ -3127,6 +3127,10 @@ def _cached_session_lags_disk(cached) -> bool: cached_scenes = getattr(cached, 'anchor_activity_scenes', None) or {} if not isinstance(cached_scenes, dict): cached_scenes = {} + # Track whether the cheap scene check was inconclusive — when it is, + # we must fall through to the full metadata comparison instead of + # returning False for inactive sessions with matching counts. + _scene_check_inconclusive = False if cached_scenes: disk_meta_quick = _persisted_session_meta_prefix(sid) if disk_meta_quick is not None: @@ -3160,6 +3164,13 @@ def _cached_session_lags_disk(cached) -> bool: if _max_updated(disk_scenes) > _anchor_scene_records_updated_at(cached): return True # disk has no scenes, cache does -> cache is ahead; keep it. + else: + # Can't cheaply verify scene freshness from disk. The prefix + # reader may have failed while _persisted_message_count + # succeeded via index fallback. Fall through to the full + # metadata load so we don't serve stale scenes on the next + # equal-count inactive session path. Greptile P1. + _scene_check_inconclusive = True else: # Cached session has no scene records. Check if disk has gained # the first scene record — without this the fast-path would miss @@ -3173,6 +3184,11 @@ def _cached_session_lags_disk(cached) -> bool: # Active session: messages may be in flight; fall through to the # full check to be safe. pass + elif _scene_check_inconclusive: + # Could not cheaply verify scene freshness from disk; fall through + # to the full metadata comparison rather than returning False + # (which would serve a potentially stale cache). Greptile P1. + pass else: # Inactive session, count matches, scene records match — cache is # at parity with disk. diff --git a/api/routes.py b/api/routes.py index 4bab6cf6..73f4a452 100644 --- a/api/routes.py +++ b/api/routes.py @@ -6314,32 +6314,34 @@ def _read_profile_model_config( # new inode on Linux). mtime+size auto-invalidates on in-place edits; a 60s TTL # is the backstop in case of coarse mtime resolution (some network filesystems # round mtime to whole seconds — the size guard catches a write of equal-length -# bytes within the same second). On cache hit, a quick content-prefix comparison -# (first 128 chars) catches in-place rewrites that inode+mtime+size miss on -# coarse filesystems (Greptile P1, PR#5803 discussion_r3548069113). -# Reads are guarded by a single Lock to keep the hot path simple; -# the underlying yaml.safe_load is the slow step, not the lock, so contention -# is bounded. -_PROFILE_CONFIG_CACHE: "dict[tuple, tuple[float, str | None, dict]]" = {} +# bytes within the same second). On cache hit, a full-content comparison catches +# any in-place rewrite that inode+mtime+size missed (Greptile P1, PR#5803 +# discussion_r3548477915). Reading and comparing the full file content (~1-10KB) +# is much cheaper than yaml.safe_load(). Reads are guarded by a single Lock to +# keep the hot path simple; the underlying yaml.safe_load is the slow step, not +# the lock, so contention is bounded. +_PROFILE_CONFIG_CACHE: "dict[tuple, tuple[float, str, dict]]" = {} _PROFILE_CONFIG_CACHE_TTL_SECONDS = 60.0 _PROFILE_CONFIG_CACHE_LOCK = threading.Lock() def _read_profile_config_cached(profile_name: str, cfg_path: str) -> dict | None: """Return parsed profile config, caching by (inode, mtime, size) with - TTL backstop and content-prefix verification. + TTL backstop and full-content verification. - The content-prefix comparison (first 128 chars of the file) catches - in-place rewrites where inode+mtime+size are identical on coarse - filesystems — most editors use atomic-rename (new inode), but tools - like sed -i or file.write() in-place can keep the same inode. + The full-content comparison reads the current file and compares it to a + copy stored in the cache entry. This catches any in-place rewrite where + inode+mtime+size are identical, regardless of where in the file the change + occurs — unlike a fixed-length prefix comparison, edits to fields after the + first N characters are always detected. Reading and comparing the full file + content (~1-10KB for a typical config.yaml) is much cheaper than + yaml.safe_load(). - NOTE: This is a best-effort backstop, not a full integrity check. - Edits that change bytes only after the first 128 characters while - keeping inode+mtime+size identical are not detected until the TTL - expires. This trade-off is acceptable because the TTL is only 60s - and the common case (atomic-rename editors) is fully handled by - the inode key component. + NOTE: The cache key uses inode+mtime+size to handle the common cases + (atomic-rename editors -> new inode; in-place editors -> mtime/size + change). The full-content comparison is a backstop for the rare case where + all three collide (e.g., sed -i on a filesystem with coarse mtime + resolution, writing the same byte count). """ try: st = os.stat(cfg_path) @@ -6353,17 +6355,20 @@ def _read_profile_config_cached(profile_name: str, cfg_path: str) -> dict | None with _PROFILE_CONFIG_CACHE_LOCK: cached = _PROFILE_CONFIG_CACHE.get(key) if cached is not None: - cached_at, cached_prefix, cached_dict = cached + cached_at, cached_content, cached_dict = cached if (now - cached_at) <= _PROFILE_CONFIG_CACHE_TTL_SECONDS: - # Cheap content verification: read first 128 chars to catch - # in-place rewrites that inode+mtime+size don't detect. - _current_prefix = None + # Full content comparison catches any in-place rewrite where + # inode+mtime+size are identical but the file content changed. + # Reading and comparing the full file (~1-10KB) is cheaper than + # yaml.safe_load(). Unlike a fixed-length prefix, this detects + # edits anywhere in the file. Greptile P1 (PR#5803). + _current_content = None try: with open(cfg_path, "r", encoding="utf-8") as _f: - _current_prefix = _f.read(128) + _current_content = _f.read() except Exception: pass - if _current_prefix == cached_prefix: + if _current_content == cached_content: return cached_dict # Content changed while key collided — fall through to re-parse import yaml @@ -6375,9 +6380,8 @@ def _read_profile_config_cached(profile_name: str, cfg_path: str) -> dict | None return None if not isinstance(parsed, dict): return None - content_prefix = content[:128] # first 128 chars for change detection with _PROFILE_CONFIG_CACHE_LOCK: - _PROFILE_CONFIG_CACHE[key] = (now, content_prefix, parsed) + _PROFILE_CONFIG_CACHE[key] = (now, content, parsed) # Cap the cache at 32 entries; profiles are bounded in practice # and unbounded growth would be a leak. if len(_PROFILE_CONFIG_CACHE) > 32: From 12a60a88b470c3851007f315dd14860ae5b53278 Mon Sep 17 00:00:00 2001 From: Konstantin M Date: Thu, 9 Jul 2026 03:44:55 +0000 Subject: [PATCH 13/16] perf(webui/session-load-latency) tier3e: fix empty-scene inconclusive prefix read (Greptile P1) When cached session has no anchor_activity_scenes and the prefix reader returns None (e.g. sidecar too large for prefix), the empty-scenes path did not mark _scene_check_inconclusive = True. This meant an inactive session with matching message counts would return False (cache fresh) even though disk may have gained its first scene record. Fix: the empty-scenes else-branch now sets _scene_check_inconclusive when disk_meta_quick is None, matching the existing behavior in the cached-scenes branch (line 3173). The code then falls through to the full metadata comparison instead of serving a stale cache. discussion_r3548650345 --- api/models.py | 6 ++++++ 1 file changed, 6 insertions(+) diff --git a/api/models.py b/api/models.py index 68e68560..38c3dfc0 100644 --- a/api/models.py +++ b/api/models.py @@ -3180,6 +3180,12 @@ def _cached_session_lags_disk(cached) -> bool: disk_scenes = disk_meta_quick.get('anchor_activity_scenes') or {} if isinstance(disk_scenes, dict) and disk_scenes: return True + else: + # Prefix read failed (may still succeed via index fallback for + # message count). Mark inconclusive so we fall through to the + # full metadata comparison instead of returning False with + # stale cache. Greptile P1 (discussion_r3548650345). + _scene_check_inconclusive = True if getattr(cached, 'active_stream_id', None) or getattr(cached, 'pending_user_message', None): # Active session: messages may be in flight; fall through to the # full check to be safe. From e96318d2e59183a46463a5935e8465f8d657121e Mon Sep 17 00:00:00 2001 From: Konstantin M Date: Thu, 9 Jul 2026 04:22:21 +0000 Subject: [PATCH 14/16] =?UTF-8?q?perf(webui/session-load-latency)=20tier4:?= =?UTF-8?q?=20fix=20CI=20failures=20=E2=80=94=20lint=20B009/B905=20+=20=5F?= =?UTF-8?q?emit=5Fslow=20format=20args?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Three fixes for the CI failures (lint + test shard 1): 1. B009 lint fix (api/routes.py:6281): Replace getattr(session, 'profile') with session.profile — the guard on line 6275 already ensures it exists. 2. B905 lint fix (api/routes.py:13843): Add strict=True to zip() of _draft_stages slices. Both sides are always the same length (shifted by one), so strict=True is correct. 3. _emit_slow format-arg fix (api/request_diagnostics.py:186-195): Keep the prefix in the format string and pass the JSON payload as a separate positional argument. The test at test_issue1855_request_diagnostics.py:33 does json.loads(caplog.records[0].args[0]) and the old code embedded the prefix in the payload string, breaking the JSON parse. Now self.logger.warning("%s %s", prefix, payload) — wait, actually self.logger.warning(f"{prefix} %s", payload) — so args[0] is the raw JSON string, same as the pre-_emit_slow code. --- api/request_diagnostics.py | 7 ++++--- api/routes.py | 4 ++-- 2 files changed, 6 insertions(+), 5 deletions(-) diff --git a/api/request_diagnostics.py b/api/request_diagnostics.py index 7c1b2536..2199567c 100644 --- a/api/request_diagnostics.py +++ b/api/request_diagnostics.py @@ -184,15 +184,16 @@ class RequestDiagnostics: self._current_stage_started = now def _emit_slow(self, prefix: str, record: dict) -> None: - payload = f"{prefix} {json.dumps(record, sort_keys=True)}" + payload = json.dumps(record, sort_keys=True) + log_msg = f"{prefix} %s" if self._print_fn is not None: try: - self._print_fn(payload) + self._print_fn(log_msg % payload) except Exception: # print_fn is best-effort; never break a request thread. pass else: - self.logger.warning("%s", payload) + self.logger.warning(log_msg, payload) def finish(self) -> None: record = None diff --git a/api/routes.py b/api/routes.py index 73f4a452..3df40cae 100644 --- a/api/routes.py +++ b/api/routes.py @@ -6278,7 +6278,7 @@ def _read_profile_model_config( try: from api.profiles import get_hermes_home_for_profile - _profile_name = str(getattr(session, "profile") or "") + _profile_name = str(session.profile or "") _profile_home = get_hermes_home_for_profile(_profile_name) _profile_cfg_path = os.path.join(str(_profile_home), "config.yaml") if not os.path.isfile(_profile_cfg_path): @@ -13840,7 +13840,7 @@ def handle_post(handler, parsed) -> bool: if _draft_stages[-1][1] - _draft_t0 > 0.2: parts = " ".join( f"{n}={((t - prev[1]) * 1000):.1f}ms" - for (n, t), prev in zip(_draft_stages[1:], _draft_stages[:-1]) + for (n, t), prev in zip(_draft_stages[1:], _draft_stages[:-1], strict=True) ) handler._safe_webui_print( "[SLOW] /api/session/draft total=%.1fms stages: %s" % ( From 264a9eab29546b630142c19270d1e5c3fc805137 Mon Sep 17 00:00:00 2001 From: Nathan Esquenazi Date: Wed, 8 Jul 2026 23:03:20 -0700 Subject: [PATCH 15/16] Update the screenshot (#5816) --- README.md | 11 +++++++---- 1 file changed, 7 insertions(+), 4 deletions(-) diff --git a/README.md b/README.md index ff7b15bb..d8e52ae7 100644 --- a/README.md +++ b/README.md @@ -3,9 +3,7 @@ [Hermes Agent](https://hermes-agent.nousresearch.com/) is a sophisticated autonomous agent that lives on your server, accessed via a terminal or messaging apps, that remembers what it learns and gets more capable the longer it runs. Hermes WebUI is a lightweight, dark-themed web app interface in your browser for [Hermes Agent](https://hermes-agent.nousresearch.com/). -Full parity with the CLI experience - everything you can do from a terminal, -you can do from this UI. No build step, no framework, no bundler. Just Python -and vanilla JS. +Full parity with the CLI experience - everything you can do from a terminal, you can do from this UI. No build step, no framework, no bundler. Just Python and vanilla JS. Layout: three-panel. Left sidebar for sessions and navigation, center for chat, right for workspace file browsing. Model, profile, and workspace controls live in @@ -13,7 +11,9 @@ the **composer footer** — always visible while composing. A circular context r shows token usage at a glance. All settings and session tools are in the **Hermes Control Center** (launcher at the sidebar bottom). -Hermes Web UI — three-panel layout +Setup Hermes so you can access it natively on every device: + +image @@ -47,6 +47,9 @@ This gives you nearly **1:1 parity with Hermes CLI from a convenient web UI** wh ## Contents +[image +](https://get-hermes.ai/setup/) + - [Why Hermes](#why-hermes) — what it is and how it compares - [Quick start](#quick-start) — clone + `bootstrap.py` / `start.sh` / `ctl.sh` - [Features](#features) — chat, sessions, workspace, voice, profiles, security, themes, panels, mobile From 1c70f7b987bb587a86baf9aa1a4b5845d12d37f2 Mon Sep 17 00:00:00 2001 From: nesquena-hermes Date: Thu, 9 Jul 2026 06:06:43 +0000 Subject: [PATCH 16/16] docs(changelog): #5803 session-load perf --- CHANGELOG.md | 2 ++ 1 file changed, 2 insertions(+) diff --git a/CHANGELOG.md b/CHANGELOG.md index 7d307fd0..0893a574 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -9,6 +9,8 @@ ### Fixed +- **Session loading is faster — addresses the "WebUI feels laggy" reports.** The session-load path (`/api/sessions` + session-by-id) had redundant full-metadata reads on every request; it now uses a profile-scoped, content-verified, lock-guarded cache (capped at 32 entries) with a fast path that only serves cached data when disk state is provably fresh, falling back to full comparison otherwise. Response shape and profile-scoping are unchanged. Thanks @Kopamed. (#5803, #5455) + - **The background-wakeup status-row label is now localized.** The "Background wakeup" label introduced with the wakeup status row (#5766) was hardcoded English; it now resolves through `t('process_wakeup_label')`, with translations in all 15 locales. Thanks @Isla-Liu. (#5768) - **Concurrent remote-gateway health checks no longer stampede the gateway.** When many requests needed a remote-gateway health probe at once, each fired its own probe (a thundering herd). Probes are now single-flighted: one "leader" thread probes while latecomers wait (bounded) and share the result, guarded by a single condition/lock with a `finally` that always releases waiters even if the probe errors. Thanks @ai-ag2026. (#5798, #5455)