fix(automation): review fixes across the automations rework

Reviewing the branch turned up defects, several of them worse than the
problems the original commits set out to solve.

Destructive: deleting an automation removed its global triggers and only then
discovered a rundown event also referenced it. The delete failed, the user
cancelled, and their triggers were gone for good. The server reports trigger
references before event ones, so this was reachable whenever both existed.
Deleted triggers are now recreated when the delete is refused.

Silently wrong: a template read the project from disk while writes are
debounced by three seconds, so "make some automations, save them as a
template" could produce a template without them. Verified by hand: an
automation created milliseconds earlier now appears.

The demo shipped half a pair. The danger warning set a stage message visible
and nothing ever cleared it, so from the first event that hit its danger
window the message covered the countdown for the rest of the session. The
recipe library ships the clearing counterpart; the demo now does too, and the
whole cycle is verified against a running server.

Flood control undid itself. resetAutomationLogState ran on every onLoad, and
roll mode loads at every event boundary, so the "logging suppressed" notice
was re-emitted once per cue: exactly the flooding it exists to prevent. It
also wiped the throttle for onLoad and onStop immediately before writing to
it. Reset now happens on stop only, outside the early returns that made the
first attempt at this a no-op.

Trigger reconciliation diffed a mount-time selection against a live prop.
Settings are polled, so a trigger created in another tab while the form was
open would be deleted by a save that never saw it. It now diffs against the
snapshot, and says which triggers a save will remove rather than removing
several same-lifecycle triggers silently.

Also: a rundowns template no longer carries a phantom empty rundown from
makeNewProject; the partial-duplicate endpoint returns the name it actually
used, since collisions get renamed; the template flow invalidates the project
list rather than relying on a refetch on mount; the last-fired label drops to
a one minute cadence instead of holding a 1Hz timer per automation forever;
e2e cleanup moved to afterEach so a mid-test failure stops leaking state.

