Compare commits

..
Author SHA1 Message Date
ChuckBuildsandClaude Opus 5 f0efdafbdb fix(web): stop dumping the config and request headers to the journal
save_main_config logged its entire POST body and the full request headers at
ERROR on every save. The body is the configuration itself, and the headers
carry the session cookie, so a routine settings change wrote both to the
journal -- at a level that guarantees they survive any sane log filter.

The lines are leftover debug output: they say "DEBUG:" in the message while
calling logging.error, and they went through the root logger rather than the
module logger, bypassing the level configured for this blueprint.

Replaced with a debug-level line recording the shape of the request, which is
the part with diagnostic value. The local `import logging` went with them; it
shadowed a module-level import that was already there.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01STMbQE4YctTacQXfbYqKuW
2026-08-20 05:55:45 -04:00
3 changed files with 8 additions and 150 deletions
+2 -46
View File
@@ -9,7 +9,7 @@ import time
import logging import logging
import threading import threading
from typing import Dict, Optional, Any, Callable from typing import Dict, Optional, Any, Callable
from dataclasses import dataclass, field, fields from dataclasses import dataclass, field
try: try:
import psutil import psutil
@@ -102,50 +102,6 @@ class PluginResourceMonitor:
"psutil not available - resource monitoring will be limited to execution time only" "psutil not available - resource monitoring will be limited to execution time only"
) )
def _metrics_from_cache(self, plugin_id: str, cached: Any) -> "ResourceMetrics":
"""Build metrics from a cached record, ignoring anything unrecognised.
ResourceMetrics(**cached) raises TypeError on a single unexpected key,
and that exception escapes into plugin_manager, which reports it as
"plugin <id> operation failed". Every plugin fails, and the plugin
system never finishes initialising.
Seen on a live rig: every plugin failing with
ResourceMetrics.__init__() got an unexpected keyword argument
'consecutive_failures'
which is a plugin_health field, not a metrics one. How a health-shaped
record came to sit under a plugin_metrics key on that machine is not
established -- a restored backup that mixed two machines' caches is the
likeliest explanation -- but the loader should not be brittle enough for
it to matter. plugin_health already repairs its records field by field
rather than trusting whatever is on disk; this does the same.
Unknown keys are dropped and named once, so a genuine schema change is
visible in the log instead of silently discarded.
"""
if not isinstance(cached, dict):
self.logger.warning(
"Ignoring cached metrics for %s: expected a mapping, got %s",
plugin_id, type(cached).__name__)
return ResourceMetrics()
known = {f.name for f in fields(ResourceMetrics)}
unknown = sorted(set(cached) - known)
if unknown:
self.logger.warning(
"Dropping unrecognised field(s) from cached metrics for %s: %s",
plugin_id, ", ".join(unknown))
usable = {k: v for k, v in cached.items() if k in known}
try:
return ResourceMetrics(**usable)
except (TypeError, ValueError) as e:
self.logger.warning(
"Cached metrics for %s unusable (%s); starting fresh",
plugin_id, e)
return ResourceMetrics()
def _get_metrics_key(self, plugin_id: str) -> str: def _get_metrics_key(self, plugin_id: str) -> str:
"""Get cache key for plugin metrics.""" """Get cache key for plugin metrics."""
return f"plugin_metrics:{plugin_id}" return f"plugin_metrics:{plugin_id}"
@@ -170,7 +126,7 @@ class PluginResourceMonitor:
cache_key, max_age=None, memory_ttl=0 if force_reload else None cache_key, max_age=None, memory_ttl=0 if force_reload else None
) )
if cached: if cached:
metrics = self._metrics_from_cache(plugin_id, cached) metrics = ResourceMetrics(**cached)
else: else:
metrics = ResourceMetrics() metrics = ResourceMetrics()
self._metrics[plugin_id] = metrics self._metrics[plugin_id] = metrics
-100
View File
@@ -1,100 +0,0 @@
"""A malformed metrics cache entry must not take every plugin down with it.
`ResourceMetrics(**cached)` raises TypeError on a single unexpected key, and
that exception escapes into plugin_manager, which reports it per plugin as
"plugin <id> operation failed". Every plugin fails and the plugin system never
finishes initialising -- the health endpoint reports
`plugin_system: not_initialized` while the display itself keeps running.
Seen on a live rig, once per plugin, continuously:
ERROR - src.plugin_system.plugin_manager - plugin geochron operation failed:
ResourceMetrics.__init__() got an unexpected keyword argument
'consecutive_failures'
`consecutive_failures` belongs to plugin_health, not to metrics. How a
health-shaped record came to sit under a plugin_metrics key on that machine is
not established -- a restored backup that mixed two machines' caches is the
likeliest explanation, and the same rig had one restored onto it -- but a
loader that turns one bad cache entry into a total outage is the part worth
fixing. plugin_health already repairs its own records field by field rather
than trusting what is on disk.
"""
import logging
from dataclasses import fields
from unittest.mock import MagicMock
import pytest
from src.plugin_system.resource_monitor import PluginResourceMonitor, ResourceMetrics
class _Cache:
def __init__(self, payload=None):
self.payload = payload
def get(self, key, max_age=None, memory_ttl=None, **kwargs):
return self.payload
def set(self, key, data, ttl=None, **kwargs):
pass
def _monitor(payload):
m = PluginResourceMonitor(cache_manager=_Cache(payload))
m.logger = logging.getLogger("test")
return m
#: What the rig actually had under the metrics key.
HEALTH_SHAPED = {
"consecutive_failures": 0, "circuit_state": "closed",
"circuit_opened_time": None, "half_open_start_time": None,
"last_error": None, "last_failure_time": None,
"last_success_time": 1_700_000_000.0, "total_failures": 0,
"total_successes": 42,
}
def test_a_health_record_under_the_metrics_key_does_not_raise():
"""The exact failure: it must degrade, not take the plugin system down."""
monitor = _monitor(HEALTH_SHAPED)
metrics = monitor.get_metrics(" plugin-a".strip())
assert isinstance(metrics, ResourceMetrics)
def test_recognised_fields_in_a_mixed_record_are_kept():
"""Dropping the record wholesale would lose real history unnecessarily."""
mixed = dict(HEALTH_SHAPED, call_count=7, memory_mb=12.5)
metrics = _monitor(mixed).get_metrics("plugin-b")
assert metrics.call_count == 7
assert metrics.memory_mb == 12.5
def test_a_clean_record_still_loads_unchanged():
clean = {f.name: 3 for f in fields(ResourceMetrics)}
metrics = _monitor(clean).get_metrics("plugin-c")
for name in (f.name for f in fields(ResourceMetrics)):
assert getattr(metrics, name) == 3
def test_unknown_fields_are_named_in_the_log(caplog):
"""Silently discarding them would hide a real schema change."""
with caplog.at_level(logging.WARNING):
_monitor(HEALTH_SHAPED).get_metrics("plugin-d")
# getMessage(), not .message: the latter is only populated once a handler
# formats the record, so the obvious spelling silently never matches.
assert any("consecutive_failures" in r.getMessage() for r in caplog.records), \
caplog.text
@pytest.mark.parametrize("payload", ["a string", 42, ["a", "list"]])
def test_a_non_mapping_cache_entry_does_not_raise(payload):
metrics = _monitor(payload).get_metrics("plugin-e")
assert isinstance(metrics, ResourceMetrics)
def test_values_of_the_wrong_type_do_not_raise():
"""A dataclass will accept these, but a later float() on them would not."""
metrics = _monitor({"call_count": "not a number"}).get_metrics("plugin-f")
assert isinstance(metrics, ResourceMetrics)
+6 -4
View File
@@ -715,10 +715,12 @@ def save_main_config():
if not data: if not data:
return jsonify({'status': 'error', 'message': 'No data provided'}), 400 return jsonify({'status': 'error', 'message': 'No data provided'}), 400
import logging # What arrives here is the config itself, and the headers carry the
logging.error(f"DEBUG: save_main_config received data: {data}") # session cookie -- neither belongs in the journal, least of all at
logging.error(f"DEBUG: Content-Type header: {request.content_type}") # ERROR on every save. The shape of the request is the part with
logging.error(f"DEBUG: Headers: {dict(request.headers)}") # diagnostic value, so log that, at the level it deserves.
logger.debug("save_main_config: %s, %d top-level key(s)",
request.content_type or 'no content-type', len(data))
# Merge with existing config (similar to original implementation) # Merge with existing config (similar to original implementation)
current_config = api_v3.config_manager.load_config() current_config = api_v3.config_manager.load_config()