Platform/FunctionTimer Usage

mozilla/FunctionTimer.h is an easy way to get timeline-like output from native code. This is especially useful when trying to understand a sequence of events and the durations of individual steps along the way, for example when looking at startup or page load speed.

Build

The following configure argument is required:

--enable-functiontimer

Code

#include "mozilla/FunctionTimer.h"

needs to be included in any file where function timer probes are to be used.

Constructors

NS_TIME_FUNCTION;

This macro instantiates a new mozilla::FunctionTimer with the current function name and line number, using the appropriate preprocessor macros. (The file isn't used as it can be inferred from the function, and causes the output to be much more verbose than necessary.) A function entry and exit mark is printed, with the exit mark containing the duration of the function. (Note: the marks are printed at the time of constructor/destructor calls; a non-trivial destructor that executes after the FT object's destructor could throw things off. To avoid this, ensure that the FT object is created as the first thing inside any method.)

NS_TIME_FUNCTION_MIN(20);

Same as above, except that a) no entry mark will be printed; b) a mark will be printed only if the time from the previous mark (or start of function) is >= 20ms.

NS_TIME_FUNCTION_FMT("MyFunction: %s", aString);
NS_TIME_FUNCTION_MIN_FMT(20, "MyFunction: %s", aString);

Same as NS_TIME_FUNCTION and NS_TIME_FUNCTION_MIN, but with a custom printf-style string.

Marking

NS_TIME_FUNCTION_MARK("SomeEvent: %d", someValue);

Used within a function that contains a function timer. This macro places a mark in the output log containing the formatted string, as well as the time from the previous mark (or start of function).

Utility

NS_TIME_FUNCTION_ELAPSED

A double value representing the time elapsed since the start of the function, in milliseconds. If the functiontimer is disabled, this value is always 0.0.

NS_TIME_FUNCTION_ELAPSED_SINCE_MARK

A double value representing the time elapsed since the last mark or start of the function, in milliseconds. If the functiontimer is disabled, this value is always 0.0.

Runtime

Run with the MOZ_FT environment variable set to either 'stdout', 'stderr', or a filename to receive the log. For example:

export MOZ_FT=stderr
./firefox ...

Example

void
SomeFunction(int aValue, double aSecondValue)
{
  NS_TIME_FUNCTION_FMT("SomeFunction(%d, %f)", aValue, aSecondValue);

  for (int i = 0; i < aValue; ++i) {
    NS_TIME_FUNCTION_MARK("Loop %d", i);
  }
}

Will print markers on function entry, exit, and for every loop iteration.

void
AnotherFunction(int aLoopMax)
{
  NS_TIME_FUNCTION_MIN(10);

  NS_TIME_FUNCTION_MARK("loop start");
  for (int i = 0; i < aLoopMax; ++i) {
    DoSomethingWithValue(i);
    NS_TIME_FUNCTION_MARK("DoSomethingWithValue(%d)", i);
  }
}

Will print a marker only during the loop execution, and only if DoSomethingWithValue(i) takes longer than 10 ms. (If mark-to-mark time is >= 10 ms.)