Profiling PHP

Benchmark memberi kita satu angka: “permintaan ini selesai dalam 120 milidetik”. Angka itu tidak mengatakan bagian mana dari 120 milidetik tersebut yang bisa dipangkas, dan memangkas di tempat yang salah hanya membuang waktu. Profiling menjawab pertanyaan yang berbeda: ke mana waktu permintaan benar-benar pergi? Pada chapter ini kita membangun profiler sederhana dengan hrtime(), menggabungkannya dengan penghitung panggilan, lalu melihat bagaimana alat seperti Xdebug mengotomatiskan pekerjaan yang sama untuk seluruh aplikasi.

Profiling Menjawab “Ke Mana Waktu Pergi” #

Benchmarking dan profiling adalah pasangan yang saling melengkapi, bukan pesaing. Benchmark mengukur total dari luar dan ideal untuk membandingkan dua implementasi; profil membedah total dari dalam dan ideal untuk menemukan sasaran. Tabel berikut merangkum perbedaan keduanya:

Satu hal yang perlu diingat: profil menunjukkan lokasi pemborosan waktu, bukan penyebabnya. Profil yang menyebut panggilQueryLaporan() sebagai fungsi terpanas baru mengarahkan kita ke file yang tepat; setelah itu kita masih perlu membaca kodenya untuk menemukan query yang hilang indeksnya.

Timer Manual dengan hrtime #

Fungsi hrtime(true) mengembalikan waktu saat ini sebagai integer nanodetik yang dihitung dari jam monotonic — jam yang hanya bergerak maju dan tidak terpengaruh sinkronisasi jam sistem. Ini menjadikannya pilihan yang lebih aman daripada microtime(true), yang bisa “melompat” ketika sistem menyesuaikan jamnya di tengah pengukuran. Mari kita buktikan dua sifat dasarnya:

<?php
$mulai = hrtime(true);
usleep(1000);
$durasi = hrtime(true) - $mulai;

echo "Nilai hrtime(true) adalah integer: ";
var_dump(is_int($durasi));
echo "Durasi tidur minimal 1 ms (1.000.000 nanodetik): ";
var_dump($durasi >= 1_000_000);

Output yang Dihasilkan:

Nilai hrtime(true) adalah integer: bool(true)
Durasi tidur minimal 1 ms (1.000.000 nanodetik): bool(true)

Baris 2 dan 4 mengambil dua titik waktu, lalu baris 4 menguranginya menjadi durasi integer dalam nanodetik. usleep(1000) pada baris 3 menidurkan proses selama minimal 1.000 mikrodetik, sehingga durasi yang terukur dijamin minimal 1.000.000 nanodetik — dan itulah fakta struktural yang kita cetak pada baris 8-9, bukan angka absolutnya yang berubah-ubah antar mesin.

Memprofil Tahap demi Tahap #

Cara profiling paling sederhana adalah membungkus setiap tahap permintaan dengan sepasang panggilan hrtime(true). Simulasi berikut meniru tiga tahap khas aplikasi web dengan beban kerja yang jauh berbeda, lalu mengurutkan hasilnya:

<?php
$waktuTahap = [];

$mulai = hrtime(true);
$total = 0;
for ($i = 0; $i < 100000; $i++) {
    $total += $i % 7;
}
$waktuTahap["validasi input"] = hrtime(true) - $mulai;

$mulai = hrtime(true);
$total = 0;
for ($i = 0; $i < 1000000; $i++) {
    $total += $i % 7;
}
$waktuTahap["query laporan"] = hrtime(true) - $mulai;

$mulai = hrtime(true);
$total = 0;
for ($i = 0; $i < 10000; $i++) {
    $total += $i % 7;
}
$waktuTahap["render template"] = hrtime(true) - $mulai;

arsort($waktuTahap);

echo "Urutan tahap dari yang paling memakan waktu:\n";
$peringkat = 1;
foreach ($waktuTahap as $tahap => $nanodetik) {
    echo $peringkat . ". " . $tahap . "\n";
    $peringkat++;
}

Output yang Dihasilkan:

Urutan tahap dari yang paling memakan waktu:
1. query laporan
2. validasi input
3. render template

