From f3100c598a3259dfc5e6f7cdf3e6fc39f83f0e22 Mon Sep 17 00:00:00 2001 From: Eli Fayerman Date: Thu, 30 Jul 2026 11:59:51 +0900 Subject: [PATCH] Save Ring's detection-time snapshot and log per-capture latency MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Motion clips were starting after subjects had already walked past, so recordings showed people leaving rather than approaching. Measured on a battery Spotlight Cam Plus over 10 real motion events, the gap between Ring detecting motion and the first frame reaching disk is ~8.5s median: Ring detection -> push arrives here ~2.3s (Ring's) trigger -> live stream negotiated ~3.7s (WebRTC signaling + wake) stream open -> first bytes on disk ~2.5s (ffmpeg analysis) At walking pace that is ~12 m of approach never recorded. Almost all of it is Ring-side. A live stream opened after an event also cannot contain footage from before it, so no amount of tuning here produces pre-roll. Confirmed the cloud route is closed without a subscription: getEvents() reports every motion event as recorded/ready, but getRecordingUrl() returns "Source video not available" and videoSearch() returns empty. What is available is the still Ring captures at detection time. Its uuid rides along on the motion push (img.snapshot_uuid), and it predates the first video frame by the whole window above — so it is the only view of the approach obtainable without Ring Protect. It costs one REST fetch and does not wake the camera. - detection.ts: parse the push into a detection context (Ring's own detection timestamp, ding id, subtype, snapshot uuid) and compute the latency segments. Pure, so the arithmetic is testable without an account, camera or clock. - events.ts: subscribe to onNewNotification alongside the existing boolean motion stream, and on trigger fetch the snapshot *in parallel* with the recording rather than after it — Ring expires these, so waiting out a 30s clip risks losing the one frame showing the approach. - recorder.ts: capture triggerAt / streamOpenAt / firstFrameAt. First-frame is detected by polling the output for non-zero size; that is time-to-first-bytes (the fMP4 header flushes just ahead of the first fragment), which is within a frame interval of first-frame and far below the latency being measured. - files.ts: appendJsonLine, which reports failure rather than throwing. Every part of this is diagnostic bookkeeping attached to a recording that already succeeded, so no failure in it can turn a saved clip into a reported one: a missing uuid, an expired snapshot, an unwritable log and a camera with no notification stream all degrade to a null field. Covered by tests. New config: detectionSnapshots and timingLog, both default true. Latency rows land in /timing.jsonl, one per capture, so the effect of a motion zone or sensitivity change can be measured against the 8.5s baseline instead of eyeballed. (A future captures.jsonl manifest, backlog #4, can supersede this.) Also corrects the README, which claimed the pre-roll loss was "~1-2s". Measured local latency alone is ~4-6s and the full window ~8.5s; that line is what set the wrong expectation. Verified: 31 tests pass. Service starts, subscribes and shuts down cleanly against the live API, and a real capture returns populated timings (4.35s stream setup, 7.01s to first bytes). --- README.md | 45 ++++++- config.example.json | 4 +- src/config.ts | 16 +++ src/detection.ts | 141 ++++++++++++++++++++ src/events.ts | 122 +++++++++++++++++- src/files.ts | 19 ++- src/recorder.ts | 67 +++++++--- test/detection.test.mjs | 279 ++++++++++++++++++++++++++++++++++++++++ 8 files changed, 670 insertions(+), 23 deletions(-) create mode 100644 src/detection.ts create mode 100644 test/detection.test.mjs diff --git a/README.md b/README.md index 7abaec8..fc84270 100644 --- a/README.md +++ b/README.md @@ -90,6 +90,8 @@ variables. See `config.example.json`. Key fields: | `motionCooldownSeconds` | `20` | Min gap between auto-recordings per camera. | | `retentionDays` | `null` | Delete clips older than N days. `null` = keep all. | | `retentionSweepMinutes` | `60` | How often retention runs while the service is up. | +| `detectionSnapshots` | `true` | Save Ring's detection-time still next to each clip. | +| `timingLog` | `true` | Append per-capture latency rows to `/timing.jsonl`. | Environment overrides: `RING_TOKEN_PATH`, `RING_OUTPUT_DIR`, `RING_CLIP_SECONDS`, `RING_RETENTION_DAYS`, `RING_DEBUG=1`. @@ -103,9 +105,46 @@ default `shouldTrigger()` policy: - Enforces `motionCooldownSeconds` between the *start* of consecutive clips. If you want "extend while motion persists" instead of fixed-length clips, or a different -cooldown, edit `shouldTrigger()`; it's deliberately isolated for that. One -no-subscription caveat: a clip can only begin *after* the event arrives, so there's no -pre-roll buffer (you lose the ~1-2s before the trigger). +cooldown, edit `shouldTrigger()`; it's deliberately isolated for that. + +### Startup latency (no pre-roll) + +A clip can only begin *after* the event arrives, so there is no pre-roll buffer. The +gap is larger than it sounds. Measured on a battery Spotlight Cam Plus, median over 10 +real motion events: + +| Segment | Typical | Whose latency | +|---------|---------|---------------| +| Ring detects motion → push arrives here | ~2.3s | Ring's | +| Trigger → live stream negotiated | ~3.7-4.4s | Ring's (WebRTC signaling + camera wake) | +| Stream open → first bytes on disk | ~2.5s | ffmpeg stream analysis | +| **Ring detection → first frame** | **~8.5s** | | + +At walking pace that is roughly 12 m of approach that is never recorded, which is why +subjects can appear to be *leaving* rather than arriving. Almost all of it is Ring-side +and cannot be reduced from here. + +Two things help: + +- **`detectionSnapshots`** (on by default) saves the still Ring captured *at detection + time* as `.detection.jpg`. It predates the first video frame by the whole + window above, so it is the only view of the approach available without a Ring + Protect subscription. Costs one REST fetch and does not wake the camera. Ring's push + does not always carry one; when it doesn't, the clip is unaffected. +- **Detect earlier rather than react faster.** Widening the camera's motion zone and + raising sensitivity moves the trigger earlier in someone's approach, so the same + latency lands while they are still walking toward the camera. + +`timingLog` (on by default) appends one row per capture to `/timing.jsonl` +with each segment above, so a settings change can be measured instead of guessed: + +```json +{"camera":"Front","clip":"Front_….mp4","detectionSnapshot":"Front_….detection.jpg", + "subtype":"motion","ringEventAt":"…","firstFrameAt":"…", + "pushDelaySec":2.27,"streamSetupSec":3.75,"firstFrameSec":2.45,"blindWindowSec":8.5} +``` + +`blindWindowSec` is the headline number: Ring's detection to the first frame on disk. ## Running as a background service diff --git a/config.example.json b/config.example.json index 9c31783..bfaa2fa 100644 --- a/config.example.json +++ b/config.example.json @@ -7,5 +7,7 @@ "recordOnDing": true, "motionCooldownSeconds": 20, "retentionDays": 14, - "retentionSweepMinutes": 60 + "retentionSweepMinutes": 60, + "detectionSnapshots": true, + "timingLog": true } diff --git a/src/config.ts b/src/config.ts index e5af440..3189b6e 100644 --- a/src/config.ts +++ b/src/config.ts @@ -33,6 +33,20 @@ export interface AppConfig { retentionDays: number | null; /** How often (minutes) to run the retention sweep while the service runs. */ retentionSweepMinutes: number; + /** + * Save the snapshot Ring captured at detection time alongside each clip. + * + * Ring's motion push can carry a snapshot uuid for a still taken when motion + * was detected — seconds *before* a live stream can be negotiated. That still + * is the only view of the approach available without a Ring Protect + * subscription. Costs one REST fetch and does not wake the camera. + */ + detectionSnapshots: boolean; + /** + * Append a per-capture latency record to `/timing.jsonl`. + * Used to measure the gap between Ring's detection and the first frame. + */ + timingLog: boolean; } const DEFAULTS: AppConfig = { @@ -45,6 +59,8 @@ const DEFAULTS: AppConfig = { motionCooldownSeconds: 20, retentionDays: null, retentionSweepMinutes: 60, + detectionSnapshots: true, + timingLog: true, }; /** Resolve a possibly-relative path against the project root. */ diff --git a/src/detection.ts b/src/detection.ts new file mode 100644 index 0000000..a10c707 --- /dev/null +++ b/src/detection.ts @@ -0,0 +1,141 @@ +import type { PushNotificationDingV2 } from 'ring-client-api'; + +/** + * Detection context lifted out of a Ring push notification. + * + * The point of this module is latency accounting. A clip can only start after + * the event reaches us, so the interesting question is *how much happened + * before the first frame* — and answering it needs Ring's own timestamps, not + * ours. `ringEventAtMs` is the moment Ring says it detected motion; + * `receivedAtMs` is when the push landed here. The gap between them is Ring's, + * and nothing in this repo can shrink it. + */ +export interface DetectionContext { + dingId?: string; + /** 'motion' | 'ding' | 'human' | 'other_motion' | ... (Ring's own label). */ + subtype?: string; + /** Ring's detection timestamp (ms epoch), from ding.created_at or analytics.triggered_at. */ + ringEventAtMs?: number; + /** UUID of the snapshot Ring captured at detection time, if the push carried one. */ + snapshotUuid?: string; + /** When this process received the push (ms epoch). */ + receivedAtMs: number; +} + +/** + * Pull the useful fields out of a push notification. + * + * Every field is optional in practice: Ring's payload shape varies by device + * and firmware, and `img` in particular is absent on some cameras. A partial + * context is still worth recording — a missing snapshot uuid should degrade to + * "no snapshot", never to a dropped recording. + */ +export function parseNotification(n: PushNotificationDingV2, receivedAtMs: number): DetectionContext { + const ding = n?.data?.event?.ding; + const createdAt = ding?.created_at ? Date.parse(ding.created_at) : NaN; + const triggeredAt = n?.analytics?.triggered_at; + + // Prefer ding.created_at (detection); fall back to analytics.triggered_at. + let ringEventAtMs: number | undefined; + if (Number.isFinite(createdAt)) ringEventAtMs = createdAt; + else if (typeof triggeredAt === 'number' && Number.isFinite(triggeredAt)) ringEventAtMs = triggeredAt; + + return { + dingId: ding?.id, + subtype: ding?.subtype, + ringEventAtMs, + snapshotUuid: n?.img?.snapshot_uuid, + receivedAtMs, + }; +} + +/** + * Decide whether a stored notification belongs to the trigger firing now. + * + * `onMotionDetected` and `onNewNotification` are separate streams over the same + * push, so a trigger normally has a notification from milliseconds earlier. A + * *stale* one must not be attached: motion triggers can also come from a + * boolean transition with no fresh push behind it, and pairing a clip with a + * 20-minute-old detection would silently corrupt the latency numbers this + * module exists to produce. Unrelated is better than wrong. + */ +export function pickDetection( + latest: DetectionContext | undefined, + triggerAtMs: number, + maxAgeMs: number, +): DetectionContext | undefined { + if (!latest) return undefined; + const age = triggerAtMs - latest.receivedAtMs; + if (age < 0 || age > maxAgeMs) return undefined; + return latest; +} + +/** Timestamps collected across one recording attempt (ms epoch). */ +export interface CaptureTiming { + triggerAtMs: number; + streamOpenAtMs?: number; + firstFrameAtMs?: number; +} + +export interface TimingRecord { + camera: string; + clip: string; + detectionSnapshot: string | null; + dingId: string | null; + subtype: string | null; + ringEventAt: string | null; + notificationReceivedAt: string | null; + triggerAt: string; + streamOpenAt: string | null; + firstFrameAt: string | null; + /** Ring detection -> push received here. Ring's latency; not ours. */ + pushDelaySec: number | null; + /** Trigger -> live stream negotiated (WebRTC signaling + camera wake). */ + streamSetupSec: number | null; + /** Stream open -> first bytes on disk (ffmpeg stream analysis). */ + firstFrameSec: number | null; + /** Ring detection -> first bytes on disk. The headline number. */ + blindWindowSec: number | null; +} + +const iso = (ms?: number): string | null => (typeof ms === 'number' && Number.isFinite(ms) ? new Date(ms).toISOString() : null); +/** Elapsed ms between two epoch timestamps, as seconds to 2dp. */ +const secs = (a?: number, b?: number): number | null => + typeof a === 'number' && typeof b === 'number' && Number.isFinite(a) && Number.isFinite(b) + ? Math.round((b - a) / 10) / 100 + : null; + +/** + * Build the JSONL record for one capture. Pure so the arithmetic is testable + * without a Ring account, a camera, or a clock. + */ +export function buildTimingRecord(args: { + cameraName: string; + clipFile: string; + snapshotFile: string | null; + detection?: DetectionContext; + timing: CaptureTiming; +}): TimingRecord { + const { cameraName, clipFile, snapshotFile, detection, timing } = args; + return { + camera: cameraName, + clip: clipFile, + detectionSnapshot: snapshotFile, + dingId: detection?.dingId ?? null, + subtype: detection?.subtype ?? null, + ringEventAt: iso(detection?.ringEventAtMs), + notificationReceivedAt: iso(detection?.receivedAtMs), + triggerAt: new Date(timing.triggerAtMs).toISOString(), + streamOpenAt: iso(timing.streamOpenAtMs), + firstFrameAt: iso(timing.firstFrameAtMs), + pushDelaySec: secs(detection?.ringEventAtMs, detection?.receivedAtMs), + streamSetupSec: secs(timing.triggerAtMs, timing.streamOpenAtMs), + firstFrameSec: secs(timing.streamOpenAtMs, timing.firstFrameAtMs), + blindWindowSec: secs(detection?.ringEventAtMs, timing.firstFrameAtMs), + }; +} + +/** Sibling path for the detection snapshot: Front_.mp4 -> Front_.detection.jpg */ +export function detectionSnapshotPath(clipPath: string): string { + return clipPath.replace(/\.mp4$/i, '') + '.detection.jpg'; +} diff --git a/src/events.ts b/src/events.ts index 4b42685..2dc8ed5 100644 --- a/src/events.ts +++ b/src/events.ts @@ -1,17 +1,39 @@ +import { join } from 'node:path'; +import { writeFileSync } from 'node:fs'; import type { Subscription } from 'rxjs'; -import type { RingCamera } from 'ring-client-api'; +import type { PushNotificationDingV2, RingCamera } from 'ring-client-api'; import type { AppConfig } from './config.js'; import { recordClip, type RecordResult } from './recorder.js'; +import { appendJsonLine } from './files.js'; +import { + buildTimingRecord, + detectionSnapshotPath, + parseNotification, + pickDetection, + type DetectionContext, +} from './detection.js'; import { log } from './log.js'; /** Recorder function shape — injectable so the trigger logic is unit-testable. */ export type RecordFn = (camera: RingCamera, cfg: AppConfig, seconds: number) => Promise; +/** Snapshot fetcher — injectable for the same reason. */ +export type SnapshotFn = (camera: RingCamera, uuid: string) => Promise; + +/** + * A notification older than this is treated as unrelated to the trigger firing + * now. Generous enough to absorb event-loop and push-processing jitter, far + * short of the `motionCooldownSeconds` floor between clips. + */ +const DETECTION_MAX_AGE_MS = 15_000; + /** Per-camera runtime state used to debounce overlapping triggers. */ interface CameraState { recording: boolean; lastStartMs: number; motionActive: boolean; + /** Most recent push notification seen for this camera, for latency accounting. */ + lastDetection?: DetectionContext; } /** @@ -26,6 +48,75 @@ interface CameraState { * coverage of long events, but unbounded clip length + battery drain). * - shorter/zero cooldown: more clips, more overlap, more account API load. */ +const defaultSnapshotFn: SnapshotFn = (camera, uuid) => camera.getSnapshotByUuid(uuid); + +/** + * Fetch the detection-time snapshot, or resolve null. + * + * Never rejects. `img.snapshot_uuid` is optional in Ring's payload and the + * fetch itself can fail (expired uuid, throttling, no subscription), none of + * which is a reason to fail the clip that is already recording. + */ +async function fetchDetectionSnapshot( + camera: RingCamera, + cfg: AppConfig, + detection: DetectionContext | undefined, + snapshotFn: SnapshotFn, +): Promise { + if (!cfg.detectionSnapshots) return null; + const uuid = detection?.snapshotUuid; + if (!uuid) { + log.debug(`No detection snapshot uuid in the push for "${camera.name}".`); + return null; + } + try { + return await snapshotFn(camera, uuid); + } catch (err) { + log.warn(`Could not fetch detection snapshot for "${camera.name}": ${(err as Error).message}`); + return null; + } +} + +/** + * Write the detection snapshot next to the clip and append the latency record. + * Never throws — see appendJsonLine for the same reasoning. + */ +async function writeCaptureMetadata( + cfg: AppConfig, + result: RecordResult, + detection: DetectionContext | undefined, + snapshot: Buffer | null, + triggerAtMs: number, +): Promise { + let snapshotFile: string | null = null; + if (snapshot) { + const path = detectionSnapshotPath(result.path); + try { + writeFileSync(path, snapshot); + snapshotFile = path.split('/').pop() ?? null; + log.info(`Saved detection snapshot ${snapshotFile} (${(snapshot.length / 1024).toFixed(0)} KB)`); + } catch (err) { + log.warn(`Could not write detection snapshot: ${(err as Error).message}`); + } + } + + if (!cfg.timingLog) return; + const record = buildTimingRecord({ + cameraName: result.camera, + clipFile: result.path.split('/').pop() ?? result.path, + snapshotFile, + detection, + timing: result.timing ?? { triggerAtMs }, + }); + appendJsonLine(join(cfg.outputDir, 'timing.jsonl'), record); + if (record.blindWindowSec !== null) { + log.info( + `Latency: Ring detection -> first frame ${record.blindWindowSec}s ` + + `(push ${record.pushDelaySec}s, stream setup ${record.streamSetupSec}s, first frame ${record.firstFrameSec}s)`, + ); + } +} + function shouldTrigger(state: CameraState, cfg: AppConfig, nowMs: number): boolean { if (state.recording) return false; const sinceLastMs = nowMs - state.lastStartMs; @@ -37,10 +128,27 @@ function shouldTrigger(state: CameraState, cfg: AppConfig, nowMs: number): boole * Wire motion + ding subscriptions for one camera. Returns the RxJS * subscriptions so the caller can tear them down on shutdown. */ -export function watchCamera(camera: RingCamera, cfg: AppConfig, recordFn: RecordFn = recordClip): Subscription[] { +export function watchCamera( + camera: RingCamera, + cfg: AppConfig, + recordFn: RecordFn = recordClip, + snapshotFn: SnapshotFn = defaultSnapshotFn, +): Subscription[] { const state: CameraState = { recording: false, lastStartMs: 0, motionActive: false }; const subs: Subscription[] = []; + // Capture the raw push so we get Ring's own detection timestamp and the + // detection-time snapshot uuid. onMotionDetected only carries a boolean, and + // the boolean is what triggers — so this runs as a parallel stream whose + // absence must never stop a recording. + if (typeof camera.onNewNotification?.subscribe === 'function') { + subs.push( + camera.onNewNotification.subscribe((n: PushNotificationDingV2) => { + state.lastDetection = parseNotification(n, Date.now()); + }), + ); + } + const trigger = (reason: string) => { const now = Date.now(); if (!shouldTrigger(state, cfg, now)) { @@ -50,11 +158,21 @@ export function watchCamera(camera: RingCamera, cfg: AppConfig, recordFn: Record state.recording = true; state.lastStartMs = now; log.info(`Trigger: ${reason} on "${camera.name}".`); + + const detection = pickDetection(state.lastDetection, now, DETECTION_MAX_AGE_MS); + // Fetch the detection snapshot in parallel with the recording, not after: + // it is the earliest view of the event and Ring expires these, so waiting + // out a 30s clip first risks losing the one frame showing the approach. + const snapshot = fetchDetectionSnapshot(camera, cfg, detection, snapshotFn); + // Wrap in Promise.resolve().then(...) so a *synchronous* throw in recordFn // still becomes a rejection (caught below) and can never leave state.recording // stuck at true, which would permanently block this camera. Promise.resolve() .then(() => recordFn(camera, cfg, cfg.clipLengthSeconds)) + .then(async (result) => { + await writeCaptureMetadata(cfg, result, detection, await snapshot, now); + }) .catch((err) => log.error(`Recording failed for "${camera.name}": ${(err as Error).message}`)) .finally(() => { state.recording = false; diff --git a/src/files.ts b/src/files.ts index 3d9071f..677257f 100644 --- a/src/files.ts +++ b/src/files.ts @@ -1,4 +1,4 @@ -import { mkdirSync, readdirSync, statSync, unlinkSync } from 'node:fs'; +import { appendFileSync, mkdirSync, readdirSync, statSync, unlinkSync } from 'node:fs'; import { join } from 'node:path'; import { log } from './log.js'; @@ -35,6 +35,23 @@ export function ensureDir(dir: string): string { return dir; } +/** + * Append one JSON object as a line to `file`. + * + * Returns false instead of throwing: this is diagnostic bookkeeping attached to + * a recording that already succeeded, so a full disk or a permissions problem + * must never turn a saved clip into a reported failure. + */ +export function appendJsonLine(file: string, record: unknown): boolean { + try { + appendFileSync(file, `${JSON.stringify(record)}\n`); + return true; + } catch (err) { + log.warn(`Could not append to ${file}: ${(err as Error).message}`); + return false; + } +} + /** * Delete .mp4 files in `dir` whose mtime is older than `retentionDays`. * Returns the list of deleted file paths. A null/0 retention is a no-op. diff --git a/src/recorder.ts b/src/recorder.ts index 9b75606..1cd42e6 100644 --- a/src/recorder.ts +++ b/src/recorder.ts @@ -4,6 +4,7 @@ import { firstValueFrom } from 'rxjs'; import type { RingCamera } from 'ring-client-api'; import type { AppConfig } from './config.js'; import { clipFilename, ensureDir } from './files.js'; +import type { CaptureTiming } from './detection.js'; import { log } from './log.js'; /** @@ -30,6 +31,30 @@ export interface RecordResult { path: string; bytes: number; seconds: number; + /** Timestamps for latency accounting (see src/detection.ts). */ + timing?: CaptureTiming; +} + +/** + * Watch `path` until it has a non-zero size, resolving the moment it does. + * + * This measures time-to-first-bytes, not strictly time-to-first-frame: the + * fragmented-MP4 header is flushed just ahead of the first media fragment. The + * two are within a frame interval of each other, which is far below the + * multi-second latency being measured, so the simpler poll is worth it. + * Returns a stop() the caller must always invoke, or the interval leaks. + */ +function watchForFirstBytes(path: string): { firstByteAtMs: () => number | undefined; stop: () => void } { + let at: number | undefined; + const timer = setInterval(() => { + if (at !== undefined) return; + try { + if (statSync(path).size > 0) at = Date.now(); + } catch { + // Not created yet — ENOENT is the normal case until ffmpeg opens it. + } + }, 25); + return { firstByteAtMs: () => at, stop: () => clearInterval(timer) }; } /** @@ -56,23 +81,33 @@ export async function recordClip( // call would otherwise hang forever, so cap the wait with a generous margin. const startTimeoutMs = 30_000; const hardTimeoutMs = (seconds + 30) * 1000; - // Cap the call setup too: streamVideo() performs WebRTC signaling that can hang - // on flaky networks or the unofficial API, and the onCallEnded timeout below - // only starts counting once the session object exists. - const session = await withTimeout( - camera.streamVideo({ output: clipOutputArgs(seconds, outPath) }), - startTimeoutMs, - `live stream for "${camera.name}" did not start within ${startTimeoutMs / 1000}s`, - ); + + const timing: CaptureTiming = { triggerAtMs: startedAt.getTime() }; + const firstBytes = watchForFirstBytes(outPath); + try { - await withTimeout( - firstValueFrom(session.onCallEnded), - hardTimeoutMs, - `live call for "${camera.name}" exceeded ${hardTimeoutMs / 1000}s`, + // Cap the call setup too: streamVideo() performs WebRTC signaling that can hang + // on flaky networks or the unofficial API, and the onCallEnded timeout below + // only starts counting once the session object exists. + const session = await withTimeout( + camera.streamVideo({ output: clipOutputArgs(seconds, outPath) }), + startTimeoutMs, + `live stream for "${camera.name}" did not start within ${startTimeoutMs / 1000}s`, ); - } catch (err) { - session.stop(); // ensure the WebRTC session + ffmpeg are torn down on timeout - throw err; + timing.streamOpenAtMs = Date.now(); + try { + await withTimeout( + firstValueFrom(session.onCallEnded), + hardTimeoutMs, + `live call for "${camera.name}" exceeded ${hardTimeoutMs / 1000}s`, + ); + } catch (err) { + session.stop(); // ensure the WebRTC session + ffmpeg are torn down on timeout + throw err; + } + } finally { + timing.firstFrameAtMs = firstBytes.firstByteAtMs(); + firstBytes.stop(); } let bytes = 0; @@ -89,7 +124,7 @@ export async function recordClip( } log.info(`Saved ${filename} (${(bytes / 1024 / 1024).toFixed(2)} MB)`); - return { camera: camera.name, path: outPath, bytes, seconds }; + return { camera: camera.name, path: outPath, bytes, seconds, timing }; } function withTimeout(p: Promise, ms: number, message: string): Promise { diff --git a/test/detection.test.mjs b/test/detection.test.mjs new file mode 100644 index 0000000..475e28f --- /dev/null +++ b/test/detection.test.mjs @@ -0,0 +1,279 @@ +// Hermetic tests for detection-context parsing, latency arithmetic and the +// snapshot/timing wiring. No Ring account or network required. +import { describe, test } from 'node:test'; +import assert from 'node:assert/strict'; +import { mkdtempSync, readFileSync, existsSync } from 'node:fs'; +import { tmpdir } from 'node:os'; +import { join } from 'node:path'; +import { + parseNotification, + pickDetection, + buildTimingRecord, + detectionSnapshotPath, +} from '../dist/detection.js'; +import { appendJsonLine } from '../dist/files.js'; +import { watchCamera } from '../dist/events.js'; + +const tick = () => new Promise((r) => setTimeout(r, 5)); + +const EVENT_AT = Date.parse('2026-07-29T18:59:54.000Z'); + +/** Minimal Ring motion push, shaped like PushNotificationDingV2. */ +const push = (over = {}) => ({ + analytics: { triggered_at: EVENT_AT, sent_at: EVENT_AT + 1_000 }, + data: { + event: { + ding: { id: 'ding-1', created_at: '2026-07-29T18:59:54.000Z', subtype: 'motion' }, + }, + }, + img: { snapshot_uuid: 'snap-uuid-1' }, + ...over, +}); + +describe('detection: parseNotification', () => { + test('lifts ding id, subtype, detection time and snapshot uuid', () => { + const d = parseNotification(push(), 1785351596454); + assert.equal(d.dingId, 'ding-1'); + assert.equal(d.subtype, 'motion'); + assert.equal(d.ringEventAtMs, Date.parse('2026-07-29T18:59:54.000Z')); + assert.equal(d.snapshotUuid, 'snap-uuid-1'); + assert.equal(d.receivedAtMs, 1785351596454); + }); + + test('falls back to analytics.triggered_at when created_at is absent', () => { + const n = push(); + delete n.data.event.ding.created_at; + assert.equal(parseNotification(n, 1).ringEventAtMs, EVENT_AT); + }); + + test('leaves detection time undefined when both sources are unusable', () => { + const n = push({ analytics: {} }); + n.data.event.ding.created_at = 'not-a-date'; + assert.equal(parseNotification(n, 1).ringEventAtMs, undefined); + }); + + test('tolerates a push with no img and no event payload', () => { + const d = parseNotification({}, 42); + assert.equal(d.snapshotUuid, undefined); + assert.equal(d.dingId, undefined); + assert.equal(d.receivedAtMs, 42, 'still records when we saw it'); + }); +}); + +describe('detection: pickDetection', () => { + const ctx = (receivedAtMs) => ({ receivedAtMs, snapshotUuid: 'u' }); + + test('accepts a notification from just before the trigger', () => { + assert.ok(pickDetection(ctx(1_000), 1_200, 15_000)); + }); + + test('rejects a stale notification rather than mispairing it', () => { + assert.equal(pickDetection(ctx(1_000), 1_000 + 20_000, 15_000), undefined); + }); + + test('rejects a notification timestamped after the trigger', () => { + assert.equal(pickDetection(ctx(5_000), 4_000, 15_000), undefined); + }); + + test('returns undefined when no notification was ever seen', () => { + assert.equal(pickDetection(undefined, 1, 15_000), undefined); + }); +}); + +describe('detection: buildTimingRecord', () => { + const base = { + cameraName: 'Front', + clipFile: 'Front_x.mp4', + snapshotFile: 'Front_x.detection.jpg', + detection: { dingId: 'd', subtype: 'motion', ringEventAtMs: 10_000, receivedAtMs: 12_270 }, + timing: { triggerAtMs: 12_300, streamOpenAtMs: 16_050, firstFrameAtMs: 18_500 }, + }; + + test('computes each latency segment and the total blind window', () => { + const r = buildTimingRecord(base); + assert.equal(r.pushDelaySec, 2.27, 'Ring detection -> push received'); + assert.equal(r.streamSetupSec, 3.75, 'trigger -> stream negotiated'); + assert.equal(r.firstFrameSec, 2.45, 'stream open -> first bytes'); + assert.equal(r.blindWindowSec, 8.5, 'Ring detection -> first bytes'); + }); + + test('serialises timestamps as ISO strings', () => { + const r = buildTimingRecord(base); + assert.equal(r.ringEventAt, new Date(10_000).toISOString()); + assert.equal(r.firstFrameAt, new Date(18_500).toISOString()); + }); + + test('nulls the segments it cannot compute instead of emitting NaN', () => { + const r = buildTimingRecord({ ...base, detection: undefined, timing: { triggerAtMs: 12_300 } }); + assert.equal(r.pushDelaySec, null); + assert.equal(r.blindWindowSec, null); + assert.equal(r.streamSetupSec, null); + assert.equal(r.ringEventAt, null); + assert.equal(r.triggerAt, new Date(12_300).toISOString(), 'trigger time is always known'); + }); + + test('records a null snapshot without dropping the timing row', () => { + const r = buildTimingRecord({ ...base, snapshotFile: null }); + assert.equal(r.detectionSnapshot, null); + assert.equal(r.blindWindowSec, 8.5); + }); +}); + +describe('detection: helpers', () => { + test('snapshot path is a sibling .detection.jpg', () => { + assert.equal(detectionSnapshotPath('/x/Front_ts.mp4'), '/x/Front_ts.detection.jpg'); + assert.equal(detectionSnapshotPath('/x/Front_ts.MP4'), '/x/Front_ts.detection.jpg'); + }); + + test('appendJsonLine writes one JSON line per call', () => { + const dir = mkdtempSync(join(tmpdir(), 'ring-jsonl-')); + const f = join(dir, 'timing.jsonl'); + assert.equal(appendJsonLine(f, { a: 1 }), true); + assert.equal(appendJsonLine(f, { a: 2 }), true); + const lines = readFileSync(f, 'utf8').trim().split('\n'); + assert.equal(lines.length, 2); + assert.deepEqual(JSON.parse(lines[1]), { a: 2 }); + }); + + test('appendJsonLine reports failure instead of throwing', () => { + // A path whose parent does not exist — must not throw, since the clip it + // describes has already been saved successfully. + assert.equal(appendJsonLine('/nonexistent-dir-xyz/timing.jsonl', { a: 1 }), false); + }); +}); + +describe('detection: watchCamera wiring', () => { + function obs() { + const subs = []; + return { + subscribe(fn) { + subs.push(fn); + return { unsubscribe() {} }; + }, + next(v) { + subs.forEach((f) => f(v)); + }, + }; + } + + const setup = (over = {}) => { + const dir = mkdtempSync(join(tmpdir(), 'ring-wire-')); + const camera = { + name: 'Front', + id: 1, + isDoorbot: false, + onMotionDetected: obs(), + onDoorbellPressed: obs(), + onNewNotification: obs(), + }; + const cfg = { + outputDir: dir, + clipLengthSeconds: 10, + recordOnMotion: true, + recordOnDing: true, + motionCooldownSeconds: 0, + detectionSnapshots: true, + timingLog: true, + ...over, + }; + const clipPath = join(dir, 'Front_x.mp4'); + // Timings must be anchored to the fixture push's detection time, or the + // computed blind window is meaningless. + const recordFn = async () => ({ + camera: 'Front', + path: clipPath, + bytes: 1, + seconds: 10, + timing: { + triggerAtMs: EVENT_AT + 2_270, + streamOpenAtMs: EVENT_AT + 6_020, + firstFrameAtMs: EVENT_AT + 8_500, + }, + }); + return { dir, camera, cfg, clipPath, recordFn }; + }; + + test('saves the detection snapshot and a timing row on a motion trigger', async () => { + const { dir, camera, cfg, recordFn } = setup(); + const asked = []; + const snapshotFn = async (_cam, uuid) => { + asked.push(uuid); + return Buffer.from('jpeg-bytes'); + }; + watchCamera(camera, cfg, recordFn, snapshotFn); + + camera.onNewNotification.next(push()); + camera.onMotionDetected.next(true); + await tick(); + + assert.deepEqual(asked, ['snap-uuid-1'], 'fetched the uuid from the push'); + assert.equal(readFileSync(join(dir, 'Front_x.detection.jpg'), 'utf8'), 'jpeg-bytes'); + + const row = JSON.parse(readFileSync(join(dir, 'timing.jsonl'), 'utf8').trim()); + assert.equal(row.detectionSnapshot, 'Front_x.detection.jpg'); + assert.equal(row.blindWindowSec, 8.5); + assert.equal(row.subtype, 'motion'); + }); + + test('still records when the push carried no snapshot uuid', async () => { + const { dir, camera, cfg, recordFn } = setup(); + let called = 0; + const snapshotFn = async () => { + called++; + return Buffer.from('x'); + }; + watchCamera(camera, cfg, recordFn, snapshotFn); + + camera.onNewNotification.next(push({ img: undefined })); + camera.onMotionDetected.next(true); + await tick(); + + assert.equal(called, 0, 'nothing to fetch'); + assert.ok(!existsSync(join(dir, 'Front_x.detection.jpg'))); + const row = JSON.parse(readFileSync(join(dir, 'timing.jsonl'), 'utf8').trim()); + assert.equal(row.detectionSnapshot, null, 'timing row still written'); + }); + + test('a failing snapshot fetch does not fail the recording', async () => { + const { dir, camera, cfg, recordFn } = setup(); + const snapshotFn = async () => { + throw new Error('uuid expired'); + }; + watchCamera(camera, cfg, recordFn, snapshotFn); + + camera.onNewNotification.next(push()); + camera.onMotionDetected.next(true); + await tick(); + + const row = JSON.parse(readFileSync(join(dir, 'timing.jsonl'), 'utf8').trim()); + assert.equal(row.detectionSnapshot, null); + assert.equal(row.blindWindowSec, 8.5, 'latency still recorded'); + }); + + test('detectionSnapshots=false skips the fetch entirely', async () => { + const { camera, cfg, recordFn } = setup({ detectionSnapshots: false }); + let called = 0; + watchCamera(camera, cfg, recordFn, async () => { + called++; + return Buffer.from('x'); + }); + + camera.onNewNotification.next(push()); + camera.onMotionDetected.next(true); + await tick(); + assert.equal(called, 0); + }); + + test('works when the camera exposes no notification stream', async () => { + const { dir, camera, cfg, recordFn } = setup(); + delete camera.onNewNotification; + watchCamera(camera, cfg, recordFn, async () => Buffer.from('x')); + + camera.onMotionDetected.next(true); + await tick(); + + const row = JSON.parse(readFileSync(join(dir, 'timing.jsonl'), 'utf8').trim()); + assert.equal(row.dingId, null, 'no detection context to attach'); + assert.equal(row.streamSetupSec, 3.75, 'our own timings are still recorded'); + }); +});