From ff45fbd075ba89bf573cab5deda95731371e8344 Mon Sep 17 00:00:00 2001 From: mgechev Date: Wed, 28 Apr 2021 17:20:20 -0700 Subject: [PATCH] feat(devtools): implement output profiling --- .../src/lib/hooks/capture.ts | 41 ++++++++++++++++++- .../src/lib/hooks/index.ts | 14 ++++++- .../src/lib/hooks/profiler/native.ts | 16 +++++--- .../src/lib/hooks/profiler/shared.ts | 21 +++++++++- .../bargraph-visualizer.component.ts | 21 +--------- .../execution-details.component.ts | 9 +--- .../flamegraph-visualizer.component.ts | 27 +----------- .../recording-visualizer/formatter.ts | 31 ++++++++++++++ .../recording/timeline/timeline.component.ts | 1 + projects/protocol/src/lib/messages.ts | 5 +++ 10 files changed, 126 insertions(+), 60 deletions(-) create mode 100644 projects/ng-devtools/src/lib/devtools-tabs/profiler/recording/timeline/recording-visualizer/formatter.ts diff --git a/projects/ng-devtools-backend/src/lib/hooks/capture.ts b/projects/ng-devtools-backend/src/lib/hooks/capture.ts index d315e26a5ef..28c855a7316 100644 --- a/projects/ng-devtools-backend/src/lib/hooks/capture.ts +++ b/projects/ng-devtools-backend/src/lib/hooks/capture.ts @@ -43,7 +43,7 @@ const getEventStart = (map: { [key: string]: number }, directive: any, label: st return map[key]; }; -const getHooks = (onFrame: (frame: ProfilerFrame) => void) => { +const getHooks = (onFrame: (frame: ProfilerFrame) => void): Partial => { const timeStartMap: { [key: string]: number } = {}; return { // We flush here because it's possible the current node to overwrite @@ -54,6 +54,7 @@ const getHooks = (onFrame: (frame: ProfilerFrame) => void) => { name: getDirectiveName(directive), isComponent, lifecycle: {}, + outputs: {}, }); }, onChangeDetectionStart(component: any, node: Node): void { @@ -75,6 +76,7 @@ const getHooks = (onFrame: (frame: ProfilerFrame) => void) => { isComponent: true, changeDetection: 0, lifecycle: {}, + outputs: {}, }); } }, @@ -104,6 +106,7 @@ const getHooks = (onFrame: (frame: ProfilerFrame) => void) => { name: getDirectiveName(directive), isComponent, lifecycle: {}, + outputs: {}, }); } }, @@ -121,6 +124,7 @@ const getHooks = (onFrame: (frame: ProfilerFrame) => void) => { name: getDirectiveName(directive), isComponent, lifecycle: {}, + outputs: {}, }); } }, @@ -138,6 +142,33 @@ const getHooks = (onFrame: (frame: ProfilerFrame) => void) => { dir.lifecycle[hookName] = (dir.lifecycle[hookName] || 0) + duration; frameDuration += duration; }, + onOutputStart(componentOrDirective: any, outputName: string, node: Node, isComponent: boolean): void { + startEvent(timeStartMap, componentOrDirective, outputName); + if (!eventMap.has(componentOrDirective)) { + eventMap.set(componentOrDirective, { + isElement: isCustomElement(node), + name: getDirectiveName(componentOrDirective), + isComponent, + lifecycle: {}, + outputs: {}, + }); + } + }, + onOutputEnd(componentOrDirective: any, outputName: string): void { + const name = outputName; + const entry = eventMap.get(componentOrDirective); + const startTimestamp = getEventStart(timeStartMap, componentOrDirective, name); + if (startTimestamp === undefined) { + return; + } + if (!entry) { + console.warn('Could not find directive or component in onOutputEnd callback', componentOrDirective, outputName); + return; + } + const duration = performance.now() - startTimestamp; + entry.outputs[name] = (entry.outputs[name] || 0) + duration; + frameDuration += duration; + }, }; }; @@ -157,6 +188,12 @@ const insertOrMerge = (lastFrame: ElementProfile, profile: DirectiveProfile) => } d.lifecycle[key] += profile.lifecycle[key]; } + for (const key of Object.keys(profile.outputs)) { + if (!d.outputs[key]) { + d.outputs[key] = 0; + } + d.outputs[key] += profile.outputs[key]; + } } }); if (!exists) { @@ -214,6 +251,7 @@ const prepareInitialFrame = (source: string, duration: number) => { isComponent: false, isElement: false, name: getDirectiveName(d.instance), + outputs: {}, lifecycle: {}, }; }); @@ -222,6 +260,7 @@ const prepareInitialFrame = (source: string, duration: number) => { isElement: node.component.isElement, isComponent: true, lifecycle: {}, + outputs: {}, name: getDirectiveName(node.component.instance), }); } diff --git a/projects/ng-devtools-backend/src/lib/hooks/index.ts b/projects/ng-devtools-backend/src/lib/hooks/index.ts index cdf21d45add..eeabdb2135a 100644 --- a/projects/ng-devtools-backend/src/lib/hooks/index.ts +++ b/projects/ng-devtools-backend/src/lib/hooks/index.ts @@ -6,7 +6,7 @@ const markName = (s: string, method: Method) => `🅰️ ${s}#${method}`; const supportsPerformance = globalThis.performance && typeof globalThis.performance.getEntriesByName === 'function'; -type Method = keyof LifecycleProfile | 'changeDetection'; +type Method = keyof LifecycleProfile | 'changeDetection' | string; const recordMark = (s: string, method: Method) => { if (supportsPerformance) { @@ -67,6 +67,18 @@ export const initializeOrGetDirectiveForestHooks = () => { } endMark(getDirectiveName(component), lifecyle); }, + onOutputStart(component: any, output: string): void { + if (!timingAPIEnabled()) { + return; + } + recordMark(getDirectiveName(component), output); + }, + onOutputEnd(component: any, output: string): void { + if (!timingAPIEnabled()) { + return; + } + endMark(getDirectiveName(component), output); + }, }); directiveForestHooks.initialize(); return directiveForestHooks; diff --git a/projects/ng-devtools-backend/src/lib/hooks/profiler/native.ts b/projects/ng-devtools-backend/src/lib/hooks/profiler/native.ts index eed434008a6..f48ebddd1c7 100644 --- a/projects/ng-devtools-backend/src/lib/hooks/profiler/native.ts +++ b/projects/ng-devtools-backend/src/lib/hooks/profiler/native.ts @@ -110,13 +110,17 @@ export class NgProfiler extends Profiler { this._onLifecycleHookEnd(directive, lifecycleHookName, element, id, isComponent); } - [ɵProfilerEvent.OutputStart](_directive: any, _hookOrListener: any): void { - // todo: implement - return; + [ɵProfilerEvent.OutputStart](componentOrDirective: any, listener: Function): void { + const isComponent = !!this._tracker.isComponent.get(componentOrDirective); + const node = getDirectiveHostElement(componentOrDirective); + const id = this._tracker.getDirectiveId(componentOrDirective); + this._onOutputStart(componentOrDirective, listener.name, node, id, isComponent); } - [ɵProfilerEvent.OutputEnd](_directive: any, _hookOrListener: any): void { - // todo: implement - return; + [ɵProfilerEvent.OutputEnd](componentOrDirective: any, listener: Function): void { + const isComponent = !!this._tracker.isComponent.get(componentOrDirective); + const node = getDirectiveHostElement(componentOrDirective); + const id = this._tracker.getDirectiveId(componentOrDirective); + this._onOutputEnd(componentOrDirective, listener.name, node, id, isComponent); } } diff --git a/projects/ng-devtools-backend/src/lib/hooks/profiler/shared.ts b/projects/ng-devtools-backend/src/lib/hooks/profiler/shared.ts index b85178910fa..42930709225 100644 --- a/projects/ng-devtools-backend/src/lib/hooks/profiler/shared.ts +++ b/projects/ng-devtools-backend/src/lib/hooks/profiler/shared.ts @@ -38,6 +38,9 @@ type DestroyHook = ( position: ElementPosition ) => void; +type OutputStartHook = (componentOrDirective: any, outputName: string, node: Node, isComponent: boolean) => void; +type OutputEndHook = (componentOrDirective: any, outputName: string, node: Node, isComponent: boolean) => void; + export interface Hooks { onCreate: CreationHook; onDestroy: DestroyHook; @@ -45,6 +48,8 @@ export interface Hooks { onChangeDetectionEnd: ChangeDetectionEndHook; onLifecycleHookStart: LifecycleStartHook; onLifecycleHookEnd: LifecycleEndHook; + onOutputStart: OutputStartHook; + onOutputEnd: OutputEndHook; } /** @@ -148,10 +153,24 @@ export abstract class Profiler { this._invokeCallback('onLifecycleHookEnd', arguments); } + protected _onOutputStart(_: any, __: string, ___: Node, id: number | undefined, ____: boolean): void { + if (id === undefined) { + return; + } + this._invokeCallback('onOutputStart', arguments); + } + + protected _onOutputEnd(_: any, __: string, ___: Node, id: number | undefined, ____: boolean): void { + if (id === undefined) { + return; + } + this._invokeCallback('onOutputEnd', arguments); + } + private _invokeCallback(name: keyof Hooks, args: IArguments): void { this._hooks.forEach((config) => { const cb = config[name]; - if (cb) { + if (typeof cb === 'function') { cb.apply(null, args); } }); diff --git a/projects/ng-devtools/src/lib/devtools-tabs/profiler/recording/timeline/recording-visualizer/bargraph-visualizer/bargraph-visualizer.component.ts b/projects/ng-devtools/src/lib/devtools-tabs/profiler/recording/timeline/recording-visualizer/bargraph-visualizer/bargraph-visualizer.component.ts index 86b991936d2..6c0a02af972 100644 --- a/projects/ng-devtools/src/lib/devtools-tabs/profiler/recording/timeline/recording-visualizer/bargraph-visualizer/bargraph-visualizer.component.ts +++ b/projects/ng-devtools/src/lib/devtools-tabs/profiler/recording/timeline/recording-visualizer/bargraph-visualizer/bargraph-visualizer.component.ts @@ -4,6 +4,7 @@ import { ProfilerFrame } from 'protocol'; import { SelectedDirective, SelectedEntry } from '../timeline-visualizer.component'; import { Theme, ThemeService } from 'projects/ng-devtools/src/lib/theme-service'; import { Subscription } from 'rxjs'; +import { formatDirectiveProfile } from '../formatter'; @Component({ selector: 'ng-bargraph-visualizer', @@ -38,25 +39,7 @@ export class BargraphVisualizerComponent implements OnInit, OnDestroy { } formatEntryData(bargraphNode: BargraphNode): SelectedDirective[] { - const graphData: SelectedDirective[] = []; - bargraphNode.original.directives.forEach((node) => { - const { changeDetection } = node; - if (changeDetection) { - graphData.push({ - directive: node.name, - method: 'changes', - value: parseFloat(changeDetection.toFixed(2)), - }); - } - Object.keys(node.lifecycle).forEach((key) => { - graphData.push({ - directive: node.name, - method: key, - value: +node.lifecycle[key].toFixed(2), - }); - }); - }); - return graphData; + return formatDirectiveProfile(bargraphNode.original.directives); } selectNode(node: BargraphNode): void { diff --git a/projects/ng-devtools/src/lib/devtools-tabs/profiler/recording/timeline/recording-visualizer/execution-details/execution-details.component.ts b/projects/ng-devtools/src/lib/devtools-tabs/profiler/recording/timeline/recording-visualizer/execution-details/execution-details.component.ts index 719e12e1846..529aad54f2f 100644 --- a/projects/ng-devtools/src/lib/devtools-tabs/profiler/recording/timeline/recording-visualizer/execution-details/execution-details.component.ts +++ b/projects/ng-devtools/src/lib/devtools-tabs/profiler/recording/timeline/recording-visualizer/execution-details/execution-details.component.ts @@ -1,10 +1,5 @@ import { Component, Input } from '@angular/core'; - -export interface GraphNode { - directive: string; - method: string; - value: number; -} +import { SelectedDirective } from '../timeline-visualizer.component'; @Component({ selector: 'ng-execution-details', @@ -12,5 +7,5 @@ export interface GraphNode { styleUrls: ['./execution-details.component.scss'], }) export class ExecutionDetailsComponent { - @Input() data: GraphNode[]; + @Input() data: SelectedDirective[]; } diff --git a/projects/ng-devtools/src/lib/devtools-tabs/profiler/recording/timeline/recording-visualizer/flamegraph-visualizer/flamegraph-visualizer.component.ts b/projects/ng-devtools/src/lib/devtools-tabs/profiler/recording/timeline/recording-visualizer/flamegraph-visualizer/flamegraph-visualizer.component.ts index edf79a4ef1e..d88a0026cae 100644 --- a/projects/ng-devtools/src/lib/devtools-tabs/profiler/recording/timeline/recording-visualizer/flamegraph-visualizer/flamegraph-visualizer.component.ts +++ b/projects/ng-devtools/src/lib/devtools-tabs/profiler/recording/timeline/recording-visualizer/flamegraph-visualizer/flamegraph-visualizer.component.ts @@ -10,12 +10,7 @@ import { ProfilerFrame } from 'protocol'; import { SelectedDirective, SelectedEntry } from '../timeline-visualizer.component'; import { Theme, ThemeService } from 'projects/ng-devtools/src/lib/theme-service'; import { Subscription } from 'rxjs'; - -export interface GraphNode { - directive: string; - method: string; - value: number; -} +import { formatDirectiveProfile } from '../formatter'; @Component({ selector: 'ng-flamegraph-visualizer', @@ -85,25 +80,7 @@ export class FlamegraphVisualizerComponent implements OnInit, OnDestroy { } formatEntryData(flameGraphNode: FlamegraphNode): SelectedDirective[] { - const graphData: SelectedDirective[] = []; - flameGraphNode.original.directives.forEach((node) => { - const changeDetection = node.changeDetection; - if (changeDetection !== undefined) { - graphData.push({ - directive: node.name, - method: 'changes', - value: parseFloat(changeDetection.toFixed(2)), - }); - } - Object.keys(node.lifecycle).forEach((key) => { - graphData.push({ - directive: node.name, - method: key, - value: +node.lifecycle[key].toFixed(2), - }); - }); - }); - return graphData; + return formatDirectiveProfile(flameGraphNode.original.directives); } private _selectFrame(): void { diff --git a/projects/ng-devtools/src/lib/devtools-tabs/profiler/recording/timeline/recording-visualizer/formatter.ts b/projects/ng-devtools/src/lib/devtools-tabs/profiler/recording/timeline/recording-visualizer/formatter.ts new file mode 100644 index 00000000000..76860abdc9d --- /dev/null +++ b/projects/ng-devtools/src/lib/devtools-tabs/profiler/recording/timeline/recording-visualizer/formatter.ts @@ -0,0 +1,31 @@ +import { DirectiveProfile } from 'protocol'; +import { SelectedDirective } from './timeline-visualizer.component'; + +export const formatDirectiveProfile = (nodes: DirectiveProfile[]) => { + const graphData: SelectedDirective[] = []; + nodes.forEach((node) => { + const { changeDetection } = node; + if (changeDetection) { + graphData.push({ + directive: node.name, + method: 'changes', + value: parseFloat(changeDetection.toFixed(2)), + }); + } + Object.keys(node.lifecycle).forEach((key) => { + graphData.push({ + directive: node.name, + method: key, + value: +node.lifecycle[key].toFixed(2), + }); + }); + Object.keys(node.outputs).forEach((key) => { + graphData.push({ + directive: node.name, + method: key, + value: +node.outputs[key].toFixed(2), + }); + }); + }); + return graphData; +}; diff --git a/projects/ng-devtools/src/lib/devtools-tabs/profiler/recording/timeline/timeline.component.ts b/projects/ng-devtools/src/lib/devtools-tabs/profiler/recording/timeline/timeline.component.ts index 4054b57b427..a6aaf43e5fe 100644 --- a/projects/ng-devtools/src/lib/devtools-tabs/profiler/recording/timeline/timeline.component.ts +++ b/projects/ng-devtools/src/lib/devtools-tabs/profiler/recording/timeline/timeline.component.ts @@ -29,6 +29,7 @@ export class TimelineComponent implements OnDestroy { this._maxDuration = -Infinity; this._subscription = data.subscribe({ next: (frames: ProfilerFrame[]): void => { + console.log(frames); this._processFrames(frames); }, complete: (): void => { diff --git a/projects/protocol/src/lib/messages.ts b/projects/protocol/src/lib/messages.ts index f2975ca1f11..6b68fce3bc2 100644 --- a/projects/protocol/src/lib/messages.ts +++ b/projects/protocol/src/lib/messages.ts @@ -112,11 +112,16 @@ export interface LifecycleProfile { ngAfterViewChecked?: number; } +export interface OutputProfile { + [outputName: string]: number; +} + export interface DirectiveProfile { name: string; isElement: boolean; isComponent: boolean; lifecycle: LifecycleProfile; + outputs: OutputProfile; changeDetection?: number; }