src.nth.io/

summaryrefslogtreecommitdiff
diff options
context:
space:
mode:
authorLuke Hoersten <[email protected]>2026-06-20 11:54:14 -0500
committerLuke Hoersten <[email protected]>2026-06-20 11:54:14 -0500
commit28f39bf5102ef398b6e91fdf61e7583c99d7252c (patch)
tree140c2dc96ee37d507afcaa0a0b18338f6ec60ced
parent16f4c5be220756808747bfb47739733d3f107634 (diff)
scrypted: kill listener leak across script reloads + one-line sent-vs-painted log
#1 — Camera listener leak Same Scripts-sandbox lifecycle gap that bit us with setInterval (fixed in 521de7e): cam.listen() returns an EventListenerRegister with a removeListener() method. The listener is held on the camera plugin's side, not the script's, so when the old Provider instance gets GC'd on script reload its registrations stay live with a dead callback. Field symptom: after re-pasting the script N times, every camera event arrives N times in handleCameraEvent. Today the streamStarting guard catches sequential dupes, but two callbacks firing on the same event within the JS microtask window both check streamStarting BEFORE either has added their nativeId, both proceed, two pushSnapshots launch in parallel. They race for the firmware decoder lock — one paints, one gets 503 — and the user perceives sharp-fighting-with-itself as "snapshot quality is bad again." Fix: same globalThis trick as the setInterval. Push a remover closure onto G.__viewportListenerCleaners every time attachListener fires; at start() of the new Provider instance, drain the array calling each remover before creating fresh listeners. Idempotent across reloads. #2 — Unified sent-vs-painted log The user asked: "do we have an understanding in the logging/ instrumentation what the FPS of the stream output is from scrypted out is vs the actual rendered FPS once the stream is loaded?" Both numbers existed but in separate log lines (skipLogger every 10s + fwPoller every 5s, interleaved in the console). Folded the /state poll into the 10s skipLogger so there's ONE line per window with sent fps + painted fps side-by-side plus the gap explicitly labeled: stream "kitchen": sent=24.2fps painted=22.8fps (fw-skipped=1.4fps, drops=0) 4.58MB/s sent / 4.29MB/s painted | socket.write p50=0ms p95=1ms max=5ms backpressured=true | recv=27776/37237/44470us dec=5788/5991/6626us paint=30/36/46us idle=164/588/11383us | g2g=142ms fw-skipped = (sent − painted), how many frames per second the firmware's FIONREAD skip dropped to keep the panel on the freshest frame. The g2g value is now meaningful per-frame thanks to the firmware-side live-update we landed last commit. Drops the separate fwPoller; one comprehensive log per 10s window.
-rw-r--r--scrypted/scrypted-viewport.ts131
1 files changed, 75 insertions, 56 deletions
diff --git a/scrypted/scrypted-viewport.ts b/scrypted/scrypted-viewport.ts
index 56b7186..7156fba 100644
--- a/scrypted/scrypted-viewport.ts
+++ b/scrypted/scrypted-viewport.ts
@@ -6,7 +6,7 @@
// short git hash of the commit that added this constant — if the
// hash in the log doesn't match the HEAD this file came from, the
// Scrypted Script editor is still on stale code.
-const SCRIPT_VERSION = "568de10";
+const SCRIPT_VERSION = "pending";
//
// Architecture
// ------------
@@ -366,6 +366,18 @@ class ScryptedViewportProvider extends ScryptedDeviceBase
if (G.__viewportRegisterInterval) {
try { clearInterval(G.__viewportRegisterInterval); } catch {}
}
+ // Tear down any camera event listeners left over from a
+ // previous script load (same Scripts-sandbox lifecycle gap as
+ // the setInterval handle). Without this every re-paste stacks
+ // an extra callback on the camera, producing duplicate stream
+ // starts + concurrent snapshot transforms that race for the
+ // firmware decoder lock and visibly degrade quality.
+ if (Array.isArray(G.__viewportListenerCleaners)) {
+ for (const remove of G.__viewportListenerCleaners) {
+ try { remove(); } catch {}
+ }
+ }
+ G.__viewportListenerCleaners = [];
G.__viewportRegisterInterval = setInterval(() => {
for (const v of this.viewports.values()) {
this.registerViewport(v).catch(() => {});
@@ -539,6 +551,16 @@ class ScryptedViewportProvider extends ScryptedDeviceBase
this.handleCameraEvent(v, details, data);
});
this.listeners.set(v.nativeId!, reg);
+ // Track on globalThis so script reload can remove this
+ // listener from the camera plugin. Without that, every
+ // re-paste leaves a dead callback subscribed to the camera
+ // and every motion/doorbell event triggers handleCameraEvent
+ // N times for N stacked reloads — observable as duplicate
+ // "stream start" log lines + two simultaneous pushSnapshots
+ // racing for the firmware decoder lock.
+ const G = globalThis as any;
+ if (!G.__viewportListenerCleaners) G.__viewportListenerCleaners = [];
+ G.__viewportListenerCleaners.push(() => { try { reg.removeListener(); } catch {} });
this.console.log(`viewport "${tag}": subscribed to "${cam.name}"`);
}
@@ -953,70 +975,67 @@ class ScryptedViewportProvider extends ScryptedDeviceBase
try { currentProc?.kill("SIGTERM"); } catch {}
});
- // Periodic stream-health log. Emits delivered fps + sustained
- // MB/s + socket.write p50/p95/max + drop count + backpressure
- // flag every 10s. drops here count frames the demux loop
- // threw away because the socket wasn't connected yet (initial
- // race at stream start) — once the socket is up we keep
- // writing past kernel backpressure and let the firmware's
- // FIONREAD skip drop the stale frames before decode.
- const skipLogger = setInterval(() => {
+ // Unified stream-health log every 10s: Scrypted-side sent fps
+ // + firmware-side painted fps side-by-side, so the user can
+ // see at a glance "we sent N, the panel showed M." The gap
+ // (sent - painted) is what the firmware's FIONREAD skip
+ // dropped to keep the panel showing the freshest frame.
+ // Includes firmware-side per-stage timings (recv/dec/paint/
+ // idle min/avg/max) + glass-to-glass age of the most recent
+ // painted frame. /state poll is folded in so there's one log
+ // line per window instead of two interleaved timelines.
+ const streamLogger = setInterval(async () => {
const now = Date.now();
const window = (now - lastLogUs) / 1000;
- if (window > 0 && (sentFrames > 0 || droppedFrames > 0)) {
- const sentRate = sentFrames / window;
- const dropRate = droppedFrames / window;
- const mbPerSec = (bytesSent / window) / (1024 * 1024);
- const sortedW = writeLatencies.slice().sort((a, b) => a - b);
- const p50 = sortedW.length ? sortedW[Math.floor(sortedW.length * 0.5)] : 0;
- const p95 = sortedW.length ? sortedW[Math.floor(sortedW.length * 0.95)] : 0;
- const max = sortedW.length ? sortedW[sortedW.length - 1] : 0;
- this.console.log(
- `stream "${v.name}": ${sentRate.toFixed(1)} fps, ${mbPerSec.toFixed(2)} MB/s ` +
- `over ${window.toFixed(1)}s ` +
- `(drops=${droppedFrames}=${dropRate.toFixed(1)} fps) ` +
- `socket.write p50=${p50}ms p95=${p95}ms max=${max}ms ` +
- `backpressured=${socketBackpressured}`);
- droppedFrames = 0;
- sentFrames = 0;
- bytesSent = 0;
- writeLatencies.length = 0;
- lastLogUs = now;
- }
- }, 10_000);
- abort.signal.addEventListener("abort", () => clearInterval(skipLogger));
-
- // Periodic /state poll to surface firmware-side window stats +
- // computed glass-to-glass. Runs every 5s while the stream is
- // active. g2g = (nowUsLow - last_paint_event_us_low) with
- // 32-bit wrap; clamped to a 30s sanity ceiling because event
- // timestamps from before the stream started are stale and
- // would yield gigantic apparent latencies.
- const fwPoller = setInterval(async () => {
+ if (window <= 0 || (sentFrames === 0 && droppedFrames === 0)) return;
+ const sentRate = sentFrames / window;
+ const dropRate = droppedFrames / window;
+ const mbPerSec = (bytesSent / window) / (1024 * 1024);
+ const sortedW = writeLatencies.slice().sort((a, b) => a - b);
+ const p50 = sortedW.length ? sortedW[Math.floor(sortedW.length * 0.5)] : 0;
+ const p95 = sortedW.length ? sortedW[Math.floor(sortedW.length * 0.95)] : 0;
+ const max = sortedW.length ? sortedW[sortedW.length - 1] : 0;
+
+ // Best-effort firmware-side snapshot. Timeout < 1s so a
+ // missed /state never wedges the logger.
+ let painted = "?", paintedMb = "?", g2g = "?", paintedNum = -1;
+ let recvStr = "?", decStr = "?", paintStr = "?", idleStr = "?";
try {
const st: any = await fetch(`http://${v.host}/state`, {
- signal: AbortSignal.timeout(1500),
+ signal: AbortSignal.timeout(800),
}).then(r => r.json());
const fs = st?.stream;
- if (!fs || !fs.frames) return;
- const fps = fs.window_us > 0 ? (fs.frames / (fs.window_us / 1e6)) : 0;
- const mb = fs.window_us > 0 ? ((fs.bytes / (fs.window_us / 1e6)) / (1024 * 1024)) : 0;
- let g2gMs = -1;
- if (fs.last_paint_event_us_low) {
+ if (fs?.frames && fs.window_us > 0) {
+ paintedNum = fs.frames / (fs.window_us / 1e6);
+ painted = paintedNum.toFixed(1);
+ paintedMb = ((fs.bytes / (fs.window_us / 1e6)) / (1024 * 1024)).toFixed(2);
+ recvStr = `${fs.recv_min_us}/${fs.recv_avg_us}/${fs.recv_max_us}`;
+ decStr = `${fs.dec_min_us}/${fs.dec_avg_us}/${fs.dec_max_us}`;
+ paintStr = `${fs.paint_min_us}/${fs.paint_avg_us}/${fs.paint_max_us}`;
+ idleStr = `${fs.idle_min_us}/${fs.idle_avg_us}/${fs.idle_max_us}`;
+ }
+ if (fs?.last_paint_event_us_low) {
const nowUsLow = (Date.now() * 1000) >>> 0;
const diff = (nowUsLow - fs.last_paint_event_us_low) >>> 0;
- if (diff < 30_000_000) g2gMs = diff / 1000;
+ if (diff < 30_000_000) g2g = (diff / 1000).toFixed(0) + "ms";
}
- this.console.log(
- `firmware "${v.name}": fps=${fps.toFixed(1)} ${mb.toFixed(2)}MB/s | ` +
- `recv=${fs.recv_min_us}/${fs.recv_avg_us}/${fs.recv_max_us}us | ` +
- `dec=${fs.dec_min_us}/${fs.dec_avg_us}/${fs.dec_max_us}us | ` +
- `paint=${fs.paint_min_us}/${fs.paint_avg_us}/${fs.paint_max_us}us | ` +
- `idle=${fs.idle_min_us}/${fs.idle_avg_us}/${fs.idle_max_us}us | ` +
- `g2g=${g2gMs >= 0 ? g2gMs.toFixed(0) + "ms" : "(no event yet)"}`);
- } catch { /* /state timeout is fine, try next tick */ }
- }, 5_000);
- abort.signal.addEventListener("abort", () => clearInterval(fwPoller));
+ } catch { /* keep the local stats; firmware-side just shows ? */ }
+
+ const skipped = paintedNum >= 0 ? Math.max(0, sentRate - paintedNum).toFixed(1) : "?";
+ this.console.log(
+ `stream "${v.name}": sent=${sentRate.toFixed(1)}fps painted=${painted}fps ` +
+ `(fw-skipped=${skipped}fps, drops=${droppedFrames}) ` +
+ `${mbPerSec.toFixed(2)}MB/s sent / ${paintedMb}MB/s painted | ` +
+ `socket.write p50=${p50}ms p95=${p95}ms max=${max}ms backpressured=${socketBackpressured} | ` +
+ `recv=${recvStr}us dec=${decStr}us paint=${paintStr}us idle=${idleStr}us | g2g=${g2g}`);
+
+ droppedFrames = 0;
+ sentFrames = 0;
+ bytesSent = 0;
+ writeLatencies.length = 0;
+ lastLogUs = now;
+ }, 10_000);
+ abort.signal.addEventListener("abort", () => clearInterval(streamLogger));
const timeoutMs = v.idleTimeoutMs > 0 ? v.idleTimeoutMs : DEFAULT_IDLE_TIMEOUT_MS;
const timeout = setTimeout(() => {