tools/profiler/tests/xpcshell/test_addProfilerMarker.js

   1 /* This Source Code Form is subject to the terms of the Mozilla Public
   2  * License, v. 2.0. If a copy of the MPL was not distributed with this
   3  * file, You can obtain one at http://mozilla.org/MPL/2.0/. */
   4
   5 /**
   6  * Test that ChromeUtils.addProfilerMarker is working correctly.
   7  */
   8
   9 const markerNamePrefix = "test_addProfilerMarker";
  10 const markerText = "Text payload";
  11 // The same startTime will be used for all markers with a duration,
  12 // and we store this value globally so that expectDuration and
  13 // expectNoDuration can access it. The value isn't set here as we
  14 // want a start time after the profiler has started
  15 var startTime;
  16
  17 function expectNoDuration(marker) {
  18   Assert.equal(
  19     typeof marker.startTime,
  20     "number",
  21     "startTime should be a number"
  22   );
  23   Assert.greater(
  24     marker.startTime,
  25     startTime,
  26     "startTime should be after the begining of the test"
  27   );
  28   Assert.equal(typeof marker.endTime, "number", "endTime should be a number");
  29   Assert.equal(marker.endTime, 0, "endTime should be 0");
  30 }
  31
  32 function expectDuration(marker) {
  33   Assert.equal(
  34     typeof marker.startTime,
  35     "number",
  36     "startTime should be a number"
  37   );
  38   // Floats can cause rounding issues. We've seen up to a 4.17e-5 difference in
  39   // intermittent failures, so we are permissive and accept up to 5e-5.
  40   Assert.less(
  41     Math.abs(marker.startTime - startTime),
  42     5e-5,
  43     "startTime should be the expected time"
  44   );
  45   Assert.equal(typeof marker.endTime, "number", "endTime should be a number");
  46   Assert.greater(
  47     marker.endTime,
  48     startTime,
  49     "endTime should be after startTime"
  50   );
  51 }
  52
  53 function expectNoData(marker) {
  54   Assert.equal(
  55     typeof marker.data,
  56     "undefined",
  57     "The data property should be undefined"
  58   );
  59 }
  60
  61 function expectText(marker) {
  62   Assert.equal(
  63     typeof marker.data,
  64     "object",
  65     "The data property should be an object"
  66   );
  67   Assert.equal(marker.data.type, "Text", "Should be a Text marker");
  68   Assert.equal(
  69     marker.data.name,
  70     markerText,
  71     "The payload should contain the expected text"
  72   );
  73 }
  74
  75 function expectNoStack(marker) {
  76   Assert.ok(!marker.data || !marker.data.stack, "There should be no stack");
  77 }
  78
  79 function expectStack(marker, thread) {
  80   let stack = marker.data.stack;
  81   Assert.ok(!!stack, "There should be a stack");
  82
  83   // Marker stacks are recorded as a profile of a thread with a single sample,
  84   // get the stack id.
  85   stack = stack.samples.data[0][stack.samples.schema.stack];
  86
  87   const stackPrefixCol = thread.stackTable.schema.prefix;
  88   const stackFrameCol = thread.stackTable.schema.frame;
  89   const frameLocationCol = thread.frameTable.schema.location;
  90
  91   // Get the entire stack in an array for easier processing.
  92   let result = [];
  93   while (stack != null) {
  94     let stackEntry = thread.stackTable.data[stack];
  95     let frame = thread.frameTable.data[stackEntry[stackFrameCol]];
  96     result.push(thread.stringTable[frame[frameLocationCol]]);
  97     stack = stackEntry[stackPrefixCol];
  98   }
  99
 100   Assert.greaterOrEqual(
 101     result.length,
 102     1,
 103     "There should be at least one frame in the stack"
 104   );
 105
 106   Assert.ok(
 107     result.some(frame => frame.includes("testMarker")),
 108     "the 'testMarker' function should be visible in the stack"
 109   );
 110
 111   Assert.ok(
 112     !result.some(frame => frame.includes("ChromeUtils.addProfilerMarker")),
 113     "the 'ChromeUtils.addProfilerMarker' label frame should not be visible in the stack"
 114   );
 115 }
 116
 117 add_task(async () => {
 118   await ProfilerTestUtils.startProfilerForMarkerTests();
 119   startTime = Cu.now();
 120   while (Cu.now() < startTime + 1) {
 121     // Busy wait for 1ms to ensure the intentionally set start time of markers
 122     // will be significantly different from the time at which the marker is
 123     // recorded.
 124   }
 125   info("startTime used for markers with durations: " + startTime);
 126
 127   /* Each call to testMarker will record a marker with a unique name.
 128    * The testFunctions and testCases objects contain respectively test
 129    * functions to verify that the marker found in the captured profile
 130    * matches expectations, and a string that can be printed to describe
 131    * in which way ChromeUtils.addProfilerMarker was called. */
 132   let testFunctions = {};
 133   let testCases = {};
 134   let markerId = 0;
 135   function testMarker(args, checks) {
 136     let name = markerNamePrefix + markerId++;
 137     ChromeUtils.addProfilerMarker(name, ...args);
 138     testFunctions[name] = checks;
 139     testCases[name] = `ChromeUtils.addProfilerMarker(${[name, ...args]
 140       .toSource()
 141       .slice(1, -1)})`;
 142   }
 143
 144   info("Record markers without options object.");
 145   testMarker([], m => {
 146     expectNoDuration(m);
 147     expectNoData(m);
 148   });
 149   testMarker([startTime], m => {
 150     expectDuration(m);
 151     expectNoData(m);
 152   });
 153   testMarker([undefined, markerText], m => {
 154     expectNoDuration(m);
 155     expectText(m);
 156   });
 157   testMarker([startTime, markerText], m => {
 158     expectDuration(m);
 159     expectText(m);
 160   });
 161
 162   info("Record markers providing the duration as the startTime property.");
 163   testMarker([{ startTime }], m => {
 164     expectDuration(m);
 165     expectNoData(m);
 166   });
 167   testMarker([{}, markerText], m => {
 168     expectNoDuration(m);
 169     expectText(m);
 170   });
 171   testMarker([{ startTime }, markerText], m => {
 172     expectDuration(m);
 173     expectText(m);
 174   });
 175
 176   info("Record markers to test the captureStack property.");
 177   const captureStack = true;
 178   testMarker([], expectNoStack);
 179   testMarker([startTime, markerText], expectNoStack);
 180   testMarker([{ captureStack: false }], expectNoStack);
 181   testMarker([{ captureStack }], expectStack);
 182   testMarker([{ startTime, captureStack }], expectStack);
 183   testMarker([{ captureStack }, markerText], expectStack);
 184   testMarker([{ startTime, captureStack }, markerText], expectStack);
 185
 186   info("Record markers to test the category property");
 187   function testCategory(args, expectedCategory) {
 188     testMarker(args, marker => {
 189       Assert.equal(marker.category, expectedCategory);
 190     });
 191   }
 192   testCategory([], "JavaScript");
 193   testCategory([{ category: "Test" }], "Test");
 194   testCategory([{ category: "Test" }, markerText], "Test");
 195   testCategory([{ category: "JavaScript" }], "JavaScript");
 196   testCategory([{ category: "Other" }], "Other");
 197   testCategory([{ category: "DOM" }], "DOM");
 198   testCategory([{ category: "does not exist" }], "Other");
 199
 200   info("Capture the profile");
 201   const profile = await ProfilerTestUtils.stopNowAndGetProfile();
 202   const mainThread = profile.threads.find(({ name }) => name === "GeckoMain");
 203   const markers = ProfilerTestUtils.getInflatedMarkerData(mainThread).filter(
 204     m => m.name.startsWith(markerNamePrefix)
 205   );
 206   Assert.equal(
 207     markers.length,
 208     Object.keys(testFunctions).length,
 209     `Found ${markers.length} test markers in the captured profile`
 210   );
 211
 212   for (let marker of markers) {
 213     marker.category = profile.meta.categories[marker.category].name;
 214     info(`${testCases[marker.name]} -> ${marker.toSource()}`);
 215
 216     testFunctions[marker.name](marker, mainThread);
 217     delete testFunctions[marker.name];
 218   }
 219
 220   Assert.equal(0, Object.keys(testFunctions).length, "all markers were found");
 221 });