Source code

Revision control

Copy as Markdown

Other Tools

Test Info: Warnings

/* Any copyright is dedicated to the Public Domain.
/* 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": [
{
path: "UAppData:Crash Reports/InstallTime20*",
condition: AppConstants.MOZ_CRASHREPORTER,
stat: 1, // only caught on Windows.
read: 1,
write: 2,
close: 1,
},
{
path: "UAppData:Crash Reports/LastCrash",
condition: WIN && AppConstants.MOZ_CRASHREPORTER,
stat: 1, // only caught on Windows.
read: 1,
},
{
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,
},
{
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,
},
{
path: "XCurProcD:omni.ja",
condition: !WIN, // Visible on Windows with an open marker
stat: 1,
},
{
path: "ProfD:parent.lock",
condition: WIN,
stat: 1,
},
{
path: "ProfD:minidumps",
condition: WIN,
stat: 1,
},
{
path: "XCurProcD:defaults/preferences",
condition: WIN,
stat: 1,
},
{
path: "ProfLDS:startupCache/scriptCache-child-current.bin",
condition: WIN,
stat: 1,
},
{
path: "ProfLDS:startupCache/scriptCache-child.bin",
condition: WIN,
stat: 1,
},
{
path: "ProfLDS:startupCache/scriptCache-current.bin",
condition: WIN,
stat: 1,
},
{
path: "ProfLDS:startupCache/scriptCache.bin",
condition: WIN,
stat: 1,
},
{
path: "PrfDef:channel-prefs.js",
condition: !MAC,
stat: 1,
read: 1,
close: 1,
},
{
// At least the read seems unavoidable
path: "PrefD:prefs.js",
stat: 1,
read: 1,
close: 1,
},
{
path: "PrefD:user.js",
stat: 1,
read: 1,
close: 1,
},
],
"before opening first browser window": [
{
path: "ProfD:",
condition: WIN,
ignoreIfUnused: true, // Sometimes happens in the next phase
stat: 1,
},
{
path: "ProfD:cookies.sqlite-journal",
condition: !LINUX,
ignoreIfUnused: true, // Sometimes happens in the next phase
stat: 3,
write: 4,
},
{
path: "ProfD:cookies.sqlite",
condition: !LINUX,
ignoreIfUnused: true, // Sometimes happens in the next phase
stat: 2,
read: 3,
write: 1,
},
{
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,
},
{
path: "ProfD:extensions",
ignoreIfUnused: true, // bug 1649590
condition: WIN,
stat: 1,
},
{
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": [
{
path: "OldUpdRootD:",
condition: WIN,
stat: 1,
},
{
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,
},
{
path: "*Fonts/StaticCache.dat",
condition: WIN,
ignoreIfUnused: true, // Only on Win7
read: 1,
},
{
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,
},
{
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,
},
{
path: "ProfD:",
condition: WIN,
ignoreIfUnused: true, // Usually happens in the previous phase
stat: 1,
},
{
path: "ProfD:cookies.sqlite-journal",
condition: WIN,
ignoreIfUnused: true, // Usually happens in the previous phase
stat: 3,
write: 4,
},
{
path: "ProfD:cookies.sqlite",
condition: WIN,
ignoreIfUnused: true, // Usually happens in the previous phase
stat: 2,
read: 3,
write: 1,
},
{
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,
},
{
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,
},
{
path: "ProfD:places.sqlite-journal",
ignoreIfUnused: true,
fsync: 1,
stat: 4,
read: 1,
write: 2,
},
{
path: "ProfD:places.sqlite-wal",
ignoreIfUnused: true,
stat: 4,
fsync: 3,
read: 51,
write: 178,
},
{
path: "ProfD:places.sqlite-shm",
condition: WIN,
ignoreIfUnused: true,
stat: 1,
},
{
path: "ProfD:places.sqlite",
ignoreIfUnused: true,
fsync: 2,
read: 4,
stat: 3,
write: 1324,
},
{
path: "ProfD:favicons.sqlite-journal",
ignoreIfUnused: true,
fsync: 2,
stat: 7,
read: 2,
write: 7,
},
{
path: "ProfD:favicons.sqlite-wal",
ignoreIfUnused: true,
fsync: 2,
stat: 7,
read: 7,
write: 15,
},
{
path: "ProfD:favicons.sqlite-shm",
condition: WIN,
ignoreIfUnused: true,
stat: 2,
},
{
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`;
}
Assert.greaterOrEqual(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`
);
}
});