-
-
Notifications
You must be signed in to change notification settings - Fork 29
Expand file tree
/
Copy pathplugin_health.py
More file actions
471 lines (409 loc) · 22.1 KB
/
Copy pathplugin_health.py
File metadata and controls
471 lines (409 loc) · 22.1 KB
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
179
180
181
182
183
184
185
186
187
188
189
190
191
192
193
194
195
196
197
198
199
200
201
202
203
204
205
206
207
208
209
210
211
212
213
214
215
216
217
218
219
220
221
222
223
224
225
226
227
228
229
230
231
232
233
234
235
236
237
238
239
240
241
242
243
244
245
246
247
248
249
250
251
252
253
254
255
256
257
258
259
260
261
262
263
264
265
266
267
268
269
270
271
272
273
274
275
276
277
278
279
280
281
282
283
284
285
286
287
288
289
290
291
292
293
294
295
296
297
298
299
300
301
302
303
304
305
306
307
308
309
310
311
312
313
314
315
316
317
318
319
320
321
322
323
324
325
326
327
328
329
330
331
332
333
334
335
336
337
338
339
340
341
342
343
344
345
346
347
348
349
350
351
352
353
354
355
356
357
358
359
360
361
362
363
364
365
366
367
368
369
370
371
372
373
374
375
376
377
378
379
380
381
382
383
384
385
386
387
388
389
390
391
392
393
394
395
396
397
398
399
400
401
402
403
404
405
406
407
408
409
410
411
412
413
414
415
416
417
418
419
420
421
422
423
424
425
426
427
428
429
430
431
432
433
434
435
436
437
438
439
440
441
442
443
444
445
446
447
448
449
450
451
452
453
454
455
456
457
458
459
460
461
462
463
464
465
466
467
468
469
470
"""
Plugin Health Tracker
Tracks plugin health metrics including success/failure rates, consecutive failures,
and circuit breaker state. Provides automatic recovery mechanisms.
"""
import time
from typing import Dict, Optional, Any, Tuple
from enum import Enum
from src.logging_config import get_logger
class CircuitState(Enum):
"""Circuit breaker states."""
CLOSED = "closed" # Normal operation
OPEN = "open" # Circuit open, skipping calls
HALF_OPEN = "half_open" # Testing if plugin recovered
class PluginHealthTracker:
"""
Tracks plugin health and manages circuit breaker state.
Circuit breaker pattern:
- CLOSED: Plugin is healthy, calls proceed normally
- OPEN: Plugin has failed too many times, calls are skipped
- HALF_OPEN: Testing if plugin has recovered (after cooldown)
"""
def __init__(self, cache_manager, failure_threshold: int = 3,
cooldown_period: float = 300.0, half_open_timeout: float = 60.0):
"""
Initialize plugin health tracker.
Args:
cache_manager: Cache manager instance for persistence
failure_threshold: Number of consecutive failures before opening circuit
cooldown_period: Seconds to wait before attempting recovery (default: 5 minutes)
half_open_timeout: Seconds to wait in half-open state before closing (default: 1 minute)
"""
self.cache_manager = cache_manager
self.failure_threshold = failure_threshold
self.cooldown_period = cooldown_period
self.half_open_timeout = half_open_timeout
self.logger = get_logger(__name__)
# In-memory health state (also persisted to cache)
self._health_state: Dict[str, Dict[str, Any]] = {}
def _get_health_key(self, plugin_id: str) -> str:
"""Get cache key for plugin health data."""
return f"plugin_health:{plugin_id}"
def _load_health_state(self, plugin_id: str, force_reload: bool = False) -> Dict[str, Any]:
"""Load health state from cache or return defaults.
``force_reload=True`` bypasses the cache manager's in-memory tier so a
read-only consumer (e.g. the web process) observes the writer process's
latest persisted state instead of a stale first snapshot.
"""
cache_key = self._get_health_key(plugin_id)
cached = self.cache_manager.get(
cache_key, max_age=None, memory_ttl=0 if force_reload else None
)
if isinstance(cached, dict) and cached:
# Complete it rather than trusting it: a persisted record can be
# missing fields the callers index directly (a partial write, a
# restored backup, an older schema), and returning it verbatim makes
# record_success / record_failure raise KeyError, which takes the
# display down in a restart loop that survives reboots because the
# bad entry is on disk.
state, repaired = self._repair_health_state(cached)
if repaired:
self.logger.warning(
f"Repaired health state for {plugin_id}: "
f"{sorted(repaired)} missing or invalid, using defaults for those."
)
return state
# Not a dict at all: written by something other than
# _save_health_state (a key collision, a corrupted entry). Nothing to
# salvage.
if cached is not None and not isinstance(cached, dict):
self.logger.warning(
f"Discarding malformed health state for {plugin_id}: expected "
f"dict, got {type(cached).__name__}. Falling back to defaults."
)
return self._default_health_state()
def _save_health_state(self, plugin_id: str, state: Dict[str, Any]) -> None:
"""Save health state to cache."""
cache_key = self._get_health_key(plugin_id)
self.cache_manager.set(cache_key, state) # Persist indefinitely
self._health_state[plugin_id] = state
# The fields callers index directly (state['circuit_state'] and friends).
# A cached dict missing any of them raises KeyError deep in record_success /
# record_failure, so the value is completed before it is handed out.
_COUNTER_FIELDS = ('consecutive_failures', 'total_failures', 'total_successes')
_TIMESTAMP_FIELDS = ('last_success_time', 'last_failure_time',
'circuit_opened_time', 'half_open_start_time')
@staticmethod
def _default_health_state() -> Dict[str, Any]:
"""A fresh state with every field the callers expect."""
return {
'consecutive_failures': 0,
'total_failures': 0,
'total_successes': 0,
'last_success_time': None,
'last_failure_time': None,
'circuit_state': CircuitState.CLOSED.value,
'circuit_opened_time': None,
'half_open_start_time': None,
'last_error': None,
}
@classmethod
def _repair_health_state(cls, cached: Dict[str, Any]) -> Tuple[Dict[str, Any], list]:
"""Return `cached` completed against the defaults, plus what was repaired.
Per-field rather than all-or-nothing: a record that has real failure
counts but is missing `last_error` should keep the counts, not be reset
to healthy. Only values that are absent or the wrong type fall back to
the default, so a partial or older-schema record survives with whatever
it does carry, while every field the callers index is guaranteed present
and of a usable type.
"""
state = cls._default_health_state()
repaired = []
for field, default in state.items():
if field not in cached:
repaired.append(field)
continue
value = cached[field]
if field in cls._COUNTER_FIELDS:
ok = isinstance(value, int) and not isinstance(value, bool) and value >= 0
elif field in cls._TIMESTAMP_FIELDS:
# bool is a subclass of int, so True would pass as a timestamp
# and then compare as 1.0 -- expiring a cooldown the instant it
# opens, or (False) making the elapsed check never fire.
ok = value is None or (
isinstance(value, (int, float)) and not isinstance(value, bool)
)
elif field == 'circuit_state':
# Membership first requires the value to be hashable: a list or
# dict here would raise TypeError out of the repair itself,
# which is the crash this whole path exists to prevent.
ok = isinstance(value, str) and value in {
member.value for member in CircuitState
}
else: # last_error
ok = value is None or isinstance(value, str)
if ok:
state[field] = value
else:
repaired.append(field)
# Anything the schema has since grown (degraded, degraded_reason) is
# read with .get() by its callers, so carry it through untouched.
for field, value in cached.items():
if field not in state:
state[field] = value
return state, repaired
def get_health_state(self, plugin_id: str, force_reload: bool = False) -> Dict[str, Any]:
"""Get current health state for a plugin.
``force_reload=True`` re-reads the persisted state from the cache,
bypassing the in-memory copy — needed by cross-process readers that
would otherwise be pinned to the first snapshot they loaded.
"""
if force_reload or plugin_id not in self._health_state:
self._health_state[plugin_id] = self._load_health_state(
plugin_id, force_reload=force_reload
)
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
state['last_success_time'] = current_time
# Update circuit state
if state['circuit_state'] == CircuitState.HALF_OPEN.value:
# Success in half-open state, close the circuit
state['circuit_state'] = CircuitState.CLOSED.value
state['half_open_start_time'] = None
self.logger.info(f"Plugin {plugin_id} recovered, circuit closed")
elif state['circuit_state'] == CircuitState.OPEN.value:
# Shouldn't happen, but handle it
state['circuit_state'] = CircuitState.CLOSED.value
state['circuit_opened_time'] = None
# 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)
current_time = time.time()
# Increment failure counters
state['consecutive_failures'] = state.get('consecutive_failures', 0) + 1
state['total_failures'] = state.get('total_failures', 0) + 1
state['last_failure_time'] = current_time
# Store error message
if error:
state['last_error'] = str(error)
# Check if we should open the circuit
if state['consecutive_failures'] >= self.failure_threshold:
if state['circuit_state'] == CircuitState.CLOSED.value:
state['circuit_state'] = CircuitState.OPEN.value
state['circuit_opened_time'] = current_time
self.logger.warning(
f"Plugin {plugin_id} circuit opened after {state['consecutive_failures']} consecutive failures"
)
elif state['circuit_state'] == CircuitState.HALF_OPEN.value:
# Failed again in half-open, reopen circuit
state['circuit_state'] = CircuitState.OPEN.value
state['circuit_opened_time'] = current_time
state['half_open_start_time'] = None
self.logger.warning(f"Plugin {plugin_id} failed in half-open state, circuit reopened")
self._save_health_state(plugin_id, state)
def record_hang(self, plugin_id: str, operation: str, seconds: float,
error: Optional[Exception] = None) -> None:
"""Record a display() or update() call that ran past its limit.
Counts as a failure, so the ordinary circuit breaker handles a plugin
that keeps hanging: after ``failure_threshold`` in a row it is skipped
by both the update scheduler and the display rotation until the
cooldown ends. The hang itself is kept alongside (``hang_count``,
``last_hang``) so the health API can tell "hung" from "raised".
Not for an update skipped because the plugin's lock stayed held: the
holder may be a healthy but long render (Vegas prefetch). That is
:meth:`record_busy_skip`, which never touches the breaker.
Args:
plugin_id: Plugin identifier
operation: What hung: ``"display"`` or ``"update"``.
seconds: How long it had been running when this was recorded.
error: The error to store as ``last_error``; one is built from
the other arguments when omitted.
"""
state = self.get_health_state(plugin_id)
count = state.get('hang_count')
state['hang_count'] = (count if isinstance(count, int) and not isinstance(count, bool)
else 0) + 1
state['last_hang'] = {
'operation': operation,
'seconds': round(float(seconds), 3),
'time': time.time(),
}
if error is None:
error = TimeoutError(f"{operation} still running after {seconds:.1f}s")
# record_failure saves the record, hang fields included.
self.record_failure(plugin_id, error)
#: Minimum seconds between persisting a plugin's slow-call or busy-skip
#: counters. The in-memory record is updated every time; a plugin that is
#: slow on every frame must not become an SD-card write per frame.
SLOW_CALL_PERSIST_INTERVAL = 60.0
def record_slow_call(self, plugin_id: str, operation: str, seconds: float) -> None:
"""Note a call that finished, but slowly. Reporting only.
Unlike :meth:`record_hang` this never touches the circuit breaker: a
slow display() still drew its frame.
"""
state = self.get_health_state(plugin_id)
count = state.get('slow_call_count')
state['slow_call_count'] = (count if isinstance(count, int) and not isinstance(count, bool)
else 0) + 1
now = time.time()
state['last_slow_call'] = {
'operation': operation,
'seconds': round(float(seconds), 3),
'time': now,
}
self._save_reporting_throttled('slow', plugin_id, state, now)
def record_busy_skip(self, plugin_id: str, operation: str, seconds: float) -> None:
"""Note a call skipped because the plugin's lock stayed held. Reporting only.
The update worker gives up on a plugin's lock after
``PluginManager.PLUGIN_LOCK_TIMEOUT``. Whatever held it may be healthy
-- Vegas prefetch holds the lock for a plugin's whole content render,
which on a slow Pi can take longer than that -- so like
:meth:`record_slow_call` this never touches the circuit breaker, the
failure streak or ``last_error``. A real hang is recorded by
:meth:`record_hang` where it is measured.
Args:
plugin_id: Plugin identifier
operation: What was skipped, e.g. ``"update lock wait"``.
seconds: How long the lock was waited on.
"""
state = self.get_health_state(plugin_id)
count = state.get('busy_skip_count')
state['busy_skip_count'] = (count if isinstance(count, int) and not isinstance(count, bool)
else 0) + 1
now = time.time()
state['last_busy_skip'] = {
'operation': operation,
'seconds': round(float(seconds), 3),
'time': now,
}
self._save_reporting_throttled('busy', plugin_id, state, now)
def _save_reporting_throttled(self, kind: str, plugin_id: str,
state: Dict[str, Any], now: float) -> None:
"""Persist a reporting-only change at most once per
SLOW_CALL_PERSIST_INTERVAL per plugin and ``kind``. The first one is
saved at once, so the web process (which reads the persisted record)
sees it; repeats in between stay in memory until the next save."""
saved_at = self.__dict__.setdefault('_reporting_saved_at', {})
last = saved_at.get((kind, plugin_id))
if last is None or now - last >= self.SLOW_CALL_PERSIST_INTERVAL:
saved_at[(kind, plugin_id)] = now
self._save_health_state(plugin_id, state)
def set_degraded(self, plugin_id: str, reason: Optional[str]) -> None:
"""Flag (or clear) a plugin as degraded without touching the circuit breaker.
Used for non-fatal issues — e.g. a config that no longer satisfies the
plugin's schema — that should be surfaced to the user but must NOT cause
the plugin to be skipped or counted as a runtime failure. Passing
``reason=None`` clears the flag. The write is skipped when nothing
actually changes, so calling this on every load is cheap.
Args:
plugin_id: Plugin identifier
reason: Human-readable reason string, or None to clear the flag
"""
state = self.get_health_state(plugin_id)
new_degraded = bool(reason)
new_reason = reason if reason else None
if state.get('degraded', False) == new_degraded and state.get('degraded_reason') == new_reason:
return # No change — avoid a redundant cache write
state['degraded'] = new_degraded
state['degraded_reason'] = new_reason
self._save_health_state(plugin_id, state)
def should_skip_plugin(self, plugin_id: str) -> bool:
"""
Check if plugin should be skipped due to circuit breaker.
Returns:
True if plugin should be skipped, False if it should be called
"""
state = self.get_health_state(plugin_id)
current_time = time.time()
circuit_state = state.get('circuit_state', CircuitState.CLOSED.value)
if circuit_state == CircuitState.CLOSED.value:
return False
if circuit_state == CircuitState.OPEN.value:
# Check if cooldown period has passed
circuit_opened_time = state.get('circuit_opened_time')
if circuit_opened_time and (current_time - circuit_opened_time) >= self.cooldown_period:
# Move to half-open state
state['circuit_state'] = CircuitState.HALF_OPEN.value
state['half_open_start_time'] = current_time
state['circuit_opened_time'] = None
self._save_health_state(plugin_id, state)
self.logger.info(f"Plugin {plugin_id} circuit moved to half-open state for testing")
return False # Allow one attempt
return True # Still in cooldown
if circuit_state == CircuitState.HALF_OPEN.value:
# In half-open state, allow calls but check timeout
half_open_start = state.get('half_open_start_time')
if half_open_start and (current_time - half_open_start) >= self.half_open_timeout:
# Timeout in half-open, close circuit if no failures
if state.get('consecutive_failures', 0) == 0:
state['circuit_state'] = CircuitState.CLOSED.value
state['half_open_start_time'] = None
self._save_health_state(plugin_id, state)
self.logger.info(f"Plugin {plugin_id} circuit closed after successful half-open period")
return False
return False # Allow calls in half-open
return False
def get_health_summary(self, plugin_id: str, force_reload: bool = False) -> Dict[str, Any]:
"""Get health summary for a plugin.
``force_reload=True`` refreshes from the persisted cache first so
cross-process readers reflect the writer's latest state.
"""
state = self.get_health_state(plugin_id, force_reload=force_reload)
total_calls = state.get('total_successes', 0) + state.get('total_failures', 0)
success_rate = 0.0
if total_calls > 0:
success_rate = state.get('total_successes', 0) / total_calls * 100
return {
'plugin_id': plugin_id,
'circuit_state': state.get('circuit_state', CircuitState.CLOSED.value),
'consecutive_failures': state.get('consecutive_failures', 0),
'total_failures': state.get('total_failures', 0),
'total_successes': state.get('total_successes', 0),
'success_rate': round(success_rate, 2),
'last_success_time': state.get('last_success_time'),
'last_failure_time': state.get('last_failure_time'),
'last_error': state.get('last_error'),
'is_healthy': state.get('circuit_state') == CircuitState.CLOSED.value,
'degraded': state.get('degraded', False),
'degraded_reason': state.get('degraded_reason'),
'circuit_opened_time': state.get('circuit_opened_time'),
'half_open_start_time': state.get('half_open_start_time'),
'hang_count': state.get('hang_count', 0),
'last_hang': state.get('last_hang'),
'slow_call_count': state.get('slow_call_count', 0),
'last_slow_call': state.get('last_slow_call'),
'busy_skip_count': state.get('busy_skip_count', 0),
'last_busy_skip': state.get('last_busy_skip'),
}
def get_all_health_summaries(self) -> Dict[str, Dict[str, Any]]:
"""Get health summaries for all tracked plugins."""
summaries = {}
for plugin_id in self._health_state.keys():
summaries[plugin_id] = self.get_health_summary(plugin_id)
return summaries
def reset_health(self, plugin_id: str) -> None:
"""Reset health state for a plugin (manual recovery)."""
state = self._load_health_state(plugin_id)
state['consecutive_failures'] = 0
state['circuit_state'] = CircuitState.CLOSED.value
state['circuit_opened_time'] = None
state['half_open_start_time'] = None
self._save_health_state(plugin_id, state)
self.logger.info(f"Health state reset for plugin {plugin_id}")