@FIR-2148 - Fix GGML Perf Summary Double Counting for Reused Graph Nodes

Merged
AK
3mo ago
+20-13

Fix GGML perf summary aggregation to avoid re-adding cumulative node perf counters across reused graph executions.
The issue caused MAT_MUL OPU runs and total time to be over-counted in the final summary. Actual MAT_MUL execution count was correct, but ggml_perf_accumulate() was repeatedly accumulating node->perf_runs, node->perf_time_us, and node->tsi_kernel_runs without clearing them. This change snapshots the node perf values, accumulates them once into totals, and then resets the node counters to prevent duplicate accounting.

TSISIM result

root@tsisim:/usr/bin/tsi/bin# /tsi/tsi-sw/check_tsictl.sh
Index 0: execute : 2930
execute_debug : 0
Index 1: execute : 969
execute_debug : 0
Index 2: execute : 969
execute_debug : 0
Index 3: execute : 969
execute_debug : 0
Index 4: execute : 969
execute_debug : 0
Index 5: execute : 908
execute_debug : 0
Index 6: execute : 765
execute_debug : 0
Index 7: execute : 765
execute_debug : 0
Index 8: execute : 765
execute_debug : 0
Index 9: execute : 765
execute_debug : 0
Index 10: execute : 765
execute_debug : 0
Index 11: execute : 765
execute_debug : 0
Index 12: execute : 765
execute_debug : 0
Index 13: execute : 765
execute_debug : 0
Index 14: execute : 765
execute_debug : 0
Index 15: execute : 765
execute_debug : 0
Index 16: execute : 765
execute_debug : 0
Index 17: execute : 765
execute_debug : 0
Index 18: execute : 765
execute_debug : 0
Index 19: execute : 385
execute_debug : 0
root@tsisim:/usr/bin/tsi/bin#
root@tsisim:/usr/bin/tsi/bin#
root@tsisim:/usr/bin/tsi/bin#
root@tsisim:/usr/bin/tsi/bin# cat ./tsi-ggml/tsavorite-model-deployment.yaml

Tsavorite deployment config

txe_count: 20
multi_thread_enable: true

Runtime user DRAM size in GiB.

Example: 1 = 1GB, 2 = 2GB.

If this key is missing, runtime DeviceConfig default is used.

user_dram_size_gb: 16

Enable additional Triton MAT_MUL shapes beyond stable baseline.

false = old behavior

true = new offload shapes

advanced_matmul_shape_offload: true

Enable Triton MAT_MUL small-N transpose optimization.

false = old behavior

true = for M >> N, compute swapped [N x M] and transpose copyback to [M x N]

triton_matmul_small_n_transpose_opt: true
root@tsisim:/usr/bin/tsi/bin# ./run_llama_cli.sh
MODEL: Llama3.2:1B-1.2B-F32.gguf
INFO: updated /usr/bin/tsi/bin/tsi-ggml/tsavorite-model-deployment.yaml with txe_count:20, multi_thread_enable:true; preserved advanced_matmul_shape_offload:true, triton_matmul_small_n_transpose_opt:true

