Bug 1671701 - Add more comprehensive tests for FileIO markers; r=gerald,julienw

This re-works our tests to run all of the branches in the interposer. There is
a bit of a risk that this won't pass on all platforms as there is an allow list
of known operations. However, it's currently only limited to macOS and Linux.

Please note the placement of utility functions in shared-head.js if they were
generally useful beyond the xpcshell tests, and in xpcshell/head.js if the
functions were only useful for the specific FileIO tests.

Differential Revision: https://phabricator.services.mozilla.com/D93850

tools/profiler/tests/shared-head.js

@@ -104,7 +104,7 @@ function getPayloadsOfType(thread, type) {
  * Applies the marker schema to create individual objects for each marker
  *
  * @param {Object} thread The thread from a profile.
- * @return {Array} The markers.
+ * @return {InflatedMarker[]} The markers.
  */
 function getInflatedMarkerData(thread) {
   const { markers, stringTable } = thread;
@@ -153,3 +153,37 @@ async function stopAndGetProfile() {
   Services.profiler.StopProfiler();
   return profile;
 }
+
+/**
+ * Verifies that a marker is an interval marker.
+ *
+ * @param {InflatedMarker} marker
+ * @returns {boolean}
+ */
+function isIntervalMarker(inflatedMarker) {
+  return (
+    inflatedMarker.phase === 1 &&
+    typeof inflatedMarker.startTime === "number" &&
+    typeof inflatedMarker.endTime === "number"
+  );
+}
+
+/**
+ * @param {Profile} profile
+ * @returns {Thread[]}
+ */
+function getThreads(profile) {
+  const threads = [];
+
+  function getThreadsRecursive(process) {
+    for (const thread of process.threads) {
+      threads.push(thread);
+    }
+    for (const subprocess of process.processes) {
+      getThreadsRecursive(subprocess);
+    }
+  }
+
+  getThreadsRecursive(profile);
+  return threads;
+}

tools/profiler/tests/xpcshell/head.js

@@ -118,3 +118,61 @@ function expectStackToContain(
 
   Assert.ok(true, message);
 }
+
+/**
+ * @param {Thread} thread
+ * @param {string} filename - The filename used to trigger FileIO.
+ * @returns {InflatedMarkers[]}
+ */
+function getInflatedFileIOMarkers(thread, filename) {
+  const markers = getInflatedMarkerData(thread);
+  return markers.filter(
+    marker =>
+      marker.data?.type === "FileIO" && marker.data?.filename.endsWith(filename)
+  );
+}
+
+/**
+ * Checks properties common to all FileIO markers.
+ *
+ * @param {InflatedMarkers[]} markers
+ * @param {string} filename
+ */
+function checkInflatedFileIOMarkers(markers, filename) {
+  greater(markers.length, 0, "Found some markers");
+
+  // See IOInterposeObserver::Observation::ObservedOperationString
+  const validOperations = new Set([
+    "write",
+    "fsync",
+    "close",
+    "stat",
+    "create/open",
+    "read",
+  ]);
+  const validSources = new Set(["PoisonIOInterposer", "NSPRIOInterposer"]);
+
+  for (const marker of markers) {
+    try {
+      ok(
+        marker.name.startsWith("FileIO"),
+        "Has a marker.name that starts with FileIO"
+      );
+      equal(marker.data.type, "FileIO", "Has a marker.data.type");
+      ok(isIntervalMarker(marker), "All FileIO markers are interval markers");
+      ok(
+        validOperations.has(marker.data.operation),
+        `The markers have a known operation - "${marker.data.operation}"`
+      );
+      ok(
+        validSources.has(marker.data.source),
+        `The FileIO marker has a known source "${marker.data.source}"`
+      );
+      ok(marker.data.filename.endsWith(filename));
+      ok(Boolean(marker.data.stack), "A stack was collected");
+    } catch (error) {
+      console.error("Failing inflated FileIO marker:", marker);
+      throw error;
+    }
+  }
+}

tools/profiler/tests/xpcshell/test_feature_fileioall.js

@@ -0,0 +1,171 @@
+/* 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 is only needed for getting a temp file location, which IOUtils
+// cannot currently do.
+const { OS } = ChromeUtils.import("resource://gre/modules/osfile.jsm");
+
+add_task(async () => {
+  if (!AppConstants.MOZ_GECKO_PROFILER) {
+    return;
+  }
+  info(
+    "Test that off-main thread fileio is captured for a profiled thread, " +
+      "and that it will be sent to the main thread."
+  );
+  const filename = "test_marker_fileio";
+  const profile = await startProfilerAndTriggerFileIO({
+    features: ["fileioall"],
+    threadsFilter: ["GeckoMain", "BackgroundThreadPool"],
+    filename,
+  });
+
+  const threads = getThreads(profile);
+  const mainThread = threads.find(thread => thread.name === "GeckoMain");
+  const mainThreadFileIO = getInflatedFileIOMarkers(mainThread, filename);
+  let backgroundThread;
+  let backgroundThreadFileIO;
+  for (const thread of threads) {
+    // Check for FileIO in any of the background threads.
+    if (thread.name.startsWith("BackgroundThreadPool")) {
+      const markers = getInflatedFileIOMarkers(thread, filename);
+      if (markers.length > 0) {
+        backgroundThread = thread;
+        backgroundThreadFileIO = markers;
+        break;
+      }
+    }
+  }
+
+  info("Check all of the main thread FileIO markers.");
+  checkInflatedFileIOMarkers(mainThreadFileIO, filename);
+  for (const { data, name } of mainThreadFileIO) {
+    equal(
+      name,
+      "FileIO (non-main thread)",
+      "The markers from off main thread are labeled as such."
+    );
+    equal(
+      data.threadId,
+      backgroundThread.tid,
+      "The main thread FileIO markers were all sent from the background thread."
+    );
+  }
+
+  info("Check all of the background thread FileIO markers.");
+  checkInflatedFileIOMarkers(backgroundThreadFileIO, filename);
+  for (const { data, name } of backgroundThreadFileIO) {
+    equal(
+      name,
+      "FileIO",
+      "The markers on the thread where they were generated just say FileIO"
+    );
+    equal(
+      data.threadId,
+      undefined,
+      "The background thread FileIO correctly excludes the threadId."
+    );
+  }
+});
+
+add_task(async () => {
+  if (!AppConstants.MOZ_GECKO_PROFILER) {
+    return;
+  }
+  info(
+    "Test that off-main thread fileio is captured for a thread that is not profiled, " +
+      "and that it will be sent to the main thread."
+  );
+  const filename = "test_marker_fileio";
+  const profile = await startProfilerAndTriggerFileIO({
+    features: ["fileioall"],
+    threadsFilter: ["GeckoMain"],
+    filename,
+  });
+
+  const threads = getThreads(profile);
+  const mainThread = threads.find(thread => thread.name === "GeckoMain");
+  const mainThreadFileIO = getInflatedFileIOMarkers(mainThread, filename);
+
+  info("Check all of the main thread FileIO markers.");
+  checkInflatedFileIOMarkers(mainThreadFileIO, filename);
+  for (const { data, name } of mainThreadFileIO) {
+    equal(
+      name,
+      "FileIO (non-profiled thread)",
+      "The markers from off main thread are labeled as such."
+    );
+    equal(typeof data.threadId, "number", "A thread ID is captured.");
+  }
+});
+
+/**
+ * @typedef {Object} TestConfig
+ * @prop {Array} features The list of profiler features
+ * @prop {string[]} threadsFilter The list of threads to profile
+ * @prop {string} filename A filename to trigger a write operation
+ */
+
+/**
+ * Start the profiler and get FileIO markers.
+ * @param {TestConfig}
+ * @returns {Profile}
+ */
+async function startProfilerAndTriggerFileIO({
+  features,
+  threadsFilter,
+  filename,
+}) {
+  const entries = 10000;
+  const interval = 10;
+  Services.profiler.StartProfiler(entries, interval, features, threadsFilter);
+
+  const tmpDir = OS.Constants.Path.tmpDir;
+  const path = OS.Path.join(tmpDir, filename);
+
+  info(`Using a temporary file to test FileIO: ${path}`);
+
+  if (fileExists(path)) {
+    console.warn(
+      "This test is triggering FileIO by writing to a file. However, the test found an " +
+        "existing file at the location it was trying to write to. This could happen " +
+        "because a previous run of the test failed to clean up after itself. This test " +
+        " will now clean up that file before running the test again."
+    );
+    await removeFile(path);
+  }
+
+  info("Write to the file, but do so using a background thread.");
+
+  // IOUtils handles file operations using a background thread.
+  await IOUtils.writeAtomic(path, new TextEncoder().encode("Test data."));
+  const exists = await fileExists(path);
+  ok(exists, `Created temporary file at: ${path}`);
+
+  info("Remove the file");
+  await removeFile(path);
+
+  // Pause the profiler as we don't need to collect more samples as we retrieve
+  // and serialize the profile.
+  Services.profiler.Pause();
+
+  const profile = await Services.profiler.getProfileDataAsync();
+  Services.profiler.StopProfiler();
+  return profile;
+}
+
+async function fileExists(file) {
+  try {
+    let { type } = await IOUtils.stat(file);
+    return type === "regular";
+  } catch (_error) {
+    return false;
+  }
+}
+
+async function removeFile(file) {
+  await IOUtils.remove(file);
+  const exists = await fileExists(file);
+  ok(!exists, `Removed temporary file: ${file}`);
+}

tools/profiler/tests/xpcshell/test_feature_mainthreadio.js

@@ -17,35 +17,21 @@ add_task(async () => {
     return;
   }
 
-  // Let the test harness settle, in order to avoid extraneous FileIO operations. This
-  // helps avoid false positives that we are actually triggering FileIO.
-  await wait(10);
-
   {
     const filename = "profiler-mainthreadio-test-firstrun";
-    const payloads = await startProfilerAndgetFileIOPayloads(
+    const markers = await startProfilerAndGetFileIOPayloads(
       ["mainthreadio"],
       filename
     );
-
+    info("Check the FileIO markers when using the mainthreadio feature");
-    greater(
+    checkInflatedFileIOMarkers(markers, filename);
-      payloads.length,
-      0,
-      "FileIO markers were found when using the mainthreadio feature on the profiler."
-    );
-
-    // It would be better to check on the filename, but Linux does not currently include
-    // it. See https://bugzilla.mozilla.org/show_bug.cgi?id=1533531
-    // ok(hasWritePayload(payloads, filename),
-    //    "A FileIO marker is found when using the mainthreadio feature on the profiler.");
   }
 
   {
     const filename = "profiler-mainthreadio-test-no-instrumentation";
-    const payloads = await startProfilerAndgetFileIOPayloads([], filename);
+    const markers = await startProfilerAndGetFileIOPayloads([], filename);
-
     equal(
-      payloads.length,
+      markers.length,
       0,
       "No FileIO markers are found when the mainthreadio feature is not turned on " +
         "in the profiler."
@@ -54,36 +40,28 @@ add_task(async () => {
 
   {
     const filename = "profiler-mainthreadio-test-secondrun";
-    const payloads = await startProfilerAndgetFileIOPayloads(
+    const markers = await startProfilerAndGetFileIOPayloads(
       ["mainthreadio"],
       filename
     );
-
+    info("Check the FileIO markers when re-starting the mainthreadio feature");
-    greater(
+    checkInflatedFileIOMarkers(markers, filename);
-      payloads.length,
-      0,
-      "FileIO markers were found when re-starting the mainthreadio feature on the " +
-        "profiler."
-    );
-    // It would be better to check on the filename, but Linux does not currently include
-    // it. See https://bugzilla.mozilla.org/show_bug.cgi?id=1533531
-    // ok(hasWritePayload(payloads, filename),
-    //    "Re-enabling the mainthreadio re-installs the interposer, and we can capture " +
-    //    "another FileIO payload.");
   }
 });
 
 /**
- * Start the profiler and get FileIO payloads.
+ * Start the profiler and get FileIO markers.
  * @param {Array} features The list of profiler features
  * @param {string} filename A filename to trigger a write operation
+ * @returns {InflatedMarkers[]}
  */
-async function startProfilerAndgetFileIOPayloads(features, filename) {
+async function startProfilerAndGetFileIOPayloads(features, filename) {
   const entries = 10000;
   const interval = 10;
   const threads = [];
   Services.profiler.StartProfiler(entries, interval, features, threads);
 
+  info("Get the file");
   const file = FileUtils.getFile("TmpD", [filename]);
   if (file.exists()) {
     console.warn(
@@ -95,33 +73,28 @@ async function startProfilerAndgetFileIOPayloads(features, filename) {
     file.remove(false);
   }
 
+  info(
+    "Generate file IO on the main thread using FileUtils.openSafeFileOutputStream."
+  );
   const outputStream = FileUtils.openSafeFileOutputStream(file);
 
   const data = "Test data.";
+  info("Write to the file");
   outputStream.write(data, data.length);
+
+  info("Close the file");
   FileUtils.closeSafeFileOutputStream(outputStream);
 
+  info("Remove the file");
   file.remove(false);
 
-  // Wait for the profiler to collect a sample.
-  // See https://bugzilla.mozilla.org/show_bug.cgi?id=1529053
-  await wait(500);
-
   // Pause the profiler as we don't need to collect more samples as we retrieve
   // and serialize the profile.
   Services.profiler.Pause();
 
   const profile = await Services.profiler.getProfileDataAsync();
   Services.profiler.StopProfiler();
-  return getPayloadsOfTypeFromAllThreads(profile, "FileIO");
+  const mainThread = profile.threads.find(({ name }) => name === "GeckoMain");
-}
 
-/**
+  return getInflatedFileIOMarkers(mainThread, filename);
- * See if a list of payloads has a write operation from a file.
- *
- * @param {Array<Object>} payloads The payloads captured from the profiler.
- * @param {string} filename The filename used to test a write operation.
- */
-function hasWritePayload(payloads, filename) {
-  return payloads.some(payload => payload.filename.endsWith(filename));
 }

tools/profiler/tests/xpcshell/xpcshell.ini

@@ -23,6 +23,8 @@ skip-if = !debug
 [test_asm.js]
 [test_feature_mainthreadio.js]
 skip-if = release_or_beta || (os == "win" && processor == "aarch64") # The IOInterposer is in an ifdef, aarch64 due to 1536657
+[test_feature_fileioall.js]
+skip-if = release_or_beta || (os == "win" && processor == "aarch64") # The IOInterposer is in an ifdef, aarch64 due to 1536657
 
 # The sanitizer checks appears to overwrite our own memory hooks in xpcshell tests,
 # and no allocation markers are gathered. Skip this test in that configuration.