Compare commits

..
Author SHA1 Message Date
ChuckBuilds 14abea2d24 perf(health): stop rewriting a health record on every healthy cycle
Every successful plugin update called record_success(), which persisted the
record unconditionally. In steady state the only fields that had changed were
total_successes and last_success_time -- a counter and a timestamp that
health_monitor surfaces for display and that nothing reads back after a
restart. Nothing alerts on the age of last_successful_update; it is carried in
the metrics dataclass and shown.

Measured on a rig running 24 plugins, all steady-state (0 consecutive
failures, circuit closed): a five-minute sample caught 22 health-file
rewrites, about 4.4 a minute or 6,300 a day. Each write is ~400 bytes through
cache_manager.set(), which writes a file per call, so each one costs a
filesystem block plus an ext4 journal write.

That lands on an SD card, where the unit of cost is an erase-block cycle
rather than the bytes involved, and where wear is what eventually kills the
card. Two cards have already failed on the other rig with the same
signature -- unreadable block device, EIO on exec, sshd unable to read its
host keys.

The circuit breaker still has to survive a restart, so the write is kept for
exactly the fields it is rebuilt from: consecutive_failures, circuit_state,
circuit_opened_time, half_open_start_time. A failure, a circuit opening and a
recovery are all still written the moment they happen. In-memory state is
updated every time either way, so the health API and web UI show what they
always did.

Tested: 100 healthy cycles now perform zero writes after the first, the
counters remain accurate in memory, and a failure, a recovery and a
half-open-to-closed transition each still reach disk. One test kills and
rebuilds the tracker from the cache to prove the breaker's state genuinely
survives what is no longer written.

