Profiling Code

Kode yang terasa lambat tidak selalu lambat di tempat yang kita duga. Sebelum menyentuh satu baris pun untuk optimasi, kita perlu tahu di mana waktu eksekusi sebenarnya habis — kegiatan mengukur ini disebut profiling. Chapter ini membuka Section Optimasi dan Performa dengan tiga alat pengukuran inti MATLAB: tic/toc untuk blok kode, profile untuk peta waktu per function, dan timeit untuk fungsi yang berjalan sangat cepat. Cakupan materinya:

• tic/toc, termasuk stopwatch bertingkat dengan handle
• profile on → jalankan kode → profile off → baca hasil profile('info')
• Analisis hot spot dengan prinsip Pareto (80% waktu di 20% kode)
• timeit dan padanannya: mediana beberapa pengulangan

Ukur Dulu, Baru Optimasi #

Aturannya sederhana: jangan mengoptimasi apa pun sebelum mengukur. Mekanismenya: intuisi programmer tentang bottleneck sering meleset karena biaya nyata sebuah operasi tidak terlihat dari kode sumber — sebuah loop yang tampak berat bisa jalan di memori cache, sementara satu baris yang tampak ringan bisa memicu penyalinan array raksasa. Profiler menempatkan pengukur waktu pada tiap panggilan function sehingga kita melihat data, bukan dugaan.

tic dan toc: Stopwatch untuk Blok Kode #

Aturannya: tic menyalakan stopwatch dan toc membacanya dalam detik. Mekanismenya: tic menyimpan penanda waktu dari high-resolution clock, lalu toc menghitung selisihnya; toc juga mengembalikan nilai sehingga kita bisa menyimpannya ke variabel. Bentuk tLoop = tic; ...; toc(tLoop) memakai handle stopwatch, sehingga pengukuran blok dalam tidak terganggu oleh tic lain yang berjalan bersamaan:

n = 200000;
tic;
sVektor = sum((1:n) .^ 2);
waktuVektor = toc;
fprintf('sum vektor    (n=%d): %.4f detik\n', n, waktuVektor);

tLoop = tic;
total = 0;
for k = 1:n
    total = total + k^2;
end
waktuLoop = toc(tLoop);
fprintf('loop akumulasi (n=%d): %.4f detik\n', n, waktuLoop);
fprintf('speedup vektor vs loop: %.0fx, hasil identik: %d\n', ...
    waktuLoop / waktuVektor, isequal(total, sVektor));

Output yang Dihasilkan:

sum vektor    (n=200000): 0.0021 detik
loop akumulasi (n=200000): 0.1333 detik
speedup vektor vs loop: 62x, hasil identik: 1

Mari kita bedah baris-baris kode di atas:

1. Baris 2 (tic;): MATLAB menyimpan penanda waktu dari high-resolution clock sebagai stopwatch aktif.
2. Baris 3 (sVektor = sum(...)): seluruh kuadrat 1..200000 dijumlahkan dalam satu panggilan sum.
3. Baris 4 (waktuVektor = toc;): toc menghitung selisih waktu dan mengembalikan nilainya; assignment ke variabel waktuVektor menampung nilai tersebut tanpa mencetak apa pun ke Command Window.
4. Baris 7 (tLoop = tic;): bentuk handle — tLoop menyimpan stopwatch spesifik blok loop.
5. Baris 12 (waktuLoop = toc(tLoop);): toc(tLoop) membaca stopwatch tLoop saja, aman meski ada tic lain aktif.
6. Baris 14 (fprintf(...)): rasio waktuLoop / waktuVektor adalah speedup; isequal memastikan kedua cara menghasilkan nilai identik.

Profiler: Peta Waktu per Function #

Aturannya: jalankan siklus profile on → kode target → profile off, lalu ambil hasilnya dengan info = profile('info'). Mekanismenya: selama aktif, profiler mencatat setiap panggilan function beserta waktunya ke sebuah tabel; profile('info') menghentikan pencatatan dan mengembalikan struct yang bernaung di bidang FunctionTable — array of struct dengan bidang FunctionName, TotalTime, dan NumCalls. Kode berikut memprofil beban kerja tiga fungsi (file pendamping hitung_statistik.m tersedia di bagian Berkas Sumber):

profile clear;
profile on;
x = sin(linspace(0, pi, n));   % beban kerja deterministik
stat = hitung_statistik(x);
y = sort(x);
profile off;
info = profile('info');
ft = info.FunctionTable;
[~, urut] = sort([ft.TotalTime], 'descend');
fprintf('%-18s %10s %9s\n', 'Fungsi', 'Waktu(s)', 'Panggilan');
m = min(5, numel(urut));
kum = 0;
for i = urut(1:m)
    kum = kum + ft(i).TotalTime;
    fprintf('%-18s %10.4f %9d\n', ft(i).FunctionName, ft(i).TotalTime, ft(i).NumCalls);
