fix(scroll): report the frame-time tail, and stop the row-major blit

Two problems, both found by looking at the panel rather than the metric.

The frame-stats line reported ONE instantaneous frame every 5 seconds --
about 1 frame in 500 -- printed beside a 100-frame average. Both hide exactly
the fault they are used to chase: a 2ms duplicate and a 21ms double-wait
average to precisely 10ms, so a ticker stalling on half its frames still
reports a healthy "Avg FPS: 100.0". That reading cost several rounds of
chasing the wrong layer. The line now aggregates every frame since the last
log and reports median, p95, max, min, and explicit stall and skip rates
(past 1.5x the median missed a refresh; under half never reached the panel,
because dirty tracking skipped the swap so the frame never waited on vsync).

On the hardware this now reads:

    leaderboard  100.0 fps over 501 frames | median 10.00ms p95 10.05ms
                 max 10.34ms | stalls 0 (0.0%) skips 0 (0.0%)

The binding rebuild's blit patch becomes opt-in (RGB_PATCH_BLIT=1, default
off). Reordering that loop to row-major changes what a torn frame looks like:
column-major tearing shows as a vertical seam, row-major as a horizontal split
between the panel's upper and lower halves. On a 1/32 scan panel that reads as
a one-pixel fold across the middle of every panel, which is what was reported
on hardware and what went away when the blit was reverted. All of the measured
gain comes from the SwapOnVSync change, so the risky half is simply not worth
taking; the header says so.

