GitHub

Profiling and timers

TensorKit's index manipulations, tensor contractions and factorizations are instrumented with TimerOutputs.jl sections that are compiled away by default, so they incur no runtime cost. They can be enabled to obtain a detailed breakdown of where time is spent inside these operations, in particular the split between the different kinds of work involved in manipulating symmetric tensors:

categorycontents
symmetryfusion tree manipulations and recoupling coefficients (braiding, transposing, F- and R-symbols)
bookkeepingblock structure computations, cache lookups, contraction planning
allocallocation of output tensors and temporary buffers
densedense tensor kernels (BLAS/LAPACK calls, strided permutations and additions)
otherremaining time within an instrumented operation (dispatch, argument checking, uncovered overhead)

The canonical workflow looks as follows:

using TensorKit

TensorKit.enable_timers!()      # triggers recompilation of the instrumented methods

# warm up first, so that compilation does not pollute the timings
V = SU2Space(0 => 4, 1//2 => 4, 1 => 2)
t = rand(V ⊗ V ← V ⊗ V)
permute(t, ((1, 3), (2, 4)))
@tensor t2[a b; c d] := t[a x; c y] * t[y b; x d]
svd_compact(t)

TensorKit.reset_timers!()
# ... run the workload of interest ...
TensorKit.print_timers()        # full nested call tree
TensorKit.timer_summary()       # symmetry / bookkeeping / alloc / dense / other totals

TensorKit.disable_timers!()

TensorKit.print_timers displays the accumulated timings as a nested call tree, with sections for the top-level operations ("permute!/braid!", "contract!", "svd_compact!", ...) and nested sections labeled by their category prefix ("symmetry: ...", "bookkeeping: ...", "alloc: ...", "dense: ..."). TensorKit.timer_summary aggregates the exclusive time of each section (its own time minus that of its timed children) into per-category totals, such that every nanosecond is counted exactly once and the totals sum to the total measured time.

A few caveats to keep in mind:

  • Enabling or disabling the timers redefines internal functions, so instrumented methods recompile on first use afterwards. This is a debug-session switch, not a runtime option.
  • While timers are enabled, TensorKit-internal task parallelism is disabled, since the timer object may only be manipulated from a single task. As a consequence, multi-threaded speedups are not measurable while timing, and TensorKit functions should not be called concurrently from multiple user tasks.
  • Each section entry costs roughly 100–200 ns, which can distort measurements of workloads on very small tensors.
  • The construction of fusion tree transformers and block structures is cached (see empty_globalcaches!), so their cost only shows up the first time a given structure is encountered. Call TensorKit.empty_globalcaches!() before the measurement if you want the construction cost to be included, or after the warm-up if you want to measure the steady-state behavior with warm caches.
  • For GPU tensors, the timings only reflect host-side dispatch of asynchronous kernels, unless the workload is explicitly synchronized.

Library documentation

TensorKit.enable_timers! — Function
TensorKit.enable_timers!()

Enable all timer sections of TensorKit (including its submodules), which accumulate timings of the internal kernels into GLOBAL_TIMER. Undone by disable_timers!.

Warning

Enabling or disabling timers redefines internal functions and therefore triggers recompilation of the instrumented methods on first use. This is a debug-session operation, not a runtime switch.

Warning

While timers are enabled, TensorKit-internal task parallelism is disabled (threaded regions run serially), so multi-threaded speedups are not measurable. Additionally, TensorKit functions should not be called concurrently from multiple user tasks while timing, as the timer object is not thread-safe.

Note that each timer section adds an overhead of roughly 100-200 ns per entry, which can distort measurements of very small workloads. For GPU tensors, timings only reflect host-side dispatch of asynchronous kernels unless the workload is explicitly synchronized.

source
TensorKit.print_timers — Function
TensorKit.print_timers(io::IO = stdout; kwargs...)

Print the accumulated timings in GLOBAL_TIMER as a nested table. Keyword arguments are forwarded to TimerOutputs.print_timer.

source
TensorKit.timer_summary — Function
TensorKit.timer_summary([io::IO]; to = GLOBAL_TIMER)
    -> Dict{Symbol, @NamedTuple{time::Int64, allocated::Int64, ncalls::Int64}}

Aggregate the timer tree into per-category totals (time in ns, allocated bytes, number of section entries) for the categories (:symmetry, :bookkeeping, :alloc, :dense, :other).

Each section's exclusive time (its own time minus that of its timed children) is attributed to the category given by its label prefix or, for unprefixed labels, to the category of the nearest categorized ancestor (:other at the root). Every nanosecond is thus counted exactly once and the totals sum to the total measured time.

When io is given (default stdout), a small table is printed; pass nothing to skip printing and only return the totals.

source
TensorKit.timer — Function
TensorKit.timer() -> TimerOutputs.TimerOutput

Return the global timer object GLOBAL_TIMER into which all TensorKit timer sections accumulate.

source
TensorKit.timers_enabled — Function
TensorKit.timers_enabled() -> Bool

Return whether the @timeit_debug timer sections of TensorKit are currently compiled in, i.e. whether enable_timers! has been called.

This is a documented alias for timeit_debug_enabled, the switch that is redefined by TimerOutputs.enable_debug_timings. It is used internally to force serial execution of parallel regions while timing, since a TimerOutput may only be manipulated from a single task. When timers are disabled this check const-folds to false, so it has no runtime cost.

source