Profiling Laravel

Optimasi tanpa pengukuran adalah judi: kita menghabiskan waktu mempercepat query yang hanya menyumbang 1% waktu response, sambil melewatkan loop yang memakan 80%. Profiling adalah kebalikannya — memotret waktu eksekusi per bagian kode untuk menemukan di mana detik-detik itu benar-benar hilang, sebelum satu baris diubah. Kabar baiknya, 80% kebutuhan profiling Laravel tidak butuh alat mewah: hrtime() bawaan PHP dan DB::listen() sudah cukup untuk menemukan tersangka. Alat ekosistem melengkapi sisanya ketika penyelidikan menjadi serius.

Remah Waktu: Profiler Sederhana #

Profiling sederhana berarti mencatat timestamp di beberapa titik eksekusi — remah rot (breadcrumb) yang menunjukkan jarak antar tahap. Class kecil ini cukup untuk itu:

class Profil
{
    private array $tahap = [];
    private float $mulai;

    public function __construct()
    {
        $this->mulai = hrtime(true);
    }

    public function tandai(string $nama): void
    {
        $this->tahap[] = [$nama, (hrtime(true) - $this->mulai) / 1e6];
    }

    public function laporan(): string
    {
        $total = (hrtime(true) - $this->mulai) / 1e6;
        $hasil = '';
        $sebelum = 0.0;
        foreach ($this->tahap as [$nama, $ms]) {
            $hasil .= sprintf("%-24s %8.2f ms\n", $nama, $ms - $sebelum);
            $sebelum = $ms;
        }
        return $hasil.sprintf("%-24s %8.2f ms\n", 'TOTAL', $total);
    }
}

Method tandai() menyimpan waktu absolut sejak mulai; laporan() mengurangkan penanda sebelumnya sehingga setiap baris menampilkan durasi tahap itu sendiri, bukan waktu kumulatif. Mari kita pakai untuk memotret satu request “halaman daftar” yang realistis:

use App\Models\Post;

$profil = new Profil();

$posts = Post::with(['user', 'category'])->orderBy('id')->limit(100)->get();
$profil->tandai('query 100 post');

$baris = $posts->map(fn ($p) => [
    'judul' => $p->judul,
    'penulis' => $p->user->name,
    'kategori' => $p->category->nama,
])->all();
$profil->tandai('transformasi koleksi');

$json = json_encode($baris, JSON_PRETTY_PRINT);
$profil->tandai('encode JSON');

echo $profil->laporan();

Output yang Dihasilkan:

query 100 post              19.72 ms
transformasi koleksi         0.83 ms
encode JSON                  0.04 ms
TOTAL                       20.60 ms

Tanpa foto ini, kita mungkin tergoda mengoptimasi json_encode yang hanya 0,04 ms — atau menambahkan cache pada transformasi yang 0,83 ms. Foto ini berkata jelas: 96% waktu ada di query. Arah kerja berikutnya sudah ditentukan data, bukan firasat: periksa query-nya di chapter-chapter sebelumnya (kolom? index? jumlah query?).

DB::listen() sebagai Query Profiler #

Untuk tersangka database, DB::listen() memberi waktu per query. Karena listener dipasang setelah kode lain berjalan, kita bisa menyalakannya hanya pada tiga query yang dicurigai:

use App\Models\Post;
use Illuminate\Support\Facades\DB;

DB::listen(function ($q) use (&$logQuery) {
    $logQuery[] = [$q->time, $q->sql];
});

Post::where('published', true)->count();
Post::where('views', '>', 9000)->count();
Post::where('judul', 'like', '%05000%')->count();

foreach ($logQuery as [$ms, $sql]) {
    echo sprintf("[%6.2f ms] %s\n", $ms, substr($sql, 0, 72));
}

Output yang Dihasilkan:

[  7.18 ms] select count(*) as "aggregate" from "posts" where "published" = ?
[ 15.93 ms] select count(*) as "aggregate" from "posts" where "views" > ?
[  1.02 ms] select count(*) as "aggregate" from "posts" where "judul" like ?

Tiga query count(*) di tabel yang sama ternyata berharga sangat berbeda: 7,18 ms, 15,93 ms, dan 1,02 ms. Angka-angka ini menunjuk pada perbedaan yang tidak terlihat dari SQL mentahnya — dan di sinilah profiler menahan kita dari kesimpulan salah. Threshold sederhana juga bisa dijadikan slow-query logger yang hanya berteriak pada query di atas ambang:

[SLOW  50.85 ms] select * from "posts"

Logger seperti ini layak dipasang di lingkungan staging dan produksi (menulis ke log, bukan echo), karena query lambat cenderung hanya muncul pada data dan trafik nyata.

Ekosistem Alat Profiling #

Ketika breadcrumb manual tidak lagi cukup, ekosistem menawarkan tangga yang bertingkat:

Debugbar dan Telescope dibangun di atas mekanisme yang sama seperti yang kita tulis tangan di atas — DB::listen, event lifecycle — hanya dibungkus UI dan penyimpanan. Xdebug bekerja di lapisan berbeda: profile mode mencatat setiap pemanggilan fungsi lengkap dengan durasinya, lalu berkas cachegrind dianalisis untuk menemukan fungsi terboros. Kekuatannya total; harga bayarannya adalah aplikasi yang berjalan beberapa kali lebih lambat selama profiling.

Kapan Profiling Dilakukan #

Aturan section ini berbunyi: setiap klaim optimasi harus didahului angka — dan profil adalah alat mengambil angkanya. Ritual minimalnya tiga foto: profil sebelum perubahan, perubahan diterapkan, profil sesudah di data dan lingkungan yang sama. Tanpa foto “sebelum”, kita tidak akan pernah tahu apakah kerja kita berhasil atau hanya terasa berhasil.

Di produksi, profil menyala dengan hemat. Profiler penuh di setiap request membebani pengguna yang justru sedang dilayani — karena itu Telescope biasanya dibatasi di staging, dan profiling request nyata memakai pendekatan sampling: hanya sebagian kecil request (misalnya 1 dari 100) yang difoto, atau hanya request yang melewati ambang lambat. Kompromi ini menjaga pengukuran tetap hidup tanpa menjadikan alat ukurnya beban baru.

Profil memberi kita angka; pertanyaan terakhirnya adalah menjaga angka itu dari waktu ke waktu — apakah 20,6 ms hari ini masih 20,6 ms minggu depan setelah fitur baru menyusul. Pekerjaan itu milik pengujian: performance testing yang menjadikan kecepatan sebagai asersi, bukan harapan.