Skip to content
Closed
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
2 changes: 1 addition & 1 deletion src/common/scroll_helper.py
Original file line number Diff line number Diff line change
Expand Up @@ -328,7 +328,7 @@ def update_scroll_position(self) -> None:
elapsed_time = current_time - (self.scroll_start_time or current_time)
# The image already includes display_width padding, so we only need total_scroll_width
required_total_distance = self.total_scroll_width
self.logger.info(
self.logger.debug(
"Scroll progress: elapsed=%.2fs, target=%.2fs, total_scrolled=%.0f/%d px (%.1f%%)",
elapsed_time,
self.calculated_duration,
Expand Down
67 changes: 66 additions & 1 deletion src/logging_config.py
Original file line number Diff line number Diff line change
Expand Up @@ -130,7 +130,12 @@ def setup_logging(
# Console handler (always add)
console_handler = logging.StreamHandler(sys.stdout)
console_handler.setLevel(level)
console_handler.setFormatter(formatter)
# Under systemd, tag each line so the journal records the real severity
# rather than filing everything as informational. The file handler below
# keeps the plain formatter: the prefix is meaningful to journald and noise
# anywhere else.
console_handler.setFormatter(
JournalPriorityFormatter(formatter) if _under_systemd() else formatter)
root_logger.addHandler(console_handler)

# File handler (if specified)
Expand All @@ -145,6 +150,66 @@ def setup_logging(
sys.stderr.write(f"Warning: Could not set up file logging to {log_file}: {e}\n")


#: syslog priorities, which is what systemd parses from a "<N>" prefix on
#: stdout. Mapped from Python's levels.
_SYSLOG_PRIORITY = {
logging.CRITICAL: 2, # LOG_CRIT
logging.ERROR: 3, # LOG_ERR
logging.WARNING: 4, # LOG_WARNING
logging.INFO: 6, # LOG_INFO
logging.DEBUG: 7, # LOG_DEBUG
}


class JournalPriorityFormatter(logging.Formatter):
"""Wraps a formatter, prefixing each line with its syslog priority.

Under systemd everything this process writes to stdout lands in the journal
as PRIORITY=6, whatever the Python level was. Measured on a live rig: 55
ERROR lines and 13 WARNING lines in a day, every one of them recorded as
informational, so `journalctl -p err -u ledmatrix` returned nothing at all
while errors were being logged. Anyone triaging has to grep the message
text instead, which is both slower and wrong -- a search for "oom" matches
the radar logging "zoom=9".

systemd reads a leading "<N>" on each line and uses it as the priority
(sd-daemon(3)), so this needs no extra dependency. Multi-line records get
the prefix on every line, since the journal splits them and an unprefixed
continuation would fall back to the default.
"""

def __init__(self, inner: logging.Formatter):
super().__init__()
self._inner = inner

@property
def inner(self) -> logging.Formatter:
"""The formatter doing the actual work.

Whether journald tagging is applied depends on JOURNAL_STREAM, so it is
on under systemd and off in a terminal -- and anything asserting which
formatter setup_logging() selected would otherwise get a different
answer in CI than on a developer's machine. Exposing the inner one lets
those checks stay about format_type, which is what they mean.
"""
return self._inner

def format(self, record: logging.LogRecord) -> str:
text = self._inner.format(record)
prefix = f"<{_SYSLOG_PRIORITY.get(record.levelno, 6)}>"
return "\n".join(prefix + line for line in text.split("\n"))


def _under_systemd() -> bool:
"""True when stdout is the journal.

systemd sets JOURNAL_STREAM for services whose output it captures. Without
this check the "<N>" prefixes would show up as literal noise when the
program is run from a terminal, in the emulator, or in tests.
"""
return bool(os.environ.get("JOURNAL_STREAM"))


class PluginLoggerAdapter(logging.LoggerAdapter):
"""LoggerAdapter that stamps every record with its plugin_id.

Expand Down
29 changes: 25 additions & 4 deletions src/plugin_system/plugin_health.py
Original file line number Diff line number Diff line change
Expand Up @@ -178,11 +178,21 @@ def get_health_state(self, plugin_id: str, force_reload: bool = False) -> Dict[s
)
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
Expand All @@ -198,9 +208,20 @@ def record_success(self, plugin_id: str) -> None:
# 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)
Expand Down
Loading
Loading