/* this source code form is subject to the terms of the mozilla public * license, v. 2.0. if a copy of the mpl was not distributed with this * file, you can obtain one at http://mozilla.org/mpl/2.0/. */ /* * This file helps tracking Javascript object allocations. * It is only included in local builds as a debugging helper. * * It is typicaly used when running DevTools tests (either mochitests or DAMP). * To use it, you need to set the following environment variable: * DEBUG_DEVTOOLS_ALLOCATIONS="normal" * This will only print the number of JS objects created during your test. * DEBUG_DEVTOOLS_ALLOCATIONS="verbose" * This will print the allocation sites of all the JS objects created during your * test. i.e. from which files and lines the objects have been created. * In both cases, look for "DEVTOOLS ALLOCATION" in your terminal to see tracker's * output. * * But you can also import it from your test script if you want to focus on one * particular piece of code: * const { allocationTracker } = * require("devtools/shared/test-helpers/allocation-tracker"); * // Calling `allocationTracker` will immediately start recording allocations * let tracker = allocationTracker(); * * // Do something * * // If you want to log all the allocation sites, call this method: * tracker.logAllocationLog(); * // Or, if you want to only print the number of objects being allocated, call this: * tracker.logCount(); * // Once you are done, stop the tracker as it slow down execution a lot. * tracker.stop(); */ "use strict"; const MemoryReporter = Cc["@mozilla.org/memory-reporter-manager;1"].getService( Ci.nsIMemoryReporterManager ); const global = Cu.getGlobalForObject(this); const { addDebuggerToGlobal } = ChromeUtils.importESModule( "resource://gre/modules/jsdebugger.sys.mjs", { global: "contextual" } ); addDebuggerToGlobal(global); /** * Start recording JS object allocations. * * @param Object watchGlobal * One global object to observe. Only allocation made from this global * will be recorded. * @param Boolean watchAllGlobals * If true, allocations from everywhere are going to be recorded. * @param Boolean watchAllGlobals * If true, only allocations made from DevTools contexts are going to be recorded. */ exports.allocationTracker = function ({ watchGlobal, watchAllGlobals, watchDevToolsGlobals, } = {}) { dump("DEVTOOLS ALLOCATION: Start logging allocations\n"); let dbg = new global.Debugger(); // Enable allocation site tracking, to have the stack for each allocation dbg.memory.trackingAllocationSites = true; // Force saving *all* the allocation sites dbg.memory.allocationSamplingProbability = 1.0; // Bumps the default buffer size, which may prevent recording all the test allocations dbg.memory.maxAllocationsLogLength = 5000000; let acceptGlobal; if (watchGlobal) { acceptGlobal = () => false; dbg.addDebuggee(watchGlobal); } else if (watchAllGlobals) { acceptGlobal = () => true; } else if (watchDevToolsGlobals) { // Only accept globals related to DevTools const builtinGlobal = require("resource://devtools/shared/loader/builtin-modules.js"); acceptGlobal = g => { // self-hosting-global crashes when trying to call unsafeDereference if (g.class == "self-hosting-global") { dump("TRACKER NEW GLOBAL: - : " + g.class + "\n"); return false; } let ref = g.unsafeDereference(); // If we are on a toolbox's iframe, typically each panel's iframe // retrieve the toolbox iframe via window.top if (g.class == "Window" && ref.top) { ref = ref.top; } const location = Cu.getRealmLocation(ref); let accept = !!location.match(/devtools/i); // Also ignore the dedicated Sandbox used to spawn builtin-modules, // as well as its internal ChromeDebugger Sandbox. // We ignore the global used by the dedicated loader used to load // the allocation-tracker module. if ( ref == Cu.getGlobalForObject(builtinGlobal) || ref == Cu.getGlobalForObject(builtinGlobal.modules.ChromeDebugger) ) { accept = false; } dump( "TRACKER NEW GLOBAL: " + (accept ? "+" : "-") + " : " + location + "\n" ); return accept; }; } // Watch all globals if (watchAllGlobals || watchDevToolsGlobals) { dbg.addAllGlobalsAsDebuggees(); for (const g of dbg.getDebuggees()) { if (!acceptGlobal(g)) { dbg.removeDebuggee(g); } } } // Remove this global to ignore all its object/JS dbg.removeDebuggee(global); // addAllGlobalsAsDebuggees won't automatically track new ones, // so ensure tracking all new globals dbg.onNewGlobalObject = function (g) { if (acceptGlobal(g)) { dbg.addDebuggee(g); } }; return { get overflowed() { return dbg.memory.allocationsLogOverflowed; }, async startRecordingAllocations(debug_allocations) { // Do a first pass of GC, to ensure all to-be-freed objects from the first run // are really freed. // We have to temporarily disable allocation-site recording in order to ensure // freeing everything and especially avoid retaining objects in the allocation-log // related to `drainAllocationLog` feature. dbg.memory.allocationSamplingProbability = 0.0; // Also force clearing the allocation log in order to prevent holding alive globals // which have been destroyed before we start recording this.flushAllocations(); await this.doGC(); dbg.memory.allocationSamplingProbability = 1.0; // Measure the current process memory usage const memory = this.getAllocatedMemory(); // Then, record how many objects were already allocated, which should not be declared // as potential leaks. For ex, there is all the modules already loaded // in the main DevTools loader. const objects = this.stillAllocatedObjects(); // Flush the allocations so that the next call to logAllocationLog // ignore allocations which happened before this call. if (debug_allocations == "allocations") { this.flushAllocations(); } // Retrieve all allocation sites of all the objects already allocated. // So that we can ignore them when we stop the record. const allocations = debug_allocations == "leaks" ? this.getAllAllocations() : null; this.data = { memory, objects, allocations }; return this.data; }, async stopRecordingAllocations(debug_allocations) { // We have to flush the allocation log in order to prevent leaking some objects // being hold in memory solely by their allocation-site (i.e. `SavedFrame` in `Debugger::allocationsLog`) if (debug_allocations != "allocations") { this.flushAllocations(); } // In the content process we watch for all globals. // Disable allocation record immediately, as we get some allocation reported by the allocation-tracker itself. if (watchAllGlobals) { dbg.memory.allocationSamplingProbability = 0.0; } // Before computing allocations, re-do some GCs in order to free all what is to-be-freed. await this.doGC(); // If we are in the parent process, we watch only for devtools globals. // So we can more safely assert that no allocation occured while doing the GCs. // If means that the test we are recording is having pending operation which aren't properly recorded. if (!watchAllGlobals) { const allocations = dbg.memory.drainAllocationsLog(); if (allocations.length) { this.logAllocationLog( allocations, "Allocation that happened during the GC" ); console.error( "Allocation happened during the GC. Are you waiting correctly before calling stopRecordingAllocations?" ); } } const memory = this.getAllocatedMemory(); const objects = this.stillAllocatedObjects(); let leaks; if (debug_allocations == "allocations") { this.logAllocationLog(); } else if (debug_allocations == "leaks") { leaks = this.logAllocationSitesDiff(this.data.allocations); } return { objectsWithoutStack: objects.objectsWithoutStack - this.data.objects.objectsWithoutStack, objectsWithStack: objects.objectsWithStack - this.data.objects.objectsWithStack, memory: memory - this.data.memory, leaks, }; }, /** * Return the collection of currently allocated JS Objects. * * This returns an object whose structure is documented in logAllocationSites. */ getAllAllocations() { const sensus = dbg.memory.takeCensus({ breakdown: { by: "allocationStack" }, }); const sources = {}; for (const [k, v] of sensus.entries()) { const src = k.source || "UNKNOWN"; const line = k.line || "?"; const count = v.count; let item = sources[src]; if (!item) { item = sources[src] = { count: 0, lines: {} }; } item.count += count; if (line != -1) { if (!item.lines[line]) { item.lines[line] = 0; } item.lines[line] += count; } } return sources; }, /** * Substract count of `previousSources` from `newSources`. * This help know which allocations where done between `previousSources` and `newSources` records, * and, are still allocated. * * The structure of source objects is documented in logAllocationSites. */ sourcesDiff(previousSources, newSources) { for (const src in previousSources) { const previousItem = previousSources[src]; const item = newSources[src]; if (!item) { continue; } item.count -= previousItem.count; for (const line in previousItem.lines) { const count = previousItem.lines[line]; if (line != -1) { if (!item.lines[line]) { continue; } item.lines[line] -= count; } } } }, /** * Print to stdout data about all recorded allocations * * It prints an array of allocations per file, sorted by files allocating the most * objects. And get detail of allocation per line. * * [{ src: "chrome://devtools/content/framework/toolbox.js", * count: 210, // Total # of allocs for toolbox.js * lines: [ * "10: 200", // toolbox.js allocation 200 objects on line 10 * "124: 10 * ] * }, * { src: "chrome://devtools/content/inspector/inspector.js", * count: 12, * lines: [ * "20: 12", * ] * }] * * @param first Number * Retrieve only the top $first script allocation the most * objects */ logAllocationSites(message, sources, { first = 1000 } = {}) { const allocationList = Object.entries(sources) // Sort by number of total object .sort(([, itemA], [, itemB]) => itemB.count - itemA.count) // Keep only the first n-th sources, with the most allocations .filter((_, i) => i < first) .map(([src, item]) => { const lines = []; Object.entries(item.lines) // Filter out lines where we only freed objects .filter(([, count]) => count > 0) .sort(([lineA, countA], [lineB, countB]) => { if (countA != countB) { return countB - countA; } return lineB - lineA; }) .forEach(([line, count]) => { // Compress the data to make it readable on stdout lines.push(line + ": " + count); }); return { src, count: item.count, lines }; }) // Filter out modules where we only freed objects .filter(({ count }) => count > 0); dump( "DEVTOOLS ALLOCATION: " + message + ":\n" + JSON.stringify(allocationList, null, 2) + "\n" ); return allocationList; }, /** * This method requires a previous call to getAllAllocations * and will print only the allocation sites which are still allocated. * Usage: * const previousSources = this.getAllAllocations(); * ... exercice something, which may leak ... * this.logAllocationSitesDiff(previousSources); */ logAllocationSitesDiff(previousSources) { const newSources = this.getAllAllocations(); this.sourcesDiff(previousSources, newSources); return this.logAllocationSites("allocations which leaked", newSources); }, /** * Convert allocation structure coming out from Memory API's `drainAllocationsLog()` * to source structure documented in logAllocationSites. */ allocationsToSources(allocations) { const sources = {}; for (const alloc of allocations) { const { frame } = alloc; let src = "UNKNOWN"; let line = -1; try { if (frame) { src = frame.source || "UNKNOWN"; line = frame.line || -1; } } catch (e) { // For some frames accessing source throws } let item = sources[src]; if (!item) { item = sources[src] = { count: 0, lines: {} }; } item.count++; if (line != -1) { if (!item.lines[line]) { item.lines[line] = 0; } item.lines[line]++; } } return sources; }, /** * This method will log all the allocations that happened since the last call * to this method -or- to `flushAllocations`. * Reported allocations may have been freed. * Use `logAllocationSitesDiff` to know what hasn't been freed. */ logAllocationLog(allocations, msg = "") { if (!allocations) { allocations = dbg.memory.drainAllocationsLog(); } const sources = this.allocationsToSources(allocations); return this.logAllocationSites( msg ? msg : "all allocations (which may be freed or are still allocated)", sources ); }, logCount() { dump( "DEVTOOLS ALLOCATION: Javascript object allocations: " + this.countAllocations() + "\n" ); }, countAllocations() { // Fetch all allocation sites from Debugger API const allocations = dbg.memory.drainAllocationsLog(); return allocations.length; }, /** * Reset the allocation log, so that the next call to logAllocationLog/drainAllocationsLog * will report all allocations which happened after this call to flushAllocations. */ flushAllocations() { dbg.memory.drainAllocationsLog(); }, /** * Compute the live count of object currently allocated. * * `objects` attribute will count all the objects, * while `objectsWithNoStack` will report how many are missing allocation site/stack. */ stillAllocatedObjects() { const sensus = dbg.memory.takeCensus({ breakdown: { by: "allocationStack" }, }); let objectsWithStack = 0; let objectsWithoutStack = 0; for (const [k, v] of sensus.entries()) { // Objects with missing stack will all be keyed under "noStack" string, // while all others will have a stack object as key. if (k === "noStack") { objectsWithoutStack += v.count; } else { objectsWithStack += v.count; } } return { objectsWithStack, objectsWithoutStack }; }, /** * Reports the amount of OS memory used by the current process. */ getAllocatedMemory() { return MemoryReporter.residentUnique; }, async doGC() { // In order to get stable results, we really have to do 3 GC attempts // *and* do wait for 1s between each GC. const numCycles = 3; for (let i = 0; i < numCycles; i++) { Cu.forceGC(); Cu.forceCC(); await new Promise(resolve => Cu.schedulePreciseShrinkingGC(resolve)); // eslint-disable-next-line mozilla/no-arbitrary-setTimeout await new Promise(resolve => setTimeout(resolve, 1000)); } // Also call minimizeMemoryUsage as that's the only way to purge JIT cache. // CachedIR objects (JIT related objects) are ultimately leading to keep // all transient globals in memory. For some reason, when enabling trackingAllocationSites=true // we compute stack traces (SavedFrame) for each object being allocated. // This either create new CachedIR -or- force holding alive existing CachedIR // and CachedIR itself hold strong references to the transient globals. // See bug 1733480. await new Promise(resolve => MemoryReporter.minimizeMemoryUsage(resolve)); }, /** * Return the absolute file path to a memory snapshot. * This is used to compute dominator trees in `traceObjects`. */ getSnapshotFile() { return ChromeUtils.saveHeapSnapshot({ debugger: dbg }); }, /** * Print information about why a list of objects are being held in memory. * * @param Array objects * List of NodeId's of objects to debug. NodeIds can be retrieved * via ChromeUtils.getObjectNodeId. * @param String snapshotFile * Absolute path to a Heap snapshot file retrieved via this.getSnapshotFile. * This is used to trace content process objects. We have to record the snapshot * from the content process, but can only read it from the parent process because * of I/O restrictions in content processes. */ traceObjects(objects, snapshotFile) { // There is no API to get the heap snapshot at runtime, // the only way is to save it to disk and then load it from disk if (!snapshotFile) { snapshotFile = this.getSnapshotFile(); } const snapshot = ChromeUtils.readHeapSnapshot(snapshotFile); function getObjectClass(id) { if (!id) { return ""; } try { let stack = [...snapshot.describeNode({ by: "allocationStack" }, id)]; let line; if (stack) { stack = stack.find(([src]) => src != "noStack"); if (stack) { line = stack[0].line; stack = stack[0].source; if (stack) { const pstack = stack; stack = stack.match(/\/([^\/]+)$/); if (stack) { stack = stack[1]; } else { stack = pstack; } } else { stack = "no-source"; } } else { stack = "no-stack"; } } else { stack = "no-desc"; } return ( Object.entries( snapshot.describeNode({ by: "objectClass" }, id) )[0][0] + (stack ? "@" + stack + ":" + line : "") ); } catch (e) { if (e.name == "NS_ERROR_ILLEGAL_VALUE") { return ""; } return ""; } } function printPath(src, dst) { let paths; try { paths = snapshot.computeShortestPaths(src, [dst], 10); } catch (e) {} if (paths && paths.has(dst)) { let pathLength = Infinity; for (const path of paths.get(dst)) { // Only print the smaller paths. // The longer ones will only repeat the smaller ones, with some extra edges. if (path.length > pathLength) { continue; } pathLength = path.length; dump( "- " + path .map( ({ predecessor, edge }) => getObjectClass(predecessor) + "." + edge ) .join("\n \\--> ") + "\n \\--> " + getObjectClass(dst) + "\n" ); } } else { dump("NO-PATH\n"); } } const tree = snapshot.computeDominatorTree(); for (const objectNodeId of objects) { dump(" # Tracing: " + getObjectClass(objectNodeId) + "\n"); // Print the path from the global object down to leaked object. // This print the allocation site of each object which has a reference // to another object, ultimately leading to our leaked object. dump("### Path(s) from root:\n"); printPath(tree.root, objectNodeId); /** * This happens to be redundant with printPath, but printed the other way around. * // Print the dominators. // i.e. from the leaked object, print all parent objects whichs // keeps a reference to the previous object, up to a global object. dump("### Dominators:\n"); let node = objectNodeId, dump(" " + getObjectClass(node) + "\n"); while ((node = tree.getImmediateDominator(node))) { dump(" ^-- " + getObjectClass(node) + "\n"); } */ /** * In case you are not able to figure out what the object is. * This will print all what it keeps allocated, * kinds of list of attributes * dump("### Dominateds:\n"); node = objectNodeId, dump(" " + getObjectClass(node) + "\n"); for (const n of tree.getImmediatelyDominated(objectNodeId)) { dump(" --> " + getObjectClass(n) + "\n"); } */ } }, stop() { dump("DEVTOOLS ALLOCATION: Stop logging allocations\n"); dbg.onNewGlobalObject = undefined; dbg.removeAllDebuggees(); dbg = null; }, }; };