refactor(report): reduce footprint and take writes off the cue path

Cuts the risk surface of the run history feature while keeping what it
delivers.

Stability:
- Sidecar writes were happening on every event stop, and each write
  serialised the project's entire history. That put work proportional to
  everything that ever ran onto the show critical path, growing without
  bound. Writes during a run are now coalesced, with immediate writes for
  anything a user did and a flush on finish, project change and shutdown.
- The editor no longer carries any of this feature's code. The per event
  last run chip is gone, so RundownEventChip, RundownEventInner and
  useProjectRundowns are back to their previous state. Each rundown row
  had gained two extra query subscriptions, one of them polling.
- closeRun is no longer called from runtime.service, so the timer path is
  untouched. Ending a run is now explicit, which also means a mid show
  stop and restart no longer splits one show across two runs.

Discovery:
- A run indicator in the editor overview appears only while a run is
  being recorded. It shows when recording started and carries the Finish
  action, then links to the report. One component with one subscription,
  rather than anything per row.

Smaller:
- report.parser drops from exhaustive validation of a file we write
  ourselves to a shallow shape check; the failure mode is unchanged.
- getCombinedReport returns to its original shape, keeping only the
  snapshot read that report accuracy depends on.
- Removes getLatestRun and GET /runs/latest, which only existed for the
  chip, and hand rolled refetches the api layer already covers.

