From 67eaca44fea01f9f00fb375e37f2bf8877f3c1ec Mon Sep 17 00:00:00 2001 From: Johan Nyman Date: Thu, 26 Sep 2024 14:51:38 +0200 Subject: [PATCH 1/5] chore: refactor: move nextEvent calculation into ResolverHandler --- src/resolver/ResolvedTimelineHandler.ts | 105 ++++++++++++++++++++++++ src/resolver/ResolverHandler.ts | 105 +----------------------- 2 files changed, 107 insertions(+), 103 deletions(-) diff --git a/src/resolver/ResolvedTimelineHandler.ts b/src/resolver/ResolvedTimelineHandler.ts index f1fdaa56..f7a00719 100644 --- a/src/resolver/ResolvedTimelineHandler.ts +++ b/src/resolver/ResolvedTimelineHandler.ts @@ -780,6 +780,108 @@ export class ResolvedTimelineHandler { return cappedInstances } + public getResolvedTimeline(): ResolvedTimeline { + return literal>({ + objects: mapToObject(this.objectsMap), + classes: mapToObject(this.classesMap), + layers: mapToObject(this.layersMap), + nextEvents: this.getNextEvents(), + + statistics: this.getStatistics(), + + error: this.resolveError, + }) + } + private getNextEvents(): NextEvent[] { + const toc = tic(' getNextEvents') + const nextEvents: NextEvent[] = [] + + const allObjects: ResolvedTimelineObject[] = [] + const allKeyframes: ResolvedTimelineObject[] = [] + + for (const obj of this.objectsMap.values()) { + if (obj.resolved.isKeyframe) { + allKeyframes.push(obj) + } else { + allObjects.push(obj) + } + } + + /** Used to fast-track in cases where there are no keyframes */ + const hasKeyframes = allKeyframes.length > 0 + + const objectInstanceStartTimes = new Set() + const objectInstanceEndTimes = new Set() + + // Go through keyframes last: + for (const obj of [...allObjects, ...allKeyframes]) { + if (!obj.resolved.isKeyframe) { + if (!objHasLayer(obj)) continue // transparent objects are omitted in NextEvents + } else if (obj.resolved.parentId !== undefined) { + const parentObj = this.getObject(obj.resolved.parentId) + if (parentObj) { + /* istanbul ignore if */ + if (!objHasLayer(parentObj)) continue // Keyframes of transparent objects are omitted in NextEvents + } + } + + for (let i = 0; i < obj.resolved.instances.length; i++) { + const instance = obj.resolved.instances[i] + if (instance.start > this.options.time && instance.start < (this.options.limitTime ?? Infinity)) { + let useThis = true + + if (hasKeyframes) { + if (!obj.resolved.isKeyframe) { + objectInstanceStartTimes.add(`${obj.id}_${instance.start}`) + } else { + // No need to put keyframe event if its parent starts at the same time: + if (objectInstanceStartTimes.has(`${obj.resolved.parentId}_${instance.start}`)) { + useThis = false + } + } + } + + if (useThis) { + nextEvents.push({ + objId: obj.id, + type: obj.resolved.isKeyframe ? EventType.KEYFRAME : EventType.START, + time: instance.start, + }) + } + } + if ( + instance.end !== null && + instance.end > this.options.time && + instance.end < (this.options.limitTime ?? Infinity) + ) { + let useThis = true + if (hasKeyframes) { + if (!obj.resolved.isKeyframe) { + objectInstanceEndTimes.add(`${obj.id}_${instance.end}`) + } else { + // No need to put keyframe event if its parent ends at the same time: + if (objectInstanceEndTimes.has(`${obj.resolved.parentId}_${instance.end}`)) { + useThis = false + } + } + } + + if (useThis) { + nextEvents.push({ + objId: obj.id, + type: obj.resolved.isKeyframe ? EventType.KEYFRAME : EventType.END, + time: instance.end, + }) + } + } + } + } + nextEvents.sort(compareNextEvents) + + toc() + return nextEvents + } + private updateDirectReferenceMap(obj: ResolvedTimelineObject, directReferences: Reference[]) { obj.resolved.directReferences = directReferences @@ -1080,3 +1182,6 @@ function compareEvents(a: T, b: T): number { export interface TimelineObjectKeyframe extends TimelineObject, TimelineKeyframe {} +function compareNextEvents(a: NextEvent, b: NextEvent): number { + return a.time - b.time || b.type - a.type || compareStrings(a.objId, b.objId) +} diff --git a/src/resolver/ResolverHandler.ts b/src/resolver/ResolverHandler.ts index f9563c20..fd318be2 100644 --- a/src/resolver/ResolverHandler.ts +++ b/src/resolver/ResolverHandler.ts @@ -66,117 +66,16 @@ resolver.run(timeline);` // Step 3: Go through and resolve all objects: this.resolvedTimeline.resolveAllTimelineObjs() - // Step 4: Populate nextEvents: - this.updateNextEvents() - // Step 5: persist cache if (cacheHandler) { cacheHandler.persistData() } - const resolvedTimeline = literal>({ - objects: mapToObject(this.resolvedTimeline.objectsMap), - classes: mapToObject(this.resolvedTimeline.classesMap), - layers: mapToObject(this.resolvedTimeline.layersMap), - nextEvents: this.nextEvents, + if (this.options.traceResolving) this.resolvedTimeline.addResolveTrace(`resolveTimeline done!`) - statistics: this.resolvedTimeline.getStatistics(), + const resolvedTimeline: ResolvedTimeline = this.resolvedTimeline.getResolvedTimeline() - error: this.resolvedTimeline.resolveError, - }) toc() return resolvedTimeline } - /** Update this.nextEvents */ - private updateNextEvents() { - const toc = tic(' updateNextEvents') - this.nextEvents = [] - - const allObjects: ResolvedTimelineObject[] = [] - const allKeyframes: ResolvedTimelineObject[] = [] - - for (const obj of this.resolvedTimeline.objectsMap.values()) { - if (obj.resolved.isKeyframe) { - allKeyframes.push(obj) - } else { - allObjects.push(obj) - } - } - - /** Used to fast-track in cases where there are no keyframes */ - const hasKeyframes = allKeyframes.length > 0 - - const objectInstanceStartTimes = new Set() - const objectInstanceEndTimes = new Set() - - // Go through keyframes last: - for (const obj of [...allObjects, ...allKeyframes]) { - if (!obj.resolved.isKeyframe) { - if (!objHasLayer(obj)) continue // transparent objects are omitted in NextEvents - } else if (obj.resolved.parentId !== undefined) { - const parentObj = this.resolvedTimeline.getObject(obj.resolved.parentId) - if (parentObj) { - /* istanbul ignore if */ - if (!objHasLayer(parentObj)) continue // Keyframes of transparent objects are omitted in NextEvents - } - } - - for (let i = 0; i < obj.resolved.instances.length; i++) { - const instance = obj.resolved.instances[i] - if (instance.start > this.options.time && instance.start < (this.options.limitTime ?? Infinity)) { - let useThis = true - - if (hasKeyframes) { - if (!obj.resolved.isKeyframe) { - objectInstanceStartTimes.add(`${obj.id}_${instance.start}`) - } else { - // No need to put keyframe event if its parent starts at the same time: - if (objectInstanceStartTimes.has(`${obj.resolved.parentId}_${instance.start}`)) { - useThis = false - } - } - } - - if (useThis) { - this.nextEvents.push({ - objId: obj.id, - type: obj.resolved.isKeyframe ? EventType.KEYFRAME : EventType.START, - time: instance.start, - }) - } - } - if ( - instance.end !== null && - instance.end > this.options.time && - instance.end < (this.options.limitTime ?? Infinity) - ) { - let useThis = true - if (hasKeyframes) { - if (!obj.resolved.isKeyframe) { - objectInstanceEndTimes.add(`${obj.id}_${instance.end}`) - } else { - // No need to put keyframe event if its parent ends at the same time: - if (objectInstanceEndTimes.has(`${obj.resolved.parentId}_${instance.end}`)) { - useThis = false - } - } - } - - if (useThis) { - this.nextEvents.push({ - objId: obj.id, - type: obj.resolved.isKeyframe ? EventType.KEYFRAME : EventType.END, - time: instance.end, - }) - } - } - } - } - this.nextEvents.sort(compareNextEvents) - toc() - } -} - -function compareNextEvents(a: NextEvent, b: NextEvent): number { - return a.time - b.time || b.type - a.type || compareStrings(a.objId, b.objId) } From 811f0b388766657b9797bdfdf3e79343ccd6396b Mon Sep 17 00:00:00 2001 From: Johan Nyman Date: Thu, 26 Sep 2024 14:57:01 +0200 Subject: [PATCH 2/5] fix: slight performance improvement --- src/resolver/ResolvedTimelineHandler.ts | 30 ++++++++++++++++++------- 1 file changed, 22 insertions(+), 8 deletions(-) diff --git a/src/resolver/ResolvedTimelineHandler.ts b/src/resolver/ResolvedTimelineHandler.ts index f7a00719..d50ab484 100644 --- a/src/resolver/ResolvedTimelineHandler.ts +++ b/src/resolver/ResolvedTimelineHandler.ts @@ -920,23 +920,37 @@ export class ResolvedTimelineHandler { } } } - private getObjectsLayers(objs: IterableIterator | ResolvedTimelineObject[]): string[] { - const layers = new Set() + private getLayersForObjects(objs: IterableIterator | ResolvedTimelineObject[]): string[] { + const sortedLayers = this.getAllObjectLayers() + + /** Map of layer and object count */ + const usedLayers = new Set() for (const obj of objs) { if (objHasLayer(obj)) { - layers.add(`${obj.layer}`) + usedLayers.add(`${obj.layer}`) } } - - return Array.from(layers.values()) + // Return the layers that are used by the objects, in the correct order: + return sortedLayers.filter((layer) => usedLayers.has(layer)) } + /** Cache of all layers, sorted by object count ASC */ private allObjectLayersCache: string[] | undefined - /** Returns a list of all object's layers */ + /** + * Returns a list of all object's layers, sorted by object count ASC + * Note: The order of the layers is important from a performance perspective. + * By feeding layers with a low object count first into this.resolveConflictsForLayer(), + * there is a higher likelihood that a conflict from a low-count layer will affect an object on + * a high-count layer, so it can be skipped in this iteration. + */ private getAllObjectLayers(): string[] { if (!this.allObjectLayersCache) { // Cache this, since this won't change: - this.allObjectLayersCache = this.getObjectsLayers(this.objectsMap.values()) + + // Sort the layers by count ASC: + this.allObjectLayersCache = Array.from(this.layersMap.entries()) + .sort((a, b) => a[1].length - b[1].length) + .map(([layer, _count]) => layer) } return this.allObjectLayersCache } @@ -1069,7 +1083,7 @@ export class ResolvedTimelineHandler { if (objs === null) { layers = this.getAllObjectLayers() } else { - layers = this.getObjectsLayers(objs) + layers = this.getLayersForObjects(objs) } for (const layer of layers) { From 7e8de97cc2cd00115f12f7b37012ef3eda18aef3 Mon Sep 17 00:00:00 2001 From: Johan Nyman Date: Thu, 26 Sep 2024 14:58:00 +0200 Subject: [PATCH 3/5] fix: improved tracing of resolver, for better troubleshooting of resolving issues in production --- src/__tests__/basic.spec.ts | 2 + src/__tests__/index.spec.ts | 65 +++++++++++++++++ src/api/resolvedTimeline.ts | 3 + src/api/resolver.ts | 8 ++- src/resolver/CacheHandler.ts | 69 ++++++++++++++---- src/resolver/LayerStateHandler.ts | 30 ++++---- src/resolver/ResolvedTimelineHandler.ts | 74 +++++++++++++------ src/resolver/ResolverHandler.ts | 94 +++++++++++++++---------- src/resolver/StateHandler.ts | 4 +- src/resolver/lib/Error.ts | 12 ++++ 10 files changed, 270 insertions(+), 91 deletions(-) create mode 100644 src/resolver/lib/Error.ts diff --git a/src/__tests__/basic.spec.ts b/src/__tests__/basic.spec.ts index b73e5e5a..9d5d7033 100644 --- a/src/__tests__/basic.spec.ts +++ b/src/__tests__/basic.spec.ts @@ -1,6 +1,7 @@ /* eslint-disable jest/no-standalone-expect */ import { EventType, ResolvedTimelineObject, TimelineObjectInstance, getResolvedState, resolveTimeline } from '..' + import { baseInstances } from '../resolver/lib/instance' import { describeVariants } from './testlib' @@ -1695,6 +1696,7 @@ describeVariants( resolvedKeyframeCount: 0, resolvingObjectCount: 0, resolvingCount: 0, + resolveTrace: [], }) }) test('Class state overrides', () => { diff --git a/src/__tests__/index.spec.ts b/src/__tests__/index.spec.ts index 096725fb..87f4cc54 100644 --- a/src/__tests__/index.spec.ts +++ b/src/__tests__/index.spec.ts @@ -8,6 +8,7 @@ import { getResolvedState, applyKeyframeContent, } from '../index' +import { ResolveError } from '../resolver/lib/Error' import { baseInstances } from '../resolver/lib/instance' import { clone } from '../resolver/lib/lib' @@ -879,4 +880,68 @@ describe('index', () => { expect(state1.layers['layerA']).toEqual(state1NoCache.layers['layerA']) }) + test('traceResolving', () => { + const timeline: TimelineObject[] = [ + { + id: 'A', + layer: 'L', + enable: { start: 100, duration: 1 }, + content: {}, + priority: 0, + }, + ] + + const resolved = resolveTimeline(timeline, { + cache: {}, + time: 0, + traceResolving: true, + }) + + // Note: The exact content of the trace isn't that important, since it's for troubleshooting purposes + expect(resolved.statistics.resolveTrace).toMatchObject([ + 'init', + 'resolveTimeline start', + 'timeline object count 1', + 'objects: 1', + 'using cache', + 'cache: init', + 'cache: canUseIncomingCache: false', + 'cache: cached objects: []', + 'cache: object "A" is new', + 'Resolver: Step 1a', + 'Resolver: Resolve object "A"', + 'Resolver: object "A" resolved.instances: [{"id":"@A_0","start":100,"end":101,"references":[]}]', + 'Resolver: object "A" directReferences: []', + 'Resolver: Step 1b', + 'Resolver: Resolve conflicts for layers: ["L"]', + 'LayerState: Resolve conflicts for layer "L", objects: A', + 'Resolver: Step 2', + 'resolveTimeline done!', + ]) + }) + test('thrown errors should be ResolveError', () => { + const timeline: TimelineObject[] = [ + { + id: 'A', + layer: 'L', + enable: { start: 'badexpression((' }, + content: {}, + priority: 0, + }, + ] + + { + let error: any = null + try { + resolveTimeline(timeline, { + time: 0, + traceResolving: true, + }) + } catch (e) { + error = e + } + expect(error).toBeInstanceOf(ResolveError) + expect(error.resolvedTimeline).toBeTruthy() + } + }) }) diff --git a/src/api/resolvedTimeline.ts b/src/api/resolvedTimeline.ts index db49eb21..40a7b928 100644 --- a/src/api/resolvedTimeline.ts +++ b/src/api/resolvedTimeline.ts @@ -48,6 +48,9 @@ export interface ResolvedTimeline { * (is affected when using cache) */ resolvingCount: number + + /** If traceResolving option is enabled, will contain a trace of the steps the resolver did while resolving */ + resolveTrace: string[] } /** Is set if there was an error during Resolving and options.dontThrowOnError is set. */ error?: Error diff --git a/src/api/resolver.ts b/src/api/resolver.ts index 9b9bcdbf..ddbd9d21 100644 --- a/src/api/resolver.ts +++ b/src/api/resolver.ts @@ -37,6 +37,12 @@ export interface ResolveOptions { */ debug?: boolean + /** + * If true, will store traces of the resolving into resolvedTimeline.statistics.resolveTrace. + * This decreases performance slightly. + */ + traceResolving?: boolean + /** * Skip timeline validation. * This improves performance slightly, but will not catch errors in the input timeline so use with caution. @@ -46,7 +52,7 @@ export interface ResolveOptions { /** Skip generating statistics, this improves performance slightly. */ skipStatistics?: boolean - /** Don't throw when an error (such as circular dependency) occurs. The Error will instead be written to resolvedTimeline.error */ + /** Don't throw when a timeline-error (such as circular dependency) occurs. The Error will instead be written to resolvedTimeline.error */ dontThrowOnError?: boolean } export interface ResolverCache { diff --git a/src/resolver/CacheHandler.ts b/src/resolver/CacheHandler.ts index 0dfd6292..bbb88644 100644 --- a/src/resolver/CacheHandler.ts +++ b/src/resolver/CacheHandler.ts @@ -25,14 +25,19 @@ export class CacheHandler { this.canUseIncomingCache = true } + if (this.resolvedTimeline.traceResolving) { + this.resolvedTimeline.addResolveTrace(`cache: init`) + this.resolvedTimeline.addResolveTrace(`cache: canUseIncomingCache: ${this.canUseIncomingCache}`) + this.resolvedTimeline.addResolveTrace( + `cache: cached objects: ${JSON.stringify(Object.keys(cache.objects))}` + ) + } + // cache.canBeUsed will be set in this.persistData() cache.canBeUsed = false this.cache = cache as ResolverCache } - private debug(...args: any[]) { - if (this.resolvedTimeline.options.debug) console.log(...args) - } public determineChangedObjects(): void { const toc = tic(' cache.determineChangedObjects') // Go through all new objects, and determine whether they have changed: @@ -45,8 +50,15 @@ export class CacheHandler { const newHash = hashTimelineObject(obj) allNewObjects[obj.id] = true - if (!oldHash) this.debug(`Cache: Object "${obj.id}" is new`) - else if (oldHash !== newHash) this.debug(`Cache: Object "${obj.id}" has changed`) + if (!oldHash) { + if (this.resolvedTimeline.traceResolving) { + this.resolvedTimeline.addResolveTrace(`cache: object "${obj.id}" is new`) + } + } else if (oldHash !== newHash) { + if (this.resolvedTimeline.traceResolving) { + this.resolvedTimeline.addResolveTrace(`cache: object "${obj.id}" has changed`) + } + } if ( // Object is new: !oldHash || @@ -61,7 +73,11 @@ export class CacheHandler { } else { // No timing-affecting changes detected /* istanbul ignore if */ - if (!oldHash) this.debug(`Cache: Object "${obj.id}" is similar`) + if (!oldHash) { + if (this.resolvedTimeline.traceResolving) { + this.resolvedTimeline.addResolveTrace(`cache: object "${obj.id}" is similar`) + } + } // Even though the timeline-properties hasn't changed, // the content (and other properties) might have: @@ -69,8 +85,8 @@ export class CacheHandler { /* istanbul ignore if */ if (!oldObj) { - console.error('oldHash', oldHash) - console.error('ids', Object.keys(this.cache.objects)) + console.error(`oldHash: "${oldHash}"`) + console.error(`ids: ${JSON.stringify(Object.keys(this.cache.objects))}`) throw new Error(`Internal Error: obj "${obj.id}" not found in cache, even though hashes match!`) } @@ -149,15 +165,28 @@ export class CacheHandler { for (const reference of changedTracker.listChanged()) { invalidator.invalidateObjectsWithReference(reference) } + if (this.resolvedTimeline.traceResolving) { + this.resolvedTimeline.addResolveTrace( + `cache: changed references: ${JSON.stringify(Array.from(changedTracker.listChanged()))}` + ) + this.resolvedTimeline.addResolveTrace( + `cache: invalidated objects: ${JSON.stringify(Array.from(invalidator.getInValidObjectIds()))}` + ) + this.resolvedTimeline.addResolveTrace( + `cache: unchanged objects: ${JSON.stringify(invalidator.getValidObjects().map((o) => o.id))}` + ) + } // At this point, the objects that are left in validObjects are still valid (ie has not changed or is affected by any others). // We can reuse the old resolving for those: for (const obj of invalidator.getValidObjects()) { - if (!this.cache.objects[obj.id]) + if (!this.cache.objects[obj.id]) { /* istanbul ignore next */ throw new Error( - `Something went wrong: "${obj.id}" does not exist in cache.resolvedTimeline.objects` + `Internal Error: Something went wrong: "${obj.id}" does not exist in cache.resolvedTimeline.objects` ) + } + this.resolvedTimeline.objectsMap.set(obj.id, this.cache.objects[obj.id]) } } @@ -210,21 +239,26 @@ function getAllReferencesThisObjectAffects(newObj: ResolvedTimelineObject): Refe } return references } +/** + * Keeps track of which timeline object have been changed + */ class ChangedTracker { private changedReferences = new Set() + /** + * Mark an object as "has changed". + * Will store all references that are affected by this object. + */ public addChangedObject(obj: ResolvedTimelineObject) { - const references = getAllReferencesThisObjectAffects(obj) - for (const ref of references) { + for (const ref of getAllReferencesThisObjectAffects(obj)) { this.changedReferences.add(ref) } - if (objHasLayer(obj)) { - this.changedReferences.add(`$${obj.layer}`) - } } + /** Returns true if a reference has changed */ public isChanged(ref: Reference): boolean { return this.changedReferences.has(ref) } + /** Returns a list of all changed references */ public listChanged(): IterableIterator { return this.changedReferences.keys() } @@ -236,6 +270,7 @@ class Invalidator { /** All references that depend on another reference (ie objects, class or layers): */ private affectReferenceMap: { [ref: Reference]: Reference[] } = {} private validObjects: ResolvedTimelineObjects = {} + private inValidObjectIds: string[] = [] /** Map of which objects can be affected by any other object, per layer */ private objectLayerMap: { [layer: string]: string[] } = {} @@ -245,6 +280,9 @@ class Invalidator { public getValidObjects(): ResolvedTimelineObject[] { return Object.values(this.validObjects) } + public getInValidObjectIds(): string[] { + return this.inValidObjectIds + } public addObjectOnLayer(layer: string, obj: ResolvedTimelineObject) { if (!this.objectLayerMap[layer]) this.objectLayerMap[layer] = [] this.objectLayerMap[layer].push(obj.id) @@ -263,6 +301,7 @@ class Invalidator { const objId = getRefObjectId(reference) if (this.validObjects[objId]) { delete this.validObjects[objId] + this.inValidObjectIds.push(objId) } } if (isLayerReference(reference)) { diff --git a/src/resolver/LayerStateHandler.ts b/src/resolver/LayerStateHandler.ts index 28b28194..b148e1c4 100644 --- a/src/resolver/LayerStateHandler.ts +++ b/src/resolver/LayerStateHandler.ts @@ -26,9 +26,6 @@ export class LayerStateHandler { this.objectsOnLayer = [] this.objectIdsOnLayer = this.resolvedTimeline.getLayerObjects(layer) } - private debug(...args: any[]) { - if (this.resolvedTimeline.options.debug) console.log(...args) - } /** Resolve conflicts between objects on the layer. */ public resolveConflicts(): void { @@ -45,6 +42,12 @@ export class LayerStateHandler { for (const objId of this.objectIdsOnLayer) { this.objectsOnLayer.push(this.resolvedTimeline.getObject(objId)) } + if (this.resolvedTimeline.traceResolving) + this.resolvedTimeline.addResolveTrace( + `LayerState: Resolve conflicts for layer "${this.layer}", objects: ${this.objectsOnLayer + .map((o) => o.id) + .join(', ')}` + ) // Fast-path: if there's only one object on the layer, it can't conflict with anything if (this.objectsOnLayer.length === 1) { @@ -59,8 +62,6 @@ export class LayerStateHandler { return } - this.debug(`======= resolveConflicts "${this.layer}" (${this.objectsOnLayer.length} objects)`) - // Sort to make sure parent groups are evaluated before their children: this.objectsOnLayer.sort(compareObjectsOnLayer) @@ -109,7 +110,7 @@ export class LayerStateHandler { // Iterate through all points-of-interest times: for (const time of times) { - this.debug(`-------------- time: ${time}`) + const traceConflicts: string[] = [] /** A set of identifiers for which instance-events have been check at this point in time. Used to avoid looking at the same object twice. */ const checkedThisTime = new Set() @@ -169,10 +170,10 @@ export class LayerStateHandler { // Cap the old instance, so it'll end at this point in time: this.instance.setInstanceEndTime(prevObjInstance.instance, time) - this.debug(`${prevObjInstance.id} stop`) - // Update activeObjIds: delete activeObjIds[prevObjInstance.id] + + if (this.resolvedTimeline.traceResolving) traceConflicts.push(`${prevObjInstance.id} stop`) } } @@ -181,8 +182,6 @@ export class LayerStateHandler { const currentObj = instanceOnTopOfLayer.obj - this.debug(`${currentObj.id} play`) - const newInstance: TimelineObjectInstance = { ...instanceOnTopOfLayer.instance, // We're setting new start & end times so they match up with the state: @@ -212,12 +211,20 @@ export class LayerStateHandler { // Update activeObjIds: activeObjIds[newObjInstance.id] = newObjInstance + + if (this.resolvedTimeline.traceResolving) traceConflicts.push(`${newObjInstance.id} start`) } else if (removeOld) { // Remove from current state: currentState = undefined + + if (this.resolvedTimeline.traceResolving) traceConflicts.push(`-nothing-`) } } } + if (this.resolvedTimeline.traceResolving) + this.resolvedTimeline.addResolveTrace( + `LayerState: Layer "${this.layer}": time: ${time}: ${traceConflicts.join(', ')}` + ) } // At this point, the instances of all objects are calculated, // taking into account priorities, clashes etc. @@ -247,8 +254,6 @@ export class LayerStateHandler { } } - this.debug('==== resolveConflicts done') - toc() } /** Add an instance and event to a certain point-in-time */ @@ -259,7 +264,6 @@ export class LayerStateHandler { instance: TimelineObjectInstance ) { // Note on order: Ending events come before starting events - this.debug('addPointInTime', time, instanceEvent, instance) if (!this.pointsInTime[time + '']) this.pointsInTime[time + ''] = [] this.pointsInTime[time + ''].push({ obj, instance, instanceEvent }) diff --git a/src/resolver/ResolvedTimelineHandler.ts b/src/resolver/ResolvedTimelineHandler.ts index d50ab484..ab9a489b 100644 --- a/src/resolver/ResolvedTimelineHandler.ts +++ b/src/resolver/ResolvedTimelineHandler.ts @@ -1,9 +1,15 @@ import { ExpressionHandler } from './ExpressionHandler' import { ObjectRefType, ReferenceHandler } from './ReferenceHandler' import { Expression } from '../api/expression' -import { ResolvedTimeline, ResolvedTimelineObject, TimelineObjectInstance } from '../api/resolvedTimeline' +import { + EventType, + NextEvent, + ResolvedTimeline, + ResolvedTimelineObject, + TimelineObjectInstance, +} from '../api/resolvedTimeline' import { Content, TimelineEnable, TimelineKeyframe, TimelineObject } from '../api/timeline' -import { assertNever, ensureArray, isArray, literal, pushToArray } from './lib/lib' +import { assertNever, compareStrings, ensureArray, isArray, literal, mapToObject, pushToArray } from './lib/lib' import { InstanceHandler } from './InstanceHandler' import { ValueWithReference, @@ -59,6 +65,8 @@ export class ResolvedTimelineHandler { private debug: boolean + private _resolveTrace: string[] = [] + /** * A Map of strings (instance hashes) that is used to determine if an objects instances have changed. * Maps objectId -> instancesHash @@ -82,12 +90,15 @@ export class ResolvedTimelineHandler { /** Error message, is set when an error is encountered and this.options.dontThrowOnError is set */ private _resolveError: Error | undefined = undefined + public readonly traceResolving: boolean + constructor(public options: ResolveOptions) { this.expression = new ExpressionHandler(false, this.options.skipValidation) this.instance = new InstanceHandler(this) this.reference = new ReferenceHandler(this, this.instance) this.debug = this.options.debug ?? false + this.traceResolving = this.options.traceResolving || this.debug } public get resolveError(): Error | undefined { return this._resolveError @@ -101,7 +112,6 @@ export class ResolvedTimelineHandler { /** Resolve the timeline. */ public resolveAllTimelineObjs(): void { const toc = tic(' resolveAllTimelineObjs') - this.debugTrace('=================================== resolveAllTimelineObjs') // Step 0: Preparations: @@ -124,6 +134,7 @@ export class ResolvedTimelineHandler { */ // Step 1a: Resolve all objects: + if (this.traceResolving) this.addResolveTrace('Resolver: Step 1a') for (const obj of this.objectsMap.values()) { this.resolveTimelineObj(obj) @@ -134,11 +145,13 @@ export class ResolvedTimelineHandler { if (this._resolveError) return // Abort on error // Step 1b: Resolve conflicts for all objects: + if (this.traceResolving) this.addResolveTrace('Resolver: Step 1b') this.resolveConflictsForObjs(null) if (this._resolveError) return // Abort on error // Step 2: re-resolve all changed objects, until no more changes are detected: + if (this.traceResolving) this.addResolveTrace('Resolver: Step 2') while (this.objectsToReResolve.size > 0) { if (this.objectResolveCount >= objectResolveCountMax) { const error = new Error( @@ -156,14 +169,11 @@ export class ResolvedTimelineHandler { } } - /* istanbul ignore if */ - if (this.debug) { - this.debugTrace(`---------------------------------`) - this.debugTrace(`objectsToReResolve: [${Array.from(this.objectsToReResolve.entries())}]`) - this.debugTrace( - `directReferences: [${Array.from(this.directReferenceMap.entries()).map( - ([key, value]) => `${key}: [${value}]` - )}]` + if (this.traceResolving) { + this.addResolveTrace( + `Resolver: Step 2: objectsToReResolve: ${JSON.stringify( + Array.from(this.objectsToReResolve.keys()) + )}` ) } @@ -219,6 +229,7 @@ export class ResolvedTimelineHandler { } if (obj.resolved.resolvedReferences) return // already resolved const toc = tic(' resolveTimelineObj') + obj.resolved.resolving = true this.statisticResolvingCount++ @@ -226,7 +237,8 @@ export class ResolvedTimelineHandler { this.statisticResolvingObjectCount++ } - this.debugTrace(`============ resolving "${obj.id}"`) + if (this.traceResolving) this.addResolveTrace(`Resolver: Resolve object "${obj.id}"`) + const directReferences: Reference[] = [] let resultingInstances: TimelineObjectInstance[] = [] @@ -553,9 +565,11 @@ export class ResolvedTimelineHandler { obj.resolved.resolving = false obj.resolved.instances = resultingInstances - if (this.debug) { - this.debugTrace(`directReferences "${obj.id}": ${JSON.stringify(directReferences)}`) - this.debugTrace(`resolved "${obj.id}": ${JSON.stringify(obj.resolved.instances)}`) + if (this.traceResolving) { + this.addResolveTrace( + `Resolver: object "${obj.id}" resolved.instances: ${JSON.stringify(obj.resolved.instances)}` + ) + this.addResolveTrace(`Resolver: object "${obj.id}" directReferences: ${JSON.stringify(directReferences)}`) } // Finally: @@ -573,6 +587,7 @@ export class ResolvedTimelineHandler { resolvedKeyframeCount: 0, resolvingObjectCount: 0, resolvingCount: 0, + resolveTrace: this._resolveTrace, } } const statistics: ResolvedTimeline['statistics'] = { @@ -584,6 +599,7 @@ export class ResolvedTimelineHandler { resolvingObjectCount: this.statisticResolvingObjectCount, resolvingCount: this.statisticResolvingCount, + resolveTrace: this._resolveTrace, } for (const obj of this.objectsMap.values()) { @@ -780,6 +796,11 @@ export class ResolvedTimelineHandler { return cappedInstances } + public addResolveTrace(message: string): void { + this._resolveTrace.push(message) + if (this.debug) console.log(message) + } + public getResolvedTimeline(): ResolvedTimeline { return literal>({ objects: mapToObject(this.objectsMap), @@ -976,6 +997,9 @@ export class ResolvedTimelineHandler { } } + /** + * Add timelineObject or keyframe + */ private _addTimelineObject( obj: TimelineObject, /** A number that increases the more levels inside of a group the objects is. 0 = no parent */ @@ -1086,6 +1110,9 @@ export class ResolvedTimelineHandler { layers = this.getLayersForObjects(objs) } + if (this.traceResolving) + this.addResolveTrace(`Resolver: Resolve conflicts for layers: ${JSON.stringify(layers)}`) + for (const layer of layers) { const maybeChangedObjs = this.resolveConflictsForLayer(layer) @@ -1108,7 +1135,10 @@ export class ResolvedTimelineHandler { // Because the objects will likely change during the next resolve-iteration anyway. for (const objId of handler.objectIdsOnLayer) { if (this.objectsToReResolve.has(objId)) { - this.debugTrace(`optimization: Skipping "${layer}" since "${objId}" changed`) + if (this.traceResolving) + this.addResolveTrace( + `Resolver: Skipping resolve conflicts for layer "${layer}" since "${objId}" changed` + ) return [] } } @@ -1141,7 +1171,10 @@ export class ResolvedTimelineHandler { ) if (this.changedObjIdsExplanations.length > 2) this.changedObjIdsExplanations.shift() - this.debugTrace(`changed: ${obj.id}: "${prevHash}" -> "${instancesHash}"`) + if (this.traceResolving) + this.addResolveTrace( + `Resolver: Object ${obj.id} changed from: "${prevHash}", to "${instancesHash}"` + ) changedObjs.add(obj.id) this.resolvedObjInstancesHash.set(obj.id, instancesHash) @@ -1158,14 +1191,13 @@ export class ResolvedTimelineHandler { // Note: obj.resolved.resolvedConflicts will be set to false later when resolving references this.objectsToReResolve.set(obj.id, obj) + + if (this.traceResolving) + this.addResolveTrace(`Resolver: Will re-resolve object ${obj.id} due to "${changedObjId}"`) } } toc() } - - private debugTrace(...args: any[]) { - if (this.debug) console.log(...args) - } } function compareEvents(a: T, b: T): number { diff --git a/src/resolver/ResolverHandler.ts b/src/resolver/ResolverHandler.ts index fd318be2..807857f9 100644 --- a/src/resolver/ResolverHandler.ts +++ b/src/resolver/ResolverHandler.ts @@ -1,12 +1,11 @@ import { ResolvedTimelineHandler } from './ResolvedTimelineHandler' -import { EventType, NextEvent, ResolvedTimeline, ResolvedTimelineObject } from '../api/resolvedTimeline' +import { ResolvedTimeline } from '../api/resolvedTimeline' import { ResolveOptions } from '../api/resolver' import { Content, TimelineObject } from '../api/timeline' -import { compareStrings, literal, mapToObject } from './lib/lib' import { tic } from './lib/performance' import { CacheHandler } from './CacheHandler' -import { objHasLayer } from './lib/timeline' import { TimelineValidator } from './TimelineValidator' +import { ResolveError } from './lib/Error' /** * Note: A Resolver instance is short-lived and used to resolve a timeline. @@ -17,8 +16,6 @@ import { TimelineValidator } from './TimelineValidator' export class ResolverHandler { private hasRun = false - private nextEvents: NextEvent[] = [] - private resolvedTimeline: ResolvedTimelineHandler private validator: TimelineValidator @@ -27,6 +24,9 @@ export class ResolverHandler { const toc = tic('new Resolver') this.resolvedTimeline = new ResolvedTimelineHandler(this.options) this.validator = new TimelineValidator() + if (this.options.traceResolving) { + this.resolvedTimeline.addResolveTrace(`init`) + } toc() } /** @@ -34,48 +34,64 @@ export class ResolverHandler { * This method can only be run once per Resolver instance. */ public resolveTimeline(timeline: TimelineObject[]): ResolvedTimeline { - const toc = tic('resolveTimeline') - /* istanbul ignore if */ - if (this.hasRun) - throw new Error( - `Resolver.resolveTimeline can only run once per instance! -Usage: -const resolver = new Resolver(options); -resolver.run(timeline);` - ) - this.hasRun = true + try { + const toc = tic('resolveTimeline') + /* istanbul ignore if */ + if (this.hasRun) { + if (this.options.traceResolving) this.resolvedTimeline.addResolveTrace(`Error: has already run`) + throw new Error( + `Resolver.resolveTimeline can only run once per instance! + Usage: + const resolver = new Resolver(options); + resolver.run(timeline);` + ) + } + this.hasRun = true - // Step 0: Validate the timeline: - if (!this.options.skipValidation) { - this.validator.validateTimeline(timeline, false) - } + if (this.options.traceResolving) { + this.resolvedTimeline.addResolveTrace(`resolveTimeline start`) + this.resolvedTimeline.addResolveTrace(`timeline object count ${timeline.length}`) + } - // Step 1: Populate ResolvedTimeline with the timeline: - for (const obj of timeline) { - this.resolvedTimeline.addTimelineObject(obj) - } + // Step 0: Validate the timeline: + if (!this.options.skipValidation) { + this.validator.validateTimeline(timeline, false) + } - // Step 2: Use cache: - let cacheHandler: CacheHandler | undefined - if (this.options.cache) { - cacheHandler = this.resolvedTimeline.initializeCache(this.options.cache) + // Step 1: Populate ResolvedTimeline with the timeline: + for (const obj of timeline) { + this.resolvedTimeline.addTimelineObject(obj) + } + if (this.options.traceResolving) { + this.resolvedTimeline.addResolveTrace(`objects: ${this.resolvedTimeline.objectsMap.size}`) + } - cacheHandler.determineChangedObjects() - } + // Step 2: Use cache: + let cacheHandler: CacheHandler | undefined + if (this.options.cache) { + if (this.options.traceResolving) this.resolvedTimeline.addResolveTrace(`using cache`) - // Step 3: Go through and resolve all objects: - this.resolvedTimeline.resolveAllTimelineObjs() + cacheHandler = this.resolvedTimeline.initializeCache(this.options.cache) - // Step 5: persist cache - if (cacheHandler) { - cacheHandler.persistData() - } + cacheHandler.determineChangedObjects() + } - if (this.options.traceResolving) this.resolvedTimeline.addResolveTrace(`resolveTimeline done!`) + // Step 3: Go through and resolve all objects: + this.resolvedTimeline.resolveAllTimelineObjs() - const resolvedTimeline: ResolvedTimeline = this.resolvedTimeline.getResolvedTimeline() + // Step 5: persist cache + if (cacheHandler) { + cacheHandler.persistData() + } - toc() - return resolvedTimeline + if (this.options.traceResolving) this.resolvedTimeline.addResolveTrace(`resolveTimeline done!`) + + const resolvedTimeline: ResolvedTimeline = this.resolvedTimeline.getResolvedTimeline() + + toc() + return resolvedTimeline + } catch (e) { + throw new ResolveError(e, this.resolvedTimeline.getResolvedTimeline()) + } } } diff --git a/src/resolver/StateHandler.ts b/src/resolver/StateHandler.ts index 076eda96..ec0eaf2c 100644 --- a/src/resolver/StateHandler.ts +++ b/src/resolver/StateHandler.ts @@ -40,8 +40,8 @@ export class StateHandler { /* istanbul ignore if */ if (state.layers[`${obj.layer}`]) { // There is already an object on this layer! - console.error(state.layers[`${obj.layer}`]) - console.error(objInstance) + console.error(`layer "${obj.layer}": ${JSON.stringify(state.layers[`${obj.layer}`])}`) + console.error(`object "${objInstance.id}": ${JSON.stringify(objInstance)}`) throw new Error(`Internal Error: There is already an object on layer "${obj.layer}"!`) } diff --git a/src/resolver/lib/Error.ts b/src/resolver/lib/Error.ts new file mode 100644 index 00000000..b93eac2c --- /dev/null +++ b/src/resolver/lib/Error.ts @@ -0,0 +1,12 @@ +import { ResolvedTimeline } from '../../api' + +export class ResolveError extends Error { + constructor(e: unknown, public readonly resolvedTimeline: ResolvedTimeline) { + super(e instanceof Error ? e.message : `${e}`) + + this.name = 'ResolveError' + if (e instanceof Error) { + this.stack = e.stack + } + } +} From fd80f855e577fa2b649b9f564325c4be96f91587 Mon Sep 17 00:00:00 2001 From: Johan Nyman Date: Thu, 3 Oct 2024 08:45:23 +0200 Subject: [PATCH 4/5] fix: reset cache in case of thrown error during resolve --- src/resolver/CacheHandler.ts | 9 +++++++-- src/resolver/ResolverHandler.ts | 5 +++++ 2 files changed, 12 insertions(+), 2 deletions(-) diff --git a/src/resolver/CacheHandler.ts b/src/resolver/CacheHandler.ts index bbb88644..60e80d93 100644 --- a/src/resolver/CacheHandler.ts +++ b/src/resolver/CacheHandler.ts @@ -17,8 +17,7 @@ export class CacheHandler { if (!cache.canBeUsed) { // Reset the cache: - cache.objHashes = {} - cache.objects = {} + CacheHandler.resetCache(cache) this.canUseIncomingCache = false } else { @@ -208,6 +207,12 @@ export class CacheHandler { toc() } + /** Resets / Clears the cache */ + static resetCache(cache: Partial): void { + delete cache.canBeUsed + cache.objHashes = {} + cache.objects = {} + } } /** Return a "hash-string" which changes whenever anything that affects timing of a timeline-object has changed. */ export function hashTimelineObject(obj: ResolvedTimelineObject): string { diff --git a/src/resolver/ResolverHandler.ts b/src/resolver/ResolverHandler.ts index 807857f9..e3d21524 100644 --- a/src/resolver/ResolverHandler.ts +++ b/src/resolver/ResolverHandler.ts @@ -91,6 +91,11 @@ export class ResolverHandler { toc() return resolvedTimeline } catch (e) { + if (this.options.cache) { + // Reset cache, since it might be corrupt. + CacheHandler.resetCache(this.options.cache) + } + throw new ResolveError(e, this.resolvedTimeline.getResolvedTimeline()) } } From 7723b89b6c02385254eb51b6c1bf5025b7505697 Mon Sep 17 00:00:00 2001 From: Johan Nyman Date: Thu, 3 Oct 2024 08:47:59 +0200 Subject: [PATCH 5/5] chore: fix export --- src/__tests__/index.spec.ts | 2 +- src/index.ts | 1 + 2 files changed, 2 insertions(+), 1 deletion(-) diff --git a/src/__tests__/index.spec.ts b/src/__tests__/index.spec.ts index 87f4cc54..a50bb44d 100644 --- a/src/__tests__/index.spec.ts +++ b/src/__tests__/index.spec.ts @@ -7,8 +7,8 @@ import { resolveTimeline, getResolvedState, applyKeyframeContent, + ResolveError, } from '../index' -import { ResolveError } from '../resolver/lib/Error' import { baseInstances } from '../resolver/lib/instance' import { clone } from '../resolver/lib/lib' diff --git a/src/index.ts b/src/index.ts index 3c8324df..b77d4d30 100644 --- a/src/index.ts +++ b/src/index.ts @@ -11,6 +11,7 @@ import { TimelineObject, } from './api' export * from './api' +export { ResolveError } from './resolver/lib/Error' import { StateHandler } from './resolver/StateHandler' import { ExpressionHandler } from './resolver/ExpressionHandler'