Navigation Menu

Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Add import of v8 heap allocation profile #170

Merged
merged 6 commits into from Oct 8, 2018
Merged
Show file tree
Hide file tree
Changes from 5 commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Jump to
Jump to file
Failed to load files.
Diff view
Diff view
1 change: 1 addition & 0 deletions sample/profiles/Chrome/69/Heap-20181005T144546.heapprofile

Large diffs are not rendered by default.

@@ -0,0 +1 @@
{"head":{"callFrame":{"functionName":"(root)","scriptId":"0","url":"","lineNumber":-1,"columnNumber":-1},"selfSize":0,"children":[{"callFrame":{"functionName":"_tickDomainCallback","scriptId":"27","url":"internal/process/next_tick.js","lineNumber":192,"columnNumber":30},"selfSize":0,"children":[{"callFrame":{"functionName":"emit","scriptId":"37","url":"internal/child_process.js","lineNumber":770,"columnNumber":15},"selfSize":0,"children":[{"callFrame":{"functionName":"emitTwo","scriptId":"17","url":"events.js","lineNumber":123,"columnNumber":16},"selfSize":0,"children":[{"callFrame":{"functionName":"onInternalMessage","scriptId":"76","url":"internal/cluster/utils.js","lineNumber":30,"columnNumber":35},"selfSize":0,"children":[{"callFrame":{"functionName":"onmessage","scriptId":"74","url":"internal/cluster/child.js","lineNumber":41,"columnNumber":20},"selfSize":0,"children":[{"callFrame":{"functionName":"onconnection","scriptId":"74","url":"internal/cluster/child.js","lineNumber":169,"columnNumber":21},"selfSize":0,"children":[{"callFrame":{"functionName":"onconnection","scriptId":"39","url":"net.js","lineNumber":1533,"columnNumber":21},"selfSize":0,"children":[{"callFrame":{"functionName":"Socket.onconnect","scriptId":"255","url":"/usr/app/node_modules/pm2-axon/lib/sockets/sock.js","lineNumber":305,"columnNumber":37},"selfSize":0,"children":[{"callFrame":{"functionName":"Socket.addSocket","scriptId":"255","url":"/usr/app/node_modules/pm2-axon/lib/sockets/sock.js","lineNumber":173,"columnNumber":37},"selfSize":33000,"children":[]}]}]}]}]}]},{"callFrame":{"functionName":"listener","scriptId":"235","url":"/usr/app/node_modules/@pm2/io/build/main/src/features/actions.js","lineNumber":14,"columnNumber":12},"selfSize":0,"children":[{"callFrame":{"functionName":"actionFeature.action","scriptId":"239","url":"/usr/app/node_modules/@pm2/io/build/main/src/actions/profilingHeap.js","lineNumber":51,"columnNumber":59},"selfSize":0,"children":[{"callFrame":{"functionName":"__awaiter","scriptId":"226","url":"/usr/app/node_modules/tslib/tslib.js","lineNumber":101,"columnNumber":25},"selfSize":0,"children":[{"callFrame":{"functionName":"Promise","scriptId":"0","url":"","lineNumber":-1,"columnNumber":-1},"selfSize":0,"children":[{"callFrame":{"functionName":"","scriptId":"226","url":"/usr/app/node_modules/tslib/tslib.js","lineNumber":102,"columnNumber":49},"selfSize":0,"children":[{"callFrame":{"functionName":"next","scriptId":"0","url":"","lineNumber":-1,"columnNumber":-1},"selfSize":0,"children":[{"callFrame":{"functionName":"","scriptId":"239","url":"/usr/app/node_modules/@pm2/io/build/main/src/actions/profilingHeap.js","lineNumber":51,"columnNumber":120},"selfSize":0,"children":[{"callFrame":{"functionName":"stop","scriptId":"609","url":"/usr/app/node_modules/@pm2/io/build/main/src/profiling/profilingHeap.js","lineNumber":32,"columnNumber":8},"selfSize":0,"children":[{"callFrame":{"functionName":"__awaiter","scriptId":"226","url":"/usr/app/node_modules/tslib/tslib.js","lineNumber":101,"columnNumber":25},"selfSize":0,"children":[{"callFrame":{"functionName":"Promise","scriptId":"0","url":"","lineNumber":-1,"columnNumber":-1},"selfSize":0,"children":[{"callFrame":{"functionName":"","scriptId":"226","url":"/usr/app/node_modules/tslib/tslib.js","lineNumber":102,"columnNumber":49},"selfSize":0,"children":[{"callFrame":{"functionName":"","scriptId":"609","url":"/usr/app/node_modules/@pm2/io/build/main/src/profiling/profilingHeap.js","lineNumber":33,"columnNumber":65},"selfSize":32800,"children":[]}]}]}]}]}]}]}]}]}]}]}]}]}]},{"callFrame":{"functionName":"","scriptId":"438","url":"/usr/app/node_modules/kareem/index.js","lineNumber":16,"columnNumber":36},"selfSize":0,"children":[{"callFrame":{"functionName":"","scriptId":"438","url":"/usr/app/node_modules/kareem/index.js","lineNumber":145,"columnNumber":38},"selfSize":0,"children":[{"callFrame":{"functionName":"Query._findOne","scriptId":"484","url":"/usr/app/node_modules/mongoose/lib/query.js","lineNumber":1139,"columnNumber":35},"selfSize":0,"children":[{"callFrame":{"functionName":"Query.findOne","scriptId":"487","url":"/usr/app/node_modules/mquery/lib/mquery.js","lineNumber":1762,"columnNumber":35},"selfSize":0,"children":[{"callFrame":{"functionName":"NodeCollection.findOne","scriptId":"496","url":"/usr/app/node_modules/mquery/lib/collection/node.js","lineNumber":36,"columnNumber":44},"selfSize":0,"children":[{"callFrame":{"functionName":"NativeCollection.(anonymous function)","scriptId":"552","url":"/usr/app/node_modules/mongoose/lib/drivers/node-mongodb-native/collection.js","lineNumber":103,"columnNumber":42},"selfSize":0,"children":[{"callFrame":{"functionName":"Collection.findOne","scriptId":"417","url":"/usr/app/node_modules/mongodb/lib/collection.js","lineNumber":1333,"columnNumber":39},"selfSize":0,"children":[{"callFrame":{"functionName":"findOne","scriptId":"417","url":"/usr/app/node_modules/mongodb/lib/collection.js","lineNumber":1351,"columnNumber":22},"selfSize":0,"children":[{"callFrame":{"functionName":"Cursor.next","scriptId":"410","url":"/usr/app/node_modules/mongodb/lib/cursor.js","lineNumber":248,"columnNumber":32},"selfSize":0,"children":[{"callFrame":{"functionName":"nextObject","scriptId":"410","url":"/usr/app/node_modules/mongodb/lib/cursor.js","lineNumber":646,"columnNumber":25},"selfSize":0,"children":[{"callFrame":{"functionName":"Cursor.next","scriptId":"385","url":"/usr/app/node_modules/mongodb/node_modules/mongodb-core/lib/cursor.js","lineNumber":691,"columnNumber":32},"selfSize":0,"children":[{"callFrame":{"functionName":"nextFunction","scriptId":"385","url":"/usr/app/node_modules/mongodb/node_modules/mongodb-core/lib/cursor.js","lineNumber":515,"columnNumber":27},"selfSize":0,"children":[{"callFrame":{"functionName":"WireProtocol.command","scriptId":"387","url":"/usr/app/node_modules/mongodb/node_modules/mongodb-core/lib/wireprotocol/2_4_support.js","lineNumber":134,"columnNumber":41},"selfSize":0,"children":[{"callFrame":{"functionName":"setupClassicFind","scriptId":"387","url":"/usr/app/node_modules/mongodb/node_modules/mongodb-core/lib/wireprotocol/2_4_support.js","lineNumber":148,"columnNumber":31},"selfSize":0,"children":[{"callFrame":{"functionName":"Query","scriptId":"363","url":"/usr/app/node_modules/mongodb/node_modules/mongodb-core/lib/connection/commands.js","lineNumber":38,"columnNumber":20},"selfSize":32800,"children":[]}]}]}]}]}]}]}]}]}]}]}]}]}]}]},{"callFrame":{"functionName":"","scriptId":"438","url":"/usr/app/node_modules/kareem/index.js","lineNumber":107,"columnNumber":36},"selfSize":0,"children":[{"callFrame":{"functionName":"","scriptId":"438","url":"/usr/app/node_modules/kareem/index.js","lineNumber":168,"columnNumber":62},"selfSize":0,"children":[{"callFrame":{"functionName":"","scriptId":"484","url":"/usr/app/node_modules/mongoose/lib/query.js","lineNumber":2173,"columnNumber":40},"selfSize":0,"children":[{"callFrame":{"functionName":"global._db.Bucket.findOne.exec","scriptId":"313","url":"/usr/app/src/shared/lib/cache.js","lineNumber":63,"columnNumber":47},"selfSize":0,"children":[{"callFrame":{"functionName":"Document.toObject","scriptId":"464","url":"/usr/app/node_modules/mongoose/lib/document.js","lineNumber":2120,"columnNumber":38},"selfSize":0,"children":[{"callFrame":{"functionName":"Document.$toObject","scriptId":"464","url":"/usr/app/node_modules/mongoose/lib/document.js","lineNumber":1913,"columnNumber":39},"selfSize":0,"children":[{"callFrame":{"functionName":"clone","scriptId":"432","url":"/usr/app/node_modules/mongoose/lib/utils.js","lineNumber":238,"columnNumber":30},"selfSize":0,"children":[{"callFrame":{"functionName":"cloneObject","scriptId":"432","url":"/usr/app/node_modules/mongoose/lib/utils.js","lineNumber":287,"columnNumber":20},"selfSize":32800,"children":[{"callFrame":{"functionName":"keys","scriptId":"0","url":"","lineNumber":-1,"columnNumber":-1},"selfSize":32832,"children":[]},{"callFrame":{"functionName":"cloneArray","scriptId":"432","url":"/usr/app/node_modules/mongoose/lib/utils.js","lineNumber":330,"columnNumber":19},"selfSize":65568,"children":[]}]}]},{"callFrame":{"functionName":"applyGetters","scriptId":"464","url":"/usr/app/node_modules/mongoose/lib/document.js","lineNumber":2168,"columnNumber":21},"selfSize":33432,"children":[]}]}]}]}]}]}]}]},{"callFrame":{"functionName":"onread","scriptId":"39","url":"net.js","lineNumber":578,"columnNumber":15},"selfSize":0,"children":[{"callFrame":{"functionName":"addChunk","scriptId":"42","url":"_stream_readable.js","lineNumber":260,"columnNumber":17},"selfSize":0,"children":[{"callFrame":{"functionName":"emit","scriptId":"17","url":"events.js","lineNumber":155,"columnNumber":43},"selfSize":0,"children":[{"callFrame":{"functionName":"ondata","scriptId":"42","url":"_stream_readable.js","lineNumber":635,"columnNumber":17},"selfSize":0,"children":[{"callFrame":{"functionName":"Parser._write","scriptId":"262","url":"/usr/app/node_modules/amp/lib/stream.js","lineNumber":37,"columnNumber":34},"selfSize":0,"children":[{"callFrame":{"functionName":"Buffer.alloc","scriptId":"23","url":"buffer.js","lineNumber":231,"columnNumber":23},"selfSize":32800,"children":[]}]}]},{"callFrame":{"functionName":"","scriptId":"289","url":"/usr/app/node_modules/redis/index.js","lineNumber":270,"columnNumber":36},"selfSize":0,"children":[{"callFrame":{"functionName":"execute","scriptId":"295","url":"/usr/app/node_modules/redis-parser/lib/parser.js","lineNumber":520,"columnNumber":59},"selfSize":0,"children":[{"callFrame":{"functionName":"returnReply","scriptId":"289","url":"/usr/app/node_modules/redis/index.js","lineNumber":190,"columnNumber":30},"selfSize":0,"children":[{"callFrame":{"functionName":"emit","scriptId":"17","url":"events.js","lineNumber":155,"columnNumber":43},"selfSize":0,"children":[{"callFrame":{"functionName":"pmessageHandler","scriptId":"311","url":"/usr/app/node_modules/node-redis-pubsub/lib/node-redis-pubsub.js","lineNumber":69,"columnNumber":32},"selfSize":164072,"children":[]}]}]}]}]},{"callFrame":{"functionName":"","scriptId":"362","url":"/usr/app/node_modules/mongodb/node_modules/mongodb-core/lib/connection/connection.js","lineNumber":179,"columnNumber":17},"selfSize":0,"children":[{"callFrame":{"functionName":"","scriptId":"359","url":"/usr/app/node_modules/mongodb/node_modules/mongodb-core/lib/topologies/server.js","lineNumber":333,"columnNumber":17},"selfSize":0,"children":[{"callFrame":{"functionName":"Response.parse","scriptId":"363","url":"/usr/app/node_modules/mongodb/node_modules/mongodb-core/lib/connection/commands.js","lineNumber":472,"columnNumber":35},"selfSize":0,"children":[{"callFrame":{"functionName":"BSON.deserialize","scriptId":"365","url":"/usr/app/node_modules/bson/lib/bson/bson.js","lineNumber":89,"columnNumber":37},"selfSize":0,"children":[{"callFrame":{"functionName":"deserializeObject","scriptId":"380","url":"/usr/app/node_modules/bson/lib/bson/parser/deserializer.js","lineNumber":36,"columnNumber":32},"selfSize":0,"children":[{"callFrame":{"functionName":"deserializeObject","scriptId":"380","url":"/usr/app/node_modules/bson/lib/bson/parser/deserializer.js","lineNumber":36,"columnNumber":32},"selfSize":0,"children":[{"callFrame":{"functionName":"deserializeObject","scriptId":"380","url":"/usr/app/node_modules/bson/lib/bson/parser/deserializer.js","lineNumber":36,"columnNumber":32},"selfSize":0,"children":[{"callFrame":{"functionName":"stringSlice","scriptId":"23","url":"buffer.js","lineNumber":554,"columnNumber":20},"selfSize":32800,"children":[]}]}]}]}]}]}]}]}]}]}]},{"callFrame":{"functionName":"processImmediate","scriptId":"49","url":"timers.js","lineNumber":719,"columnNumber":25},"selfSize":0,"children":[{"callFrame":{"functionName":"tryOnImmediate","scriptId":"49","url":"timers.js","lineNumber":762,"columnNumber":23},"selfSize":0,"children":[{"callFrame":{"functionName":"runCallback","scriptId":"49","url":"timers.js","lineNumber":801,"columnNumber":20},"selfSize":0,"children":[{"callFrame":{"functionName":"","scriptId":"490","url":"/usr/app/node_modules/mquery/lib/utils.js","lineNumber":135,"columnNumber":17},"selfSize":0,"children":[{"callFrame":{"functionName":"","scriptId":"484","url":"/usr/app/node_modules/mongoose/lib/query.js","lineNumber":1152,"columnNumber":45},"selfSize":0,"children":[{"callFrame":{"functionName":"completeOne","scriptId":"484","url":"/usr/app/node_modules/mongoose/lib/query.js","lineNumber":1488,"columnNumber":20},"selfSize":0,"children":[{"callFrame":{"functionName":"Document.init","scriptId":"464","url":"/usr/app/node_modules/mongoose/lib/document.js","lineNumber":267,"columnNumber":34},"selfSize":0,"children":[{"callFrame":{"functionName":"DocumentArray.cast","scriptId":"455","url":"/usr/app/node_modules/mongoose/lib/schema/documentarray.js","lineNumber":192,"columnNumber":39},"selfSize":0,"children":[{"callFrame":{"functionName":"EmbeddedDocument","scriptId":"455","url":"/usr/app/node_modules/mongoose/lib/schema/documentarray.js","lineNumber":24,"columnNumber":27},"selfSize":0,"children":[{"callFrame":{"functionName":"EmbeddedDocument","scriptId":"462","url":"/usr/app/node_modules/mongoose/lib/types/embedded.js","lineNumber":19,"columnNumber":25},"selfSize":0,"children":[{"callFrame":{"functionName":"Document","scriptId":"464","url":"/usr/app/node_modules/mongoose/lib/document.js","lineNumber":37,"columnNumber":17},"selfSize":0,"children":[{"callFrame":{"functionName":"forEach","scriptId":"0","url":"","lineNumber":-1,"columnNumber":-1},"selfSize":0,"children":[{"callFrame":{"functionName":"","scriptId":"464","url":"/usr/app/node_modules/mongoose/lib/document.js","lineNumber":1848,"columnNumber":38},"selfSize":32800,"children":[]}]}]}]}]}]}]}]}]}]}]}]}]}]}}
7 changes: 7 additions & 0 deletions src/import/index.ts
Expand Up @@ -12,6 +12,7 @@ import {importFromLinuxPerf} from './linux-tools-perf'
import {ProfileDataSource, TextProfileDataSource, MaybeCompressedDataReader} from './utils'
import {importAsPprofProfile} from './pprof'
import {decodeBase64} from '../lib/utils'
import {importFromChromeHeapProfile} from './v8heapalloc'