Also fixes --install resolving its paths against $HOME, which is /root under
sudo, so it looked in /root/rgbmatrix-nogil-build and died with "no built
module found" on a machine where the build had just succeeded. It now resolves
SUDO_USER's home. Both build paths are verified on the Pi: default yields one
GIL-release site, RGB_PATCH_BLIT=1 yields two.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
This commit is contained in:
Chuck
2026-09-03 21:41:33 -04:00
co-authored by Claude Opus 5
parent 85ab02bb7e
commit 6031e70525
2 changed files with 142 additions and 80 deletions
+105 -70
View File
@@ -15,11 +15,17 @@
# Measured on a Pi 4 driving a 2x128x64 chain at limit_refresh_rate_hz=100: # Measured on a Pi 4 driving a 2x128x64 chain at limit_refresh_rate_hz=100:
# #
# before ~44 fps average, 14-17% of frames 41-53ms # before ~44 fps average, 14-17% of frames 41-53ms
# after 100 fps locked, no stalls observed # after 100 fps, median 10.00ms, p95 10.05ms, 0% stalls
# #
# This script also releases the GIL across the per-pixel blit # The per-pixel blit (SetPixelsPillow) can also release the GIL and walk the
# (SetPixelsPillow) and walks the Pillow buffer row-major instead of # Pillow buffer row-major, but that is OFF by default and you almost certainly
# column-major so each row is contiguous. # want to leave it that way. Row-major changes what a partially-written frame
# looks like: column-major tearing shows as a vertical seam, row-major tearing
# shows as a horizontal split between the panel's upper and lower halves. On a
# 1/32 scan panel that reads as a one-pixel "fold" across the middle of every
# panel -- reported on hardware, and it went away when the blit was reverted.
# Enable with RGB_PATCH_BLIT=1 only if you have measured that you need it;
# essentially all of the gain above comes from the SwapOnVSync change alone.
# #
# SAFETY # SAFETY
# ------ # ------
@@ -35,10 +41,19 @@
# #
set -uo pipefail set -uo pipefail
SRC_TREE="${RGB_SRC_TREE:-$HOME/LEDMatrix/rpi-rgb-led-matrix-master}" # Resolve the invoking user's home, not root's. --install runs under sudo,
BUILD_DIR="${RGB_BUILD_DIR:-$HOME/rgbmatrix-nogil-build}" # where $HOME is /root, so every default path below pointed somewhere the
VENV="${RGB_CYTHON_VENV:-$HOME/.cache/ledmatrix-cython}" # build had never written and the install died with "no built module found".
BACKUP="${RGB_BACKUP:-$HOME/rgbmatrix-core.so.ORIGINAL}" if [ -n "${SUDO_USER:-}" ]; then
OWNER_HOME="$(getent passwd "$SUDO_USER" | cut -d: -f6)"
fi
OWNER_HOME="${OWNER_HOME:-$HOME}"
SRC_TREE="${RGB_SRC_TREE:-$OWNER_HOME/LEDMatrix/rpi-rgb-led-matrix-master}"
BUILD_DIR="${RGB_BUILD_DIR:-$OWNER_HOME/rgbmatrix-nogil-build}"
VENV="${RGB_CYTHON_VENV:-$OWNER_HOME/.cache/ledmatrix-cython}"
BACKUP="${RGB_BACKUP:-$OWNER_HOME/rgbmatrix-core.so.ORIGINAL}"
PATCH_BLIT="${RGB_PATCH_BLIT:-0}"
die() { echo "FATAL: $*" >&2; exit 1; } die() { echo "FATAL: $*" >&2; exit 1; }
@@ -51,7 +66,7 @@ abi_so() {
} }
do_rollback() { do_rollback() {
local dst; dst="$(py_site)" || die "rgbmatrix not importable" local dst; dst="$(py_site)"
[ -n "$dst" ] || die "could not locate the installed rgbmatrix package" [ -n "$dst" ] || die "could not locate the installed rgbmatrix package"
[ -f "$BACKUP" ] || die "no backup at $BACKUP" [ -f "$BACKUP" ] || die "no backup at $BACKUP"
systemctl stop ledmatrix 2>/dev/null systemctl stop ledmatrix 2>/dev/null
@@ -115,83 +130,100 @@ rm -rf "$BUILD_DIR"
cp -r "$SRC_TREE" "$BUILD_DIR" || die "copy failed" cp -r "$SRC_TREE" "$BUILD_DIR" || die "copy failed"
echo "==> patching the bindings to release the GIL" echo "==> patching the bindings to release the GIL"
python3 - "$BUILD_DIR" <<'PYEOF' || die "patch failed" python3 - "$BUILD_DIR" "$PATCH_BLIT" <<'PYEOF' || die "patch failed"
import io, sys import io
base = sys.argv[1] + "/bindings/python/rgbmatrix/" import sys
base = sys.argv[1] + "/bindings/python/rgbmatrix/"
patch_blit = len(sys.argv) > 2 and sys.argv[2] == "1"
# --- declare SwapOnVSync as nogil ---------------------------------------
p = base + "cppinc.pxd" p = base + "cppinc.pxd"
s = io.open(p, encoding="utf-8").read() s = io.open(p, encoding="utf-8").read()
old = " FrameCanvas *SwapOnVSync(FrameCanvas*, uint8_t)\n" OLD_DECL = " FrameCanvas *SwapOnVSync(FrameCanvas*, uint8_t)\n"
new = " FrameCanvas *SwapOnVSync(FrameCanvas*, uint8_t) nogil\n" NEW_DECL = " FrameCanvas *SwapOnVSync(FrameCanvas*, uint8_t) nogil\n"
if old in s: if OLD_DECL in s:
io.open(p, "w", encoding="utf-8", newline="\n").write(s.replace(old, new, 1)) io.open(p, "w", encoding="utf-8", newline="\n").write(s.replace(OLD_DECL, NEW_DECL, 1))
print(" cppinc.pxd: SwapOnVSync declared nogil") print(" cppinc.pxd: SwapOnVSync declared nogil")
elif new in s: elif NEW_DECL in s:
print(" cppinc.pxd: already nogil") print(" cppinc.pxd: already nogil")
else: else:
sys.exit("could not find the SwapOnVSync declaration") sys.exit("could not find the SwapOnVSync declaration")
# --- release the GIL across the vsync wait ------------------------------
p = base + "core.pyx" p = base + "core.pyx"
s = io.open(p, encoding="utf-8").read() s = io.open(p, encoding="utf-8").read()
old = """ def SwapOnVSync(self, FrameCanvas newFrame, uint8_t framerate_fraction = 1): OLD_SWAP = (
return __createFrameCanvas(self.__matrix.SwapOnVSync(newFrame.__canvas, framerate_fraction)) " def SwapOnVSync(self, FrameCanvas newFrame, uint8_t framerate_fraction = 1):\n"
""" " return __createFrameCanvas("
new = """ def SwapOnVSync(self, FrameCanvas newFrame, uint8_t framerate_fraction = 1): "self.__matrix.SwapOnVSync(newFrame.__canvas, framerate_fraction))\n"
# Blocks until the panel's next vertical sync. Holding the GIL across )
# that wait starves every other Python thread for most of each frame. NEW_SWAP = (
cdef cppinc.RGBMatrix* matrix = self.__matrix " def SwapOnVSync(self, FrameCanvas newFrame, uint8_t framerate_fraction = 1):\n"
cdef cppinc.FrameCanvas* frame = newFrame.__canvas " # Blocks until the panel's next vertical sync. Holding the GIL\n"
cdef uint8_t fraction = framerate_fraction " # across that wait starves every other Python thread for most of\n"
cdef cppinc.FrameCanvas* swapped " # each frame. Pointers are hoisted into C locals so the blocking\n"
with nogil: " # call itself needs no Python state.\n"
swapped = matrix.SwapOnVSync(frame, fraction) " cdef cppinc.RGBMatrix* matrix = self.__matrix\n"
return __createFrameCanvas(swapped) " cdef cppinc.FrameCanvas* frame = newFrame.__canvas\n"
""" " cdef uint8_t fraction = framerate_fraction\n"
if old in s: " cdef cppinc.FrameCanvas* swapped\n"
s = s.replace(old, new, 1) " with nogil:\n"
" swapped = matrix.SwapOnVSync(frame, fraction)\n"
" return __createFrameCanvas(swapped)\n"
)
if OLD_SWAP in s:
s = s.replace(OLD_SWAP, NEW_SWAP, 1)
print(" core.pyx: SwapOnVSync releases the GIL") print(" core.pyx: SwapOnVSync releases the GIL")
elif "with nogil:\n swapped = matrix.SwapOnVSync" in s: elif "swapped = matrix.SwapOnVSync(frame, fraction)" in s:
print(" core.pyx: SwapOnVSync already patched") print(" core.pyx: SwapOnVSync already patched")
else: else:
sys.exit("could not find the SwapOnVSync body") sys.exit("could not find the SwapOnVSync body")
old = """ buffer = get_pillow_buffer(image_capsule) # --- optional: release the GIL across the blit --------------------------
OLD_BLIT = (
for col in range(max(0, -xstart), min(width, frame_width - xstart)): " buffer = get_pillow_buffer(image_capsule)\n"
for row in range(max(0, -ystart), min(height, frame_height - ystart)): "\n"
pixel = buffer[row][col] " for col in range(max(0, -xstart), min(width, frame_width - xstart)):\n"
r = (pixel ) & 0xFF " for row in range(max(0, -ystart), min(height, frame_height - ystart)):\n"
g = (pixel >> 8) & 0xFF " pixel = buffer[row][col]\n"
b = (pixel >> 16) & 0xFF " r = (pixel ) & 0xFF\n"
my_canvas.SetPixel(xstart+col, ystart+row, r, g, b) " g = (pixel >> 8) & 0xFF\n"
""" " b = (pixel >> 16) & 0xFF\n"
new = """ buffer = get_pillow_buffer(image_capsule) " my_canvas.SetPixel(xstart+col, ystart+row, r, g, b)\n"
)
# Bounds hoisted so the blit needs no Python state and can run without NEW_BLIT = (
# the GIL: it touches only a C buffer and a C++ canvas. Row-major order " buffer = get_pillow_buffer(image_capsule)\n"
# walks each row contiguously; col-outer re-strided the whole buffer. "\n"
cdef int col_start = max(0, -xstart) " # Bounds hoisted so the blit needs no Python state and can run\n"
cdef int col_end = min(width, frame_width - xstart) " # without the GIL: it touches only a C buffer and a C++ canvas.\n"
cdef int row_start = max(0, -ystart) " # NOTE: row-major order makes a torn frame show as a horizontal\n"
cdef int row_end = min(height, frame_height - ystart) " # split across the panel's halves. See the header before enabling.\n"
" cdef int col_start = max(0, -xstart)\n"
with nogil: " cdef int col_end = min(width, frame_width - xstart)\n"
for row in range(row_start, row_end): " cdef int row_start = max(0, -ystart)\n"
for col in range(col_start, col_end): " cdef int row_end = min(height, frame_height - ystart)\n"
pixel = buffer[row][col] "\n"
r = (pixel ) & 0xFF " with nogil:\n"
g = (pixel >> 8) & 0xFF " for row in range(row_start, row_end):\n"
b = (pixel >> 16) & 0xFF " for col in range(col_start, col_end):\n"
my_canvas.SetPixel(xstart+col, ystart+row, r, g, b) " pixel = buffer[row][col]\n"
""" " r = (pixel ) & 0xFF\n"
if old in s: " g = (pixel >> 8) & 0xFF\n"
s = s.replace(old, new, 1) " b = (pixel >> 16) & 0xFF\n"
" my_canvas.SetPixel(xstart+col, ystart+row, r, g, b)\n"
)
if patch_blit:
if OLD_BLIT in s:
s = s.replace(OLD_BLIT, NEW_BLIT, 1)
print(" core.pyx: pixel blit releases the GIL, row-major") print(" core.pyx: pixel blit releases the GIL, row-major")
elif "with nogil:\n for row in range(row_start, row_end):" in s: elif "for row in range(row_start, row_end):" in s:
print(" core.pyx: blit already patched") print(" core.pyx: blit already patched")
else: else:
sys.exit("could not find the SetPixelsPillow loop") sys.exit("could not find the SetPixelsPillow loop")
else:
print(" core.pyx: blit left unpatched (RGB_PATCH_BLIT=1 to enable)")
io.open(p, "w", encoding="utf-8", newline="\n").write(s) io.open(p, "w", encoding="utf-8", newline="\n").write(s)
PYEOF PYEOF
@@ -231,12 +263,15 @@ echo "==> compiling the extension"
SO="$(abi_so)"; [ -n "$SO" ] || die "no .so produced" SO="$(abi_so)"; [ -n "$SO" ] || die "no .so produced"
# Verify the GIL really is released before anyone installs this. # Verify the GIL really is released before anyone installs this.
PAIRS=$(grep -c "PyEval_SaveThread\|Py_UNBLOCK_THREADS" "$BUILD_DIR/bindings/python/rgbmatrix/core.cpp") EXPECTED=1; [ "$PATCH_BLIT" = "1" ] && EXPECTED=2
[ "$PAIRS" -ge 2 ] || die "generated C++ has only $PAIRS GIL releases, expected >= 2" PAIRS=$(grep -c "PyEval_SaveThread\|Py_UNBLOCK_THREADS" \
"$BUILD_DIR/bindings/python/rgbmatrix/core.cpp")
[ "$PAIRS" -ge "$EXPECTED" ] \
|| die "generated C++ has $PAIRS GIL-release sites, expected >= $EXPECTED"
echo echo
echo "BUILT: $SO" echo "BUILT: $SO"
echo " ($PAIRS GIL-release sites in the generated C++)" echo " ($PAIRS GIL-release site(s) in the generated C++)"
echo echo
echo "Install with: sudo bash $0 --install" echo "Install with: sudo bash $0 --install"
echo "Roll back with: sudo bash $0 --rollback" echo "Roll back with: sudo bash $0 --rollback"
+33 -6
View File
@@ -116,6 +116,9 @@ class ScrollHelper:
self.last_frame_time = time.time() self.last_frame_time = time.time()
self.last_fps_log_time = time.time() self.last_fps_log_time = time.time()
self.frame_times = [] self.frame_times = []
# Every frame time since the last stats line, so the 5s summary can
# report the tail rather than one arbitrary sample. Cleared on log.
self._window: list = []
# Scrolling state management # Scrolling state management
self.is_scrolling = False self.is_scrolling = False
@@ -1041,17 +1044,41 @@ class ScrollHelper:
if len(self.frame_times) > 100: if len(self.frame_times) > 100:
self.frame_times.pop(0) self.frame_times.pop(0)
# Every frame since the last log, not just the last 100 and not just
# the one that happens to land on the 5s boundary. The old line
# reported a single instantaneous sample -- roughly 1 frame in 500 --
# which cannot see a stall that hits 1% of frames, and reported it
# next to an average that hides the same stall by construction (a 2ms
# duplicate and a 21ms double-wait mean exactly 10ms). Chasing scroll
# judder needs the tail, so keep the window and report percentiles.
self._window.append(frame_time)
# Log FPS every 5 seconds to avoid spam # Log FPS every 5 seconds to avoid spam
if current_time - self.last_fps_log_time >= 5.0: if current_time - self.last_fps_log_time >= 5.0:
avg_frame_time = sum(self.frame_times) / len(self.frame_times) window = sorted(self._window) if self._window else [frame_time]
avg_fps = 1.0 / avg_frame_time if avg_frame_time > 0 else 0 n = len(window)
instant_fps = 1.0 / frame_time if frame_time > 0 else 0 median = window[n // 2]
p95 = window[min(n - 1, int(n * 0.95))]
worst = window[-1]
best = window[0]
mean = sum(window) / n
# Anything past 1.5x the median missed a panel refresh; anything
# under half of it never reached the panel at all (dirty tracking
# skipped the swap, so the frame did not wait for vsync).
stalls = sum(1 for f in window if f > median * 1.5)
skips = sum(1 for f in window if f < median * 0.5)
self.logger.info(f"Scroll frame stats - Avg FPS: {avg_fps:.1f}, " self.logger.info(
f"Current FPS: {instant_fps:.1f}, " "Scroll frame stats - %.1f fps over %d frames | "
f"Frame time: {frame_time*1000:.2f}ms") "median %.2fms p95 %.2fms max %.2fms min %.2fms | "
"stalls %d (%.1f%%) skips %d (%.1f%%)",
(1.0 / mean) if mean > 0 else 0.0, n,
median * 1000, p95 * 1000, worst * 1000, best * 1000,
stalls, 100.0 * stalls / n, skips, 100.0 * skips / n,
)
self.last_fps_log_time = current_time self.last_fps_log_time = current_time
self.frame_count = 0 self.frame_count = 0
self._window = []
self.last_frame_time = current_time self.last_frame_time = current_time
self.frame_count += 1 self.frame_count += 1