Attempt to measure the time taken between 3 events within Firefox (OnIncrementalData, OnStreamComplete and ExecScript)

idle-monitor.bt

#!/usr/bin/env bpftrace
//
// idle-monitor    Records amount of time the CPU is idle in-between 2 events.
//
// USAGE: idle-monitor.bt
//

// Monitor when CPUs are entering the idle state, and record the associated timestamp.
kprobe:rcu_idle_enter {
  @cpuIdleCount[cpu] = nsecs
}

// Monitor when CPUs are leaving the idle state, and save the time difference
// in the @idleCount counter.
kretprobe:rcu_idle_exit {
  if (@cpuIdleCount[cpu]) {
    @idleCount += nsecs - @cpuIdleCount[cpu];
  }
  @cpuIdleCount[cpu] = 0;
}

// This is a user probe attached to the following function, which is called when we
// first call ScriptLoadHandler::OnIncrementalData.
//
// static __attribute__((noinline)) void idleMonitorStep0(mozilla::dom::ScriptLoadRequest* ptr) {
//   asm("");
//   if (uintptr_t(ptr) < 4096) {
//     printf("Grmbl!\n");
//   }
// }
uprobe:/home/nicolas/mozilla/_build/firefox/bugzil.la/1579876/wip/x64/gcc/oopt/dist/bin/libxul.so:_ZL16idleMonitorStep0PN7mozilla3dom17ScriptLoadRequestE {
  $i = 0;
  $enter = 0;
  $time = nsecs;
  unroll (8) {
    if (@cpuIdleCount[$i]) {
      $enter += $time - @cpuIdleCount[$i];
    }
    $i++;
  }
  @step0SumTime[arg0] = $enter + @idleCount;
  @step0Timestamp[arg0] = $time;
}

// Same as above, except that it is called when we call OnStreamComplete.
uprobe:/home/nicolas/mozilla/_build/firefox/bugzil.la/1579876/wip/x64/gcc/oopt/dist/bin/libxul.so:_ZL16idleMonitorStep1PN7mozilla3dom17ScriptLoadRequestE {
  if (@step0Timestamp[arg0]) {
    $i = 0;
    $enter = 0;
    $time = nsecs;
    unroll (8) {
      if (@cpuIdleCount[$i]) {
        $enter += $time - @cpuIdleCount[$i];
      }
      $i++;
    }
    @step1SumTime[arg0] = $enter + @idleCount;
    @step1Timestamp[arg0] = $time;
    $idle = @step1SumTime[arg0] - @step0SumTime[arg0];
    $delta = $time - @step0Timestamp[arg0];
    @time_bw_fetch_start_end_fetch_end = hist($delta);
    @idle_bw_fetch_start_end_fetch_end = hist($idle);
    @per_cent_idle_bw_fetch_start_and_fetch_end =
        lhist($idle * 100 / ($delta), 0, 800, 20);
    delete(@step0SumTime[arg0]);
    delete(@step0Timestamp[arg0]);
  }
}

// Same as above except that it is called when we execute ExecuteCompiledScript.
uprobe:/home/nicolas/mozilla/_build/firefox/bugzil.la/1579876/wip/x64/gcc/oopt/dist/bin/libxul.so:_ZL16idleMonitorStep2PN7mozilla3dom17ScriptLoadRequestE {
  if (@step1Timestamp[arg0]) {
    $i = 0;
    $enter = 0;
    $time = nsecs;
    unroll (8) {
      if (@cpuIdleCount[$i]) {
        $enter += $time - @cpuIdleCount[$i];
      }
      $i++;
    }
    $step2SumTime = $enter + @idleCount;
    $idle = $step2SumTime - @step1SumTime[arg0];
    $delta = $time - @step1Timestamp[arg0];
    @time_bw_fetch_end_and_exec_start = hist($delta);
    @idle_bw_fetch_end_and_exec_start = hist($idle);
    @per_cent_idle_bw_fetch_end_and_exec_start =
        lhist($idle * 100 / ($delta), 0, 800, 20);
    delete(@step1SumTime[arg0]);
    delete(@step1Timestamp[arg0]);
  }
}