From 88eb8068cbab8036d62d469edd79de82531ef427 Mon Sep 17 00:00:00 2001 From: Jamie Wong Date: Wed, 17 Jan 2018 11:00:39 -0800 Subject: [PATCH] Faster Chrome profile import --- flamechart.ts | 2 + import/chrome.ts | 104 ++++++++++++++++++++++----------------- profile.ts | 32 +++++++++--- sample/simple.cpuprofile | 1 + sample/simple.js | 24 +++++++++ 5 files changed, 110 insertions(+), 53 deletions(-) create mode 100644 sample/simple.cpuprofile create mode 100644 sample/simple.js diff --git a/flamechart.ts b/flamechart.ts index 5213a06..6ce6982 100644 --- a/flamechart.ts +++ b/flamechart.ts @@ -69,5 +69,7 @@ export class Flamechart { this.totalWeight = source.getTotalWeight() source.forEachCall(openFrame, closeFrame) + + if (!isFinite(this.minFrameWidth)) this.minFrameWidth = 1 } } \ No newline at end of file diff --git a/import/chrome.ts b/import/chrome.ts index 72c69e1..e280fff 100644 --- a/import/chrome.ts +++ b/import/chrome.ts @@ -1,5 +1,5 @@ import {Profile, TimeFormatter, FrameInfo} from '../profile' -import {getOrInsert} from '../utils' +import {getOrInsert, lastOf} from '../utils' interface TimelineEvent { pid: number, @@ -50,6 +50,24 @@ export function importFromChromeTimeline(events: TimelineEvent[]) { return importFromChromeCPUProfile(chromeProfile) } + +const callFrameToFrameInfo = new Map() +function frameInfoForCallFrame(callFrame: CPUProfileCallFrame) { + return getOrInsert(callFrameToFrameInfo, callFrame, (callFrame) => { + const name = callFrame.functionName || "(anonymous)" + const file = callFrame.url + const line = callFrame.lineNumber + const col = callFrame.columnNumber + return { + key: `${name}:${file}:${line}:${col}`, + name, + file, + line, + col + } + }) +} + export function importFromChromeCPUProfile(chromeProfile: CPUProfile) { const profile = new Profile(chromeProfile.endTime - chromeProfile.startTime) @@ -90,60 +108,56 @@ export function importFromChromeCPUProfile(chromeProfile: CPUProfile) { timeDeltas.push(elapsed) } - const callFrameToFrameInfo = new Map() + let prevStack: CPUProfileNode[] = [] - let lastNonGCStackTop: CPUProfileNode | null = null + let value = 0 for (let i = 0; i < samples.length; i++) { const timeDelta = timeDeltas[i+1] || 0 const nodeId = samples[i] - let node = nodeById.get(nodeId) - if (!node) continue + let stackTop = nodeById.get(nodeId) + if (!stackTop) continue - const stack: FrameInfo[] = [] + // Find lowest common ancestor of the current stack and the previous one + let lca: CPUProfileNode | null = null - if (node.callFrame.functionName === "(garbage collector)") { + // This is O(n^2), but n should be relatively small here (stack height), + // so hopefully this isn't much of a problem + for ( + lca = stackTop; + lca && prevStack.indexOf(lca) === -1; + lca = lca.callFrame.functionName === "(garbage collector)" ? lastOf(prevStack) : lca.parent || null + ) {} + + // Close frames that are no longer open + while (prevStack.length > 0 && lastOf(prevStack) != lca) { + const closingNode = prevStack.pop()! + const frame = frameInfoForCallFrame(closingNode.callFrame) + profile.leaveFrame(frame, value) + } + + // Open frames that are now becoming open + const toOpen: CPUProfileNode[] = [] + for ( + let node: CPUProfileNode | null = stackTop; + node && node != lca; // Place GC calls on top of the previous call stack - const frame = getOrInsert(callFrameToFrameInfo, node.callFrame, (callFrame) => ({ - key: callFrame.functionName, - name: callFrame.functionName, - file: callFrame.url, - line: callFrame.lineNumber, - col: callFrame.columnNumber - })) - stack.push(frame) - if (!lastNonGCStackTop) { - profile.appendSample(stack, timeDelta) - continue - } else { - node = lastNonGCStackTop - } + node = node.callFrame.functionName === "(garbage collector)" ? lastOf(prevStack) : node.parent || null + ) { + toOpen.push(node) + } + toOpen.reverse() + + for (let node of toOpen) { + profile.enterFrame(frameInfoForCallFrame(node.callFrame), value) } - lastNonGCStackTop = node + prevStack = prevStack.concat(toOpen) + value += timeDelta + } - // TODO(jlfwong): This is silly and slow, but good enough for now - for (; node; node = node.parent) { - if (node.callFrame.functionName === '(root)') continue - if (node.callFrame.functionName === '(idle)') continue - - const frame = getOrInsert(callFrameToFrameInfo, node.callFrame, (callFrame) => { - const name = callFrame.functionName || "(anonymous)" - const file = callFrame.url - const line = callFrame.lineNumber - const col = callFrame.columnNumber - return { - key: `${name}:${file}:${line}:${col}`, - name, - file, - line, - col - } - }) - stack.push(frame) - } - stack.reverse() - - profile.appendSample(stack, timeDelta) + // Close frames that are open at the end of the trace + for (let i = prevStack.length - 1; i >= 0; i--) { + profile.leaveFrame(frameInfoForCallFrame(prevStack[i].callFrame), value) } profile.setValueFormatter(new TimeFormatter('microseconds')) diff --git a/profile.ts b/profile.ts index 12882c5..326fa64 100644 --- a/profile.ts +++ b/profile.ts @@ -288,16 +288,26 @@ export class Profile { let stack = useAppendOrder ? this.appendOrderStack : this.groupedOrderStack this.addWeightsToNodes(value, stack) - let node = lastOf(stack) - if (node) { - const last = useAppendOrder ? lastOf(node.children) : node.children.find(c => c.frame === frame) + let prevTop = lastOf(stack) + + if (prevTop) { + if (useAppendOrder) { + const delta = value - this.lastValue! + if (delta > 0) { + this.samples.push(prevTop) + this.weights.push(value - this.lastValue!) + } + } + + const last = useAppendOrder ? lastOf(prevTop.children) : prevTop.children.find(c => c.frame === frame) + let node: CallTreeNode if (last && last.frame == frame) { node = last } else { - const parent = node - node = new CallTreeNode(frame, node) - parent.children.push(node) + node = new CallTreeNode(frame, prevTop) + prevTop.children.push(node) } + stack.push(node) } } enterFrame(frameInfo: FrameInfo, value: number) { @@ -317,7 +327,12 @@ export class Profile { this.addWeightsToNodes(value, stack) if (useAppendOrder) { - this.appendOrderStack.pop() + const leavingStackTop = this.appendOrderStack.pop() + const delta = value - this.lastValue! + if (delta > 0) { + this.samples.push(leavingStackTop!) + this.weights.push(value - this.lastValue!) + } } else { this.groupedOrderStack.pop() } @@ -325,6 +340,7 @@ export class Profile { leaveFrame(frameInfo: FrameInfo, value: number) { const frame = getOrInsert(this.frames, frameInfo.key, () => new Frame(frameInfo)) this.addWeightsToFrames(value) + this._leaveFrame(frame, value, true) this._leaveFrame(frame, value, false) @@ -334,7 +350,7 @@ export class Profile { if (frameCount === 1) { this.framesInStack.delete(frame) } else { - this.framesInStack.set(frame, frameCount) + this.framesInStack.set(frame, frameCount - 1) } this.lastValue = value } diff --git a/sample/simple.cpuprofile b/sample/simple.cpuprofile new file mode 100644 index 0000000..56aaa72 --- /dev/null +++ b/sample/simple.cpuprofile @@ -0,0 +1 @@ +{"nodes":[{"id":1,"callFrame":{"functionName":"(root)","scriptId":"0","url":"","lineNumber":-1,"columnNumber":-1},"hitCount":0,"children":[2]},{"id":2,"callFrame":{"functionName":"","scriptId":"164","url":"","lineNumber":0,"columnNumber":0},"hitCount":0,"children":[3]},{"id":3,"callFrame":{"functionName":"a","scriptId":"164","url":"","lineNumber":0,"columnNumber":10},"hitCount":0,"children":[4,6]},{"id":4,"callFrame":{"functionName":"b","scriptId":"164","url":"","lineNumber":5,"columnNumber":10},"hitCount":0,"children":[5]},{"id":5,"callFrame":{"functionName":"d","scriptId":"164","url":"","lineNumber":13,"columnNumber":10},"hitCount":14,"positionTicks":[{"line":16,"ticks":13},{"line":14,"ticks":1}],"children":[]},{"id":6,"callFrame":{"functionName":"c","scriptId":"164","url":"","lineNumber":9,"columnNumber":10},"hitCount":0,"children":[7]},{"id":7,"callFrame":{"functionName":"d","scriptId":"164","url":"","lineNumber":13,"columnNumber":10},"hitCount":14,"positionTicks":[{"line":16,"ticks":14}],"children":[]}],"startTime":163140599286,"endTime":163140647178,"samples":[2,5,5,5,5,5,5,5,5,5,5,5,5,5,5,7,7,7,7,7,7,7,7,7,7,7,7,7,7],"timeDeltas":[11575,1060,1045,1270,1271,1187,1274,1270,1020,1249,1258,1272,1266,1075,1271,1274,1268,1266,1289,1286,1272,1136,1276,1274,1265,1265,1271,1272,1143]} \ No newline at end of file diff --git a/sample/simple.js b/sample/simple.js new file mode 100644 index 0000000..aa5f8b7 --- /dev/null +++ b/sample/simple.js @@ -0,0 +1,24 @@ +function a() { + b(); + c(); +} + +function b() { + d(); +} + +function c() { + d(); +} + +function d() { + let prod = 1; + for (let i = 1; i < 10000000; i++) { + prod *= i + } + return prod; +} + +console.profile('a') +a(); +console.profileEnd('a') \ No newline at end of file