From bb39b69bdc43f562e61f9cd6fc9e9876a5c4426a Mon Sep 17 00:00:00 2001 From: Alex Sorafumo Date: Fri, 2 Oct 2026 13:12:33 +1000 Subject: [PATCH 1/2] fix(signage): keep display updates, cron and metrics reliable - Save ETag and Last-Modified only after a payload is applied, so a failed apply is fetched again. localStorage reads and writes are best effort, so a full store no longer blocks new content. - Cron searches step in UTC and match local fields. A repeated wall-clock time in the DST fall-back hour runs once. Searches are capped at 366 days. - Keep one schedule tick timer and clear it on destroy. - Record poll.last_success only when the backend answers. - Post metrics from a fresh object, catch errors and keep failed counts. - Prune completed schedule keys once their window has passed. - Do not release media that the cache sync already evicted. --- apps/signage/DEBUGGING.md | 2 +- apps/signage/USER_STORIES.md | 10 +- apps/signage/src/app/cron-helpers.ts | 78 +++-- apps/signage/src/app/signage.service.ts | 305 +++++++++++------- apps/signage/src/tests/cron-helpers.spec.ts | 87 +++++ .../signage/src/tests/signage.service.spec.ts | 220 +++++++++++++ 6 files changed, 558 insertions(+), 144 deletions(-) diff --git a/apps/signage/DEBUGGING.md b/apps/signage/DEBUGGING.md index 765caeeba02..ab7b748d3b4 100644 --- a/apps/signage/DEBUGGING.md +++ b/apps/signage/DEBUGGING.md @@ -80,7 +80,7 @@ makes the display request use `?preview=true`. | Takeover scheduled but not showing | A takeover with no valid media does not start. Compare the playlist and media `valid_from` / `valid_until` with `schedule.now` | | Trigger did not start a takeover | A trigger fires only when its value changes to true. A display update does not replay a trigger that is already true, and a trigger is ignored while another override plays | | Stuck on old content | `poll.last_success` and `poll.next_due`; run `signage.poll()` | -| Not picking up new content | `poll.last_success` vs now; if stale, look for `Display poll failed` in the console | +| Not picking up new content | `poll.last_success` is when the backend last answered; if stale, look for `Failed to fetch display details` or `Display poll failed` | | Media never appears | `media_cache.files` for that URL — `invalidated` means the download failed; `failed_sync_attempts` shows the backoff | | Old version running | `updates.new_version`, `updates.reload_pending` (a reload waits for the network and for play-through content to finish), `updates.last_check` | | Blank screen after a reboot | Likely offline boot — check `online`, then whether cached credentials exist | diff --git a/apps/signage/USER_STORIES.md b/apps/signage/USER_STORIES.md index 206c05ed9a2..1c81390136b 100644 --- a/apps/signage/USER_STORIES.md +++ b/apps/signage/USER_STORIES.md @@ -84,11 +84,12 @@ The Signage app is a kiosk-style digital signage player. It bootstraps a device - The app calls the PlaceOS signage endpoint for the active display ID. - Requests include preview context when debug mode is enabled and include the currently playing item ID when available. -- After a successful response, later requests send its `ETag` and `Last-Modified` values as `If-None-Match` and `If-Modified-Since`. +- After a response has been applied, later requests send its `ETag` and `Last-Modified` values as `If-None-Match` and `If-Modified-Since`. A response that fails to apply is requested again in full. - Display requests bypass the browser cache, and a `304 Not Modified` response keeps the current display configuration. - The latest display configuration is cached in localStorage under a display-specific `PlaceOS.SIGNAGE.display_details.` key. - Legacy cached configuration under `PlaceOS.SIGNAGE.display_details` can still be used as a fallback. - If the API request fails, the app falls back to the cached display configuration only when it matches the active display ID. +- A cached copy that cannot be read or saved does not stop the display configuration from loading. - Unchanged responses keep the current parsed display, trigger bindings, media cache, and playlist state. - Display configuration refreshes every 60 seconds. @@ -321,9 +322,10 @@ The Signage app is a kiosk-style digital signage player. It bootstraps a device **Acceptance Criteria:** - A scheduled playlist with `play_takeover` disabled is included in normal playback only while its schedule is active. -- `play_at` schedules support Unix timestamps in seconds or milliseconds. +- `play_at` schedules use a Unix timestamp in seconds. - `play_at_local` schedules play once at a wall-clock time (for example `2027-01-01T00:00:00`) in the display's timezone. -- `play_cron` schedules support recurring cron-based activation. +- `play_cron` schedules support recurring cron-based activation in the display's local time. +- When clocks go back, a repeated cron time runs once, at its first occurrence. A cron time skipped when clocks go forward does not run. - `play_period` controls the active window in minutes. - When `play_period` is missing, the default active window is 24 hours. - Schedule activation is re-evaluated every 15 seconds, or faster while debug time is accelerated. @@ -536,7 +538,7 @@ The Signage app is a kiosk-style digital signage player. It bootstraps a device - Empty metrics are not posted. - Non-empty metrics are posted to `/api/engine/v2/signage/:display_id/metrics`. - Metric posting is delayed by a random offset of up to 60 seconds to avoid synchronized device traffic. -- Metrics are cleared only after a successful post. +- Metrics recorded while a post is in flight are kept for the next post. - Failed posts leave metrics available for the next posting attempt. --- diff --git a/apps/signage/src/app/cron-helpers.ts b/apps/signage/src/app/cron-helpers.ts index b7513d2e9b1..dafca58badb 100644 --- a/apps/signage/src/app/cron-helpers.ts +++ b/apps/signage/src/app/cron-helpers.ts @@ -238,6 +238,35 @@ export function createScheduleMaskFilter(cron: string, schedule: ScheduleMask) { /** Search limit below which a lookup is too cheap and too precise to memoise */ const MIN_CACHEABLE_SEARCH_LIMIT_SECONDS = 60; +/** Longest search, so a lookup always ends whatever limit it is given */ +const MAX_SEARCH_LIMIT_SECONDS = 366 * 24 * 60 * 60; +const MINUTE_MS = 60_000; + +/** + * Whether `date` is the first time its local wall-clock minute occurs. When the + * clocks go back, the repeated hour only counts once, at its first occurrence, + * as in the signage manager and the schedule mask count. + */ +function isFirstLocalOccurrence(date: Date) { + const wall_clock = new Date( + date.getFullYear(), + date.getMonth(), + date.getDate(), + date.getHours(), + date.getMinutes(), + ); + return wall_clock.getTime() === date.getTime(); +} + +/** Whether a cron runs at `date`, a whole minute, in local time */ +function isCronRun(cron_parts: string[], date: Date) { + return doesCronMatchDate(cron_parts, date) && isFirstLocalOccurrence(date); +} + +/** Search limit in milliseconds, capped to `MAX_SEARCH_LIMIT_SECONDS` */ +function searchLimitMs(search_limit_in_seconds: number) { + return Math.min(search_limit_in_seconds, MAX_SEARCH_LIMIT_SECONDS) * 1000; +} const CRON_LOOKUP_CACHE = new Map(); let cron_lookup_second = 0; @@ -297,21 +326,17 @@ export function getNextCronRunTimestampInRange( const mask_key = JSON.stringify([schedule.valid_from, schedule.mask]); const key = `next|${cron_string}|${search_limit_in_seconds}|${mask_key}`; return cachedCronLookup(key, now, search_limit_in_seconds, () => { - const searchLimitDate = new Date(now + search_limit_in_seconds * 1000); - const start_time = new Date(now); - start_time.setSeconds(0, 0); - start_time.setMinutes(start_time.getMinutes() + 1); - - const current_date = new Date(start_time.getTime()); - - while (current_date <= searchLimitDate) { - if ( - doesCronMatchDate(parts, current_date) && - allows(current_date) - ) { - return Math.floor(current_date.getTime() / 1000); + // Steps in UTC, not local time: a local step resolves the hour that + // repeats when the clocks go back to its first occurrence, which + // would move the search an hour into the past. + const limit = now + searchLimitMs(search_limit_in_seconds); + const start = Math.floor(now / MINUTE_MS) * MINUTE_MS + MINUTE_MS; + const current_date = new Date(start); + for (let time = start; time <= limit; time += MINUTE_MS) { + current_date.setTime(time); + if (isCronRun(parts, current_date) && allows(current_date)) { + return Math.floor(time / 1000); } - current_date.setMinutes(current_date.getMinutes() + 1); } return null; }); @@ -345,23 +370,14 @@ export function getLastCronRunTimestampInRange( const mask_key = JSON.stringify([schedule.valid_from, schedule.mask]); const key = `last|${cron_string}|${search_limit_in_seconds}|${mask_key}`; return cachedCronLookup(key, now, search_limit_in_seconds, () => { - const search_limit_date = new Date( - now - search_limit_in_seconds * 1000, - ); - const current_date = new Date(now); - current_date.setSeconds(0, 0); - - while (current_date >= search_limit_date) { - if (doesCronMatchDate(parts, current_date)) { - return allows(current_date) - ? Math.floor(current_date.getTime() / 1000) - : null; - } - const previous = current_date.getTime(); - current_date.setMinutes(current_date.getMinutes() - 1); - // A missing local hour can normalise a backwards step forwards. - if (current_date.getTime() >= previous) { - current_date.setTime(previous - 60_000); + // Steps in UTC for the same reason as the forwards search. + const limit = now - searchLimitMs(search_limit_in_seconds); + const start = Math.floor(now / MINUTE_MS) * MINUTE_MS; + const current_date = new Date(start); + for (let time = start; time >= limit; time -= MINUTE_MS) { + current_date.setTime(time); + if (isCronRun(parts, current_date)) { + return allows(current_date) ? Math.floor(time / 1000) : null; } } return null; diff --git a/apps/signage/src/app/signage.service.ts b/apps/signage/src/app/signage.service.ts index 82c3f540c45..166bd0d9f8a 100644 --- a/apps/signage/src/app/signage.service.ts +++ b/apps/signage/src/app/signage.service.ts @@ -83,6 +83,24 @@ interface ActivePlaylistSchedule { key: string; } +/** Raw display details as the API returns them */ +interface DisplayPayload { + readonly id?: string; + readonly [key: string]: unknown; +} + +/** HTTP validators of a display response */ +interface DisplayValidators { + etag: string; + last_modified: string; +} + +interface DisplayFetch { + payload: DisplayPayload; + /** Validators of the response; null when the backend could not be reached */ + validators: DisplayValidators | null; +} + interface PlaylistMediaReference { id: string; playlist_id: string; @@ -90,11 +108,16 @@ interface PlaylistMediaReference { valid_until: number; } -const EMPTY_METRICS = JSON.stringify({ - play_through_counts: {}, - playlist_counts: {}, - media_counts: {}, -}); +function emptyMetrics(): SignageMetrics { + return { play_through_counts: {}, playlist_counts: {}, media_counts: {} }; +} + +const EMPTY_METRICS = JSON.stringify(emptyMetrics()); +const METRIC_TYPES: readonly (keyof SignageMetrics)[] = [ + 'play_through_counts', + 'playlist_counts', + 'media_counts', +]; const DEFAULT_PLAY_PERIOD_MINUTES = 24 * 60; const SINGLE_PASS_TRIGGER_WINDOW_MS = 30 * 1000; @@ -166,6 +189,10 @@ function isNestedPlayerWindow() { } } +function isDisplayPayload(value: unknown): value is DisplayPayload { + return !!value && typeof value === 'object'; +} + function displayCacheKey(id: string) { return `${DISPLAY_KEY}.${id}`; } @@ -256,13 +283,9 @@ function scheduledPlaylistExpiry(starts_at: number, period_minutes: number) { return period_minutes ? starts_at + period_minutes * 60 * 1000 : 0; } -function scheduledPlaylistWindow( - schedule: PlaylistSchedule, - now = time(), - trigger_window_seconds = 0, -) { +function scheduledPlaylistWindow(schedule: PlaylistSchedule, now = time()) { const period_minutes = playlistPlayPeriodMinutes(schedule); - const window_seconds = trigger_window_seconds || period_minutes * 60; + const window_seconds = period_minutes * 60; const valid_until = parseValidUntilTimestamp(schedule.valid_until); if (!hasPlayableScheduleMask(schedule)) return null; if (valid_until && now > valid_until) return null; @@ -429,8 +452,10 @@ export class SignageService extends AsyncHandler { private readonly _display_data = signal(null); /** Counter incremented on the schedule timer to re-evaluate time windows */ private readonly _tick = signal(0); + /** Pending schedule tick; see `_scheduleTick` */ + private _schedule_tick_timer?: ReturnType; private _display_signature = ''; - /** Validators from the last successful display response */ + /** Validators from the last display response that was applied */ private _etag = ''; private _last_modified = ''; /** Signature of the media set the cache was last synced against */ @@ -447,18 +472,14 @@ export class SignageService extends AsyncHandler { private _poll_in_flight = false; /** Wall-clock time the last poll attempt started */ private _last_poll_attempt = 0; - /** Wall-clock time the last poll completed without throwing */ + /** Wall-clock time the last poll got an answer from the backend */ private _last_poll_success = 0; /** Wall-clock time of the last recovery download, keyed by media URL */ private _media_recovery = new Map(); private _playlists: SignagePlaylist[] = []; private _last_playlist: MediaPlayerItem[] = []; private _last_override_playlists: string[] = []; - private _metrics: SignageMetrics = { - play_through_counts: {}, - playlist_counts: {}, - media_counts: {}, - }; + private _metrics = emptyMetrics(); private _completed_schedule_overrides = new Set(); /** Shuffled order of each random playlist and the media list it is for */ private _shuffles = new Map< @@ -574,6 +595,12 @@ export class SignageService extends AsyncHandler { this._scheduleTick(); } + protected override destroy() { + clearTimeout(this._schedule_tick_timer); + this._schedule_tick_timer = undefined; + super.destroy(); + } + private _startPolling() { this.interval('poll', () => this._poll(), POLL_INTERVAL_MS); } @@ -596,8 +623,8 @@ export class SignageService extends AsyncHandler { this._last_poll_attempt = now; recordHeartbeat('poll'); try { - await this._reloadDisplay(); - this._last_poll_success = Date.now(); + const reached_backend = await this._reloadDisplay(); + if (reached_backend) this._last_poll_success = Date.now(); } catch (e) { log.error('Display poll failed.', e); } finally { @@ -641,20 +668,26 @@ export class SignageService extends AsyncHandler { }); } - /** Re-fetch the active display details and refresh derived player state. */ + /** + * Re-fetch the active display details and refresh derived player state. + * Returns whether the backend answered. + */ private async _reloadDisplay() { const id = this._display(); - if (!id) return; - const value = await this._fetchDisplay(id); - if (value === null) return; - const display_signature = `${id}:${JSON.stringify(value || {})}`; + if (!id) return false; + const result = await this._fetchDisplay(id); + // Not modified since the last response that was applied + if (result === null) return true; + const { payload, validators } = result; + const display_signature = `${id}:${JSON.stringify(payload)}`; if ( display_signature === this._display_signature && this._display_data() ) { - return; + this._setValidators(validators); + return !!validators; } - const display = this._parseDisplay(value); + const display = this._parseDisplay(payload); display.plugins = await this._withTimeout( this._resolveDisplayPlugins(display), DISPLAY_FETCH_TIMEOUT_MS, @@ -678,10 +711,26 @@ export class SignageService extends AsyncHandler { // Recorded last. Marking the payload as handled before the work above // completes would make every later poll skip whatever did not finish, // leaving the display stuck until its configuration changed again. + // The validators too: sent early, they would get a 304 for the + // payload that failed, and it would never be applied. this._display_signature = display_signature; + this._setValidators(validators); + return !!validators; + } + + /** Keep the validators to send with the next request, if there are any */ + private _setValidators(validators: DisplayValidators | null) { + if (!validators) return; + this._etag = validators.etag; + this._last_modified = validators.last_modified; } - private async _fetchDisplay(id: string) { + /** + * Fetch the display details. Falls back to the copy saved for offline use + * when the backend cannot be reached. Returns null when the backend reports + * the details have not changed. + */ + private async _fetchDisplay(id: string): Promise { const query_params = cleanObject( { preview: this.debug() || undefined, @@ -701,34 +750,55 @@ export class SignageService extends AsyncHandler { // A request that never settles would otherwise leave the poll waiting // forever, so it is abandoned and retried on the next interval. - let d: any; + let payload: DisplayPayload | null = null; + let validators: DisplayValidators | null = null; try { - d = await this._withTimeout( + const response = await this._withTimeout( showSignage(id, query_params, request_options), DISPLAY_FETCH_TIMEOUT_MS, ); - const response_headers = responseHeaders( - displayRequestURL(id, query_params), - ); - this._etag = response_headers.etag || ''; - this._last_modified = response_headers['last-modified'] || ''; + if (isDisplayPayload(response)) { + payload = response; + const response_headers = responseHeaders( + displayRequestURL(id, query_params), + ); + validators = { + etag: response_headers.etag || '', + last_modified: response_headers['last-modified'] || '', + }; + } } catch (e) { if (e instanceof Response && e.status === 304) return null; log.warn('Failed to fetch display details.', e); } - if (!d) { - const display_key = displayCacheKey(id); - d = JSON.parse( - localStorage.getItem(display_key) || + if (!payload) payload = this._offlineDisplay(id); + if (payload.id === id) { + // Best effort: a full storage must not stop the display updating + try { + localStorage.setItem( + displayCacheKey(id), + JSON.stringify(payload), + ); + } catch (e) { + log.warn('Unable to save display details for offline use.', e); + } + } + return { payload, validators }; + } + + /** The display details saved for offline use; empty when there are none */ + private _offlineDisplay(id: string): DisplayPayload { + try { + const saved: unknown = JSON.parse( + localStorage.getItem(displayCacheKey(id)) || localStorage.getItem(DISPLAY_KEY) || - '{}', + 'null', ); - if (d.id !== id) d = {}; - } - if (d.id === id) { - localStorage.setItem(displayCacheKey(id), JSON.stringify(d)); + return isDisplayPayload(saved) && saved.id === id ? saved : {}; + } catch (e) { + log.warn('Unable to read saved display details.', e); + return {}; } - return d; } private _bindTriggers(display: any) { @@ -758,6 +828,12 @@ export class SignageService extends AsyncHandler { /** * Re-evaluate time-based schedules on a recurring timer, speeding up when * debug time is fast-forwarding so scheduled playlists activate on time. + * Calling it again replaces the pending tick, so there is only ever one + * timer chain. + * + * The timer is held here, not with `this.timeout`: that forgets a timer + * once its callback returns, which loses the timer the callback re-arms, + * so a later call could not replace it and would start a second chain. */ private _scheduleTick() { const { active, speed } = mockTimeState(); @@ -766,31 +842,28 @@ export class SignageService extends AsyncHandler { MIN_SCHEDULE_TICK_MS, Math.min(SCHEDULE_TICK_MS, SCHEDULE_TICK_MS / effective_speed), ); - this.timeout( - 'schedule_tick', - () => { - try { - recordHeartbeat('schedule'); - this._checkPollHealth(); - this._tick.update((_) => _ + 1); - const display = this._display_data(); - if (display) { - this._checkScheduledOverrides( - display, - this.override_playlists(), - ); - this._checkMediaCache(display); - } - } catch (e) { - log.error('Failed to evaluate playlist schedules.', e); - } finally { - // Always re-arm; a single bad pass must not stop the player - // evaluating schedules for the rest of its uptime. - this._scheduleTick(); + clearTimeout(this._schedule_tick_timer); + this._schedule_tick_timer = setTimeout(() => { + try { + recordHeartbeat('schedule'); + this._checkPollHealth(); + this._tick.update((_) => _ + 1); + const display = this._display_data(); + if (display) { + this._checkScheduledOverrides( + display, + this.override_playlists(), + ); + this._checkMediaCache(display); } - }, - delay, - ); + } catch (e) { + log.error('Failed to evaluate playlist schedules.', e); + } finally { + // Always re-arm; a single bad pass must not stop the player + // evaluating schedules for the rest of its uptime. + this._scheduleTick(); + } + }, delay); } /** Force an immediate display refresh. Exposed for diagnostics. */ @@ -943,24 +1016,34 @@ export class SignageService extends AsyncHandler { } private _postMetrics() { - this.timeout( - 'post-metrics', - async () => { - if (EMPTY_METRICS === JSON.stringify(this._metrics)) return; - const display_id = this._display(); - await post( - `/api/engine/v2/signage/${encodeURIComponent(display_id)}/metrics`, - this._metrics, - ); - log.debug('Posted metrics:', this._metrics); - this._metrics = { - play_through_counts: {}, - playlist_counts: {}, - media_counts: {}, - }; - }, - randomInt(60), - ); + this.timeout('post-metrics', () => this._sendMetrics(), randomInt(60)); + } + + /** + * Post the counts recorded so far. Counting continues into a new set while + * the post is in flight; if the post fails, its counts are added back so + * the next attempt sends them. + */ + private async _sendMetrics() { + if (EMPTY_METRICS === JSON.stringify(this._metrics)) return; + const metrics = this._metrics; + this._metrics = emptyMetrics(); + const display_id = this._display(); + try { + await post( + `/api/engine/v2/signage/${encodeURIComponent(display_id)}/metrics`, + metrics, + ); + log.debug('Posted metrics:', metrics); + } catch (e) { + log.warn('Failed to post metrics. Retrying later.', e); + for (const type of METRIC_TYPES) { + for (const [ref_id, count] of Object.entries(metrics[type])) { + this._metrics[type][ref_id] = + (this._metrics[type][ref_id] || 0) + count; + } + } + } } private _mappedPlaylistIds(display: any) { @@ -1048,16 +1131,16 @@ export class SignageService extends AsyncHandler { const cache_owner = display.id || ''; const media = this._activeCacheableMediaURLs(display); const known_media = this._cacheableMediaURLs(display); - const available_media = - this._media_cache.availableFiles(cache_owner); - const extra_media = available_media.filter( - (url) => !known_media.includes(url), - ); const has_failures = await this._media_cache.requestFilesToCache( media, cache_owner, { prune_other_owners: !this._isNestedPlayerWindow() }, ); + // Listed after caching, which can evict files: releasing a file + // that is already gone fails and only adds noise to the log. + const extra_media = this._media_cache + .availableFiles(cache_owner) + .filter((url) => !known_media.includes(url)); for (const item of extra_media) { Promise.resolve( this._media_cache.invalidateFile(item, cache_owner), @@ -1215,22 +1298,28 @@ export class SignageService extends AsyncHandler { */ private _activeOverrideSchedules(display: any, playlist_ids: string[]) { const now = time(); - return ( - playlist_ids - .map((id) => this._playlistConfig(display, id)?.[0]) - .filter((_) => !!_) - // Detect across each schedule's full play period (like `play_at` and - // the background playlist) so an in-progress cron takeover is picked - // up even if the display booted/ticked after it fired. Single-pass - // (period 0) schedules still resolve to a short ~30s window. - .flatMap((playlist) => - activePlaylistSchedules(playlist, now, 'takeover'), - ) - .filter( - ({ key, playlist }) => - !this._completed_schedule_overrides.has(key) && - this._hasValidTakeoverMedia(display, playlist.id), - ) + const active = playlist_ids + .map((id) => this._playlistConfig(display, id)?.[0]) + .filter((_) => !!_) + // Detect across each schedule's full play period (like `play_at` and + // the background playlist) so an in-progress cron takeover is picked + // up even if the display booted/ticked after it fired. Single-pass + // (period 0) schedules still resolve to a short ~30s window. + .flatMap((playlist) => + activePlaylistSchedules(playlist, now, 'takeover'), + ); + // A key names one run, which is never active again once its window + // has passed, so completed runs are only remembered while active. + const active_keys = new Set(active.map(({ key }) => key)); + for (const key of this._completed_schedule_overrides) { + if (!active_keys.has(key)) { + this._completed_schedule_overrides.delete(key); + } + } + return active.filter( + ({ key, playlist }) => + !this._completed_schedule_overrides.has(key) && + this._hasValidTakeoverMedia(display, playlist.id), ); } diff --git a/apps/signage/src/tests/cron-helpers.spec.ts b/apps/signage/src/tests/cron-helpers.spec.ts index 2acf4bd4827..8c031778066 100644 --- a/apps/signage/src/tests/cron-helpers.spec.ts +++ b/apps/signage/src/tests/cron-helpers.spec.ts @@ -336,3 +336,90 @@ describe('schedule masking', () => { ).toBeNull(); }); }); + +describe('cron runs across daylight saving changes', () => { + const original_timezone = process.env.TZ; + const at = (iso: string) => Date.parse(iso); + const unix = (iso: string) => Date.parse(iso) / 1000; + + afterEach(() => { + if (original_timezone === undefined) delete process.env.TZ; + else process.env.TZ = original_timezone; + }); + + describe('in New York', () => { + // Clocks go back from 02:00 EDT to 01:00 EST on 1 November 2026, so + // 01:00 to 01:59 happens twice: 05:00Z to 05:59Z, then 06:00Z to 06:59Z. + beforeEach(() => (process.env.TZ = 'America/New_York')); + + it('finds a run from the first 1 am while in the repeated hour', () => { + expect( + getLastCronRunTimestampInRange( + '45 1 * * *', + 60 * 60, + at('2026-11-01T06:30:00Z'), + ), + ).toBe(unix('2026-11-01T05:45:00Z')); + }); + + it('never looks for the next run in the past during the repeated hour', () => { + expect( + getNextCronRunTimestampInRange( + '*/15 * * * *', + 60 * 60, + at('2026-11-01T06:10:00Z'), + ), + ).toBe(unix('2026-11-01T07:00:00Z')); + }); + + it('runs a repeated wall-clock time once', () => { + expect( + getNextCronRunTimestampInRange( + '30 1 * * *', + 4 * 60 * 60, + at('2026-11-01T04:00:00Z'), + ), + ).toBe(unix('2026-11-01T05:30:00Z')); + expect( + getLastCronRunTimestampInRange( + '30 1 * * *', + 30, + at('2026-11-01T06:30:10Z'), + ), + ).toBeNull(); + }); + }); + + describe('in Sydney', () => { + // Clocks go back from 03:00 AEDT to 02:00 AEST on 5 April 2026, and + // forward from 02:00 AEST to 03:00 AEDT on 4 October 2026. + beforeEach(() => (process.env.TZ = 'Australia/Sydney')); + + it('finds a run from the first 2 am while in the repeated hour', () => { + expect( + getLastCronRunTimestampInRange( + '45 2 * * *', + 60 * 60, + at('2026-04-04T16:30:00Z'), + ), + ).toBe(unix('2026-04-04T15:45:00Z')); + }); + + it('skips a run in the hour the clocks go forward over', () => { + expect( + getNextCronRunTimestampInRange( + '30 2 * * *', + 2 * 60 * 60, + at('2026-10-03T15:50:00Z'), + ), + ).toBeNull(); + expect( + getLastCronRunTimestampInRange( + '0 1 * * *', + 3 * 60 * 60, + at('2026-10-03T17:05:00Z'), + ), + ).toBe(unix('2026-10-03T15:00:00Z')); + }); + }); +}); diff --git a/apps/signage/src/tests/signage.service.spec.ts b/apps/signage/src/tests/signage.service.spec.ts index 453b1498f1f..df43bb8d892 100644 --- a/apps/signage/src/tests/signage.service.spec.ts +++ b/apps/signage/src/tests/signage.service.spec.ts @@ -2683,4 +2683,224 @@ describe('SignageService', () => { play_through_counts: {}, }); }); + + it('should keep metrics recorded while a post is in flight', async () => { + let finishPost = () => undefined as void; + (ts_client.post as any).mockClear(); + (ts_client.post as any).mockReturnValue( + new Promise((resolve) => (finishPost = resolve)), + ); + spectator.service.setDisplay('display-1'); + await spectator.service.storeMetricEvent({ + type: 'media_count', + ref_id: 'media-1', + }); + (spectator.service as any)._postMetrics(); + vi.advanceTimersByTime(60); + expect(ts_client.post).toHaveBeenCalledTimes(1); + + await spectator.service.storeMetricEvent({ + type: 'media_count', + ref_id: 'media-2', + }); + finishPost(); + await flush(); + + expect((spectator.service as any)._metrics.media_counts).toEqual({ + 'media-2': 1, + }); + }); + + it('should keep metrics that fail to post for the next attempt', async () => { + (ts_client.post as any).mockReturnValueOnce( + Promise.reject(new Error('backend unavailable')), + ); + spectator.service.setDisplay('display-1'); + await spectator.service.storeMetricEvent({ + type: 'media_count', + ref_id: 'media-1', + }); + (spectator.service as any)._postMetrics(); + vi.advanceTimersByTime(60); + await flush(); + await spectator.service.storeMetricEvent({ + type: 'media_count', + ref_id: 'media-1', + }); + + (spectator.service as any)._postMetrics(); + vi.advanceTimersByTime(60); + await flush(); + + expect(ts_client.post).toHaveBeenLastCalledWith( + '/api/engine/v2/signage/display-1/metrics', + { + media_counts: { 'media-1': 2 }, + playlist_counts: {}, + play_through_counts: {}, + }, + ); + }); + + it('should not keep the validators of a display that failed to apply', async () => { + (ts_client.responseHeaders as any).mockReturnValue({ + etag: '"display-v1"', + }); + vi.spyOn( + spectator.service as any, + '_checkScheduledOverrides', + ).mockImplementationOnce(() => { + throw new Error('schedule evaluation failed'); + }); + spectator.service.setDisplay('display-1'); + await flush(); + + // A conditional request here would get a 304 for the payload that + // failed, and it would never be applied. + await (spectator.service as any)._reloadDisplay(); + expect(ts_client.showSignage).toHaveBeenLastCalledWith( + 'display-1', + {}, + { headers: {}, cache: 'no-store' }, + ); + + await (spectator.service as any)._reloadDisplay(); + expect(ts_client.showSignage).toHaveBeenLastCalledWith( + 'display-1', + {}, + { + headers: { 'If-None-Match': '"display-v1"' }, + cache: 'no-store', + }, + ); + }); + + it('should apply the display when it cannot be saved for offline use', async () => { + vi.spyOn( + Object.getPrototypeOf(localStorage), + 'setItem', + ).mockImplementation(() => { + throw new DOMException('Storage is full', 'QuotaExceededError'); + }); + + spectator.service.setDisplay('display-1'); + await flush(); + + expect(spectator.service.display()?.id).toBe('display-1'); + }); + + it('should ignore a saved display that cannot be read', async () => { + localStorage.setItem( + 'PlaceOS.SIGNAGE.display_details.display-1', + '{not json', + ); + (ts_client.showSignage as any).mockImplementation(() => + Promise.reject(new Error('backend unavailable')), + ); + + spectator.service.setDisplay('display-1'); + await flush(); + + expect(spectator.service.display()).toEqual( + expect.objectContaining({ playlist_media: [], plugins: [] }), + ); + }); + + it('should only record a poll success when the backend answers', async () => { + (ts_client.showSignage as any).mockImplementationOnce(() => + Promise.reject(new Error('backend unavailable')), + ); + localStorage.setItem( + 'PlaceOS.SIGNAGE.display_details.display-1', + JSON.stringify(create_display()), + ); + spectator.service.setDisplay('display-1'); + await flush(); + + expect(spectator.service.display()?.id).toBe('display-1'); + expect(spectator.service.diagnostics().poll.last_success).toBe('never'); + + await spectator.service.refresh(); + + expect(spectator.service.diagnostics().poll.last_success).not.toBe( + 'never', + ); + }); + + it('should keep one schedule timer however often the display is set', async () => { + spectator.service.setDisplay('display-1'); + await flush(); + vi.advanceTimersByTime(15_000); + await flush(); + spectator.service.setDisplay('display-1'); + spectator.service.setDisplay('display-1'); + const tick = vi.spyOn(spectator.service as any, '_checkPollHealth'); + + vi.advanceTimersByTime(15_000); + expect(tick).toHaveBeenCalledTimes(1); + + spectator.service.ngOnDestroy(); + vi.advanceTimersByTime(60_000); + expect(tick).toHaveBeenCalledTimes(1); + }); + + it('should forget a completed takeover run once its window has passed', async () => { + const now = new Date('2026-01-01T10:00:00Z').getTime(); + vi.setSystemTime(now); + (ts_client.showSignage as any).mockReturnValue( + Promise.resolve( + create_display({ + playlist_config: { + ...create_display().playlist_config, + 'scheduled-playlist': [ + { + id: 'scheduled-playlist', + name: 'Scheduled Playlist', + enabled: true, + default_animation: MediaAnimation.Cut, + default_duration: 10000, + schedules: [ + { + play_at: Math.floor(now / 1000), + play_cron: '', + play_period: 0, + play_takeover: true, + }, + ], + }, + ['media-3'], + ], + }, + }) as any, + ), + ); + spectator.service.setDisplay('display-1'); + await flush(); + spectator.service.clearPlaylistOverride(); + const completed: Set = (spectator.service as any) + ._completed_schedule_overrides; + + vi.advanceTimersByTime(15_000); + await flush(); + expect(completed.size).toBe(1); + + vi.advanceTimersByTime(30_000); + await flush(); + expect(completed.size).toBe(0); + expect(spectator.service.override_playlist().playlist).toHaveLength(0); + }); + + it('should not release media the cache has already evicted', async () => { + let cached = ['/stale-file.jpg']; + media_cache.availableFiles.mockImplementation(() => cached); + media_cache.requestFilesToCache.mockImplementation(() => { + cached = []; + return Promise.resolve(false); + }); + + spectator.service.setDisplay('display-1'); + await flush(); + + expect(media_cache.invalidateFile).not.toHaveBeenCalled(); + }); }); From 209e80469607dfb2fbd023935ce1ae6249971362 Mon Sep 17 00:00:00 2001 From: Alex Sorafumo Date: Fri, 2 Oct 2026 13:25:30 +1000 Subject: [PATCH 2/2] fix(signage): find long cron runs and keep completed takeovers done - Cron searches cover the requested period, capped at 10 years, so a run longer than a year is still found. They skip local days the cron cannot match, so a long search costs one check per day. - Completed takeover runs are remembered until their window ends, not only while active. A playlist that briefly leaves the display no longer replays a finished takeover. --- apps/signage/src/app/cron-helpers.ts | 57 +++++++++++++++-- apps/signage/src/app/signage.service.ts | 63 ++++++++++++------- apps/signage/src/tests/cron-helpers.spec.ts | 12 ++++ .../signage/src/tests/signage.service.spec.ts | 48 +++++++++++++- 4 files changed, 152 insertions(+), 28 deletions(-) diff --git a/apps/signage/src/app/cron-helpers.ts b/apps/signage/src/app/cron-helpers.ts index dafca58badb..2e85c8ff3ed 100644 --- a/apps/signage/src/app/cron-helpers.ts +++ b/apps/signage/src/app/cron-helpers.ts @@ -163,7 +163,7 @@ export function createScheduleMaskFilter(cron: string, schedule: ScheduleMask) { slots.push(hour * 60 + minute); } } - const calendar_parts = ['*', '*', ...parts.slice(2)]; + const calendar_parts = cronDayParts(parts); const first_day = new Date(anchor); first_day.setHours(0, 0, 0, 0); const month_totals = new Map(); @@ -238,8 +238,14 @@ export function createScheduleMaskFilter(cron: string, schedule: ScheduleMask) { /** Search limit below which a lookup is too cheap and too precise to memoise */ const MIN_CACHEABLE_SEARCH_LIMIT_SECONDS = 60; -/** Longest search, so a lookup always ends whatever limit it is given */ -const MAX_SEARCH_LIMIT_SECONDS = 366 * 24 * 60 * 60; +/** + * Longest search, so a lookup always ends whatever limit it is given. A search + * as long as a play period must find the run that started it, and the manager + * sets no upper limit on play periods, so this is ten years: far above any + * real period. Days the cron cannot match are skipped whole, so a search costs + * at most about 3,700 day checks plus the minutes of the days it does match. + */ +const MAX_SEARCH_LIMIT_SECONDS = 10 * 366 * 24 * 60 * 60; const MINUTE_MS = 60_000; /** @@ -263,6 +269,31 @@ function isCronRun(cron_parts: string[], date: Date) { return doesCronMatchDate(cron_parts, date) && isFirstLocalOccurrence(date); } +/** Whether a cron can run at some time of day; `61 * * * *` never can */ +function hasCronTimeOfDay([minute_part, hour_part]: string[]) { + for (let hour = 0; hour < 24; hour++) { + if (!matchesCronPart(hour, hour_part)) continue; + for (let minute = 0; minute < 60; minute++) { + if (matchesCronPart(minute, minute_part)) return true; + } + } + return false; +} + +/** Cron fields that match any time on the days the cron runs */ +function cronDayParts(cron_parts: string[]) { + return ['*', '*', ...cron_parts.slice(2)]; +} + +/** Start of the local day `offset_days` from the day of `date` */ +function localDayStart(date: Date, offset_days = 0) { + return new Date( + date.getFullYear(), + date.getMonth(), + date.getDate() + offset_days, + ).getTime(); +} + /** Search limit in milliseconds, capped to `MAX_SEARCH_LIMIT_SECONDS` */ function searchLimitMs(search_limit_in_seconds: number) { return Math.min(search_limit_in_seconds, MAX_SEARCH_LIMIT_SECONDS) * 1000; @@ -329,14 +360,22 @@ export function getNextCronRunTimestampInRange( // Steps in UTC, not local time: a local step resolves the hour that // repeats when the clocks go back to its first occurrence, which // would move the search an hour into the past. + if (!hasCronTimeOfDay(parts)) return null; + const day_parts = cronDayParts(parts); const limit = now + searchLimitMs(search_limit_in_seconds); const start = Math.floor(now / MINUTE_MS) * MINUTE_MS + MINUTE_MS; const current_date = new Date(start); - for (let time = start; time <= limit; time += MINUTE_MS) { + // Every step moves forwards, by a minute or to the next day + for (let time = start; time <= limit; ) { current_date.setTime(time); + if (!doesCronMatchDate(day_parts, current_date)) { + time = localDayStart(current_date, 1); + continue; + } if (isCronRun(parts, current_date) && allows(current_date)) { return Math.floor(time / 1000); } + time += MINUTE_MS; } return null; }); @@ -371,14 +410,22 @@ export function getLastCronRunTimestampInRange( const key = `last|${cron_string}|${search_limit_in_seconds}|${mask_key}`; return cachedCronLookup(key, now, search_limit_in_seconds, () => { // Steps in UTC for the same reason as the forwards search. + if (!hasCronTimeOfDay(parts)) return null; + const day_parts = cronDayParts(parts); const limit = now - searchLimitMs(search_limit_in_seconds); const start = Math.floor(now / MINUTE_MS) * MINUTE_MS; const current_date = new Date(start); - for (let time = start; time >= limit; time -= MINUTE_MS) { + // Every step moves backwards, by a minute or to the day before + for (let time = start; time >= limit; ) { current_date.setTime(time); + if (!doesCronMatchDate(day_parts, current_date)) { + time = localDayStart(current_date) - MINUTE_MS; + continue; + } if (isCronRun(parts, current_date)) { return allows(current_date) ? Math.floor(time / 1000) : null; } + time -= MINUTE_MS; } return null; }); diff --git a/apps/signage/src/app/signage.service.ts b/apps/signage/src/app/signage.service.ts index 166bd0d9f8a..a62ea8156a5 100644 --- a/apps/signage/src/app/signage.service.ts +++ b/apps/signage/src/app/signage.service.ts @@ -46,6 +46,8 @@ interface PlaylistOverride { ends_at: number; playlist: MediaPlayerItem[]; schedule_keys?: string[]; + /** When the last of its scheduled runs stops being detected as active */ + schedule_window_end?: number; } interface SignageMetrics { @@ -480,7 +482,8 @@ export class SignageService extends AsyncHandler { private _last_playlist: MediaPlayerItem[] = []; private _last_override_playlists: string[] = []; private _metrics = emptyMetrics(); - private _completed_schedule_overrides = new Set(); + /** Scheduled runs that have played, with when each can be forgotten */ + private _completed_schedule_overrides = new Map(); /** Shuffled order of each random playlist and the media list it is for */ private _shuffles = new Map< string, @@ -985,9 +988,15 @@ export class SignageService extends AsyncHandler { } public clearPlaylistOverride() { - const { schedule_keys } = this.override_playlist(); + const { schedule_keys, schedule_window_end } = this.override_playlist(); + // Remembered until the run can no longer be detected, so it does not + // play again. Scheduled overrides always record that time; the default + // play period is only a fallback. + const forget_after = + schedule_window_end || + time() + DEFAULT_PLAY_PERIOD_MINUTES * MINUTES; for (const key of schedule_keys || []) { - this._completed_schedule_overrides.add(key); + this._completed_schedule_overrides.set(key, forget_after); } this.override_playlist.set({ playlist: [], ends_at: 0 }); } @@ -1283,11 +1292,19 @@ export class SignageService extends AsyncHandler { const ends_at = has_single_pass ? 0 : Math.max(...active.map(({ ends_at }) => ends_at)); + // Held runs come from the current override, so its window end is kept + const schedule_window_end = Math.max( + this.override_playlist().schedule_window_end || 0, + ...(has_single_pass ? single_pass : active).map( + ({ ends_at }) => ends_at, + ), + ); log.debug('Setting override playlist', media, ends_at); this.override_playlist.set({ playlist: media, ends_at, schedule_keys: keys, + schedule_window_end, }); } @@ -1298,28 +1315,30 @@ export class SignageService extends AsyncHandler { */ private _activeOverrideSchedules(display: any, playlist_ids: string[]) { const now = time(); - const active = playlist_ids - .map((id) => this._playlistConfig(display, id)?.[0]) - .filter((_) => !!_) - // Detect across each schedule's full play period (like `play_at` and - // the background playlist) so an in-progress cron takeover is picked - // up even if the display booted/ticked after it fired. Single-pass - // (period 0) schedules still resolve to a short ~30s window. - .flatMap((playlist) => - activePlaylistSchedules(playlist, now, 'takeover'), - ); - // A key names one run, which is never active again once its window - // has passed, so completed runs are only remembered while active. - const active_keys = new Set(active.map(({ key }) => key)); - for (const key of this._completed_schedule_overrides) { - if (!active_keys.has(key)) { + // A key names one run, which is never detected again once its window + // has passed. Until then it is kept, even while its playlist is + // missing from the display, so that restoring it does not replay it. + for (const [key, forget_after] of this._completed_schedule_overrides) { + if (forget_after < now) { this._completed_schedule_overrides.delete(key); } } - return active.filter( - ({ key, playlist }) => - !this._completed_schedule_overrides.has(key) && - this._hasValidTakeoverMedia(display, playlist.id), + return ( + playlist_ids + .map((id) => this._playlistConfig(display, id)?.[0]) + .filter((_) => !!_) + // Detect across each schedule's full play period (like `play_at` and + // the background playlist) so an in-progress cron takeover is picked + // up even if the display booted/ticked after it fired. Single-pass + // (period 0) schedules still resolve to a short ~30s window. + .flatMap((playlist) => + activePlaylistSchedules(playlist, now, 'takeover'), + ) + .filter( + ({ key, playlist }) => + !this._completed_schedule_overrides.has(key) && + this._hasValidTakeoverMedia(display, playlist.id), + ) ); } diff --git a/apps/signage/src/tests/cron-helpers.spec.ts b/apps/signage/src/tests/cron-helpers.spec.ts index 8c031778066..5eb02a41526 100644 --- a/apps/signage/src/tests/cron-helpers.spec.ts +++ b/apps/signage/src/tests/cron-helpers.spec.ts @@ -206,6 +206,18 @@ describe('cron helpers', () => { ).toBeNull(); }); + it('finds a run that started more than a year ago', () => { + // A 29 February run with a 368 day play period is still active on + // 2 March of the next year. + const result = getLastCronRunTimestampInRange( + '0 0 29 2 *', + 368 * 24 * 60 * 60, + localDate(2025, 3, 2, 12, 0).getTime(), + ); + + expectLocalDate(result, localDate(2024, 2, 29, 0, 0)); + }); + it('rejects last-run cron strings that are not five fields', () => { expect(() => getLastCronRunTimestampInRange( diff --git a/apps/signage/src/tests/signage.service.spec.ts b/apps/signage/src/tests/signage.service.spec.ts index df43bb8d892..537a0e63a58 100644 --- a/apps/signage/src/tests/signage.service.spec.ts +++ b/apps/signage/src/tests/signage.service.spec.ts @@ -2877,7 +2877,7 @@ describe('SignageService', () => { spectator.service.setDisplay('display-1'); await flush(); spectator.service.clearPlaylistOverride(); - const completed: Set = (spectator.service as any) + const completed: Map = (spectator.service as any) ._completed_schedule_overrides; vi.advanceTimersByTime(15_000); @@ -2890,6 +2890,52 @@ describe('SignageService', () => { expect(spectator.service.override_playlist().playlist).toHaveLength(0); }); + it('should not replay a completed takeover when its playlist briefly leaves the display', async () => { + const now = new Date('2026-01-01T10:00:00Z').getTime(); + vi.setSystemTime(now); + const display = create_display({ + playlist_config: { + ...create_display().playlist_config, + 'scheduled-playlist': [ + { + id: 'scheduled-playlist', + name: 'Scheduled Playlist', + enabled: true, + default_animation: MediaAnimation.Cut, + default_duration: 10000, + schedules: [ + { + play_at: Math.floor(now / 1000), + play_cron: '', + play_period: 0, + play_takeover: true, + }, + ], + }, + ['media-3'], + ], + }, + }); + (ts_client.showSignage as any).mockReturnValue( + Promise.resolve(display), + ); + spectator.service.setDisplay('display-1'); + await flush(); + spectator.service.clearPlaylistOverride(); + + (ts_client.showSignage as any).mockReturnValueOnce( + Promise.resolve({ + ...display, + playlist_mappings: { 'display-1': ['base-playlist'] }, + }), + ); + await (spectator.service as any)._reloadDisplay(); + vi.setSystemTime(now + 10_000); + await (spectator.service as any)._reloadDisplay(); + + expect(spectator.service.override_playlist().playlist).toHaveLength(0); + }); + it('should not release media the cache has already evicted', async () => { let cached = ['/stale-file.jpg']; media_cache.availableFiles.mockImplementation(() => cached);