Mutation-checked both ways: persisting unconditionally again fails the
steady-state test, and widening _DURABLE_FIELDS to include last_success_time
fails it too. The 46 existing health tests pass.
2026-08-19 20:35:02 -04:00
4 changed files with 141 additions and 52 deletions
+25 -4
View File
@@ -178,11 +178,21 @@ class PluginHealthTracker:
)
return self._health_state[plugin_id]
# Fields the circuit breaker is rebuilt from after a restart. Everything
# else in a health record is reporting, read only for display.
_DURABLE_FIELDS = ('consecutive_failures', 'circuit_state',
'circuit_opened_time', 'half_open_start_time')
def _durable(self, state: Dict[str, Any]) -> tuple:
"""The part of a health record whose loss would change behaviour."""
return tuple(state.get(field) for field in self._DURABLE_FIELDS)
def record_success(self, plugin_id: str) -> None:
"""Record a successful plugin execution."""
state = self.get_health_state(plugin_id)
current_time = time.time()
durable_before = self._durable(state)
# Reset consecutive failures
state['consecutive_failures'] = 0
state['total_successes'] = state.get('total_successes', 0) + 1
@@ -198,9 +208,20 @@ class PluginHealthTracker:
# Shouldn't happen, but handle it
state['circuit_state'] = CircuitState.CLOSED.value
state['circuit_opened_time'] = None
self._save_health_state(plugin_id, state)
# A healthy plugin reports success every cycle, and in that steady state
# the only fields changed above are a counter and a timestamp that
# nothing reads back after a restart. Persisting them anyway rewrites a
# small file per plugin per cycle: on a rig running 24 plugins, a
# five-minute sample measured 22 rewrites, about 4.4 a minute or 6,300 a
# day. Those land on an SD card, where the cost is an erase-block cycle
# rather than the 400 bytes involved, and where wear is what eventually
# kills the card.
# In-memory state is still updated every time, so the health API and web
# UI show exactly what they did before; only the write is skipped.
if self._durable(state) != durable_before:
self._save_health_state(plugin_id, state)
def record_failure(self, plugin_id: str, error: Optional[Exception] = None) -> None:
"""Record a failed plugin execution."""
state = self.get_health_state(plugin_id)
+110
View File
@@ -0,0 +1,110 @@
"""A healthy plugin must not rewrite its health record every cycle.
Every successful plugin update called record_success(), which persisted the
record unconditionally. In steady state the only fields that had changed were
total_successes and last_success_time -- a counter and a timestamp that
health_monitor reads for display and that nothing reads back after a restart.
Measured on a rig running 24 plugins: about 17 health-file rewrites a minute,
roughly 25,000 a day. Each is ~400 bytes, but they land on an SD card where
the unit of cost is an erase-block cycle, not the byte count, and where wear is
what eventually kills the card.
The circuit breaker still needs its own state to survive a restart, so the
write is kept for exactly the fields it is rebuilt from -- and a failure, a
circuit opening, or a recovery must still be written the moment it happens.
"""
import time
import pytest
from src.plugin_system.plugin_health import PluginHealthTracker, CircuitState
class _Cache:
"""Counts writes; serves back whatever was last written."""
def __init__(self):
self.store = {}
self.writes = 0
def set(self, key, data, ttl=None, **kwargs):
self.writes += 1
self.store[key] = data
def get(self, key, max_age=None, memory_ttl=None, **kwargs):
return self.store.get(key)
@pytest.fixture
def tracker():
cache = _Cache()
t = PluginHealthTracker(cache_manager=cache)
return t, cache
def test_steady_state_success_stops_writing(tracker):
"""The regression: 100 healthy cycles used to be 100 SD writes."""
t, cache = tracker
t.record_success("weather")
first = cache.writes
for _ in range(100):
t.record_success("weather")
assert cache.writes == first, (
f"{cache.writes - first} redundant writes across 100 healthy cycles"
)
def test_the_counters_are_still_accurate_in_memory(tracker):
"""Skipping the write must not skip the bookkeeping."""
t, _ = tracker
for _ in range(10):
t.record_success("weather")
state = t.get_health_state("weather")
assert state["total_successes"] == 10
assert state["last_success_time"] is not None
assert state["last_success_time"] <= time.time()
def test_a_failure_is_written_immediately(tracker):
t, cache = tracker
t.record_success("weather")
before = cache.writes
t.record_failure("weather", RuntimeError("boom"))
assert cache.writes > before, "a failure must reach disk"
def test_recovery_after_failure_is_written(tracker):
"""consecutive_failures returning to 0 is durable state changing."""
t, cache = tracker
t.record_failure("weather", RuntimeError("boom"))
before = cache.writes
t.record_success("weather")
assert cache.writes > before, "recovery must reach disk"
assert t.get_health_state("weather")["consecutive_failures"] == 0
def test_a_closing_circuit_is_written(tracker):
"""Success in half-open closes the circuit -- that must survive a restart."""
t, cache = tracker
state = t.get_health_state("weather")
state["circuit_state"] = CircuitState.HALF_OPEN.value
state["half_open_start_time"] = time.time()
before = cache.writes
t.record_success("weather")
assert cache.writes > before, "a circuit transition must reach disk"
assert t.get_health_state("weather")["circuit_state"] == CircuitState.CLOSED.value
def test_durable_state_survives_a_restart(tracker):
"""What is skipped must genuinely not matter to the breaker."""
t, cache = tracker
for _ in range(3):
t.record_failure("weather", RuntimeError("boom"))
for _ in range(50):
t.record_success("weather")
revived = PluginHealthTracker(cache_manager=cache)
state = revived.get_health_state("weather")
assert state["consecutive_failures"] == 0
assert state["circuit_state"] == CircuitState.CLOSED.value
@@ -194,46 +194,15 @@ class TestSavePluginConfig:
def test_secret_count_message_counts_top_level_keys(self, env):
# Pinned: the "(N secret field(s))" message counts TOP-LEVEL keys of
# the separated secrets dict. Here that is 1: the posted accounts
# array, whose item tokens all count as ONE key.
#
# It was 2 before blank secrets were dropped, the second being the
# schema's api_key default (""), which merge_with_defaults adds to
# every save. Counting it was the visible edge of a real bug: that
# injected blank was merged over the stored api_key, so saving any
# unrelated field destroyed the credential. See
# test_an_unrelated_edit_does_not_erase_a_stored_secret.
# the separated secrets dict. Here that is 2: the posted accounts
# array (all its item tokens count as ONE key) plus the schema's
# api_key default ("") that merge_with_defaults adds before
# separation.
resp = self._save(env, {
"accounts": [{"name": "a", "token": "t"}],
})
message = resp.get_json()["message"]
assert "(1 secret field(s) saved to config_secrets.json)" in message
def test_an_unrelated_edit_does_not_erase_a_stored_secret(self, env):
"""Editing one field must not wipe the plugin's API key.
The config form renders secrets masked, so the browser posts them
back blank; merge_with_defaults injects a blank api_key even when
the client omits it entirely. Either way a "" reached the secrets
file and deep_merge wrote it over the stored credential.
"""
assert self._save(env, {"api_key": "REAL-KEY-0123456789",
"city": "Austin"}).status_code == 200
assert _on_disk(env.secrets_file)[PLUGIN_ID]["api_key"] == \
"REAL-KEY-0123456789"
# the user changes the city; the masked api_key rides along blank
assert self._save(env, {"api_key": "", "city": "Dallas"}).status_code == 200
assert _on_disk(env.secrets_file)[PLUGIN_ID]["api_key"] == \
"REAL-KEY-0123456789", "an unrelated edit destroyed the API key"
assert env.fresh_load()[PLUGIN_ID]["city"] == "Dallas"
def test_a_secret_can_still_be_changed(self, env):
"""Dropping blanks must not stop a real new value from being saved."""
self._save(env, {"api_key": "first-key"})
self._save(env, {"api_key": "second-key"})
assert _on_disk(env.secrets_file)[PLUGIN_ID]["api_key"] == "second-key"
assert "(2 secret field(s) saved to config_secrets.json)" in message
def test_resave_replaces_stored_secrets_list_wholesale(self, env):
# Characterized: api_v3's deep_merge intentionally replaces lists,
+1 -12
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, remove_empty_secrets,
separate_secrets)
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 (
@@ -1217,11 +1216,6 @@ def save_main_config():
# Separate secrets from regular config (same logic as save_plugin_config)
regular_config, secrets_config = separate_secrets(plugin_config, secret_fields)
# The config form renders secrets masked, so every save posts
# them back blank. Without this the blank is merged over the
# stored value and the credential is destroyed by the act of
# changing an unrelated setting. A blank means "unchanged".
secrets_config = remove_empty_secrets(secrets_config)
# PRE-PROCESSING: Preserve 'enabled' state if not in regular_config
# This prevents overwriting the enabled state when saving config from a form that doesn't include the toggle
@@ -5605,11 +5599,6 @@ def save_plugin_config():
# Separate secrets from regular config (handles nested configs and
# array-item secrets — see src/web_interface/secret_helpers.py)
regular_config, secrets_config = separate_secrets(plugin_config, secret_fields)
# The config form renders secrets masked, so every save posts
# them back blank. Without this the blank is merged over the
# stored value and the credential is destroyed by the act of
# changing an unrelated setting. A blank means "unchanged".
secrets_config = remove_empty_secrets(secrets_config)
# Get current configs
current_config = api_v3.config_manager.load_config()