Tujuan Belajar — Belajar

📚 Profiling: Flame Graph & Menemukan Bottleneck Nyata Sesi: Technical Exploration · Level 3 · diverifikasi 3 Nov 2026

🎯 Tujuan Belajar

Bisa jawab "kenapa lambat" dengan bukti sampel, bukan tebakan. Konkret besok bisa:

Ambil CPU profile tanpa ubah kode (--cpu-prof, -cpuprofile, profiling.sampling attach)
Baca flame graph: lebar = waktu, bukan "tinggi = penting"
Bedakan on-CPU vs off-CPU bottleneck dan tahu kapan CPU profile menipu
Pakai differential flame graph untuk bukti optimasi berhasil

🏗️ Arsitektur & Alur Teknis

Semua profiler modern pakai sampling, bukan instrumentation:

timer (100-1000 Hz) → ambil stack trace → agregasi in-process
                    → flush tiap ~15s → storage
                    → flamegraph (frame = 1 rect, width ∝ sampel)

Kenapa sampling menang: overhead ~1 digit persen, aman di produksi. Instrumentation (cProfile non-sampling, APM "every call") overhead 2-10x dan mengubah bentuk masalah.

Tiga sumbu yang harus dipisah sebelum profiling:

Sumbu	Pertanyaan	Alat
on-CPU	CPU habis di fungsi mana?	CPU profile / flame graph
off-CPU	thread nunggu apa?	wall-clock profile, off-CPU flame, trace
alokasi	siapa bikin GC kerja?	heap/allocation profile

Aturan diagnosis: kalau wall time naik tapi CPU utilisation <30%, CPU profile bukan alat pertama. Itu off-CPU.

💻 Kode Nyata

Semua di bawah dijalankan di mesin ini (Go 1.27.3, Node v22.23.1, Python 3.11.15). Output asli.

1. Go — profil tanpa ubah kode

// main.go
package main

import "fmt"

var floatStrings = []string{"1.234", "3.14159", "2.7182818", "0.000123", "1234567.89"}

func ParseSafe(s string) (float64, error) { return parseIt(s) }
func parseIt(s string) (float64, error)   { return parseSlow(s) }

func parseSlow(s string) (float64, error) {
    var mant uint64
    var exp int
    var neg bool
    i := 0
    if i < len(s) && (s[i] == '-' || s[i] == '+') { neg = s[i] == '-'; i++ }
    for ; i < len(s) && s[i] != '.' && s[i] != 'e'; i++ { mant = mant*10 + uint64(s[i]-'0') }
    if i < len(s) && s[i] == '.' {
        i++
        for ; i < len(s) && s[i] != 'e'; i++ { mant = mant*10 + uint64(s[i]-'0'); exp-- }
    }
    f := float64(mant)
    for ; exp < 0; exp++ { f /= 10 }
    if neg { f = -f }
    return f, nil
}

go test -run XXX -bench BenchmarkParseSafe -cpuprofile=cpu.prof
go tool pprof -top -nodecount=8 cpu.prof
go tool pprof -http=:8123 cpu.prof     # Go >=1.26: default view = flame graph

Output nyata:

BenchmarkParseSafe-2   53218654   23.88 ns/op
Duration: 1.30s, Total samples = 1.29s (99.51%)
      flat  flat%   sum%        cum   cum%
     1.22s 94.57% 94.57%      1.22s 94.57%  profdemo.parseSlow
     0.03s  2.33% 96.90%      1.28s 99.22%  profdemo.BenchmarkParseSafe
     0.03s  2.33% 99.22%      1.25s 96.90%  profdemo.parseIt (inline)

Baca: parseSlow 94.57% flat (self time) dan cum sama → tidak ada anak yang mahal, biaya di badan fungsi sendiri. Kalau flat rendah tapi cum tinggi, bottleneck ada di callee, jangan optimasi fungsi itu.

2. Pitfall: benchmark menipu

BenchmarkNaive-2       9.494 ns/op   # parser buangan, cuma scan char
BenchmarkParseSafe-2  22.67 ns/op   # parser "produksi" di atas
BenchmarkStdlib-2     53.12 ns/op   # strconv.ParseFloat

