Interpreting ISS Profiler Results

Running inference with the ISS runtime is invoked using the

After running inference with ISS, you can inspect the runtime performance of your model by examining the profiler results. The results are reported in number of cycles per instruction which can be converted into inferences per second by assuming a clock speed for your GPNPU processor. Note: A 1 GHz clock speed is typically assumed when performance is reported in inferences per second.

For convenience, Quadric groups these instructions into categories to quickly evaluate which types of instructions are called most frequently during the execution of your program. During debugging, this information can be useful to discover where inefficiencies may exist in the execution of your model for the hardware configuration specified. To learn more about the different instructions types, refer to the section on Instruction Type Definitions.

Interpreting an ISS Terminal Log

Below is an example terminal log after running the

 2024-02-21 23:23 - INFO - epu - iss_testing - Started Executing lowered relay on Chimera ISS...

  0%!|(MISSING)          | 0/10 [00:00

During inference, the model's program is executed one FILM (Fusion in Local Memory) region at a time. To learn more about FILM regions, refer to the FILM Regions section of the Graph Optimizations Performed by CGC doc.

2024-02-21 23:23 - INFO - epu - iss_testing - Started Executing lowered relay on Chimera ISS...

  0%!|(MISSING)          | 0/10 [00:00

After all FILM regions have been executed, inference is complete and the total time to run inference in ISS is reported. In the example below, the total execution time was 1 minute and 22.45 seconds:

 2024-02-21 23:24 - INFO - epu - iss_testing - Done 0:01:22.450789

A table is printed verifying the original ONNX model's path, the target hardware parameters used, the maximum L2 and LRM memory used by the program:

╒═══════════════════╤═════════════════════════════════════════════════╕
 │ Module Name       │ quadric_blazepose_detector_QB1_16MB_8GBps_8GBps │
 ├───────────────────┼─────────────────────────────────────────────────┤
 │ ONNX File         │ nodes/quadric_blazepose-detector.onnx           │
 ├───────────────────┼─────────────────────────────────────────────────┤
 │ Product Target    │ QB1                                             │
 ├───────────────────┼─────────────────────────────────────────────────┤
 │ L2M Size          │ 16MB                                            │
 ├───────────────────┼─────────────────────────────────────────────────┤
 │ External Read BW  │ 8GBps                                           │
 ├───────────────────┼─────────────────────────────────────────────────┤
 │ External Write BW │ 8GBps                                           │
 ├───────────────────┼─────────────────────────────────────────────────┤
 │ Max L2M           │ 2.77MB                                          │
 ├───────────────────┼─────────────────────────────────────────────────┤
 │ Max LRM           │ 0.88kB                                          │
 ╘═══════════════════╧═════════════════════════════════════════════════╛

A second table is printed verifying the model's input and output tensor names, shapes, and the number of fractional bits used to represent the tensor's FixedPoint data type:

 ╒════╤════════╤═════════╤══════════════════╤═════════════╤═══════╕
 │    │ Type   │ Name    │ shape            │   frac_bits │ mse   │
 ╞════╪════════╪═════════╪══════════════════╪═════════════╪═══════╡
 │  0 │ Input  │ input.1 │ [1, 3, 128, 128] │          27 │ n/a   │
 ├────┼────────┼─────────┼──────────────────┼─────────────┼───────┤
 │  1 │ Output │ 303     │ [1, 896, 12]     │          24 │ n/a   │
 ├────┼────────┼─────────┼──────────────────┼─────────────┼───────┤
 │  2 │ Output │ 284     │ [1, 896, 1]      │          22 │ n/a   │
 ╘════╧════════╧═════════╧══════════════════╧═════════════╧═══════╛

Lastly, the runtime performance statistics are reported:

--------Run Statistics Normalized to 1GHz---------

 ╒═══════════════╤══════════╕
 │ Latency       │ 6.59ms   │
 ├───────────────┼──────────┤
 │ FPS @ 1GHz    │ 151.67   │
 ├───────────────┼──────────┤
 │ Ext Rd Bytes  │ 1.13MB   │
 ├───────────────┼──────────┤
 │ Ext Wr Bytes  │ 0.08MB   │
 ├───────────────┼──────────┤
 │ Avg Ext Rd BW │ 0.17GBps │
 ├───────────────┼──────────┤
 │ Avg Ext Wr BW │ 0.01GBps │
 ╘═══════════════╧══════════╛

 [SDK-CLI] : TotalCycles: 6,593,271
 [SDK-CLI] : Executions/second: 152

 compute      : ▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇ 2.954M
 data_array   : ▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇ 1.787M
 mac          : ▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇▇ 1.723M
 data_external: ▏ 32.331K
 data_ocm     : ▏ 11.832K

The final bar chart reported is a breakdown of the total number of runtime cycles by instruction type.

Instruction Type Definitions

Advanced

The remainder of the document explains how to interpret the advanced performance profiling output from ISS standalone.

Table of Contents

1. Generating Advanced Performance Metrics
2. Console Output (stdout)
3. JSON Output Files
4. Execution Categories Reference

Generating Advanced Performance Metrics

Running with ISS Standalone

Run the ISS executable with profiling flags: --profile or -p

(when running through sdk, this is done automatically)

Output Formats

Performance metrics are output in two formats:

1. Console Output - Summary printed to stdout
2. JSON Files - Detailed metrics written to the current working directory

Console Output (stdout)

Example Output

[PROFILE_KGVCID_{01:13}] Total execution time (cycles): 87162687
------------------------------------------------
[PROFILE_KGVCID_{01:13}] Profile: default
[PROFILE_KGVCID_{01:13}] TotalCycles = 87162687
[PROFILE_KGVCID_{01:13}]     ExecCycles[COMPUTE] = 43328596
[PROFILE_KGVCID_{01:13}]     ExecCycles[MAC] = 0
[PROFILE_KGVCID_{01:13}]     ExecCycles[COMPARE] = 84050
[PROFILE_KGVCID_{01:13}]     ExecCycles[BRANCH] = 43286570
[PROFILE_KGVCID_{01:13}]     ExecCycles[CONDITIONAL] = 42025
[PROFILE_KGVCID_{01:13}]     ExecCycles[ITERATIVE] = 0
[PROFILE_KGVCID_{01:13}]     ExecCycles[PREDICATION] = 0
[PROFILE_KGVCID_{01:13}]     ExecCycles[CONSTANT_MATERIALIZATION] = 84258
[PROFILE_KGVCID_{01:13}]     ExecCycles[FLOW_SETUP] = 0
[PROFILE_KGVCID_{01:13}]     ExecCycles[LOOP_SETUP] = 0
[PROFILE_KGVCID_{01:13}]     ExecCycles[REG_MOVEMENT] = 168100
[PROFILE_KGVCID_{01:13}]     ExecCycles[DATA_MOVEMENT] = 0
[PROFILE_KGVCID_{01:13}]     ExecCycles[KERNEL_SETUP] = 13
[PROFILE_KGVCID_{01:13}]     ExecCycles[INTERRUPT] = 1
[PROFILE_KGVCID_{01:13}]     StallCycles[DIV] = 0
[PROFILE_KGVCID_{01:13}]     StallCycles[MODE_WRITE] = 0
[PROFILE_KGVCID_{01:13}]     StallCycles[SPRF_RAW] = 0
[PROFILE_KGVCID_{01:13}]     StallCycles[SPRF_RARMW] = 0
[PROFILE_KGVCID_{01:13}]     StallCycles[SPRF_PWARMW] = 0
[PROFILE_KGVCID_{01:13}]     StallCycles[DEREF_REGPTR_CONFLICT] = 0
[PROFILE_KGVCID_{01:13}]     StallCycles[BRANCH] = 126693
[PROFILE_KGVCID_{01:13}]     StallCycles[LOAD] = 0
[PROFILE_KGVCID_{01:13}]     StallCycles[STORE] = 0
[PROFILE_KGVCID_{01:13}]     StallCycles[EXT_LOAD] = 0
[PROFILE_KGVCID_{01:13}]     StallCycles[EXT_STORE] = 0
[PROFILE_KGVCID_{01:13}]     StallCycles[MLS_SEND] = 0
[PROFILE_KGVCID_{01:13}]     StallCycles[RAU] = 0
[PROFILE_KGVCID_{01:13}]     StallCycles[PREDICATION] = 0
[PROFILE_KGVCID_{01:13}]     StallCycles[MUL] = 42025
[PROFILE_KGVCID_{01:13}]     StallCycles[FX32TOFP16] = 0
[PROFILE_KGVCID_{01:13}]     StallCycles[NBR_RAW] = 0
[PROFILE_KGVCID_{01:13}]     StallCycles[MEU] = 0
[PROFILE_KGVCID_{01:13}]     StallCycles[PATCH_MESH] = 0
[PROFILE_KGVCID_{01:13}]     StallCycles[QLS_Q_FULL] = 0
[PROFILE_KGVCID_{01:13}]     StallCycles[BAR_LOAD] = 0
[PROFILE_KGVCID_{01:13}]     StallCycles[BAR_STORE] = 0
[PROFILE_KGVCID_{01:13}]     StallCycles[BARRIER_MLS_DONE] = 0
[PROFILE_KGVCID_{01:13}]     StallCycles[INTERRUPT] = 0
[PROFILE_KGVCID_{01:13}]     StallCycles[TENSOR_TABLE_FULL] = 0
[PROFILE_KGVCID_{01:13}]     StallCycles[MLS_FIFO_FULL] = 0
[PROFILE_KGVCID_{01:13}]     StallCycles[INSTRUCTION_FETCH] = 355
------------------------------------------------
[PROFILE_KGVCID_{01:13}] ExtBytes[LOAD] = 0
[PROFILE_KGVCID_{01:13}] ExtBytes[STORE] = 0

Understanding the Output

Profile Prefix

Each profile entry has a prefix like [PROFILE_KGVCID_{01:13}] where:

• 01 = Kernel Group ID (Kgid)
• 13 = Virtual Core ID (Vcid)

The output includes one profile per core per profiling region.

Total Cycles

[PROFILE_KGVCID_{01:13}] TotalCycles = 87162687

The total number of cycles the kernel executed on this core.

Execution Cycles (ExecCycles)

Shows cycles spent executing each category of instruction:

[PROFILE_KGVCID_{01:13}]     ExecCycles[COMPUTE] = 43328596

In this example, 43,328,596 out of 87,162,687 total cycles were spent executing compute instructions.

Execution Categories:

Stall Cycles (StallCycles)

Shows cycles where no instruction executed due to pipeline stalls:

[PROFILE_KGVCID_{01:13}]     StallCycles[BRANCH] = 126693

In this example, 126,693 cycles no instruction was executed due to branch stalls.

Stall Categories:

External Memory Bytes (ExtBytes)

[PROFILE_KGVCID_{01:13}] ExtBytes[LOAD] = 0
[PROFILE_KGVCID_{01:13}] ExtBytes[STORE] = 0

Total bytes transferred to/from external memory.

JSON Output Files

File Naming Conventions

The JSON filename depends on your system configuration:

Note: For backwards compatibility, cluster 0 uses the filename pattern profile_coreX.json instead of profile_cluster0_coreX.json. This behavior will change in a future version.

JSON Structure

Example profile.json file:

[
{
    "data": {
        "ExecCycles": {
            "BRANCH": 43286570,
            "COMPARE": 84050,
            "COMPUTE": 43328596,
            "CONDITIONAL": 42025,
            "CONSTANT_MATERIALIZATION": 84258,
            "DATA_MOVEMENT": 0,
            "FLOW_SETUP": 0,
            "INTERRUPT": 1,
            "ITERATIVE": 0,
            "KERNEL_SETUP": 13,
            "LOOP_SETUP": 0,
            "MAC": 0,
            "PREDICATION": 0,
            "REG_MOVEMENT": 168100
        },
        "ExtBytes": {
            "LOAD": 0,
            "STORE": 0
        },
        "StallCycles": {
            "BARRIER_MLS_DONE": 0,
            "BAR_LOAD": 0,
            "BAR_STORE": 0,
            "BRANCH": 126693,
            "DEREF_REGPTR_CONFLICT": 0,
            "DIV": 0,
            "EXT_LOAD": 0,
            "EXT_STORE": 0,
            "FX32TOFP16": 0,
            "INSTRUCTION_FETCH": 355,
            "INTERRUPT": 0,
            "LOAD": 0,
            "MEU": 0,
            "MLS_FIFO_FULL": 0,
            "MLS_SEND": 0,
            "MODE_WRITE": 0,
            "MUL": 42025,
            "NBR_RAW": 0,
            "PATCH_MESH": 0,
            "PREDICATION": 0,
            "QLS_Q_FULL": 0,
            "RAU": 0,
            "SPRF_PWARMW": 0,
            "SPRF_RARMW": 0,
            "SPRF_RAW": 0,
            "STORE": 0,
            "TENSOR_TABLE_FULL": 0
        },
        "TotalCycles": 87162687
    },
    "name": "default"
}
]

The JSON format contains the same data as the print to stdout, but formatted as a json