TSI deploy yaml=tsavorite-model-deployment.yaml txe_count=20 multi_thread_enable=1 user_dram_size_gb=16 user_dram_size_bytes=17179869184 advanced_matmul_shape_offload=1 triton_matmul_small_n_transpose_opt=1
[2026-08-05 03:07:33.182] [info] </proj/work/srv-ghr/ral/FlexHAL/src/hal.c:170> hal_lib_init: topology from tsi-soc-hal: ral_tag=SKYLP_G0741 num_chiplets=10 chiplet_stride=0x1c000000 ral_csr_base=0x20000000
[2026-08-05 03:07:33.187] [info] </proj/work/srv-ghr/ral/FlexHAL/src/hal.c:263> hal_lib_init: complete — 10 chiplets, ral_tag=SKYLP_G0741
[2026-08-05 03:07:33.189] [info] </proj/work/srv-ghr/git-runner/sdk-ci-arm64-actions-runner/_work/sdk/sdk/runtime/third-party/common-runtime/src/cma/cma.c:823> num_vm_segments: 2
[2026-08-05 03:07:33.189] [info] </proj/work/srv-ghr/git-runner/sdk-ci-arm64-actions-runner/_work/sdk/sdk/runtime/third-party/common-runtime/src/cma/cma.c:826> VM segment 0: start_addr = 0xfe08bccb5000, size = 17079185408
[2026-08-05 03:07:33.189] [info] </proj/work/srv-ghr/git-runner/sdk-ci-arm64-actions-runner/_work/sdk/sdk/runtime/third-party/common-runtime/src/cma/cma.c:833> VMA: map_addr = 0xfe08bccb5000, map_size = 17079185408
[2026-08-05 03:07:33.189] [info] </proj/work/srv-ghr/git-runner/sdk-ci-arm64-actions-runner/_work/sdk/sdk/runtime/third-party/common-runtime/src/cma/cma.c:835> VMA: dev_buf = 0xfe0dcfea03b8
[2026-08-05 03:07:33.189] [info] </proj/work/srv-ghr/git-runner/sdk-ci-arm64-actions-runner/_work/sdk/sdk/runtime/third-party/common-runtime/src/cma/cma.c:836> VMA: dev_buf_num = 1
[2026-08-05 03:07:33.189] [info] </proj/work/srv-ghr/git-runner/sdk-ci-arm64-actions-runner/_work/sdk/sdk/runtime/third-party/common-runtime/src/cma/cma.c:837> VMA: dev_buf_offset = 100683776
[2026-08-05 03:07:33.189] [info] </proj/work/srv-ghr/git-runner/sdk-ci-arm64-actions-runner/_work/sdk/sdk/runtime/third-party/common-runtime/src/cma/cma.c:826> VM segment 1: start_addr = 0xfe08b6cb0000, size = 100683776
[2026-08-05 03:07:33.189] [info] </proj/work/srv-ghr/git-runner/sdk-ci-arm64-actions-runner/_work/sdk/sdk/runtime/third-party/common-runtime/src/cma/cma.c:833> VMA: map_addr = 0xfe08b6cb0000, map_size = 100683776
[2026-08-05 03:07:33.189] [info] </proj/work/srv-ghr/git-runner/sdk-ci-arm64-actions-runner/_work/sdk/sdk/runtime/third-party/common-runtime/src/cma/cma.c:835> VMA: dev_buf = 0xfe0dcfea0490
[2026-08-05 03:07:33.189] [info] </proj/work/srv-ghr/git-runner/sdk-ci-arm64-actions-runner/_work/sdk/sdk/runtime/third-party/common-runtime/src/cma/cma.c:836> VMA: dev_buf_num = 2
[2026-08-05 03:07:33.189] [info] </proj/work/srv-ghr/git-runner/sdk-ci-arm64-actions-runner/_work/sdk/sdk/runtime/third-party/common-runtime/src/cma/cma.c:837> VMA: dev_buf_offset = 0
is molly and she's a 3 year

llama_perf_sampler_print: sampling time = 64.21 ms / 15 runs ( 4.28 ms per token, 233.62 tokens per second)
llama_perf_context_print: load time = 468285.46 ms
llama_perf_context_print: prompt eval time = 464521.70 ms / 5 tokens (92904.34 ms per token, 0.01 tokens per second)
llama_perf_context_print: eval time = 4123141.87 ms / 9 runs (458126.87 ms per token, 0.00 tokens per second)
llama_perf_context_print: total time = 4591505.93 ms / 14 tokens

=== GGML Perf Summary ===
Op Target Runs TSI_KERNEL-RUN Total us Avg us
ADD OPU 320 440 112294 350.92
MUL OPU 330 454 94597 286.66
RMS_NORM OPU 330 330 59820 181.27
MUL_MAT CPU 3156 0 6778272 2147.74
MUL_MAT OPU 640 12480 4541443767 7096005.89
CONT OPU 320 0 80329 251.03
RESHAPE CPU 1307 0 1411 1.08
VIEW CPU 1390 0 230 0.17
VIEW OPU 320 0 567 1.77
PERMUTE CPU 902 0 256 0.28
PERMUTE OPU 320 0 306 0.96
TRANSPOSE CPU 446 0 78 0.17
GET_ROWS OPU 30 0 738 24.60
SET_ROWS CPU 1068 0 8375 7.84
SOFT_MAX OPU 160 0 74806 467.54
ROPE CPU 1066 0 13674 12.83
GLU OPU 160 220 14929403 93308.77

OPU Profiling Results:
Profiler disabled

root@tsisim:/usr/bin/tsi/bin#
root@tsisim:/usr/bin/tsi/bin#
root@tsisim:/usr/bin/tsi/bin#
root@tsisim:/usr/bin/tsi/bin# /tsi/tsi-sw/check_tsictl.sh
Index 0: execute : 4770
execute_debug : 0
Index 1: execute : 1670
execute_debug : 0
Index 2: execute : 1670
execute_debug : 0
Index 3: execute : 1670
execute_debug : 0
Index 4: execute : 1670
execute_debug : 0
Index 5: execute : 1548
execute_debug : 0
Index 6: execute : 1405
execute_debug : 0
Index 7: execute : 1405
execute_debug : 0
Index 8: execute : 1405
execute_debug : 0
Index 9: execute : 1405
execute_debug : 0
Index 10: execute : 1405
execute_debug : 0
Index 11: execute : 1405
execute_debug : 0
Index 12: execute : 1405
execute_debug : 0
Index 13: execute : 1405
execute_debug : 0
Index 14: execute : 1405
execute_debug : 0
Index 15: execute : 1405
execute_debug : 0
Index 16: execute : 1405
execute_debug : 0
Index 17: execute : 1405
execute_debug : 0
Index 18: execute : 1405
execute_debug : 0
Index 19: execute : 705
execute_debug : 0
root@tsisim:/usr/bin/tsi/bin#

