Rutin Cek PHP-FPM Slow Log untuk Menemukan Script yang Bikin Worker Macet

Situs mendadak lambat, lalu error log PHP-FPM menampilkan server reached pm.max_children setting. Biasanya reaksi pertama adalah menaikkan pm.max_children. Masalahnya, pesan itu hanya memberi tahu bahwa worker sudah habis, bukan apa yang membuat worker habis. Kalau ada script yang menahan worker belasan detik, misalnya karena menunggu API eksternal, menambah worker cuma memperpanjang antrean. Tempat untuk mencari tahu script mana yang macet, sampai ke baris kodenya, adalah slow log PHP-FPM.

Kenapa error log saja tidak cukup

Worker PHP-FPM adalah proses yang mengerjakan satu request PHP dalam satu waktu. Selama request itu belum selesai, worker tersebut tidak bisa melayani request lain. Saat semua worker sedang sibuk, request baru masuk ke antrean. Kalau antreannya terlalu lama, web server di depannya (Nginx, Apache, atau LiteSpeed) akhirnya mengembalikan 502 atau 504. Error log PHP-FPM mencatat kejadian di level proses: worker dibuat, worker mati, batas max_children tercapai. Isi request tidak dicatat di sana. Access log web server memang menunjukkan URL mana yang lambat, tapi untuk WordPress atau framework modern, URL lambat itu bisa melewati puluhan plugin dan library sebelum sampai ke bagian yang sebenarnya lambat. Ada dua hal yang sering mengecoh. Pertama, CPU terlihat santai padahal worker penuh. Ini justru petunjuk bahwa worker sedang menunggu, entah respons HTTP dari luar, query database, atau lock file. Worker yang menunggu tidak memakai CPU, tapi tetap terpakai. Kedua, max_execution_time sudah diset tapi script tetap berjalan lebih lama dari batas itu. Di Linux, waktu yang dihabiskan untuk stream, query database, dan system call tidak dihitung oleh max_execution_time, jadi script yang menunggu curl bisa lolos dari batas tersebut. Di meja support, pola ini cukup sering muncul. Customer melapor situsnya lemot, resource server terlihat normal, dan tidak ada error yang jelas. Slow log biasanya jadi cara paling cepat untuk mengubah keluhan "situs lambat" menjadi "plugin X menunggu API Y di file Z baris 88".

Mengaktifkan slow log di pool PHP-FPM

Slow log diatur per pool. Tiap pool punya file konfigurasi sendiri, misalnya www.conf di direktori pool.d atau php-fpm.d, tergantung distro dan versi PHP. Dua direktif utamanya adalah slowlog (lokasi file log) dan request_slowlog_timeout (berapa lama request boleh berjalan sebelum stack trace-nya dicatat). Default request_slowlog_timeout adalah 0, artinya fitur ini mati.

INI

; Di file konfigurasi pool, contoh: www.conf
slowlog = /var/log/php-fpm/www-slow.log
request_slowlog_timeout = 5s

; Opsional, hanya di versi PHP yang mendukung.
; Jumlah frame stack trace yang dicatat per entri.
request_slowlog_trace_depth = 20

Path di atas hanya contoh. Pastikan direktorinya sudah ada. Proses master PHP-FPM yang menulis slow log, jadi biasanya izin user pool tidak jadi masalah. Untuk ambang waktu, aku biasanya mulai dari 3 sampai 5 detik untuk situs biasa. Ini rule of thumb, bukan angka resmi. Kalau terlalu rendah, log penuh dengan request yang memang wajar berat seperti export laporan. Kalau terlalu tinggi, request yang menahan worker selama 4 detik tidak tercatat, padahal dengan trafik yang cukup, durasi seperti itu sudah bisa menghabiskan worker. Satu hal yang wajib: nilainya harus lebih kecil dari request_terminate_timeout, kalau direktif itu dipakai. Kalau tidak, worker keburu dibunuh sebelum stack trace-nya sempat dicatat. Setelah mengedit, cek syntax dulu dengan menjalankan binary PHP-FPM memakai opsi -t. Nama binary-nya bisa php-fpm atau php-fpm8.x, tergantung instalasi. Lalu lakukan reload pada service, bukan restart, supaya request yang sedang berjalan tidak terputus. Ada dua catatan sesuai lingkungan. Di server cPanel, konfigurasi pool dibuat oleh panel, jadi edit manual di file pool bisa tertimpa. Cek cara resmi mengubah direktif FPM di WHM versi yang dipakai. Di dalam container, PHP-FPM membaca stack trace worker lewat ptrace. Kalau ptrace dibatasi, slow log bisa kosong dan error log berisi pesan gagal ptrace.

Membaca stack trace di slow log

Setiap kali request melewati ambang waktu, error log PHP-FPM mencatat peringatan berisi frasa executing too slow, dan slow log mencatat stack trace lengkapnya. Bentuknya kurang lebih seperti ini. Contoh format output (path dan nama plugin fiktif):

TEXT

[01-Jan-2026 10:00:00]  [pool www] pid 21873
script_filename = /var/www/example/public/index.php
[0x00007f3a1c2152d0] curl_exec() /var/www/example/public/wp-content/plugins/contoh-plugin/lib/Client.php:120
[0x00007f3a1c215180] send() /var/www/example/public/wp-content/plugins/contoh-plugin/lib/Client.php:64
[0x00007f3a1c214f20] sync_stock() /var/www/example/public/wp-content/plugins/contoh-plugin/inc/sync.php:88
[0x00007f3a1c214d10] do_action() /var/www/example/public/wp-includes/plugin.php:517

