From 371474323cfec9c7688810867472ebd026d0bd0e Mon Sep 17 00:00:00 2001 From: Tobias Ortmayr Date: Tue, 1 Oct 2024 11:37:49 +0200 Subject: [PATCH] Improve performance tracking Measure actions when they are actually handled instead of on dispatch (avoids inconsistencies due to action queue blocking) Add in depth logging for set-model-command and model update --- .../src/performance/per-set-model-command.ts | 21 +++++++ .../src/performance/perf-action-dispatcher.ts | 10 ++-- .../src/performance/perf-diagram-loader.ts | 35 ++++++++++- .../editor/src/performance/perf-viewer.ts | 14 ----- .../editor/src/performance/perf-viewer.tsx | 59 +++++++++++++++++++ .../src/performance/performance-module.ts | 4 +- 6 files changed, 123 insertions(+), 20 deletions(-) create mode 100644 packages/editor/src/performance/per-set-model-command.ts delete mode 100644 packages/editor/src/performance/perf-viewer.ts create mode 100644 packages/editor/src/performance/perf-viewer.tsx diff --git a/packages/editor/src/performance/per-set-model-command.ts b/packages/editor/src/performance/per-set-model-command.ts new file mode 100644 index 00000000..99969ee0 --- /dev/null +++ b/packages/editor/src/performance/per-set-model-command.ts @@ -0,0 +1,21 @@ +import { CommandExecutionContext, GModelRoot, SetModelCommand } from '@eclipse-glsp/client'; +import { injectable } from 'inversify'; + +@injectable() +export class PerfSetModelCommand extends SetModelCommand { + protected counter = 0; + + execute(context: CommandExecutionContext): GModelRoot { + const counter = ++this.counter; + console.time(`execute SetModelCommand (sc) ${counter}`); + console.time(`sc-createOldRoot (${counter})`); + this.oldRoot = context.modelFactory.createRoot(context.root); + console.timeEnd(`sc-createOldRoot (${counter})`); + console.time(`sc-createNewRoot (${counter})`); + this.newRoot = context.modelFactory.createRoot(this.action.newRoot); + console.timeEnd(`sc-createNewRoot (${counter})`); + console.timeEnd(`execute SetModelCommand (sc) ${counter}`); + + return this.newRoot; + } +} diff --git a/packages/editor/src/performance/perf-action-dispatcher.ts b/packages/editor/src/performance/perf-action-dispatcher.ts index e9ba0658..1747c104 100644 --- a/packages/editor/src/performance/perf-action-dispatcher.ts +++ b/packages/editor/src/performance/perf-action-dispatcher.ts @@ -14,10 +14,12 @@ export class PerfActionDispatcher extends GLSPActionDispatcher { return result; } - override async dispatch(action: Action): Promise { + protected override async handleAction(action: Action): Promise { const counter = ++this.counter; - console.time(`dispatch-${action.kind}-${counter}`); - await super.dispatch(action); - console.timeEnd(`dispatch-${action.kind}-${counter}`); + console.time(`handleAction-${action.kind}-${counter}`); + console.log(`handleAction-${action.kind}-${counter}`, action); + const result = await super.handleAction(action); + console.timeEnd(`handleAction-${action.kind}-${counter}`); + return result; } } diff --git a/packages/editor/src/performance/perf-diagram-loader.ts b/packages/editor/src/performance/perf-diagram-loader.ts index 5d944efc..dbe07f54 100644 --- a/packages/editor/src/performance/perf-diagram-loader.ts +++ b/packages/editor/src/performance/perf-diagram-loader.ts @@ -1,4 +1,12 @@ -import { DiagramLoader, IDiagramStartup, ResolvedDiagramLoadingOptions } from '@eclipse-glsp/client'; +import { + ApplicationIdProvider, + DiagramLoader, + DiagramLoadingOptions, + GLSPClient, + IDiagramStartup, + Ranked, + ResolvedDiagramLoadingOptions +} from '@eclipse-glsp/client'; import { injectable } from 'inversify'; @injectable() @@ -20,4 +28,29 @@ export class PerfDiagramLoader extends DiagramLoader { await super.requestModel(options); console.timeEnd('DiagramLoader.requestModel'); } + + override async load(options: DiagramLoadingOptions = {}): Promise { + this.diagramStartups.sort(Ranked.sort); + await this.invokeStartupHook('preLoadDiagram'); + const resolvedOptions: ResolvedDiagramLoadingOptions = { + requestModelOptions: { + sourceUri: this.options.sourceUri ?? '', + diagramType: this.options.diagramType, + ...options.requestModelOptions + }, + initializeParameters: { + applicationId: ApplicationIdProvider.get(), + protocolVersion: GLSPClient.protocolVersion, + ...options.initializeParameters + }, + enableNotifications: options.enableNotifications ?? true + }; + await this.actionDispatcher.initialize(); + await this.invokeStartupHook('preInitialize'); + await this.initialize(resolvedOptions); + await this.invokeStartupHook('preRequestModel'); + await this.requestModel(resolvedOptions); + await this.invokeStartupHook('postRequestModel'); + this.modelInitializationConstraint.onInitialized(() => this.invokeStartupHook('postModelInitialization')); + } } diff --git a/packages/editor/src/performance/perf-viewer.ts b/packages/editor/src/performance/perf-viewer.ts deleted file mode 100644 index a6e6163d..00000000 --- a/packages/editor/src/performance/perf-viewer.ts +++ /dev/null @@ -1,14 +0,0 @@ -import { Action, GModelRoot, ModelViewer } from '@eclipse-glsp/client'; -import { injectable } from 'inversify'; - -@injectable() -export class PerfModelViewer extends ModelViewer { - protected counter = 0; - - update(model: Readonly, cause?: Action): void { - const counter = ++this.counter; - console.time('Viewer update ' + counter); - super.update(model, cause); - console.timeEnd('Viewer update ' + counter); - } -} diff --git a/packages/editor/src/performance/perf-viewer.tsx b/packages/editor/src/performance/perf-viewer.tsx new file mode 100644 index 00000000..1cbd430a --- /dev/null +++ b/packages/editor/src/performance/perf-viewer.tsx @@ -0,0 +1,59 @@ +/** @jsx html */ +// eslint-disable-next-line @typescript-eslint/no-unused-vars +import { Action, GModelRoot, ModelViewer, copyClassesFromElement, copyClassesFromVNode, html, setClass } from '@eclipse-glsp/client'; +import { injectable } from 'inversify'; + +@injectable() +export class PerfModelViewer extends ModelViewer { + protected counter = 0; + update(model: Readonly, cause?: Action): void { + const counter = ++this.counter; + console.time(`Viewer update (vu) (${counter})`); + this.logger.log(this, 'rendering', model); + console.time(`vu- renderElement (${counter})`); + const newVDOM =
{this.renderer.renderElement(model)}
; + console.timeEnd(`vu- renderElement (${counter})`); + if (this.lastVDOM !== undefined) { + const hadFocus = this.hasFocus(); + console.time(`vu- copyClassesFromVNode (${counter})`); + copyClassesFromVNode(this.lastVDOM, newVDOM); + console.timeEnd(`vu- copyClassesFromVNode (${counter})`); + console.time(`vu- patch vdom (${counter})`); + this.lastVDOM = this.patcher.call(this, this.lastVDOM, newVDOM); + console.timeEnd(`vu- patch vdom (${counter})`); + console.time(`vu- restoreFocus (${counter})`); + this.restoreFocus(hadFocus); + console.timeEnd(`vu- restoreFocus (${counter})`); + } else if (typeof document !== 'undefined') { + let placeholder = null; + if (this.options.shadowRoot) { + const shadowRoot = document.getElementById(this.options.shadowRoot)?.shadowRoot; + if (shadowRoot) { + placeholder = shadowRoot.getElementById(this.options.baseDiv); + } + } else { + placeholder = document.getElementById(this.options.baseDiv); + } + if (placeholder !== null) { + if (typeof window !== 'undefined') { + window.addEventListener('resize', () => { + this.onWindowResize(newVDOM); + }); + } + console.time(`vu- copyClassesFromElement (${counter})`); + copyClassesFromElement(placeholder, newVDOM); + setClass(newVDOM, this.options.baseClass, true); + console.timeEnd(`vu- copyClassesFromElement (${counter})`); + console.time(`vu- patch vdom (${counter})`); + this.lastVDOM = this.patcher.call(this, placeholder, newVDOM); + console.timeEnd(`vu- patch vdom (${counter})`); + } else { + this.logger.error(this, 'element not in DOM:', this.options.baseDiv); + } + } + console.time(`vu- postUpdate (${counter})`); + this.renderer.postUpdate(cause); + console.timeEnd(`vu- postUpdate (${counter})`); + console.timeEnd(`Viewer update (vu) (${counter})`); + } +} diff --git a/packages/editor/src/performance/performance-module.ts b/packages/editor/src/performance/performance-module.ts index d5eebe0b..b072aa22 100644 --- a/packages/editor/src/performance/performance-module.ts +++ b/packages/editor/src/performance/performance-module.ts @@ -1,7 +1,8 @@ -import { DiagramLoader, FeatureModule, GLSPActionDispatcher, TYPES } from '@eclipse-glsp/client'; +import { DiagramLoader, FeatureModule, GLSPActionDispatcher, SetModelCommand, TYPES } from '@eclipse-glsp/client'; import { PerfDiagramLoader } from './perf-diagram-loader'; import { PerfActionDispatcher } from './perf-action-dispatcher'; import { PerfModelViewer } from './perf-viewer'; +import { PerfSetModelCommand } from './per-set-model-command'; export function createPerformanceModule(enabled?: boolean): FeatureModule { return new FeatureModule( @@ -12,6 +13,7 @@ export function createPerformanceModule(enabled?: boolean): FeatureModule { rebind(DiagramLoader).to(PerfDiagramLoader).inSingletonScope(); rebind(GLSPActionDispatcher).to(PerfActionDispatcher).inSingletonScope(); rebind(TYPES.ModelViewer).to(PerfModelViewer).inSingletonScope(); + rebind(SetModelCommand).to(PerfSetModelCommand); }, { featureId: Symbol('performance') } );