Tiga angka ini tidak bisa dibandingkan sebagai "siapa lebih cepat". parseNaive tidak menangani tanda, eksponen, denormal, atau presisi; strconv.ParseFloat menangani semuanya + round-trip exact. ns/op hanya valid untuk implementasi dengan kontrak yang sama. Kalau salah satu lebih lambat tapi benar dan satunya cepat tapi salah, tidak ada trade-off — itu bug.

3. Off-CPU: CPU profile kosong padahal lambat

func blockingWork() {
    time.Sleep(2 * time.Millisecond) // simulasi DB/HTTP wait
    busyWork()
}

go test -run XXX -bench BenchmarkSleepBound -benchtime=200x -cpuprofile=offcpu.prof

BenchmarkSleepBound-2   200   2152106 ns/op     # 2.15 ms wall per op
Duration: 435.34ms, Total samples = 10ms ( 2.30%)
      10ms   100%   100%       10ms   100%  runtime.(*timers).run

2.15 ms wall, cuma 10 ms sampel CPU dari 435 ms. Flame graph-nya kosong dan itu jawabannya: biaya bukan di CPU. Yang muncul cuma runtime timer, bukan kode bisnis. Kalau lihat pola ini, pindah ke wall-clock/off-CPU profile atau distributed trace.

4. Differential flame graph (bukti optimasi)

go tool pprof -top -diff_base=base.prof new.prof

      flat  flat%   sum%        cum   cum%
     4.55s 369.92% 369.92%      4.55s 369.92%  internal/strconv.readFloat
     1.45s 117.89% 629.27%      1.45s 117.89%  profdemo.BenchmarkStdlib
    -1.15s  93.50% 535.77%     -1.15s 535.77%  profdemo.parseSlow

Persen >100% dan negatif muncul karena base profile cuma 1.23 s sampel sementara diff-nya 7.67 s — durasi base dan new tidak sebanding. Aturan: differential flame graph hanya sah kalau durasi dan total sampel dua profile sebanding. Kalau beda, normalisasi dulu (-normalize) atau samakan -benchtime.

5. Node.js — `.cpuprofile` + agregasi sendiri

const crypto = require('node:crypto');

function formatRowsBad(rows) {                     // formatter dibuat per baris
  return rows.map(r => new Intl.NumberFormat('id-ID', {
    style: 'currency', currency: 'IDR'
  }).format(r.amount));
}
function formatRows(rows) {                        // formatter dibuat sekali
  const fmt = new Intl.NumberFormat('id-ID', { style: 'currency', currency: 'IDR' });
  return rows.map(r => fmt.format(r.amount));
}
const rows = Array.from({ length: 20000 }, (_, i) => ({ amount: 1000 + i * 37 }));

{"formatRowsBad_ms":986.115301,"formatRowsReuse_ms":15.685767,"sha256x20k_ms":50.688036,
 "same":true,"node":"v22.23.1"}

20.000 baris: 986 ms vs 15.7 ms (~63x), output identik. Ini kelas bug paling umum di endpoint laporan: konstruksi objek berat (Intl.NumberFormat, RegExp, TextEncoder, koneksi, prepared statement) di dalam loop.

Ambil profil:

node --cpu-prof --cpu-prof-dir=./nprof --cpu-prof-name=cpu.cpuprofile node_demo.js

Agregator self-time tanpa dependency (.cpuprofile = JSON: nodes[].hitCount + callFrame):

const p = JSON.parse(require('node:fs').readFileSync(process.argv[2], 'utf8'));
const agg = new Map();
for (const n of p.nodes) {
  const cf = n.callFrame;
  const key = `${cf.functionName || '(anon)'} @ ${(cf.url || '').replace(/^file:\/\//, '')}:${cf.lineNumber + 1}`;
  agg.set(key, (agg.get(key) || 0) + (n.hitCount || 0));
}
const total = [...agg.values()].reduce((a, b) => a + b, 0);
[...agg].sort((a, b) => b[1] - a[1]).slice(0, 8)
  .forEach(([k, v]) => console.log(`${(v / total * 100).toFixed(1)}%  ${k}`));

Output pada run 1.05 s:

samples=816 nodes=77
 89.7%  (anon) @ node_demo.js:11     <- arrow fn di dalam formatRowsBad
  1.6%  (anon) @ node_demo.js:6
  1.2%  digest @ node:internal/crypto/hash:150
  0.7%  formatRowsBad @ node_demo.js:10

Perhatikan: fungsi bernama formatRowsBad cuma 0.7%. 89.7% masuk ke arrow function anonim di baris 11 — di dalam map. Ini kenapa .cpuprofile mentah sering menyesatkan kalau cuma lihat nama fungsi teratas.

Pola kedua, naive.js (JSON.parse(JSON.stringify()) per iterasi 100k kali):

samples=234
 58.6%  jsonClones @ naive.js:9

Dominan dan jelas. Deep-clone lewat JSON stringify = serialize + parse penuh per baris.

--cpu-prof juga jalan di Node 26 LTS; flag stabil sejak Node 12.

6. Python

Versi 3.15 (rilis 9 Okt 2026, PEP 799) punya sampling profiler di stdlib:

python -m profiling.sampling run --flamegraph -o profile.html script.py
sudo python -m profiling.sampling attach --live 12345   # butuh sudo

Mode: --mode wall (default) / cpu / gil / exception; --async-aware untuk asyncio; -a untuk semua thread. cProfile pindah nama jadi profiling.tracing; modul profile (pure-Python) deprecated, dibuang di 3.17.

Di mesin ini Python 3.11.15, jadi diukur pakai cProfile:

240006 function calls in 0.122 seconds
   ncalls  tottime  percall  cumtime  percall filename
        1    0.048    0.048    0.095    0.095 hash.py:4(<dictcomp>)
    60000    0.025    0.000    0.025    0.025 {method 'hexdigest' of '_hashlib.HASH'}

Tachyon belum diverifikasi jalan di sini — hanya dokumentasi resmi 3.15.2 yang saya baca, bukan eksekusi.

📊 Angka & Benchmark (dari sesi ini)

Pengukuran	Angka	Catatan
`parseSlow` Go	22.67–24.06 ns/op	0 alloc, 0 B/op
`parseNaive` Go	9.49–10.25 ns/op	kontrak beda, bukan pembanding sah
`strconv.ParseFloat`	53.12–53.73 ns/op	correctness penuh
`parseSlow` share CPU	94.57% flat	dari 1.29 s sampel / 1.30 s durasi
Sleep-bound bench	2.15 ms/op, sampel 10 ms dari 435 ms (2.3%)	CPU profile buta
`Intl.NumberFormat` per baris	986 ms / 20k baris	vs 15.7 ms reuse → ~63x
`--cpu-prof` Node	816 sampel / ~1.05 s	≈1.3 ms per sampel (inferensi dari wall time)
`jsonClones`	58.6% sampel	100k iterasi
Pyroscope sampling	100 Hz, flush 15 s, <50 MB/pod	klaim vendor, Grafana Labs, 9 Feb 2026
Pyroscope 2.0 symbol storage	turun sampai 95%	klaim vendor, rilis 21 Apr 2026

Semua angka di tabel pertama hasil eksekusi lokal (Go 1.27.3, Node 22.23.1, Python 3.11.15, EPYC 7K62 2 vCPU). Dua baris terakhir klaim vendor, bukan diukur sendiri.

⚖️ Trade-off & Alternatif

Alat	Overhead	Butuh restart?	Kekuatan	Kelemahan
`go test -cpuprofile`	rendah	ya (build tes)	presisi, diff mudah	bukan beban produksi
`net/http/pprof`	rendah	tidak (impor paket)	endpoint live	harus ada di kode
`perf record -g`	rendah	tidak	whole-system, native + kernel	butuh CAP_PERFMON
`--cpu-prof` Node	rendah	ya	zero-dep, file portabel	hanya CPU
`py-spy`	sangat rendah	tidak	attach ke proses Python apa pun	Rust binary, butuh ptrace
Tachyon (3.15)	~nol (eksternal)	tidak	stdlib, mode GIL/wall/async	sangat baru, butuh 3.15
Pyroscope/Parca (eBPF)	~1 digit %	tidak	kontinu, korelasi trace	biaya storage, kompleksitas

Kapan tidak profiling:

wall naik, CPU <30% → trace/db metrics dulu
masalah cuma di 1 request dari 10.000 → distributed trace, bukan flame graph (flame graph agregat, outlier hilang di rata-rata)
butuh call count exact → butuh tracing profiler, sampling tidak bisa
butuh presisi <2% untuk A/B dua implementasi → benchstat/timeit, sampling noise menutupi sinyal

🏭 Use Case Produksi & Failure Mode

Produksi: - Endpoint p99 naik, CPU 85% → ambil 30 s CPU profile saat beban nyata, cari plateau terlebar - Biaya cloud naik tanpa trafik naik → continuous profiling, cari fungsi yang makan CPU per request - Sebelum/sesudah refactor → differential flame graph, merah = regresi

Failure mode yang harus diwaspadai:

Profil di beban salah. Profil server idle menampilkan startup/JIT, bukan hot path. Harus saat beban representatif.
Durasi terlalu pendek. Contoh nyata sesi ini: 435 ms run, 10 ms sampel → tidak bisa disimpulkan apa pun. Aturan kasar: minimal 10 detik, idealnya 30+.
Base dan new tidak sebanding → persen >100% dan negatif (lihat output diff di atas). Normalisasi dulu.
Inline mengaburkan atribusi. parseIt (inline) muncul sebagai frame sendiri dengan flat 0.03 s, bukan bagian ParseSafe. Jangan heran kalau nama fungsi yang dicari "hilang".
Nama anonim mendominasi. 89.7% ke <anon> di Node. Selalu resolve ke file:line, bukan nama fungsi.
Kesalahan atribusi off-CPU. Melihat CPU profile kosong lalu menyimpulkan "tidak ada masalah". Justru sebaliknya.
perf diblokir environment. Di mesin ini perf_event_paranoid=4: Error: Access to performance monitoring and observability operations is limited. Container/K8s sering set 2-4. Solusi: --cap-add=PERFMON atau sysctl di host, jangan asal --privileged.
Sampling noise dikira regresi. 12% vs 13% di dua run itu normal. Butuh beberapa run + median sebelum klaim.

🛠️ Latihan Praktis (bisa dicoba sekarang)

Latihan 1 — buktikan angka 63x sendiri (10 menit)

mkdir -p ~/prof-lab && cd ~/prof-lab
node -e '
const mk = n => Array.from({length:n},(_,i)=>({amount:1000+i*37}));
const rows = mk(20000);
let t=process.hrtime.bigint();
rows.map(r=>new Intl.NumberFormat("id-ID",{style:"currency",currency:"IDR"}).format(r.amount));
const a=Number(process.hrtime.bigint()-t)/1e6;
const f=new Intl.NumberFormat("id-ID",{style:"currency",currency:"IDR"});
t=process.hrtime.bigint();
rows.map(r=>f.format(r.amount));
const b=Number(process.hrtime.bigint()-t)/1e6;
console.log({bad_ms:a.toFixed(1), good_ms:b.toFixed(1), ratio:(a/b).toFixed(1)});'

Lalu ambil --cpu-prof dan cari: berapa persen masuk ke <anon> vs fungsi bernama.

Latihan 2 — bangkitkan bottleneck sendiri (15 menit)

Tulis fungsi Go yang sengaja lambat (loop strings.Split berulang, atau fmt.Sprintf dalam loop 1 juta), lalu:

go test -bench . -cpuprofile=before.prof
# perbaiki, lalu:
go test -bench . -cpuprofile=after.prof
go tool pprof -top -diff_base=before.prof after.prof

Target: baca tanda - (hilang) dan + (baru) dengan benar, dan jelaskan kenapa persen bisa >100%.

Latihan 3 — uji batas profiling (10 menit)

Buat benchmark yang 95% time.Sleep. Profil. Perhatikan total sampel <5% durasi. Tulis satu paragraf: sinyal apa yang harus dicari selain flame graph.

✅ Cek Pemahaman

Flame graph menunjukkan handleRequest cum 80% tapi flat 2%. Di mana biaya sebenarnya, dan langkah berikutnya apa?
Endpoint lambat 800 ms. CPU profile 10 detik menunjukkan runtime.mcall, runtime.findRunnable, dan GC, total sampel 4% dari durasi. Diagnosis pertama Anda apa, dan alat apa yang dipakai?
Differential flame graph antara build lama dan baru menunjukkan frame dengan flat 4.5s, 370%. Apa kemungkinan besar penyebabnya, dan bagaimana membuktikan bahwa itu artefak pengukuran, bukan regresi 3.7x?