The e2e spec has now been run against a real server, green on both the demo
project and a blank one, leaving no residue.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01LpbLJVVT26tzWkduck1M9H
This commit is contained in:
Claude
2026-08-08 16:43:29 +00:00
parent 32734de679
commit cdde054b14
18 changed files with 249 additions and 77 deletions
@@ -702,18 +702,44 @@ describe('automation reporting', () => {
expect(logSpy.mock.calls[0][1]).toContain('suppressed');
});
it('shows the suppression notice again after a reload', async () => {
it('does not repeat the suppression notice on every load', async () => {
await bind('reporting-clock', TimerLifeCycle.onClock);
triggerAutomations(TimerLifeCycle.onClock);
logSpy.mockClear();
// onLoad bookends a run and resets the reporting state
triggerAutomations(TimerLifeCycle.onLoad);
// roll mode loads at every event boundary, and an operator steps through cues by hand.
// Re-notifying on each one would be the very flooding the notice exists to prevent
for (let i = 0; i < 5; i++) {
triggerAutomations(TimerLifeCycle.onLoad);
triggerAutomations(TimerLifeCycle.onClock);
}
expect(logSpy.mock.calls.filter(([, message]) => String(message).includes('suppressed'))).toHaveLength(0);
});
it('shows the suppression notice again after a stop', async () => {
await bind('reporting-clock', TimerLifeCycle.onClock);
triggerAutomations(TimerLifeCycle.onClock);
logSpy.mockClear();
// a stop ends the run, the next one reports from scratch
triggerAutomations(TimerLifeCycle.onStop);
triggerAutomations(TimerLifeCycle.onClock);
expect(logSpy.mock.calls.some(([, message]) => String(message).includes('suppressed'))).toBe(true);
});
it('throttles repeated loads, which the reset used to defeat', async () => {
vi.useFakeTimers();
await bind('reporting-load', TimerLifeCycle.onLoad);
logSpy.mockClear();
triggerAutomations(TimerLifeCycle.onLoad);
triggerAutomations(TimerLifeCycle.onLoad);
expect(logSpy).toHaveBeenCalledTimes(1);
});
it('collapses repeats of the same automation and cycle inside the throttle window', async () => {
vi.useFakeTimers();
await bind('reporting-danger', TimerLifeCycle.onDanger);
@@ -41,9 +41,9 @@ const lastLoggedAt = new Map<string, number>();
const lastReportedAt = new Map<string, number>();
/**
* Clears the per-load logging state.
* Called when the runtime loads or stops so the suppression notice is shown again
* for the next show rather than once per server lifetime
* Clears the reporting state.
* Called when the runtime stops, so the next run reports from scratch rather than
* inheriting throttles from the last one
*/
export function resetAutomationLogState() {
suppressionNotices.clear();
@@ -55,15 +55,24 @@ export function resetAutomationLogState() {
* Exposes a method for triggering actions based on a TimerLifeCycle event
*/
export function triggerAutomations(cycle: TimerLifeCycle) {
// a load or a stop bookends a run: start reporting from scratch so the next show
// gets its own suppression notice rather than inheriting one from the last
if (cycle === TimerLifeCycle.onLoad || cycle === TimerLifeCycle.onStop) {
resetAutomationLogState();
}
if (!getAutomationsEnabled()) {
return;
}
fireForCycle(cycle);
// A stop ends a run, so the next one reports from scratch. This deliberately does not
// happen on load: loading is not rare, roll mode loads at every event boundary, and
// resetting there would re-emit the suppression notice once per cue, which is the
// flooding the notice exists to prevent.
// It sits out here because fireForCycle returns early when nothing is bound to onStop,
// which is the common case
if (cycle === TimerLifeCycle.onStop) {
resetAutomationLogState();
}
}
function fireForCycle(cycle: TimerLifeCycle) {
const store = eventStore.poll();
let triggers = getAutomationTriggers();
+3 -4
View File
@@ -235,16 +235,15 @@ export async function loadDemo(_req: Request, res: Response<MessageResponse | Er
* Creates a template: a new project file containing only the selected sections of an existing one.
* The result is not loaded, so making a template does not disturb the running show.
*/
export async function partialDuplicateProjectFile(req: Request, res: Response<MessageResponse | ErrorResponse>) {
export async function partialDuplicateProjectFile(req: Request, res: Response<{ filename: string } | ErrorResponse>) {
const { filename } = req.params;
const { newFilename, sections } = req.body;
try {
// the created name can differ from what was asked for, generateUniqueFileName resolves collisions
const created = await projectService.createProjectFromSections(filename, newFilename, sections);
res.status(201).send({
message: `Created template ${created} from ${filename}`,
});
res.status(201).send({ filename: created });
} catch (error) {
const message = getErrorMessage(error);
if (message.startsWith('Project file')) {
+3 -1
View File
@@ -75,7 +75,9 @@ export const validateSectionsBody = [
body('sections')
.isArray({ min: 1 })
.withMessage(`Select at least one of: ${templateSections.join(', ')}`)
.custom((sections: unknown[]) => sections.every((section) => typeof section === 'string' && isTemplateSection(section)))
.custom((sections: unknown[]) =>
sections.every((section) => typeof section === 'string' && isTemplateSection(section)),
)
.withMessage(`Sections must be any of: ${templateSections.join(', ')}`),
requestValidationFunction,
+15
View File
@@ -99,6 +99,12 @@ export const demoDb: DatabaseModel = {
trigger: TimerLifeCycle.onStart,
automationId: 'demo-aux-timer',
},
{
id: 'demo-trigger-clear',
title: 'Demo: clear the wrap up warning',
trigger: TimerLifeCycle.onFinish,
automationId: 'demo-clear-message',
},
],
automations: {
'demo-aux-timer': {
@@ -119,6 +125,15 @@ export const demoDb: DatabaseModel = {
// self labelled, so nobody mistakes it for something Ontime does on its own
outputs: [{ type: 'ontime', action: 'message-set', text: 'Demo automation: please wrap up', visible: true }],
},
'demo-clear-message': {
id: 'demo-clear-message',
title: 'Demo: clear the wrap up warning',
filterRule: 'all',
filters: [],
// the pair to the warning above. Without it the message would stay on the stage
// timer for the rest of the session, blanking the countdown on every later event
outputs: [{ type: 'ontime', action: 'message-set', text: '', visible: false }],
},
'demo-osc-example': {
id: 'demo-osc-example',
title: 'Demo: OSC to a lighting console (example, not wired up)',
@@ -9,7 +9,7 @@ import { parseDatabaseModel } from '../../api-data/db/db.parser.js';
import { getCurrentRundown } from '../../api-data/rundown/rundown.dao.js';
import { parseRundowns } from '../../api-data/rundown/rundown.parser.js';
import { initRundown } from '../../api-data/rundown/rundown.service.js';
import { getDataProvider, initPersistence } from '../../classes/data-provider/DataProvider.js';
import { flushPendingWrites, getDataProvider, initPersistence } from '../../classes/data-provider/DataProvider.js';
import { safeMerge } from '../../classes/data-provider/DataProvider.utils.js';
import { logger } from '../../classes/Logger.js';
import { makeNewProject } from '../../models/dataModel.js';
@@ -342,6 +342,10 @@ export async function createProjectFromSections(
throw new Error('At least one section must be selected');
}
// writes are debounced, and the natural flow here is "make some automations, then save them
// as a template". Without this the template silently misses anything from the last few seconds
await flushPendingWrites();
const fileData = await parseJsonFile(projectFilePath);
const { data } = parseDatabaseModel(fileData);
@@ -355,6 +359,13 @@ export async function createProjectFromSections(
}
const template = safeMerge(makeNewProject(), patch);
// makeNewProject seeds an empty rundown and safeMerge merges rundowns by key, so without
// this the template would ship a phantom "Default" rundown alongside the real ones
if (patch.rundowns !== undefined) {
template.rundowns = patch.rundowns;
}
const fileNameWithExtension = generateUniqueFileName(publicDir.projectsDir, ensureJsonExtension(newFilename));
await writeFile(getPathToProject(fileNameWithExtension), JSON.stringify(template, null, 2), 'utf-8');
@@ -3,6 +3,7 @@ import { writeFile } from 'fs/promises';
import { OntimeView, TimerLifeCycle } from 'ontime-types';
import { Mock } from 'vitest';
import { makeNewProject } from '../../../models/dataModel.js';
import { isLastLoadedProject } from '../../app-state-service/AppStateService.js';
import {
createProjectFromSections,
@@ -11,7 +12,6 @@ import {
renameProjectFile,
} from '../ProjectService.js';
import { doesProjectExist, parseJsonFile } from '../projectServiceUtils.js';
import { makeNewProject } from '../../../models/dataModel.js';
// stop the database loading from initiating
vi.mock('../../../setup/loadDb.js', () => {
@@ -100,16 +100,20 @@ describe('createProjectFromSections', () => {
(doesProjectExist as Mock).mockReturnValue('/projects/source.json');
(parseJsonFile as Mock).mockResolvedValue({
...makeNewProject(),
urlPresets: [
{ target: OntimeView.Timer, enabled: true, alias: 'from-source', search: '', displayInNav: false },
],
urlPresets: [{ target: OntimeView.Timer, enabled: true, alias: 'from-source', search: '', displayInNav: false }],
automation: {
enabledAutomations: true,
enabledOscIn: false,
oscPortIn: 8888,
triggers: [{ id: 't1', title: 'on start', trigger: TimerLifeCycle.onStart, automationId: 'a1' }],
automations: {
a1: { id: 'a1', title: 'from source', filterRule: 'all', filters: [], outputs: [{ type: 'http', url: 'http://127.0.0.1/go' }] },
a1: {
id: 'a1',
title: 'from source',
filterRule: 'all',
filters: [],
outputs: [{ type: 'http', url: 'http://127.0.0.1/go' }],
},
},
},
});