Compare commits

..
Author SHA1 Message Date
ChuckBuildsandClaude Opus 5 dab4b3ea57 fix: use a monotonic clock and only mark metrics persisted once written
Two review findings on the throttle, both right.

The interval compared wall-clock timestamps. These devices have no RTC, so
the clock jumps by however far off boot-time was the moment NTP first syncs
-- a forward jump would allow an early write, a backward one would stall the
snapshot well past the interval. time.monotonic() is not subject to either.

The timestamp was also recorded before cache_manager.set(). A set() that
raised would buy the next interval's silence without leaving a snapshot
behind, which is the one case where skipping the write is least affordable.
Recorded after the write lands instead, so a failure is retried on the next
call.

Verified by restoring the original ordering: the new test then reports one
write where two are expected.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01STMbQE4YctTacQXfbYqKuW
2026-08-20 07:42:24 -04:00
ChuckBuildsandClaude Opus 5 0fd2bfae99 perf(plugins): stop rewriting a plugin's metrics file on every call
Plugin metrics were persisted to the cache inside monitor_call, so every
call by every plugin rewrote a small JSON file. Measured on a running rig:
one plugin's plugin_metrics file changed nine times a minute, with fourteen
such files active. Each is around 350 bytes, which on ext4 costs a 4KB block
plus a journal entry, so the cost is dominated by the write itself rather
than the payload. Cache writes accounted for essentially all of that device's
2.4 MB/min of SD traffic, on a card that wears out and has already failed
twice on the other rig.

Metrics cannot be de-duplicated the way health state can, because call_count
changes on every call and the timings usually do too. So they are rate-limited
instead: at most one write per plugin per 30 seconds.

The in-memory copy stays authoritative and exact -- a plugin's call_count is
still precise the instant after it runs. Only the cross-process snapshot the
web UI reads is delayed, and telemetry up to half a minute old is still a fair
description of a long-running plugin.

reset_metrics clears the throttle timestamp, so a reset is not left showing a
deleted key for the rest of the interval.

Extrapolating the sampled rate, this takes metric writes from roughly 126 a
minute to 28. Health persistence, the other half of the churn, is handled
separately in #475.

Verified by reverting the throttle: the churn test then reports 50 writes for
50 calls. 88 tests pass across resource monitor, plugin system and web API.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01STMbQE4YctTacQXfbYqKuW
2026-08-20 07:06:21 -04:00
7 changed files with 129 additions and 157 deletions
Binary file not shown.

Before

Width:  |  Height:  |  Size: 467 B

