perf: cut avoidable SD writes and per-cycle log volume - #468
Conversation
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. (cherry picked from commit 14abea2)
plugin_adapter narrates every step of acquiring content from every plugin --
"Has get_vegas_content", "Native: calling get_vegas_content()", "Native
content returned None", "Has scroll_helper", per-item sizes -- once per plugin
per cycle, all at INFO.
Measured on a live rig: 13,408 log lines an hour, of which 13,366 were INFO
and 35 were WARNING. Roughly 223 lines a minute of string formatting on a Pi
that is also driving the panel, written through journald to the SD card, with
the 35 lines that actually indicate a problem buried among them.
Top repeated messages in that hour:
717 Scroll progress: elapsed=... total_scrolled=.../... px
399 [plugin] --> INCLUDED in Vegas scroll
323 [plugin] content_type=static, display_mode=fixed
195 [plugin] Has get_vegas_content: True
195 [plugin] Native: calling get_vegas_content()
168 [plugin] Native: get_vegas_content() returned None
168 [plugin] Native content returned None <- the same fact, twice
54 logger.info calls in plugin_adapter become logger.debug, along with the
per-frame scroll-progress line in scroll_helper. Together those are 3,174 of
the 13,408 lines an hour, a 23% cut, and the ~3,600 odds-manager lines are
addressed separately by ledmatrix-plugins#300.
Nothing is lost: the 19 warning/error/exception calls in the module are
untouched, so real failures still surface at their own level. This is a
logging-level change only -- no control flow, no behaviour.
One INFO call is deliberate and stays. The padding-strip message picks its
level at runtime (`logger.warning if (left and right) else logger.info`) and
test_vegas_plugin_adapter.py pins that choice; it survives because it is not a
direct logger.info call site. That test still passes.
Mutation-checked both ways: reintroducing a single INFO trace fails the guard,
and demoting the warning/error calls along with the trace fails a second guard
written for exactly that mistake. 537 vegas and scroll tests pass.
(cherry picked from commit e496d95)
|
Warning Review limit reached
Next review available in: 6 minutes Limit details: You’ve used the included review currently available. You've used all free OSS reviews for now. Wait for the free limit to reset to keep reviewing this public repository. How can I continue?Wait for the limit to reset, then comment An organization admin can change what happens after included review limits in Billing. How do review limits work?CodeRabbit enforces per-developer PR review limits within each organization. For paid Pro and Pro+ reviews, CodeRabbit uses a developer's included PR review attempts over the past 7 days to set the current hourly allowance. At typical activity levels, the full plan allowance applies. Higher sustained activity can lower the allowance until earlier attempts leave the 7-day window. Please refer docs for additional details. Review details⚙️ Run configurationConfiguration used: Organization UI Review profile: CHILL Plan: Pro Plus Run ID: 📒 Files selected for processing (5)
Thanks for using CodeRabbit! It's free for OSS, and your support helps us grow. If you like it, consider giving us a shout-out. Comment |
Up to standards ✅🟢 Issues
|
| Metric | Results |
|---|---|
| Complexity | 0 |
| Duplication | 0 |
NEW Get contextual insights on your PRs based on Codacy's metrics, along with PR and Jira context, without leaving GitHub. Enable AI reviewer
TIP This summary will be updated as you push new changes.
|
Superseded by #475, which carries both commits unchanged (cherry-picked with |
1 participant
Consolidates #466 and #467 into one review, to spare CodeRabbit two passes. Both commits are unchanged and cherry-picked with
-x; the originals will be closed pointing here.Two independent findings from measuring a live rig. They touch disjoint files —
plugin_health.pyfor one,plugin_adapter.py/scroll_helper.pyfor the other — so they can be reviewed separately even though they arrive together.1. A health record was rewritten on every healthy cycle
record_success()fires on every successful plugin update and persisted unconditionally. In steady state the only changed fields weretotal_successesandlast_success_time— a counter and a timestamp thathealth_monitorshows and that nothing reads back after a restart.Measured on a rig with 24 plugins, all steady-state: a five-minute sample caught 22 rewrites, ~4.4/min, ~6,300/day.
Each write is ~400 bytes through
cache_manager.set(), which writes a file per call — so a filesystem block plus an ext4 journal write. On SD the unit of cost is an erase-block cycle, not bytes.Persisting is now limited to the four fields the circuit breaker is rebuilt from. Failures, circuit openings and recoveries still write immediately; in-memory state is untouched, so the health API and UI are unchanged.
Checked and deliberately not changed:
plugin_metrics:*churns at the same cadence and looked like the same fix. It isn't — the web service builds its ownPluginResourceMonitorover the shared cache (app.py:189), so that write is the cross-process transport, and per plugin it already writes exactly once per cycle. Already at its floor.2. The Vegas content path traced at INFO
13,408 log lines/hour — 13,366 INFO, 35 WARNING, 5 ERROR. ~223 lines/min of string formatting on a Pi that is also driving the panel, written through journald to the SD card, burying the 35 lines that mean something.
54
logger.info→logger.debuginplugin_adapter, plus the per-frame scroll-progress line. 13,408 → 10,234 lines/hour, a 23% cut. Level change only.The 19 warning/error/exception calls are untouched. One INFO call is deliberate and stays — the padding-strip message picks its level at runtime and
test_vegas_plugin_adapter.pypins it; I found that test before making the change, not after.Verification
599 tests pass across the health, vegas and scroll suites on the combined branch.
Mutation-checked, four ways:
_DURABLE_FIELDSto includelast_success_time🤖 Generated with Claude Code
https://claude.ai/code/session_01STMbQE4YctTacQXfbYqKuW