Compare commits

..
Author SHA1 Message Date
ChuckBuilds 73fff8d2d5 test(systemd): pin the arena value instead of accepting a range
Review follow-up. The range check accepted 1, 3 and 4, so a change to 4 --
which hands most of the resident saving back -- passed a test whose whole
purpose is to notice that.

Pinned to the value the unit ships, in one named constant. Raising it is still
a legitimate response to a frame-time regression, but it should be a visible
edit here rather than silent drift, and the failure message says so.

Mutation-checked: changing the unit to 4 now fails.
2026-08-20 01:55:14 -04:00
ChuckBuilds 446207ffbc perf(systemd): cap glibc malloc arenas on the display service
Measured on a live rig 2.5 hours after start:

    RSS                          1030 MB
    Private_Dirty                 988 MB
    anonymous mappings > 10 MB       23
    largest        104, 79, 66, 63, 63 MB, on 64 MB-aligned addresses
    threads                           9
    cores                             3   -> glibc ceiling = 8 x 3 = 24 arenas

23 against a ceiling of 24, all 64 MB-aligned: these are glibc's per-thread
malloc arenas, not live objects. The data the process was actually holding
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.

It is bloat rather than a leak: sampled four times over 135 seconds, RSS sat
between 990 and 1030 MB rather than climbing. glibc gives each allocating
thread its own arena, grows them to hold peak demand, and never gives them
back. A process that builds and drops large images across several threads is
exactly the shape that produces this.

The device had 59 MB free at the time, on 1845 MB total.

MALLOC_ARENA_MAX=2 trades a little allocator concurrency for that resident
memory. It is a tuning knob rather than a fix for a defect, so the rationale
and the measurements sit next to it in the unit file, and a test asserts they
stay there -- a bare environment variable invites removal by whoever meets it
next.

Two things this is NOT, both checked rather than assumed:

- Not an OOM problem today. A grep for "oom" in the service journal returned
  24 matches, all of which were the radar logging zoom=9 and zoom=7. The kernel
  OOM killer has not fired: dmesg has zero matches.
- Not currently capped by the unit's MemoryMax=85% either. That directive is in
  this file but absent from the unit actually installed on the rig, which
  reports MemoryMax=infinity, so nothing is enforcing a ceiling there.

The saving is unmeasured on hardware: applying it needs a service restart,
which blanks the panel, so that is the user's call rather than something to do
mid-audit. If p99 frame time regresses -- it sits at 18.4 ms against a 16.7 ms
budget for 60 FPS, so there is not much headroom -- raise the value rather than
remove it.
2026-08-20 00:17:27 -04:00
6 changed files with 115 additions and 42 deletions
Binary file not shown.

Before

Width:  |  Height:  |  Size: 76 KiB

Binary file not shown.

Before

Width:  |  Height:  |  Size: 128 KiB

+1 -5
View File
@@ -328,11 +328,7 @@ 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
# Progress telemetry, emitted every few seconds for the whole of self.logger.info(
# 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,
+7 -37
View File
@@ -31,14 +31,6 @@ if TYPE_CHECKING:
logger = logging.getLogger(__name__) logger = logging.getLogger(__name__)
#: A frame rate this close to target is not news; below it is.
_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.
@@ -403,9 +395,7 @@ 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 # Sample FPS every 5 seconds fps_log_interval = 5.0 # Log FPS every 5 seconds
last_fps_health_log = 0.0 # last INFO-level report
was_degraded = False # so the recovery is reported too
last_fps_log_time = start_time last_fps_log_time = start_time
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
@@ -458,36 +448,16 @@ class VegasModeCoordinator:
frame_count += 1 frame_count += 1
fps_frame_count += 1 fps_frame_count += 1
# Periodic FPS logging. Reported at INFO only when the frame rate # Periodic FPS logging
# 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".
current_time = time.time() current_time = time.time()
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)
target = self.vegas_config.target_fps logger.info(
degraded = target > 0 and fps < target * _FPS_HEALTHY_FRACTION "Vegas FPS: %.1f (target: %d, frames: %d) p99 %.1fms worst %.1fms",
due = current_time - last_fps_health_log >= _FPS_HEARTBEAT_INTERVAL fps, self.vegas_config.target_fps, fps_frame_count,
if degraded or was_degraded or due: p99 * 1000.0, frame_worst * 1000.0
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
)
last_fps_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
)
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
+12
View File
@@ -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
+95
View File
@@ -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")