end
totWaktu = sum([ft.TotalTime]);
fprintf('total waktu tercatat : %.4f detik\n', totWaktu);
fprintf('%d fungsi teratas menyumbang %.0f%% dari total waktu\n', m, 100 * kum / totWaktu);

Output yang Dihasilkan:

Fungsi               Waktu(s) Panggilan
sin                    0.0020         1
sort                   0.0016         1
hitung_statistik       0.0014         1
linspace               0.0008         1
sum                    0.0002         2
total waktu tercatat : 0.0065 detik
5 fungsi teratas menyumbang 92% dari total waktu
statistik valid: 1 (elemen=200000)

Mari kita bedah baris-baris kode di atas:

1. Baris 1 (profile clear;): menghentikan profiler dan menghapus statistik lama agar pengukuran bersih.
2. Baris 6 (profile off;): pencatatan berhenti — jangan lupa mematikan profiler sebelum membaca hasil.
3. Baris 8 (ft = info.FunctionTable;): tabel per fungsi; [ft.TotalTime] merangkum waktu seluruh baris menjadi satu vektor.
4. Baris 9 (sort(..., 'descend')): mengurutkan indeks fungsi dari waktu terbesar — hot spot berada di atas.
5. Baris 13-16 (for i = urut(1:m)): mencetak lima fungsi teratas sekaligus mengakumulasi kum untuk hitungan Pareto.

Perintah profile punya beberapa aksi lain yang perlu kita kenal:

Di MATLAB, profile viewer membuka jendela Profiler yang memperlihatkan waktu per function sekaligus per baris kode — padanan GUI dari tabel profile('info') di atas.

Hot Spot dan Prinsip Pareto #

Hasil di atas mengilustrasikan prinsip Pareto: mayoritas waktu memusat di minoritas kode. Lima fungsi teratas menyumbang 92% dari total waktu tercatat — dan dalam kode nyata, satu-dua fungsi sering menyumbang 80% dari seluruh waktu. Konsekuensinya: optimasi efektif dimulai dari fungsi paling atas tabel, bukan dari fungsi yang paling mudah diubah. Urutkan FunctionTable berdasarkan TotalTime seperti contoh kita, perbaiki fungsi nomor satu, ukur ulang, lalu ulangi bila masih perlu.

timeit: Mediana untuk Function yang Cepat #

Aturannya: untuk fungsi yang selesai di bawah beberapa milidetik, satu kali tic/toc tidak cukup akurat karena noise sistem bisa lebih besar dari waktu fungsi itu sendiri. Mekanismenya: timeit memanggil fungsi berkali-kali (lebih banyak untuk fungsi yang makin cepat) dan melaporkan mediana pengukuran — mediana kebal terhadap nilai ekstrem dari gangguan sistem. timeit tersedia sejak MATLAB R2013b:

f = @() sum((1:n) .^ 2);
t = timeit(f)

Function handle anonim @() sum(...) membungkus pemanggilan tanpa argumen sehingga timeit dapat mengulanginya. Nilai kembalian t adalah detik per pemanggilan.

f = @() sum((1:n) .^ 2);
ulang = 5;
w = zeros(1, ulang);
for r = 1:ulang
    t1 = tic;
    f();
    w(r) = toc(t1);
end
fprintf('mediana %d pengulangan: %.6f detik\n', ulang, median(w));

Output yang Dihasilkan:

mediana 5 pengulangan: 0.001686 detik

Praktik Pengukuran yang Benar #

Pilih alat sesuai kebutuhan agar pengukuran tidak lebih mahal dari kode yang diukur:

Dua kebiasaan terakhir: pertama, matikan profiler sebelum mengukur waktu akhir dengan tic/toc, karena pencatatan profiler menambah overhead sendiri. Kedua, ulangi pengukuran — bila angka antar pengulangan berayun lebar, laporkan mediana atau nilai minimum, bukan satu nilai tunggal.

Ringkasan #

Profiling mengubah optimasi dari tebak-tebakan menjadi keputusan berbasis data: tic/toc untuk stopwatch blok (dengan handle untuk blok bersarang), profile + FunctionTable (FunctionName, TotalTime, NumCalls) untuk menemukan hot spot, dan timeit/mediana berulang untuk fungsi cepat. Data pada contoh kita menunjukkan pola Pareto yang khas: lima fungsi teratas menyumbang 92% waktu. Setelah hot spot ditemukan, senjata perbaikan pertama kita di chapter berikutnya adalah vectorization.