feat: add context to state diffing for troubleshooting, de-asyncify State Handler to hopefuly resolve some paralel execution cases (SOFIE-3889)

packages/timeline-state-resolver/package.json

@@ -109,7 +109,7 @@
 		"p-timeout": "^3.2.0",
 		"simple-oauth2": "^5.0.0",
 		"sprintf-js": "^1.1.3",
-		"superfly-timeline": "9.0.2",
+		"superfly-timeline": "9.1.2",
 		"threadedclass": "^1.2.1",
 		"timeline-state-resolver-types": "9.2.0",
 		"tslib": "^2.6.2",

packages/timeline-state-resolver/src/__tests__/conductor.spec.ts

@@ -85,6 +85,8 @@ describe('Conductor', () => {
 				options: {},
 			})
 
+			conductor.timelineHash = 'timelineHashABC'
+
 			// add something that will play in a seconds time
 			const abstractThing0: TSRTimelineObj<any> = {
 				id: 'a0',
@@ -145,22 +147,25 @@ describe('Conductor', () => {
 					},
 					time: 10005,
 				}),
-				device0Mappings
+				device0Mappings,
+				'timelineHashABC'
 			)
 			expect(device0.handleState).toHaveBeenNthCalledWith(
 				2,
 				expect.objectContaining({
 					time: 11000,
 				}),
-				device0Mappings
+				device0Mappings,
+				'timelineHashABC'
 			)
 			expect(device0.handleState).toHaveBeenNthCalledWith(
 				3,
 				expect.objectContaining({
 					layers: {},
 					time: 12000,
 				}),
-				device0Mappings
+				device0Mappings,
+				'timelineHashABC'
 			)
 
 			// Ensure device1 has been fed sensible states
@@ -171,7 +176,8 @@ describe('Conductor', () => {
 				expect.objectContaining({
 					layers: {},
 				}),
-				device1Mappings
+				device1Mappings,
+				'timelineHashABC'
 			)
 			expect(device1.handleState).toHaveBeenNthCalledWith(
 				2,
@@ -186,14 +192,16 @@ describe('Conductor', () => {
 						}),
 					},
 				}),
-				device1Mappings
+				device1Mappings,
+				'timelineHashABC'
 			)
 			expect(device1.handleState).toHaveBeenNthCalledWith(
 				3,
 				expect.objectContaining({
 					layers: {},
 				}),
-				device1Mappings
+				device1Mappings,
+				'timelineHashABC'
 			)
 
 			// Remove the device
@@ -231,6 +239,8 @@ describe('Conductor', () => {
 				options: {},
 			})
 
+			conductor.timelineHash = 'timelineHashABC'
+
 			// add something that will play "now"
 			const abstractThing0: TSRTimelineObj<any> = {
 				// will be converted from "now" to 10000
@@ -323,7 +333,8 @@ describe('Conductor', () => {
 					},
 					time: 10000,
 				}),
-				myLayerMapping
+				myLayerMapping,
+				'timelineHashABC'
 			)
 			expect(device0.handleState).toHaveBeenNthCalledWith(
 				2, // setTimelineTriggerTime
@@ -339,7 +350,8 @@ describe('Conductor', () => {
 					},
 					time: 10000,
 				}),
-				myLayerMapping
+				myLayerMapping,
+				'timelineHashABC'
 			)
 			expect(device0.handleState).toHaveBeenNthCalledWith(
 				3, // End of object
@@ -355,7 +367,8 @@ describe('Conductor', () => {
 					},
 					time: 10300,
 				}),
-				myLayerMapping
+				myLayerMapping,
+				'timelineHashABC'
 			)
 
 			device0.handleState.mockClear()
@@ -370,15 +383,17 @@ describe('Conductor', () => {
 					layers: {},
 					time: 15300,
 				}),