Posix result
akapoor@wspd0 llama.cpp]$ rm -f run.log
[akapoor@wspd0 llama.cpp]$
[akapoor@wspd0 llama.cpp]$ build-posix/bin/llama-cli \

-p "My cat's name is"
-m /proj/rel/sw/ggml/models/Tiny-Llama-v0.3-FP32-1.1B-F32.gguf
--device tsavorite
-c 12288
--temp 0.0
--n-predict 4
--repeat-penalty 1.5
-b 1024
--top-k 50
--top-p 0.9
--repeat-last-n 5
--no-warmup
--no-conversation \

run.log 2>&1
[akapoor@wspd0 llama.cpp]$
[akapoor@wspd0 llama.cpp]$ grep "MUL_MAT OPU" run.log
MUL_MAT OPU 356 356 422058262 1185556.92
[akapoor@wspd0 llama.cpp]$
[akapoor@wspd0 llama.cpp]$ grep "llama_perf_context_print: total time" run.log
llama_perf_context_print: total time = 435343.57 ms / 10 tokens
[akapoor@wspd0 llama.cpp]$
[akapoor@wspd0 llama.cpp]$ grep "result_output" run.log | wc -l
0
[akapoor@wspd0 llama.cpp]$
[akapoor@wspd0 llama.cpp]$
[akapoor@wspd0 llama.cpp]$
[akapoor@wspd0 llama.cpp]$
[akapoor@wspd0 llama.cpp]$
[akapoor@wspd0 llama.cpp]$ vi run.log
[akapoor@wspd0 llama.cpp]$
[akapoor@wspd0 llama.cpp]$
[akapoor@wspd0 llama.cpp]$
[akapoor@wspd0 llama.cpp]$
[akapoor@wspd0 llama.cpp]$
[akapoor@wspd0 llama.cpp]$
[akapoor@wspd0 llama.cpp]$
[akapoor@wspd0 llama.cpp]$
[akapoor@wspd0 llama.cpp]$ cat run.log

TSI deploy yaml=tsavorite-model-deployment.yaml txe_count=1 multi_thread_enable=1 user_dram_size_gb=16 user_dram_size_bytes=17179869184 advanced_matmul_shape_offload=1 triton_matmul_small_n_transpose_opt=1
My cat's name is Luna. She

llama_perf_sampler_print: sampling time = 7.92 ms / 11 runs ( 0.72 ms per token, 1389.59 tokens per second)
llama_perf_context_print: load time = 118537.36 ms
llama_perf_context_print: prompt eval time = 108210.36 ms / 7 tokens (15458.62 ms per token, 0.06 tokens per second)
llama_perf_context_print: eval time = 316795.15 ms / 3 runs (105598.38 ms per token, 0.01 tokens per second)
llama_perf_context_print: total time = 435343.57 ms / 10 tokens

=== GGML Perf Summary ===
Op Target Runs TSI_KERNEL-RUN Total us Avg us
ADD OPU 176 428 124216 705.77
MUL OPU 180 438 310410 1724.50
RMS_NORM OPU 180 180 260411 1446.73
MUL_MAT CPU 1708 0 1713575 1003.26
MUL_MAT OPU 356 356 422058262 1185556.92
CONT OPU 176 0 30274 172.01
RESHAPE CPU 934 0 537 0.57
VIEW CPU 880 0 118 0.13
VIEW OPU 176 0 60 0.34
PERMUTE CPU 631 0 201 0.32
PERMUTE OPU 176 0 35 0.20
TRANSPOSE CPU 310 0 62 0.20
GET_ROWS OPU 12 0 2691 224.25
SET_ROWS CPU 691 0 955 1.38
SOFT_MAX OPU 88 0 59937 681.10
ROPE CPU 686 0 6253 9.12
GLU OPU 88 214 485250 5514.20

OPU Profiling Results:
Profiler disabled


Summary by cubic

Fixes double counting in GGML perf summaries when reusing a graph by snapshotting node perf counters and resetting them after accumulation. Totals (e.g., OPU MUL_MAT time and TSI kernel counts) now match actual runs, resolving FIR-2148.

  • Bug Fixes
    • Snapshot perf_time_us, perf_runs, and tsi_kernel_runs per node; skip zeros.
    • Accumulate per op/backend/unary from the snapshot, then reset node counters to 0 to prevent re-adding on reuse.
    • In GGML_PERF_DETAIL, write the detailed CSV before accumulation so per-node values are preserved.