+54 -12
View File
@@ -49,6 +49,20 @@ class ResourceMetrics:
self.total_execution_time = self.total_execution_time / self.call_count
#: How often a plugin's metrics are written to the cache, in seconds.
#:
#: Persisting on every call meant a small file rewritten roughly nine times a
#: minute per plugin. On a rig with fourteen active plugins that was ~126
#: writes a minute for metrics alone, and since each ~350-byte file costs a
#: 4KB block plus an ext4 journal entry, it dominated the device's write
#: volume -- on an SD card, which wears out.
#:
#: The in-memory copy stays authoritative and exact; only the cross-process
#: snapshot the web UI reads is delayed, and telemetry up to half a minute old
#: is still a fair description of a long-running plugin.
_METRICS_PERSIST_INTERVAL = 30.0
class PluginResourceMonitor:
"""
Monitors resource usage for plugins.
@@ -75,6 +89,10 @@ class PluginResourceMonitor:
# Resource metrics per plugin
self._metrics: Dict[str, ResourceMetrics] = {}
self._limits: Dict[str, ResourceLimits] = {}
# When each plugin's metrics last reached the cache. Metrics change on
# every call, so they cannot be de-duplicated the way health state can;
# they are rate-limited instead. See _METRICS_PERSIST_INTERVAL.
self._metrics_persisted_at: Dict[str, float] = {}
# Thread-local storage for execution tracking
self._local = threading.local()
@@ -232,18 +250,8 @@ class PluginResourceMonitor:
# CPU is harder to measure per-call, so we track it separately
metrics.cpu_percent = self._get_process_cpu_percent()
# Persist metrics
cache_key = self._get_metrics_key(plugin_id)
self.cache_manager.set(cache_key, {
'memory_mb': metrics.memory_mb,
'cpu_percent': metrics.cpu_percent,
'execution_time': metrics.execution_time,
'call_count': metrics.call_count,
'total_execution_time': metrics.total_execution_time,
'max_execution_time': metrics.max_execution_time,
'min_execution_time': metrics.min_execution_time if metrics.min_execution_time != float('inf') else 0.0,
'last_update_time': metrics.last_update_time
})
# Persist metrics, at most once per interval per plugin.
self._persist_metrics(plugin_id, metrics)
# Check limits
if limits:
@@ -363,6 +371,37 @@ class PluginResourceMonitor:
summaries[plugin_id] = self.get_metrics_summary(plugin_id)
return summaries
def _persist_metrics(self, plugin_id: str, metrics: ResourceMetrics,
force: bool = False) -> None:
"""Write a plugin's metrics to the cache, at most once per interval.
Caller must hold ``self._lock``.
"""
# Monotonic, not wall clock: these devices have no RTC, so the clock
# jumps by however far off boot-time was the moment NTP first syncs.
# A forward jump would allow an early write, a backward one would
# stall the snapshot well past the interval.
now = time.monotonic()
if not force and now - self._metrics_persisted_at.get(plugin_id, 0.0) \
< _METRICS_PERSIST_INTERVAL:
return
cache_key = self._get_metrics_key(plugin_id)
self.cache_manager.set(cache_key, {
'memory_mb': metrics.memory_mb,
'cpu_percent': metrics.cpu_percent,
'execution_time': metrics.execution_time,
'call_count': metrics.call_count,
'total_execution_time': metrics.total_execution_time,
'max_execution_time': metrics.max_execution_time,
'min_execution_time': (metrics.min_execution_time
if metrics.min_execution_time != float('inf')
else 0.0),
'last_update_time': metrics.last_update_time,
})
# Only after the write lands. Marking it first would mean a failed
# set() bought the next interval's silence without leaving a snapshot.
self._metrics_persisted_at[plugin_id] = now
def reset_metrics(self, plugin_id: str) -> None:
"""Reset metrics for a plugin."""
with self._lock:
@@ -370,4 +409,7 @@ class PluginResourceMonitor:
self._metrics[plugin_id] = ResourceMetrics()
cache_key = self._get_metrics_key(plugin_id)
self.cache_manager.delete(cache_key)
# Let the next call persist immediately rather than leaving the
# deleted key absent for the rest of the interval.
self._metrics_persisted_at.pop(plugin_id, None)
+1 -34
View File
@@ -143,12 +143,6 @@ def mask_secret_fields(config: Dict[str, Any], schema_properties: Dict[str, Any]
return result
#: What a masked secret looks like on the wire. Named because the write path
#: has to recognise it coming back: a client that renders the mask and posts
#: it unchanged must not store the mask as if it were the secret.
SECRET_MASK = '\u2022' * 8
def mask_all_secret_values(config: Dict[str, Any]) -> Dict[str, Any]:
"""Blanket-mask every non-empty value in a secrets config dict.
@@ -167,7 +161,7 @@ def mask_all_secret_values(config: Dict[str, Any]) -> Dict[str, Any]:
if isinstance(v, dict):
masked[k] = mask_all_secret_values(v)
elif v not in (None, '') and not (isinstance(v, str) and v.startswith('YOUR_')):
masked[k] = SECRET_MASK
masked[k] = '••••••••'
else:
masked[k] = v
return masked
@@ -195,30 +189,3 @@ def remove_empty_secrets(secrets: Dict[str, Any]) -> Dict[str, Any]:
elif v is not None and not (isinstance(v, str) and v.strip() == ''):
result[k] = v
return result
def strip_masked_values(secrets: Dict[str, Any]) -> Dict[str, Any]:
"""Remove values a client echoed back rather than changed.
The counterpart to :func:`mask_all_secret_values`. A client that GETs the
masked secrets, edits one field and POSTs the whole object back is sending
``SECRET_MASK`` for every field it did not touch. Storing those would
replace each untouched credential with eight bullet characters.
Drops the mask and, like :func:`remove_empty_secrets`, blank values -- so
the caller can merge the result onto what is already stored and have
"unchanged" mean unchanged. Empty nested dicts are pruned.
"""
result: Dict[str, Any] = {}
for k, v in secrets.items():
if isinstance(v, dict):
nested = strip_masked_values(v)
if nested:
result[k] = nested
elif v is None:
continue
elif isinstance(v, str) and (v.strip() == '' or v == SECRET_MASK):
continue
else:
result[k] = v
return result
+64
View File
@@ -127,3 +127,67 @@ class TestForceReload:
fresh = mon.get_metrics_summary("p", force_reload=True)
assert fresh["call_count"] == 7
assert any(c.kwargs.get("memory_ttl") == 0 for c in cache.get.call_args_list)
class TestMetricsPersistenceChurn:
"""Metrics are telemetry; writing them on every call wore the SD card.
Each write is a ~350-byte file, which on ext4 costs a 4KB block plus a
journal entry. At roughly nine calls a minute per plugin across fourteen
plugins it dominated the device's write volume.
"""
def test_repeated_calls_persist_once_per_interval(self):
cache = _cache()
mon = PluginResourceMonitor(cache, enable_monitoring=False)
for _ in range(50):
mon.monitor_call("p", lambda: None)
writes = [c for c in cache.set.call_args_list
if c.args and str(c.args[0]).startswith("plugin_metrics:")]
assert len(writes) == 1, (
f"50 calls produced {len(writes)} metric writes; expected 1")
def test_the_interval_elapsing_allows_the_next_write(self, monkeypatch):
import src.plugin_system.resource_monitor as rm
cache = _cache()
mon = PluginResourceMonitor(cache, enable_monitoring=False)
mon.monitor_call("p", lambda: None)
# pretend the interval has passed
mon._metrics_persisted_at["p"] -= rm._METRICS_PERSIST_INTERVAL + 1
mon.monitor_call("p", lambda: None)
writes = [c for c in cache.set.call_args_list
if c.args and str(c.args[0]).startswith("plugin_metrics:")]
assert len(writes) == 2
def test_in_memory_metrics_stay_exact_while_writes_are_skipped(self):
mon = PluginResourceMonitor(_cache(), enable_monitoring=False)
for _ in range(20):
mon.monitor_call("p", lambda: None)
assert mon.get_metrics("p").call_count == 20
def test_reset_lets_the_next_call_persist_immediately(self):
cache = _cache()
mon = PluginResourceMonitor(cache, enable_monitoring=False)
mon.monitor_call("p", lambda: None)
mon.reset_metrics("p")
mon.monitor_call("p", lambda: None)
writes = [c for c in cache.set.call_args_list
if c.args and str(c.args[0]).startswith("plugin_metrics:")]
assert len(writes) == 2, "reset should clear the throttle timestamp"
def test_a_failed_write_does_not_buy_the_next_interval_of_silence(self):
"""A set() that raises must not count as having persisted.
Marking the timestamp before the write would leave no snapshot in the
cache and still suppress the next 30 seconds of attempts.
"""
cache = _cache()
cache.set.side_effect = [OSError("disk full"), None]
mon = PluginResourceMonitor(cache, enable_monitoring=False)
with pytest.raises(OSError):
mon.monitor_call("p", lambda: None)
# the very next call must try again rather than skip the interval
mon.monitor_call("p", lambda: None)
writes = [c for c in cache.set.call_args_list
if c.args and str(c.args[0]).startswith("plugin_metrics:")]
assert len(writes) == 2, "a failed write should be retried, not skipped"
@@ -1,82 +0,0 @@
"""GET /config/secrets must not hand out credentials, and the client's
read-modify-write cycle must not destroy them.
This interface has no authentication. The endpoint returned the whole
config_secrets.json to anyone who could reach the port; on one rig that was a
40-character GitHub token, a 183-character Home Assistant token and three API
keys. Masking it alone is not enough: the only client fetches every secret,
edits one field and posts all of them back, so the write path has to treat an
echoed mask as "unchanged".
"""
import json
import sys
from pathlib import Path
sys.path.insert(0, str(Path(__file__).parent))
from test_api_v3_secret_roundtrip import env, _on_disk # noqa: F401,E402
from src.web_interface.secret_helpers import SECRET_MASK # noqa: E402
STORED = {
"github": {"api_token": "ghp_" + "x" * 36},
"ledmatrix-weather": {"api_key": "w" * 32},
"incoming-packages": {"ha_token": "h" * 183},
"unset-plugin": {"api_key": ""},
"placeholder-plugin": {"api_key": "YOUR_API_KEY_HERE"},
}
def _seed(env):
env.secrets_file.write_text(json.dumps(STORED))
def _get(env):
r = env.client.get("/api/v3/config/secrets")
assert r.status_code == 200, r.get_data(as_text=True)[:200]
return r.get_json()["data"]
def test_no_credential_leaves_the_process(env):
_seed(env)
body = json.dumps(_get(env))
for secret in ("ghp_" + "x" * 36, "w" * 32, "h" * 183):
assert secret not in body, "endpoint returned a stored credential"
def test_set_and_unset_remain_distinguishable(env):
_seed(env)
data = _get(env)
assert data["github"]["api_token"] == SECRET_MASK
assert data["unset-plugin"]["api_key"] == ""
assert data["placeholder-plugin"]["api_key"] == "YOUR_API_KEY_HERE"
def test_the_clients_read_modify_write_preserves_every_other_secret(env):
"""What the GitHub-token save button actually does."""
_seed(env)
secrets = _get(env) # everything arrives masked
secrets["github"]["api_token"] = "ghp_" + "n" * 36 # user changes one
r = env.client.post("/api/v3/config/raw/secrets", json=secrets)
assert r.status_code == 200, r.get_data(as_text=True)[:200]
on_disk = _on_disk(env.secrets_file)
assert on_disk["github"]["api_token"] == "ghp_" + "n" * 36, "new token not saved"
assert on_disk["ledmatrix-weather"]["api_key"] == "w" * 32
assert on_disk["incoming-packages"]["ha_token"] == "h" * 183
def test_a_mask_echoed_back_is_never_stored(env):
_seed(env)
env.client.post("/api/v3/config/raw/secrets", json=_get(env))
on_disk = _on_disk(env.secrets_file)
assert SECRET_MASK not in json.dumps(on_disk), "the mask was stored as a secret"
assert on_disk["github"]["api_token"] == "ghp_" + "x" * 36
def test_a_brand_new_secret_can_still_be_added(env):
_seed(env)
env.client.post("/api/v3/config/raw/secrets",
json={"new-plugin": {"api_key": "brand-new"}})
on_disk = _on_disk(env.secrets_file)
assert on_disk["new-plugin"]["api_key"] == "brand-new"
assert on_disk["github"]["api_token"] == "ghp_" + "x" * 36
+4 -21
View File
@@ -21,8 +21,7 @@ logger = logging.getLogger(__name__)
# Import new infrastructure
from src.web_interface.api_helpers import success_response, error_response, validate_request_json
from src.web_interface.errors import ErrorCode
from src.web_interface.secret_helpers import (find_secret_fields, mask_all_secret_values,
separate_secrets, strip_masked_values)
from src.web_interface.secret_helpers import find_secret_fields, separate_secrets
from src.web_interface.error_handler import describe_exception, redact_text
from src.plugin_system.operation_types import OperationType
from src.web_interface.validators import (
@@ -1334,12 +1333,7 @@ def get_secrets_config():
return jsonify({'status': 'error', 'message': 'Config manager not initialized'}), 500
config = api_v3.config_manager.get_raw_file_content('secrets')
# This interface has no authentication, and this file is nothing but
# credentials. It was handing all of them to anyone who could reach
# the port. Values are masked; empty and YOUR_* placeholders are left
# alone so a client can still tell "set" from "not set".
return jsonify({'status': 'success',
'data': mask_all_secret_values(config)})
return jsonify({'status': 'success', 'data': config})
except Exception as e:
logger.error('Unhandled exception', exc_info=True)
return jsonify({'status': 'error', 'message': 'An error occurred; see logs for details', 'details': describe_exception(e)}), 500
@@ -1401,19 +1395,8 @@ def save_raw_secrets_config():
if not data:
return jsonify({'status': 'error', 'message': 'No data provided'}), 400
# The GET above masks what it returns, and this endpoint's only client
# reads the whole file, edits one field and posts all of it back. So
# most of what arrives here is the mask, echoed rather than changed --
# storing it verbatim would replace every untouched credential with
# eight bullets. Strip those, then merge onto what is already stored,
# which makes "unchanged" mean unchanged.
#
# The cost is that a secret can no longer be cleared by blanking it.
# That needs its own affordance; a control that erases credentials as
# a side effect of saving an unrelated one is not it.
current = api_v3.config_manager.get_raw_file_content('secrets') or {}
merged = deep_merge(current, strip_masked_values(data))
api_v3.config_manager.save_raw_file_content('secrets', merged)
# Save the secrets config
api_v3.config_manager.save_raw_file_content('secrets', data)
# Reload GitHub token in plugin store manager if it exists
if api_v3.plugin_store_manager:
+6 -8
View File
@@ -4622,17 +4622,15 @@ window.loadGithubToken = function() {
// Handle empty data (secrets file doesn't exist) - API returns {} in this case
const secrets = data.data || {};
const token = secrets.github?.api_token || '';
const configured = token && token !== 'YOUR_GITHUB_PERSONAL_ACCESS_TOKEN';
if (input) {
// The endpoint masks what it returns, so this never holds
// the real token -- and the field is deliberately left
// empty rather than filled with the mask, which would be
// saved verbatim the next time the user pressed Save.
input.value = '';
if (configured) {
showNotification('A GitHub token is saved. Enter a new one to replace it.', 'success');
if (token && token !== 'YOUR_GITHUB_PERSONAL_ACCESS_TOKEN') {
// Token exists and is valid
input.value = token;
showNotification('GitHub token loaded successfully', 'success');
} else {
// No token configured or placeholder value
input.value = '';
showNotification('No GitHub token configured. Enter a new token to save.', 'info');
}
}