🔑 Poin Kunci

Flame graph = distribusi sampel, bukan pengukuran waktu. Lebar = proporsi sampel, dan proporsi itu estimasi dengan margin error yang mengecil seiring jumlah sampel.
flat = biaya di badan fungsi; cum = termasuk callee. Optimasi hanya masuk akal kalau flat besar.
CPU profile kosong pada program lambat adalah temuan, bukan kegagalan alat. Artinya off-CPU.
Sampling butuh durasi cukup. 435 ms → 10 ms sampel → tidak ada kesimpulan.
Differential flame graph butuh dua profil dengan total sampel sebanding, kalau tidak persen jadi tak bermakna.
Konstruksi objek berat di dalam loop adalah sumber overhead paling umum dan paling mudah diperbaiki. Ukur dulu, jangan asal cache — cache yang salah lebih mahal dari yang tidak di-cache.
Verifikasi klaim versi. Go 1.26 (Feb 2026) menjadikan flame graph tampilan default pprof -http; Go 1.27 (Agu 2026) menaikkan profil goroutineleak jadi reguler. Python 3.15 (9 Okt 2026) membawa Tachyon. Node LTS aktif: v24 "Krypton" dan v26 "Lithium"; mulai v27 siklus rilis jadi tahunan.

➡️ Eksplorasi Lanjut

Off-CPU flame graph dengan eBPF (offcputime-bpfcc) — pasangan wajib CPU flame graph
Heap/allocation profile Go (-memprofile, pprof -alloc_space vs -inuse_space) — bedanya sering salah paham
Continuous profiling Pyroscope 2.0 (arsitektur baru Apr 2026: tulis sekali ke object storage, read path stateless, dukungan OTLP Profiles) vs Parca/FrostDB
Correlation: profile ↔ trace (span ID di flame graph) — ini yang mengubah profiling dari seni jadi rutin
benchstat untuk signifikansi statistik, penutup masalah "12% vs 13%"

🔗 Sumber

Go 1.26 Release Notes — pprof default flame graph, Green Tea GC — https://go.dev/doc/go1.26 (Feb 2026)
Go 1.27 Release Notes — goroutineleak profile — https://go.dev/doc/go1.27 (Agu 2026)
Go Diagnostics — https://go.dev/doc/diagnostics
Node.js CLI --cpu-prof — https://nodejs.org/api/cli.html (v26.13.0 docs)
Node.js Releases — v24/v26 LTS, siklus tahunan mulai v27 — https://nodejs.org/en/about/previous-releases (update 28 Okt 2026)
Python 3.15 What's New — PEP 799, Tachyon — https://docs.python.org/3/whatsnew/3.15.html (rilis 9 Okt 2026)
profiling.sampling docs — https://docs.python.org/3/library/profiling.sampling.html (3.15.2)
Daniel Lemire, "Flame Graphs in Go" — https://lemire.me/blog/2025/10/26/flame-graphs-in-go/ (26 Okt 2025)
Brendan Gregg, Flame Graphs — https://www.brendangregg.com/flamegraphs.html
Grafana Labs, "Continuous profiling in production" — https://grafana.com/blog/continuous-profiling-in-production-a-real-world-example-to-measure-benefits-and-costs/ (9 Feb 2026) — klaim vendor
InfoQ, "Pyroscope 2.0" — https://www.infoq.com/news/2026/05/pyroscope-2-profiling/ (13 Mei 2026)
Platformatic, "Next-Gen Flamegraph for Node.js" — https://blog.platformatic.dev/introducing-next-gen-flamegraphs-for-nodejs (Agu 2025)

⚠️ Batasan: semua angka benchmark dari 1 mesin 2 vCPU (EPYC 7K62), bukan hardware target. Tachyon belum dieksekusi (mesin ini 3.11.15) — hanya dari dokumentasi. perf tidak bisa dijalankan di sini (perf_event_paranoid=4), jadi klaim tentang output perf tidak diverifikasi langsung. Overhead Pyroscope = angka vendor.