Notes on timing LLVM

Getting LLVM Pass Timings

The dispatcher stores LLVM pass timings in the dispatcher object metadata under the llvm_pass_timings key when NUMBA_LLVM_PASS_TIMINGS is enabled or numba.config.LLVM_PASS_TIMINGS is set to truthy. The timings information contains details on how much time has been spent in each pass. The pass timings are also grouped by their purpose. For example, there will be pass timings for function-level pre-optimizations, module-level optimizations, and object code generation.

Code Example

from test_pass_timings of numba/tests/doc_examples/
 1import numba
 4def foo(n):
 5    c = 0
 6    for i in range(n):
 7        for j in range(i):
 8            c += j
 9    return c
12md = foo.get_metadata(foo.signatures[0])

Example output:

Printing pass timings for JITCodeLibrary('DocsLLVMPassTimings.test_pass_timings.<locals>.foo')
Total time: 0.0376
== #0 Function passes on '_ZN5numba5tests12doc_examples22test_llvm_pass_timings19DocsLLVMPassTimings17test_pass_timings12$3clocals$3e7foo$241Ex'
Percent: 4.8%
Total 0.0018s
Top timings:
  0.0015s ( 81.6%) SROA #3
  0.0002s (  9.3%) Early CSE #2
  0.0001s (  4.0%) Simplify the CFG #9
  0.0000s (  1.5%) Prune NRT refops #4
  0.0000s (  1.1%) Post-Dominator Tree Construction #5
== #1 Function passes on '_ZN7cpython5numba5tests12doc_examples22test_llvm_pass_timings19DocsLLVMPassTimings17test_pass_timings12$3clocals$3e7foo$241Ex'
Percent: 0.8%
Total 0.0003s
Top timings:
  0.0001s ( 30.4%) Simplify the CFG #10
  0.0001s ( 24.1%) Early CSE #3
  0.0001s ( 17.8%) SROA #4
  0.0000s (  8.8%) Prune NRT refops #5
  0.0000s (  5.6%) Post-Dominator Tree Construction #6
== #2 Function passes on 'cfunc._ZN5numba5tests12doc_examples22test_llvm_pass_timings19DocsLLVMPassTimings17test_pass_timings12$3clocals$3e7foo$241Ex'
Percent: 0.5%
Total 0.0002s
Top timings:
  0.0001s ( 27.7%) Early CSE #4
  0.0001s ( 26.8%) Simplify the CFG #11
  0.0000s ( 13.8%) Prune NRT refops #6
  0.0000s (  7.4%) Post-Dominator Tree Construction #7
  0.0000s (  6.7%) Dominator Tree Construction #29
== #3 Module passes (cheap optimization for refprune)
Percent: 3.7%
Total 0.0014s
Top timings:
  0.0007s ( 52.0%) Combine redundant instructions
  0.0001s (  5.4%) Function Integration/Inlining
  0.0001s (  4.9%) Prune NRT refops #2
  0.0001s (  4.8%) Natural Loop Information
  0.0001s (  4.6%) Post-Dominator Tree Construction #2
== #4 Module passes (full optimization)
Percent: 43.9%
Total 0.0165s
Top timings:
  0.0032s ( 19.5%) Combine redundant instructions #9
  0.0022s ( 13.5%) Combine redundant instructions #7
  0.0010s (  6.1%) Induction Variable Simplification
  0.0008s (  4.8%) Unroll loops #2
  0.0007s (  4.5%) Loop Vectorization
== #5 Finalize object
Percent: 46.3%
Total 0.0174s
Top timings:
  0.0060s ( 34.6%) X86 DAG->DAG Instruction Selection #2
  0.0019s ( 11.0%) Greedy Register Allocator #2
  0.0013s (  7.4%) Machine Instruction Scheduler #2
  0.0012s (  7.1%) Loop Strength Reduction
  0.0004s (  2.3%) Induction Variable Users

API for custom analysis

It is possible to get more details then the summary text in the above example. The pass timings are stored in a numba.misc.llvm_pass_timings.PassTimingsCollection, which contains methods for accessing individual record for each pass.

class numba.misc.llvm_pass_timings.PassTimingsCollection(name)

A collection of pass timings.

This class implements the Sequence protocol for accessing the individual timing records.


Get the i-th timing record.

res: (name, timings)

A named tuple with two fields:

  • name: str

  • timings: ProcessedPassTimings


Length of this collection.


Computes the sum of the total time across all contained timings.

res: float or None

Returns the total number of seconds or None if no timings were recorded


Returns the timings in descending order of total time duration.

res: List[ProcessedPassTimings]

Return a string representing the summary of the timings.

topn: int; optional, default=5.

This limits the maximum number of items to show. This function will show the topn most time-consuming passes.

res: str
See also ProcessedPassTimings.summary()
class numba.misc.llvm_pass_timings.ProcessedPassTimings(raw_data)

A class for processing raw timing report from LLVM.

The processing is done lazily so we don’t waste time processing unused timing information.


Returns the raw string data.

res: str

Compute the total time spend in all passes.

res: float

Get the processed data for the timing report.

res: List[PassTimingRecord]

Returns the top(n) most time-consuming (by wall-time) passes.

n: int

This limits the maximum number of items to show. This function will show the n most time-consuming passes.

res: List[PassTimingRecord]

Returns the top(n) most time-consuming passes in descending order.

summary(topn=5, indent=0)

Return a string summarizing the timing information.

topn: int; optional

This limits the maximum number of items to show. This function will show the topn most time-consuming passes.

indent: int; optional

Set the indentation level. Defaults to 0 for no indentation.

res: str
class numba.misc.llvm_pass_timings.PassTimingRecord(user_time, user_percent, system_time, system_percent, user_system_time, user_system_percent, wall_time, wall_percent, pass_name, instruction)