-				myLayerMapping
+				myLayerMapping,
+				'timelineHashABC'
 			)
 			expect(device0.handleState).toHaveBeenNthCalledWith(
 				1,
 				expect.objectContaining({
 					layers: {},
 					time: 15300,
 				}),
-				myLayerMapping
+				myLayerMapping,
+				'timelineHashABC'
 			)
 		} finally {
 			await conductor.destroy()
@@ -512,7 +527,7 @@ describe('Conductor', () => {
 		const timeline: TSRTimeline = [video0]
 
 		const device0Container = conductor.getDevice('device0')
-		const device0 = device0Container!.device as ThreadedClass<DeviceInstanceWrapper>
+		const device0 = device0Container?.device as ThreadedClass<DeviceInstanceWrapper>
 		expect(device0).toBeTruthy()
 
 		conductor.setTimelineAndMappings(timeline)

packages/timeline-state-resolver/src/__tests__/mockDeviceInstanceWrapper.ts

@@ -80,7 +80,11 @@ export class MockDeviceInstanceWrapper
 	}
 
 	handleState = jest.fn(
-		(_newState: Timeline.TimelineState<TSRTimelineContent>, _newMappings: Mappings<unknown>): void => {
+		(
+			_newState: Timeline.TimelineState<TSRTimelineContent>,
+			_newMappings: Mappings<unknown>,
+			_timelineHash: string
+		): void => {
 			// throw new Error('Method not implemented.')
 		}
 	)

packages/timeline-state-resolver/src/conductor.ts

@@ -981,7 +981,13 @@ export class Conductor extends EventEmitter<ConductorEvents> {
 					// Pass along the state to the device, it will generate its commands and execute them:
 					try {
 						// await device.device.handleState(removeParentFromState(subState), this._mappings)
-						await this._setDeviceState(device.deviceId, tlState.time, removeParentFromState(subState), this._mappings)
+						await this._setDeviceState(
+							device.deviceId,
+							tlState.time,
+							removeParentFromState(subState),
+							this._mappings,
+							this.timelineHash ?? 'NoTimelineHash'
+						)
 					} catch (e) {
 						this.emit('error', 'Error in device "' + device.deviceId + '"' + e + ' ' + (e as Error).stack)
 					}
@@ -1111,7 +1117,8 @@ export class Conductor extends EventEmitter<ConductorEvents> {
 		deviceId: string,
 		time: number,
 		state: Timeline.TimelineState<TSRTimelineContent>,
-		unfilteredMappings: Mappings
+		unfilteredMappings: Mappings,
+		timelineHash: string
 	) {
 		// only take mappings that are for this deviceId
 		const mappings = Object.fromEntries(
@@ -1151,7 +1158,7 @@ export class Conductor extends EventEmitter<ConductorEvents> {
 		const filledState = fillStateFromDatastore(state, this._datastore)
 
 		// send the filled state to the device handler
-		return this.getDevice(deviceId)?.device.handleState(filledState, mappings)
+		return this.getDevice(deviceId)?.device.handleState(filledState, mappings, timelineHash)
 	}
 
 	setDatastore(newStore: Datastore) {
@@ -1184,7 +1191,7 @@ export class Conductor extends EventEmitter<ConductorEvents> {
 						const filledState = fillStateFromDatastore(s.state, this._datastore)
 
 						this.getDevice(deviceId)
-							?.device.handleState(filledState, s.mappings)
+							?.device.handleState(filledState, s.mappings, 'dataStoreChanged')
 							.catch((e) => this.emit('error', 'resolveTimeline' + e + '\nStack: ' + (e as Error).stack))
 					}
 				}

packages/timeline-state-resolver/src/integrations/abstract/__tests__/abstract.spec.ts

@@ -50,7 +50,7 @@ describe('Abstract device', () => {
 		) {
 			const device = await getInitialisedDevice()
 
-			const commands = device.diffStates(oldDevState, newDevState)
+			const commands = device.diffStates(oldDevState, newDevState, {}, 0, 'test')
 
 			expect(commands).toEqual(expCommands)
 		}
@@ -100,7 +100,7 @@ describe('Abstract device', () => {
 				[
 					{
 						command: 'addedAbstract',
-						context: 'added: obj0',
+						context: 'added: obj0 (test)',
 						timelineObjId: 'obj0',
 					},
 				]
@@ -126,7 +126,7 @@ describe('Abstract device', () => {
 				[
 					{
 						command: 'changedAbstract',
-						context: 'changed: obj1',
+						context: 'changed: obj1 (test)',
 						timelineObjId: 'obj1',
 					},
 				]
@@ -148,7 +148,7 @@ describe('Abstract device', () => {
 				[
 					{
 						command: 'removedAbstract',
-						context: 'removed: obj0',
+						context: 'removed: obj0 (test)',
 						timelineObjId: 'obj0',
 					},
 				]

packages/timeline-state-resolver/src/integrations/abstract/index.ts

@@ -7,6 +7,7 @@ import {
 	DeviceOptionsAbstract,
 	AbstractActions,
 	ActionExecutionResultCode,
+	Mappings,
 } from 'timeline-state-resolver-types'
 import { Device } from '../../service/device'
 
@@ -73,7 +74,13 @@ export class AbstractDevice extends Device<AbstractOptions, AbstractDeviceState,
 	 * @param oldAbstractState
 	 * @param newAbstractState
 	 */
-	diffStates(oldAbstractState: AbstractDeviceState | undefined, newAbstractState: AbstractDeviceState) {
+	diffStates(
+		oldAbstractState: AbstractDeviceState | undefined,
+		newAbstractState: AbstractDeviceState,
+		_mappings: Mappings,
+		_time: number,
+		context: string
+	) {
 		// in this abstract class, let's just cheat:
 
 		const commands: Array<AbstractCommandWithContext> = []
@@ -87,7 +94,7 @@ export class AbstractDevice extends Device<AbstractOptions, AbstractDeviceState,
 				commands.push({
 					command: 'addedAbstract',
 					timelineObjId: newLayer.id,
-					context: `added: ${newLayer.id}`,
+					context: `added: ${newLayer.id} (${context})`,
 				})
 			} else {
 				// changed?
@@ -96,7 +103,7 @@ export class AbstractDevice extends Device<AbstractOptions, AbstractDeviceState,
 					commands.push({
 						command: 'changedAbstract',
 						timelineObjId: newLayer.id,
-						context: `changed: ${newLayer.id}`,
+						context: `changed: ${newLayer.id} (${context})`,
 					})
 				}
 			}
@@ -112,7 +119,7 @@ export class AbstractDevice extends Device<AbstractOptions, AbstractDeviceState,
 				commands.push({
 					command: 'removedAbstract',
 					timelineObjId: oldLayer.id,
-					context: `removed: ${oldLayer.id}`,
+					context: `removed: ${oldLayer.id} (${context})`,
 				})
 			}
 		}

packages/timeline-state-resolver/src/integrations/atem/__tests__/atem.spec.ts

@@ -124,7 +124,7 @@ describe('Atem', () => {
 
 		const deviceState = device.convertTimelineStateToDeviceState(mockState, {})
 
-		const commands = device.diffStates(undefined, deviceState, {})
+		const commands = device.diffStates(undefined, deviceState, {}, 0, 'test')
 
 		expect(commands).toHaveLength(0)
 	})
@@ -161,7 +161,7 @@ describe('Atem', () => {
 		})
 
 		{
-			const commands = device.diffStates(undefined, deviceState1, myLayerMapping)
+			const commands = device.diffStates(undefined, deviceState1, myLayerMapping, 0, 'test')
 
 			const allCommands = extractAllCommands(commands)
 			expect(allCommands).toHaveLength(2)
@@ -198,7 +198,7 @@ describe('Atem', () => {
 		})
 
 		{
-			const commands = device.diffStates(deviceState1, deviceState2, myLayerMapping)
+			const commands = device.diffStates(deviceState1, deviceState2, myLayerMapping, 0, 'test')
 
 			const allCommands = extractAllCommands(commands)
 			expect(allCommands).toHaveLength(2)
@@ -240,12 +240,12 @@ describe('Atem', () => {
 		})
 
 		// Expect that a command has been scheduled
-		const commands = device.diffStates(undefined, deviceState, myLayerMapping)
+		const commands = device.diffStates(undefined, deviceState, myLayerMapping, 0, 'test')
 		const allCommands = extractAllCommands(commands)
 		expect(allCommands).toHaveLength(2)
 
 		// Diff the same state, after the commands have been sent
-		const commands2 = device.diffStates(deviceState, deviceState, myLayerMapping)
+		const commands2 = device.diffStates(deviceState, deviceState, myLayerMapping, 0, 'test')
 		expect(commands2).toHaveLength(0)
 	})
 
@@ -282,7 +282,7 @@ describe('Atem', () => {
 		})
 
 		{
-			const commands = device.diffStates(undefined, deviceState1, myLayerMapping)
+			const commands = device.diffStates(undefined, deviceState1, myLayerMapping, 0, 'test')
 
 			const allCommands = extractAllCommands(commands)
 			expect(allCommands).toHaveLength(2)
@@ -319,7 +319,7 @@ describe('Atem', () => {
 		})
 
 		{
-			const commands = device.diffStates(deviceState1, deviceState2, myLayerMapping)
+			const commands = device.diffStates(deviceState1, deviceState2, myLayerMapping, 0, 'test')
 
 			const allCommands = extractAllCommands(commands)
 			expect(allCommands).toHaveLength(5)