Baca dari atas. Frame paling atas adalah fungsi yang sedang dijalankan worker tepat saat ambang waktu terlewati, dalam contoh ini curl_exec(). Frame di bawahnya adalah fungsi yang memanggilnya, dan seterusnya sampai titik masuk. Jadi contoh di atas berarti fungsi sinkronisasi stok di plugin sedang menunggu respons HTTP dari luar. Ada satu jebakan di sini. Untuk WordPress, script_filename hampir selalu index.php, karena hampir semua request masuk lewat file itu. Baris itu nyaris tidak membantu. Informasi yang berguna ada di frame-frame di bawahnya, terutama path yang mengandung wp-content/plugins/ atau wp-content/themes/. Frame teratas biasanya masuk ke salah satu pola berikut. Kalau isinya curl_exec(), file_get_contents(), atau fungsi stream lain, worker sedang menunggu layanan luar. Perbaikannya biasanya memasang timeout yang masuk akal di kode, atau memindahkan panggilan itu ke background job. Kalau isinya mysqli_query() atau PDOStatement->execute(), masalahnya ada di sisi database, jadi lanjutkan ke slow query log MySQL untuk query yang sama. Kalau isinya session_start(), kemungkinan request dari user yang sama sedang antre menunggu lock file session. Kalau isinya sleep() atau usleep(), ada kode yang memang sengaja menunggu, misalnya retry loop. Satu entri berarti satu snapshot. Kamu melihat posisi worker pada detik ke-5, bukan total waktu request. Request yang tercatat bisa saja selesai di detik ke-6 atau tertahan sampai detik ke-60. Untuk tahu durasi sebenarnya, cocokkan pid dan waktunya dengan access log atau peringatan executing too slow di error log.

Memisahkan pola dari kejadian sesekali

Satu entri slow log belum berarti ada masalah. Jaringan bisa tersendat sesaat, atau backup database sedang jalan. Yang perlu dicari adalah frame yang muncul berulang. Perintah di bawah ini read-only dan bisa langsung dipakai. Sesuaikan path log dengan servermu.

BASH

# Jumlah request lambat per pool, dari error log PHP-FPM
grep -c 'executing too slow' /var/log/php-fpm/error.log

# Fungsi di frame teratas yang paling sering muncul
grep -A1 'script_filename' /var/log/php-fpm/www-slow.log | grep '^\[0x' | awk '{print $2}' | sort | uniq -c | sort -rn | head

# File plugin atau theme yang paling sering muncul di stack trace
grep -o 'wp-content/[a-z]*/[^/]*' /var/log/php-fpm/www-slow.log | sort | uniq -c | sort -rn | head

Perintah kedua mengambil baris tepat setelah script_filename, yaitu frame teratas, lalu menghitung fungsi yang paling sering muncul. Perintah ketiga menghitung plugin atau theme yang paling sering ikut di stack trace. Kalau satu plugin muncul di sebagian besar entri, itu kandidat kuat. Tetap ingat bahwa plugin yang sering muncul di frame bawah bisa jadi hanya pemanggil, bukan bagian yang lambat. Cocokkan juga waktu entri dengan jadwal lain di server. Entri yang menumpuk di jam yang sama setiap hari sering berkaitan dengan cron, backup, atau sinkronisasi terjadwal. Entri yang tersebar merata lebih mungkin berasal dari kode yang berjalan di setiap page load. Kalau temuannya perlu dibawa ke developer atau tim engineering, sertakan potongan stack trace, rentang waktu, dan jumlah kemunculannya. Info apa saja yang perlu disiapkan sudah dibahas di Memilih Info Apa yang Wajib Ada Sebelum Eskalasi Tiket ke Tim Engineering.

Menjadikannya cek rutin, bukan cuma saat insiden

Slow log paling berguna kalau sudah aktif sebelum ada keluhan. Saat situs sudah down, kita butuh data dari jam-jam sebelumnya, dan kalau slow log baru dinyalakan saat itu, datanya belum ada. Overhead-nya kecil karena stack trace hanya diambil untuk request yang melewati ambang, jadi biasanya aman dibiarkan menyala di production. Ritme yang masuk akal: jalankan perintah agregasi di atas seminggu sekali, dan setiap kali selesai update plugin, theme, atau deploy kode baru. Plugin yang baru diupdate lalu tiba-tiba memanggil API eksternal di setiap page load akan langsung terlihat di sini, jauh sebelum worker penuh di jam ramai. Kalau halaman status PHP-FPM (pm.status_path) sudah aktif, field slow requests di sana bisa jadi indikator cepat. Kalau angkanya naik tajam dibanding minggu lalu, saatnya membuka slow log. Jangan lupa memasukkan file slow log ke konfigurasi logrotate. Dengan ambang yang rendah dan trafik yang tinggi, file ini bisa membesar dengan cepat. Satu lagi, kalau kamu menurunkan ambang ke 1 atau 2 detik untuk investigasi, kembalikan ke nilai semula setelah selesai. Intinya, saat worker PHP-FPM penuh, pertanyaan pertama bukan berapa worker yang perlu ditambah, tapi apa yang sedang ditunggu worker yang ada. Aktifkan request_slowlog_timeout di setiap pool, baca frame teratas di slow log, abaikan script_filename yang cuma berisi index.php, dan cari pola yang berulang. Kalau ini jadi kebiasaan mingguan, script yang menahan worker biasanya sudah ketahuan sebelum customer sempat mengeluh.