Wall time tells you THAT something is slow. Counters tell you WHY: branch-misses -> the CPU guessed the wrong direction and threw work away cache misses -> the core waited for memory IPC -> instructions retired per cycle: how busy the core was Two workloads, each with a "good" and a "bad" twin: branch-sorted vs branch-random : SAME instructions, SAME data volume, 13x the time. Only one counter differs. stride-1 vs stride-16 : an order of magnitude FEWER instructions, yet only 1.5x less time — and the counters look nothing alike.
$ git clone https://github.com/adit4443ya/debug_labs.git && cd debug_labs
$ cd perf && ./build.sh
$ for m in branch-sorted branch-random stride-1 stride-16; do ../tools/pin.sh -q ./bin/02_counters $m; done
branch-sorted 10 passes 82.28 ms (cpu 2)
branch-random 10 passes 1070.11 ms (cpu 2)
stride-1 10 passes 78.39 ms (cpu 2)
stride-16 10 passes 45.93 ms (cpu 2)(cpu_atom "<not counted>" lines omitted below; see lab 01 for why they exist)
$ ../tools/pin.sh -q perf stat -e cycles:u,instructions:u,branches:u,branch-misses:u ./bin/02_counters branch-sorted
301,619,631 cpu_core/cycles/u
1,455,602,504 cpu_core/instructions/u # 4.83 insn per cycle
432,062,143 cpu_core/branches/u
2,773 cpu_core/branch-misses/u # 0.00% of all branches$ ../tools/pin.sh -q perf stat -e cycles:u,instructions:u,branches:u,branch-misses:u ./bin/02_counters branch-random
2,334,724,280 cpu_core/cycles/u
1,409,457,710 cpu_core/instructions/u # 0.60 insn per cycle
427,866,447 cpu_core/branches/u
83,885,665 cpu_core/branch-misses/u # 19.61% of all branches
Read it:
- `instructions` and `branches` agree to within 3%: the two runs execute
the SAME program on the same amount of data. Time differs 7.7x in cycles.
- The only counter that moved is branch-misses: 2.8 thousand vs 83.9
MILLION. The loop runs 160M iterations (10 passes x 16M bytes) and the
`>= 128` test is a coin flip on random data, so the predictor is wrong
~80M times = half the time. "19.61% of all branches" is lower than 50%
only because the loop back-edge and the other ~2 branches per iteration
are predicted perfectly.
- Cost per mispredict: (2334.7M - 301.6M cycles) / 83.9M = ~24 cycles.That is the pipeline flush + refill on this core. IPC collapses from 4.83 to 0.60 because after every flush the core starts over. This is the classic "why is processing a sorted array faster" question, and the counter IS the answer. The `:u` suffix = user-space only, which is what unprivileged perf may count (perf_event_paranoid=2 on this box).
completely different:
$ ../tools/pin.sh -q perf stat -e cycles:u,instructions:u,L1-dcache-loads:u,L1-dcache-load-misses:u,LLC-load-misses:u ./bin/02_counters stride-1
163,189,726 cpu_core/cycles/u
565,339,998 cpu_core/instructions/u # 3.46 insn per cycle
83,934,670 cpu_core/L1-dcache-loads/
50,884 cpu_core/L1-dcache-load-misses/ # 0.06% of all L1-dcache accesses
16,498 cpu_core/LLC-load-misses/$ ../tools/pin.sh -q perf stat -e cycles:u,instructions:u,L1-dcache-loads:u,L1-dcache-load-misses:u,LLC-load-misses:u ./bin/02_counters stride-16
111,093,819 cpu_core/cycles/u
52,848,391 cpu_core/instructions/u # 0.48 insn per cycle
10,534,311 cpu_core/L1-dcache-loads/
6,906,832 cpu_core/L1-dcache-load-misses/ # 65.57% of all L1-dcache accesses
4,425,578 cpu_core/LLC-load-misses/
Read it:
- Both loops walk the same 64 MB array 10 times: 640 MB from DRAM either
way (the array is far bigger than the 18 MB L3). Same bytes moved.
- stride-1 executes 11x more instructions (it touches all 16 ints per
line, vectorized 4-wide) at 3.46 IPC and shows ALMOST NO MISSES: 16K
LLC misses for 10M cache lines. That is not because the data was in
cache — it was not — but because the hardware PREFETCHER saw the
sequential stream and fetched every line before the load asked for
it. Counters count DEMAND misses. A prefetched line is a hit.
- stride-16 touches one int per line. The prefetcher keeps up less well
with a 64-byte stride: 66% of loads miss L1 and 4.4M of the 10M lines
miss LLC on demand, so the core waits: IPC 0.48. It still finishes
faster (45 vs 78 ms) because it does 1/11 of the instructions, but
nowhere near 11x faster: the cost is moving lines, not executing loads.
Two lessons: (1) memory-bound code can show HIGH IPC and ~zero misses
when the prefetcher hides the latency; the tell is that time scales with
bytes, not instructions. (2) "cache misses" counters count what the core
waited for, not what came from DRAM. For bytes-from-DRAM you need the
uncore/memory-controller events (or just compute GB/s from bytes/time:
640 MB / 78 ms = 8.2 GB/s here).
HOW TO READ perf stat OUTPUT:
- Lines are `count event # derived metric`. Derived metrics (insn per
cycle, % of all branches) are computed by perf from the raw counts.
- perf stat counts the WHOLE process, setup included. Make the timed loop
dominate (10 passes here; the fill is <5% of instructions) or the
counters describe your setup code. (First draft of this lab used
qsort on 16M bytes: 4 seconds of sorting made the "sorted" run look
30x worse than random. Always sanity-check counts against expectations.)
- On this hybrid CPU each event is listed twice (cpu_core/ and cpu_atom/);
the PMU your process did not run on shows <not counted>. Pin first.
- `-r 5` repeats and prints mean +- stddev. If you ask for more events
than the PMU has counters, perf time-multiplexes them and prints a
"(xx.xx%)" scaling note: those counts are ESTIMATES.
- `perf list` shows event names. Generic names (cache-misses) map to
vendor events differently per CPU; for serious work use the specific
ones (L1-dcache-load-misses, LLC-load-misses, dTLB-load-misses) or raw
cpu_core/event=…,umask=…/ from the vendor's event list../bin/02_counters branch-sorted | branch-random | stride-1 | stride-16 [passes]
They are totals over the whole run. To find WHERE the misses happen you need sampling (perf record, lab 03). And a miss count is not a cost: an out-of-order core overlaps misses; the cost is the STALL, which is why cycles remain the ground truth and IPC the first thing to look at.
1. `perf stat -r 5 …` on branch-random and read the +- figure. 2. Remove the `asm volatile` barrier in `branch_sum()` and rebuild: clang turns the if into a conditional move / vector ops, the branch vanishes, and sorted == random. Compilers remove branches when they legally can; that is why "branchless" hand-tricks must be checked against the asm. 3. Change STRIDE to 8 and to 32. Predict L1 misses and time before running. 4. Add `-march=native` to build.sh: stride-1 becomes 8-wide (AVX2). Does the time change? (It should not: it is bound by bytes, not instructions.) ============================================================
#include "../tools/bench.h"
#define BRANCH_N (1u << 24) /* 16M bytes */
#define STRIDE_N (1u << 24) /* 16M ints = 64 MB, far bigger than L3 */
#define STRIDE 16 /* 16 ints = 64 bytes = one cache line */
/* Sum values >= 128 with a REAL branch: the asm barrier inside the taken path
* stops clang from if-converting (cmov) or vectorizing it. */
static uint64_t branch_sum(const unsigned char *a, size_t n) {
uint64_t sum = 0;
for (size_t i = 0; i < n; i++) {
if (a[i] >= 128) { sum += a[i]; __asm__ __volatile__("" ::: "memory"); }
}
return sum;
}
static uint64_t stride_sum(const int *a, size_t n, size_t stride) {
uint64_t sum = 0;
for (size_t i = 0; i < n; i += stride) sum += (uint64_t)a[i];
return sum;
}
/* O(n) counting sort: qsort on 16M bytes takes seconds and would swamp the
* counters (perf stat counts the WHOLE process, setup included). */
static void counting_sort(unsigned char *a, size_t n) {
size_t cnt[256] = {0};
for (size_t i = 0; i < n; i++) cnt[a[i]]++;
size_t k = 0;
for (int v = 0; v < 256; v++) while (cnt[v]--) a[k++] = (unsigned char)v;
}
int main(int argc, char **argv) {
const char *mode = argc > 1 ? argv[1] : "branch-random";
int passes = argc > 2 ? atoi(argv[2]) : 10; /* long enough that setup is <5% of counts */
uint64_t seed = 0x9E3779B97F4A7C15ull, result = 0, t0, t1;
if (!strncmp(mode, "branch", 6)) {
unsigned char *a = (unsigned char *)malloc(BRANCH_N);
for (size_t i = 0; i < BRANCH_N; i++) a[i] = (unsigned char)(bench_rand(&seed) >> 56);
if (!strcmp(mode, "branch-sorted")) counting_sort(a, BRANCH_N);
t0 = bench_ns();
for (int p = 0; p < passes; p++) result += branch_sum(a, BRANCH_N);
t1 = bench_ns();
free(a);
} else if (!strncmp(mode, "stride", 6)) {
size_t stride = !strcmp(mode, "stride-16") ? STRIDE : 1;
int *a = (int *)malloc(STRIDE_N * sizeof *a);
for (size_t i = 0; i < STRIDE_N; i++) a[i] = (int)(i & 0xFF); /* cheap fill */
t0 = bench_ns();
for (int p = 0; p < passes; p++) result += stride_sum(a, STRIDE_N, stride);
t1 = bench_ns();
free(a);
} else {
fprintf(stderr, "usage: %s branch-sorted|branch-random|stride-1|stride-16 [passes]\n", argv[0]);
return 2;
}
BENCH_KEEP(result);
printf("%-14s %3d passes %8.2f ms (cpu %d)\n", mode, passes, (double)(t1 - t0) / 1e6, bench_cpu());
return 0;
}A lab is done when you can say what it showed on your machine — not when you have read it.
It decides which problems come first, which drills open, which labs you see and how the Learn surface is organised. Change it any time from the switch in the top bar, or press Escape to look around first.