Production diff is down from ~1460 to ~1290 lines, and the four floating
promises the previous revision introduced are gone.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_019nr3FbLbM8gB8Jm771YgTV
This commit is contained in:
Claude
2026-08-08 21:25:03 +00:00
parent 8551c161f1
commit faca1a1c76
22 changed files with 474 additions and 438 deletions
@@ -7,6 +7,8 @@ import { makeRuntimeStateData } from '../../../stores/__mocks__/runtimeState.moc
// in-memory stand-in for the sidecar store, verified separately in report.store.test.ts
let runs: ShowRun[] = [];
/** write options seen by the store, so we can assert what reaches the disk and when */
let writeOptions: ({ debounce?: boolean } | undefined)[] = [];
vi.mock('../../../services/report-service/report.store.js', () => ({
// isolation between tests comes from the top-level beforeEach resetting `runs`,
@@ -14,7 +16,8 @@ vi.mock('../../../services/report-service/report.store.js', () => ({
loadReports: vi.fn(async () => ({ runs })),
getRuns: vi.fn(() => runs),
getRun: vi.fn((id: string) => runs.find((run) => run.id === id)),
upsertRun: vi.fn(async (run: ShowRun) => {
upsertRun: vi.fn(async (run: ShowRun, options?: { debounce?: boolean }) => {
writeOptions.push(options);
const index = runs.findIndex((candidate) => candidate.id === run.id);
if (index === -1) {
runs.unshift(run);
@@ -74,7 +77,6 @@ const {
initReports,
listRuns,
getRun,
getLatestRun,
renameRun,
deleteRun,
deleteAllRuns,
@@ -85,6 +87,7 @@ const eventB = makeOntimeEvent({ id: 'event-b', timeStart: 10000, timeEnd: 20000
beforeEach(async () => {
runs = [];
writeOptions = [];
currentRundown = makeRundown({
id: 'rundown-1',
title: 'Test rundown',
@@ -166,6 +169,48 @@ describe('triggerReportEntry()', () => {
});
});
describe('write pressure on the show critical path', () => {
function runEvent(clock: number) {
const state = makeRuntimeStateData({ eventNow: eventA, timer: { startedAt: 0 }, clock, _startEpoch: showEpoch });
triggerReportEntry(TimerLifeCycle.onStart, state);
triggerReportEntry(TimerLifeCycle.onStop, { ...state, clock: clock + 1000 } as typeof state);
}
it('coalesces writes while a run is in progress', async () => {
// the sidecar holds the whole project history, so writing per event would
// put work proportional to everything that ever ran onto the cue path
runEvent(0);
runEvent(2000);
runEvent(4000);
await new Promise((resolve) => setImmediate(resolve));
expect(writeOptions.length).toBeGreaterThan(0);
expect(writeOptions.every((options) => options?.debounce === true)).toBe(true);
});
it('writes immediately when the run is finished', async () => {
runEvent(0);
await new Promise((resolve) => setImmediate(resolve));
writeOptions = [];
await closeRun();
expect(writeOptions).toHaveLength(1);
expect(writeOptions[0]?.debounce).toBeFalsy();
});
it('writes immediately when a user renames a run', async () => {
runEvent(0);
await closeRun();
const runId = listRuns()[0].id;
writeOptions = [];
await renameRun(runId, 'Dress rehearsal');
expect(writeOptions[0]?.debounce).toBeFalsy();
});
});
describe('run timestamps', () => {
it('dates a run with the wall clock epoch, not the time of day', async () => {
// clock/actualStart are millis since midnight, which cannot date a run.
@@ -198,19 +243,19 @@ describe('run timestamps', () => {
expect(run.startedAt).toBeLessThanOrEqual(Date.now());
});
it('orders runs from different days correctly', async () => {
// a run at 09:30 today must rank above one at 20:00 yesterday, which
// time-of-day ordering would get backwards
it('dates runs from different days apart', async () => {
// the times of day here disagree with chronological order: 20:00 yesterday
// is a larger time of day than 09:30 today
const yesterdayEvening = Date.UTC(2026, 7, 7, 20, 0);
await makeClosedRunAt('older', yesterdayEvening);
await makeClosedRunAt('newer', showEpoch);
await makeClosedRunAt(yesterdayEvening);
const older = listRuns()[0].startedAt;
await makeClosedRunAt(showEpoch);
const newer = listRuns()[0].startedAt;
expect(getLatestRun()?.id).toBe('newer');
expect(newer).toBeGreaterThan(older);
});
async function makeClosedRunAt(id: string, epoch: number) {
// the time of day deliberately disagrees with chronological order here:
// 20:00 yesterday is a larger time of day than 09:30 today
async function makeClosedRunAt(epoch: number) {
const timeOfDay = epoch % 86400000;
const state = makeRuntimeStateData({
eventNow: eventA,
@@ -221,9 +266,7 @@ describe('run timestamps', () => {
});
triggerReportEntry(TimerLifeCycle.onStart, state);
triggerReportEntry(TimerLifeCycle.onStop, { ...state, clock: timeOfDay + 10000 } as typeof state);
closeRun();
await new Promise((resolve) => setImmediate(resolve));
runs[0] = { ...runs[0], id };
await closeRun();
}
});
@@ -233,7 +276,7 @@ describe('closeRun()', () => {
triggerReportEntry(TimerLifeCycle.onStart, start);
triggerReportEntry(TimerLifeCycle.onStop, { ...start, clock: 10000 } as typeof start);
closeRun();
await closeRun();
await new Promise((resolve) => setImmediate(resolve));
expect(listRuns()).toHaveLength(1);
@@ -248,8 +291,8 @@ describe('closeRun()', () => {
expect(listRuns()).toHaveLength(2);
});
it('does nothing when no run is open', () => {
expect(() => closeRun()).not.toThrow();
it('does nothing when no run is open', async () => {
await expect(closeRun()).resolves.toBeNull();
expect(listRuns()).toHaveLength(0);
});
});
@@ -379,7 +422,7 @@ describe('run history queries and edits', () => {
currentRundown = { ...currentRundown, id: rundownId };
triggerReportEntry(TimerLifeCycle.onStart, start);
triggerReportEntry(TimerLifeCycle.onStop, { ...start, clock: 10000 } as typeof start);
closeRun();
await closeRun();
await new Promise((resolve) => setImmediate(resolve));
// stamp a predictable id so tests can address the run directly
const created = listRuns()[0];
@@ -396,15 +439,6 @@ describe('run history queries and edits', () => {
expect(listRuns()).toHaveLength(2);
});
it('returns the most recently started closed run', async () => {
await makeClosedRun('older');
await makeClosedRun('newer');
runs.find((run) => run.id === 'older')!.startedAt = 0;
runs.find((run) => run.id === 'newer')!.startedAt = 100000;
expect(getLatestRun()?.id).toBe('newer');
});
it('renames a run', async () => {
await makeClosedRun('run-a');
const renamed = await renameRun('run-a', 'Dress rehearsal');
@@ -24,12 +24,11 @@ router.get('/runs', validateRundownIdQuery, (req: Request, res: Response) => {
});
/**
* Most recently closed run, used to compare a rundown against its last outing.
* Registered ahead of /runs/:id so "latest" is not read as an id.
* Closes the run in progress and writes it to history immediately.
* Registered ahead of /runs/:id so "finish" is not read as an id.
*/
router.get('/runs/latest', validateRundownIdQuery, (req: Request, res: Response) => {
const { rundownId } = req.query as { rundownId?: string };
const run = report.getLatestRun(rundownId);
router.post('/runs/finish', async (_req: Request, res: Response) => {
const run = await report.closeRun();
if (!run) {
res.status(404).send();
return;
@@ -108,22 +108,26 @@ export function triggerReportEntry(
}
/**
* Closes the run in progress.
* Called when playback stops and events are unloaded, which is the operator
* saying the show is over. Pausing or loading another event does not end a run.
* Closes the run in progress and writes it to history immediately.
*
* Ending a run is an explicit act by the operator, not a side effect of
* playback. Stopping and starting again mid show is ordinary, and would
* otherwise split one show across several runs.
* @returns the closed run, or null if none was open
*/
export function closeRun() {
export async function closeRun(): Promise<ShowRun | null> {
if (openRun === null) {
return;
return null;
}
// detach the run before the async write so a start arriving in between
// opens a new run instead of appending to the one we are closing
// detach the run before the write so a start arriving in between opens a
// new run instead of appending to the one we are closing
const closing = { ...openRun, endedAt: lastEndedAtIn(generate()) };
openRun = null;
void persistRun(closing, generate());
const closed = await persistRun(closing, generate());
sendRefetch(RefetchKey.Report);
return closed;
}
/**
@@ -154,6 +158,10 @@ function openRunIfNeeded(state: DeepReadonly<RuntimeState>) {
startedAt,
endedAt: null,
};
// let the editor show that a run is being recorded without waiting
// for the first event to finish
sendRefetch(RefetchKey.Report);
}
/**
@@ -177,14 +185,19 @@ async function persistOpenRun(): Promise<void> {
if (openRun === null) {
return;
}
await persistRun(openRun, generate());
// debounced: this runs as events stop, which is the show critical path
await persistRun(openRun, generate(), { debounce: true });
}
/**
* Writes a run and its derived summary to the sidecar
* @private
*/
async function persistRun(run: Omit<ShowRun, 'report' | 'summary'>, currentReport: OntimeReport): Promise<void> {
async function persistRun(
run: Omit<ShowRun, 'report' | 'summary'>,
currentReport: OntimeReport,
options?: reportStore.WriteOptions,
): Promise<ShowRun> {
const rundown = getRundownForRun(run.rundownId);
// a rundown deleted mid-run leaves nothing to count against, so we keep
// whatever the run was last written with rather than reporting zero
@@ -192,11 +205,14 @@ async function persistRun(run: Omit<ShowRun, 'report' | 'summary'>, currentRepor
? countPlannedEvents(rundown.entries, rundown.flatOrder)
: (reportStore.getRun(run.id)?.summary.eventsPlanned ?? 0);
await reportStore.upsertRun({
const persisted: ShowRun = {
...run,
report: structuredClone(currentReport),
summary: getRunSummary(currentReport, eventsPlanned),
});
};
await reportStore.upsertRun(persisted, options);
return persisted;
}
/**
@@ -266,15 +282,6 @@ export function getRun(id: string): ShowRun | undefined {
return reportStore.getRun(id);
}
/** Most recent closed run, used to compare a rundown against its last outing */
export function getLatestRun(rundownId?: string): ShowRun | undefined {
return reportStore
.getRuns()
.filter((run) => run.endedAt !== null && (rundownId === undefined || run.rundownId === rundownId))
.sort((a, b) => b.startedAt - a.startedAt)
.at(0);
}
export async function renameRun(id: string, label: string): Promise<ShowRun | undefined> {
const run = reportStore.getRun(id);
if (!run) {
+9
View File
@@ -28,6 +28,7 @@ import { ONTIME_VERSION } from './ONTIME_VERSION.js';
import { getShowWelcomeDialog } from './services/app-state-service/AppStateService.js';
import * as messageService from './services/message-service/message.service.js';
import { initialiseProject } from './services/project-service/ProjectService.js';
import { flush as flushReports } from './services/report-service/report.store.js';
import { restoreService } from './services/restore-service/restore.service.js';
import type { RestorePoint } from './services/restore-service/restore.type.js';
import { runtimeService } from './services/runtime-service/runtime.service.js';
@@ -331,6 +332,14 @@ async function performShutdown(exitCode: number): Promise<void> {
shutdownTimeout,
);
// report writes are coalesced during a run, make sure none are outstanding
await withTimeout(
flushReports().catch((_error) => {
/** nothing do to here */
}),
shutdownTimeout,
);
// clear the restore file if it was a normal exit
// 0 means it was a SIGNAL
// 1 means crash -> keep the file
@@ -52,6 +52,8 @@ const {
renameReportsForProject,
resetStore,
getPathToReports,
flush,
hasUnwrittenChanges,
} = await import('../report.store.js');
function makeRun(patch: Partial<ShowRun> = {}): ShowRun {
@@ -170,6 +172,52 @@ describe('upsertRuns()', () => {
});
});
describe('write coalescing', () => {
beforeEach(async () => {
await loadReports('project-a');
});
it('keeps a debounced write off the disk until flushed', async () => {
await upsertRun(makeRun({ id: 'a' }), { debounce: true });
expect(hasUnwrittenChanges()).toBe(true);
expect(files.has(getPathToReports('project-a'))).toBe(false);
await flush();
expect(hasUnwrittenChanges()).toBe(false);
const written = files.get(getPathToReports('project-a')) as { runs: ShowRun[] };
expect(written.runs).toHaveLength(1);
});
it('collapses repeated debounced writes into one flush', async () => {
await upsertRun(makeRun({ id: 'a' }), { debounce: true });
await upsertRun(makeRun({ id: 'b' }), { debounce: true });
await upsertRun(makeRun({ id: 'c' }), { debounce: true });
await flush();
const written = files.get(getPathToReports('project-a')) as { runs: ShowRun[] };
expect(written.runs).toHaveLength(3);
});
it('writes straight through when not debounced', async () => {
await upsertRun(makeRun({ id: 'a' }));
expect(hasUnwrittenChanges()).toBe(false);
expect(files.has(getPathToReports('project-a'))).toBe(true);
});
it('flushes pending work before switching project', async () => {
await upsertRun(makeRun({ id: 'a' }), { debounce: true });
await loadReports('project-b');
const written = files.get(getPathToReports('project-a')) as { runs: ShowRun[] };
expect(written.runs).toHaveLength(1);
expect(getRuns()).toEqual([]);
});
});
describe('deleteRun()', () => {
beforeEach(async () => {
await loadReports('project-a');
@@ -1,18 +1,17 @@
import type { OntimeEventReport, ProjectReports, RunSummary, ShowRun } from 'ontime-types';
import type { ProjectReports } from 'ontime-types';
import { is } from '../../utils/is.js';
/**
* Validates the contents of a report sidecar file.
* A file which fails validation is discarded rather than repaired: reports are
* a record, and a partially understood record is worse than an empty one.
* Shallow check on the contents of a report sidecar.
*
* We are the only writer of this file, so this guards against it being
* missing, empty or hand edited rather than against arbitrary payloads.
* Anything that fails is discarded and the project starts with no history,
* which is the same outcome as a first run.
*/
export function isProjectReports(value: unknown): value is ProjectReports {
if (!is.object(value)) {
return false;
}
if (!is.objectWithKeys(value, ['runs'])) {
if (!is.object(value) || !is.objectWithKeys(value, ['runs'])) {
return false;
}
@@ -20,111 +19,14 @@ export function isProjectReports(value: unknown): value is ProjectReports {
return false;
}
return value.runs.every(isShowRun);
return value.runs.every(isRunShaped);
}
function isShowRun(value: unknown): value is ShowRun {
if (!is.object(value)) {
/** Enough of a run to be listed and opened without throwing */
function isRunShaped(value: unknown): boolean {
if (!is.object(value) || !is.objectWithKeys(value, ['id', 'startedAt', 'report', 'summary'])) {
return false;
}
if (
!is.objectWithKeys(value, [
'id',
'rundownId',
'rundownTitle',
'label',
'startedAt',
'endedAt',
'report',
'summary',
])
) {
return false;
}
if (!is.string(value.id) || !is.string(value.rundownId) || !is.string(value.rundownTitle)) {
return false;
}
if (!is.string(value.label)) {
return false;
}
if (!is.number(value.startedAt)) {
return false;
}
if (!is.number(value.endedAt) && value.endedAt !== null) {
return false;
}
if (!isOntimeReport(value.report)) {
return false;
}
return isRunSummary(value.summary);
}
function isOntimeReport(value: unknown): value is Record<string, OntimeEventReport> {
if (!is.object(value)) {
return false;
}
return Object.values(value).every(isEventReport);
}
function isEventReport(value: unknown): value is OntimeEventReport {
if (!is.object(value)) {
return false;
}
if (!is.objectWithKeys(value, ['startedAt', 'endedAt', 'scheduledStart', 'scheduledDuration', 'playCount'])) {
return false;
}
if (!is.number(value.startedAt) && value.startedAt !== null) {
return false;
}
if (!is.number(value.endedAt) && value.endedAt !== null) {
return false;
}
return is.number(value.scheduledStart) && is.number(value.scheduledDuration) && is.number(value.playCount);
}
function isRunSummary(value: unknown): value is RunSummary {
if (!is.object(value)) {
return false;
}
const numericKeys = [
'eventsRun',
'eventsPlanned',
'scheduledDuration',
'actualDuration',
'drift',
'eventsOver',
'eventsUnder',
'eventsOnTime',
] as const;
if (!is.objectWithKeys(value, [...numericKeys, 'worstOverrun'])) {
return false;
}
if (!numericKeys.every((key) => is.number(value[key]))) {
return false;
}
if (value.worstOverrun === null) {
return true;
}
if (!is.object(value.worstOverrun) || !is.objectWithKeys(value.worstOverrun, ['id', 'delta'])) {
return false;
}
return is.string(value.worstOverrun.id) && is.number(value.worstOverrun.delta);
return is.string(value.id) && is.number(value.startedAt) && is.object(value.report) && is.object(value.summary);
}
@@ -25,9 +25,19 @@ function emptyStore(): ProjectReports {
return { runs: [] };
}
/**
* How long writes are coalesced for while a run is in progress.
* A run's events stop frequently and the sidecar holds the project's whole
* history, so writing per event would put work proportional to everything
* that ever ran onto the show critical path.
*/
const writeDebounce = 5000;
let fileRef: JSONFile<ProjectReports> | null = null;
let cache: ProjectReports = emptyStore();
let failedWriteAttempts = 0;
let writeTimer: NodeJS.Timeout | null = null;
let hasPendingWrite = false;
/**
* Resolves the sidecar path for a given project file name
@@ -42,6 +52,9 @@ export function getPathToReports(projectFilename: string): string {
* project changes.
*/
export async function loadReports(projectFilename: string): Promise<ProjectReports> {
// the outgoing project may have a coalesced write outstanding
await flush();
fileRef = new JSONFile<ProjectReports>(getPathToReports(projectFilename));
failedWriteAttempts = 0;
@@ -67,19 +80,27 @@ export function getRun(id: string): ShowRun | undefined {
return cache.runs.find((run) => run.id === id);
}
export type WriteOptions = {
/** coalesce this write instead of hitting disk straight away */
debounce?: boolean;
};
/**
* Inserts or replaces a run, keeping the list ordered newest first
*/
export async function upsertRun(run: ShowRun): Promise<void> {
return upsertRuns([run]);
export async function upsertRun(run: ShowRun, options?: WriteOptions): Promise<void> {
return upsertRuns([run], options);
}
/**
* Inserts or replaces several runs in one pass.
* Batching matters: these all live in a single file, so writing per run would
* mean concurrent writes racing on the same path.
*
* Writes are immediate unless the caller opts into debouncing. Anything driven
* by a user action should stay immediate so it cannot be lost.
*/
export async function upsertRuns(updated: ShowRun[]): Promise<void> {
export async function upsertRuns(updated: ShowRun[], options?: WriteOptions): Promise<void> {
if (updated.length === 0) {
return;
}
@@ -92,7 +113,12 @@ export async function upsertRuns(updated: ShowRun[]): Promise<void> {
cache.runs[index] = run;
}
}
await persist();
if (options?.debounce) {
scheduleWrite();
return;
}
await flush();
}
/**
@@ -106,7 +132,7 @@ export async function deleteRun(id: string): Promise<boolean> {
}
cache.runs.splice(index, 1);
await persist();
await flush();
return true;
}
@@ -120,7 +146,7 @@ export async function deleteRunsForRundown(rundownId: string): Promise<number> {
const removed = before - cache.runs.length;
if (removed > 0) {
await persist();
await flush();
}
return removed;
}
@@ -130,7 +156,7 @@ export async function deleteRunsForRundown(rundownId: string): Promise<number> {
*/
export async function deleteAllRuns(): Promise<void> {
cache.runs = [];
await persist();
await flush();
}
/**
@@ -170,11 +196,34 @@ export async function renameReportsForProject(originalFilename: string, newFilen
}
/**
* Writes the cache to disk.
* Gives up after repeated failures so a broken disk cannot stall the runtime.
* Marks the cache dirty and arms the coalescing timer.
* @private
*/
async function persist(): Promise<void> {
function scheduleWrite(): void {
hasPendingWrite = true;
if (writeTimer !== null) {
return;
}
writeTimer = setTimeout(() => {
writeTimer = null;
void flush();
}, writeDebounce);
// a pending report write is never a reason to keep the process alive
writeTimer.unref?.();
}
/**
* Writes any outstanding changes to disk now.
* Called on every immediate write, when the project changes, and on shutdown.
*/
export async function flush(): Promise<void> {
if (writeTimer !== null) {
clearTimeout(writeTimer);
writeTimer = null;
}
hasPendingWrite = false;
if (fileRef === null || failedWriteAttempts > 3) {
return;
}
@@ -187,10 +236,20 @@ async function persist(): Promise<void> {
}
}
/** Whether a coalesced write is still outstanding, for tests and diagnostics */
export function hasUnwrittenChanges(): boolean {
return hasPendingWrite;
}
/**
* Resets in-memory state, used when no project is loaded and in tests
*/
export function resetStore(): void {
if (writeTimer !== null) {
clearTimeout(writeTimer);
writeTimer = null;
}
hasPendingWrite = false;
fileRef = null;
cache = emptyStore();
failedWriteAttempts = 0;
@@ -17,7 +17,7 @@ import {
import { millisToString, validatePlayback } from 'ontime-utils';
import { triggerAutomations } from '../../api-data/automation/automation.service.js';
import { closeRun, triggerReportEntry } from '../../api-data/report/report.service.js';
import { triggerReportEntry } from '../../api-data/report/report.service.js';
import { getCurrentRundown, getEntryWithId, getRundownMetadata } from '../../api-data/rundown/rundown.dao.js';
import { RundownMetadata } from '../../api-data/rundown/rundown.types.js';
import { logger } from '../../classes/Logger.js';
@@ -523,8 +523,6 @@ class RuntimeService {
logger.info(LogOrigin.Playback, `Play Mode ${newState.timer.playback.toUpperCase()}`);
process.nextTick(() => {
triggerReportEntry(TimerLifeCycle.onStop, previousState);
// a full stop unloads the events, which is the operator ending the show
closeRun();
triggerAutomations(TimerLifeCycle.onStop);
});