Mari kita bedah kode di atas:

1. Baris 4-9: tahap “validasi input” disimulasikan dengan perulangan 100.000 iterasi; hrtime(true) diambil sebelum dan sesudahnya, selisihnya disimpan ke array $waktuTahap dengan nama tahap sebagai kunci.
2. Baris 11-16 dan 18-23: tahap “query laporan” (1.000.000 iterasi) dan “render template” (10.000 iterasi) diukur dengan pola yang sama — pada aplikasi nyata, isinya adalah query database dan pemanggilan template sungguhan.
3. Baris 25: arsort() mengurutkan array dari nilai terbesar, sehingga tahap termahal berada di posisi pertama.
4. Baris 27-32: laporan hanya mencetak urutan dan nama tahap. Di laporan internal tim Anda, mencetak persentase juga lazim; kita mencetak urutan saja karena persentase persisnya bergeser sedikit antar eksekusi, sedangkan urutannya stabil.

Hasilnya jelas: “query laporan” adalah tahap panas yang layak disoroti lebih dulu sebelum menyentuh “render template”.

Menggabungkan Timer dengan Penghitung Panggilan #

Waktu total sebuah fungsi adalah hasil kali jumlah pemanggilan dengan waktu per pemanggilan. Karena itu timer saja belum cukup: fungsi yang dipanggil 1.000 kali dengan 0,1 milidetik per panggilan lebih mahal daripada fungsi yang dipanggil sekali selama 10 milidetik. Class berikut menggabungkan kedua metrik menjadi satu profiler manual yang siap dipakai:

<?php
class ProfilerManual
{
    private array $totalNanodetik = [];
    private array $jumlahPanggilan = [];

    public function ukur(string $nama, callable $fungsi): mixed
    {
        $mulai = hrtime(true);
        try {
            return $fungsi();
        } finally {
            $this->totalNanodetik[$nama] =
                ($this->totalNanodetik[$nama] ?? 0) + (hrtime(true) - $mulai);
            $this->jumlahPanggilan[$nama] =
                ($this->jumlahPanggilan[$nama] ?? 0) + 1;
        }
    }

    public function laporanUrutan(): array
    {
        $total = $this->totalNanodetik;
        arsort($total);
        $baris = [];
        $peringkat = 1;
        foreach ($total as $nama => $nanodetik) {
            $baris[] = sprintf(
                "%d. %s (%d panggilan)",
                $peringkat,
                $nama,
                $this->jumlahPanggilan[$nama]
            );
            $peringkat++;
        }
        return $baris;
    }
}

$profiler = new ProfilerManual();

$kerjakan = function (int $jumlahIterasi): int {
    $total = 0;
    for ($i = 0; $i < $jumlahIterasi; $i++) {
        $total += $i % 5;
    }
    return $total;
};

$profiler->ukur("muat data laporan", fn () => $kerjakan(1500000));
$profiler->ukur("muat data laporan", fn () => $kerjakan(1500000));
$profiler->ukur("render template", fn () => $kerjakan(150000));

echo "Profil panggilan (diurutkan dari waktu total terbesar):\n";
foreach ($profiler->laporanUrutan() as $baris) {
    echo $baris, "\n";
}

Output yang Dihasilkan:

Profil panggilan (diurutkan dari waktu total terbesar):
1. muat data laporan (2 panggilan)
2. render template (1 panggilan)

Beberapa keputusan desain pada class ini layak diperhatikan:

1. Method ukur() (baris 7-18): menerima nama bagian dan sebuah callable, mencatat hrtime(true) sebelum menjalankannya, lalu mengembalikan hasil callable apa adanya. Blok try/finally memastikan pencatatan waktu tetap terjadi meskipun callable melempar exception — instrumen yang hilang tepat saat terjadi error justru menyesatkan.
2. Akumulasi dengan ?? 0 (baris 13-16): pemanggilan kedua untuk nama yang sama menambahkan durasinya ke total, bukan menimpa — begitu pula dengan penghitung jumlahPanggilan.
3. Method laporanUrutan() (baris 20-36): mengurutkan total waktu terbesar lebih dulu, lalu memformat setiap baris berisi peringkat, nama, dan jumlah panggilan — angka nanodetiknya sengaja tidak dicetak.
4. Pemakaian (baris 39-52): “muat data laporan” diukur dua kali dengan beban besar, “render template” sekali dengan beban kecil. Laporan menempatkan “muat data laporan” di peringkat pertama dengan 2 panggilan — persis informasi yang dibutuhkan untuk memutuskan sasaran optimasi berikutnya.

