mirror of
https://github.com/ChuckBuilds/LEDMatrix.git
synced 2026-08-22 02:48:15 +00:00
Compare commits
5
Commits
| Author | SHA1 | Date | |
|---|---|---|---|
|
|
b7cf94f20a | ||
|
|
863e4a1ecd | ||
|
|
9c0c0dc851 | ||
|
|
71739d85d1 | ||
|
|
cc258aaffd |
Binary file not shown.
|
After Width: | Height: | Size: 467 B |
Regular → Executable
@@ -100,10 +100,15 @@ TEMP_SUDOERS="/tmp/ledmatrix_web_sudoers_$$"
|
|||||||
echo "$WEB_USER ALL=(ALL) NOPASSWD: $SYSTEMCTL_PATH restart ledmatrix-web.service"
|
echo "$WEB_USER ALL=(ALL) NOPASSWD: $SYSTEMCTL_PATH restart ledmatrix-web.service"
|
||||||
|
|
||||||
# Optional: journalctl (non-critical — skip if not found)
|
# Optional: journalctl (non-critical — skip if not found)
|
||||||
|
#
|
||||||
|
# NOEXEC, matching first_time_install.sh. These rules end in a wildcard and
|
||||||
|
# journalctl starts a pager, so without it the caller can reach a shell:
|
||||||
|
# less runs "!command" as the user the pager belongs to, which here is
|
||||||
|
# root. NOEXEC stops the granted command executing anything of its own.
|
||||||
if [ -n "$JOURNALCTL_PATH" ]; then
|
if [ -n "$JOURNALCTL_PATH" ]; then
|
||||||
echo "$WEB_USER ALL=(ALL) NOPASSWD: $JOURNALCTL_PATH -u ledmatrix.service *"
|
echo "$WEB_USER ALL=(ALL) NOPASSWD:NOEXEC: $JOURNALCTL_PATH -u ledmatrix.service *"
|
||||||
echo "$WEB_USER ALL=(ALL) NOPASSWD: $JOURNALCTL_PATH -u ledmatrix *"
|
echo "$WEB_USER ALL=(ALL) NOPASSWD:NOEXEC: $JOURNALCTL_PATH -u ledmatrix *"
|
||||||
echo "$WEB_USER ALL=(ALL) NOPASSWD: $JOURNALCTL_PATH -t ledmatrix *"
|
echo "$WEB_USER ALL=(ALL) NOPASSWD:NOEXEC: $JOURNALCTL_PATH -t ledmatrix *"
|
||||||
fi
|
fi
|
||||||
|
|
||||||
# Required: python3, bash
|
# Required: python3, bash
|
||||||
|
|||||||
@@ -25,9 +25,44 @@ if [ "$EUID" -eq 0 ]; then
|
|||||||
exit 1
|
exit 1
|
||||||
fi
|
fi
|
||||||
|
|
||||||
|
# Resolve command paths against a fixed PATH, and check what we resolved.
|
||||||
|
#
|
||||||
|
# Every path found here is written into a sudoers file as a NOPASSWD grant, so
|
||||||
|
# whoever controls the binary at that path controls root. first_time_install.sh
|
||||||
|
# re-execs itself with `sudo -E`, which preserves the invoking user's
|
||||||
|
# environment -- PATH included -- so without pinning it, `which nmcli` can
|
||||||
|
# resolve to anything on that PATH: a writable directory early in it turns a
|
||||||
|
# compromise of the low-privilege web user into permanent root.
|
||||||
|
PATH=/usr/sbin:/usr/bin:/sbin:/bin
|
||||||
|
export PATH
|
||||||
|
|
||||||
|
# A binary named in a sudoers rule must be root-owned and writable by nobody
|
||||||
|
# else, or the grant hands root to whoever can rewrite it.
|
||||||
|
require_trusted_binary() {
|
||||||
|
local label="$1" path="$2"
|
||||||
|
if [ ! -x "$path" ]; then
|
||||||
|
echo "✗ $label: $path is not an executable file"
|
||||||
|
exit 1
|
||||||
|
fi
|
||||||
|
local owner perms
|
||||||
|
owner=$(stat -c '%u' "$path") || exit 1
|
||||||
|
perms=$(stat -c '%a' "$path") || exit 1
|
||||||
|
if [ "$owner" != "0" ]; then
|
||||||
|
echo "✗ $label: $path is not owned by root (uid $owner); refusing to"
|
||||||
|
echo " grant it NOPASSWD sudo."
|
||||||
|
exit 1
|
||||||
|
fi
|
||||||
|
# Group- or world-writable means someone other than root can replace it.
|
||||||
|
case "$perms" in
|
||||||
|
*[2367]) echo "✗ $label: $path is writable by group or other ($perms);"
|
||||||
|
echo " refusing to grant it NOPASSWD sudo."
|
||||||
|
exit 1 ;;
|
||||||
|
esac
|
||||||
|
}
|
||||||
|
|
||||||
# Get the full paths to commands
|
# Get the full paths to commands
|
||||||
NMCLI_PATH=$(which nmcli || echo "/usr/bin/nmcli")
|
NMCLI_PATH=$(command -v nmcli || echo "/usr/bin/nmcli")
|
||||||
SYSTEMCTL_PATH=$(which systemctl)
|
SYSTEMCTL_PATH=$(command -v systemctl)
|
||||||
|
|
||||||
echo "Command paths:"
|
echo "Command paths:"
|
||||||
echo " nmcli: $NMCLI_PATH"
|
echo " nmcli: $NMCLI_PATH"
|
||||||
@@ -37,6 +72,18 @@ echo " systemctl: $SYSTEMCTL_PATH"
|
|||||||
echo ""
|
echo ""
|
||||||
echo "Step 1: Configuring sudo permissions for nmcli..."
|
echo "Step 1: Configuring sudo permissions for nmcli..."
|
||||||
SUDOERS_FILE="/etc/sudoers.d/ledmatrix_wifi"
|
SUDOERS_FILE="/etc/sudoers.d/ledmatrix_wifi"
|
||||||
|
SYSCTL_PATH=$(command -v sysctl || echo /usr/sbin/sysctl)
|
||||||
|
NFT_PATH=$(command -v nft || echo /usr/sbin/nft)
|
||||||
|
RFKILL_PATH=$(command -v rfkill || echo /usr/sbin/rfkill)
|
||||||
|
MKDIR_PATH=$(command -v mkdir || echo /usr/bin/mkdir)
|
||||||
|
|
||||||
|
# Checked before any of them reaches the sudoers file.
|
||||||
|
require_trusted_binary "nmcli" "$NMCLI_PATH"
|
||||||
|
require_trusted_binary "systemctl" "$SYSTEMCTL_PATH"
|
||||||
|
require_trusted_binary "sysctl" "$SYSCTL_PATH"
|
||||||
|
require_trusted_binary "nft" "$NFT_PATH"
|
||||||
|
require_trusted_binary "rfkill" "$RFKILL_PATH"
|
||||||
|
require_trusted_binary "mkdir" "$MKDIR_PATH"
|
||||||
|
|
||||||
# Create a temporary sudoers file using mktemp (handles permissions better)
|
# Create a temporary sudoers file using mktemp (handles permissions better)
|
||||||
TEMP_SUDOERS=$(mktemp) || {
|
TEMP_SUDOERS=$(mktemp) || {
|
||||||
@@ -62,6 +109,36 @@ $WEB_USER ALL=(ALL) NOPASSWD: $SYSTEMCTL_PATH start dnsmasq
|
|||||||
$WEB_USER ALL=(ALL) NOPASSWD: $SYSTEMCTL_PATH stop dnsmasq
|
$WEB_USER ALL=(ALL) NOPASSWD: $SYSTEMCTL_PATH stop dnsmasq
|
||||||
$WEB_USER ALL=(ALL) NOPASSWD: $SYSTEMCTL_PATH restart dnsmasq
|
$WEB_USER ALL=(ALL) NOPASSWD: $SYSTEMCTL_PATH restart dnsmasq
|
||||||
$WEB_USER ALL=(ALL) NOPASSWD: $SYSTEMCTL_PATH restart NetworkManager
|
$WEB_USER ALL=(ALL) NOPASSWD: $SYSTEMCTL_PATH restart NetworkManager
|
||||||
|
# The captive portal turns IP forwarding on while the access point is up and
|
||||||
|
# restores the previous value when it comes down (wifi_manager._setup_iptables_
|
||||||
|
# redirect / _teardown_iptables_redirect). Without this rule that sudo call
|
||||||
|
# needs a password, so forwarding stays off and clients associate to the AP but
|
||||||
|
# cannot route. It goes unnoticed on a stock Raspberry Pi image, where
|
||||||
|
# /etc/sudoers.d/010_pi-nopasswd grants the default user blanket NOPASSWD and
|
||||||
|
# masks every gap in this file -- it only bites once that blanket rule is
|
||||||
|
# removed.
|
||||||
|
$WEB_USER ALL=(ALL) NOPASSWD: $SYSCTL_PATH -w net.ipv4.ip_forward=0
|
||||||
|
$WEB_USER ALL=(ALL) NOPASSWD: $SYSCTL_PATH -w net.ipv4.ip_forward=1
|
||||||
|
# The portal's redirect lives in its own nftables table, created when the AP
|
||||||
|
# comes up and deleted when it goes down, and the radio has to be unblocked
|
||||||
|
# before the AP can start at all. Same story as the sysctl rules above: called
|
||||||
|
# with sudo, never granted here, and invisible on a stock Pi image.
|
||||||
|
$WEB_USER ALL=(ALL) NOPASSWD: $NFT_PATH add table ip ledmatrix
|
||||||
|
$WEB_USER ALL=(ALL) NOPASSWD: $NFT_PATH delete table ip ledmatrix
|
||||||
|
$WEB_USER ALL=(ALL) NOPASSWD: $RFKILL_PATH unblock wifi
|
||||||
|
# NetworkManager's dnsmasq drop-in directory, exact path.
|
||||||
|
$WEB_USER ALL=(ALL) NOPASSWD: $MKDIR_PATH -p /etc/NetworkManager/dnsmasq-shared.d
|
||||||
|
#
|
||||||
|
# iptables is deliberately NOT granted here. Its rules are built from the live
|
||||||
|
# interface name and port, so a rule covering them needs a trailing wildcard --
|
||||||
|
# and `iptables --modprobe=/path/to/anything` runs that path as root, so
|
||||||
|
# `NOPASSWD: iptables *` is a root shell for the web user by another name. That
|
||||||
|
# is a worse outcome than the gap it would close, which today is masked anyway
|
||||||
|
# by the blanket NOPASSWD rule on stock Pi images.
|
||||||
|
#
|
||||||
|
# Closing it safely means a wrapper script that builds the rules itself and
|
||||||
|
# takes only an interface and a port, granted the way safe_plugin_rm.sh already
|
||||||
|
# is. That belongs in its own change rather than being smuggled into this one.
|
||||||
|
|
||||||
# Allow copying hostapd and dnsmasq config files into place
|
# Allow copying hostapd and dnsmasq config files into place
|
||||||
$WEB_USER ALL=(ALL) NOPASSWD: /usr/bin/cp /tmp/hostapd.conf /etc/hostapd/hostapd.conf
|
$WEB_USER ALL=(ALL) NOPASSWD: /usr/bin/cp /tmp/hostapd.conf /etc/hostapd/hostapd.conf
|
||||||
|
|||||||
Regular → Executable
Regular → Executable
@@ -328,7 +328,11 @@ class ScrollHelper:
|
|||||||
elapsed_time = current_time - (self.scroll_start_time or current_time)
|
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
|
# The image already includes display_width padding, so we only need total_scroll_width
|
||||||
required_total_distance = self.total_scroll_width
|
required_total_distance = self.total_scroll_width
|
||||||
self.logger.info(
|
# Progress telemetry, emitted every few seconds for the whole of
|
||||||
|
# every scroll. It says how far along a marquee is, which is what
|
||||||
|
# you turn debug on to watch and not something an operator needs
|
||||||
|
# in the journal on a device that scrolls all day.
|
||||||
|
self.logger.debug(
|
||||||
"Scroll progress: elapsed=%.2fs, target=%.2fs, total_scrolled=%.0f/%d px (%.1f%%)",
|
"Scroll progress: elapsed=%.2fs, target=%.2fs, total_scrolled=%.0f/%d px (%.1f%%)",
|
||||||
elapsed_time,
|
elapsed_time,
|
||||||
self.calculated_duration,
|
self.calculated_duration,
|
||||||
|
|||||||
+84
-1
@@ -130,7 +130,12 @@ def setup_logging(
|
|||||||
# Console handler (always add)
|
# Console handler (always add)
|
||||||
console_handler = logging.StreamHandler(sys.stdout)
|
console_handler = logging.StreamHandler(sys.stdout)
|
||||||
console_handler.setLevel(level)
|
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)
|
root_logger.addHandler(console_handler)
|
||||||
|
|
||||||
# File handler (if specified)
|
# File handler (if specified)
|
||||||
@@ -145,6 +150,84 @@ def setup_logging(
|
|||||||
sys.stderr.write(f"Warning: Could not set up file logging to {log_file}: {e}\n")
|
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 really is the journal.
|
||||||
|
|
||||||
|
systemd sets JOURNAL_STREAM to "dev:ino" for services whose output it
|
||||||
|
captures. Presence alone is not enough to act on: the variable is
|
||||||
|
inherited by child processes and survives redirection, so a subprocess
|
||||||
|
whose stdout is a pipe or a file still sees it and would emit the "<N>"
|
||||||
|
priority prefixes as literal noise into that output. systemd's own
|
||||||
|
guidance is to fstat the descriptor and compare st_dev/st_ino, which is
|
||||||
|
what distinguishes "the journal is somewhere in my ancestry" from "my
|
||||||
|
stdout is the journal".
|
||||||
|
"""
|
||||||
|
declared = os.environ.get("JOURNAL_STREAM")
|
||||||
|
if not declared:
|
||||||
|
return False
|
||||||
|
try:
|
||||||
|
dev_text, ino_text = declared.split(":", 1)
|
||||||
|
declared_ids = (int(dev_text), int(ino_text))
|
||||||
|
except (ValueError, AttributeError):
|
||||||
|
return False
|
||||||
|
try:
|
||||||
|
stat_result = os.fstat(sys.stdout.fileno())
|
||||||
|
except (OSError, ValueError, AttributeError):
|
||||||
|
# No usable stdout: captured by pytest, detached, or already closed.
|
||||||
|
return False
|
||||||
|
return (stat_result.st_dev, stat_result.st_ino) == declared_ids
|
||||||
|
|
||||||
|
|
||||||
class PluginLoggerAdapter(logging.LoggerAdapter):
|
class PluginLoggerAdapter(logging.LoggerAdapter):
|
||||||
"""LoggerAdapter that stamps every record with its plugin_id.
|
"""LoggerAdapter that stamps every record with its plugin_id.
|
||||||
|
|
||||||
|
|||||||
@@ -178,10 +178,20 @@ class PluginHealthTracker:
|
|||||||
)
|
)
|
||||||
return self._health_state[plugin_id]
|
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:
|
def record_success(self, plugin_id: str) -> None:
|
||||||
"""Record a successful plugin execution."""
|
"""Record a successful plugin execution."""
|
||||||
state = self.get_health_state(plugin_id)
|
state = self.get_health_state(plugin_id)
|
||||||
current_time = time.time()
|
current_time = time.time()
|
||||||
|
durable_before = self._durable(state)
|
||||||
|
|
||||||
# Reset consecutive failures
|
# Reset consecutive failures
|
||||||
state['consecutive_failures'] = 0
|
state['consecutive_failures'] = 0
|
||||||
@@ -199,7 +209,18 @@ class PluginHealthTracker:
|
|||||||
state['circuit_state'] = CircuitState.CLOSED.value
|
state['circuit_state'] = CircuitState.CLOSED.value
|
||||||
state['circuit_opened_time'] = None
|
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:
|
def record_failure(self, plugin_id: str, error: Optional[Exception] = None) -> None:
|
||||||
"""Record a failed plugin execution."""
|
"""Record a failed plugin execution."""
|
||||||
|
|||||||
@@ -9,7 +9,7 @@ import time
|
|||||||
import logging
|
import logging
|
||||||
import threading
|
import threading
|
||||||
from typing import Dict, Optional, Any, Callable
|
from typing import Dict, Optional, Any, Callable
|
||||||
from dataclasses import dataclass, field
|
from dataclasses import dataclass, field, fields
|
||||||
|
|
||||||
try:
|
try:
|
||||||
import psutil
|
import psutil
|
||||||
@@ -49,6 +49,20 @@ class ResourceMetrics:
|
|||||||
self.total_execution_time = self.total_execution_time / self.call_count
|
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:
|
class PluginResourceMonitor:
|
||||||
"""
|
"""
|
||||||
Monitors resource usage for plugins.
|
Monitors resource usage for plugins.
|
||||||
@@ -75,6 +89,10 @@ class PluginResourceMonitor:
|
|||||||
# Resource metrics per plugin
|
# Resource metrics per plugin
|
||||||
self._metrics: Dict[str, ResourceMetrics] = {}
|
self._metrics: Dict[str, ResourceMetrics] = {}
|
||||||
self._limits: Dict[str, ResourceLimits] = {}
|
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
|
# Thread-local storage for execution tracking
|
||||||
self._local = threading.local()
|
self._local = threading.local()
|
||||||
@@ -102,6 +120,66 @@ class PluginResourceMonitor:
|
|||||||
"psutil not available - resource monitoring will be limited to execution time only"
|
"psutil not available - resource monitoring will be limited to execution time only"
|
||||||
)
|
)
|
||||||
|
|
||||||
|
def _metrics_from_cache(self, plugin_id: str, cached: Any) -> "ResourceMetrics":
|
||||||
|
"""Build metrics from a cached record, ignoring anything unrecognised.
|
||||||
|
|
||||||
|
ResourceMetrics(**cached) raises TypeError on a single unexpected key,
|
||||||
|
and that exception escapes into plugin_manager, which reports it as
|
||||||
|
"plugin <id> operation failed". Every plugin fails, and the plugin
|
||||||
|
system never finishes initialising.
|
||||||
|
|
||||||
|
Seen on a live rig: every plugin failing with
|
||||||
|
|
||||||
|
ResourceMetrics.__init__() got an unexpected keyword argument
|
||||||
|
'consecutive_failures'
|
||||||
|
|
||||||
|
which is a plugin_health field, not a metrics one. How a health-shaped
|
||||||
|
record came to sit under a plugin_metrics key on that machine is not
|
||||||
|
established -- a restored backup that mixed two machines' caches is the
|
||||||
|
likeliest explanation -- but the loader should not be brittle enough for
|
||||||
|
it to matter. plugin_health already repairs its records field by field
|
||||||
|
rather than trusting whatever is on disk; this does the same.
|
||||||
|
|
||||||
|
Unknown keys are dropped and named once, so a genuine schema change is
|
||||||
|
visible in the log instead of silently discarded.
|
||||||
|
"""
|
||||||
|
if not isinstance(cached, dict):
|
||||||
|
self.logger.warning(
|
||||||
|
"Ignoring cached metrics for %s: expected a mapping, got %s",
|
||||||
|
plugin_id, type(cached).__name__)
|
||||||
|
return ResourceMetrics()
|
||||||
|
|
||||||
|
known = {f.name for f in fields(ResourceMetrics)}
|
||||||
|
unknown = sorted(set(cached) - known)
|
||||||
|
if unknown:
|
||||||
|
self.logger.warning(
|
||||||
|
"Dropping unrecognised field(s) from cached metrics for %s: %s",
|
||||||
|
plugin_id, ", ".join(unknown))
|
||||||
|
# A dataclass does not enforce its annotations, so
|
||||||
|
# ResourceMetrics(call_count="not a number") builds happily and only
|
||||||
|
# blows up later, deep inside monitor_call ("can only concatenate str
|
||||||
|
# (not \"int\") to str"). Coerce here, where there is still a cache
|
||||||
|
# key to name in the warning.
|
||||||
|
declared = {f.name: f.type for f in fields(ResourceMetrics)}
|
||||||
|
usable = {}
|
||||||
|
for key, value in cached.items():
|
||||||
|
if key not in known:
|
||||||
|
continue
|
||||||
|
try:
|
||||||
|
usable[key] = int(value) if declared[key] in ('int', int) else float(value)
|
||||||
|
except (TypeError, ValueError):
|
||||||
|
self.logger.warning(
|
||||||
|
"Cached metrics for %s have a bad %s (%r); starting fresh",
|
||||||
|
plugin_id, key, value)
|
||||||
|
return ResourceMetrics()
|
||||||
|
try:
|
||||||
|
return ResourceMetrics(**usable)
|
||||||
|
except (TypeError, ValueError) as e:
|
||||||
|
self.logger.warning(
|
||||||
|
"Cached metrics for %s unusable (%s); starting fresh",
|
||||||
|
plugin_id, e)
|
||||||
|
return ResourceMetrics()
|
||||||
|
|
||||||
def _get_metrics_key(self, plugin_id: str) -> str:
|
def _get_metrics_key(self, plugin_id: str) -> str:
|
||||||
"""Get cache key for plugin metrics."""
|
"""Get cache key for plugin metrics."""
|
||||||
return f"plugin_metrics:{plugin_id}"
|
return f"plugin_metrics:{plugin_id}"
|
||||||
@@ -126,7 +204,7 @@ class PluginResourceMonitor:
|
|||||||
cache_key, max_age=None, memory_ttl=0 if force_reload else None
|
cache_key, max_age=None, memory_ttl=0 if force_reload else None
|
||||||
)
|
)
|
||||||
if cached:
|
if cached:
|
||||||
metrics = ResourceMetrics(**cached)
|
metrics = self._metrics_from_cache(plugin_id, cached)
|
||||||
else:
|
else:
|
||||||
metrics = ResourceMetrics()
|
metrics = ResourceMetrics()
|
||||||
self._metrics[plugin_id] = metrics
|
self._metrics[plugin_id] = metrics
|
||||||
@@ -232,18 +310,8 @@ class PluginResourceMonitor:
|
|||||||
# CPU is harder to measure per-call, so we track it separately
|
# CPU is harder to measure per-call, so we track it separately
|
||||||
metrics.cpu_percent = self._get_process_cpu_percent()
|
metrics.cpu_percent = self._get_process_cpu_percent()
|
||||||
|
|
||||||
# Persist metrics
|
# Persist metrics, at most once per interval per plugin.
|
||||||
cache_key = self._get_metrics_key(plugin_id)
|
self._persist_metrics(plugin_id, metrics)
|
||||||
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
|
|
||||||
})
|
|
||||||
|
|
||||||
# Check limits
|
# Check limits
|
||||||
if limits:
|
if limits:
|
||||||
@@ -363,6 +431,44 @@ class PluginResourceMonitor:
|
|||||||
summaries[plugin_id] = self.get_metrics_summary(plugin_id)
|
summaries[plugin_id] = self.get_metrics_summary(plugin_id)
|
||||||
return summaries
|
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.
|
||||||
|
#
|
||||||
|
# The sentinel for "never written" is None, not 0.0. monotonic() is
|
||||||
|
# time since boot on Linux, and systemd starts this service *at* boot,
|
||||||
|
# so `now - 0.0 < 30` was true for the first half-minute of every
|
||||||
|
# single run -- the throttle swallowed the very first snapshot, which
|
||||||
|
# is the one that matters most after a restart.
|
||||||
|
now = time.monotonic()
|
||||||
|
last_written = self._metrics_persisted_at.get(plugin_id)
|
||||||
|
if (not force and last_written is not None
|
||||||
|
and now - last_written < _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:
|
def reset_metrics(self, plugin_id: str) -> None:
|
||||||
"""Reset metrics for a plugin."""
|
"""Reset metrics for a plugin."""
|
||||||
with self._lock:
|
with self._lock:
|
||||||
@@ -370,4 +476,7 @@ class PluginResourceMonitor:
|
|||||||
self._metrics[plugin_id] = ResourceMetrics()
|
self._metrics[plugin_id] = ResourceMetrics()
|
||||||
cache_key = self._get_metrics_key(plugin_id)
|
cache_key = self._get_metrics_key(plugin_id)
|
||||||
self.cache_manager.delete(cache_key)
|
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)
|
||||||
|
|
||||||
|
|||||||
@@ -63,6 +63,9 @@ class StartupValidator:
|
|||||||
if self.plugin_manager:
|
if self.plugin_manager:
|
||||||
self._validate_plugins()
|
self._validate_plugins()
|
||||||
|
|
||||||
|
# Warn when the running systemd unit no longer matches the repo's
|
||||||
|
self._validate_systemd_units()
|
||||||
|
|
||||||
is_valid = len(self.errors) == 0
|
is_valid = len(self.errors) == 0
|
||||||
|
|
||||||
if is_valid:
|
if is_valid:
|
||||||
@@ -74,6 +77,80 @@ class StartupValidator:
|
|||||||
|
|
||||||
return (is_valid, self.errors.copy(), self.warnings.copy())
|
return (is_valid, self.errors.copy(), self.warnings.copy())
|
||||||
|
|
||||||
|
#: Units this project installs, and where each is installed to.
|
||||||
|
_UNITS = (
|
||||||
|
("systemd/ledmatrix.service", "/etc/systemd/system/ledmatrix.service"),
|
||||||
|
("systemd/ledmatrix-web.service", "/etc/systemd/system/ledmatrix-web.service"),
|
||||||
|
)
|
||||||
|
|
||||||
|
def _validate_systemd_units(self) -> None:
|
||||||
|
"""Warn when an installed unit has drifted from the repo's template.
|
||||||
|
|
||||||
|
Nothing re-applies these after the first install. `git pull` -- which is
|
||||||
|
what the web UI's update button runs -- brings a new template into the
|
||||||
|
checkout, but nothing copies it to /etc/systemd/system and nothing runs
|
||||||
|
`systemctl daemon-reload`, so the unit that actually runs is whatever
|
||||||
|
first_time_install.sh wrote on day one.
|
||||||
|
|
||||||
|
That makes every hardening added to a unit inert on existing installs.
|
||||||
|
Measured on one rig: the installed unit was thirteen days older than the
|
||||||
|
repo's and differed in content, so a MemoryMax the repo had specified
|
||||||
|
was not being enforced at all -- `systemctl show` reported
|
||||||
|
MemoryMax=infinity.
|
||||||
|
|
||||||
|
A warning rather than an error, and certainly not a silent rewrite:
|
||||||
|
editing files under /etc and restarting services is the installer's job,
|
||||||
|
not something a display process should do to a machine while it boots.
|
||||||
|
The remedy is to re-run scripts/install/install_service.sh.
|
||||||
|
"""
|
||||||
|
try:
|
||||||
|
project_root = Path(__file__).resolve().parent.parent
|
||||||
|
for template_rel, installed_path in self._UNITS:
|
||||||
|
template = project_root / template_rel
|
||||||
|
installed = Path(installed_path)
|
||||||
|
if not template.is_file() or not installed.is_file():
|
||||||
|
continue
|
||||||
|
|
||||||
|
# The template carries placeholders the installer substitutes,
|
||||||
|
# so compare the substituted form rather than the raw file.
|
||||||
|
expected = template.read_text(encoding="utf-8")
|
||||||
|
expected = expected.replace("__PROJECT_ROOT_DIR__", str(project_root))
|
||||||
|
expected = expected.replace("__USER__", "root")
|
||||||
|
|
||||||
|
try:
|
||||||
|
actual = installed.read_text(encoding="utf-8")
|
||||||
|
except PermissionError:
|
||||||
|
continue
|
||||||
|
|
||||||
|
if self._unit_body(expected) != self._unit_body(actual):
|
||||||
|
self.warnings.append(
|
||||||
|
f"{installed.name} differs from {template_rel}; the "
|
||||||
|
"installed unit is not refreshed by an update, so "
|
||||||
|
"settings added to the template are not in effect. "
|
||||||
|
"Re-run scripts/install/install_service.sh to apply them."
|
||||||
|
)
|
||||||
|
except OSError as e:
|
||||||
|
self.logger.debug("Could not compare systemd units: %s", e)
|
||||||
|
|
||||||
|
@staticmethod
|
||||||
|
def _unit_body(text: str) -> str:
|
||||||
|
"""A unit's meaningful lines, in order: no comments, no blanks.
|
||||||
|
|
||||||
|
Order is preserved deliberately. This used to sort, which made the
|
||||||
|
comparison insensitive to two changes that matter in a systemd unit:
|
||||||
|
repeated directives such as ExecStartPre= and ExecStartPost= run in
|
||||||
|
the order they appear, and a directive that moves between [Unit],
|
||||||
|
[Service] and [Install] means something different -- or nothing --
|
||||||
|
where it lands. A drift check that normalises those away reports no
|
||||||
|
drift for a unit that has genuinely changed.
|
||||||
|
"""
|
||||||
|
lines = []
|
||||||
|
for line in text.splitlines():
|
||||||
|
line = line.strip()
|
||||||
|
if line and not line.startswith("#"):
|
||||||
|
lines.append(line)
|
||||||
|
return "\n".join(lines)
|
||||||
|
|
||||||
def _validate_config(self) -> None:
|
def _validate_config(self) -> None:
|
||||||
"""Validate configuration files."""
|
"""Validate configuration files."""
|
||||||
try:
|
try:
|
||||||
|
|||||||
@@ -31,6 +31,18 @@ if TYPE_CHECKING:
|
|||||||
logger = logging.getLogger(__name__)
|
logger = logging.getLogger(__name__)
|
||||||
|
|
||||||
|
|
||||||
|
#: Degradation threshold, as a fraction of target_fps. A marquee jitters a
|
||||||
|
#: little all the time, so "anything under target" would report constantly and
|
||||||
|
#: mean nothing; 90% of target is the point where a shortfall is real. At a
|
||||||
|
#: 60fps target that is 54fps -- 55fps is a normal wobble and stays at DEBUG,
|
||||||
|
#: which is deliberate, not an off-by-one.
|
||||||
|
_FPS_HEALTHY_FRACTION = 0.9
|
||||||
|
|
||||||
|
#: A healthy marquee still reports this often, so silence means stopped
|
||||||
|
#: rather than fine.
|
||||||
|
_FPS_HEARTBEAT_INTERVAL = 300.0
|
||||||
|
|
||||||
|
|
||||||
def _percentile(ordered: List[float], fraction: float) -> float:
|
def _percentile(ordered: List[float], fraction: float) -> float:
|
||||||
"""Nearest-rank percentile of an already-sorted list.
|
"""Nearest-rank percentile of an already-sorted list.
|
||||||
|
|
||||||
@@ -96,6 +108,11 @@ class VegasModeCoordinator:
|
|||||||
self._is_active = False
|
self._is_active = False
|
||||||
self._is_paused = False
|
self._is_paused = False
|
||||||
self._should_stop = False
|
self._should_stop = False
|
||||||
|
# Frame-rate health, tracked across run_iteration() calls so the
|
||||||
|
# heartbeat is one-per-interval rather than one-per-cycle, and so a
|
||||||
|
# recovery spanning two cycles is still reported. Reset on start().
|
||||||
|
self._fps_last_health_log = 0.0
|
||||||
|
self._fps_was_degraded = False
|
||||||
self._state_lock = threading.Lock()
|
self._state_lock = threading.Lock()
|
||||||
|
|
||||||
# Live priority tracking
|
# Live priority tracking
|
||||||
@@ -248,6 +265,11 @@ class VegasModeCoordinator:
|
|||||||
self._is_active = True
|
self._is_active = True
|
||||||
self._should_stop = False
|
self._should_stop = False
|
||||||
self._start_time = time.time()
|
self._start_time = time.time()
|
||||||
|
# A fresh run starts with a clean health slate: no stale
|
||||||
|
# "was degraded" from the previous run, and a heartbeat that is
|
||||||
|
# due immediately so the first sample confirms the marquee is up.
|
||||||
|
self._fps_last_health_log = 0.0
|
||||||
|
self._fps_was_degraded = False
|
||||||
|
|
||||||
# Line up the next group immediately, so the first extension is already
|
# Line up the next group immediately, so the first extension is already
|
||||||
# warm rather than stalling the scroll to fetch it.
|
# warm rather than stalling the scroll to fetch it.
|
||||||
@@ -395,8 +417,18 @@ class VegasModeCoordinator:
|
|||||||
duration = self.render_pipeline.get_dynamic_duration()
|
duration = self.render_pipeline.get_dynamic_duration()
|
||||||
start_time = time.time()
|
start_time = time.time()
|
||||||
frame_count = 0
|
frame_count = 0
|
||||||
fps_log_interval = 5.0 # Log FPS every 5 seconds
|
fps_log_interval = 5.0 # Sample FPS every 5 seconds
|
||||||
last_fps_log_time = start_time
|
# Health state lives on the coordinator, not here: run_iteration() is
|
||||||
|
# called once per cycle, so locals reset every few seconds. That made
|
||||||
|
# `last_fps_health_log = 0.0` fire the "heartbeat" on the first sample
|
||||||
|
# of every iteration rather than once per interval, and a recovery
|
||||||
|
# that crossed an iteration boundary was never reported at all --
|
||||||
|
# was_degraded had already gone back to False.
|
||||||
|
# Monotonic, and deliberately not start_time: start_time is wall
|
||||||
|
# clock and is used below to report the iteration's duration. Mixing
|
||||||
|
# the two here would make every delta hugely negative and silence the
|
||||||
|
# frame-rate reporting altogether.
|
||||||
|
last_fps_log_time = time.monotonic()
|
||||||
fps_frame_count = 0
|
fps_frame_count = 0
|
||||||
# A mean hides stutter completely. At 120fps a five-second window is
|
# A mean hides stutter completely. At 120fps a five-second window is
|
||||||
# ~600 frames, so a 200ms freeze -- plainly visible on a marquee --
|
# ~600 frames, so a 200ms freeze -- plainly visible on a marquee --
|
||||||
@@ -408,7 +440,13 @@ class VegasModeCoordinator:
|
|||||||
logger.info("Starting Vegas iteration for %.1fs", duration)
|
logger.info("Starting Vegas iteration for %.1fs", duration)
|
||||||
|
|
||||||
while True:
|
while True:
|
||||||
frame_started = time.time()
|
# Monotonic, like the FPS window below. These devices have no RTC,
|
||||||
|
# so the wall clock jumps by however wrong boot time was the moment
|
||||||
|
# NTP first syncs. A backward jump makes frame_elapsed negative,
|
||||||
|
# and `frame_interval - frame_elapsed` then sleeps for longer than
|
||||||
|
# the whole budget -- the render loop stalls for the size of the
|
||||||
|
# correction. A forward jump inflates p99 and worst-frame instead.
|
||||||
|
frame_started = time.monotonic()
|
||||||
|
|
||||||
# Check for STATIC mode plugin that should pause scroll
|
# Check for STATIC mode plugin that should pause scroll
|
||||||
static_plugin = self._check_static_plugin_trigger()
|
static_plugin = self._check_static_plugin_trigger()
|
||||||
@@ -436,7 +474,7 @@ class VegasModeCoordinator:
|
|||||||
# quarter of the budget spent not rendering. Subtracting the work
|
# quarter of the budget spent not rendering. Subtracting the work
|
||||||
# already done keeps the pacing target while reclaiming that time,
|
# already done keeps the pacing target while reclaiming that time,
|
||||||
# and yields the GIL either way so other threads still run.
|
# and yields the GIL either way so other threads still run.
|
||||||
frame_elapsed = time.time() - frame_started
|
frame_elapsed = time.monotonic() - frame_started
|
||||||
time.sleep(max(0.0, frame_interval - frame_elapsed))
|
time.sleep(max(0.0, frame_interval - frame_elapsed))
|
||||||
|
|
||||||
# Measured before the sleep: time spent working, not pacing.
|
# Measured before the sleep: time spent working, not pacing.
|
||||||
@@ -448,16 +486,42 @@ class VegasModeCoordinator:
|
|||||||
frame_count += 1
|
frame_count += 1
|
||||||
fps_frame_count += 1
|
fps_frame_count += 1
|
||||||
|
|
||||||
# Periodic FPS logging
|
# Periodic FPS logging. Reported at INFO only when the frame rate
|
||||||
current_time = time.time()
|
# is actually worth an operator's attention -- a shortfall against
|
||||||
|
# target, or the recovery from one -- with a slow heartbeat so a
|
||||||
|
# healthy marquee still shows a pulse.
|
||||||
|
#
|
||||||
|
# Measured over two hours on a running rig: 1410 samples, 98.5%
|
||||||
|
# of them within 10% of target. The 1.5% that were not included a
|
||||||
|
# reading of 8.6fps against a target of 60 -- a real stall, and
|
||||||
|
# completely invisible inside 1389 lines reading "59.6".
|
||||||
|
# Monotonic: every use of this value in the block below is a
|
||||||
|
# duration, and these devices have no RTC, so the wall clock jumps
|
||||||
|
# by however wrong boot time was the moment NTP first syncs. That
|
||||||
|
# would not only mis-fire the heartbeat, it would corrupt the
|
||||||
|
# frame rate itself, since fps is frames divided by this delta.
|
||||||
|
current_time = time.monotonic()
|
||||||
if current_time - last_fps_log_time >= fps_log_interval:
|
if current_time - last_fps_log_time >= fps_log_interval:
|
||||||
fps = fps_frame_count / (current_time - last_fps_log_time)
|
fps = fps_frame_count / (current_time - last_fps_log_time)
|
||||||
p99 = _percentile(sorted(frame_times), 0.99)
|
p99 = _percentile(sorted(frame_times), 0.99)
|
||||||
logger.info(
|
target = self.vegas_config.target_fps
|
||||||
"Vegas FPS: %.1f (target: %d, frames: %d) p99 %.1fms worst %.1fms",
|
degraded = target > 0 and fps < target * _FPS_HEALTHY_FRACTION
|
||||||
fps, self.vegas_config.target_fps, fps_frame_count,
|
due = (current_time - self._fps_last_health_log
|
||||||
p99 * 1000.0, frame_worst * 1000.0
|
>= _FPS_HEARTBEAT_INTERVAL)
|
||||||
)
|
if degraded or self._fps_was_degraded or due:
|
||||||
|
logger.info(
|
||||||
|
"Vegas FPS: %.1f (target: %d, frames: %d) p99 %.1fms worst %.1fms",
|
||||||
|
fps, target, fps_frame_count,
|
||||||
|
p99 * 1000.0, frame_worst * 1000.0
|
||||||
|
)
|
||||||
|
self._fps_last_health_log = current_time
|
||||||
|
else:
|
||||||
|
logger.debug(
|
||||||
|
"Vegas FPS: %.1f (target: %d, frames: %d) p99 %.1fms worst %.1fms",
|
||||||
|
fps, target, fps_frame_count,
|
||||||
|
p99 * 1000.0, frame_worst * 1000.0
|
||||||
|
)
|
||||||
|
self._fps_was_degraded = degraded
|
||||||
last_fps_log_time = current_time
|
last_fps_log_time = current_time
|
||||||
fps_frame_count = 0
|
fps_frame_count = 0
|
||||||
frame_worst = 0.0
|
frame_worst = 0.0
|
||||||
|
|||||||
@@ -83,7 +83,7 @@ class PluginAdapter:
|
|||||||
# into unrelated headlines once the strip refreshed to 9,505px.
|
# into unrelated headlines once the strip refreshed to 9,505px.
|
||||||
self._offset_shapes: dict = {}
|
self._offset_shapes: dict = {}
|
||||||
|
|
||||||
logger.info(
|
logger.debug(
|
||||||
"PluginAdapter initialized: display=%dx%d",
|
"PluginAdapter initialized: display=%dx%d",
|
||||||
self.display_width, self.display_height
|
self.display_width, self.display_height
|
||||||
)
|
)
|
||||||
@@ -109,7 +109,7 @@ class PluginAdapter:
|
|||||||
Returns:
|
Returns:
|
||||||
List of PIL Images representing plugin content, or None if no content
|
List of PIL Images representing plugin content, or None if no content
|
||||||
"""
|
"""
|
||||||
logger.info(
|
logger.debug(
|
||||||
"[%s] Getting content (class=%s)",
|
"[%s] Getting content (class=%s)",
|
||||||
plugin_id, plugin.__class__.__name__
|
plugin_id, plugin.__class__.__name__
|
||||||
)
|
)
|
||||||
@@ -118,7 +118,7 @@ class PluginAdapter:
|
|||||||
cached = self._get_cached(plugin_id)
|
cached = self._get_cached(plugin_id)
|
||||||
if cached is not None:
|
if cached is not None:
|
||||||
total_width = sum(img.width for img in cached)
|
total_width = sum(img.width for img in cached)
|
||||||
logger.info(
|
logger.debug(
|
||||||
"[%s] Using cached content: %d images, %dpx total",
|
"[%s] Using cached content: %d images, %dpx total",
|
||||||
plugin_id, len(cached), total_width
|
plugin_id, len(cached), total_width
|
||||||
)
|
)
|
||||||
@@ -126,46 +126,46 @@ class PluginAdapter:
|
|||||||
|
|
||||||
# Try native Vegas content method first
|
# Try native Vegas content method first
|
||||||
has_native = hasattr(plugin, 'get_vegas_content')
|
has_native = hasattr(plugin, 'get_vegas_content')
|
||||||
logger.info("[%s] Has get_vegas_content: %s", plugin_id, has_native)
|
logger.debug("[%s] Has get_vegas_content: %s", plugin_id, has_native)
|
||||||
if has_native:
|
if has_native:
|
||||||
content = self._get_native_content(plugin, plugin_id, offscreen_only)
|
content = self._get_native_content(plugin, plugin_id, offscreen_only)
|
||||||
if content:
|
if content:
|
||||||
total_width = sum(img.width for img in content)
|
total_width = sum(img.width for img in content)
|
||||||
logger.info(
|
logger.debug(
|
||||||
"[%s] Native content SUCCESS: %d images, %dpx total",
|
"[%s] Native content SUCCESS: %d images, %dpx total",
|
||||||
plugin_id, len(content), total_width
|
plugin_id, len(content), total_width
|
||||||
)
|
)
|
||||||
return self._finalize(content, plugin_id, 'native', plugin)
|
return self._finalize(content, plugin_id, 'native', plugin)
|
||||||
logger.info("[%s] Native content returned None", plugin_id)
|
logger.debug("[%s] Native content returned None", plugin_id)
|
||||||
|
|
||||||
# Try to get scroll_helper's cached image (for scrolling plugins like stocks/odds)
|
# Try to get scroll_helper's cached image (for scrolling plugins like stocks/odds)
|
||||||
has_scroll_helper = hasattr(plugin, 'scroll_helper')
|
has_scroll_helper = hasattr(plugin, 'scroll_helper')
|
||||||
logger.info("[%s] Has scroll_helper: %s", plugin_id, has_scroll_helper)
|
logger.debug("[%s] Has scroll_helper: %s", plugin_id, has_scroll_helper)
|
||||||
content = self._get_scroll_helper_content(plugin, plugin_id, offscreen_only)
|
content = self._get_scroll_helper_content(plugin, plugin_id, offscreen_only)
|
||||||
if content:
|
if content:
|
||||||
total_width = sum(img.width for img in content)
|
total_width = sum(img.width for img in content)
|
||||||
logger.info(
|
logger.debug(
|
||||||
"[%s] ScrollHelper content SUCCESS: %d images, %dpx total",
|
"[%s] ScrollHelper content SUCCESS: %d images, %dpx total",
|
||||||
plugin_id, len(content), total_width
|
plugin_id, len(content), total_width
|
||||||
)
|
)
|
||||||
return self._finalize(content, plugin_id, 'scroll_helper', plugin)
|
return self._finalize(content, plugin_id, 'scroll_helper', plugin)
|
||||||
if has_scroll_helper:
|
if has_scroll_helper:
|
||||||
logger.info("[%s] ScrollHelper content returned None", plugin_id)
|
logger.debug("[%s] ScrollHelper content returned None", plugin_id)
|
||||||
|
|
||||||
if offscreen_only:
|
if offscreen_only:
|
||||||
# Display capture needs the shared canvas; leave it to the caller.
|
# Display capture needs the shared canvas; leave it to the caller.
|
||||||
logger.info(
|
logger.debug(
|
||||||
"[%s] Needs display capture, deferring to the render thread",
|
"[%s] Needs display capture, deferring to the render thread",
|
||||||
plugin_id
|
plugin_id
|
||||||
)
|
)
|
||||||
return None
|
return None
|
||||||
|
|
||||||
# Fall back to display capture
|
# Fall back to display capture
|
||||||
logger.info("[%s] Trying fallback display capture...", plugin_id)
|
logger.debug("[%s] Trying fallback display capture...", plugin_id)
|
||||||
content = self._capture_display_content(plugin, plugin_id)
|
content = self._capture_display_content(plugin, plugin_id)
|
||||||
if content:
|
if content:
|
||||||
total_width = sum(img.width for img in content)
|
total_width = sum(img.width for img in content)
|
||||||
logger.info(
|
logger.debug(
|
||||||
"[%s] Fallback capture SUCCESS: %d images, %dpx total",
|
"[%s] Fallback capture SUCCESS: %d images, %dpx total",
|
||||||
plugin_id, len(content), total_width
|
plugin_id, len(content), total_width
|
||||||
)
|
)
|
||||||
@@ -226,7 +226,7 @@ class PluginAdapter:
|
|||||||
kept.append(result.image)
|
kept.append(result.image)
|
||||||
|
|
||||||
if not kept:
|
if not kept:
|
||||||
logger.info(
|
logger.debug(
|
||||||
"[%s] All %d image(s) from %s were blank — contributing nothing",
|
"[%s] All %d image(s) from %s were blank — contributing nothing",
|
||||||
plugin_id, len(images), source
|
plugin_id, len(images), source
|
||||||
)
|
)
|
||||||
@@ -235,14 +235,14 @@ class PluginAdapter:
|
|||||||
trimmed_width = sum(img.width for img in kept)
|
trimmed_width = sum(img.width for img in kept)
|
||||||
|
|
||||||
if trimmed_width < self.config.min_plugin_width:
|
if trimmed_width < self.config.min_plugin_width:
|
||||||
logger.info(
|
logger.debug(
|
||||||
"[%s] Trimmed content %dpx is below min_plugin_width %dpx — skipping",
|
"[%s] Trimmed content %dpx is below min_plugin_width %dpx — skipping",
|
||||||
plugin_id, trimmed_width, self.config.min_plugin_width
|
plugin_id, trimmed_width, self.config.min_plugin_width
|
||||||
)
|
)
|
||||||
return None
|
return None
|
||||||
|
|
||||||
if trimmed_width != original_width or dropped_blank:
|
if trimmed_width != original_width or dropped_blank:
|
||||||
logger.info(
|
logger.debug(
|
||||||
"[%s] Trimmed %s content: %dpx -> %dpx (%.0f%% reclaimed), "
|
"[%s] Trimmed %s content: %dpx -> %dpx (%.0f%% reclaimed), "
|
||||||
"%d image(s) kept, %d blank dropped",
|
"%d image(s) kept, %d blank dropped",
|
||||||
plugin_id, source, original_width, trimmed_width,
|
plugin_id, source, original_width, trimmed_width,
|
||||||
@@ -431,7 +431,7 @@ class PluginAdapter:
|
|||||||
"""
|
"""
|
||||||
if self._offset_shapes.get(plugin_id) != shape:
|
if self._offset_shapes.get(plugin_id) != shape:
|
||||||
if plugin_id in self._item_offsets:
|
if plugin_id in self._item_offsets:
|
||||||
logger.info(
|
logger.debug(
|
||||||
"[%s] Content is %s now, was %s — restarting the rotation "
|
"[%s] Content is %s now, was %s — restarting the rotation "
|
||||||
"rather than resuming at a position that no longer means "
|
"rather than resuming at a position that no longer means "
|
||||||
"anything", plugin_id, shape,
|
"anything", plugin_id, shape,
|
||||||
@@ -579,7 +579,7 @@ class PluginAdapter:
|
|||||||
consumed += 1
|
consumed += 1
|
||||||
|
|
||||||
if mode == 'truncate':
|
if mode == 'truncate':
|
||||||
logger.info(
|
logger.debug(
|
||||||
"[%s] Width budget %dpx: showing the first %d of %d row(s) "
|
"[%s] Width budget %dpx: showing the first %d of %d row(s) "
|
||||||
"(%dpx incl. gaps); the rest are not shown (overflow=truncate)",
|
"(%dpx incl. gaps); the rest are not shown (overflow=truncate)",
|
||||||
plugin_id, budget, len(selected), len(images), used
|
plugin_id, budget, len(selected), len(images), used
|
||||||
@@ -587,7 +587,7 @@ class PluginAdapter:
|
|||||||
else:
|
else:
|
||||||
self._record_offset(
|
self._record_offset(
|
||||||
plugin_id, (start + consumed) % len(images), shape)
|
plugin_id, (start + consumed) % len(images), shape)
|
||||||
logger.info(
|
logger.debug(
|
||||||
"[%s] Width budget %dpx: showing %d of %d row(s) (%dpx incl. gaps) "
|
"[%s] Width budget %dpx: showing %d of %d row(s) (%dpx incl. gaps) "
|
||||||
"from offset %d; remainder deferred to a later cycle",
|
"from offset %d; remainder deferred to a later cycle",
|
||||||
plugin_id, budget, len(selected), len(images), used, start
|
plugin_id, budget, len(selected), len(images), used, start
|
||||||
@@ -636,7 +636,7 @@ class PluginAdapter:
|
|||||||
if mode != 'truncate':
|
if mode != 'truncate':
|
||||||
self._record_offset(
|
self._record_offset(
|
||||||
plugin_id, 0 if end >= img.width else end, shape)
|
plugin_id, 0 if end >= img.width else end, shape)
|
||||||
logger.info(
|
logger.debug(
|
||||||
"[%s] Width budget %dpx: cropped continuous %dpx image to "
|
"[%s] Width budget %dpx: cropped continuous %dpx image to "
|
||||||
"[%d:%d] (no item gaps of %dpx+ to align to)%s",
|
"[%d:%d] (no item gaps of %dpx+ to align to)%s",
|
||||||
plugin_id, budget, img.width, offset, end, min_run,
|
plugin_id, budget, img.width, offset, end, min_run,
|
||||||
@@ -674,7 +674,7 @@ class PluginAdapter:
|
|||||||
self._record_offset(
|
self._record_offset(
|
||||||
plugin_id, 0 if end >= img.width else end_index, shape)
|
plugin_id, 0 if end >= img.width else end_index, shape)
|
||||||
|
|
||||||
logger.info(
|
logger.debug(
|
||||||
"[%s] Width budget %dpx: cropped single %dpx image to [%d:%d] "
|
"[%s] Width budget %dpx: cropped single %dpx image to [%d:%d] "
|
||||||
"(%dpx) at item boundaries %d-%d of %d, %s",
|
"(%dpx) at item boundaries %d-%d of %d, %s",
|
||||||
plugin_id, budget, img.width, start, end, end - start,
|
plugin_id, budget, img.width, start, end, end - start,
|
||||||
@@ -698,7 +698,7 @@ class PluginAdapter:
|
|||||||
List of images or None
|
List of images or None
|
||||||
"""
|
"""
|
||||||
try:
|
try:
|
||||||
logger.info("[%s] Native: calling get_vegas_content()", plugin_id)
|
logger.debug("[%s] Native: calling get_vegas_content()", plugin_id)
|
||||||
|
|
||||||
# Tell the plugin how much width the ticker wants it to use, and
|
# Tell the plugin how much width the ticker wants it to use, and
|
||||||
# narrow the canvas for the duration of the call. A plugin that
|
# narrow the canvas for the duration of the call. A plugin that
|
||||||
@@ -707,7 +707,7 @@ class PluginAdapter:
|
|||||||
# be explicit can read get_vegas_render_width().
|
# be explicit can read get_vegas_render_width().
|
||||||
render_width = self.resolve_render_width(plugin, plugin_id)
|
render_width = self.resolve_render_width(plugin, plugin_id)
|
||||||
if render_width != self.display_width:
|
if render_width != self.display_width:
|
||||||
logger.info(
|
logger.debug(
|
||||||
"[%s] Native: requesting %dpx instead of %dpx",
|
"[%s] Native: requesting %dpx instead of %dpx",
|
||||||
plugin_id, render_width, self.display_width
|
plugin_id, render_width, self.display_width
|
||||||
)
|
)
|
||||||
@@ -735,19 +735,19 @@ class PluginAdapter:
|
|||||||
plugin._vegas_render_width = None
|
plugin._vegas_render_width = None
|
||||||
|
|
||||||
if result is None:
|
if result is None:
|
||||||
logger.info("[%s] Native: get_vegas_content() returned None", plugin_id)
|
logger.debug("[%s] Native: get_vegas_content() returned None", plugin_id)
|
||||||
return None
|
return None
|
||||||
|
|
||||||
# Normalize to list
|
# Normalize to list
|
||||||
if isinstance(result, Image.Image):
|
if isinstance(result, Image.Image):
|
||||||
images = [result]
|
images = [result]
|
||||||
logger.info(
|
logger.debug(
|
||||||
"[%s] Native: got single Image %dx%d",
|
"[%s] Native: got single Image %dx%d",
|
||||||
plugin_id, result.width, result.height
|
plugin_id, result.width, result.height
|
||||||
)
|
)
|
||||||
elif isinstance(result, (list, tuple)):
|
elif isinstance(result, (list, tuple)):
|
||||||
images = list(result)
|
images = list(result)
|
||||||
logger.info(
|
logger.debug(
|
||||||
"[%s] Native: got %d items in list/tuple",
|
"[%s] Native: got %d items in list/tuple",
|
||||||
plugin_id, len(images)
|
plugin_id, len(images)
|
||||||
)
|
)
|
||||||
@@ -768,14 +768,14 @@ class PluginAdapter:
|
|||||||
)
|
)
|
||||||
continue
|
continue
|
||||||
|
|
||||||
logger.info(
|
logger.debug(
|
||||||
"[%s] Native: item[%d] is %dx%d, mode=%s",
|
"[%s] Native: item[%d] is %dx%d, mode=%s",
|
||||||
plugin_id, i, img.width, img.height, img.mode
|
plugin_id, i, img.width, img.height, img.mode
|
||||||
)
|
)
|
||||||
|
|
||||||
# Ensure correct height
|
# Ensure correct height
|
||||||
if img.height != self.display_height:
|
if img.height != self.display_height:
|
||||||
logger.info(
|
logger.debug(
|
||||||
"[%s] Native: resizing item[%d]: %dx%d -> %dx%d",
|
"[%s] Native: resizing item[%d]: %dx%d -> %dx%d",
|
||||||
plugin_id, i, img.width, img.height,
|
plugin_id, i, img.width, img.height,
|
||||||
img.width, self.display_height
|
img.width, self.display_height
|
||||||
@@ -793,13 +793,13 @@ class PluginAdapter:
|
|||||||
|
|
||||||
if valid_images:
|
if valid_images:
|
||||||
total_width = sum(img.width for img in valid_images)
|
total_width = sum(img.width for img in valid_images)
|
||||||
logger.info(
|
logger.debug(
|
||||||
"[%s] Native: SUCCESS - %d images, %dpx total width",
|
"[%s] Native: SUCCESS - %d images, %dpx total width",
|
||||||
plugin_id, len(valid_images), total_width
|
plugin_id, len(valid_images), total_width
|
||||||
)
|
)
|
||||||
return valid_images
|
return valid_images
|
||||||
|
|
||||||
logger.info("[%s] Native: no valid images after validation", plugin_id)
|
logger.debug("[%s] Native: no valid images after validation", plugin_id)
|
||||||
return None
|
return None
|
||||||
|
|
||||||
except (AttributeError, TypeError, ValueError, OSError) as e:
|
except (AttributeError, TypeError, ValueError, OSError) as e:
|
||||||
@@ -833,20 +833,20 @@ class PluginAdapter:
|
|||||||
logger.debug("[%s] No scroll_helper attribute", plugin_id)
|
logger.debug("[%s] No scroll_helper attribute", plugin_id)
|
||||||
return None
|
return None
|
||||||
|
|
||||||
logger.info(
|
logger.debug(
|
||||||
"[%s] Found scroll_helper: %s",
|
"[%s] Found scroll_helper: %s",
|
||||||
plugin_id, type(scroll_helper).__name__
|
plugin_id, type(scroll_helper).__name__
|
||||||
)
|
)
|
||||||
|
|
||||||
cached_image = getattr(scroll_helper, 'cached_image', None)
|
cached_image = getattr(scroll_helper, 'cached_image', None)
|
||||||
if cached_image is None:
|
if cached_image is None:
|
||||||
logger.info(
|
logger.debug(
|
||||||
"[%s] scroll_helper.cached_image is None, triggering content generation",
|
"[%s] scroll_helper.cached_image is None, triggering content generation",
|
||||||
plugin_id
|
plugin_id
|
||||||
)
|
)
|
||||||
if offscreen_only:
|
if offscreen_only:
|
||||||
# Generating it calls display(), which needs the canvas.
|
# Generating it calls display(), which needs the canvas.
|
||||||
logger.info(
|
logger.debug(
|
||||||
"[%s] scroll_helper cache empty; deferring generation "
|
"[%s] scroll_helper cache empty; deferring generation "
|
||||||
"to the render thread", plugin_id
|
"to the render thread", plugin_id
|
||||||
)
|
)
|
||||||
@@ -859,13 +859,13 @@ class PluginAdapter:
|
|||||||
return None
|
return None
|
||||||
|
|
||||||
if not isinstance(cached_image, Image.Image):
|
if not isinstance(cached_image, Image.Image):
|
||||||
logger.info(
|
logger.debug(
|
||||||
"[%s] scroll_helper.cached_image is not an Image: %s",
|
"[%s] scroll_helper.cached_image is not an Image: %s",
|
||||||
plugin_id, type(cached_image).__name__
|
plugin_id, type(cached_image).__name__
|
||||||
)
|
)
|
||||||
return None
|
return None
|
||||||
|
|
||||||
logger.info(
|
logger.debug(
|
||||||
"[%s] scroll_helper.cached_image found: %dx%d, mode=%s",
|
"[%s] scroll_helper.cached_image found: %dx%d, mode=%s",
|
||||||
plugin_id, cached_image.width, cached_image.height, cached_image.mode
|
plugin_id, cached_image.width, cached_image.height, cached_image.mode
|
||||||
)
|
)
|
||||||
@@ -888,7 +888,7 @@ class PluginAdapter:
|
|||||||
|
|
||||||
# Ensure correct height
|
# Ensure correct height
|
||||||
if img.height != self.display_height:
|
if img.height != self.display_height:
|
||||||
logger.info(
|
logger.debug(
|
||||||
"[%s] Resizing scroll_helper content: %dx%d -> %dx%d",
|
"[%s] Resizing scroll_helper content: %dx%d -> %dx%d",
|
||||||
plugin_id, img.width, img.height,
|
plugin_id, img.width, img.height,
|
||||||
img.width, self.display_height
|
img.width, self.display_height
|
||||||
@@ -902,7 +902,7 @@ class PluginAdapter:
|
|||||||
if img.mode != 'RGB':
|
if img.mode != 'RGB':
|
||||||
img = img.convert('RGB')
|
img = img.convert('RGB')
|
||||||
|
|
||||||
logger.info(
|
logger.debug(
|
||||||
"[%s] ScrollHelper content ready: %dx%d",
|
"[%s] ScrollHelper content ready: %dx%d",
|
||||||
plugin_id, img.width, img.height
|
plugin_id, img.width, img.height
|
||||||
)
|
)
|
||||||
@@ -1002,7 +1002,7 @@ class PluginAdapter:
|
|||||||
with self._capture():
|
with self._capture():
|
||||||
# Method 1: Try _create_scrolling_display (stocks pattern)
|
# Method 1: Try _create_scrolling_display (stocks pattern)
|
||||||
if hasattr(plugin, '_create_scrolling_display'):
|
if hasattr(plugin, '_create_scrolling_display'):
|
||||||
logger.info(
|
logger.debug(
|
||||||
"[%s] Triggering via _create_scrolling_display()",
|
"[%s] Triggering via _create_scrolling_display()",
|
||||||
plugin_id
|
plugin_id
|
||||||
)
|
)
|
||||||
@@ -1010,7 +1010,7 @@ class PluginAdapter:
|
|||||||
plugin._create_scrolling_display()
|
plugin._create_scrolling_display()
|
||||||
cached_image = getattr(scroll_helper, 'cached_image', None)
|
cached_image = getattr(scroll_helper, 'cached_image', None)
|
||||||
if cached_image is not None and isinstance(cached_image, Image.Image):
|
if cached_image is not None and isinstance(cached_image, Image.Image):
|
||||||
logger.info(
|
logger.debug(
|
||||||
"[%s] _create_scrolling_display() SUCCESS: %dx%d",
|
"[%s] _create_scrolling_display() SUCCESS: %dx%d",
|
||||||
plugin_id, cached_image.width, cached_image.height
|
plugin_id, cached_image.width, cached_image.height
|
||||||
)
|
)
|
||||||
@@ -1022,7 +1022,7 @@ class PluginAdapter:
|
|||||||
|
|
||||||
# Method 2: Try display(force_clear=True) which typically builds scroll content
|
# Method 2: Try display(force_clear=True) which typically builds scroll content
|
||||||
if hasattr(plugin, 'display'):
|
if hasattr(plugin, 'display'):
|
||||||
logger.info(
|
logger.debug(
|
||||||
"[%s] Triggering via display(force_clear=True)",
|
"[%s] Triggering via display(force_clear=True)",
|
||||||
plugin_id
|
plugin_id
|
||||||
)
|
)
|
||||||
@@ -1031,12 +1031,12 @@ class PluginAdapter:
|
|||||||
plugin.display(force_clear=True)
|
plugin.display(force_clear=True)
|
||||||
cached_image = getattr(scroll_helper, 'cached_image', None)
|
cached_image = getattr(scroll_helper, 'cached_image', None)
|
||||||
if cached_image is not None and isinstance(cached_image, Image.Image):
|
if cached_image is not None and isinstance(cached_image, Image.Image):
|
||||||
logger.info(
|
logger.debug(
|
||||||
"[%s] display(force_clear=True) SUCCESS: %dx%d",
|
"[%s] display(force_clear=True) SUCCESS: %dx%d",
|
||||||
plugin_id, cached_image.width, cached_image.height
|
plugin_id, cached_image.width, cached_image.height
|
||||||
)
|
)
|
||||||
return cached_image
|
return cached_image
|
||||||
logger.info(
|
logger.debug(
|
||||||
"[%s] display(force_clear=True) did not populate cached_image",
|
"[%s] display(force_clear=True) did not populate cached_image",
|
||||||
plugin_id
|
plugin_id
|
||||||
)
|
)
|
||||||
@@ -1045,7 +1045,7 @@ class PluginAdapter:
|
|||||||
"[%s] display(force_clear=True) failed", plugin_id
|
"[%s] display(force_clear=True) failed", plugin_id
|
||||||
)
|
)
|
||||||
|
|
||||||
logger.info(
|
logger.debug(
|
||||||
"[%s] Could not trigger scroll content generation",
|
"[%s] Could not trigger scroll content generation",
|
||||||
plugin_id
|
plugin_id
|
||||||
)
|
)
|
||||||
@@ -1077,15 +1077,15 @@ class PluginAdapter:
|
|||||||
try:
|
try:
|
||||||
# Save current display state
|
# Save current display state
|
||||||
original_image = self.display_manager.image.copy()
|
original_image = self.display_manager.image.copy()
|
||||||
logger.info("[%s] Fallback: saved original display state", plugin_id)
|
logger.debug("[%s] Fallback: saved original display state", plugin_id)
|
||||||
|
|
||||||
# Ensure plugin has fresh data before capturing
|
# Ensure plugin has fresh data before capturing
|
||||||
has_update_data = hasattr(plugin, 'update_data')
|
has_update_data = hasattr(plugin, 'update_data')
|
||||||
logger.info("[%s] Fallback: has update_data=%s", plugin_id, has_update_data)
|
logger.debug("[%s] Fallback: has update_data=%s", plugin_id, has_update_data)
|
||||||
if has_update_data:
|
if has_update_data:
|
||||||
try:
|
try:
|
||||||
plugin.update_data()
|
plugin.update_data()
|
||||||
logger.info("[%s] Fallback: update_data() called", plugin_id)
|
logger.debug("[%s] Fallback: update_data() called", plugin_id)
|
||||||
except (AttributeError, RuntimeError, OSError):
|
except (AttributeError, RuntimeError, OSError):
|
||||||
logger.exception("[%s] Fallback: update_data() failed", plugin_id)
|
logger.exception("[%s] Fallback: update_data() failed", plugin_id)
|
||||||
|
|
||||||
@@ -1097,41 +1097,41 @@ class PluginAdapter:
|
|||||||
# arrangement rather than one that has to be cropped afterwards.
|
# arrangement rather than one that has to be cropped afterwards.
|
||||||
render_width = self.resolve_render_width(plugin, plugin_id)
|
render_width = self.resolve_render_width(plugin, plugin_id)
|
||||||
if render_width != self.display_width:
|
if render_width != self.display_width:
|
||||||
logger.info(
|
logger.debug(
|
||||||
"[%s] Fallback: rendering at %dpx instead of %dpx",
|
"[%s] Fallback: rendering at %dpx instead of %dpx",
|
||||||
plugin_id, render_width, self.display_width
|
plugin_id, render_width, self.display_width
|
||||||
)
|
)
|
||||||
|
|
||||||
with self._capture(), self._render_at(render_width):
|
with self._capture(), self._render_at(render_width):
|
||||||
self.display_manager.clear()
|
self.display_manager.clear()
|
||||||
logger.info("[%s] Fallback: display cleared, calling display()", plugin_id)
|
logger.debug("[%s] Fallback: display cleared, calling display()", plugin_id)
|
||||||
|
|
||||||
# First try without force_clear (some plugins behave better this way)
|
# First try without force_clear (some plugins behave better this way)
|
||||||
try:
|
try:
|
||||||
plugin.display()
|
plugin.display()
|
||||||
logger.info("[%s] Fallback: display() called successfully", plugin_id)
|
logger.debug("[%s] Fallback: display() called successfully", plugin_id)
|
||||||
except TypeError:
|
except TypeError:
|
||||||
# Plugin may require force_clear argument
|
# Plugin may require force_clear argument
|
||||||
logger.info("[%s] Fallback: display() failed, trying with force_clear=True", plugin_id)
|
logger.debug("[%s] Fallback: display() failed, trying with force_clear=True", plugin_id)
|
||||||
plugin.display(force_clear=True)
|
plugin.display(force_clear=True)
|
||||||
|
|
||||||
# Capture the result
|
# Capture the result
|
||||||
captured = self.display_manager.image.copy()
|
captured = self.display_manager.image.copy()
|
||||||
|
|
||||||
logger.info(
|
logger.debug(
|
||||||
"[%s] Fallback: captured frame %dx%d, mode=%s",
|
"[%s] Fallback: captured frame %dx%d, mode=%s",
|
||||||
plugin_id, captured.width, captured.height, captured.mode
|
plugin_id, captured.width, captured.height, captured.mode
|
||||||
)
|
)
|
||||||
|
|
||||||
# Check if captured image has content (not all black)
|
# Check if captured image has content (not all black)
|
||||||
is_blank, bright_ratio = self._is_blank_image(captured, return_ratio=True)
|
is_blank, bright_ratio = self._is_blank_image(captured, return_ratio=True)
|
||||||
logger.info(
|
logger.debug(
|
||||||
"[%s] Fallback: brightness check - %.3f%% bright pixels (threshold=0.5%%)",
|
"[%s] Fallback: brightness check - %.3f%% bright pixels (threshold=0.5%%)",
|
||||||
plugin_id, bright_ratio * 100
|
plugin_id, bright_ratio * 100
|
||||||
)
|
)
|
||||||
|
|
||||||
if is_blank:
|
if is_blank:
|
||||||
logger.info(
|
logger.debug(
|
||||||
"[%s] Fallback: first capture blank, retrying with force_clear",
|
"[%s] Fallback: first capture blank, retrying with force_clear",
|
||||||
plugin_id
|
plugin_id
|
||||||
)
|
)
|
||||||
@@ -1142,7 +1142,7 @@ class PluginAdapter:
|
|||||||
captured = self.display_manager.image.copy()
|
captured = self.display_manager.image.copy()
|
||||||
|
|
||||||
is_blank, bright_ratio = self._is_blank_image(captured, return_ratio=True)
|
is_blank, bright_ratio = self._is_blank_image(captured, return_ratio=True)
|
||||||
logger.info(
|
logger.debug(
|
||||||
"[%s] Fallback: retry brightness - %.3f%% bright pixels",
|
"[%s] Fallback: retry brightness - %.3f%% bright pixels",
|
||||||
plugin_id, bright_ratio * 100
|
plugin_id, bright_ratio * 100
|
||||||
)
|
)
|
||||||
@@ -1159,7 +1159,7 @@ class PluginAdapter:
|
|||||||
if captured.mode != 'RGB':
|
if captured.mode != 'RGB':
|
||||||
captured = captured.convert('RGB')
|
captured = captured.convert('RGB')
|
||||||
|
|
||||||
logger.info(
|
logger.debug(
|
||||||
"[%s] Fallback: SUCCESS - captured %dx%d",
|
"[%s] Fallback: SUCCESS - captured %dx%d",
|
||||||
plugin_id, captured.width, captured.height
|
plugin_id, captured.width, captured.height
|
||||||
)
|
)
|
||||||
|
|||||||
@@ -143,6 +143,12 @@ def mask_secret_fields(config: Dict[str, Any], schema_properties: Dict[str, Any]
|
|||||||
return result
|
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]:
|
def mask_all_secret_values(config: Dict[str, Any]) -> Dict[str, Any]:
|
||||||
"""Blanket-mask every non-empty value in a secrets config dict.
|
"""Blanket-mask every non-empty value in a secrets config dict.
|
||||||
|
|
||||||
@@ -156,15 +162,25 @@ def mask_all_secret_values(config: Dict[str, Any]) -> Dict[str, Any]:
|
|||||||
Returns:
|
Returns:
|
||||||
A copy with all real values replaced by ``'••••••••'``.
|
A copy with all real values replaced by ``'••••••••'``.
|
||||||
"""
|
"""
|
||||||
masked: Dict[str, Any] = {}
|
return {k: _mask_value(v) for k, v in config.items()}
|
||||||
for k, v in config.items():
|
|
||||||
if isinstance(v, dict):
|
|
||||||
masked[k] = mask_all_secret_values(v)
|
def _mask_value(value: Any) -> Any:
|
||||||
elif v not in (None, '') and not (isinstance(v, str) and v.startswith('YOUR_')):
|
"""Mask one value, recursing through dicts and lists.
|
||||||
masked[k] = '••••••••'
|
|
||||||
else:
|
A list used to be masked as though it were a scalar, so
|
||||||
masked[k] = v
|
``accounts: [{"name": "a", "token": "..."}]`` came back as a single
|
||||||
return masked
|
``'••••••••'``. Nothing leaked, but the caller could no longer see how
|
||||||
|
many entries there were or any of their non-secret fields, and the raw
|
||||||
|
editor was shown a string where the file holds an array.
|
||||||
|
"""
|
||||||
|
if isinstance(value, dict):
|
||||||
|
return {k: _mask_value(v) for k, v in value.items()}
|
||||||
|
if isinstance(value, list):
|
||||||
|
return [_mask_value(item) for item in value]
|
||||||
|
if value in (None, '') or (isinstance(value, str) and value.startswith('YOUR_')):
|
||||||
|
return value
|
||||||
|
return SECRET_MASK
|
||||||
|
|
||||||
|
|
||||||
def remove_empty_secrets(secrets: Dict[str, Any]) -> Dict[str, Any]:
|
def remove_empty_secrets(secrets: Dict[str, Any]) -> Dict[str, Any]:
|
||||||
@@ -189,3 +205,52 @@ def remove_empty_secrets(secrets: Dict[str, Any]) -> Dict[str, Any]:
|
|||||||
elif v is not None and not (isinstance(v, str) and v.strip() == ''):
|
elif v is not None and not (isinstance(v, str) and v.strip() == ''):
|
||||||
result[k] = v
|
result[k] = v
|
||||||
return result
|
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 isinstance(v, list):
|
||||||
|
# A list is merged by replacement, not element by element -- there
|
||||||
|
# is no identity to match entries on -- so a list that still holds
|
||||||
|
# a mask cannot be merged safely: keeping it would store bullets,
|
||||||
|
# and keeping the submitted entries alone would drop whichever the
|
||||||
|
# client did not send back. Dropping the key leaves the stored
|
||||||
|
# list untouched, which is what an untouched list should do.
|
||||||
|
#
|
||||||
|
# The consequence, deliberately: editing one secret inside a list
|
||||||
|
# through this endpoint requires sending real values for all of
|
||||||
|
# them. Sending some masks leaves the whole list as it was.
|
||||||
|
if not _contains_mask(v):
|
||||||
|
result[k] = v
|
||||||
|
elif v is None:
|
||||||
|
continue
|
||||||
|
elif isinstance(v, str) and (v.strip() == '' or v == SECRET_MASK):
|
||||||
|
continue
|
||||||
|
else:
|
||||||
|
result[k] = v
|
||||||
|
return result
|
||||||
|
|
||||||
|
|
||||||
|
def _contains_mask(value: Any) -> bool:
|
||||||
|
"""True when a mask sentinel survives anywhere inside ``value``."""
|
||||||
|
if isinstance(value, dict):
|
||||||
|
return any(_contains_mask(v) for v in value.values())
|
||||||
|
if isinstance(value, list):
|
||||||
|
return any(_contains_mask(item) for item in value)
|
||||||
|
return value == SECRET_MASK
|
||||||
|
|||||||
Regular → Executable
Regular → Executable
@@ -8,6 +8,18 @@ Type=simple
|
|||||||
User=root
|
User=root
|
||||||
WorkingDirectory=__PROJECT_ROOT_DIR__
|
WorkingDirectory=__PROJECT_ROOT_DIR__
|
||||||
Environment=PYTHONDONTWRITEBYTECODE=1
|
Environment=PYTHONDONTWRITEBYTECODE=1
|
||||||
|
# glibc gives each allocating thread its own malloc arena, up to 8 x CPU count,
|
||||||
|
# and an arena that has grown is never handed back to the OS. This process runs
|
||||||
|
# 9 threads on a 3-core Pi, so the ceiling is 24 arenas -- and a rig measured at
|
||||||
|
# 1030 MB resident held 23 large anonymous mappings on 64 MB-aligned addresses,
|
||||||
|
# 920 MB of them, while the live data it was actually holding (widest scroll
|
||||||
|
# strip seen: 35,746 x 64) accounts for roughly 15 MB. That gap is arena bloat,
|
||||||
|
# not leaked objects: RSS was flat across repeated sampling, not climbing.
|
||||||
|
#
|
||||||
|
# Capping the arenas trades a little allocator concurrency for a large amount of
|
||||||
|
# resident memory on a device that has neither to spare. 2 is the usual value;
|
||||||
|
# raise it if frame times regress.
|
||||||
|
Environment=MALLOC_ARENA_MAX=2
|
||||||
ExecStart=/usr/bin/python3 __PROJECT_ROOT_DIR__/run.py
|
ExecStart=/usr/bin/python3 __PROJECT_ROOT_DIR__/run.py
|
||||||
# Restart=always, not on-failure: run.py exiting 0 (a clean shutdown path taken
|
# Restart=always, not on-failure: run.py exiting 0 (a clean shutdown path taken
|
||||||
# for a reason that no longer applies, e.g. a config reload) would otherwise leave
|
# for a reason that no longer applies, e.g. a config reload) would otherwise leave
|
||||||
|
|||||||
@@ -0,0 +1,143 @@
|
|||||||
|
"""GET /config/main must not hand out credentials.
|
||||||
|
|
||||||
|
The endpoint returned the raw config to anyone who could reach the port, and
|
||||||
|
this web interface has no authentication of any kind. Measured against a live
|
||||||
|
rig, an unauthenticated request returned:
|
||||||
|
|
||||||
|
github.api_token 40 chars
|
||||||
|
incoming-packages.ha_token 183 chars
|
||||||
|
jellyfin-now-playing.api_key 32 chars
|
||||||
|
ledmatrix-weather.api_key 32 chars
|
||||||
|
on-air.mqtt_password 8 chars
|
||||||
|
youtube.api_key 20 chars
|
||||||
|
youtube-stats.api_key 39 chars
|
||||||
|
|
||||||
|
A GitHub token and a Home Assistant long-lived token among them.
|
||||||
|
|
||||||
|
The x-secret masking the plugin config endpoints use does not apply here: this
|
||||||
|
endpoint never consults a schema, and core keys such as github.api_token have
|
||||||
|
no schema to carry the marker. Several of those fields *are* tagged x-secret in
|
||||||
|
their plugin's schema and were still returned in full, which is what makes the
|
||||||
|
schema route the wrong one to rely on for this endpoint.
|
||||||
|
|
||||||
|
Matching on field name is blunt. For a whole-config dump it is the right
|
||||||
|
default: anything named like a credential should not leave the process, and a
|
||||||
|
new plugin that adds a differently-shaped secret is covered without anyone
|
||||||
|
remembering to tag it.
|
||||||
|
"""
|
||||||
|
import pytest
|
||||||
|
|
||||||
|
from web_interface.blueprints.api_v3 import (
|
||||||
|
_looks_like_a_credential,
|
||||||
|
_redact_credentials,
|
||||||
|
)
|
||||||
|
|
||||||
|
|
||||||
|
@pytest.mark.parametrize("name", [
|
||||||
|
"password", "mqtt_password", "opensky_password", "passwd",
|
||||||
|
"api_key", "apikey", "API_KEY", "flightaware_api_key",
|
||||||
|
"token", "ha_token", "api_token", "access_token",
|
||||||
|
"secret", "client_secret", "spotify_client_secret",
|
||||||
|
"access_key", "private_key",
|
||||||
|
])
|
||||||
|
def test_credential_names_are_recognised(name):
|
||||||
|
assert _looks_like_a_credential(name)
|
||||||
|
|
||||||
|
|
||||||
|
@pytest.mark.parametrize("name", [
|
||||||
|
"timezone", "city", "brightness", "enabled", "update_interval",
|
||||||
|
"favorite_teams", "display_duration", "keyword",
|
||||||
|
])
|
||||||
|
def test_ordinary_names_are_left_alone(name):
|
||||||
|
assert not _looks_like_a_credential(name)
|
||||||
|
|
||||||
|
|
||||||
|
def test_the_measured_leak_is_closed():
|
||||||
|
"""The exact shape taken off the rig."""
|
||||||
|
config = {
|
||||||
|
"github": {"api_token": "ghp_" + "x" * 36},
|
||||||
|
"incoming-packages": {"ha_token": "y" * 183, "enabled": True},
|
||||||
|
"jellyfin-now-playing": {"api_key": "z" * 32},
|
||||||
|
"on-air": {"mqtt_password": "hunter22"},
|
||||||
|
"youtube": {"api_key": "k" * 20},
|
||||||
|
"timezone": "America/New_York",
|
||||||
|
}
|
||||||
|
out = _redact_credentials(config)
|
||||||
|
assert out["github"]["api_token"] == ""
|
||||||
|
assert out["incoming-packages"]["ha_token"] == ""
|
||||||
|
assert out["jellyfin-now-playing"]["api_key"] == ""
|
||||||
|
assert out["on-air"]["mqtt_password"] == ""
|
||||||
|
assert out["youtube"]["api_key"] == ""
|
||||||
|
# Everything else survives, or the config editor breaks.
|
||||||
|
assert out["timezone"] == "America/New_York"
|
||||||
|
assert out["incoming-packages"]["enabled"] is True
|
||||||
|
|
||||||
|
|
||||||
|
def test_nested_and_listed_credentials_are_reached():
|
||||||
|
config = {"a": {"b": {"c": {"password": "p"}}},
|
||||||
|
"feeds": [{"name": "x", "api_key": "k"}, {"name": "y"}]}
|
||||||
|
out = _redact_credentials(config)
|
||||||
|
assert out["a"]["b"]["c"]["password"] == ""
|
||||||
|
assert out["feeds"][0]["api_key"] == ""
|
||||||
|
assert out["feeds"][0]["name"] == "x"
|
||||||
|
|
||||||
|
|
||||||
|
def test_the_original_is_not_mutated():
|
||||||
|
"""The caller holds the live config; redaction must not edit it in place."""
|
||||||
|
config = {"github": {"api_token": "keepme"}}
|
||||||
|
_redact_credentials(config)
|
||||||
|
assert config["github"]["api_token"] == "keepme"
|
||||||
|
|
||||||
|
|
||||||
|
def test_a_credential_shaped_container_is_still_walked():
|
||||||
|
"""`secrets: {...}` is a section name, not a value to blank."""
|
||||||
|
config = {"secrets": {"api_key": "k", "note": "keep"}}
|
||||||
|
out = _redact_credentials(config)
|
||||||
|
assert out["secrets"]["api_key"] == ""
|
||||||
|
assert out["secrets"]["note"] == "keep"
|
||||||
|
|
||||||
|
|
||||||
|
def test_non_dict_input_passes_through():
|
||||||
|
assert _redact_credentials("plain") == "plain"
|
||||||
|
assert _redact_credentials(7) == 7
|
||||||
|
assert _redact_credentials(None) is None
|
||||||
|
|
||||||
|
|
||||||
|
def test_the_endpoint_itself_redacts():
|
||||||
|
"""Through the view function, not the helper.
|
||||||
|
|
||||||
|
The helper tests above all passed with the route still returning
|
||||||
|
`config` -- reverting the one line that calls the redactor changed
|
||||||
|
nothing, because nothing exercised the route. A property asserted on a
|
||||||
|
helper is not a property asserted on the endpoint, and it is the endpoint
|
||||||
|
that is exposed to the network.
|
||||||
|
"""
|
||||||
|
import json as _json
|
||||||
|
from unittest.mock import MagicMock
|
||||||
|
|
||||||
|
import flask
|
||||||
|
|
||||||
|
from web_interface.blueprints import api_v3 as mod
|
||||||
|
|
||||||
|
raw = {"github": {"api_token": "ghp_secret_value"},
|
||||||
|
"timezone": "America/New_York"}
|
||||||
|
|
||||||
|
manager = MagicMock()
|
||||||
|
manager.load_config.return_value = raw
|
||||||
|
previous = getattr(mod.api_v3, "config_manager", None)
|
||||||
|
mod.api_v3.config_manager = manager
|
||||||
|
|
||||||
|
app = flask.Flask(__name__)
|
||||||
|
try:
|
||||||
|
with app.test_request_context("/config/main"):
|
||||||
|
response = mod.get_main_config()
|
||||||
|
payload = response.get_json() if hasattr(response, "get_json") else _json.loads(response[0].data)
|
||||||
|
finally:
|
||||||
|
mod.api_v3.config_manager = previous
|
||||||
|
|
||||||
|
data = payload["data"]
|
||||||
|
assert data["github"]["api_token"] == "", (
|
||||||
|
"the endpoint returned the token; the redactor is not wired in")
|
||||||
|
assert data["timezone"] == "America/New_York"
|
||||||
|
# And the config the manager handed over is untouched.
|
||||||
|
assert raw["github"]["api_token"] == "ghp_secret_value"
|
||||||
@@ -58,7 +58,7 @@ def repos(tmp_path):
|
|||||||
def test_branch_with_upstream_uses_a_plain_pull(repos):
|
def test_branch_with_upstream_uses_a_plain_pull(repos):
|
||||||
args, note, error = resolve_pull_command(str(repos))
|
args, note, error = resolve_pull_command(str(repos))
|
||||||
assert error is None
|
assert error is None
|
||||||
assert args == ['git', 'pull', '--rebase']
|
assert args == ['git', 'pull', '--rebase', '--autostash']
|
||||||
assert note == ''
|
assert note == ''
|
||||||
|
|
||||||
|
|
||||||
@@ -73,7 +73,7 @@ def test_branch_without_upstream_falls_back_to_origin_branch(repos):
|
|||||||
|
|
||||||
args, note, error = resolve_pull_command(str(repos))
|
args, note, error = resolve_pull_command(str(repos))
|
||||||
assert error is None
|
assert error is None
|
||||||
assert args == ['git', 'pull', '--rebase', 'origin', 'audit']
|
assert args == ['git', 'pull', '--rebase', '--autostash', 'origin', 'audit']
|
||||||
assert 'audit' in note
|
assert 'audit' in note
|
||||||
|
|
||||||
|
|
||||||
@@ -155,7 +155,7 @@ def test_switching_attaches_tracking_so_pull_needs_no_fallback(repos):
|
|||||||
|
|
||||||
args, note, error = resolve_pull_command(str(repos))
|
args, note, error = resolve_pull_command(str(repos))
|
||||||
assert error is None
|
assert error is None
|
||||||
assert args == ['git', 'pull', '--rebase']
|
assert args == ['git', 'pull', '--rebase', '--autostash']
|
||||||
assert note == ''
|
assert note == ''
|
||||||
|
|
||||||
|
|
||||||
@@ -200,3 +200,44 @@ def test_stash_option_lets_the_switch_through_and_keeps_the_work(repos):
|
|||||||
assert _git('branch', '--show-current', cwd=repos).stdout.strip() == 'other'
|
assert _git('branch', '--show-current', cwd=repos).stdout.strip() == 'other'
|
||||||
# The edit is not lost — it is on the stash.
|
# The edit is not lost — it is on the stash.
|
||||||
assert 'switch to other' in _git('stash', 'list', cwd=repos).stdout
|
assert 'switch to other' in _git('stash', 'list', cwd=repos).stdout
|
||||||
|
|
||||||
|
|
||||||
|
class TestInstallerDoesNotBlockTheUpdateButton:
|
||||||
|
"""first_time_install.sh chmods scripts that git tracked as 644.
|
||||||
|
|
||||||
|
With core.fileMode true -- the default on Linux -- that leaves five
|
||||||
|
permanently modified tracked files on every machine that ran the
|
||||||
|
installer, and `git pull --rebase` refuses to start:
|
||||||
|
|
||||||
|
error: cannot pull with rebase: You have unstaged changes.
|
||||||
|
|
||||||
|
Tracking them as executable makes the installer's chmod a no-op.
|
||||||
|
"""
|
||||||
|
|
||||||
|
CHMODDED = [
|
||||||
|
'first_time_install.sh',
|
||||||
|
'start_display.sh',
|
||||||
|
'stop_display.sh',
|
||||||
|
'scripts/install/install_service.sh',
|
||||||
|
'scripts/install/install_web_service.sh',
|
||||||
|
]
|
||||||
|
|
||||||
|
def test_scripts_the_installer_chmods_are_tracked_executable(self):
|
||||||
|
import subprocess
|
||||||
|
from pathlib import Path
|
||||||
|
root = Path(__file__).resolve().parent.parent
|
||||||
|
out = subprocess.run(['git', 'ls-files', '-s', *self.CHMODDED],
|
||||||
|
capture_output=True, text=True, cwd=str(root)).stdout
|
||||||
|
modes = {line.split()[3]: line.split()[0] for line in out.strip().split('\n') if line}
|
||||||
|
# git ls-files says nothing about a path it does not track, so a
|
||||||
|
# renamed or deleted script would simply be absent here and the mode
|
||||||
|
# check below would pass over it silently.
|
||||||
|
untracked = sorted(set(self.CHMODDED) - set(modes))
|
||||||
|
assert not untracked, (
|
||||||
|
f"{untracked} are chmodded by the installer but not tracked by "
|
||||||
|
"git, so their mode cannot be asserted at all")
|
||||||
|
non_exec = sorted(f for f, m in modes.items() if m != '100755')
|
||||||
|
assert not non_exec, (
|
||||||
|
f"{non_exec} are chmodded by the installer but tracked non-executable, "
|
||||||
|
"so every install leaves the working tree dirty and the update "
|
||||||
|
"button cannot pull")
|
||||||
|
|||||||
@@ -0,0 +1,119 @@
|
|||||||
|
"""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 copy
|
||||||
|
|
||||||
|
import pytest
|
||||||
|
|
||||||
|
from src.plugin_system.plugin_health import PluginHealthTracker, CircuitState
|
||||||
|
|
||||||
|
|
||||||
|
class _Cache:
|
||||||
|
"""Counts writes; serves back whatever was last written.
|
||||||
|
|
||||||
|
Both directions deep-copy, so this behaves like a real cache that
|
||||||
|
serialises through a file. Storing by reference let the tracker keep
|
||||||
|
mutating the object already in the store, so a record could appear to
|
||||||
|
have been persisted when no write ever happened -- which is precisely
|
||||||
|
what test_durable_state_survives_a_restart is supposed to detect.
|
||||||
|
"""
|
||||||
|
|
||||||
|
def __init__(self):
|
||||||
|
self.store = {}
|
||||||
|
self.writes = 0
|
||||||
|
|
||||||
|
def set(self, key, data, ttl=None, **kwargs):
|
||||||
|
self.writes += 1
|
||||||
|
self.store[key] = copy.deepcopy(data)
|
||||||
|
|
||||||
|
def get(self, key, max_age=None, memory_ttl=None, **kwargs):
|
||||||
|
return copy.deepcopy(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
|
||||||
@@ -13,7 +13,6 @@ need root and mutate the system, so they are exercised manually instead.
|
|||||||
"""
|
"""
|
||||||
|
|
||||||
import subprocess
|
import subprocess
|
||||||
import tempfile
|
|
||||||
from pathlib import Path
|
from pathlib import Path
|
||||||
|
|
||||||
import pytest
|
import pytest
|
||||||
@@ -32,16 +31,6 @@ def run_lib(snippet: str, env: dict | None = None) -> subprocess.CompletedProces
|
|||||||
)
|
)
|
||||||
|
|
||||||
|
|
||||||
def _fstype_of(path: object) -> str:
|
|
||||||
"""Filesystem type backing ``path``, via the same tool the helper uses."""
|
|
||||||
result = subprocess.run(
|
|
||||||
["findmnt", "-no", "FSTYPE", "--target", str(path)],
|
|
||||||
capture_output=True, text=True,
|
|
||||||
env={"PATH": "/usr/bin:/bin:/usr/sbin:/sbin"},
|
|
||||||
)
|
|
||||||
return result.stdout.strip()
|
|
||||||
|
|
||||||
|
|
||||||
def call(fn: str, *args: object, env: dict | None = None) -> str:
|
def call(fn: str, *args: object, env: dict | None = None) -> str:
|
||||||
joined = " ".join(str(a) for a in args)
|
joined = " ".join(str(a) for a in args)
|
||||||
result = run_lib(f"{fn} {joined}", env=env)
|
result = run_lib(f"{fn} {joined}", env=env)
|
||||||
@@ -206,29 +195,8 @@ class TestOomDetection:
|
|||||||
|
|
||||||
class TestDiskBackedTmpdir:
|
class TestDiskBackedTmpdir:
|
||||||
def test_returns_nothing_when_tmpdir_is_already_disk_backed(self, tmp_path):
|
def test_returns_nothing_when_tmpdir_is_already_disk_backed(self, tmp_path):
|
||||||
# Do not assume tmp_path is disk-backed. Debian 13 -- the platform this
|
# tmp_path is on the regular filesystem, so the default must be kept.
|
||||||
# helper exists for -- mounts /tmp as tmpfs, and pytest puts tmp_path
|
assert call("lm_disk_backed_tmpdir", env={"TMPDIR": str(tmp_path)}) == ""
|
||||||
# under /tmp, so this asserted against a *memory*-backed directory and
|
|
||||||
# failed on the target platform while the helper behaved exactly as
|
|
||||||
# designed. Search for a directory whose backing store is really disk.
|
|
||||||
scratch = None
|
|
||||||
disk_backed = None
|
|
||||||
for candidate in (tmp_path, Path("/var/tmp"), LIB.parent):
|
|
||||||
if _fstype_of(candidate) not in ("tmpfs", "ramfs", ""):
|
|
||||||
if candidate is tmp_path:
|
|
||||||
disk_backed = candidate
|
|
||||||
else:
|
|
||||||
scratch = Path(tempfile.mkdtemp(dir=str(candidate)))
|
|
||||||
disk_backed = scratch
|
|
||||||
break
|
|
||||||
if disk_backed is None:
|
|
||||||
pytest.skip("no disk-backed directory available to test against")
|
|
||||||
try:
|
|
||||||
assert call("lm_disk_backed_tmpdir",
|
|
||||||
env={"TMPDIR": str(disk_backed)}) == ""
|
|
||||||
finally:
|
|
||||||
if scratch is not None:
|
|
||||||
scratch.rmdir()
|
|
||||||
|
|
||||||
def test_redirects_away_from_a_memory_backed_tmpdir(self):
|
def test_redirects_away_from_a_memory_backed_tmpdir(self):
|
||||||
# Debian 13 mounts /tmp as tmpfs, which would otherwise hold the whole
|
# Debian 13 mounts /tmp as tmpfs, which would otherwise hold the whole
|
||||||
|
|||||||
@@ -0,0 +1,137 @@
|
|||||||
|
"""Log lines must reach the journal with their real severity.
|
||||||
|
|
||||||
|
Everything this process writes to stdout lands in the journal as PRIORITY=6,
|
||||||
|
whatever the Python level was, because journald has no other signal. Measured
|
||||||
|
on a live rig over 24 hours: 55 lines containing " - ERROR - " and 13
|
||||||
|
containing " - WARNING - ", every one of them recorded as informational. So
|
||||||
|
|
||||||
|
journalctl -p err -u ledmatrix
|
||||||
|
|
||||||
|
returned nothing while errors were being logged, and anyone triaging has to
|
||||||
|
grep the message text instead. That is slower and it is wrong: a search for
|
||||||
|
"oom" also matches the radar logging "zoom=9", which is exactly the false
|
||||||
|
positive it produced during this audit.
|
||||||
|
|
||||||
|
systemd reads a leading "<N>" on each stdout line and uses it as the priority
|
||||||
|
(sd-daemon(3)), so this needs no extra dependency -- and it must only be
|
||||||
|
applied when systemd is actually reading, or the prefixes become literal noise
|
||||||
|
in a terminal, the emulator, and test output.
|
||||||
|
"""
|
||||||
|
import logging
|
||||||
|
import os
|
||||||
|
import sys
|
||||||
|
from unittest.mock import patch
|
||||||
|
|
||||||
|
import pytest
|
||||||
|
|
||||||
|
from src.logging_config import JournalPriorityFormatter, _SYSLOG_PRIORITY, _under_systemd
|
||||||
|
|
||||||
|
|
||||||
|
class _Plain(logging.Formatter):
|
||||||
|
def format(self, record):
|
||||||
|
return record.getMessage()
|
||||||
|
|
||||||
|
|
||||||
|
def _record(level, msg="hello"):
|
||||||
|
return logging.LogRecord("t", level, "f.py", 1, msg, None, None)
|
||||||
|
|
||||||
|
|
||||||
|
@pytest.mark.parametrize("level,expected", [
|
||||||
|
(logging.CRITICAL, 2),
|
||||||
|
(logging.ERROR, 3),
|
||||||
|
(logging.WARNING, 4),
|
||||||
|
(logging.INFO, 6),
|
||||||
|
(logging.DEBUG, 7),
|
||||||
|
])
|
||||||
|
def test_each_level_maps_to_its_syslog_priority(level, expected):
|
||||||
|
out = JournalPriorityFormatter(_Plain()).format(_record(level))
|
||||||
|
assert out.startswith(f"<{expected}>"), out
|
||||||
|
assert _SYSLOG_PRIORITY[level] == expected
|
||||||
|
|
||||||
|
|
||||||
|
def test_error_and_info_are_distinguishable():
|
||||||
|
"""The whole point: journalctl -p err must be able to tell them apart."""
|
||||||
|
fmt = JournalPriorityFormatter(_Plain())
|
||||||
|
assert fmt.format(_record(logging.ERROR))[:3] != fmt.format(_record(logging.INFO))[:3]
|
||||||
|
|
||||||
|
|
||||||
|
def test_every_line_of_a_multiline_record_is_tagged():
|
||||||
|
"""The journal splits them, and an untagged continuation loses its level.
|
||||||
|
|
||||||
|
A traceback is the case that matters -- it is the most important thing in
|
||||||
|
the log and the longest.
|
||||||
|
"""
|
||||||
|
out = JournalPriorityFormatter(_Plain()).format(
|
||||||
|
_record(logging.ERROR, "Traceback:\nline one\nline two"))
|
||||||
|
lines = out.split("\n")
|
||||||
|
assert len(lines) == 3
|
||||||
|
assert all(line.startswith("<3>") for line in lines), lines
|
||||||
|
|
||||||
|
|
||||||
|
def test_the_message_survives_intact():
|
||||||
|
out = JournalPriorityFormatter(_Plain()).format(_record(logging.WARNING, "disk full"))
|
||||||
|
assert out == "<4>disk full"
|
||||||
|
|
||||||
|
|
||||||
|
def test_an_unknown_level_falls_back_to_info():
|
||||||
|
out = JournalPriorityFormatter(_Plain()).format(_record(25))
|
||||||
|
assert out.startswith("<6>")
|
||||||
|
|
||||||
|
|
||||||
|
def _stdout_ids():
|
||||||
|
"""The dev:ino systemd would publish for this process's stdout."""
|
||||||
|
st = os.fstat(sys.stdout.fileno())
|
||||||
|
return f"{st.st_dev}:{st.st_ino}"
|
||||||
|
|
||||||
|
|
||||||
|
def test_prefixing_is_off_outside_systemd():
|
||||||
|
"""Otherwise a terminal run, the emulator and pytest all show `<6>`."""
|
||||||
|
with patch.dict(os.environ, {}, clear=True):
|
||||||
|
assert not _under_systemd()
|
||||||
|
with patch.dict(os.environ, {"JOURNAL_STREAM": _stdout_ids()}):
|
||||||
|
assert _under_systemd()
|
||||||
|
|
||||||
|
|
||||||
|
def test_an_inherited_journal_stream_does_not_count():
|
||||||
|
"""The variable outlives the descriptor it describes.
|
||||||
|
|
||||||
|
systemd sets JOURNAL_STREAM for the service, and every child inherits it
|
||||||
|
-- including one whose stdout has been redirected to a pipe or a file.
|
||||||
|
Trusting the variable alone put literal "<6>" prefixes into that captured
|
||||||
|
output. Only a descriptor whose dev:ino actually matches is the journal.
|
||||||
|
"""
|
||||||
|
with patch.dict(os.environ, {"JOURNAL_STREAM": "8:12345"}):
|
||||||
|
assert not _under_systemd(), \
|
||||||
|
"a stale inherited JOURNAL_STREAM was treated as the journal"
|
||||||
|
|
||||||
|
|
||||||
|
@pytest.mark.parametrize("value", ["", "not-a-pair", "8", "8:", ":12345",
|
||||||
|
"eight:12345", "8:12345:9"])
|
||||||
|
def test_a_malformed_journal_stream_is_not_the_journal(value):
|
||||||
|
with patch.dict(os.environ, {"JOURNAL_STREAM": value}):
|
||||||
|
assert not _under_systemd()
|
||||||
|
|
||||||
|
|
||||||
|
def test_a_closed_stdout_is_not_the_journal():
|
||||||
|
"""os.fstat raises rather than answers; that must not propagate."""
|
||||||
|
with patch.dict(os.environ, {"JOURNAL_STREAM": "8:12345"}), \
|
||||||
|
patch("src.logging_config.sys.stdout") as fake_stdout:
|
||||||
|
fake_stdout.fileno.side_effect = ValueError("I/O operation on closed file")
|
||||||
|
assert not _under_systemd()
|
||||||
|
|
||||||
|
|
||||||
|
def test_setup_uses_the_wrapper_only_under_systemd():
|
||||||
|
from src.logging_config import setup_logging
|
||||||
|
|
||||||
|
for env, expect_wrapped in (({}, False),
|
||||||
|
({"JOURNAL_STREAM": _stdout_ids()}, True)):
|
||||||
|
with patch.dict(os.environ, env, clear=True):
|
||||||
|
setup_logging()
|
||||||
|
handlers = [h for h in logging.getLogger().handlers
|
||||||
|
if isinstance(h, logging.StreamHandler)]
|
||||||
|
assert handlers, "no stream handler installed"
|
||||||
|
wrapped = any(isinstance(h.formatter, JournalPriorityFormatter)
|
||||||
|
for h in handlers)
|
||||||
|
assert wrapped is expect_wrapped, (
|
||||||
|
f"JOURNAL_STREAM={env}: wrapped={wrapped}, expected {expect_wrapped}")
|
||||||
|
logging.getLogger().handlers.clear()
|
||||||
@@ -183,15 +183,27 @@ class TestSetupLogging:
|
|||||||
setup_logging()
|
setup_logging()
|
||||||
assert len(logging.getLogger().handlers) == 1
|
assert len(logging.getLogger().handlers) == 1
|
||||||
|
|
||||||
|
@staticmethod
|
||||||
|
def _selected_formatter():
|
||||||
|
"""The formatter setup_logging() chose, past any journald wrapper.
|
||||||
|
|
||||||
|
Under systemd the console handler's formatter is wrapped so each line
|
||||||
|
carries its syslog priority. That wrapper is applied only when
|
||||||
|
JOURNAL_STREAM is set, which is true in CI and false in a terminal, so
|
||||||
|
asserting on the handler's formatter directly passes locally and fails
|
||||||
|
on the runner. These tests are about which formatter format_type
|
||||||
|
selects, so they look through the wrapper.
|
||||||
|
"""
|
||||||
|
formatter = logging.getLogger().handlers[0].formatter
|
||||||
|
return getattr(formatter, "inner", formatter)
|
||||||
|
|
||||||
def test_json_format_selects_structured_formatter(self):
|
def test_json_format_selects_structured_formatter(self):
|
||||||
setup_logging(format_type="json")
|
setup_logging(format_type="json")
|
||||||
assert isinstance(
|
assert isinstance(self._selected_formatter(), StructuredFormatter)
|
||||||
logging.getLogger().handlers[0].formatter, StructuredFormatter)
|
|
||||||
|
|
||||||
def test_readable_format_selects_contextual_formatter(self):
|
def test_readable_format_selects_contextual_formatter(self):
|
||||||
setup_logging(format_type="readable")
|
setup_logging(format_type="readable")
|
||||||
assert isinstance(
|
assert isinstance(self._selected_formatter(), ContextualFormatter)
|
||||||
logging.getLogger().handlers[0].formatter, ContextualFormatter)
|
|
||||||
|
|
||||||
def test_log_file_adds_file_handler(self, tmp_path):
|
def test_log_file_adds_file_handler(self, tmp_path):
|
||||||
log_file = tmp_path / "test.log"
|
log_file = tmp_path / "test.log"
|
||||||
|
|||||||
@@ -0,0 +1,128 @@
|
|||||||
|
"""A malformed metrics cache entry must not take every plugin down with it.
|
||||||
|
|
||||||
|
`ResourceMetrics(**cached)` raises TypeError on a single unexpected key, and
|
||||||
|
that exception escapes into plugin_manager, which reports it per plugin as
|
||||||
|
"plugin <id> operation failed". Every plugin fails and the plugin system never
|
||||||
|
finishes initialising -- the health endpoint reports
|
||||||
|
`plugin_system: not_initialized` while the display itself keeps running.
|
||||||
|
|
||||||
|
Seen on a live rig, once per plugin, continuously:
|
||||||
|
|
||||||
|
ERROR - src.plugin_system.plugin_manager - plugin geochron operation failed:
|
||||||
|
ResourceMetrics.__init__() got an unexpected keyword argument
|
||||||
|
'consecutive_failures'
|
||||||
|
|
||||||
|
`consecutive_failures` belongs to plugin_health, not to metrics. How a
|
||||||
|
health-shaped record came to sit under a plugin_metrics key on that machine is
|
||||||
|
not established -- a restored backup that mixed two machines' caches is the
|
||||||
|
likeliest explanation, and the same rig had one restored onto it -- but a
|
||||||
|
loader that turns one bad cache entry into a total outage is the part worth
|
||||||
|
fixing. plugin_health already repairs its own records field by field rather
|
||||||
|
than trusting what is on disk.
|
||||||
|
"""
|
||||||
|
import logging
|
||||||
|
from dataclasses import fields
|
||||||
|
from unittest.mock import MagicMock
|
||||||
|
|
||||||
|
import pytest
|
||||||
|
|
||||||
|
from src.plugin_system.resource_monitor import PluginResourceMonitor, ResourceMetrics
|
||||||
|
|
||||||
|
|
||||||
|
class _Cache:
|
||||||
|
def __init__(self, payload=None):
|
||||||
|
self.payload = payload
|
||||||
|
|
||||||
|
def get(self, key, max_age=None, memory_ttl=None, **kwargs):
|
||||||
|
return self.payload
|
||||||
|
|
||||||
|
def set(self, key, data, ttl=None, **kwargs):
|
||||||
|
pass
|
||||||
|
|
||||||
|
|
||||||
|
def _monitor(payload):
|
||||||
|
m = PluginResourceMonitor(cache_manager=_Cache(payload))
|
||||||
|
m.logger = logging.getLogger("test")
|
||||||
|
return m
|
||||||
|
|
||||||
|
|
||||||
|
#: What the rig actually had under the metrics key.
|
||||||
|
HEALTH_SHAPED = {
|
||||||
|
"consecutive_failures": 0, "circuit_state": "closed",
|
||||||
|
"circuit_opened_time": None, "half_open_start_time": None,
|
||||||
|
"last_error": None, "last_failure_time": None,
|
||||||
|
"last_success_time": 1_700_000_000.0, "total_failures": 0,
|
||||||
|
"total_successes": 42,
|
||||||
|
}
|
||||||
|
|
||||||
|
|
||||||
|
def test_a_health_record_under_the_metrics_key_does_not_raise():
|
||||||
|
"""The exact failure: it must degrade, not take the plugin system down."""
|
||||||
|
monitor = _monitor(HEALTH_SHAPED)
|
||||||
|
metrics = monitor.get_metrics(" plugin-a".strip())
|
||||||
|
assert isinstance(metrics, ResourceMetrics)
|
||||||
|
|
||||||
|
|
||||||
|
def test_recognised_fields_in_a_mixed_record_are_kept():
|
||||||
|
"""Dropping the record wholesale would lose real history unnecessarily."""
|
||||||
|
mixed = dict(HEALTH_SHAPED, call_count=7, memory_mb=12.5)
|
||||||
|
metrics = _monitor(mixed).get_metrics("plugin-b")
|
||||||
|
assert metrics.call_count == 7
|
||||||
|
assert metrics.memory_mb == 12.5
|
||||||
|
|
||||||
|
|
||||||
|
def test_a_clean_record_still_loads_unchanged():
|
||||||
|
clean = {f.name: 3 for f in fields(ResourceMetrics)}
|
||||||
|
metrics = _monitor(clean).get_metrics("plugin-c")
|
||||||
|
for name in (f.name for f in fields(ResourceMetrics)):
|
||||||
|
assert getattr(metrics, name) == 3
|
||||||
|
|
||||||
|
|
||||||
|
def test_unknown_fields_are_named_in_the_log(caplog):
|
||||||
|
"""Silently discarding them would hide a real schema change."""
|
||||||
|
with caplog.at_level(logging.WARNING):
|
||||||
|
_monitor(HEALTH_SHAPED).get_metrics("plugin-d")
|
||||||
|
# getMessage(), not .message: the latter is only populated once a handler
|
||||||
|
# formats the record, so the obvious spelling silently never matches.
|
||||||
|
assert any("consecutive_failures" in r.getMessage() for r in caplog.records), \
|
||||||
|
caplog.text
|
||||||
|
|
||||||
|
|
||||||
|
@pytest.mark.parametrize("payload", ["a string", 42, ["a", "list"]])
|
||||||
|
def test_a_non_mapping_cache_entry_does_not_raise(payload):
|
||||||
|
metrics = _monitor(payload).get_metrics("plugin-e")
|
||||||
|
assert isinstance(metrics, ResourceMetrics)
|
||||||
|
|
||||||
|
|
||||||
|
@pytest.mark.parametrize("bad", [
|
||||||
|
{"call_count": "not a number"},
|
||||||
|
{"memory_mb": None},
|
||||||
|
{"execution_time": {"nested": "junk"}},
|
||||||
|
{"min_execution_time": ["a", "list"]},
|
||||||
|
])
|
||||||
|
def test_values_of_the_wrong_type_fall_back_to_usable_defaults(bad):
|
||||||
|
"""isinstance() alone was not enough.
|
||||||
|
|
||||||
|
A dataclass does not enforce its annotations, so the bad value was simply
|
||||||
|
stored and the old assertion passed -- then monitor_call() raised
|
||||||
|
"can only concatenate str (not \"int\") to str" on the next call. The
|
||||||
|
metrics must come back *usable*, not merely constructed.
|
||||||
|
"""
|
||||||
|
monitor = _monitor(bad)
|
||||||
|
metrics = monitor.get_metrics("plugin-f")
|
||||||
|
assert isinstance(metrics, ResourceMetrics)
|
||||||
|
|
||||||
|
field_name = next(iter(bad))
|
||||||
|
assert isinstance(getattr(metrics, field_name), (int, float)), \
|
||||||
|
f"{field_name} came back as {getattr(metrics, field_name)!r}"
|
||||||
|
|
||||||
|
# The real proof: arithmetic on the loaded metrics must not explode.
|
||||||
|
metrics.call_count += 1
|
||||||
|
metrics.total_execution_time += 0.5
|
||||||
|
metrics.update_average_execution_time()
|
||||||
|
|
||||||
|
|
||||||
|
def test_a_numeric_string_is_accepted_rather_than_discarded():
|
||||||
|
"""JSON round-trips can widen an int to a string; that is recoverable."""
|
||||||
|
metrics = _monitor({"call_count": "7"}).get_metrics("plugin-g")
|
||||||
|
assert metrics.call_count == 7
|
||||||
@@ -11,7 +11,7 @@ Focus areas:
|
|||||||
import time
|
import time
|
||||||
|
|
||||||
import pytest
|
import pytest
|
||||||
from unittest.mock import MagicMock
|
from unittest.mock import MagicMock, patch
|
||||||
|
|
||||||
from src.plugin_system.resource_monitor import (
|
from src.plugin_system.resource_monitor import (
|
||||||
PluginResourceMonitor,
|
PluginResourceMonitor,
|
||||||
@@ -127,3 +127,87 @@ class TestForceReload:
|
|||||||
fresh = mon.get_metrics_summary("p", force_reload=True)
|
fresh = mon.get_metrics_summary("p", force_reload=True)
|
||||||
assert fresh["call_count"] == 7
|
assert fresh["call_count"] == 7
|
||||||
assert any(c.kwargs.get("memory_ttl") == 0 for c in cache.get.call_args_list)
|
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_the_first_snapshot_is_written_even_seconds_after_boot(self):
|
||||||
|
"""The throttle must key off "have we written?", not process uptime.
|
||||||
|
|
||||||
|
time.monotonic() is time since boot on Linux, and systemd starts this
|
||||||
|
service at boot. With 0.0 as the missing-timestamp default,
|
||||||
|
`now - 0.0 < 30` was true for the first half-minute of every run, so
|
||||||
|
the very first metrics write -- the one that matters most after a
|
||||||
|
restart -- was silently skipped.
|
||||||
|
"""
|
||||||
|
import src.plugin_system.resource_monitor as rm
|
||||||
|
cache = _cache()
|
||||||
|
mon = PluginResourceMonitor(cache, enable_monitoring=False)
|
||||||
|
# 12 seconds after boot: inside the interval, but nothing written yet.
|
||||||
|
with patch.object(rm.time, "monotonic", return_value=12.0):
|
||||||
|
mon.monitor_call("p", lambda: None)
|
||||||
|
writes = [c for c in cache.set.call_args_list
|
||||||
|
if "plugin_metrics:" in str(c)]
|
||||||
|
assert writes, \
|
||||||
|
"the first snapshot was dropped because the process was young"
|
||||||
|
|
||||||
|
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"
|
||||||
|
|||||||
@@ -0,0 +1,147 @@
|
|||||||
|
"""The captive portal's fixed-argument sudo calls must be granted.
|
||||||
|
|
||||||
|
The installers write two allow-lists, /etc/sudoers.d/ledmatrix_web and
|
||||||
|
ledmatrix_wifi. A sudo call absent from both needs a password, which a service
|
||||||
|
cannot supply, so it fails.
|
||||||
|
|
||||||
|
Four such calls were ungranted, all of them captive-portal teardown/setup:
|
||||||
|
|
||||||
|
sysctl -w net.ipv4.ip_forward=0|1 wifi_manager.py:788, 883
|
||||||
|
nft add|delete table ip ledmatrix wifi_manager.py:835, 895
|
||||||
|
rfkill unblock wifi wifi_manager.py:1811
|
||||||
|
mkdir -p .../dnsmasq-shared.d wifi_manager.py:922
|
||||||
|
|
||||||
|
It goes unnoticed because a stock Raspberry Pi image ships
|
||||||
|
/etc/sudoers.d/010_pi-nopasswd granting the default user
|
||||||
|
`ALL=(ALL) NOPASSWD: ALL`, which satisfies every gap in both files. It only
|
||||||
|
bites once that blanket rule is removed or the service runs as another user.
|
||||||
|
|
||||||
|
Scope, deliberately narrow: this pins the four commands above, each of which
|
||||||
|
can be written out literally. The portal makes further sudo calls whose
|
||||||
|
arguments are built at runtime -- iptables and nft rules carrying an interface
|
||||||
|
name and a port, `ip addr`, `ip link` -- and those cannot be granted safely
|
||||||
|
here. A rule covering them needs a trailing wildcard, and
|
||||||
|
`iptables --modprobe=/path/to/anything` runs that path as root, so
|
||||||
|
`NOPASSWD: iptables *` is a root shell for the web user by another name.
|
||||||
|
Closing that half needs a privileged helper that builds the rules itself and
|
||||||
|
takes only an interface and a port, granted the way safe_plugin_rm.sh already
|
||||||
|
is. That is a design decision, not a one-line grant, and belongs in its own
|
||||||
|
change.
|
||||||
|
"""
|
||||||
|
import re
|
||||||
|
from pathlib import Path
|
||||||
|
|
||||||
|
import pytest
|
||||||
|
|
||||||
|
ROOT = Path(__file__).resolve().parent.parent
|
||||||
|
INSTALLERS = (
|
||||||
|
ROOT / "first_time_install.sh",
|
||||||
|
ROOT / "scripts" / "install" / "configure_wifi_permissions.sh",
|
||||||
|
)
|
||||||
|
|
||||||
|
#: Commands this change grants, each fully literal in the source.
|
||||||
|
REQUIRED = (
|
||||||
|
("sysctl", "-w", "net.ipv4.ip_forward=0"),
|
||||||
|
("sysctl", "-w", "net.ipv4.ip_forward=1"),
|
||||||
|
("nft", "add", "table", "ip", "ledmatrix"),
|
||||||
|
("nft", "delete", "table", "ip", "ledmatrix"),
|
||||||
|
("rfkill", "unblock", "wifi"),
|
||||||
|
("mkdir", "-p", "/etc/NetworkManager/dnsmasq-shared.d"),
|
||||||
|
)
|
||||||
|
|
||||||
|
#: Tools with an option that executes a program of the caller's choosing.
|
||||||
|
#: A trailing wildcard on any of these is a privilege escalation.
|
||||||
|
EXEC_CAPABLE = ("iptables", "ip6tables", "nft", "tcpdump", "find", "awk",
|
||||||
|
"sed", "perl", "python", "python3", "env")
|
||||||
|
|
||||||
|
|
||||||
|
def _grant_lines():
|
||||||
|
lines = []
|
||||||
|
for installer in INSTALLERS:
|
||||||
|
if not installer.is_file():
|
||||||
|
continue
|
||||||
|
for line in installer.read_text(encoding="utf-8", errors="replace").splitlines():
|
||||||
|
if "NOPASSWD:" in line:
|
||||||
|
lines.append(line.split("NOPASSWD:", 1)[1])
|
||||||
|
return lines
|
||||||
|
|
||||||
|
|
||||||
|
def _normalise(rule):
|
||||||
|
"""One rule with binary-path variables reduced to bare tool names.
|
||||||
|
|
||||||
|
Rules are written as `$SYSCTL_PATH -w ...` or `${NFT_PATH} ...`, so
|
||||||
|
matching the literal "sysctl" finds nothing and every rule looks absent --
|
||||||
|
which is exactly how an earlier version of this test reported six gaps
|
||||||
|
that did not exist. Both spellings are handled: shell expands them
|
||||||
|
identically, and a check that understood only one silently skipped the
|
||||||
|
other.
|
||||||
|
"""
|
||||||
|
rule = re.sub(r"\$\{?([A-Z][A-Z0-9_]*)_PATH\}?",
|
||||||
|
lambda m: m.group(1).lower(), rule)
|
||||||
|
return re.sub(r"/usr/(?:s?bin)/", "", rule)
|
||||||
|
|
||||||
|
|
||||||
|
def _granted_commands():
|
||||||
|
"""The command each NOPASSWD rule actually grants, normalised.
|
||||||
|
|
||||||
|
_grant_lines() already returns everything after "NOPASSWD:", so what
|
||||||
|
arrives here is the command, possibly preceded by the NOEXEC tag and
|
||||||
|
possibly still carrying the closing quote of an `echo "..."` that wrote
|
||||||
|
it. Both are stripped so the result is comparable to a plain command.
|
||||||
|
"""
|
||||||
|
commands = []
|
||||||
|
for rule in _grant_lines():
|
||||||
|
command = _normalise(rule).strip()
|
||||||
|
command = re.sub(r"^NOEXEC:\s*", "", command)
|
||||||
|
command = command.rstrip('"').rstrip("'").strip()
|
||||||
|
if command:
|
||||||
|
commands.append(" ".join(command.split()))
|
||||||
|
return commands
|
||||||
|
|
||||||
|
|
||||||
|
def test_the_installers_are_present():
|
||||||
|
missing = [str(p.relative_to(ROOT)) for p in INSTALLERS if not p.is_file()]
|
||||||
|
assert not missing, f"installer(s) missing: {missing}"
|
||||||
|
|
||||||
|
|
||||||
|
@pytest.mark.parametrize("command", REQUIRED, ids=lambda c: " ".join(c))
|
||||||
|
def test_the_command_is_granted(command):
|
||||||
|
"""Whole command, not just the binary.
|
||||||
|
|
||||||
|
Checking only the binary made this far weaker than it looked: with
|
||||||
|
`sysctl` present anywhere, deleting the ip_forward=0 grant still passed,
|
||||||
|
and the portal would then be unable to restore forwarding on teardown.
|
||||||
|
"""
|
||||||
|
wanted = " ".join(command)
|
||||||
|
granted = _granted_commands()
|
||||||
|
# Exact match, not a prefix. A substring search was satisfied by
|
||||||
|
# `sysctl -w net.ipv4.ip_forward=0 *`, and that trailing wildcard lets the
|
||||||
|
# caller append whatever they like to a command running as root -- a far
|
||||||
|
# wider grant than the one this test is meant to be confirming.
|
||||||
|
assert wanted in granted, (
|
||||||
|
f"no installer grants exactly `{wanted}`; closest matches: "
|
||||||
|
+ str([g for g in granted if g.startswith(command[0])])[:200])
|
||||||
|
|
||||||
|
|
||||||
|
def test_no_wildcard_on_a_tool_that_can_exec():
|
||||||
|
"""`NOPASSWD: iptables *` hands the web user root.
|
||||||
|
|
||||||
|
iptables --modprobe=/path runs that path as root. This caught a grant added
|
||||||
|
in this very change, which is why it is here.
|
||||||
|
"""
|
||||||
|
offenders = []
|
||||||
|
for rule in _grant_lines():
|
||||||
|
rule = rule.strip()
|
||||||
|
if not rule.endswith("*"):
|
||||||
|
continue
|
||||||
|
# Normalised the same way as everything else: `${NFT_PATH} *` left a
|
||||||
|
# brace before the tool name, and the word-boundary check below does
|
||||||
|
# not treat "{" as a boundary, so that spelling slipped through.
|
||||||
|
haystack = _normalise(rule).lower()
|
||||||
|
for tool in EXEC_CAPABLE:
|
||||||
|
if re.search(rf"(^|/|\s|\$){tool}(\s|$)", haystack):
|
||||||
|
offenders.append(rule)
|
||||||
|
break
|
||||||
|
assert not offenders, (
|
||||||
|
"wildcard grant on a tool that can execute another program:\n "
|
||||||
|
+ "\n ".join(offenders))
|
||||||
@@ -30,6 +30,10 @@ ROOT = Path(__file__).resolve().parent.parent
|
|||||||
INSTALLERS = (
|
INSTALLERS = (
|
||||||
ROOT / "first_time_install.sh",
|
ROOT / "first_time_install.sh",
|
||||||
ROOT / "scripts" / "install" / "configure_wifi_permissions.sh",
|
ROOT / "scripts" / "install" / "configure_wifi_permissions.sh",
|
||||||
|
# Writes the same journalctl grants as first_time_install.sh. It was
|
||||||
|
# missing here, and because of that this suite passed while three
|
||||||
|
# ungranted wildcard rules sat in it.
|
||||||
|
ROOT / "scripts" / "install" / "configure_web_sudo.sh",
|
||||||
)
|
)
|
||||||
|
|
||||||
#: Commands that will start another program of their own accord -- a pager, an
|
#: Commands that will start another program of their own accord -- a pager, an
|
||||||
@@ -44,8 +48,14 @@ def _grant_lines():
|
|||||||
continue
|
continue
|
||||||
for line in installer.read_text(encoding="utf-8", errors="replace").splitlines():
|
for line in installer.read_text(encoding="utf-8", errors="replace").splitlines():
|
||||||
stripped = line.strip()
|
stripped = line.strip()
|
||||||
if "NOPASSWD" in stripped and not stripped.startswith("#"):
|
if "NOPASSWD" not in stripped or stripped.startswith("#"):
|
||||||
lines.append(stripped)
|
continue
|
||||||
|
# Installers emit rules two ways: written literally into a heredoc,
|
||||||
|
# or echoed into a file. An echoed rule ends in a quote, so the
|
||||||
|
# trailing-wildcard check below would skip it and the rule would
|
||||||
|
# never be examined at all.
|
||||||
|
echoed = re.fullmatch(r"""echo\s+(['"])(.*)\1""", stripped)
|
||||||
|
lines.append(echoed.group(2) if echoed else stripped)
|
||||||
return lines
|
return lines
|
||||||
|
|
||||||
|
|
||||||
@@ -78,10 +88,12 @@ def test_journalctl_is_granted_at_all():
|
|||||||
"no journalctl grant remains; the web interface reads logs through it")
|
"no journalctl grant remains; the web interface reads logs through it")
|
||||||
|
|
||||||
|
|
||||||
@pytest.mark.parametrize("unit", ["ledmatrix.service", "ledmatrix"])
|
@pytest.mark.parametrize("selector", ["-u ledmatrix.service", "-u ledmatrix",
|
||||||
def test_each_journalctl_rule_is_tagged(unit):
|
"-t ledmatrix"])
|
||||||
|
def test_each_journalctl_rule_is_tagged(selector):
|
||||||
|
"""Every selector, so removing one cannot pass by the others' presence."""
|
||||||
matching = [r for r in _grant_lines()
|
matching = [r for r in _grant_lines()
|
||||||
if "JOURNALCTL_PATH" in r and f"-u {unit} " in r]
|
if "JOURNALCTL_PATH" in r and f"{selector} " in r]
|
||||||
assert matching, f"no journalctl rule for -u {unit}"
|
assert matching, f"no journalctl rule for {selector}"
|
||||||
untagged = [r for r in matching if "NOEXEC" not in r]
|
untagged = [r for r in matching if "NOEXEC" not in r]
|
||||||
assert not untagged, f"untagged journalctl rule(s): {untagged}"
|
assert not untagged, f"untagged journalctl rule(s): {untagged}"
|
||||||
|
|||||||
@@ -0,0 +1,95 @@
|
|||||||
|
"""The display unit must cap glibc's malloc arenas.
|
||||||
|
|
||||||
|
glibc hands each allocating thread its own malloc arena, up to 8 x CPU count,
|
||||||
|
and an arena that has grown is never returned to the OS. This process runs
|
||||||
|
threads for the render loop, the update workers and the background fetchers, so
|
||||||
|
on a 3-core Pi the ceiling is 24 arenas.
|
||||||
|
|
||||||
|
Measured on a live rig, 2.5 hours in:
|
||||||
|
|
||||||
|
RSS 1030 MB
|
||||||
|
Private_Dirty 988 MB
|
||||||
|
anonymous mappings > 10 MB 23 (ceiling is 8 x 3 = 24)
|
||||||
|
largest few 104, 79, 66, 63, 63 MB, on 64 MB-aligned addresses
|
||||||
|
|
||||||
|
against live data that accounts for perhaps 15 MB -- the widest scroll strip
|
||||||
|
observed was 35,746 x 64, about 7 MB as RGB and the same again for its numpy
|
||||||
|
mirror. Repeated sampling showed RSS flat between 990 and 1030 MB rather than
|
||||||
|
climbing, so this is arena bloat rather than a leak: memory Python has freed
|
||||||
|
but glibc is holding per-arena.
|
||||||
|
|
||||||
|
The device had 59 MB free at the time.
|
||||||
|
|
||||||
|
Capping the arena count trades a little allocator concurrency for that resident
|
||||||
|
memory. The render loop is latency-sensitive, so if p99 frame time regresses the
|
||||||
|
right response is to raise this rather than remove it.
|
||||||
|
"""
|
||||||
|
import re
|
||||||
|
from pathlib import Path
|
||||||
|
|
||||||
|
import pytest
|
||||||
|
|
||||||
|
UNIT = (Path(__file__).resolve().parent.parent / "systemd" / "ledmatrix.service")
|
||||||
|
|
||||||
|
#: The value the unit is expected to carry. 2 is the usual choice for a
|
||||||
|
#: threaded Python process; 1-4 all keep some of the saving, but only one of
|
||||||
|
#: them is what this project ships.
|
||||||
|
EXPECTED_ARENA_MAX = 2
|
||||||
|
|
||||||
|
|
||||||
|
def _environment(unit_text):
|
||||||
|
return dict(
|
||||||
|
line.split("=", 2)[1:3] if line.count("=") >= 2 else (line.split("=", 1)[1], "")
|
||||||
|
for line in unit_text.splitlines()
|
||||||
|
if line.startswith("Environment=")
|
||||||
|
)
|
||||||
|
|
||||||
|
|
||||||
|
def test_the_unit_exists():
|
||||||
|
assert UNIT.is_file(), f"{UNIT} is missing"
|
||||||
|
|
||||||
|
|
||||||
|
def test_malloc_arena_max_is_capped():
|
||||||
|
env = _environment(UNIT.read_text(encoding="utf-8"))
|
||||||
|
assert "MALLOC_ARENA_MAX" in env, (
|
||||||
|
"the display unit does not cap glibc arenas; on a 3-core Pi the default "
|
||||||
|
"ceiling is 24 and a measured rig held 23 of them, 920 MB"
|
||||||
|
)
|
||||||
|
value = int(env["MALLOC_ARENA_MAX"])
|
||||||
|
# Pinned, not a range. A range let a change to 4 -- which hands most of the
|
||||||
|
# saving back -- pass unnoticed, which was the point of the finding that
|
||||||
|
# prompted this. Raising it is a legitimate response to a frame-time
|
||||||
|
# regression, but it should be a visible edit here rather than a silent
|
||||||
|
# drift, so the number lives in one place and changing it shows up in
|
||||||
|
# review.
|
||||||
|
assert value == EXPECTED_ARENA_MAX, (
|
||||||
|
f"MALLOC_ARENA_MAX={value}, expected {EXPECTED_ARENA_MAX}. If this was "
|
||||||
|
"raised deliberately because frame times regressed, update "
|
||||||
|
"EXPECTED_ARENA_MAX here and say so in the commit."
|
||||||
|
)
|
||||||
|
|
||||||
|
|
||||||
|
def test_the_reason_is_recorded_next_to_it():
|
||||||
|
"""A bare tuning knob invites removal by whoever meets it next."""
|
||||||
|
text = UNIT.read_text(encoding="utf-8")
|
||||||
|
index = text.index("Environment=MALLOC_ARENA_MAX")
|
||||||
|
preamble = text[:index].splitlines()[-12:]
|
||||||
|
comment = "\n".join(line for line in preamble if line.startswith("#"))
|
||||||
|
assert "arena" in comment.lower(), "no explanation precedes the setting"
|
||||||
|
assert re.search(r"\d", comment), (
|
||||||
|
"the explanation cites no measurement, so a reader cannot tell whether "
|
||||||
|
"it still applies to their hardware"
|
||||||
|
)
|
||||||
|
|
||||||
|
|
||||||
|
@pytest.mark.parametrize("unit", ["ledmatrix.service"])
|
||||||
|
def test_the_unit_still_parses_as_ini(unit):
|
||||||
|
"""systemd will refuse a malformed unit, and the panel stays dark."""
|
||||||
|
import configparser
|
||||||
|
|
||||||
|
path = UNIT.parent / unit
|
||||||
|
parser = configparser.ConfigParser(strict=False)
|
||||||
|
# systemd allows repeated keys; ConfigParser needs them merged, not rejected.
|
||||||
|
parser.read_string(path.read_text(encoding="utf-8"))
|
||||||
|
assert parser.has_section("Service")
|
||||||
|
assert parser.has_option("Service", "ExecStart")
|
||||||
@@ -0,0 +1,152 @@
|
|||||||
|
"""An installed unit that no longer matches the repo's must be reported.
|
||||||
|
|
||||||
|
Nothing re-applies systemd units after the first install. `git pull` -- what
|
||||||
|
the web UI's update button runs -- brings a new template into the checkout, but
|
||||||
|
no code in web_interface/ or src/ copies it to /etc/systemd/system or runs
|
||||||
|
`systemctl daemon-reload`. The unit that actually runs is whatever
|
||||||
|
first_time_install.sh wrote on day one.
|
||||||
|
|
||||||
|
So every hardening added to a unit is inert on existing installs. Measured on a
|
||||||
|
live rig: the installed unit was dated 2026-08-06 and the repo's 2026-08-19,
|
||||||
|
and they differed -- with the result that a MemoryMax=85% present in the repo's
|
||||||
|
template was not being enforced at all. `systemctl show` reported
|
||||||
|
MemoryMax=infinity.
|
||||||
|
|
||||||
|
This is a warning, not an error, and deliberately not a silent rewrite:
|
||||||
|
editing files under /etc and restarting services is the installer's job, not
|
||||||
|
something a display process should do to a machine while it boots.
|
||||||
|
"""
|
||||||
|
import logging
|
||||||
|
from pathlib import Path
|
||||||
|
from unittest.mock import MagicMock
|
||||||
|
|
||||||
|
import pytest
|
||||||
|
|
||||||
|
from src.startup_validator import StartupValidator
|
||||||
|
|
||||||
|
|
||||||
|
@pytest.fixture
|
||||||
|
def validator():
|
||||||
|
v = StartupValidator(config_manager=MagicMock())
|
||||||
|
v.logger = logging.getLogger("test")
|
||||||
|
v.warnings = []
|
||||||
|
v.errors = []
|
||||||
|
return v
|
||||||
|
|
||||||
|
|
||||||
|
def test_a_matching_unit_produces_no_warning(validator, tmp_path):
|
||||||
|
"""The installed unit, substituted exactly as the installer would."""
|
||||||
|
project_root = Path("src/startup_validator.py").resolve().parent.parent
|
||||||
|
template_rel = "systemd/ledmatrix.service"
|
||||||
|
template = project_root / template_rel
|
||||||
|
if not template.is_file():
|
||||||
|
pytest.skip("repo unit template not present")
|
||||||
|
|
||||||
|
installed = tmp_path / "ledmatrix.service"
|
||||||
|
installed.write_text(
|
||||||
|
template.read_text(encoding="utf-8")
|
||||||
|
.replace("__PROJECT_ROOT_DIR__", str(project_root))
|
||||||
|
.replace("__USER__", "root"),
|
||||||
|
encoding="utf-8")
|
||||||
|
|
||||||
|
validator._UNITS = ((template_rel, str(installed)),)
|
||||||
|
validator._validate_systemd_units()
|
||||||
|
assert not validator.warnings, f"a matching unit warned: {validator.warnings}"
|
||||||
|
assert not validator.errors
|
||||||
|
|
||||||
|
|
||||||
|
def test_comments_and_blank_lines_are_not_drift():
|
||||||
|
"""Otherwise every comment the repo adds would look like a changed unit."""
|
||||||
|
a = "[Service]\n# explains a setting\nExecStart=/x\nRestart=always\n"
|
||||||
|
b = "[Service]\nExecStart=/x\n\nRestart=always\n"
|
||||||
|
assert StartupValidator._unit_body(a) == StartupValidator._unit_body(b)
|
||||||
|
|
||||||
|
|
||||||
|
def test_a_changed_directive_is_drift():
|
||||||
|
a = "[Service]\nExecStart=/x\nMemoryMax=85%\n"
|
||||||
|
b = "[Service]\nExecStart=/x\n"
|
||||||
|
assert StartupValidator._unit_body(a) != StartupValidator._unit_body(b)
|
||||||
|
|
||||||
|
|
||||||
|
def test_reordered_directives_are_drift():
|
||||||
|
"""Order is not noise in a systemd unit.
|
||||||
|
|
||||||
|
Repeated directives -- ExecStartPre=, ExecStartPost= -- run in the order
|
||||||
|
they appear, and a directive that moves between [Unit], [Service] and
|
||||||
|
[Install] means something different, or nothing, where it lands. This
|
||||||
|
check used to sort the lines before comparing, which reported no drift for
|
||||||
|
a unit that had genuinely changed.
|
||||||
|
"""
|
||||||
|
a = "[Service]\nExecStartPre=/first\nExecStartPre=/second\n"
|
||||||
|
b = "[Service]\nExecStartPre=/second\nExecStartPre=/first\n"
|
||||||
|
assert StartupValidator._unit_body(a) != StartupValidator._unit_body(b), (
|
||||||
|
"swapping two ExecStartPre= lines changes what runs first, and was "
|
||||||
|
"being normalised away")
|
||||||
|
|
||||||
|
|
||||||
|
def test_a_directive_moved_between_sections_is_drift():
|
||||||
|
a = "[Unit]\nDescription=x\n[Service]\nExecStart=/x\n"
|
||||||
|
b = "[Unit]\nDescription=x\nExecStart=/x\n[Service]\n"
|
||||||
|
assert StartupValidator._unit_body(a) != StartupValidator._unit_body(b), (
|
||||||
|
"ExecStart= in [Unit] is not the same unit, and sorting hid it")
|
||||||
|
|
||||||
|
|
||||||
|
def test_cosmetic_differences_do_not_warn(validator, tmp_path):
|
||||||
|
"""Through the real comparison, not the helper.
|
||||||
|
|
||||||
|
The repo's template carries explanatory comments the installed copy may not
|
||||||
|
have, and the installer does not preserve ordering or blank lines. If those
|
||||||
|
counted as drift, every boot would warn and the warning would be ignored.
|
||||||
|
Asserting this on _unit_body alone would not catch a comparison that stopped
|
||||||
|
calling it -- which is exactly what a careless edit does.
|
||||||
|
"""
|
||||||
|
project_root = Path("src/startup_validator.py").resolve().parent.parent
|
||||||
|
template_rel = "systemd/ledmatrix.service"
|
||||||
|
template = project_root / template_rel
|
||||||
|
if not template.is_file():
|
||||||
|
pytest.skip("repo unit template not present")
|
||||||
|
|
||||||
|
substituted = (template.read_text(encoding="utf-8")
|
||||||
|
.replace("__PROJECT_ROOT_DIR__", str(project_root))
|
||||||
|
.replace("__USER__", "root"))
|
||||||
|
# Cosmetic means comments, blank lines and stray indentation -- the things
|
||||||
|
# the installer really does drop. Not reordering: that changes the unit,
|
||||||
|
# and is asserted as drift above.
|
||||||
|
directives = [line.strip() for line in substituted.splitlines()
|
||||||
|
if line.strip() and not line.strip().startswith("#")]
|
||||||
|
installed = tmp_path / "ledmatrix.service"
|
||||||
|
installed.write_text(
|
||||||
|
"\n\n".join(" " + d for d in directives) + "\n", encoding="utf-8")
|
||||||
|
|
||||||
|
validator._UNITS = ((template_rel, str(installed)),)
|
||||||
|
validator._validate_systemd_units()
|
||||||
|
assert not validator.warnings, (
|
||||||
|
f"cosmetic-only difference reported as drift: {validator.warnings}")
|
||||||
|
|
||||||
|
|
||||||
|
def test_drift_is_reported_as_a_warning(validator, tmp_path):
|
||||||
|
"""The whole point: a real difference must surface, and only as a warning."""
|
||||||
|
installed = tmp_path / "ledmatrix.service"
|
||||||
|
installed.write_text("[Service]\nExecStart=/usr/bin/python3 /x/run.py\n")
|
||||||
|
|
||||||
|
project_root = Path("src/startup_validator.py").resolve().parent.parent
|
||||||
|
template_rel = "systemd/ledmatrix.service"
|
||||||
|
template = project_root / template_rel
|
||||||
|
if not template.is_file():
|
||||||
|
pytest.skip("repo unit template not present")
|
||||||
|
|
||||||
|
validator._UNITS = ((template_rel, str(installed)),)
|
||||||
|
validator._validate_systemd_units()
|
||||||
|
|
||||||
|
assert validator.warnings, "a differing unit produced no warning"
|
||||||
|
assert "install_service.sh" in validator.warnings[0], (
|
||||||
|
"the warning does not tell the user how to fix it")
|
||||||
|
assert not validator.errors, "drift must not be fatal at startup"
|
||||||
|
|
||||||
|
|
||||||
|
def test_a_missing_installed_unit_is_silent(validator, tmp_path):
|
||||||
|
"""Development checkouts have no /etc/systemd unit; that is not drift."""
|
||||||
|
validator._UNITS = (("systemd/ledmatrix.service", str(tmp_path / "absent.service")),)
|
||||||
|
validator._validate_systemd_units()
|
||||||
|
assert not validator.warnings
|
||||||
|
assert not validator.errors
|
||||||
@@ -0,0 +1,85 @@
|
|||||||
|
"""A check that could not run must not be reported as "up to date".
|
||||||
|
|
||||||
|
check-update returned update_available=False whenever git failed. The banner
|
||||||
|
is the only route to the update button, so a checkout git refuses to touch
|
||||||
|
looked exactly like a current one -- permanently, and with nothing for the
|
||||||
|
user to act on. The usual cause is an install performed as root, after which
|
||||||
|
every git command fails with "detected dubious ownership".
|
||||||
|
"""
|
||||||
|
import subprocess
|
||||||
|
import sys
|
||||||
|
from pathlib import Path
|
||||||
|
from unittest.mock import patch
|
||||||
|
|
||||||
|
import pytest
|
||||||
|
from flask import Flask
|
||||||
|
|
||||||
|
sys.path.insert(0, str(Path(__file__).resolve().parent.parent))
|
||||||
|
|
||||||
|
from web_interface.blueprints import api_v3 as mod # noqa: E402
|
||||||
|
from web_interface.blueprints.api_v3 import api_v3 # noqa: E402
|
||||||
|
|
||||||
|
DUBIOUS = ("fatal: detected dubious ownership in repository at "
|
||||||
|
"'/home/pi/LEDMatrix'\nTo add an exception for this directory, call:\n"
|
||||||
|
"\tgit config --global --add safe.directory /home/pi/LEDMatrix\n")
|
||||||
|
|
||||||
|
|
||||||
|
@pytest.fixture
|
||||||
|
def client():
|
||||||
|
app = Flask(__name__)
|
||||||
|
app.config['TESTING'] = True
|
||||||
|
app.register_blueprint(api_v3, url_prefix='/api/v3')
|
||||||
|
mod._update_check_cache['result'] = None
|
||||||
|
mod._update_check_cache['ts'] = 0
|
||||||
|
return app.test_client()
|
||||||
|
|
||||||
|
|
||||||
|
def _fetch_fails(stderr: bytes):
|
||||||
|
def fake_run(args, **kwargs):
|
||||||
|
if args[:2] == ['git', 'fetch']:
|
||||||
|
return subprocess.CompletedProcess(args, 1, stdout=b'', stderr=stderr)
|
||||||
|
return subprocess.CompletedProcess(args, 0, stdout='', stderr='')
|
||||||
|
return fake_run
|
||||||
|
|
||||||
|
|
||||||
|
class TestFailedCheckIsNotSilence:
|
||||||
|
def test_dubious_ownership_is_reported_not_swallowed(self, client):
|
||||||
|
with patch.object(mod.subprocess, 'run', _fetch_fails(DUBIOUS.encode())):
|
||||||
|
data = client.get('/api/v3/system/check-update').get_json()
|
||||||
|
assert data['check_failed'] is True, (
|
||||||
|
"a git failure was reported as a successful 'no update' check")
|
||||||
|
assert data['update_available'] is False
|
||||||
|
|
||||||
|
def test_the_message_tells_the_user_what_to_do(self, client):
|
||||||
|
with patch.object(mod.subprocess, 'run', _fetch_fails(DUBIOUS.encode())):
|
||||||
|
data = client.get('/api/v3/system/check-update').get_json()
|
||||||
|
assert 'chown' in data['error'], (
|
||||||
|
"dubious ownership is unactionable without the fix command")
|
||||||
|
assert 'root' in data['error']
|
||||||
|
|
||||||
|
def test_an_ordinary_git_failure_still_surfaces(self, client):
|
||||||
|
with patch.object(mod.subprocess, 'run',
|
||||||
|
_fetch_fails(b'fatal: some other git problem\n')):
|
||||||
|
data = client.get('/api/v3/system/check-update').get_json()
|
||||||
|
assert data['check_failed'] is True
|
||||||
|
assert 'some other git problem' in data['error']
|
||||||
|
|
||||||
|
def test_offline_reads_as_offline(self, client):
|
||||||
|
with patch.object(mod.subprocess, 'run',
|
||||||
|
_fetch_fails(b'fatal: could not resolve host: github.com\n')):
|
||||||
|
data = client.get('/api/v3/system/check-update').get_json()
|
||||||
|
assert 'Could not reach GitHub' in data['error']
|
||||||
|
|
||||||
|
|
||||||
|
class TestSuccessPathUnchanged:
|
||||||
|
def test_up_to_date_carries_no_failure_flag(self, client):
|
||||||
|
def fake_run(args, **kwargs):
|
||||||
|
if args[:2] == ['git', 'fetch']:
|
||||||
|
return subprocess.CompletedProcess(args, 0, stdout=b'', stderr=b'')
|
||||||
|
if args[:2] == ['git', 'rev-parse']:
|
||||||
|
return subprocess.CompletedProcess(args, 0, stdout='abc123\n', stderr='')
|
||||||
|
return subprocess.CompletedProcess(args, 0, stdout='0\n', stderr='')
|
||||||
|
with patch.object(mod.subprocess, 'run', fake_run):
|
||||||
|
data = client.get('/api/v3/system/check-update').get_json()
|
||||||
|
assert data['update_available'] is False
|
||||||
|
assert not data.get('check_failed'), "a healthy check must not look like a failure"
|
||||||
@@ -0,0 +1,84 @@
|
|||||||
|
"""A pull that changed nothing on the running system is not an applied update.
|
||||||
|
|
||||||
|
git_pull replaces files on disk and restarts nothing -- there is no systemctl
|
||||||
|
call anywhere in the handler. The display and web services keep running the
|
||||||
|
code they loaded at boot, so the user is told "Code updated successfully" and
|
||||||
|
sees no change until they happen to reboot. The response now says whether a
|
||||||
|
restart is owed, and the UI raises the existing restart-pending banner.
|
||||||
|
"""
|
||||||
|
import subprocess
|
||||||
|
import sys
|
||||||
|
from pathlib import Path
|
||||||
|
from unittest.mock import patch
|
||||||
|
|
||||||
|
import pytest
|
||||||
|
from flask import Flask
|
||||||
|
|
||||||
|
sys.path.insert(0, str(Path(__file__).resolve().parent.parent))
|
||||||
|
|
||||||
|
from web_interface.blueprints import api_v3 as mod # noqa: E402
|
||||||
|
from web_interface.blueprints.api_v3 import api_v3 # noqa: E402
|
||||||
|
|
||||||
|
|
||||||
|
@pytest.fixture
|
||||||
|
def client():
|
||||||
|
app = Flask(__name__)
|
||||||
|
app.config['TESTING'] = True
|
||||||
|
app.register_blueprint(api_v3, url_prefix='/api/v3')
|
||||||
|
# The handler consults these after a successful pull; None is the
|
||||||
|
# "not wired up" case it already guards for.
|
||||||
|
api_v3.plugin_store_manager = None
|
||||||
|
api_v3.config_manager = None
|
||||||
|
return app.test_client()
|
||||||
|
|
||||||
|
|
||||||
|
def _git(heads, pull_rc=0, pull_out='Updating a1b2c3..d4e5f6\n'):
|
||||||
|
"""Fake git. `heads` are the successive answers to rev-parse HEAD."""
|
||||||
|
seq = list(heads)
|
||||||
|
|
||||||
|
def run(args, **kwargs):
|
||||||
|
def ok(stdout='', rc=0, b=False):
|
||||||
|
return subprocess.CompletedProcess(
|
||||||
|
args, rc, stdout=(stdout.encode() if b else stdout),
|
||||||
|
stderr=(b'' if b else ''))
|
||||||
|
if args[:2] == ['git', 'rev-parse'] and args[-1] == 'HEAD':
|
||||||
|
return ok(seq.pop(0) + '\n' if seq else 'deadbeef\n')
|
||||||
|
if 'symbolic-full-name' in args or '@{u}' in args:
|
||||||
|
return ok('origin/main\n')
|
||||||
|
if args[:2] == ['git', 'status']:
|
||||||
|
return ok('')
|
||||||
|
if args[:2] == ['git', 'diff']:
|
||||||
|
return ok('')
|
||||||
|
if args[:2] == ['git', 'pull']:
|
||||||
|
return ok(pull_out, pull_rc)
|
||||||
|
return ok('')
|
||||||
|
return run
|
||||||
|
|
||||||
|
|
||||||
|
def _pull(client):
|
||||||
|
return client.post('/api/v3/system/action',
|
||||||
|
json={'action': 'git_pull'}).get_json()
|
||||||
|
|
||||||
|
|
||||||
|
class TestRestartIsRequestedWhenCodeChanged:
|
||||||
|
def test_a_pull_that_moved_head_asks_for_a_restart(self, client):
|
||||||
|
with patch.object(mod.subprocess, 'run', _git(['aaa111', 'bbb222'])):
|
||||||
|
data = _pull(client)
|
||||||
|
assert data['status'] == 'success'
|
||||||
|
assert data['restart_required'] is True, (
|
||||||
|
"new code on disk, services still running the old code, and "
|
||||||
|
"nothing told the user to restart")
|
||||||
|
|
||||||
|
def test_already_up_to_date_does_not(self, client):
|
||||||
|
with patch.object(mod.subprocess, 'run',
|
||||||
|
_git(['aaa111', 'aaa111'], pull_out='Already up to date.\n')):
|
||||||
|
data = _pull(client)
|
||||||
|
assert data['status'] == 'success'
|
||||||
|
assert data['restart_required'] is False, (
|
||||||
|
"prompting after a no-op update trains users to ignore the prompt")
|
||||||
|
|
||||||
|
def test_a_failed_pull_does_not(self, client):
|
||||||
|
with patch.object(mod.subprocess, 'run', _git(['aaa111'], pull_rc=1)):
|
||||||
|
data = _pull(client)
|
||||||
|
assert data['status'] == 'error'
|
||||||
|
assert data['restart_required'] is False
|
||||||
@@ -0,0 +1,99 @@
|
|||||||
|
"""Frame pacing and FPS health reporting must not depend on the wall clock.
|
||||||
|
|
||||||
|
These devices have no RTC, so the system clock jumps by however wrong boot
|
||||||
|
time was the moment NTP first syncs. The render loop sleeps the *remainder*
|
||||||
|
of each frame budget:
|
||||||
|
|
||||||
|
frame_elapsed = <now> - frame_started
|
||||||
|
time.sleep(max(0.0, frame_interval - frame_elapsed))
|
||||||
|
|
||||||
|
With a wall-clock `now`, a backward jump makes frame_elapsed negative, so
|
||||||
|
`frame_interval - frame_elapsed` exceeds the whole budget and the render loop
|
||||||
|
stalls for the size of the correction. A forward jump instead inflates the
|
||||||
|
p99 and worst-frame numbers the telemetry reports.
|
||||||
|
"""
|
||||||
|
import ast
|
||||||
|
import sys
|
||||||
|
from pathlib import Path
|
||||||
|
|
||||||
|
sys.path.insert(0, str(Path(__file__).resolve().parent.parent))
|
||||||
|
|
||||||
|
COORD = (Path(__file__).resolve().parent.parent
|
||||||
|
/ "src" / "vegas_mode" / "coordinator.py")
|
||||||
|
TREE = ast.parse(COORD.read_text(encoding="utf-8"))
|
||||||
|
|
||||||
|
|
||||||
|
def _assignments_of(name):
|
||||||
|
"""Every `name = <expr>` in the module, as unparsed source."""
|
||||||
|
out = []
|
||||||
|
for node in ast.walk(TREE):
|
||||||
|
if isinstance(node, ast.Assign):
|
||||||
|
for target in node.targets:
|
||||||
|
if isinstance(target, ast.Name) and target.id == name:
|
||||||
|
out.append((node.lineno, ast.unparse(node.value)))
|
||||||
|
return out
|
||||||
|
|
||||||
|
|
||||||
|
def test_per_frame_timestamps_are_monotonic():
|
||||||
|
for name in ("frame_started", "frame_elapsed"):
|
||||||
|
assigns = _assignments_of(name)
|
||||||
|
assert assigns, f"{name} is no longer assigned -- has the loop changed?"
|
||||||
|
for lineno, expr in assigns:
|
||||||
|
assert "time.time()" not in expr, (
|
||||||
|
f"{name} at line {lineno} uses the wall clock ({expr!r}). A "
|
||||||
|
"backward NTP step makes the per-frame delta negative and the "
|
||||||
|
"loop then sleeps longer than the whole frame budget.")
|
||||||
|
assert "time.monotonic()" in expr, (
|
||||||
|
f"{name} at line {lineno} is {expr!r}, expected monotonic")
|
||||||
|
|
||||||
|
|
||||||
|
def test_the_fps_window_is_monotonic():
|
||||||
|
for lineno, expr in _assignments_of("current_time"):
|
||||||
|
assert "time.monotonic()" in expr, (
|
||||||
|
f"current_time at line {lineno} is {expr!r}; fps is frames divided "
|
||||||
|
"by this delta, so a clock step would corrupt the rate itself")
|
||||||
|
|
||||||
|
|
||||||
|
def test_health_state_is_not_reset_every_iteration():
|
||||||
|
"""run_iteration() runs once per cycle -- locals here reset every few seconds.
|
||||||
|
|
||||||
|
As locals, `last_fps_health_log = 0.0` made the 300s heartbeat fire on the
|
||||||
|
first sample of every iteration, and a recovery spanning two iterations was
|
||||||
|
never reported because was_degraded had already gone back to False.
|
||||||
|
"""
|
||||||
|
run_iteration = next(
|
||||||
|
(n for n in ast.walk(TREE)
|
||||||
|
if isinstance(n, ast.FunctionDef) and n.name == "run_iteration"), None)
|
||||||
|
assert run_iteration is not None, "run_iteration() not found"
|
||||||
|
|
||||||
|
local_names = {t.id for n in ast.walk(run_iteration)
|
||||||
|
if isinstance(n, ast.Assign)
|
||||||
|
for t in n.targets if isinstance(t, ast.Name)}
|
||||||
|
for leaked in ("last_fps_health_log", "was_degraded"):
|
||||||
|
assert leaked not in local_names, (
|
||||||
|
f"{leaked} is a local of run_iteration() again, so it resets every "
|
||||||
|
"cycle -- the heartbeat degenerates to once per iteration")
|
||||||
|
|
||||||
|
body = ast.unparse(run_iteration)
|
||||||
|
assert "self._fps_last_health_log" in body and "self._fps_was_degraded" in body, (
|
||||||
|
"the health state should live on the coordinator, across iterations")
|
||||||
|
|
||||||
|
|
||||||
|
def test_start_clears_stale_health_state():
|
||||||
|
"""A new run must not inherit "was degraded" from the previous one."""
|
||||||
|
start = next((n for n in ast.walk(TREE)
|
||||||
|
if isinstance(n, ast.FunctionDef) and n.name == "start"), None)
|
||||||
|
assert start is not None, "start() not found"
|
||||||
|
body = ast.unparse(start)
|
||||||
|
assert "self._fps_last_health_log" in body and "self._fps_was_degraded" in body, (
|
||||||
|
"start() does not reset the FPS health state")
|
||||||
|
|
||||||
|
|
||||||
|
def test_the_degraded_threshold_is_documented():
|
||||||
|
"""The 90% band is deliberate; say so where the constant is defined."""
|
||||||
|
source = COORD.read_text(encoding="utf-8")
|
||||||
|
idx = source.index("_FPS_HEALTHY_FRACTION = ")
|
||||||
|
preamble = source[max(0, idx - 700):idx]
|
||||||
|
assert "90%" in preamble or "0.9" in preamble, (
|
||||||
|
"the degradation threshold is not explained at its definition, so "
|
||||||
|
"'below target' reads as a bug rather than a deliberate band")
|
||||||
@@ -0,0 +1,73 @@
|
|||||||
|
"""The Vegas content path must trace at DEBUG, not INFO.
|
||||||
|
|
||||||
|
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", the per-item sizes -- and it does that for
|
||||||
|
each plugin on each cycle.
|
||||||
|
|
||||||
|
Measured on a live rig: 13,408 log lines an hour, of which 13,366 were INFO and
|
||||||
|
35 were WARNING. plugin_adapter alone produced 2,457 of them. That is ~223
|
||||||
|
lines a minute of string formatting on a Pi that is also driving the panel, all
|
||||||
|
of it written through journald to the SD card, and it buries the 35 lines that
|
||||||
|
actually indicate a problem.
|
||||||
|
|
||||||
|
Nothing is lost by moving it to DEBUG: the 19 warning/error/exception calls in
|
||||||
|
the module are untouched, so real failures still surface at their own level.
|
||||||
|
|
||||||
|
One INFO call is deliberate and stays -- the padding-strip message chooses its
|
||||||
|
level at runtime (`logger.warning if (left and right) else logger.info`) and
|
||||||
|
test_vegas_plugin_adapter.py pins it.
|
||||||
|
"""
|
||||||
|
import ast
|
||||||
|
from pathlib import Path
|
||||||
|
|
||||||
|
import pytest
|
||||||
|
|
||||||
|
ADAPTER = (Path(__file__).resolve().parent.parent / "src" / "vegas_mode"
|
||||||
|
/ "plugin_adapter.py")
|
||||||
|
|
||||||
|
|
||||||
|
def _logger_calls(path, *levels):
|
||||||
|
"""Direct logger.<level>(...) call sites in a module."""
|
||||||
|
tree = ast.parse(path.read_text(encoding="utf-8"))
|
||||||
|
found = []
|
||||||
|
for node in ast.walk(tree):
|
||||||
|
if (isinstance(node, ast.Call)
|
||||||
|
and isinstance(node.func, ast.Attribute)
|
||||||
|
and node.func.attr in levels
|
||||||
|
and getattr(node.func.value, "id", None) == "logger"):
|
||||||
|
found.append(node.lineno)
|
||||||
|
return found
|
||||||
|
|
||||||
|
|
||||||
|
def _info_calls(path):
|
||||||
|
"""Direct logger.info(...) call sites in a module."""
|
||||||
|
return _logger_calls(path, "info")
|
||||||
|
|
||||||
|
|
||||||
|
def test_the_content_path_does_not_trace_at_info():
|
||||||
|
calls = _info_calls(ADAPTER)
|
||||||
|
assert not calls, (
|
||||||
|
"plugin_adapter should trace at DEBUG; found logger.info at lines "
|
||||||
|
f"{calls}. This path runs per plugin per cycle and its output goes to "
|
||||||
|
"the SD card via journald."
|
||||||
|
)
|
||||||
|
|
||||||
|
|
||||||
|
def test_real_failures_still_have_a_level_of_their_own():
|
||||||
|
"""Demoting the trace must not have swept up the error reporting.
|
||||||
|
|
||||||
|
Counted from the AST rather than with source.count(): the text form also
|
||||||
|
matches comments, docstrings and string literals -- including this
|
||||||
|
module's own docstring, which names these levels -- so a real
|
||||||
|
logger.error() could be demoted while the tally stayed put.
|
||||||
|
"""
|
||||||
|
loud = _logger_calls(ADAPTER, "warning", "error", "exception")
|
||||||
|
assert len(loud) >= 15, \
|
||||||
|
f"only {len(loud)} warning/error/exception calls remain: {loud}"
|
||||||
|
|
||||||
|
|
||||||
|
def test_the_deliberate_runtime_chosen_level_survives():
|
||||||
|
"""The padding-strip message picks its level at runtime; leave it alone."""
|
||||||
|
source = ADAPTER.read_text(encoding="utf-8")
|
||||||
|
assert "logger.warning if (left and right) else logger.info" in source
|
||||||
@@ -194,15 +194,46 @@ class TestSavePluginConfig:
|
|||||||
|
|
||||||
def test_secret_count_message_counts_top_level_keys(self, env):
|
def test_secret_count_message_counts_top_level_keys(self, env):
|
||||||
# Pinned: the "(N secret field(s))" message counts TOP-LEVEL keys of
|
# Pinned: the "(N secret field(s))" message counts TOP-LEVEL keys of
|
||||||
# the separated secrets dict. Here that is 2: the posted accounts
|
# the separated secrets dict. Here that is 1: the posted accounts
|
||||||
# array (all its item tokens count as ONE key) plus the schema's
|
# array, whose item tokens all count as ONE key.
|
||||||
# api_key default ("") that merge_with_defaults adds before
|
#
|
||||||
# separation.
|
# 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.
|
||||||
resp = self._save(env, {
|
resp = self._save(env, {
|
||||||
"accounts": [{"name": "a", "token": "t"}],
|
"accounts": [{"name": "a", "token": "t"}],
|
||||||
})
|
})
|
||||||
message = resp.get_json()["message"]
|
message = resp.get_json()["message"]
|
||||||
assert "(2 secret field(s) saved to config_secrets.json)" in 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"
|
||||||
|
|
||||||
def test_resave_replaces_stored_secrets_list_wholesale(self, env):
|
def test_resave_replaces_stored_secrets_list_wholesale(self, env):
|
||||||
# Characterized: api_v3's deep_merge intentionally replaces lists,
|
# Characterized: api_v3's deep_merge intentionally replaces lists,
|
||||||
|
|||||||
@@ -0,0 +1,123 @@
|
|||||||
|
"""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)
|
||||||
|
# Assert the write succeeded. A 500 leaves the old file in place, so the
|
||||||
|
# assertions below would hold without the write path running at all.
|
||||||
|
resp = env.client.post("/api/v3/config/raw/secrets", json=_get(env))
|
||||||
|
assert resp.status_code == 200, resp.get_data(as_text=True)[:200]
|
||||||
|
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
|
||||||
|
|
||||||
|
|
||||||
|
def test_a_list_of_secrets_keeps_its_shape(env):
|
||||||
|
"""A list must not be masked as though it were one scalar.
|
||||||
|
|
||||||
|
accounts: [{...}, {...}] came back as a single '••••••••', so a caller
|
||||||
|
could not see how many entries existed, and the raw editor was shown a
|
||||||
|
string where the file holds an array.
|
||||||
|
"""
|
||||||
|
env.secrets_file.write_text(json.dumps({
|
||||||
|
"myplugin": {"accounts": [{"name": "a", "token": "tok-a"},
|
||||||
|
{"name": "b", "token": "tok-b"}]}}))
|
||||||
|
accounts = _get(env)["myplugin"]["accounts"]
|
||||||
|
assert isinstance(accounts, list), "the list was flattened to a scalar"
|
||||||
|
assert len(accounts) == 2, "entries were lost"
|
||||||
|
assert all(isinstance(a, dict) for a in accounts), "entry shape was lost"
|
||||||
|
assert "tok-a" not in json.dumps(accounts), "a token survived masking"
|
||||||
|
|
||||||
|
|
||||||
|
def test_a_list_posted_back_unchanged_is_left_alone(env):
|
||||||
|
"""Lists merge by replacement, so a half-masked list must not be stored."""
|
||||||
|
original = {"myplugin": {"accounts": [{"name": "a", "token": "tok-a"},
|
||||||
|
{"name": "b", "token": "tok-b"}]}}
|
||||||
|
env.secrets_file.write_text(json.dumps(original))
|
||||||
|
resp = env.client.post("/api/v3/config/raw/secrets", json=_get(env))
|
||||||
|
assert resp.status_code == 200, resp.get_data(as_text=True)[:200]
|
||||||
|
assert _on_disk(env.secrets_file)["myplugin"]["accounts"] == \
|
||||||
|
original["myplugin"]["accounts"], "round-tripping the mask damaged the list"
|
||||||
|
|
||||||
|
|
||||||
|
def test_a_fully_supplied_list_still_saves(env):
|
||||||
|
env.secrets_file.write_text(json.dumps(
|
||||||
|
{"myplugin": {"accounts": [{"name": "a", "token": "old"}]}}))
|
||||||
|
body = _get(env)
|
||||||
|
body["myplugin"]["accounts"] = [{"name": "a", "token": "new"}]
|
||||||
|
resp = env.client.post("/api/v3/config/raw/secrets", json=body)
|
||||||
|
assert resp.status_code == 200, resp.get_data(as_text=True)[:200]
|
||||||
|
assert _on_disk(env.secrets_file)["myplugin"]["accounts"][0]["token"] == "new"
|
||||||
@@ -21,7 +21,9 @@ logger = logging.getLogger(__name__)
|
|||||||
# Import new infrastructure
|
# Import new infrastructure
|
||||||
from src.web_interface.api_helpers import success_response, error_response, validate_request_json
|
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.errors import ErrorCode
|
||||||
from src.web_interface.secret_helpers import find_secret_fields, separate_secrets
|
from src.web_interface.secret_helpers import (find_secret_fields, mask_all_secret_values,
|
||||||
|
remove_empty_secrets, separate_secrets,
|
||||||
|
strip_masked_values)
|
||||||
from src.web_interface.error_handler import describe_exception, redact_text
|
from src.web_interface.error_handler import describe_exception, redact_text
|
||||||
from src.plugin_system.operation_types import OperationType
|
from src.plugin_system.operation_types import OperationType
|
||||||
from src.web_interface.validators import (
|
from src.web_interface.validators import (
|
||||||
@@ -262,15 +264,54 @@ def _stop_display_service():
|
|||||||
result['status'] = status
|
result['status'] = status
|
||||||
return result
|
return result
|
||||||
|
|
||||||
|
#: Field names whose value is a credential. Matched by name because this
|
||||||
|
#: endpoint returns the whole config, core keys included, and core config has
|
||||||
|
#: no schema to carry x-secret markers.
|
||||||
|
_CREDENTIAL_NAME_PARTS = ("password", "passwd", "secret", "token", "api_key",
|
||||||
|
"apikey", "access_key", "private_key", "client_secret")
|
||||||
|
|
||||||
|
|
||||||
|
def _looks_like_a_credential(name: str) -> bool:
|
||||||
|
lowered = name.lower()
|
||||||
|
return any(part in lowered for part in _CREDENTIAL_NAME_PARTS)
|
||||||
|
|
||||||
|
|
||||||
|
def _redact_credentials(value):
|
||||||
|
"""A copy of `value` with credential-named fields blanked.
|
||||||
|
|
||||||
|
/config/main returned the raw config to anyone who could reach the port,
|
||||||
|
and this interface has no authentication. On one rig that meant a 40-char
|
||||||
|
GitHub token, a 183-char Home Assistant token and five API keys were
|
||||||
|
readable by anything on the LAN.
|
||||||
|
|
||||||
|
The x-secret masking used by the plugin config endpoints does not help
|
||||||
|
here: this endpoint never consults a schema, and core keys such as
|
||||||
|
github.api_token have no schema to mark. Matching on the field name is
|
||||||
|
blunt, but for a whole-config dump the right default is that anything
|
||||||
|
named like a credential does not leave the process.
|
||||||
|
|
||||||
|
Blanked rather than removed, and safe to blank: POST /config/main merges
|
||||||
|
into the loaded config and only writes the keys it was given, so a client
|
||||||
|
that round-trips this response cannot erase a secret it never saw.
|
||||||
|
"""
|
||||||
|
if isinstance(value, dict):
|
||||||
|
return {k: ("" if _looks_like_a_credential(k) and not isinstance(v, (dict, list))
|
||||||
|
else _redact_credentials(v))
|
||||||
|
for k, v in value.items()}
|
||||||
|
if isinstance(value, list):
|
||||||
|
return [_redact_credentials(item) for item in value]
|
||||||
|
return value
|
||||||
|
|
||||||
|
|
||||||
@api_v3.route('/config/main', methods=['GET'])
|
@api_v3.route('/config/main', methods=['GET'])
|
||||||
def get_main_config():
|
def get_main_config():
|
||||||
"""Get main configuration"""
|
"""Get main configuration, with credentials redacted."""
|
||||||
try:
|
try:
|
||||||
if not api_v3.config_manager:
|
if not api_v3.config_manager:
|
||||||
return jsonify({'status': 'error', 'message': 'Config manager not initialized'}), 500
|
return jsonify({'status': 'error', 'message': 'Config manager not initialized'}), 500
|
||||||
|
|
||||||
config = api_v3.config_manager.load_config()
|
config = api_v3.config_manager.load_config()
|
||||||
return jsonify({'status': 'success', 'data': config})
|
return jsonify({'status': 'success', 'data': _redact_credentials(config)})
|
||||||
except Exception as e:
|
except Exception as e:
|
||||||
logger.error('Unhandled exception', exc_info=True)
|
logger.error('Unhandled exception', exc_info=True)
|
||||||
return jsonify({'status': 'error', 'message': 'An error occurred; see logs for details', 'details': describe_exception(e)}), 500
|
return jsonify({'status': 'error', 'message': 'An error occurred; see logs for details', 'details': describe_exception(e)}), 500
|
||||||
@@ -715,10 +756,12 @@ def save_main_config():
|
|||||||
if not data:
|
if not data:
|
||||||
return jsonify({'status': 'error', 'message': 'No data provided'}), 400
|
return jsonify({'status': 'error', 'message': 'No data provided'}), 400
|
||||||
|
|
||||||
import logging
|
# What arrives here is the config itself, and the headers carry the
|
||||||
logging.error(f"DEBUG: save_main_config received data: {data}")
|
# session cookie -- neither belongs in the journal, least of all at
|
||||||
logging.error(f"DEBUG: Content-Type header: {request.content_type}")
|
# ERROR on every save. The shape of the request is the part with
|
||||||
logging.error(f"DEBUG: Headers: {dict(request.headers)}")
|
# diagnostic value, so log that, at the level it deserves.
|
||||||
|
logger.debug("save_main_config: %s, %d top-level key(s)",
|
||||||
|
request.content_type or 'no content-type', len(data))
|
||||||
|
|
||||||
# Merge with existing config (similar to original implementation)
|
# Merge with existing config (similar to original implementation)
|
||||||
current_config = api_v3.config_manager.load_config()
|
current_config = api_v3.config_manager.load_config()
|
||||||
@@ -1216,6 +1259,11 @@ def save_main_config():
|
|||||||
|
|
||||||
# Separate secrets from regular config (same logic as save_plugin_config)
|
# Separate secrets from regular config (same logic as save_plugin_config)
|
||||||
regular_config, secrets_config = separate_secrets(plugin_config, secret_fields)
|
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
|
# 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
|
# This prevents overwriting the enabled state when saving config from a form that doesn't include the toggle
|
||||||
@@ -1333,7 +1381,12 @@ def get_secrets_config():
|
|||||||
return jsonify({'status': 'error', 'message': 'Config manager not initialized'}), 500
|
return jsonify({'status': 'error', 'message': 'Config manager not initialized'}), 500
|
||||||
|
|
||||||
config = api_v3.config_manager.get_raw_file_content('secrets')
|
config = api_v3.config_manager.get_raw_file_content('secrets')
|
||||||
return jsonify({'status': 'success', 'data': config})
|
# 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)})
|
||||||
except Exception as e:
|
except Exception as e:
|
||||||
logger.error('Unhandled exception', exc_info=True)
|
logger.error('Unhandled exception', exc_info=True)
|
||||||
return jsonify({'status': 'error', 'message': 'An error occurred; see logs for details', 'details': describe_exception(e)}), 500
|
return jsonify({'status': 'error', 'message': 'An error occurred; see logs for details', 'details': describe_exception(e)}), 500
|
||||||
@@ -1401,8 +1454,19 @@ def save_raw_secrets_config():
|
|||||||
if not data:
|
if not data:
|
||||||
return jsonify({'status': 'error', 'message': 'No data provided'}), 400
|
return jsonify({'status': 'error', 'message': 'No data provided'}), 400
|
||||||
|
|
||||||
# Save the secrets config
|
# The GET above masks what it returns, and this endpoint's only client
|
||||||
api_v3.config_manager.save_raw_file_content('secrets', data)
|
# 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)
|
||||||
|
|
||||||
# Reload GitHub token in plugin store manager if it exists
|
# Reload GitHub token in plugin store manager if it exists
|
||||||
if api_v3.plugin_store_manager:
|
if api_v3.plugin_store_manager:
|
||||||
@@ -1660,13 +1724,22 @@ def resolve_pull_command(project_dir):
|
|||||||
backup, or following an install guide that names one. The update button
|
backup, or following an install guide that names one. The update button
|
||||||
then reports a failure the user cannot act on.
|
then reports a failure the user cannot act on.
|
||||||
|
|
||||||
|
``--autostash`` is passed for the same reason. Rebase refuses to start
|
||||||
|
when any tracked file is modified, and on these installs something always
|
||||||
|
is: first_time_install.sh chmods five scripts that git tracked as 644, so
|
||||||
|
every machine that ran the installer carries five permanent mode changes
|
||||||
|
and the update button reports "cannot pull with rebase: You have unstaged
|
||||||
|
changes". Those modes are corrected in this commit, but a user cannot pull
|
||||||
|
the correction while the pull is what is blocked, and any other local edit
|
||||||
|
would reproduce it anyway. Autostash reapplies the changes afterwards.
|
||||||
|
|
||||||
Returns ``(args, note, error)``. When ``origin/<branch>`` exists the pull
|
Returns ``(args, note, error)``. When ``origin/<branch>`` exists the pull
|
||||||
is made explicit against it, so the update proceeds and the branch is
|
is made explicit against it, so the update proceeds and the branch is
|
||||||
given tracking information afterwards.
|
given tracking information afterwards.
|
||||||
"""
|
"""
|
||||||
upstream = _git_upstream(project_dir)
|
upstream = _git_upstream(project_dir)
|
||||||
if upstream:
|
if upstream:
|
||||||
return ['git', 'pull', '--rebase'], '', None
|
return ['git', 'pull', '--rebase', '--autostash'], '', None
|
||||||
|
|
||||||
branch = _git_current_branch(project_dir)
|
branch = _git_current_branch(project_dir)
|
||||||
if not branch:
|
if not branch:
|
||||||
@@ -1676,7 +1749,7 @@ def resolve_pull_command(project_dir):
|
|||||||
)
|
)
|
||||||
if _git_remote_branch_exists(project_dir, branch):
|
if _git_remote_branch_exists(project_dir, branch):
|
||||||
return (
|
return (
|
||||||
['git', 'pull', '--rebase', 'origin', branch],
|
['git', 'pull', '--rebase', '--autostash', 'origin', branch],
|
||||||
f"Branch '{branch}' had no upstream; pulled from origin/{branch} and set it as the upstream.",
|
f"Branch '{branch}' had no upstream; pulled from origin/{branch} and set it as the upstream.",
|
||||||
None,
|
None,
|
||||||
)
|
)
|
||||||
@@ -1824,6 +1897,33 @@ def get_system_version():
|
|||||||
_update_check_cache: Dict[str, Any] = {'result': None, 'ts': 0.0}
|
_update_check_cache: Dict[str, Any] = {'result': None, 'ts': 0.0}
|
||||||
_UPDATE_CHECK_TTL = 300 # 5 minutes — avoids a git fetch on every page load
|
_UPDATE_CHECK_TTL = 300 # 5 minutes — avoids a git fetch on every page load
|
||||||
|
|
||||||
|
def _update_check_failed(detail: str) -> Dict[str, Any]:
|
||||||
|
"""A check that could not run is not the same as being up to date.
|
||||||
|
|
||||||
|
Reporting update_available=False on a git failure hides the banner, and
|
||||||
|
the banner is the only route to the update button -- so a checkout git
|
||||||
|
refuses to touch looks exactly like a current one, permanently. The most
|
||||||
|
common cause is an install performed as root: git then reports "dubious
|
||||||
|
ownership" and every command fails, including the fetch here.
|
||||||
|
"""
|
||||||
|
return {'update_available': False, 'remote_sha': 'unknown',
|
||||||
|
'commits_behind': 0, 'check_failed': True, 'error': detail}
|
||||||
|
|
||||||
|
|
||||||
|
def _describe_git_failure(stderr: str) -> str:
|
||||||
|
"""Turn git's stderr into something the user can act on."""
|
||||||
|
text = (stderr or '').strip()
|
||||||
|
if 'dubious ownership' in text or 'detected dubious ownership' in text:
|
||||||
|
return ("This checkout is owned by a different user than the one "
|
||||||
|
"running the web interface, so git refuses to use it. It is "
|
||||||
|
"usually the result of installing as root. Fix the ownership "
|
||||||
|
"and the update will work: sudo chown -R $USER:$USER "
|
||||||
|
+ str(PROJECT_ROOT))
|
||||||
|
if 'could not resolve host' in text.lower() or 'network is unreachable' in text.lower():
|
||||||
|
return "Could not reach GitHub to check for updates."
|
||||||
|
return "Could not check for updates: " + (text.splitlines()[0] if text else "git failed")
|
||||||
|
|
||||||
|
|
||||||
@api_v3.route('/system/check-update', methods=['GET'])
|
@api_v3.route('/system/check-update', methods=['GET'])
|
||||||
def check_for_update():
|
def check_for_update():
|
||||||
"""Check whether a newer LEDMatrix commit is available on origin/main."""
|
"""Check whether a newer LEDMatrix commit is available on origin/main."""
|
||||||
@@ -1839,12 +1939,13 @@ def check_for_update():
|
|||||||
capture_output=True, timeout=10, cwd=cwd,
|
capture_output=True, timeout=10, cwd=cwd,
|
||||||
)
|
)
|
||||||
if fetch_result.returncode != 0:
|
if fetch_result.returncode != 0:
|
||||||
|
stderr = fetch_result.stderr.decode(errors='replace').strip()
|
||||||
logger.warning("check-update: git fetch failed (rc=%d): %s",
|
logger.warning("check-update: git fetch failed (rc=%d): %s",
|
||||||
fetch_result.returncode,
|
fetch_result.returncode, stderr)
|
||||||
fetch_result.stderr.decode(errors='replace').strip())
|
failed = _update_check_failed(_describe_git_failure(stderr))
|
||||||
_update_check_cache['result'] = _safe
|
_update_check_cache['result'] = failed
|
||||||
_update_check_cache['ts'] = now
|
_update_check_cache['ts'] = now
|
||||||
return jsonify(_safe)
|
return jsonify(failed)
|
||||||
local = subprocess.run(
|
local = subprocess.run(
|
||||||
['git', 'rev-parse', 'HEAD'],
|
['git', 'rev-parse', 'HEAD'],
|
||||||
capture_output=True, text=True, timeout=5, cwd=cwd,
|
capture_output=True, text=True, timeout=5, cwd=cwd,
|
||||||
@@ -1872,7 +1973,8 @@ def check_for_update():
|
|||||||
return jsonify(result)
|
return jsonify(result)
|
||||||
except Exception as e:
|
except Exception as e:
|
||||||
logger.warning("check-update failed: %s", e)
|
logger.warning("check-update failed: %s", e)
|
||||||
return jsonify(_safe)
|
return jsonify(_update_check_failed(
|
||||||
|
"Could not check for updates; see logs for details."))
|
||||||
|
|
||||||
@api_v3.route('/system/action', methods=['POST'])
|
@api_v3.route('/system/action', methods=['POST'])
|
||||||
def execute_system_action():
|
def execute_system_action():
|
||||||
@@ -1999,6 +2101,11 @@ def execute_system_action():
|
|||||||
except subprocess.TimeoutExpired:
|
except subprocess.TimeoutExpired:
|
||||||
logger.warning("git rev-parse timed out before pull")
|
logger.warning("git rev-parse timed out before pull")
|
||||||
|
|
||||||
|
# Whether the pull actually brought new code in. "Already up to
|
||||||
|
# date" is a success too, and prompting for a restart then would
|
||||||
|
# train users to ignore the prompt.
|
||||||
|
code_changed = False
|
||||||
|
|
||||||
# Perform the git pull. Branches without an upstream were given
|
# Perform the git pull. Branches without an upstream were given
|
||||||
# an explicit "origin <branch>" above so the update still works.
|
# an explicit "origin <branch>" above so the update still works.
|
||||||
result = subprocess.run(
|
result = subprocess.run(
|
||||||
@@ -2042,6 +2149,7 @@ def execute_system_action():
|
|||||||
capture_output=True, text=True, timeout=10, cwd=project_dir)
|
capture_output=True, text=True, timeout=10, cwd=project_dir)
|
||||||
new_head = _post.stdout.strip() if _post.returncode == 0 else None
|
new_head = _post.stdout.strip() if _post.returncode == 0 else None
|
||||||
if old_head and new_head and old_head != new_head:
|
if old_head and new_head and old_head != new_head:
|
||||||
|
code_changed = True
|
||||||
diff = subprocess.run(
|
diff = subprocess.run(
|
||||||
['git', 'diff', '--name-only', f'{old_head}..{new_head}'],
|
['git', 'diff', '--name-only', f'{old_head}..{new_head}'],
|
||||||
capture_output=True, text=True, timeout=15, cwd=project_dir)
|
capture_output=True, text=True, timeout=15, cwd=project_dir)
|
||||||
@@ -2101,9 +2209,14 @@ def execute_system_action():
|
|||||||
if ln.strip()), '')
|
if ln.strip()), '')
|
||||||
pull_message = f"Update failed: {detail}" if detail else "Update failed; check logs for details"
|
pull_message = f"Update failed: {detail}" if detail else "Update failed; check logs for details"
|
||||||
|
|
||||||
|
# Nothing here restarts anything: the pull replaces files on
|
||||||
|
# disk while the display and web services keep running the code
|
||||||
|
# they loaded at boot. Without this the user is told the update
|
||||||
|
# succeeded and sees no change until they happen to reboot.
|
||||||
return jsonify({
|
return jsonify({
|
||||||
'status': 'success' if result.returncode == 0 else 'error',
|
'status': 'success' if result.returncode == 0 else 'error',
|
||||||
'message': pull_message,
|
'message': pull_message,
|
||||||
|
'restart_required': bool(result.returncode == 0 and code_changed),
|
||||||
})
|
})
|
||||||
elif action == 'checkout_branch':
|
elif action == 'checkout_branch':
|
||||||
# Switch branches from the Tools tab. Needed because a checkout
|
# Switch branches from the Tools tab. Needed because a checkout
|
||||||
@@ -5617,6 +5730,11 @@ def save_plugin_config():
|
|||||||
# Separate secrets from regular config (handles nested configs and
|
# Separate secrets from regular config (handles nested configs and
|
||||||
# array-item secrets — see src/web_interface/secret_helpers.py)
|
# array-item secrets — see src/web_interface/secret_helpers.py)
|
||||||
regular_config, secrets_config = separate_secrets(plugin_config, secret_fields)
|
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
|
# Get current configs
|
||||||
current_config = api_v3.config_manager.load_config()
|
current_config = api_v3.config_manager.load_config()
|
||||||
|
|||||||
@@ -116,14 +116,25 @@ document.body.addEventListener('htmx:afterRequest', function(event) {
|
|||||||
// ===== Restart-pending banner =====
|
// ===== Restart-pending banner =====
|
||||||
// Shown after restart-requiring saves; persists across tab switches (and
|
// Shown after restart-requiring saves; persists across tab switches (and
|
||||||
// reloads, via sessionStorage) until the display restarts or it's dismissed.
|
// reloads, via sessionStorage) until the display restarts or it's dismissed.
|
||||||
window.showRestartPending = function() {
|
window.showRestartPending = function(message) {
|
||||||
try { sessionStorage.setItem('ledmatrix-restart-pending', '1'); } catch { /* private browsing */ }
|
try {
|
||||||
|
sessionStorage.setItem('ledmatrix-restart-pending', '1');
|
||||||
|
// Persisted alongside the flag: a code update and a config save want
|
||||||
|
// different wording, and the banner outlives the page that raised it.
|
||||||
|
if (message) sessionStorage.setItem('ledmatrix-restart-pending-text', message);
|
||||||
|
else sessionStorage.removeItem('ledmatrix-restart-pending-text');
|
||||||
|
} catch { /* private browsing */ }
|
||||||
const banner = document.getElementById('restart-pending-banner');
|
const banner = document.getElementById('restart-pending-banner');
|
||||||
|
const text = document.getElementById('restart-pending-text');
|
||||||
|
if (text && message) text.textContent = message;
|
||||||
if (banner) banner.style.display = 'block';
|
if (banner) banner.style.display = 'block';
|
||||||
};
|
};
|
||||||
|
|
||||||
window.dismissRestartPending = function() {
|
window.dismissRestartPending = function() {
|
||||||
try { sessionStorage.removeItem('ledmatrix-restart-pending'); } catch { /* no-op */ }
|
try {
|
||||||
|
sessionStorage.removeItem('ledmatrix-restart-pending');
|
||||||
|
sessionStorage.removeItem('ledmatrix-restart-pending-text');
|
||||||
|
} catch { /* no-op */ }
|
||||||
const banner = document.getElementById('restart-pending-banner');
|
const banner = document.getElementById('restart-pending-banner');
|
||||||
if (banner) banner.style.display = 'none';
|
if (banner) banner.style.display = 'none';
|
||||||
};
|
};
|
||||||
@@ -151,6 +162,9 @@ document.addEventListener('DOMContentLoaded', function() {
|
|||||||
try {
|
try {
|
||||||
if (sessionStorage.getItem('ledmatrix-restart-pending') === '1') {
|
if (sessionStorage.getItem('ledmatrix-restart-pending') === '1') {
|
||||||
const banner = document.getElementById('restart-pending-banner');
|
const banner = document.getElementById('restart-pending-banner');
|
||||||
|
const saved = sessionStorage.getItem('ledmatrix-restart-pending-text');
|
||||||
|
const text = document.getElementById('restart-pending-text');
|
||||||
|
if (text && saved) text.textContent = saved;
|
||||||
if (banner) banner.style.display = 'block';
|
if (banner) banner.style.display = 'block';
|
||||||
}
|
}
|
||||||
} catch { /* no-op */ }
|
} catch { /* no-op */ }
|
||||||
|
|||||||
@@ -4622,15 +4622,17 @@ window.loadGithubToken = function() {
|
|||||||
// Handle empty data (secrets file doesn't exist) - API returns {} in this case
|
// Handle empty data (secrets file doesn't exist) - API returns {} in this case
|
||||||
const secrets = data.data || {};
|
const secrets = data.data || {};
|
||||||
const token = secrets.github?.api_token || '';
|
const token = secrets.github?.api_token || '';
|
||||||
|
const configured = token && token !== 'YOUR_GITHUB_PERSONAL_ACCESS_TOKEN';
|
||||||
|
|
||||||
if (input) {
|
if (input) {
|
||||||
if (token && token !== 'YOUR_GITHUB_PERSONAL_ACCESS_TOKEN') {
|
// The endpoint masks what it returns, so this never holds
|
||||||
// Token exists and is valid
|
// the real token -- and the field is deliberately left
|
||||||
input.value = token;
|
// empty rather than filled with the mask, which would be
|
||||||
showNotification('GitHub token loaded successfully', 'success');
|
// 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');
|
||||||
} else {
|
} else {
|
||||||
// No token configured or placeholder value
|
|
||||||
input.value = '';
|
|
||||||
showNotification('No GitHub token configured. Enter a new token to save.', 'info');
|
showNotification('No GitHub token configured. Enter a new token to save.', 'info');
|
||||||
}
|
}
|
||||||
}
|
}
|
||||||
|
|||||||
@@ -413,7 +413,8 @@
|
|||||||
<div class="flex items-center justify-between">
|
<div class="flex items-center justify-between">
|
||||||
<div class="flex items-center space-x-3">
|
<div class="flex items-center space-x-3">
|
||||||
<i class="fas fa-rotate text-lg"></i>
|
<i class="fas fa-rotate text-lg"></i>
|
||||||
<span class="text-sm font-medium" aria-live="polite">
|
<span class="text-sm font-medium" aria-live="polite"
|
||||||
|
id="restart-pending-text">
|
||||||
Configuration saved — restart the display to apply the changes
|
Configuration saved — restart the display to apply the changes
|
||||||
</span>
|
</span>
|
||||||
</div>
|
</div>
|
||||||
@@ -1107,15 +1108,29 @@
|
|||||||
fetch('/api/v3/system/check-update')
|
fetch('/api/v3/system/check-update')
|
||||||
.then(function(r) { return r.json(); })
|
.then(function(r) { return r.json(); })
|
||||||
.then(function(data) {
|
.then(function(data) {
|
||||||
|
var banner = document.getElementById('update-banner');
|
||||||
|
var btn = document.getElementById('update-banner-btn');
|
||||||
|
if (data.check_failed) {
|
||||||
|
// A check that could not run is not the same as being up
|
||||||
|
// to date. Hiding the banner here made a checkout git
|
||||||
|
// refuses to touch look permanently current, with no
|
||||||
|
// route to the update button and nothing to act on.
|
||||||
|
document.getElementById('update-banner-text').textContent =
|
||||||
|
data.error || 'Could not check for updates.';
|
||||||
|
if (btn) btn.style.display = 'none';
|
||||||
|
banner.style.display = '';
|
||||||
|
return;
|
||||||
|
}
|
||||||
|
if (btn) btn.style.display = '';
|
||||||
if (data.update_available && getDismissedSha() !== data.remote_sha) {
|
if (data.update_available && getDismissedSha() !== data.remote_sha) {
|
||||||
var n = data.commits_behind || 0;
|
var n = data.commits_behind || 0;
|
||||||
var msg = 'A new LEDMatrix update is available';
|
var msg = 'A new LEDMatrix update is available';
|
||||||
if (n > 0) msg += ' (' + n + ' commit' + (n > 1 ? 's' : '') + ')';
|
if (n > 0) msg += ' (' + n + ' commit' + (n > 1 ? 's' : '') + ')';
|
||||||
document.getElementById('update-banner-text').textContent = msg;
|
document.getElementById('update-banner-text').textContent = msg;
|
||||||
document.getElementById('update-banner').style.display = '';
|
banner.style.display = '';
|
||||||
try { sessionStorage.setItem('update-sha', data.remote_sha); } catch(e) {}
|
try { sessionStorage.setItem('update-sha', data.remote_sha); } catch(e) {}
|
||||||
} else {
|
} else {
|
||||||
document.getElementById('update-banner').style.display = 'none';
|
banner.style.display = 'none';
|
||||||
}
|
}
|
||||||
})
|
})
|
||||||
.catch(function() {});
|
.catch(function() {});
|
||||||
@@ -1146,6 +1161,13 @@
|
|||||||
if (data.status === 'success') {
|
if (data.status === 'success') {
|
||||||
document.getElementById('update-banner').style.display = 'none';
|
document.getElementById('update-banner').style.display = 'none';
|
||||||
try { sessionStorage.removeItem('update-sha-dismissed'); } catch(e) {}
|
try { sessionStorage.removeItem('update-sha-dismissed'); } catch(e) {}
|
||||||
|
// The pull replaced files on disk; the running services still
|
||||||
|
// hold the code they loaded at boot. Ask for the restart that
|
||||||
|
// makes the update actually take effect.
|
||||||
|
if (data.restart_required && typeof window.showRestartPending === 'function') {
|
||||||
|
window.showRestartPending(
|
||||||
|
'Update installed \u2014 restart the display to run the new code');
|
||||||
|
}
|
||||||
}
|
}
|
||||||
if (typeof showNotification === 'function') {
|
if (typeof showNotification === 'function') {
|
||||||
showNotification(data.message || 'Update complete', data.status || 'success');
|
showNotification(data.message || 'Update complete', data.status || 'success');
|
||||||
|
|||||||
Reference in New Issue
Block a user