export async function importProfileGroupFromText(
fileName: string,
Expand Down Expand Up @@ -103,6 +104,9 @@ async function _importProfileGroup(dataSource: ProfileDataSource): Promise<Profi
} else if (fileName.endsWith('.v8log.json')) {
console.log('Importing as --prof-process v8 log')
return toGroup(importFromV8ProfLog(JSON.parse(contents)))
} else if (fileName.endsWith('.heapprofile')) {
Copy link
Owner

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I try to make every kind of profile import even if it has the incorrect extension by using heuristics. Can you please add a sensible heuristic to the list below for the second pass?

Maybe something like:

'head' in parsed && 'callFrame' in parsed['head']

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I went for 'head' in parsed && 'selfSize' in parsed['head'] because it's more specific to the heap profile format

console.log('Importing as Chrome Heap Profile')
return toGroup(importFromChromeHeapProfile(JSON.parse(contents)))
}

// Second pass: Try to guess what file format it is based on structure
Expand All @@ -129,6 +133,9 @@ async function _importProfileGroup(dataSource: ProfileDataSource): Promise<Profi
} else if ('code' in parsed && 'functions' in parsed && 'ticks' in parsed) {
console.log('Importing as --prof-process v8 log')
return toGroup(importFromV8ProfLog(parsed))
} else if ('head' in parsed && 'selfSize' in parsed['head']) {
console.log('Importing as Chrome Heap Profile')
return toGroup(importFromChromeHeapProfile(JSON.parse(contents)))
}
} else {
// Format is not JSON
Expand Down
9 changes: 9 additions & 0 deletions src/import/v8heapalloc.test.ts
@@ -0,0 +1,9 @@
import {checkProfileSnapshot} from '../lib/test-utils'

test('importV8HeapAlloc from Chrome', async () => {
await checkProfileSnapshot('./sample/profiles/Chrome/69/Heap-20181005T144546.heapprofile')
Copy link
Owner

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The way these tests work is by generating output, then comparing against output that's checked into the repository. To seed the initial data, you'll need to run npm run jest -- -u, which should create local snapshot files that you'll need to check into the repository. I believe that should result in CI passing.

CI is currently failing because jest is run in a mode which does not write snapshots to disk, it only compares them. It doesn't find a corresponding snapshot on disk to compare against since none was checked in, resulting in a test failure.

See: https://jestjs.io/docs/en/snapshot-testing

})

test('importV8HeapAlloc from NodeJS', async () => {
await checkProfileSnapshot('./sample/profiles/node/10.11.0/Heap-20181003T105432.heapprofile')
})
109 changes: 109 additions & 0 deletions src/import/v8heapalloc.ts
@@ -0,0 +1,109 @@
import {Profile, FrameInfo, StackListProfileBuilder} from '../lib/profile'
Copy link
Owner

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Is there a URL you can add to a comment here that provides documentation on this file format? Or at least a link that explains how to record this kind of profile?

import {getOrInsert} from '../lib/utils'
import {ByteFormatter} from '../lib/value-formatters'

/**
Copy link
Owner

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This is perfect! Thanks for writing this :)

* The V8 Heap Allocation profile is a way to represent heap allocation for each
* javascript function. The format is a simple tree where the weight of each node
* represent the memory allocated by the function and all its callee.
* You can find more information on how to get a profile there :
* https://developers.google.com/web/tools/chrome-devtools/memory-problems/#allocation-profile
* You need to scroll down to "Investigate memory allocation by function"
*
* Note that Node.JS can retrieve this kind of profile via the Inspector protocol.
*/

interface HeapProfileCallFrame {
columnNumber: number
functionName: string
lineNumber: number
scriptId: string
url: string
}

interface HeapProfileNode {
callFrame: HeapProfileCallFrame
selfSize: number
children: HeapProfileNode[]
id: number
parent?: number
totalSize: number
}

interface HeapProfile {
head: HeapProfileNode
}

const callFrameToFrameInfo = new Map<HeapProfileCallFrame, FrameInfo>()
function frameInfoForCallFrame(callFrame: HeapProfileCallFrame) {
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 importFromChromeHeapProfile(chromeProfile: HeapProfile): Profile {
const nodeById = new Map<number, HeapProfileNode>()
let currentId = 0
const computeId = (node: HeapProfileNode, parent?: HeapProfileNode) => {
node.id = currentId++
nodeById.set(node.id, node)
if (parent) {
node.parent = parent.id
}

node.children.forEach(children => computeId(children, node))
}
computeId(chromeProfile.head)

// Compute the total size
const computeTotalSize = (node: HeapProfileNode): number => {
if (node.children.length === 0) return node.selfSize || 0
const totalChild = node.children.reduce((total: number, children) => {
total += computeTotalSize(children)
return total
}, node.selfSize)
node.totalSize = totalChild
return totalChild
}
const total = computeTotalSize(chromeProfile.head)

// Compute all stacks by taking each last node and going upward
const stacks: HeapProfileNode[][] = []
for (let currentNode of nodeById.values()) {
let stack: HeapProfileNode[] = []
stack.push(currentNode)
// While we found a parent
while (true) {
if (currentNode.parent === undefined) break
const parent = nodeById.get(currentNode.parent)
if (parent === undefined) break
Copy link
Owner

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

In this case I would just do if (!parent) break, since any node returned by nodeById.get(...) will not be falsy. if (parent != null) would also be fine.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Performance wise, it's better to check against the type you need than relying on V8 adding the check for 0/null/undefined for you
Since any Map return undefined if no entry is found, i believe we can check only for undefined

// Push the parent at the beginning of the stack
stack.unshift(parent)
Copy link
Owner

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Weird! I would've expected doing repeated stack.push(parent) followed by a stack.reverse() at the end to be more efficient than doing repeated unshift calls, but it looks like that's wrong? https://jsperf.com/array-unshift-vs-array-push-and-array-reverse. I would've thought that arrays would be implemented as vectors, making unshift an O(n) operation, but it looks like it's optimized really well somehow.

currentNode = parent
}
stacks.push(stack)
}

const profile = new StackListProfileBuilder(total)

for (let stack of stacks) {
const lastFrame = stack[stack.length - 1]
profile.appendSampleWithWeight(
stack.map(frame => frameInfoForCallFrame(frame.callFrame)),
lastFrame.selfSize,
)
}

profile.setValueFormatter(new ByteFormatter())
return profile.build()
}