browser/base/content/test/performance/browser_startup_mainthreadio.js

   1 /* Any copyright is dedicated to the Public Domain.
   2    http://creativecommons.org/publicdomain/zero/1.0/ */
   3
   4 /* This test records I/O syscalls done on the main thread during startup.
   5  *
   6  * To run this test similar to try server, you need to run:
   7  *   ./mach package
   8  *   ./mach test --appname=dist <path to test>
   9  *
  10  * If you made changes that cause this test to fail, it's likely because you
  11  * are touching more files or directories during startup.
  12  * Most code has no reason to use main thread I/O.
  13  * If for some reason accessing the file system on the main thread is currently
  14  * unavoidable, consider defering the I/O as long as you can, ideally after
  15  * the end of startup.
  16  * If your code isn't strictly required to show the first browser window,
  17  * it shouldn't be loaded before we are done with first paint.
  18  * Finally, if your code isn't really needed during startup, it should not be
  19  * loaded before we have started handling user events.
  20  */
  21
  22 "use strict";
  23
  24 /* Set this to true only for debugging purpose; it makes the output noisy. */
  25 const kDumpAllStacks = false;
  26
  27 // Shortcuts for conditions.
  28 const LINUX = AppConstants.platform == "linux";
  29 const WIN = AppConstants.platform == "win";
  30 const MAC = AppConstants.platform == "macosx";
  31
  32 const kSharedFontList = SpecialPowers.getBoolPref("gfx.e10s.font-list.shared");
  33
  34 /* This is an object mapping string phases of startup to lists of known cases
  35  * of IO happening on the main thread. Ideally, IO should not be on the main
  36  * thread, and should happen as late as possible (see above).
  37  *
  38  * Paths in the entries in these lists can:
  39  *  - be a full path, eg. "/etc/mime.types"
  40  *  - have a prefix which will be resolved using Services.dirsvc
  41  *    eg. "GreD:omni.ja"
  42  *    It's possible to have only a prefix, in thise case the directory will
  43  *    still be resolved, eg. "UAppData:"
  44  *  - use * at the begining and/or end as a wildcard
  45  * The folder separator is '/' even for Windows paths, where it'll be
  46  * automatically converted to '\'.
  47  *
  48  * Specifying 'ignoreIfUnused: true' will make the test ignore unused entries;
  49  * without this the test is strict and will fail if the described IO does not
  50  * happen.
  51  *
  52  * Each entry specifies the maximum number of times an operation is expected to
  53  * occur.
  54  * The operations currently reported by the I/O interposer are:
  55  *   create/open: only supported on Windows currently. The test currently
  56  *     ignores these markers to have a shorter initial list of IO operations.
  57  *     Adding Unix support is bug 1533779.
  58  *   stat: supported on all platforms when checking the last modified date or
  59  *     file size. Supported only on Windows when checking if a file exists;
  60  *     fixing this inconsistency is bug 1536109.
  61  *   read: supported on all platforms, but unix platforms will only report read
  62  *     calls going through NSPR.
  63  *   write: supported on all platforms, but Linux will only report write calls
  64  *     going through NSPR.
  65  *   close: supported only on Unix, and only for close calls going through NSPR.
  66  *     Adding Windows support is bug 1524574.
  67  *   fsync: supported only on Windows.
  68  *
  69  * If an entry specifies more than one operation, if at least one of them is
  70  * encountered, the test won't report a failure for the entry if other
  71  * operations are not encountered. This helps when listing cases where the
  72  * reported operations aren't the same on all platforms due to the I/O
  73  * interposer inconsistencies across platforms documented above.
  74  */
  75 const startupPhases = {
  76   // Anything done before or during app-startup must have a compelling reason
  77   // to run before we have even selected the user profile.
  78   "before profile selection": [
  79     {
  80       // bug 1541200
  81       path: "UAppData:Crash Reports/InstallTime20*",
  82       condition: AppConstants.MOZ_CRASHREPORTER,
  83       stat: 1, // only caught on Windows.
  84       read: 1,
  85       write: 2,
  86       close: 1,
  87     },
  88     {
  89       // bug 1541200
  90       path: "UAppData:Crash Reports/LastCrash",
  91       condition: WIN && AppConstants.MOZ_CRASHREPORTER,
  92       stat: 1, // only caught on Windows.
  93       read: 1,
  94     },
  95     {
  96       // bug 1541200
  97       path: "UAppData:Crash Reports/LastCrash",
  98       condition: !WIN && AppConstants.MOZ_CRASHREPORTER,
  99       ignoreIfUnused: true, // only if we ever crashed on this machine
 100       read: 1,
 101       close: 1,
 102     },
 103     {
 104       // At least the read seems unavoidable for a regular startup.
 105       path: "UAppData:profiles.ini",
 106       ignoreIfUnused: true,
 107       condition: MAC,
 108       stat: 1,
 109       read: 1,
 110       close: 1,
 111     },
 112     {
 113       // At least the read seems unavoidable for a regular startup.
 114       path: "UAppData:profiles.ini",
 115       condition: WIN,
 116       ignoreIfUnused: true, // only if a real profile exists on the system.
 117       read: 1,
 118       stat: 1,
 119     },
 120     {
 121       // bug 1541226, bug 1363586, bug 1541593
 122       path: "ProfD:",
 123       condition: WIN,
 124       stat: 1,
 125     },
 126     {
 127       path: "ProfLD:.startup-incomplete",
 128       condition: !WIN, // Visible on Windows with an open marker
 129       close: 1,
 130     },
 131     {
 132       // bug 1541491 to stop using this file, bug 1541494 to write correctly.
 133       path: "ProfLD:compatibility.ini",
 134       write: 18,
 135       close: 1,
 136     },
 137     {
 138       path: "GreD:omni.ja",
 139       condition: !WIN, // Visible on Windows with an open marker
 140       stat: 1,
 141     },
 142     {
 143       // bug 1376994
 144       path: "XCurProcD:omni.ja",
 145       condition: !WIN, // Visible on Windows with an open marker
 146       stat: 1,
 147     },
 148     {
 149       path: "ProfD:parent.lock",
 150       condition: WIN,
 151       stat: 1,
 152     },
 153     {
 154       // bug 1541603
 155       path: "ProfD:minidumps",
 156       condition: WIN,
 157       stat: 1,
 158     },
 159     {
 160       // bug 1543746
 161       path: "XCurProcD:defaults/preferences",
 162       condition: WIN,
 163       stat: 1,
 164     },
 165     {
 166       // bug 1544034
 167       path: "ProfLDS:startupCache/scriptCache-child-current.bin",
 168       condition: WIN,
 169       stat: 1,
 170     },
 171     {
 172       // bug 1544034
 173       path: "ProfLDS:startupCache/scriptCache-child.bin",
 174       condition: WIN,
 175       stat: 1,
 176     },
 177     {
 178       // bug 1544034
 179       path: "ProfLDS:startupCache/scriptCache-current.bin",
 180       condition: WIN,
 181       stat: 1,
 182     },
 183     {
 184       // bug 1544034
 185       path: "ProfLDS:startupCache/scriptCache.bin",
 186       condition: WIN,
 187       stat: 1,
 188     },
 189     {
 190       // bug 1541601
 191       path: "PrfDef:channel-prefs.js",
 192       stat: 1,
 193       read: 1,
 194       close: 1,
 195     },
 196     {
 197       // At least the read seems unavoidable
 198       path: "PrefD:prefs.js",
 199       stat: 1,
 200       read: 1,
 201       close: 1,
 202     },
 203     {
 204       // bug 1543752
 205       path: "PrefD:user.js",
 206       stat: 1,
 207       read: 1,
 208       close: 1,
 209     },
 210   ],
 211
 212   "before opening first browser window": [
 213     {
 214       // bug 1541226
 215       path: "ProfD:",
 216       condition: WIN,
 217       ignoreIfUnused: true, // Sometimes happens in the next phase
 218       stat: 1,
 219     },
 220     {
 221       // bug 1534745
 222       path: "ProfD:cookies.sqlite-journal",
 223       condition: !LINUX,
 224       ignoreIfUnused: true, // Sometimes happens in the next phase
 225       stat: 3,
 226       write: 4,
 227     },
 228     {
 229       // bug 1534745
 230       path: "ProfD:cookies.sqlite",
 231       condition: !LINUX,
 232       ignoreIfUnused: true, // Sometimes happens in the next phase
 233       stat: 2,
 234       read: 3,
 235       write: 1,
 236     },
 237     {
 238       // bug 1534745
 239       path: "ProfD:cookies.sqlite-wal",
 240       ignoreIfUnused: true, // Sometimes happens in the next phase
 241       condition: WIN,
 242       stat: 2,
 243     },
 244     {
 245       // Seems done by OS X and outside of our control.
 246       path: "*.savedState/restorecount.plist",
 247       condition: MAC,
 248       ignoreIfUnused: true,
 249       write: 1,
 250     },
 251     {
 252       // Side-effect of bug 1412090, via sandboxing (but the real
 253       // problem there is main-thread CPU use; see bug 1439412)
 254       path: "*ld.so.conf*",
 255       condition: LINUX && !AppConstants.MOZ_CODE_COVERAGE && !kSharedFontList,
 256       read: 22,
 257       close: 11,
 258     },
 259     {
 260       // bug 1541246
 261       path: "ProfD:extensions",
 262       ignoreIfUnused: true, // bug 1649590
 263       condition: WIN,
 264       stat: 1,
 265     },
 266     {
 267       // bug 1541246
 268       path: "UAppData:",
 269       ignoreIfUnused: true, // sometimes before opening first browser window,
 270       // sometimes before first paint
 271       condition: WIN,
 272       stat: 1,
 273     },
 274     {
 275       // bug 1833104 has context - this is artifact-only so doesn't affect
 276       // any real users, will just show up for developer builds and
 277       // artifact trypushes so we include it here.
 278       path: "GreD:jogfile.json",
 279       condition:
 280         WIN && Services.prefs.getBoolPref("telemetry.fog.artifact_build"),
 281       stat: 1,
 282     },
 283   ],
 284
 285   // We reach this phase right after showing the first browser window.
 286   // This means that any I/O at this point delayed first paint.
 287   "before first paint": [
 288     {
 289       // bug 1545119
 290       path: "OldUpdRootD:",
 291       condition: WIN,
 292       stat: 1,
 293     },
 294     {
 295       // bug 1446012
 296       path: "UpdRootD:updates/0/update.status",
 297       condition: WIN,
 298       stat: 1,
 299     },
 300     {
 301       path: "XREAppFeat:formautofill@mozilla.org.xpi",
 302       condition: !WIN,
 303       stat: 1,
 304       close: 1,
 305     },
 306     {
 307       path: "XREAppFeat:webcompat@mozilla.org.xpi",
 308       condition: LINUX,
 309       ignoreIfUnused: true, // Sometimes happens in the previous phase
 310       close: 1,
 311     },
 312     {
 313       // We only hit this for new profiles.
 314       path: "XREAppDist:distribution.ini",
 315       // check we're not msix to disambiguate from the next entry...
 316       condition: WIN && !Services.sysinfo.getProperty("hasWinPackageId"),
 317       stat: 1,
 318     },
 319     {
 320       // On MSIX, we actually read this file - bug 1833341.
 321       path: "XREAppDist:distribution.ini",
 322       condition: WIN && Services.sysinfo.getProperty("hasWinPackageId"),
 323       stat: 1,
 324       read: 1,
 325     },
 326     {
 327       // bug 1545139
 328       path: "*Fonts/StaticCache.dat",
 329       condition: WIN,
 330       ignoreIfUnused: true, // Only on Win7
 331       read: 1,
 332     },
 333     {
 334       // Bug 1626738
 335       path: "SysD:spool/drivers/color/*",
 336       condition: WIN,
 337       read: 1,
 338     },
 339     {
 340       // Sandbox policy construction
 341       path: "*ld.so.conf*",
 342       condition: LINUX && !AppConstants.MOZ_CODE_COVERAGE,
 343       read: 22,
 344       close: 11,
 345     },
 346     {
 347       // bug 1541246
 348       path: "UAppData:",
 349       ignoreIfUnused: true, // sometimes before opening first browser window,
 350       // sometimes before first paint
 351       condition: WIN,
 352       stat: 1,
 353     },
 354     {
 355       // Not in packaged builds; useful for artifact builds.
 356       path: "GreD:ScalarArtifactDefinitions.json",
 357       condition: WIN && !AppConstants.MOZILLA_OFFICIAL,
 358       stat: 1,
 359     },
 360     {
 361       // Not in packaged builds; useful for artifact builds.
 362       path: "GreD:EventArtifactDefinitions.json",
 363       condition: WIN && !AppConstants.MOZILLA_OFFICIAL,
 364       stat: 1,
 365     },
 366     {
 367       // bug 1541226
 368       path: "ProfD:",
 369       condition: WIN,
 370       ignoreIfUnused: true, // Usually happens in the previous phase
 371       stat: 1,
 372     },
 373     {
 374       // bug 1534745
 375       path: "ProfD:cookies.sqlite-journal",
 376       condition: WIN,
 377       ignoreIfUnused: true, // Usually happens in the previous phase
 378       stat: 3,
 379       write: 4,
 380     },
 381     {
 382       // bug 1534745
 383       path: "ProfD:cookies.sqlite",
 384       condition: WIN,
 385       ignoreIfUnused: true, // Usually happens in the previous phase
 386       stat: 2,
 387       read: 3,
 388       write: 1,
 389     },
 390     {
 391       // bug 1534745
 392       path: "ProfD:cookies.sqlite-wal",
 393       condition: WIN,
 394       ignoreIfUnused: true, // Usually happens in the previous phase
 395       stat: 2,
 396     },
 397   ],
 398
 399   // We are at this phase once we are ready to handle user events.
 400   // Any IO at this phase or before gets in the way of the user
 401   // interacting with the first browser window.
 402   "before handling user events": [
 403     {
 404       path: "GreD:update.test",
 405       ignoreIfUnused: true,
 406       condition: LINUX,
 407       close: 1,
 408     },
 409     {
 410       path: "XREAppFeat:webcompat-reporter@mozilla.org.xpi",
 411       condition: !WIN,
 412       ignoreIfUnused: true,
 413       stat: 1,
 414       close: 1,
 415     },
 416     {
 417       // Bug 1660582 - access while running on windows10 hardware.
 418       path: "ProfD:wmfvpxvideo.guard",
 419       condition: WIN,
 420       ignoreIfUnused: true,
 421       stat: 1,
 422       close: 1,
 423     },
 424     {
 425       // Bug 1649590
 426       path: "ProfD:extensions",
 427       ignoreIfUnused: true,
 428       condition: WIN,
 429       stat: 1,
 430     },
 431   ],
 432
 433   // Things that are expected to be completely out of the startup path
 434   // and loaded lazily when used for the first time by the user should
 435   // be listed here.
 436   "before becoming idle": [
 437     {
 438       // bug 1370516 - NSS should be initialized off main thread.
 439       path: `ProfD:cert9.db`,
 440       condition: WIN,
 441       read: 5,
 442       stat: AppConstants.NIGHTLY_BUILD ? 5 : 4,
 443     },
 444     {
 445       // bug 1370516 - NSS should be initialized off main thread.
 446       path: `ProfD:cert9.db-journal`,
 447       condition: WIN,
 448       stat: 3,
 449     },
 450     {
 451       // bug 1370516 - NSS should be initialized off main thread.
 452       path: `ProfD:cert9.db-wal`,
 453       condition: WIN,
 454       stat: 3,
 455     },
 456     {
 457       // bug 1370516 - NSS should be initialized off main thread.
 458       path: "ProfD:pkcs11.txt",
 459       condition: WIN,
 460       read: 2,
 461     },
 462     {
 463       // bug 1370516 - NSS should be initialized off main thread.
 464       path: `ProfD:key4.db`,
 465       condition: WIN,
 466       read: 10,
 467       stat: AppConstants.NIGHTLY_BUILD ? 5 : 4,
 468     },
 469     {
 470       // bug 1370516 - NSS should be initialized off main thread.
 471       path: `ProfD:key4.db-journal`,
 472       condition: WIN,
 473       stat: 7,
 474     },
 475     {
 476       // bug 1370516 - NSS should be initialized off main thread.
 477       path: `ProfD:key4.db-wal`,
 478       condition: WIN,
 479       stat: 7,
 480     },
 481     {
 482       path: "XREAppFeat:screenshots@mozilla.org.xpi",
 483       ignoreIfUnused: true,
 484       close: 1,
 485     },
 486     {
 487       path: "XREAppFeat:webcompat-reporter@mozilla.org.xpi",
 488       ignoreIfUnused: true,
 489       stat: 1,
 490       close: 1,
 491     },
 492     {
 493       // bug 1391590
 494       path: "ProfD:places.sqlite-journal",
 495       ignoreIfUnused: true,
 496       fsync: 1,
 497       stat: 4,
 498       read: 1,
 499       write: 2,
 500     },
 501     {
 502       // bug 1391590
 503       path: "ProfD:places.sqlite-wal",
 504       ignoreIfUnused: true,
 505       stat: 4,
 506       fsync: 3,
 507       read: 51,
 508       write: 178,
 509     },
 510     {
 511       // bug 1391590
 512       path: "ProfD:places.sqlite-shm",
 513       condition: WIN,
 514       ignoreIfUnused: true,
 515       stat: 1,
 516     },
 517     {
 518       // bug 1391590
 519       path: "ProfD:places.sqlite",
 520       ignoreIfUnused: true,
 521       fsync: 2,
 522       read: 4,
 523       stat: 3,
 524       write: 1324,
 525     },
 526     {
 527       // bug 1391590
 528       path: "ProfD:favicons.sqlite-journal",
 529       ignoreIfUnused: true,
 530       fsync: 2,
 531       stat: 7,
 532       read: 2,
 533       write: 7,
 534     },
 535     {
 536       // bug 1391590
 537       path: "ProfD:favicons.sqlite-wal",
 538       ignoreIfUnused: true,
 539       fsync: 2,
 540       stat: 7,
 541       read: 7,
 542       write: 15,
 543     },
 544     {
 545       // bug 1391590
 546       path: "ProfD:favicons.sqlite-shm",
 547       condition: WIN,
 548       ignoreIfUnused: true,
 549       stat: 2,
 550     },
 551     {
 552       // bug 1391590
 553       path: "ProfD:favicons.sqlite",
 554       ignoreIfUnused: true,
 555       fsync: 3,
 556       read: 8,
 557       stat: 4,
 558       write: 1300,
 559     },
 560     {
 561       path: "ProfD:",
 562       condition: WIN,
 563       ignoreIfUnused: true,
 564       stat: 3,
 565     },
 566   ],
 567 };
 568
 569 for (let name of ["d3d11layers", "glcontext", "wmfvpxvideo"]) {
 570   startupPhases["before first paint"].push({
 571     path: `ProfD:${name}.guard`,
 572     ignoreIfUnused: true,
 573     stat: 1,
 574   });
 575 }
 576
 577 function expandPathWithDirServiceKey(path) {
 578   if (path.includes(":")) {
 579     let [prefix, suffix] = path.split(":");
 580     let [key, property] = prefix.split(".");
 581     let dir = Services.dirsvc.get(key, Ci.nsIFile);
 582     if (property) {
 583       dir = dir[property];
 584     }
 585
 586     // Resolve symLinks.
 587     let dirPath = dir.path;
 588     while (dir && !dir.isSymlink()) {
 589       dir = dir.parent;
 590     }
 591     if (dir) {
 592       dirPath = dirPath.replace(dir.path, dir.target);
 593     }
 594
 595     path = dirPath;
 596
 597     if (suffix) {
 598       path += "/" + suffix;
 599     }
 600   }
 601   if (AppConstants.platform == "win") {
 602     path = path.replace(/\//g, "\\");
 603   }
 604   return path;
 605 }
 606
 607 function getStackFromProfile(profile, stack) {
 608   const stackPrefixCol = profile.stackTable.schema.prefix;
 609   const stackFrameCol = profile.stackTable.schema.frame;
 610   const frameLocationCol = profile.frameTable.schema.location;
 611
 612   let result = [];
 613   while (stack) {
 614     let sp = profile.stackTable.data[stack];
 615     let frame = profile.frameTable.data[sp[stackFrameCol]];
 616     stack = sp[stackPrefixCol];
 617     frame = profile.stringTable[frame[frameLocationCol]];
 618     if (frame != "js::RunScript" && !frame.startsWith("next (self-hosted:")) {
 619       result.push(frame);
 620     }
 621   }
 622   return result;
 623 }
 624
 625 function pathMatches(path, filename) {
 626   path = path.toLowerCase();
 627   return (
 628     path == filename || // Full match
 629     // Wildcard on both sides of the path
 630     (path.startsWith("*") &&
 631       path.endsWith("*") &&
 632       filename.includes(path.slice(1, -1))) ||
 633     // Wildcard suffix
 634     (path.endsWith("*") && filename.startsWith(path.slice(0, -1))) ||
 635     // Wildcard prefix
 636     (path.startsWith("*") && filename.endsWith(path.slice(1)))
 637   );
 638 }
 639
 640 add_task(async function() {
 641   if (
 642     !AppConstants.NIGHTLY_BUILD &&
 643     !AppConstants.MOZ_DEV_EDITION &&
 644     !AppConstants.DEBUG
 645   ) {
 646     ok(
 647       !("@mozilla.org/test/startuprecorder;1" in Cc),
 648       "the startup recorder component shouldn't exist in this non-nightly/non-devedition/" +
 649         "non-debug build."
 650     );
 651     return;
 652   }
 653
 654   TestUtils.assertPackagedBuild();
 655
 656   let startupRecorder = Cc["@mozilla.org/test/startuprecorder;1"].getService()
 657     .wrappedJSObject;
 658   await startupRecorder.done;
 659
 660   // Add system add-ons to the list of known IO dynamically.
 661   // They should go in the omni.ja file (bug 1357205).
 662   {
 663     let addons = await AddonManager.getAddonsByTypes(["extension"]);
 664     for (let addon of addons) {
 665       if (addon.isSystem) {
 666         startupPhases["before opening first browser window"].push({
 667           path: `XREAppFeat:${addon.id}.xpi`,
 668           stat: 3,
 669           close: 2,
 670         });
 671         startupPhases["before handling user events"].push({
 672           path: `XREAppFeat:${addon.id}.xpi`,
 673           condition: WIN,
 674           stat: 2,
 675         });
 676       }
 677     }
 678   }
 679
 680   // Check for main thread I/O markers in the startup profile.
 681   let profile = startupRecorder.data.profile.threads[0];
 682
 683   let phases = {};
 684   {
 685     const nameCol = profile.markers.schema.name;
 686     const dataCol = profile.markers.schema.data;
 687
 688     let markersForCurrentPhase = [];
 689     let foundIOMarkers = false;
 690
 691     for (let m of profile.markers.data) {
 692       let markerName = profile.stringTable[m[nameCol]];
 693       if (markerName.startsWith("startupRecorder:")) {
 694         phases[
 695           markerName.split("startupRecorder:")[1]
 696         ] = markersForCurrentPhase;
 697         markersForCurrentPhase = [];
 698         continue;
 699       }
 700
 701       if (markerName != "FileIO") {
 702         continue;
 703       }
 704
 705       let markerData = m[dataCol];
 706       if (markerData.source == "sqlite-mainthread") {
 707         continue;
 708       }
 709
 710       let samples = markerData.stack.samples;
 711       let stack = samples.data[0][samples.schema.stack];
 712       markersForCurrentPhase.push({
 713         operation: markerData.operation,
 714         filename: markerData.filename,
 715         source: markerData.source,
 716         stackId: stack,
 717       });
 718       foundIOMarkers = true;
 719     }
 720
 721     // The I/O interposer is disabled if !RELEASE_OR_BETA, so we expect to have
 722     // no I/O marker in that case, but it's good to keep the test running to check
 723     // that we are still able to produce startup profiles.
 724     is(
 725       foundIOMarkers,
 726       !AppConstants.RELEASE_OR_BETA,
 727       "The IO interposer should be enabled in builds that are not RELEASE_OR_BETA"
 728     );
 729     if (!foundIOMarkers) {
 730       // If a profile unexpectedly contains no I/O marker, it's better to return
 731       // early to avoid having a lot of of confusing "no main thread IO when we
 732       // expected some" failures.
 733       return;
 734     }
 735   }
 736
 737   for (let phase in startupPhases) {
 738     startupPhases[phase] = startupPhases[phase].filter(
 739       entry => !("condition" in entry) || entry.condition
 740     );
 741     startupPhases[phase].forEach(entry => {
 742       entry.listedPath = entry.path;
 743       entry.path = expandPathWithDirServiceKey(entry.path);
 744     });
 745   }
 746
 747   let tmpPath = expandPathWithDirServiceKey("TmpD:").toLowerCase();
 748   let shouldPass = true;
 749   for (let phase in phases) {
 750     let knownIOList = startupPhases[phase];
 751     info(
 752       `known main thread IO paths during ${phase}:\n` +
 753         knownIOList
 754           .map(e => {
 755             let operations = Object.keys(e)
 756               .filter(k => k != "path")
 757               .map(k => `${k}: ${e[k]}`);
 758             return `  ${e.path} - ${operations.join(", ")}`;
 759           })
 760           .join("\n")
 761     );
 762
 763     let markers = phases[phase];
 764     for (let marker of markers) {
 765       if (marker.operation == "create/open") {
 766         // TODO: handle these I/O markers once they are supported on
 767         // non-Windows platforms.
 768         continue;
 769       }
 770
 771       if (!marker.filename) {
 772         // We are still missing the filename on some mainthreadio markers,
 773         // these markers are currently useless for the purpose of this test.
 774         continue;
 775       }
 776
 777       // Convert to lower case before comparing because the OS X test machines
 778       // have the 'Firefox' folder in 'Library/Application Support' created
 779       // as 'firefox' for some reason.
 780       let filename = marker.filename.toLowerCase();
 781
 782       if (!WIN && filename == "/dev/urandom") {
 783         continue;
 784       }
 785
 786       // /dev/shm is always tmpfs (a memory filesystem); this isn't
 787       // really I/O any more than mmap/munmap are.
 788       if (LINUX && filename.startsWith("/dev/shm/")) {
 789         continue;
 790       }
 791
 792       // "Files" from memfd_create() are similar to tmpfs but never
 793       // exist in the filesystem; however, they have names which are
 794       // exposed in procfs, and the I/O interposer observes when
 795       // they're close()d.
 796       if (LINUX && filename.startsWith("/memfd:")) {
 797         continue;
 798       }
 799
 800       // Shared memory uses temporary files on MacOS <= 10.11 to avoid
 801       // a kernel security bug that will never be patched (see
 802       // https://crbug.com/project-zero/1671 for details).  This can
 803       // be removed when we no longer support those OS versions.
 804       if (MAC && filename.startsWith(tmpPath + "/org.mozilla.ipc.")) {
 805         continue;
 806       }
 807
 808       let expected = false;
 809       for (let entry of knownIOList) {
 810         if (pathMatches(entry.path, filename)) {
 811           entry[marker.operation] = (entry[marker.operation] || 0) - 1;
 812           entry._used = true;
 813           expected = true;
 814           break;
 815         }
 816       }
 817       if (!expected) {
 818         record(
 819           false,
 820           `unexpected ${marker.operation} on ${marker.filename} ${phase}`,
 821           undefined,
 822           "  " + getStackFromProfile(profile, marker.stackId).join("\n  ")
 823         );
 824         shouldPass = false;
 825       }
 826       info(`(${marker.source}) ${marker.operation} - ${marker.filename}`);
 827       if (kDumpAllStacks) {
 828         info(
 829           getStackFromProfile(profile, marker.stackId)
 830             .map(f => "  " + f)
 831             .join("\n")
 832         );
 833       }
 834     }
 835
 836     for (let entry of knownIOList) {
 837       for (let op in entry) {
 838         if (
 839           [
 840             "listedPath",
 841             "path",
 842             "condition",
 843             "ignoreIfUnused",
 844             "_used",
 845           ].includes(op)
 846         ) {
 847           continue;
 848         }
 849         let message = `${op} on ${entry.path} `;
 850         if (entry[op] == 0) {
 851           message += "as many times as expected";
 852         } else if (entry[op] > 0) {
 853           message += `allowed ${entry[op]} more times`;
 854         } else {
 855           message += `${entry[op] * -1} more times than expected`;
 856         }
 857         ok(entry[op] >= 0, `${message} ${phase}`);
 858       }
 859       if (!("_used" in entry) && !entry.ignoreIfUnused) {
 860         ok(
 861           false,
 862           `no main thread IO when we expected some during ${phase}: ${entry.path} (${entry.listedPath})`
 863         );
 864         shouldPass = false;
 865       }
 866     }
 867   }
 868
 869   if (shouldPass) {
 870     ok(shouldPass, "No unexpected main thread I/O during startup");
 871   } else {
 872     const filename = "profile_startup_mainthreadio.json";
 873     let path = Services.env.get("MOZ_UPLOAD_DIR");
 874     let profilePath = PathUtils.join(path, filename);
 875     await IOUtils.writeJSON(profilePath, startupRecorder.data.profile);
 876     ok(
 877       false,
 878       "Unexpected main thread I/O behavior during startup; open the " +
 879         `${filename} artifact in the Firefox Profiler to see what happened`
 880     );
 881   }
 882 });