fix(config): stop provider-key warn-storm that stalls Windows logging

_normalize_custom_provider_entry() runs on every load_picker_context()
call (per picker/inventory request) and warned each time for (a) the
redundant `provider` key that Hermes' own config writer emits into
provider entries and (b) any other unknown key. On Windows the serve
launcher+worker pair share one rotating log via concurrent-log-handler's
cross-process lock, so that per-load warning volume drove 'Cannot acquire
lock after 20 attempts' retries that pegged a core, stalled the event
loop ~14s, and dropped every desktop/TUI WebSocket while /health stayed
green (gateway looked down; dashboard looked fine).

- Accept `provider` as a known key (silently ignored) so self-written
  legacy configs don't warn.
- Deduplicate the normalizer's warnings per (provider, signature) so a
  static config quirk is surfaced once, not on every inventory load.

Adds regression tests for both.

Fixes #58265
This commit is contained in:
lEWFkRAD 2026-07-04 08:39:28 -04:00 committed by kshitij
parent 7e8f50a141
commit af01b3cb38
2 changed files with 77 additions and 3 deletions

View file

@ -4470,6 +4470,26 @@ def get_missing_skill_config_vars() -> List[Dict[str, Any]]:
return missing
# ``_normalize_custom_provider_entry`` runs on every ``load_picker_context()``
# call (i.e. per interactive picker/inventory request), so any warning it emits
# fires repeatedly for the same static config. Deduplicate per (provider,
# signature): on Windows a repeated-warning storm contends on
# ``concurrent-log-handler``'s cross-process rotation lock and can peg a core /
# stall the gateway/serve event loop. The cache lives for the process lifetime.
_PROVIDER_NORMALIZE_WARNED: set = set()
def _warn_once_per_provider(
provider_key: str, signature: str, msg: str, *args: Any
) -> None:
"""Emit ``logger.warning(msg, *args)`` at most once per (provider, signature)."""
dedup_key = (provider_key or "?", signature)
if dedup_key in _PROVIDER_NORMALIZE_WARNED:
return
_PROVIDER_NORMALIZE_WARNED.add(dedup_key)
logger.warning(msg, *args)
def _normalize_custom_provider_entry(
entry: Any,
*,
@ -4496,6 +4516,11 @@ def _normalize_custom_provider_entry(
if "api_key_env" in entry and "key_env" not in entry:
entry["key_env"] = entry["api_key_env"]
_KNOWN_KEYS = {
# ``provider`` duplicates the ``providers.<name>`` mapping key and is
# unused here, but Hermes' own config writer has historically emitted it
# into provider entries. Accept it silently so those (self-written)
# configs don't warn on every load.
"provider",
"name", "api", "url", "base_url", "api_key", "key_env", "api_key_env",
"api_mode", "transport", "model", "default_model", "models",
"context_length", "rate_limit_delay",
@ -4505,7 +4530,8 @@ def _normalize_custom_provider_entry(
}
for camel, snake in _CAMEL_ALIASES.items():
if camel in entry and snake not in entry:
logger.warning(
_warn_once_per_provider(
provider_key, f"camel:{camel}",
"providers.%s: camelCase key '%s' auto-mapped to '%s' "
"(use snake_case to avoid this warning)",
provider_key or "?", camel, snake,
@ -4513,7 +4539,8 @@ def _normalize_custom_provider_entry(
entry[snake] = entry[camel]
unknown = set(entry.keys()) - _KNOWN_KEYS - set(_CAMEL_ALIASES.keys())
if unknown:
logger.warning(
_warn_once_per_provider(
provider_key, "unknown:" + ",".join(sorted(unknown)),
"providers.%s: unknown config keys ignored: %s",
provider_key or "?", ", ".join(sorted(unknown)),
)

View file

@ -6,13 +6,26 @@ accepted as base_url, and unknown keys go unreported.
import logging
import pytest
from hermes_cli.config import _normalize_custom_provider_entry
from hermes_cli.config import (
_PROVIDER_NORMALIZE_WARNED,
_normalize_custom_provider_entry,
)
class TestNormalizeCustomProviderEntry:
"""Tests for _normalize_custom_provider_entry validation."""
@pytest.fixture(autouse=True)
def _reset_warn_cache(self):
"""The normalizer deduplicates its warnings via a process-lifetime
cache; clear it around each test so warning assertions are independent
of test order."""
_PROVIDER_NORMALIZE_WARNED.clear()
yield
_PROVIDER_NORMALIZE_WARNED.clear()
def test_valid_entry_snake_case(self):
"""Standard snake_case entry should normalize correctly."""
entry = {
@ -89,6 +102,40 @@ class TestNormalizeCustomProviderEntry:
assert result is not None
assert any("unknown config keys" in r.message.lower() for r in caplog.records)
def test_provider_key_not_flagged_unknown(self, caplog):
"""A redundant ``provider`` key (written by Hermes' own config writer)
must be accepted silently not reported as an unknown key. Regression
for the config warn-storm that deadlocked Windows logging."""
entry = {
"provider": "",
"base_url": "https://api.example.com/v1",
"api_key": "***",
}
with caplog.at_level(logging.WARNING):
result = _normalize_custom_provider_entry(entry, provider_key="onyx-6000")
assert result is not None
assert not any("unknown config keys" in r.message.lower() for r in caplog.records)
def test_unknown_keys_warned_once_per_signature(self, caplog):
"""Repeated normalization of the same entry (as happens on every
picker/inventory load) must warn only once otherwise the warning
storms the log handler. Fix B."""
entry = {
"base_url": "https://api.example.com/v1",
"api_key": "***",
"unknownField": "value",
}
with caplog.at_level(logging.WARNING):
for _ in range(5):
_normalize_custom_provider_entry(
dict(entry), provider_key="test"
)
unknown_warnings = [
r for r in caplog.records
if "unknown config keys" in r.message.lower()
]
assert len(unknown_warnings) == 1
def test_timeout_keys_not_flagged_unknown(self, caplog):
"""request_timeout_seconds and stale_timeout_seconds should not produce warnings."""
entry = {