From 960d2e37a85e16462a00c0a3a596b86da3debb7a Mon Sep 17 00:00:00 2001 From: Patrick Hulce Date: Wed, 18 Nov 2020 16:54:07 -0600 Subject: [PATCH] core(tracehouse): improve CPU profiler timing refinement (#11608) --- .../lib/tracehouse/cpu-profile-model.js | 344 ++++++++++++++---- .../lib/tracehouse/main-thread-tasks.js | 13 +- .../lib/tracehouse/cpu-profile-model-test.js | 291 +++++++++++---- .../lib/tracehouse/main-thread-tasks-test.js | 62 +++- types/externs.d.ts | 5 + 5 files changed, 565 insertions(+), 150 deletions(-) diff --git a/lighthouse-core/lib/tracehouse/cpu-profile-model.js b/lighthouse-core/lib/tracehouse/cpu-profile-model.js index 9c32d5715cc4..a716c00ae220 100644 --- a/lighthouse-core/lib/tracehouse/cpu-profile-model.js +++ b/lighthouse-core/lib/tracehouse/cpu-profile-model.js @@ -5,6 +5,10 @@ */ 'use strict'; +const MainThreadTasks = require('./main-thread-tasks.js'); + +const SAMPLER_TRACE_EVENT_NAME = 'FunctionCall-SynthesizedByProfilerModel'; + /** * @fileoverview * @@ -40,6 +44,10 @@ * @property {Array} timeDeltas */ +/** @typedef {Required['data']>['_syntheticProfilerRange']} ProfilerRange */ +/** @typedef {LH.TraceEvent & {args: {data: {_syntheticProfilerRange: ProfilerRange}}}} SynthethicEvent */ +/** @typedef {Omit & {event: SynthethicEvent, endEvent: SynthethicEvent}} SynthethicTaskNode */ + class CpuProfilerModel { /** * @param {CpuProfile} profile @@ -108,22 +116,28 @@ class CpuProfilerModel { /** * Generates the necessary B/E-style trace events for a single transition from stack A to stack B - * at the given timestamp. + * at the given latest timestamp (includes possible range in event.args.data). * * Example: * - * timestamp 1234 + * latestPossibleTimestamp 1234 * previousNodeIds 1,2,3 * currentNodeIds 1,2,4 * * yields [end 3 at ts 1234, begin 4 at ts 1234] * - * @param {number} timestamp + * @param {number} earliestPossibleTimestamp + * @param {number} latestPossibleTimestamp * @param {Array} previousNodeIds * @param {Array} currentNodeIds - * @return {Array} + * @return {Array} */ - _synthesizeTraceEventsForTransition(timestamp, previousNodeIds, currentNodeIds) { + _synthesizeTraceEventsForTransition( + earliestPossibleTimestamp, + latestPossibleTimestamp, + previousNodeIds, + currentNodeIds + ) { const startNodes = currentNodeIds .filter(id => !previousNodeIds.includes(id)) .map(id => this._nodesById.get(id)) @@ -133,31 +147,62 @@ class CpuProfilerModel { .map(id => this._nodesById.get(id)) .filter(/** @return {node is CpuProfile['nodes'][0]} */ node => !!node); - /** @param {CpuProfile['nodes'][0]} node @return {LH.TraceEvent} */ + /** @param {CpuProfile['nodes'][0]} node @return {SynthethicEvent} */ const createSyntheticEvent = node => ({ - ts: timestamp, + ts: Number.isFinite(latestPossibleTimestamp) + ? latestPossibleTimestamp + : earliestPossibleTimestamp, pid: this._profile.pid, tid: this._profile.tid, dur: 0, ph: 'I', // This trace event name is Lighthouse-specific and wouldn't be found in a real trace. // Attribution logic in main-thread-tasks.js special cases this event. - name: 'FunctionCall-SynthesizedByProfilerModel', + name: SAMPLER_TRACE_EVENT_NAME, cat: 'lighthouse', - args: {data: {callFrame: node.callFrame}}, + args: { + data: { + callFrame: node.callFrame, + _syntheticProfilerRange: {earliestPossibleTimestamp, latestPossibleTimestamp}, + }, + }, }); - /** @type {Array} */ + /** @type {Array} */ const startEvents = startNodes.map(createSyntheticEvent).map(evt => ({...evt, ph: 'B'})); - /** @type {Array} */ + /** @type {Array} */ const endEvents = endNodes.map(createSyntheticEvent).map(evt => ({...evt, ph: 'E'})); + // Ensure we put end events in first to finish prior tasks before starting new ones. return [...endEvents.reverse(), ...startEvents]; } + /** + * @param {LH.TraceEvent | undefined} event + * @return {event is SynthethicEvent} + */ + static isSyntheticEvent(event) { + if (!event) return false; + return Boolean( + event.name === SAMPLER_TRACE_EVENT_NAME && + event.args.data && + event.args.data._syntheticProfilerRange + ); + } + + /** + * @param {LH.Artifacts.TaskNode} task + * @return {task is SynthethicTaskNode} + */ + static isSyntheticTask(task) { + return CpuProfilerModel.isSyntheticEvent(task.event) && + CpuProfilerModel.isSyntheticEvent(task.endEvent); + } + /** * Finds all the tasks that started or ended (depending on `type`) within the provided time range. * Uses a memory index to remember the place in the array the last invocation left off to avoid - * re-traversing the entire array. + * re-traversing the entire array, but note that this index might still be slightly off from the + * true start position. * * @param {Array<{startTime: number, endTime: number}>} knownTasks * @param {{type: 'startTime'|'endTime', initialIndex: number, earliestPossibleTimestamp: number, latestPossibleTimestamp: number}} options @@ -165,9 +210,17 @@ class CpuProfilerModel { static _getTasksInRange(knownTasks, options) { const {type, initialIndex, earliestPossibleTimestamp, latestPossibleTimestamp} = options; + // We may have overshot a little from last time, so back up to find the real starting index. + let startIndex = initialIndex; + while (startIndex > 0) { + const task = knownTasks[startIndex]; + if (task && task[type] < earliestPossibleTimestamp) break; + startIndex--; + } + /** @type {Array<{startTime: number, endTime: number}>} */ const matchingTasks = []; - for (let i = initialIndex; i < knownTasks.length; i++) { + for (let i = startIndex; i < knownTasks.length; i++) { const task = knownTasks[i]; // Task is before our range of interest, keep looping. if (task[type] < earliestPossibleTimestamp) continue; @@ -181,6 +234,7 @@ class CpuProfilerModel { matchingTasks.push(task); } + // We went through all tasks before reaching the end of our range. return {tasks: matchingTasks, lastIndex: knownTasks.length}; } @@ -193,26 +247,33 @@ class CpuProfilerModel { * range. For example, if we know that a function ended between 800ms and 810ms, we can use the * knowledge that a toplevel task ended at 807ms to use 807ms as the correct endtime for this function. * - * @param {{earliestPossibleTimestamp: number, latestPossibleTimestamp: number, knownTaskStartTimeIndex: number, knownTaskEndTimeIndex: number, knownTasksByStartTime: Array<{startTime: number, endTime: number}>, knownTasksByEndTime: Array<{startTime: number, endTime: number}>}} data + * @param {{syntheticTask: SynthethicTaskNode, eventType: 'start'|'end', allEventsAtTs: {naive: Array, refined: Array}, knownTaskStartTimeIndex: number, knownTaskEndTimeIndex: number, knownTasksByStartTime: Array<{startTime: number, endTime: number}>, knownTasksByEndTime: Array<{startTime: number, endTime: number}>}} data * @return {{timestamp: number, lastStartTimeIndex: number, lastEndTimeIndex: number}} */ static _findEffectiveTimestamp(data) { const { - earliestPossibleTimestamp, - latestPossibleTimestamp, + eventType, + syntheticTask, + allEventsAtTs, knownTasksByStartTime, knownTaskStartTimeIndex, knownTasksByEndTime, knownTaskEndTimeIndex, } = data; + const targetEvent = eventType === 'start' ? syntheticTask.event : syntheticTask.endEvent; + const pairEvent = eventType === 'start' ? syntheticTask.endEvent : syntheticTask.event; + + const timeRange = targetEvent.args.data._syntheticProfilerRange; + const pairTimeRange = pairEvent.args.data._syntheticProfilerRange; + const {tasks: knownTasksStarting, lastIndex: lastStartTimeIndex} = this._getTasksInRange( knownTasksByStartTime, { type: 'startTime', initialIndex: knownTaskStartTimeIndex, - earliestPossibleTimestamp, - latestPossibleTimestamp, + earliestPossibleTimestamp: timeRange.earliestPossibleTimestamp, + latestPossibleTimestamp: timeRange.latestPossibleTimestamp, } ); @@ -221,8 +282,8 @@ class CpuProfilerModel { { type: 'endTime', initialIndex: knownTaskEndTimeIndex, - earliestPossibleTimestamp, - latestPossibleTimestamp, + earliestPossibleTimestamp: timeRange.earliestPossibleTimestamp, + latestPossibleTimestamp: timeRange.latestPossibleTimestamp, } ); @@ -232,44 +293,108 @@ class CpuProfilerModel { const knownTasksEndingNotContained = knownTasksEnding .filter(t => !knownTasksStarting.includes(t)); - let effectiveTimestamp = latestPossibleTimestamp; - if (knownTasksStartingNotContained.length) { - // Tasks that started but did not finish take priority. Use the earliest of their timestamps. - effectiveTimestamp = Math.min(...knownTasksStartingNotContained.map(t => t.startTime)); - } else if (knownTasksEndingNotContained.length) { - // Tasks that ended but did not start take next priority. Use the latest of their timestamps. - effectiveTimestamp = Math.max(...knownTasksEndingNotContained.map(t => t.endTime)); - } + // Each one of these spanning tasks can be in one of three situations: + // - Task is a parent of the sample. + // - Task is a child of the sample. + // - Task has no overlap with the sample. + + // Parent tasks must satisfy... + // parentTask.startTime <= syntheticTask.startTime + // AND + // syntheticTask.endTime <= parentTask.endTime + const parentTasks = + eventType === 'start' + ? knownTasksStartingNotContained.filter( + t => t.endTime >= pairTimeRange.earliestPossibleTimestamp + ) + : knownTasksEndingNotContained.filter( + t => t.startTime <= pairTimeRange.latestPossibleTimestamp + ); + + // Child tasks must satisfy... + // syntheticTask.startTime <= childTask.startTime + // AND + // childTask.endTime <= syntheticTask.endTime + const childTasks = + eventType === 'start' + ? knownTasksStartingNotContained.filter( + t => t.endTime < pairTimeRange.earliestPossibleTimestamp + ) + : knownTasksEndingNotContained.filter( + t => t.startTime > pairTimeRange.latestPossibleTimestamp + ); + + // Unrelated tasks must satisfy... + // unrelatedTask.endTime <= syntheticTask.startTime + // OR + // syntheticTask.endTime <= unrelatedTask.startTime + const unrelatedTasks = + eventType === 'start' ? knownTasksEndingNotContained : knownTasksStartingNotContained; + + // Now we narrow our allowable range using the three types of tasks and the other events + // that we've already refined. + const minimumTs = Math.max( + // Sampled event couldn't be earlier than this to begin with. + timeRange.earliestPossibleTimestamp, + // Sampled start event can't be before its parent started. + // Sampled end event can't be before its child ended. + ...(eventType === 'start' + ? parentTasks.map(t => t.startTime) + : childTasks.map(t => t.endTime)), + // Sampled start event can't be before unrelated tasks ended. + ...(eventType === 'start' ? unrelatedTasks.map(t => t.endTime) : []), + // Sampled start event can't be before the other `E` events at its same timestamp. + ...(eventType === 'start' + ? allEventsAtTs.refined.filter(e => e.ph === 'E').map(e => e.ts) + : []) + ); + + const maximumTs = Math.min( + // Sampled event couldn't be later than this to begin with. + timeRange.latestPossibleTimestamp, + // Sampled start event can't be after its child started. + // Sampled end event can't be after its parent ended. + ...(eventType === 'start' + ? childTasks.map(t => t.startTime) + : parentTasks.map(t => t.endTime)), + // Sampled end event can't be after unrelated tasks started. + ...(eventType === 'start' ? [] : unrelatedTasks.map(t => t.startTime)), + // Sampled end event can't be after the other `B` events at its same timestamp. + // This is _currently_ only possible in contrived scenarios due to the sorted order of processing, + // but it's a non-obvious observation and case to account for. + ...(eventType === 'start' + ? [] + : allEventsAtTs.refined.filter(e => e.ph === 'B').map(e => e.ts)) + ); + + // We want to maximize the size of the sampling tasks within our constraints, so we'll pick + // the _earliest_ possible time for start events and the _latest_ possible time for end events. + const effectiveTimestamp = + (eventType === 'start' && Number.isFinite(minimumTs)) || !Number.isFinite(maximumTs) + ? minimumTs + : maximumTs; return {timestamp: effectiveTimestamp, lastStartTimeIndex, lastEndTimeIndex}; } /** - * Creates B/E-style trace events from a CpuProfile object created by `collectProfileEvents()`. - * An optional set of tasks can be passed in to refine the start/end times. + * Creates the B/E-style trace events using only data from the profile itself. Each B/E event will + * include the actual _range_ the timestamp could have been in its metadata that is used for + * refinement later. * - * With the sampling profiler we know that a function started/ended *sometime between* two points, - * but not exactly when. Using the information from other tasks gives us more information to be - * more precise with timings and allows us to create a valid task tree later on. - * - * @param {Array} [knownTasks] - * @return {Array} + * @return {Array} */ - synthesizeTraceEvents(knownTasks = []) { + _synthesizeNaiveTraceEvents() { const profile = this._profile; const length = profile.samples.length; if (profile.timeDeltas.length !== length) throw new Error(`Invalid CPU profile length`); - const knownTasksByStartTime = knownTasks.slice().sort((a, b) => a.startTime - b.startTime); - const knownTasksByEndTime = knownTasks.slice().sort((a, b) => a.endTime - b.endTime); - - /** @type {Array} */ + /** @type {Array} */ const events = []; let currentProfilerTimestamp = profile.startTime; - let lastEffectiveTimestamp = currentProfilerTimestamp; - let knownTaskStartTimeIndex = 0; - let knownTaskEndTimeIndex = 0; + let earliestPossibleTimestamp = -Infinity; + /** @type {Array} */ let lastActiveNodeIds = []; for (let i = 0; i < profile.samples.length; i++) { @@ -278,42 +403,137 @@ class CpuProfilerModel { const node = this._nodesById.get(nodeId); if (!node) throw new Error(`Missing node ${nodeId}`); - const { - timestamp: effectiveTimestamp, - lastStartTimeIndex, - lastEndTimeIndex, - } = CpuProfilerModel._findEffectiveTimestamp({ - earliestPossibleTimestamp: lastEffectiveTimestamp, - latestPossibleTimestamp: currentProfilerTimestamp + timeDelta, - knownTaskStartTimeIndex, - knownTaskEndTimeIndex, - knownTasksByStartTime, - knownTasksByEndTime, - }); - currentProfilerTimestamp += timeDelta; - lastEffectiveTimestamp = effectiveTimestamp; - knownTaskStartTimeIndex = lastStartTimeIndex; - knownTaskEndTimeIndex = lastEndTimeIndex; const activeNodeIds = this._getActiveNodeIds(nodeId); events.push( ...this._synthesizeTraceEventsForTransition( - effectiveTimestamp, + earliestPossibleTimestamp, + currentProfilerTimestamp, lastActiveNodeIds, activeNodeIds ) ); + + earliestPossibleTimestamp = currentProfilerTimestamp; lastActiveNodeIds = activeNodeIds; } events.push( - ...this._synthesizeTraceEventsForTransition(currentProfilerTimestamp, lastActiveNodeIds, []) + ...this._synthesizeTraceEventsForTransition( + currentProfilerTimestamp, + Infinity, + lastActiveNodeIds, + [] + ) ); return events; } + /** + * Creates a copy of B/E-style trace events with refined timestamps using knowledge from the + * tasks that have definitive timestamps. + * + * With the sampling profiler we know that a function started/ended _sometime between_ two points, + * but not exactly when. Using the information from other tasks gives us more information to be + * more precise with timings and allows us to create a valid task tree later on. + * + * @param {Array<{startTime: number, endTime: number}>} knownTasks + * @param {Array} syntheticTasks + * @param {Array} syntheticEvents + * @return {Array} + */ + _refineTraceEventsWithTasks(knownTasks, syntheticTasks, syntheticEvents) { + /** @type {Array} */ + const refinedEvents = []; + + /** @type {Map, refined: Array}>} */ + const syntheticEventsByTs = new Map(); + for (const event of syntheticEvents) { + const group = syntheticEventsByTs.get(event.ts) || {naive: [], refined: []}; + group.naive.push(event); + syntheticEventsByTs.set(event.ts, group); + } + + /** @type {Map} */ + const syntheticTasksByEvent = new Map(); + for (const task of syntheticTasks) { + syntheticTasksByEvent.set(task.event, task); + syntheticTasksByEvent.set(task.endEvent, task); + } + + const knownTasksByStartTime = knownTasks.slice().sort((a, b) => a.startTime - b.startTime); + const knownTasksByEndTime = knownTasks.slice().sort((a, b) => a.endTime - b.endTime); + + let knownTaskStartTimeIndex = 0; + let knownTaskEndTimeIndex = 0; + + for (const event of syntheticEvents) { + const syntheticTask = syntheticTasksByEvent.get(event); + if (!syntheticTask) throw new Error('Impossible - all events have a task'); + const allEventsAtTs = syntheticEventsByTs.get(event.ts); + if (!allEventsAtTs) throw new Error('Impossible - we just mapped every event'); + + const effectiveTimestampData = CpuProfilerModel._findEffectiveTimestamp({ + eventType: event.ph === 'B' ? 'start' : 'end', + syntheticTask, + allEventsAtTs, + knownTaskStartTimeIndex, + knownTaskEndTimeIndex, + knownTasksByStartTime, + knownTasksByEndTime, + }); + + knownTaskStartTimeIndex = effectiveTimestampData.lastStartTimeIndex; + knownTaskEndTimeIndex = effectiveTimestampData.lastEndTimeIndex; + + const refinedEvent = {...event, ts: effectiveTimestampData.timestamp}; + refinedEvents.push(refinedEvent); + allEventsAtTs.refined.push(refinedEvent); + } + + return refinedEvents; + } + + /** + * Creates B/E-style trace events from a CpuProfile object created by `collectProfileEvents()`. + * An optional set of tasks can be passed in to refine the start/end times. + * + * @param {Array} [knownTaskNodes] + * @return {Array} + */ + synthesizeTraceEvents(knownTaskNodes = []) { + const naiveEvents = this._synthesizeNaiveTraceEvents(); + if (!naiveEvents.length) return []; + + let finalEvents = naiveEvents; + if (knownTaskNodes.length) { + // If we have task information, put the times back into raw trace event ts scale. + /** @type {(baseTs: number) => (node: LH.Artifacts.TaskNode) => LH.Artifacts.TaskNode} */ + const rebaseTaskTime = baseTs => node => ({ + ...node, + startTime: baseTs + node.startTime * 1000, + endTime: baseTs + node.endTime * 1000, + duration: node.duration * 1000, + }); + + // The first task node might not be time 0, so recompute the baseTs. + const baseTs = knownTaskNodes[0].event.ts - knownTaskNodes[0].startTime * 1000; + const knownTasks = knownTaskNodes.map(rebaseTaskTime(baseTs)); + + // We'll also create tasks for our naive events so we have the B/E pairs readily available. + const naiveProfilerTasks = MainThreadTasks.getMainThreadTasks(naiveEvents, [], Infinity) + .map(rebaseTaskTime(naiveEvents[0].ts)) + .filter(CpuProfilerModel.isSyntheticTask); + if (!naiveProfilerTasks.length) throw new Error('Failed to create naive profiler tasks'); + + finalEvents = this._refineTraceEventsWithTasks(knownTasks, naiveProfilerTasks, naiveEvents); + } + + return finalEvents; + } + /** * Creates B/E-style trace events from a CpuProfile object created by `collectProfileEvents()` * diff --git a/lighthouse-core/lib/tracehouse/main-thread-tasks.js b/lighthouse-core/lib/tracehouse/main-thread-tasks.js index de52c7c27b4d..0889b29681c2 100644 --- a/lighthouse-core/lib/tracehouse/main-thread-tasks.js +++ b/lighthouse-core/lib/tracehouse/main-thread-tasks.js @@ -29,6 +29,7 @@ const {taskGroups, taskNameToGroup} = require('./task-groups.js'); /** * @typedef TaskNode * @prop {LH.TraceEvent} event + * @prop {LH.TraceEvent|undefined} endEvent * @prop {TaskNode[]} children * @prop {TaskNode|undefined} parent * @prop {boolean} unbounded Indicates that the task had an endTime that was inferred rather than specified in the trace. i.e. in the source trace this task was unbounded. @@ -45,7 +46,7 @@ const {taskGroups, taskNameToGroup} = require('./task-groups.js'); class MainThreadTasks { /** * @param {LH.TraceEvent} event - * @param {Pick} [endEvent] + * @param {LH.TraceEvent} [endEvent] * @return {TaskNode} */ static _createNewTaskNode(event, endEvent) { @@ -60,6 +61,7 @@ class MainThreadTasks { const newTask = { event, + endEvent, startTime, endTime, duration: endTime - startTime, @@ -181,13 +183,13 @@ class MainThreadTasks { break; } - /** @type {Pick} */ + /** @type {LH.TraceEvent} */ let taskEndEvent; let unbounded = false; if (matchedEventIndex === -1) { // If we couldn't find an end event, we'll assume it's the end of the trace. // If this creates invalid parent/child relationships it will be caught in the next step. - taskEndEvent = {ph: 'E', ts: traceEndTs}; + taskEndEvent = {...taskStartEvent, ph: 'E', ts: traceEndTs}; unbounded = true; } else if (matchedEventIndex === taskEndEventsReverseQueue.length - 1) { // Use .pop() in the common case where the immediately next event is needed. @@ -309,14 +311,17 @@ class MainThreadTasks { // When we fall into this error, it's usually because of one of two reasons. // - There was slop in the opposite direction (child started 1ms before parent), // the child was assumed to be parent instead, and another task already started. - // - The child timestamp ended more than 1ms after tha parent. + // - The child timestamp ended more than 1ms after the parent. + // Two unrelated tasks where the first hangs over the second by >1ms is also this case. // These have more complicated fixes, so handling separately https://github.com/GoogleChrome/lighthouse/pull/9491#discussion_r327331204. /** @type {any} */ const error = new Error('Fatal trace logic error - child cannot end after parent'); error.timeDelta = timeDelta; error.nextTaskEvent = nextTask.event; + error.nextTaskEndEvent = nextTask.endEvent; error.nextTaskEndTime = nextTask.endTime; error.currentTaskEvent = currentTask.event; + error.currentTaskEndEvent = currentTask.endEvent; error.currentTaskEndTime = currentTask.endTime; throw error; } diff --git a/lighthouse-core/test/lib/tracehouse/cpu-profile-model-test.js b/lighthouse-core/test/lib/tracehouse/cpu-profile-model-test.js index b0fd821a4213..f7e781e51593 100644 --- a/lighthouse-core/test/lib/tracehouse/cpu-profile-model-test.js +++ b/lighthouse-core/test/lib/tracehouse/cpu-profile-model-test.js @@ -45,73 +45,119 @@ describe('CPU Profiler Model', () => { }); describe('#_findEffectiveTimestamp', () => { - it('should default to the latest possible timestamp when no task data available', () => { - const result = CpuProfilerModel._findEffectiveTimestamp({ - earliestPossibleTimestamp: 0, - latestPossibleTimestamp: 1000, + const findTimestamp = CpuProfilerModel._findEffectiveTimestamp.bind(CpuProfilerModel); + let defaultData; + + function createTask(startProfilerRange, endProfilerRange) { + return { + event: {args: {data: {_syntheticProfilerRange: startProfilerRange}}}, + endEvent: {args: {data: {_syntheticProfilerRange: endProfilerRange}}}, + }; + } + + beforeEach(() => { + defaultData = { + syntheticTask: createTask( + {earliestPossibleTimestamp: 100, latestPossibleTimestamp: 1000}, + {earliestPossibleTimestamp: 1000, latestPossibleTimestamp: 2000} + ), + allEventsAtTs: {naive: [], refined: []}, knownTasksByStartTime: [], knownTaskStartTimeIndex: 0, knownTasksByEndTime: [], knownTaskEndTimeIndex: 0, - }); + }; + }); - expect(result).toEqual({timestamp: 1000, lastStartTimeIndex: 0, lastEndTimeIndex: 0}); + it('should default to the longest possible timestamps when no task data available', () => { + const startResult = findTimestamp({...defaultData, eventType: 'start'}); + const endResult = findTimestamp({...defaultData, eventType: 'end'}); + expect(startResult).toEqual({timestamp: 100, lastStartTimeIndex: 0, lastEndTimeIndex: 0}); + expect(endResult).toEqual({timestamp: 2000, lastStartTimeIndex: 0, lastEndTimeIndex: 0}); }); - it('should use the latest possible timestamp when tasks fully include range', () => { - const tasks = [{startTime: 500, endTime: 2500}]; - const result = CpuProfilerModel._findEffectiveTimestamp({ - earliestPossibleTimestamp: 1000, - latestPossibleTimestamp: 2000, - knownTasksByStartTime: tasks, - knownTaskStartTimeIndex: 0, - knownTasksByEndTime: tasks, - knownTaskEndTimeIndex: 0, + it('should use the longest possible timestamps when tasks fully include range', () => { + // Cases tested: + // - eventType=start,task=parent + // - eventType=end,task=parent + const tasks = [{startTime: 0, endTime: 2500}]; + const data = {...defaultData, knownTasksByStartTime: tasks, knownTasksByEndTime: tasks}; + const startResult = findTimestamp({...data, eventType: 'start'}); + const endResult = findTimestamp({...data, eventType: 'end', knownTaskStartTimeIndex: 1}); + + expect(startResult).toEqual({timestamp: 100, lastStartTimeIndex: 1, lastEndTimeIndex: 0}); + expect(endResult).toEqual({timestamp: 2000, lastStartTimeIndex: 1, lastEndTimeIndex: 0}); + }); + + it('should use the longest possible timestamps when tasks are fully contained in range', () => { + // Cases tested: + // - eventType=start,task=child + // - eventType=end,task=child + const tasks = [{startTime: 250, endTime: 750}, {startTime: 1250, endTime: 1750}]; + const data = {...defaultData, knownTasksByStartTime: tasks, knownTasksByEndTime: tasks}; + const startResult = findTimestamp({...data, eventType: 'start'}); + const endResult = findTimestamp({ + ...data, + eventType: 'end', + knownTaskStartTimeIndex: 1, + knownTaskEndTimeIndex: 1, }); - expect(result).toEqual({timestamp: 2000, lastStartTimeIndex: 1, lastEndTimeIndex: 0}); + expect(startResult).toEqual({timestamp: 100, lastStartTimeIndex: 1, lastEndTimeIndex: 1}); + expect(endResult).toEqual({timestamp: 2000, lastStartTimeIndex: 2, lastEndTimeIndex: 2}); }); - it('should use the latest possible timestamp when tasks are fully contained in range', () => { - const tasks = [{startTime: 250, endTime: 750}]; - const result = CpuProfilerModel._findEffectiveTimestamp({ - earliestPossibleTimestamp: 0, - latestPossibleTimestamp: 1000, - knownTasksByStartTime: tasks, - knownTaskStartTimeIndex: 0, - knownTasksByEndTime: tasks, - knownTaskEndTimeIndex: 0, + it('should use the earliest possible timestamp when tasks started in range', () => { + // Cases tested: + // - eventType=start,task=parent,minTs + // - eventType=end,task=unrelated,maxTs + const tasks = [{startTime: 250, endTime: 3000}, {startTime: 1500, endTime: 3000}]; + const data = {...defaultData, knownTasksByStartTime: tasks, knownTasksByEndTime: tasks}; + const startResult = findTimestamp({...data, eventType: 'start'}); + const endResult = findTimestamp({ + ...data, + eventType: 'end', + knownTaskStartTimeIndex: 1, }); - expect(result).toEqual({timestamp: 1000, lastStartTimeIndex: 1, lastEndTimeIndex: 1}); + expect(startResult).toEqual({timestamp: 250, lastStartTimeIndex: 1, lastEndTimeIndex: 0}); + expect(endResult).toEqual({timestamp: 1500, lastStartTimeIndex: 2, lastEndTimeIndex: 0}); }); - it('should use earliest of the start task timestamps when tasks started in range', () => { - const tasks = [{startTime: 250, endTime: 2000}]; - const result = CpuProfilerModel._findEffectiveTimestamp({ - earliestPossibleTimestamp: 0, - latestPossibleTimestamp: 1000, - knownTasksByStartTime: tasks, - knownTaskStartTimeIndex: 0, - knownTasksByEndTime: tasks, - knownTaskEndTimeIndex: 0, + it('should use the latest possible timestamp when tasks ended in range', () => { + // Cases tested: + // - eventType=start,task=unrelated,minTs + // - eventType=end,task=parent,maxTs + const tasks = [{startTime: 0, endTime: 500}, {startTime: 0, endTime: 1500}]; + const data = {...defaultData, knownTasksByStartTime: tasks, knownTasksByEndTime: tasks}; + const startResult = findTimestamp({...data, eventType: 'start'}); + const endResult = findTimestamp({ + ...data, + eventType: 'end', + knownTaskStartTimeIndex: 1, }); - expect(result).toEqual({timestamp: 250, lastStartTimeIndex: 1, lastEndTimeIndex: 0}); + expect(startResult).toEqual({timestamp: 500, lastStartTimeIndex: 2, lastEndTimeIndex: 1}); + expect(endResult).toEqual({timestamp: 1500, lastStartTimeIndex: 2, lastEndTimeIndex: 2}); }); - it('should use latest of the end task timestamps when tasks ended in range', () => { - const tasks = [{startTime: 250, endTime: 1500}]; - const result = CpuProfilerModel._findEffectiveTimestamp({ - earliestPossibleTimestamp: 1000, - latestPossibleTimestamp: 2000, - knownTasksByStartTime: tasks, - knownTaskStartTimeIndex: 0, - knownTasksByEndTime: tasks, - knownTaskEndTimeIndex: 0, + it('should consider the other refined timestamps at the same range', () => { + // Cases tested: + // - eventType=start,allEventsAtTs=[late E],minTs + // - eventType=end,allEventsAtTs=[early B],maxTs + const startResult = findTimestamp({ + ...defaultData, + eventType: 'start', + allEventsAtTs: {refined: [{ph: 'E', ts: 1000}]}, + }); + const endResult = findTimestamp({ + ...defaultData, + eventType: 'end', + allEventsAtTs: {refined: [{ph: 'B', ts: 1100}]}, }); - expect(result).toEqual({timestamp: 1500, lastStartTimeIndex: 1, lastEndTimeIndex: 1}); + expect(startResult).toEqual({timestamp: 1000, lastStartTimeIndex: 0, lastEndTimeIndex: 0}); + expect(endResult).toEqual({timestamp: 1100, lastStartTimeIndex: 0, lastEndTimeIndex: 0}); }); it('should handle multiple tasks', () => { @@ -124,19 +170,30 @@ describe('CPU Profiler Model', () => { {startTime: 1925, endTime: 1975}, ]; - // TODO: eventually, this should split the start and end effective timestamps. - // For now it assumes both are the same timestamp which forces this to choose the latest option. - // Eventually the endTimestamp should be 1500 and the startTimestamp should be 1900. - const result = CpuProfilerModel._findEffectiveTimestamp({ - earliestPossibleTimestamp: 1000, - latestPossibleTimestamp: 2000, + const data = { + ...defaultData, knownTasksByStartTime: tasks, - knownTaskStartTimeIndex: 0, knownTasksByEndTime: tasks.slice().sort((a, b) => a.endTime - b.endTime), - knownTaskEndTimeIndex: 0, + }; + const startResult = findTimestamp({ + ...data, + eventType: 'start', + syntheticTask: createTask( + {earliestPossibleTimestamp: 1000, latestPossibleTimestamp: 2000}, + {earliestPossibleTimestamp: 2000, latestPossibleTimestamp: 3000} + ), + }); + const endResult = findTimestamp({ + ...data, + eventType: 'end', + syntheticTask: createTask( + {earliestPossibleTimestamp: 100, latestPossibleTimestamp: 1000}, + {earliestPossibleTimestamp: 1000, latestPossibleTimestamp: 2000} + ), }); - expect(result).toEqual({timestamp: 1900, lastStartTimeIndex: 6, lastEndTimeIndex: 5}); + expect(startResult).toEqual({timestamp: 1900, lastStartTimeIndex: 6, lastEndTimeIndex: 5}); + expect(endResult).toEqual({timestamp: 1400, lastStartTimeIndex: 6, lastEndTimeIndex: 5}); }); }); @@ -167,14 +224,14 @@ describe('CPU Profiler Model', () => { // With the sampling profiler we know that Baz and Foo ended *sometime between* 17e3 and 18e3. // We want to make sure when additional task information is present, we refine the end time. const tasks = [ - // The RunTask at the toplevel, should move start time of Foo to 8.0e3 and end time to 17.5e3 - {startTime: ts(8.0e3), endTime: ts(17.5e3)}, - // The EvaluateScript at the 2nd level, should not affect anything. - {startTime: ts(9.0e3), endTime: ts(17.4e3)}, + // The RunTask at the toplevel, but should move start/end time of root/program to 8.0e3/19.5e3. + {startTime: 8.0, endTime: 19.5, event: {ts: ts(8e3)}}, + // The EvaluateScript at the 2nd level, should move start/end time of Foo + 2nd Baz to 9.0e3/17.4e3. + {startTime: 9.0, endTime: 17.4}, // A small task inside Baz, should move the start time of Baz to 12.5e3. - {startTime: ts(12.5e3), endTime: ts(13.4e3)}, + {startTime: 12.5, endTime: 13.4}, // A small task inside Foo, should move the end time of Bar to 15.7e3, start time of Baz to 16.8e3. - {startTime: ts(15.7e3), endTime: ts(16.8e3)}, + {startTime: 15.7, endTime: 16.8}, ]; const events = CpuProfilerModel.synthesizeTraceEvents(profile, tasks); @@ -182,16 +239,116 @@ describe('CPU Profiler Model', () => { expect(events).toMatchObject([ {ph: 'B', ts: ts(8.0e3), args: {data: {callFrame: {functionName: '(root)'}}}}, {ph: 'B', ts: ts(8.0e3), args: {data: {callFrame: {functionName: '(program)'}}}}, - {ph: 'B', ts: ts(8.0e3), args: {data: {callFrame: {functionName: 'Foo'}}}}, - {ph: 'B', ts: ts(12.0e3), args: {data: {callFrame: {functionName: 'Bar'}}}}, + {ph: 'B', ts: ts(9.0e3), args: {data: {callFrame: {functionName: 'Foo'}}}}, + {ph: 'B', ts: ts(11.0e3), args: {data: {callFrame: {functionName: 'Bar'}}}}, {ph: 'B', ts: ts(12.5e3), args: {data: {callFrame: {functionName: 'Baz'}}}}, {ph: 'E', ts: ts(13.4e3), args: {data: {callFrame: {functionName: 'Baz'}}}}, {ph: 'E', ts: ts(15.7e3), args: {data: {callFrame: {functionName: 'Bar'}}}}, {ph: 'B', ts: ts(16.8e3), args: {data: {callFrame: {functionName: 'Baz'}}}}, - {ph: 'E', ts: ts(17.5e3), args: {data: {callFrame: {functionName: 'Baz'}}}}, - {ph: 'E', ts: ts(17.5e3), args: {data: {callFrame: {functionName: 'Foo'}}}}, - {ph: 'E', ts: ts(19.0e3), args: {data: {callFrame: {functionName: '(program)'}}}}, - {ph: 'E', ts: ts(19.0e3), args: {data: {callFrame: {functionName: '(root)'}}}}, + {ph: 'E', ts: ts(17.4e3), args: {data: {callFrame: {functionName: 'Baz'}}}}, + {ph: 'E', ts: ts(17.4e3), args: {data: {callFrame: {functionName: 'Foo'}}}}, + {ph: 'E', ts: ts(19.5e3), args: {data: {callFrame: {functionName: '(program)'}}}}, + {ph: 'E', ts: ts(19.5e3), args: {data: {callFrame: {functionName: '(root)'}}}}, + ]); + }); + + it('should handle multiple task start/stop times with low sampling rate', () => { + /* + An artistic rendering of the below profile with tasks: + ████████████████(root)████████████████ + ███████Task███████ ██████Task██████ █ + ██████Eval██████ ██████Eval██████ + ██████Foo███████ ██████Bar██████ + █Fn█ + █Fn█ + */ + profile = { + id: '0x1', + pid: 1, + tid: 1, + startTime: 9e6, + nodes: [ + {id: 0, callFrame: {functionName: '(root)'}}, + {id: 1, callFrame: {functionName: 'Foo', url: 'fileA.js'}, parent: 0}, + {id: 2, callFrame: {functionName: 'Bar', url: 'fileA.js'}, parent: 0}, + ], + samples: [0, 1, 1, 2, 2, 0], + timeDeltas: [0.5e3, 19.5e3, 20e3, 20e3, 20e3, 20e3], + }; + + const ts = x => profile.startTime + x; + + // With the sampling profiler we know that Foo switched to Bar, but we don't know when. + // Create a set of tasks that force large changes. + const tasks = [ + // The RunTask at the toplevel, parent of Foo execution + {startTime: 1, endTime: 50, event: {ts: ts(1e3)}}, + // The EvaluateScript at the next level, parent of Foo execution + {startTime: 5, endTime: 45}, + // The FunctionCall at the next level, should be a child of Foo execution + {startTime: 10, endTime: 25}, + // The FunctionCall at the next level, should be a child of Foo execution + {startTime: 12, endTime: 22}, + // The RunTask at the toplevel, parent of Bar execution + {startTime: 51, endTime: 90}, + // The EvaluateScript at the next level, parent of Bar execution + {startTime: 55, endTime: 85}, + // The RunTask at the toplevel, there to mess with Bar timing + {startTime: 92, endTime: 103}, + ]; + + const events = CpuProfilerModel.synthesizeTraceEvents(profile, tasks); + + expect(events).toMatchObject([ + {ph: 'B', ts: ts(0.5e3), args: {data: {callFrame: {functionName: '(root)'}}}}, + {ph: 'B', ts: ts(5e3), args: {data: {callFrame: {functionName: 'Foo'}}}}, + {ph: 'E', ts: ts(45e3), args: {data: {callFrame: {functionName: 'Foo'}}}}, + {ph: 'B', ts: ts(55e3), args: {data: {callFrame: {functionName: 'Bar'}}}}, + {ph: 'E', ts: ts(85e3), args: {data: {callFrame: {functionName: 'Bar'}}}}, + {ph: 'E', ts: ts(103e3), args: {data: {callFrame: {functionName: '(root)'}}}}, + ]); + }); + + it('should handle multiple roots', () => { + /* + An artistic rendering of the below profile with tasks: + ███(rootA)███ ███(rootB)███ ███(rootC)███ + ███Task███ ███Task███ ███Task███ + */ + profile = { + id: '0x1', + pid: 1, + tid: 1, + startTime: 9e6, + nodes: [ + {id: 0, callFrame: {functionName: '(rootA)'}}, + {id: 1, callFrame: {functionName: 'Task'}, parent: 0}, + {id: 2, callFrame: {functionName: '(rootB)'}}, + {id: 3, callFrame: {functionName: 'Task'}, parent: 2}, + {id: 4, callFrame: {functionName: '(rootC)'}}, + {id: 5, callFrame: {functionName: 'Task'}, parent: 4}, + ], + samples: [0, 1, 3, 3, 5, 4], + timeDeltas: [0.5e3, 19.5e3, 20e3, 20e3, 20e3, 20e3], + }; + + const ts = x => profile.startTime + x; + + const events = CpuProfilerModel.synthesizeTraceEvents(profile, []); + + expect(events).toMatchObject([ + {ph: 'B', ts: ts(0.5e3), args: {data: {callFrame: {functionName: '(rootA)'}}}}, + {ph: 'B', ts: ts(20e3), args: {data: {callFrame: {functionName: 'Task'}}}}, + {ph: 'E', ts: ts(40e3), args: {data: {callFrame: {functionName: 'Task'}}}}, + {ph: 'E', ts: ts(40e3), args: {data: {callFrame: {functionName: '(rootA)'}}}}, + {ph: 'B', ts: ts(40e3), args: {data: {callFrame: {functionName: '(rootB)'}}}}, + {ph: 'B', ts: ts(40e3), args: {data: {callFrame: {functionName: 'Task'}}}}, + {ph: 'E', ts: ts(80e3), args: {data: {callFrame: {functionName: 'Task'}}}}, + {ph: 'E', ts: ts(80e3), args: {data: {callFrame: {functionName: '(rootB)'}}}}, + {ph: 'B', ts: ts(80e3), args: {data: {callFrame: {functionName: '(rootC)'}}}}, + {ph: 'B', ts: ts(80e3), args: {data: {callFrame: {functionName: 'Task'}}}}, + {ph: 'E', ts: ts(100e3), args: {data: {callFrame: {functionName: 'Task'}}}}, + {ph: 'E', ts: ts(100e3), args: {data: {callFrame: {functionName: '(rootC)'}}}}, ]); }); diff --git a/lighthouse-core/test/lib/tracehouse/main-thread-tasks-test.js b/lighthouse-core/test/lib/tracehouse/main-thread-tasks-test.js index 43747882bfdb..569c8d796ecc 100644 --- a/lighthouse-core/test/lib/tracehouse/main-thread-tasks-test.js +++ b/lighthouse-core/test/lib/tracehouse/main-thread-tasks-test.js @@ -108,6 +108,7 @@ describe('Main Thread Tasks', () => { children: [taskC], event: traceEvents[4], + endEvent: traceEvents[6], startTime: 5, endTime: 55, duration: 50, @@ -202,11 +203,13 @@ describe('Main Thread Tasks', () => { const baseTs = 1241250325; const url = s => ({args: {data: {url: s}}}); const xhr = (s, readyState, stackTrace) => ({ - args: {data: { - url: s, - readyState, - stackTrace: stackTrace && stackTrace.map(url => ({url})), - }}, + args: { + data: { + url: s, + readyState, + stackTrace: stackTrace && stackTrace.map(url => ({url})), + }, + }, }); /* @@ -222,7 +225,13 @@ describe('Main Thread Tasks', () => { {ph: 'X', name: 'EvaluateScript', ts: baseTs + 10e3, dur: 30e3, ...url('urlA')}, {ph: 'X', name: 'XHRReadyStateChange', ts: baseTs + 15e3, dur: 15e3, ...xhr('urlXHR', 1)}, {ph: 'X', name: 'TaskB', ts: baseTs + 80e3, dur: 20e3}, - {ph: 'X', name: 'XHRReadyStateChange', ts: baseTs + 85e3, dur: 15e3, ...xhr('urlXHR', 4, ['urlC'])}, // eslint-disable-line max-len + { + ph: 'X', + name: 'XHRReadyStateChange', + ts: baseTs + 85e3, + dur: 15e3, + ...xhr('urlXHR', 4, ['urlC']), + }, // eslint-disable-line max-len {ph: 'X', name: 'TaskC', ts: baseTs + 89e3, dur: 4e3}, ]; @@ -261,7 +270,15 @@ describe('Main Thread Tasks', () => { {ph: 'X', name: 'TaskA', pid, tid, ts: baseTs, dur: 30e3}, {ph: 'X', name: 'Paint', pid, tid, ts: baseTs + 10e3, dur: 10e3, ...frame('A')}, {ph: 'X', name: 'TaskB', pid, tid, ts: baseTs + 50e3, dur: 20e3}, - {ph: 'X', name: 'EvaluateScript', pid, tid, ts: baseTs + 51e3, dur: 15e3, ...stackTrace('B', ['urlB'])}, // eslint-disable-line max-len + { + ph: 'X', + name: 'EvaluateScript', + pid, + tid, + ts: baseTs + 51e3, + dur: 15e3, + ...stackTrace('B', ['urlB']), + }, // eslint-disable-line max-len {ph: 'X', name: 'TaskC', pid, tid, ts: baseTs + 90e3, dur: 5e3}, {ph: 'X', name: 'Layout', pid, tid, ts: baseTs + 90e3, dur: 4e3, ...frame('B')}, ]; @@ -345,7 +362,7 @@ describe('Main Thread Tasks', () => { const taskA = tasks.find(task => task.event.name === 'TaskA'); const taskB = tasks.find(task => task.event.name === 'TaskB'); const taskC = tasks.find(task => task.event.name === 'TaskC'); - expect(taskA).toEqual({ + expect(taskA).toMatchObject({ parent: undefined, attributableURLs: [], @@ -359,7 +376,7 @@ describe('Main Thread Tasks', () => { unbounded: true, }); - expect(taskB).toEqual({ + expect(taskB).toMatchObject({ parent: taskA, attributableURLs: [], @@ -496,6 +513,7 @@ describe('Main Thread Tasks', () => { children: [], event: traceEvents.find(event => event.name === 'TaskB'), + endEvent: traceEvents.find(event => event.ph === 'E' && event.name === 'TaskB'), startTime: 0, endTime: 50, duration: 50, @@ -528,7 +546,8 @@ describe('Main Thread Tasks', () => { attributableURLs: [], children: [], - event: traceEvents.find(event => event.name === 'TaskA'), + event: traceEvents.find(evt => evt.ph === 'B' && evt.name === 'TaskA'), + endEvent: traceEvents.find(evt => evt.ph === 'E' && evt.name === 'TaskA'), startTime: 0, endTime: 100, duration: 100, @@ -541,7 +560,8 @@ describe('Main Thread Tasks', () => { attributableURLs: [], children: [], - event: traceEvents.find(event => event.name === 'TaskB' && event.ph === 'B'), + event: traceEvents.find(event => event.ph === 'B' && event.name === 'TaskB'), + endEvent: traceEvents.find(event => event.ph === 'E' && event.name === 'TaskB'), startTime: 100, endTime: 100, duration: 0, @@ -576,6 +596,7 @@ describe('Main Thread Tasks', () => { children: [tasks[1]], event: traceEvents.find(event => event.name === 'SameName' && event.ts === baseTs), + endEvent: traceEvents.find(evt => evt.name === 'SameName' && evt.ts === baseTs + 100e3), startTime: 0, endTime: 100, duration: 100, @@ -589,6 +610,7 @@ describe('Main Thread Tasks', () => { children: [], event: traceEvents.find(event => event.ts === baseTs + 25e3), + endEvent: traceEvents.find(evt => evt.name === 'SameName' && evt.ts === baseTs + 75e3), startTime: 25, endTime: 75, duration: 50, @@ -624,6 +646,7 @@ describe('Main Thread Tasks', () => { children: [taskB], event: traceEvents.find(event => event.name === 'TaskA'), + endEvent: traceEvents.find(evt => evt.ph === 'E' && evt.name === 'TaskA'), startTime: 0, endTime: 100, duration: 100, @@ -636,7 +659,8 @@ describe('Main Thread Tasks', () => { attributableURLs: [], children: [], - event: traceEvents.find(event => event.name === 'TaskB' && event.ph === 'B'), + event: traceEvents.find(evt => evt.ph === 'B' && evt.name === 'TaskB'), + endEvent: traceEvents.find(evt => evt.ph === 'E' && evt.name === 'TaskB'), startTime: 25, endTime: 100, duration: 75, @@ -665,13 +689,14 @@ describe('Main Thread Tasks', () => { const tasks = run({traceEvents}); const [taskA, taskB] = tasks; - expect(tasks).toEqual([ + expect(tasks).toMatchObject([ { parent: undefined, attributableURLs: [], children: [taskB], - event: traceEvents.find(event => event.name === 'TaskA'), + event: traceEvents.find(evt => evt.ph === 'B' && evt.name === 'TaskA'), + endEvent: traceEvents.find(evt => evt.ph === 'E' && evt.name === 'TaskA'), startTime: 0, endTime: 100, duration: 100, @@ -722,7 +747,8 @@ describe('Main Thread Tasks', () => { attributableURLs: [], children: [taskB], - event: traceEvents.find(event => event.name === 'TaskA'), + event: traceEvents.find(evt => evt.ph === 'B' && evt.name === 'TaskA'), + endEvent: traceEvents.find(evt => evt.ph === 'E' && evt.name === 'TaskA'), startTime: 0, endTime: 100, duration: 100, @@ -735,7 +761,8 @@ describe('Main Thread Tasks', () => { attributableURLs: [], children: [taskC], - event: traceEvents.find(event => event.name === 'TaskB' && event.ph === 'B'), + event: traceEvents.find(evt => evt.ph === 'B' && evt.name === 'TaskB'), + endEvent: traceEvents.find(evt => evt.ph === 'E' && evt.name === 'TaskB'), startTime: 25, endTime: 90, duration: 65, @@ -748,7 +775,8 @@ describe('Main Thread Tasks', () => { attributableURLs: [], children: [], - event: traceEvents.find(event => event.name === 'TaskC' && event.ph === 'B'), + event: traceEvents.find(evt => evt.ph === 'B' && evt.name === 'TaskC'), + endEvent: traceEvents.find(evt => evt.ph === 'E' && evt.name === 'TaskC'), startTime: 25, endTime: 60, duration: 35, diff --git a/types/externs.d.ts b/types/externs.d.ts index 62226156afef..d8abe93bb6c3 100644 --- a/types/externs.d.ts +++ b/types/externs.d.ts @@ -270,6 +270,11 @@ declare global { timeDeltas?: TraceCpuProfile['timeDeltas']; cpuProfile?: TraceCpuProfile; callFrame?: Required['nodes'][0]['callFrame'] + /** Marker for each synthetic CPU profiler event for the range of _potential_ ts values. */ + _syntheticProfilerRange?: { + earliestPossibleTimestamp: number + latestPossibleTimestamp: number + } stackTrace?: { url: string }[];