Time tracing

Time tracing

SPAdes includes a time-tracing facility that produces trace files in more or less standard Chrome Trace Event Format that could be further visualized by Chrome and 3-rd party tools (see Useful links below).

The time tracing for SPAdes itself could be enabled by --trace-time option of spades.py as well as in developer mode --debug. Time tracing is also enabled by default on TeamCity CI.

The time trace file is a JSON file containing various steps and events as annotated in SPAdes codebase. By default the event trace file is created in each working directory of spades-core (i.e., in the each "k-mer length directory").

Some important parts of SPAdes codebase is annotated. This includes some important algorithms (e.g. k-mer index builders) as well as stages and phases in StageManager.

Adding time traces

Initialization

• Time tracing is provided by utils/perf/timetracer.hpp header
• One need to ensure that the time tracing facility is initialized and the final write handling is setup properly (see necessary steps in SPAdes codebase: SPAdes 1. SPAdes 2)

Adding time tracing

• RAII-lke object that traces the execution time between its creation and destruction:

{
  TIME_TRACE_SCOPE("event_name")
}

or

{
  TIME_TRACE_SCOPE("event_name", "data")
}

• Alternatively, one could use explicit bracket-like macro:

TIME_TRACE_BEGIN("event_name")
///
TIME_TRACE_END

NOTE: time tracing incurs some overhead and while by default all events with the durations below the pre-configured granularity is dropped is not advised to use it for measurement of time for short-timed events.

Useful links

• Chrome tracing facility (chrome://tracing)
• New Perfetto UI
• Speedscope.app