Statistics API

Overview

Each time a garbage collection occurs, SpiderMonkey keeps track of how long each phase of the collection took, along with some related data. There are several ways to get access to this data:

  • The environment variable MOZ_GCTIMER controls text dumping of GC stats. MOZ_GCTIMER may be none, stderr, stdout, or a filename. If a filename is given, data is appended to that file.
    When logging to a file is used in combination with multi-process firefox (e10s) it is necessary to set security.sandbox.content.level = 0, otherwise the content process will crash.
  • The browser preference javascript.options.mem.log controls dumping of human-readable GC stats messages to the developer console.
  • The browser preference javascript.options.mem.notify controls emission of JSON encoded GC stats to an observer interface.

JSON API

Addons can obtain the complete data in JSON format via an observer. The following adds an observer using the JetPack framework.

var prefs = require("api-utils/preferences-service");
Components.utils.import('resource://gre/modules/Services.jsm');

function observer(subject, topic, json)
{
    var data = JSON.parse(json);
    // process the data
}

prefs.set("javascript.options.mem.notify", true);
Services.obs.addObserver(observer, "garbage-collection-statistics", false);

The toplevel JSON object contains these fields:

  • timestamp: integer (microseconds) - Time at which the GC ended, measured from epoch.
  • total_time: number (milliseconds) - The amount of wall time that this GC consumed. Note: this is the sum of all the slice durations, not end time - start time.
  • compartments_collected: integer - The number of compartments that were collected by the GC.
  • compartment_count: integer - The number of compartments that were present in the system at the end of the GC.
  • max_pause: number (milliseconds) - Longest duration pause during the GC.
  • nonincremental_reason: string - A string representing the reason that an incremental GC was aborted or forced to finish in a single slice. If the incremental GC completed normally, this will be "none".
  • allocated: integer (MB) - Size of the JavaScript heap in MiB at the start of the GC.
  • slices: array of Objects - A list of objects describing each slice in detail.
  • times: Object - A map from phase names to the total time taken by each phase: the sum of each field of the map from the slices.

The last two fields require a bit of elaboration. GC work can be divided into phases, such as marking or sweeping. The division into phases is hierarchical, so a phase can be split into subphases. For example, the sweep phase includes the time for the sweep_atoms, sweep_tables, sweep_compartments phases and so on. The times object gives how much time was spent in each phase of the GC, in milliseconds.

Additionally, an incremental GC is divided into a series of slices (the division into slices is completely separate from the division into phases; neither one is a refinment of the other). A little bit of GC work is done in each slice. In between slices, other browser code is allowed to run. The slices array describes how long each slice took and what work was done during the slice. Each element of the slices array is an object with these fields:

  • slice: integer - The slice index, starting at 0.
  • pause: number (milliseconds) - The slice duration.
  • when: number (milliseconds) - The time this slice started, relative to the first slice's start time.
  • reason: string - A string describing the API that initiated this GC slice.
  • page_faults: integer - Number of page faults incurred during the processing of this slice.
  • start_timestamp: integer (microseconds) - Time of slice start from epoch.
  • end_timestamp: integer (microseconds) - Time of slice end from epoch.
  • times: Object - A map from phase names to the total time taken by that phase during this slice.