diff options
Diffstat (limited to 'browser/base/content/test/performance/browser_startup_mainthreadio.js')
| -rw-r--r-- | browser/base/content/test/performance/browser_startup_mainthreadio.js | 881 |
1 files changed, 881 insertions, 0 deletions
diff --git a/browser/base/content/test/performance/browser_startup_mainthreadio.js b/browser/base/content/test/performance/browser_startup_mainthreadio.js new file mode 100644 index 0000000000..3b34af5ad0 --- /dev/null +++ b/browser/base/content/test/performance/browser_startup_mainthreadio.js @@ -0,0 +1,881 @@ +/* Any copyright is dedicated to the Public Domain. + http://creativecommons.org/publicdomain/zero/1.0/ */ + +/* This test records I/O syscalls done on the main thread during startup. + * + * To run this test similar to try server, you need to run: + * ./mach package + * ./mach test --appname=dist <path to test> + * + * If you made changes that cause this test to fail, it's likely because you + * are touching more files or directories during startup. + * Most code has no reason to use main thread I/O. + * If for some reason accessing the file system on the main thread is currently + * unavoidable, consider defering the I/O as long as you can, ideally after + * the end of startup. + * If your code isn't strictly required to show the first browser window, + * it shouldn't be loaded before we are done with first paint. + * Finally, if your code isn't really needed during startup, it should not be + * loaded before we have started handling user events. + */ + +"use strict"; + +/* Set this to true only for debugging purpose; it makes the output noisy. */ +const kDumpAllStacks = false; + +// Shortcuts for conditions. +const LINUX = AppConstants.platform == "linux"; +const WIN = AppConstants.platform == "win"; +const MAC = AppConstants.platform == "macosx"; + +const kSharedFontList = SpecialPowers.getBoolPref("gfx.e10s.font-list.shared"); + +/* This is an object mapping string phases of startup to lists of known cases + * of IO happening on the main thread. Ideally, IO should not be on the main + * thread, and should happen as late as possible (see above). + * + * Paths in the entries in these lists can: + * - be a full path, eg. "/etc/mime.types" + * - have a prefix which will be resolved using Services.dirsvc + * eg. "GreD:omni.ja" + * It's possible to have only a prefix, in thise case the directory will + * still be resolved, eg. "UAppData:" + * - use * at the begining and/or end as a wildcard + * The folder separator is '/' even for Windows paths, where it'll be + * automatically converted to '\'. + * + * Specifying 'ignoreIfUnused: true' will make the test ignore unused entries; + * without this the test is strict and will fail if the described IO does not + * happen. + * + * Each entry specifies the maximum number of times an operation is expected to + * occur. + * The operations currently reported by the I/O interposer are: + * create/open: only supported on Windows currently. The test currently + * ignores these markers to have a shorter initial list of IO operations. + * Adding Unix support is bug 1533779. + * stat: supported on all platforms when checking the last modified date or + * file size. Supported only on Windows when checking if a file exists; + * fixing this inconsistency is bug 1536109. + * read: supported on all platforms, but unix platforms will only report read + * calls going through NSPR. + * write: supported on all platforms, but Linux will only report write calls + * going through NSPR. + * close: supported only on Unix, and only for close calls going through NSPR. + * Adding Windows support is bug 1524574. + * fsync: supported only on Windows. + * + * If an entry specifies more than one operation, if at least one of them is + * encountered, the test won't report a failure for the entry if other + * operations are not encountered. This helps when listing cases where the + * reported operations aren't the same on all platforms due to the I/O + * interposer inconsistencies across platforms documented above. + */ +const startupPhases = { + // Anything done before or during app-startup must have a compelling reason + // to run before we have even selected the user profile. + "before profile selection": [ + { + // bug 1541200 + path: "UAppData:Crash Reports/InstallTime20*", + condition: AppConstants.MOZ_CRASHREPORTER, + stat: 1, // only caught on Windows. + read: 1, + write: 2, + close: 1, + }, + { + // bug 1541200 + path: "UAppData:Crash Reports/LastCrash", + condition: WIN && AppConstants.MOZ_CRASHREPORTER, + stat: 1, // only caught on Windows. + read: 1, + }, + { + // bug 1541200 + path: "UAppData:Crash Reports/LastCrash", + condition: !WIN && AppConstants.MOZ_CRASHREPORTER, + ignoreIfUnused: true, // only if we ever crashed on this machine + read: 1, + close: 1, + }, + { + // At least the read seems unavoidable for a regular startup. + path: "UAppData:profiles.ini", + ignoreIfUnused: true, + condition: MAC, + stat: 1, + read: 1, + close: 1, + }, + { + // At least the read seems unavoidable for a regular startup. + path: "UAppData:profiles.ini", + condition: WIN, + ignoreIfUnused: true, // only if a real profile exists on the system. + read: 1, + stat: 1, + }, + { + // bug 1541226, bug 1363586, bug 1541593 + path: "ProfD:", + condition: WIN, + stat: 1, + }, + { + path: "ProfLD:.startup-incomplete", + condition: !WIN, // Visible on Windows with an open marker + close: 1, + }, + { + // bug 1541491 to stop using this file, bug 1541494 to write correctly. + path: "ProfLD:compatibility.ini", + write: 18, + close: 1, + }, + { + path: "GreD:omni.ja", + condition: !WIN, // Visible on Windows with an open marker + stat: 1, + }, + { + // bug 1376994 + path: "XCurProcD:omni.ja", + condition: !WIN, // Visible on Windows with an open marker + stat: 1, + }, + { + path: "ProfD:parent.lock", + condition: WIN, + stat: 1, + }, + { + // bug 1541603 + path: "ProfD:minidumps", + condition: WIN, + stat: 1, + }, + { + // bug 1543746 + path: "XCurProcD:defaults/preferences", + condition: WIN, + stat: 1, + }, + { + // bug 1544034 + path: "ProfLDS:startupCache/scriptCache-child-current.bin", + condition: WIN, + stat: 1, + }, + { + // bug 1544034 + path: "ProfLDS:startupCache/scriptCache-child.bin", + condition: WIN, + stat: 1, + }, + { + // bug 1544034 + path: "ProfLDS:startupCache/scriptCache-current.bin", + condition: WIN, + stat: 1, + }, + { + // bug 1544034 + path: "ProfLDS:startupCache/scriptCache.bin", + condition: WIN, + stat: 1, + }, + { + // bug 1541601 + path: "PrfDef:channel-prefs.js", + stat: 1, + read: 1, + close: 1, + }, + { + // At least the read seems unavoidable + path: "PrefD:prefs.js", + stat: 1, + read: 1, + close: 1, + }, + { + // bug 1543752 + path: "PrefD:user.js", + stat: 1, + read: 1, + close: 1, + }, + ], + + "before opening first browser window": [ + { + // bug 1541226 + path: "ProfD:", + condition: WIN, + ignoreIfUnused: true, // Sometimes happens in the next phase + stat: 1, + }, + { + // bug 1534745 + path: "ProfD:cookies.sqlite-journal", + condition: !LINUX, + ignoreIfUnused: true, // Sometimes happens in the next phase + stat: 3, + write: 4, + }, + { + // bug 1534745 + path: "ProfD:cookies.sqlite", + condition: !LINUX, + ignoreIfUnused: true, // Sometimes happens in the next phase + stat: 2, + read: 3, + write: 1, + }, + { + // bug 1534745 + path: "ProfD:cookies.sqlite-wal", + ignoreIfUnused: true, // Sometimes happens in the next phase + condition: WIN, + stat: 2, + }, + { + // Seems done by OS X and outside of our control. + path: "*.savedState/restorecount.plist", + condition: MAC, + ignoreIfUnused: true, + write: 1, + }, + { + // Side-effect of bug 1412090, via sandboxing (but the real + // problem there is main-thread CPU use; see bug 1439412) + path: "*ld.so.conf*", + condition: LINUX && !AppConstants.MOZ_CODE_COVERAGE && !kSharedFontList, + read: 22, + close: 11, + }, + { + // bug 1541246 + path: "ProfD:extensions", + ignoreIfUnused: true, // bug 1649590 + condition: WIN, + stat: 1, + }, + { + // bug 1541246 + path: "UAppData:", + ignoreIfUnused: true, // sometimes before opening first browser window, + // sometimes before first paint + condition: WIN, + stat: 1, + }, + { + // bug 1833104 has context - this is artifact-only so doesn't affect + // any real users, will just show up for developer builds and + // artifact trypushes so we include it here. + path: "GreD:jogfile.json", + condition: + WIN && Services.prefs.getBoolPref("telemetry.fog.artifact_build"), + stat: 1, + }, + ], + + // We reach this phase right after showing the first browser window. + // This means that any I/O at this point delayed first paint. + "before first paint": [ + { + // bug 1545119 + path: "OldUpdRootD:", + condition: WIN, + stat: 1, + }, + { + // bug 1446012 + path: "UpdRootD:updates/0/update.status", + condition: WIN, + stat: 1, + }, + { + path: "XREAppFeat:formautofill@mozilla.org.xpi", + condition: !WIN, + stat: 1, + close: 1, + }, + { + path: "XREAppFeat:webcompat@mozilla.org.xpi", + condition: LINUX, + ignoreIfUnused: true, // Sometimes happens in the previous phase + close: 1, + }, + { + // We only hit this for new profiles. + path: "XREAppDist:distribution.ini", + // check we're not msix to disambiguate from the next entry... + condition: WIN && !Services.sysinfo.getProperty("hasWinPackageId"), + stat: 1, + }, + { + // On MSIX, we actually read this file - bug 1833341. + path: "XREAppDist:distribution.ini", + condition: WIN && Services.sysinfo.getProperty("hasWinPackageId"), + stat: 1, + read: 1, + }, + { + // bug 1545139 + path: "*Fonts/StaticCache.dat", + condition: WIN, + ignoreIfUnused: true, // Only on Win7 + read: 1, + }, + { + // Bug 1626738 + path: "SysD:spool/drivers/color/*", + condition: WIN, + read: 1, + }, + { + // Sandbox policy construction + path: "*ld.so.conf*", + condition: LINUX && !AppConstants.MOZ_CODE_COVERAGE, + read: 22, + close: 11, + }, + { + // bug 1541246 + path: "UAppData:", + ignoreIfUnused: true, // sometimes before opening first browser window, + // sometimes before first paint + condition: WIN, + stat: 1, + }, + { + // Not in packaged builds; useful for artifact builds. + path: "GreD:ScalarArtifactDefinitions.json", + condition: WIN && !AppConstants.MOZILLA_OFFICIAL, + stat: 1, + }, + { + // Not in packaged builds; useful for artifact builds. + path: "GreD:EventArtifactDefinitions.json", + condition: WIN && !AppConstants.MOZILLA_OFFICIAL, + stat: 1, + }, + { + // bug 1541226 + path: "ProfD:", + condition: WIN, + ignoreIfUnused: true, // Usually happens in the previous phase + stat: 1, + }, + { + // bug 1534745 + path: "ProfD:cookies.sqlite-journal", + condition: WIN, + ignoreIfUnused: true, // Usually happens in the previous phase + stat: 3, + write: 4, + }, + { + // bug 1534745 + path: "ProfD:cookies.sqlite", + condition: WIN, + ignoreIfUnused: true, // Usually happens in the previous phase + stat: 2, + read: 3, + write: 1, + }, + { + // bug 1534745 + path: "ProfD:cookies.sqlite-wal", + condition: WIN, + ignoreIfUnused: true, // Usually happens in the previous phase + stat: 2, + }, + ], + + // We are at this phase once we are ready to handle user events. + // Any IO at this phase or before gets in the way of the user + // interacting with the first browser window. + "before handling user events": [ + { + path: "GreD:update.test", + ignoreIfUnused: true, + condition: LINUX, + close: 1, + }, + { + path: "XREAppFeat:webcompat-reporter@mozilla.org.xpi", + condition: !WIN, + ignoreIfUnused: true, + stat: 1, + close: 1, + }, + { + // Bug 1660582 - access while running on windows10 hardware. + path: "ProfD:wmfvpxvideo.guard", + condition: WIN, + ignoreIfUnused: true, + stat: 1, + close: 1, + }, + { + // Bug 1649590 + path: "ProfD:extensions", + ignoreIfUnused: true, + condition: WIN, + stat: 1, + }, + ], + + // Things that are expected to be completely out of the startup path + // and loaded lazily when used for the first time by the user should + // be listed here. + "before becoming idle": [ + { + // bug 1370516 - NSS should be initialized off main thread. + path: `ProfD:cert9.db`, + condition: WIN, + read: 5, + stat: AppConstants.NIGHTLY_BUILD ? 5 : 4, + }, + { + // bug 1370516 - NSS should be initialized off main thread. + path: `ProfD:cert9.db-journal`, + condition: WIN, + stat: 3, + }, + { + // bug 1370516 - NSS should be initialized off main thread. + path: `ProfD:cert9.db-wal`, + condition: WIN, + stat: 3, + }, + { + // bug 1370516 - NSS should be initialized off main thread. + path: "ProfD:pkcs11.txt", + condition: WIN, + read: 2, + }, + { + // bug 1370516 - NSS should be initialized off main thread. + path: `ProfD:key4.db`, + condition: WIN, + read: 10, + stat: AppConstants.NIGHTLY_BUILD ? 5 : 4, + }, + { + // bug 1370516 - NSS should be initialized off main thread. + path: `ProfD:key4.db-journal`, + condition: WIN, + stat: 7, + }, + { + // bug 1370516 - NSS should be initialized off main thread. + path: `ProfD:key4.db-wal`, + condition: WIN, + stat: 7, + }, + { + path: "XREAppFeat:screenshots@mozilla.org.xpi", + ignoreIfUnused: true, + close: 1, + }, + { + path: "XREAppFeat:webcompat-reporter@mozilla.org.xpi", + ignoreIfUnused: true, + stat: 1, + close: 1, + }, + { + // bug 1391590 + path: "ProfD:places.sqlite-journal", + ignoreIfUnused: true, + fsync: 1, + stat: 4, + read: 1, + write: 2, + }, + { + // bug 1391590 + path: "ProfD:places.sqlite-wal", + ignoreIfUnused: true, + stat: 4, + fsync: 3, + read: 51, + write: 178, + }, + { + // bug 1391590 + path: "ProfD:places.sqlite-shm", + condition: WIN, + ignoreIfUnused: true, + stat: 1, + }, + { + // bug 1391590 + path: "ProfD:places.sqlite", + ignoreIfUnused: true, + fsync: 2, + read: 4, + stat: 3, + write: 1324, + }, + { + // bug 1391590 + path: "ProfD:favicons.sqlite-journal", + ignoreIfUnused: true, + fsync: 2, + stat: 7, + read: 2, + write: 7, + }, + { + // bug 1391590 + path: "ProfD:favicons.sqlite-wal", + ignoreIfUnused: true, + fsync: 2, + stat: 7, + read: 7, + write: 15, + }, + { + // bug 1391590 + path: "ProfD:favicons.sqlite-shm", + condition: WIN, + ignoreIfUnused: true, + stat: 2, + }, + { + // bug 1391590 + path: "ProfD:favicons.sqlite", + ignoreIfUnused: true, + fsync: 3, + read: 8, + stat: 4, + write: 1300, + }, + { + path: "ProfD:", + condition: WIN, + ignoreIfUnused: true, + stat: 3, + }, + ], +}; + +for (let name of ["d3d11layers", "glcontext", "wmfvpxvideo"]) { + startupPhases["before first paint"].push({ + path: `ProfD:${name}.guard`, + ignoreIfUnused: true, + stat: 1, + }); +} + +function expandPathWithDirServiceKey(path) { + if (path.includes(":")) { + let [prefix, suffix] = path.split(":"); + let [key, property] = prefix.split("."); + let dir = Services.dirsvc.get(key, Ci.nsIFile); + if (property) { + dir = dir[property]; + } + + // Resolve symLinks. + let dirPath = dir.path; + while (dir && !dir.isSymlink()) { + dir = dir.parent; + } + if (dir) { + dirPath = dirPath.replace(dir.path, dir.target); + } + + path = dirPath; + + if (suffix) { + path += "/" + suffix; + } + } + if (AppConstants.platform == "win") { + path = path.replace(/\//g, "\\"); + } + return path; +} + +function getStackFromProfile(profile, stack) { + const stackPrefixCol = profile.stackTable.schema.prefix; + const stackFrameCol = profile.stackTable.schema.frame; + const frameLocationCol = profile.frameTable.schema.location; + + let result = []; + while (stack) { + let sp = profile.stackTable.data[stack]; + let frame = profile.frameTable.data[sp[stackFrameCol]]; + stack = sp[stackPrefixCol]; + frame = profile.stringTable[frame[frameLocationCol]]; + if (frame != "js::RunScript" && !frame.startsWith("next (self-hosted:")) { + result.push(frame); + } + } + return result; +} + +function pathMatches(path, filename) { + path = path.toLowerCase(); + return ( + path == filename || // Full match + // Wildcard on both sides of the path + (path.startsWith("*") && + path.endsWith("*") && + filename.includes(path.slice(1, -1))) || + // Wildcard suffix + (path.endsWith("*") && filename.startsWith(path.slice(0, -1))) || + // Wildcard prefix + (path.startsWith("*") && filename.endsWith(path.slice(1))) + ); +} + +add_task(async function () { + if ( + !AppConstants.NIGHTLY_BUILD && + !AppConstants.MOZ_DEV_EDITION && + !AppConstants.DEBUG + ) { + ok( + !("@mozilla.org/test/startuprecorder;1" in Cc), + "the startup recorder component shouldn't exist in this non-nightly/non-devedition/" + + "non-debug build." + ); + return; + } + + TestUtils.assertPackagedBuild(); + + let startupRecorder = + Cc["@mozilla.org/test/startuprecorder;1"].getService().wrappedJSObject; + await startupRecorder.done; + + // Add system add-ons to the list of known IO dynamically. + // They should go in the omni.ja file (bug 1357205). + { + let addons = await AddonManager.getAddonsByTypes(["extension"]); + for (let addon of addons) { + if (addon.isSystem) { + startupPhases["before opening first browser window"].push({ + path: `XREAppFeat:${addon.id}.xpi`, + stat: 3, + close: 2, + }); + startupPhases["before handling user events"].push({ + path: `XREAppFeat:${addon.id}.xpi`, + condition: WIN, + stat: 2, + }); + } + } + } + + // Check for main thread I/O markers in the startup profile. + let profile = startupRecorder.data.profile.threads[0]; + + let phases = {}; + { + const nameCol = profile.markers.schema.name; + const dataCol = profile.markers.schema.data; + + let markersForCurrentPhase = []; + let foundIOMarkers = false; + + for (let m of profile.markers.data) { + let markerName = profile.stringTable[m[nameCol]]; + if (markerName.startsWith("startupRecorder:")) { + phases[markerName.split("startupRecorder:")[1]] = + markersForCurrentPhase; + markersForCurrentPhase = []; + continue; + } + + if (markerName != "FileIO") { + continue; + } + + let markerData = m[dataCol]; + if (markerData.source == "sqlite-mainthread") { + continue; + } + + let samples = markerData.stack.samples; + let stack = samples.data[0][samples.schema.stack]; + markersForCurrentPhase.push({ + operation: markerData.operation, + filename: markerData.filename, + source: markerData.source, + stackId: stack, + }); + foundIOMarkers = true; + } + + // The I/O interposer is disabled if !RELEASE_OR_BETA, so we expect to have + // no I/O marker in that case, but it's good to keep the test running to check + // that we are still able to produce startup profiles. + is( + foundIOMarkers, + !AppConstants.RELEASE_OR_BETA, + "The IO interposer should be enabled in builds that are not RELEASE_OR_BETA" + ); + if (!foundIOMarkers) { + // If a profile unexpectedly contains no I/O marker, it's better to return + // early to avoid having a lot of of confusing "no main thread IO when we + // expected some" failures. + return; + } + } + + for (let phase in startupPhases) { + startupPhases[phase] = startupPhases[phase].filter( + entry => !("condition" in entry) || entry.condition + ); + startupPhases[phase].forEach(entry => { + entry.listedPath = entry.path; + entry.path = expandPathWithDirServiceKey(entry.path); + }); + } + + let tmpPath = expandPathWithDirServiceKey("TmpD:").toLowerCase(); + let shouldPass = true; + for (let phase in phases) { + let knownIOList = startupPhases[phase]; + info( + `known main thread IO paths during ${phase}:\n` + + knownIOList + .map(e => { + let operations = Object.keys(e) + .filter(k => k != "path") + .map(k => `${k}: ${e[k]}`); + return ` ${e.path} - ${operations.join(", ")}`; + }) + .join("\n") + ); + + let markers = phases[phase]; + for (let marker of markers) { + if (marker.operation == "create/open") { + // TODO: handle these I/O markers once they are supported on + // non-Windows platforms. + continue; + } + + if (!marker.filename) { + // We are still missing the filename on some mainthreadio markers, + // these markers are currently useless for the purpose of this test. + continue; + } + + // Convert to lower case before comparing because the OS X test machines + // have the 'Firefox' folder in 'Library/Application Support' created + // as 'firefox' for some reason. + let filename = marker.filename.toLowerCase(); + + if (!WIN && filename == "/dev/urandom") { + continue; + } + + // /dev/shm is always tmpfs (a memory filesystem); this isn't + // really I/O any more than mmap/munmap are. + if (LINUX && filename.startsWith("/dev/shm/")) { + continue; + } + + // "Files" from memfd_create() are similar to tmpfs but never + // exist in the filesystem; however, they have names which are + // exposed in procfs, and the I/O interposer observes when + // they're close()d. + if (LINUX && filename.startsWith("/memfd:")) { + continue; + } + + // Shared memory uses temporary files on MacOS <= 10.11 to avoid + // a kernel security bug that will never be patched (see + // https://crbug.com/project-zero/1671 for details). This can + // be removed when we no longer support those OS versions. + if (MAC && filename.startsWith(tmpPath + "/org.mozilla.ipc.")) { + continue; + } + + let expected = false; + for (let entry of knownIOList) { + if (pathMatches(entry.path, filename)) { + entry[marker.operation] = (entry[marker.operation] || 0) - 1; + entry._used = true; + expected = true; + break; + } + } + if (!expected) { + record( + false, + `unexpected ${marker.operation} on ${marker.filename} ${phase}`, + undefined, + " " + getStackFromProfile(profile, marker.stackId).join("\n ") + ); + shouldPass = false; + } + info(`(${marker.source}) ${marker.operation} - ${marker.filename}`); + if (kDumpAllStacks) { + info( + getStackFromProfile(profile, marker.stackId) + .map(f => " " + f) + .join("\n") + ); + } + } + + for (let entry of knownIOList) { + for (let op in entry) { + if ( + [ + "listedPath", + "path", + "condition", + "ignoreIfUnused", + "_used", + ].includes(op) + ) { + continue; + } + let message = `${op} on ${entry.path} `; + if (entry[op] == 0) { + message += "as many times as expected"; + } else if (entry[op] > 0) { + message += `allowed ${entry[op]} more times`; + } else { + message += `${entry[op] * -1} more times than expected`; + } + ok(entry[op] >= 0, `${message} ${phase}`); + } + if (!("_used" in entry) && !entry.ignoreIfUnused) { + ok( + false, + `no main thread IO when we expected some during ${phase}: ${entry.path} (${entry.listedPath})` + ); + shouldPass = false; + } + } + } + + if (shouldPass) { + ok(shouldPass, "No unexpected main thread I/O during startup"); + } else { + const filename = "profile_startup_mainthreadio.json"; + let path = Services.env.get("MOZ_UPLOAD_DIR"); + let profilePath = PathUtils.join(path, filename); + await IOUtils.writeJSON(profilePath, startupRecorder.data.profile); + ok( + false, + "Unexpected main thread I/O behavior during startup; open the " + + `${filename} artifact in the Firefox Profiler to see what happened` + ); + } +}); |