Profiling dengan Xdebug #

Untuk memprofil seluruh aplikasi tanpa menulis instrumen manual, alat standar de facto adalah ekstensi Xdebug. Saat mode profile aktif, Xdebug merekam setiap pemanggilan fungsi beserta durasinya, lalu menuliskannya ke berkas berformat Cachegrind per permintaan. Konfigurasinya berada di php.ini atau konfigurasi pool FPM:

; aktifkan mode profil Xdebug
zend_extension = xdebug.so
xdebug.mode = profile
xdebug.output_dir = /tmp/profil
xdebug.start_with_request = yes

Setiap permintaan yang diprofil menghasilkan satu berkas seperti cachegrind.out.12345 (angka di akhir adalah PID proses). Isinya berbentuk teks yang ringkas:

events: Time

fl=/var/www/app/LaporanController.php
fn=panggilQueryLaporan
42 4820
cfl=php:internal
cfn=pdo::query
43 4710

fl=/var/www/app/LaporanController.php
fn=renderTemplate
58 940

Setiap pasangan fl/fn menyatakan berkas dan fungsi, angka pertama pada baris biaya adalah nomor baris kode, dan angka kedua adalah biaya waktunya sesuai satuan yang dinyatakan di kepala berkas; cfl/cfn menunjukkan fungsi yang dipanggil dari sana. Anda tidak perlu membaca format ini secara manual — KCacheGrind atau QCachegrind (aplikasi desktop) serta webgrind (berbasis browser) mengubahnya menjadi pohon panggilan interaktif lengkap dengan persentase waktu.

Membaca Hasil Profil #

Berapapun canggihnya alatnya, cara membaca hasilnya sama. Fokus pada dua istilah berikut:

Prosedurnya: urutkan berdasarkan self time untuk menemukan fungsi yang tubuh kodenya sendiri mahal, gunakan inclusive time untuk melihat rantai panggilan yang menumpuk biaya, lalu perbaiki dua sampai tiga teratas — bukan sepuluh sekaligus. Setelah setiap perubahan, profil ulang dan bandingkan; porsi waktu berpindah tempat setelah tiap perbaikan, jadi daftar prioritas lama tidak berlaku lagi.

Ekosistem Alat Profil #

Di luar timer manual dan Xdebug, ekosistem PHP memiliki beberapa alat profil yang mapan. Blackfire dari SensioLabs mengambil pendekatan komersial: sebuah agen mengumpulkan profil tanpa perubahan kode, menampilkannya sebagai call graph di browser, dan dapat membandingkan dua profil atau menjalankan assertion performa di CI. Laravel menyediakan Telescope untuk membedah permintaan, query, dan job pada saat pengembangan, sementara Symfony memiliki Web Profiler dengan timeline per permintaan. Untuk kasus yang hanya butuh satu angka pembanding — bukan peta waktu — kita cukup memakai harness benchmark yang akan dibangun pada chapter berikutnya.

Ringkasan #

Profiling menjawab ke mana waktu permintaan pergi, dan kita bisa memulainya tanpa alat apa pun: bungkus tahap dengan hrtime(true), akumulasikan durasi, hitung jumlah panggilan, lalu urutkan. Xdebug mengotomatiskan pengukuran ini untuk seluruh aplikasi lewat berkas Cachegrind, dan alat seperti Blackfire atau profiler framework membantu pada skala lebih besar. Setelah profil menunjukkan sasaran, langkah berikutnya adalah membuktikan bahwa perbaikan kita benar-benar lebih cepat — tugas chapter Benchmarking.

Referensi #

• PHP: hrtime — jam monotonic beresolusi tinggi yang menjadi dasar semua pengukuran di chapter ini.
• Xdebug: Profiler — dokumentasi resmi mode profil, format Cachegrind, dan pemicuannya.