Profiling dengan cProfile

Program kita lambat — tetapi lambat di baris yang mana? Menebak-nebak tempat yang perlu dioptimasi hampir selalu salah sasaran, karena intuisi programmer terbukti buruk dalam menebak hotspot. Profiling adalah tindakan mengukur berapa lama setiap function berjalan, dan Python sudah membawa alatnya di standard library: module cProfile. Pada Chapter ini kita akan memprofil program nyata, membaca tabel hasilnya, dan mengenali kapan angkanya bisa menyesatkan.

Menjalankan cProfile dari Terminal #

Cara termudah adalah menjalankan program lewat cProfile sebagai module. Simpan dulu program uji berikut sebagai profil_demo.py — program kecil pengolah transaksi dengan satu bagian yang sengaja boros:

def muat_data(jumlah):
    """Membuat daftar transaksi sebagai pasangan (id, nilai)."""
    data = []
    for i in range(jumlah):
        data.append((i, (i * 37) % 1000))
    return data


def hitung_total(data):
    total = 0
    for _, nilai in data:
        total += nilai
    return total


def cari_transaksi_mahal(data, batas):
    hasil = []
    for _, nilai in data:
        if nilai > batas:
            hasil.append(nilai)
    return hasil


def analisis_boros(data):
    # Hotspot: membership check terhadap list di dalam loop = O(n^2)
    nilai_semua = [nilai for _, nilai in data]
    mahal = []
    for _, nilai in data:
        if nilai in nilai_semua[:500]:  # memotong list di setiap iterasi
            mahal.append(nilai)
    return mahal


if __name__ == "__main__":
    transaksi = muat_data(5_000)
    print("total       :", hitung_total(transaksi))
    print("mahal       :", len(cari_transaksi_mahal(transaksi, 900)))
    print("analisis    :", len(analisis_boros(transaksi)))

Lalu jalankan dengan opsi -s cumulative agar baris diurutkan berdasarkan waktu total termasuk panggilan turunannya:

python3 -m cProfile -s cumulative profil_demo.py

Output yang Dihasilkan (waktu bergantung pada mesin):

total       : 2497500
mahal       : 495
analisis    : 2500
         8007 function calls in 0.030 seconds

   Ordered by: cumulative time

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        1    0.000    0.000    0.030    0.030 {built-in method builtins.exec}
        1    0.000    0.000    0.030    0.030 profil_demo.py:1(<module>)
        1    0.025    0.025    0.025    0.025 profil_demo.py:24(analisis_boros)
        1    0.003    0.003    0.004    0.004 profil_demo.py:1(muat_data)
     7995    0.001    0.000    0.001    0.000 {method 'append' of 'list' objects}
        1    0.000    0.000    0.000    0.000 profil_demo.py:16(cari_transaksi_mahal)
        1    0.000    0.000    0.000    0.000 profil_demo.py:9(hitung_total)
        3    0.000    0.000    0.000    0.000 {built-in method builtins.print}
        1    0.000    0.000    0.000    0.000 {method 'disable' of '_lsprof.Profiler' objects}
        2    0.000    0.000    0.000    0.000 {built-in method builtins.len}

Membaca Tabel Profil #

Empat kolom angka di tabel ini adalah seluruh bahasa yang perlu kita kuasai:

Menerapkan tabel pada output di atas: keseluruhan program berjalan 0,030 detik, dan analisis_boros menyumbang 0,025 detik — sekitar 83% waktu program ada di satu function saja. Baris {method 'append' of 'list' objects} dengan ncalls 7995 menunjukkan biaya append() tersebar di banyak function (5.000 dari muat_data, sisanya dari dua function lain), tetapi totalnya hanya 0,001 detik — jelas bukan prioritas. Inilah pola klasik membaca profil: carilah satu-dua baris dengan tottime atau cumtime terbesar, abaikan sisanya.

Perbedaan tottime dan cumtime juga langsung kelihatan: muat_data memiliki tottime 0,003 tetapi cumtime 0,004 — selisihnya adalah waktu append() yang dipanggil dari dalamnya.

Menyimpan dan Menganalisis dengan pstats #

Menjalankan profil sekali lalu membaca di terminal itu cepat, tetapi untuk analisis berulang lebih nyaman menyimpan hasilnya ke file dengan opsi -o, lalu mengolahnya lewat module pstats:

python3 -m cProfile -o profil.pstats profil_demo.py

import pstats

statistik = pstats.Stats("profil.pstats")
statistik.strip_dirs()
statistik.sort_stats("cumulative")
statistik.print_stats("profil_demo", 4)

Output yang Dihasilkan (baris pertama berisi tanggal pembuatan file, nilainya berbeda setiap dijalankan):

Mon Oct 12 22:31:19 2026    profil.pstats

         8007 function calls in 0.028 seconds

   Ordered by: cumulative time
   List reduced from 10 to 5 due to restriction <'profil_demo'>
   List reduced from 5 to 4 due to restriction <4>

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        1    0.000    0.000    0.028    0.028 profil_demo.py:1(<module>)
        1    0.025    0.025    0.025    0.025 profil_demo.py:24(analisis_boros)
        1    0.002    0.002    0.002    0.002 profil_demo.py:1(muat_data)
        1    0.000    0.000    0.000    0.000 profil_demo.py:16(cari_transaksi_mahal)

Mari kita telaah pemakaian pstats di atas:

1. Baris 1 (pstats.Stats("profil.pstats")): membaca file statistik yang ditulis opsi -o.
2. Baris 2 (strip_dirs()): merapikan tampilan dengan membuang direktori dari path file.
3. Baris 3 (sort_stats("cumulative")): mengurutkan berdasarkan cumtime — sama seperti -s cumulative di terminal.
4. Baris 4 (print_stats("profil_demo", 4)): memfilter hanya baris yang mengandung teks profil_demo, lalu membatasi 4 baris teratas.

Kapan cProfile Menyesatkan #

cProfile mengukur wall-clock time — durasi nyata, bukan waktu CPU. Akibatnya ada dua jebakan klasik. Pertama, function yang dominan menunggu terlihat aneh: tottime-nya kecil padahal cumtime-nya besar, karena penantian jaringan, disk, atau time.sleep() tercatat di built-in seperti {built-in method time.sleep} atau di dalam extension C yang tidak dibedah. Kedua, overhead cProfile sendiri (sekitar mikrosekon per panggilan) menggelembi angka function yang sangat cepat dan dipanggil jutaan kali — untuk mengukur kecepatan satu operasi kecil, gunakan timeit seperti pada Chapter Benchmarking, bukan cProfile.

Untuk program produksi yang tidak boleh dihentikan, alat sampling seperti py-spy dapat memprofil proses Python yang sedang berjalan tanpa mengubah kode — cukup dikenal sebagai standar praktis ketika profiling dari dalam program sudah tidak memungkinkan.