PHP-FPM Slowlog richtig auswerten: Performance-Bottlenecks sicher finden

Ich zeige dir, wie du den PHP-FPM Slowlog zielgerichtet ausliest, die Backtraces richtig deutest und daraus klare Schritte für weniger Latenz ableitest. So findest du Performance-Bottlenecks zuverlässig, priorisierst Maßnahmen und machst Ladezeiten für Nutzer spürbar schneller.

Zentrale Punkte

• Backtrace lesen: Frame #0 zeigt den aktuellen Bremsklotz.
• Timeout wählen: erst hoch starten, dann schrittweise senken.
• Korrelation mit Access-Log: langsame URLs sicher zuordnen.
• Muster zählen: wiederkehrende Funktionen priorisieren.
• Code-Fixes ableiten: DB, APIs, Loops, Plugins gezielt anpacken.

Was ist der PHP-FPM Slowlog?

Der Slowlog schreibt für lange Requests einen Backtrace in eine Logdatei und hält so den aktuellen Ausführungspunkt fest, ohne die Anfrage zu beenden. Ich erkenne daran sofort, welches Skript, welche URL und welche Funktion den Weg blockiert. Die Einträge enthalten Zeitstempel, Pool, Script-Filename, Request-URI und die Kette der Funktionsaufrufe. Dadurch unterscheidet sich der Slowlog klar von klassischen Fehlerlogs, denn er dokumentiert Performance, nicht Fehler. Für stark ausgelastete Seiten wie WordPress-Backends liefert er schnell verwertbare Hinweise auf teure Abfragen, ausladendes Rendering oder blockierende I/O-Operationen. Wer diese Momentaufnahmen versteht, kann sehr schnell die Hauptursache eingrenzen und Maßnahmen planen.

So arbeitet der Slowlog im Alltag

Nach dem Aktivieren schreibt PHP-FPM bei Überschreiten einer definierten Schwelle einen Snapshot des Stacks ins Log, während der Request weiterläuft. Jeder Eintrag startet typischerweise bei „#0“, also an der Stelle, an der gerade Zeit verloren geht. Zwischen den Blöcken erkenne ich häufig Leerzeilen, was das Trennen der Ereignisse vereinfacht. Die Methode liefert Stichproben statt Vollprofilen, dafür treffsichere Hinweise auf echte Bremsen wie aufwendige Template-Pfade, verwaiste Hooks oder träge Netzwerkaufrufe. In stark frequentierten Phasen verknüpfe ich diese Hinweise mit Lastspitzen und ordne dadurch Code-Abschnitte sauber ein. Sobald ich wiederkehrende Muster sehe, passe ich beispielsweise pm.max_children an und nutze dafür die Infos aus pm.max_children richtig einstellen.

Slowlog aktivieren und konfigurieren

Ich schalte die Funktion im jeweiligen Pool ein und lege Pfad, Timeout und Tiefe des Traces fest, damit die Auswertung handhabbar bleibt. Danach lade ich PHP-FPM neu und prüfe, ob die Logdatei mit den Rechten des Pool-Users beschreibbar ist. Als Startwert setze ich oft 5 Sekunden, um erst grobe Ausreißer zu fangen, ohne das System mit Logdaten zu fluten. Anschließend senke ich den Wert schrittweise, sobald die dicken Brocken erledigt sind. Für überschaubare Logs begrenze ich die Trace-Tiefe auf 20 bis 30 Frames, was in der Praxis meist genügt. So halte ich die Dateigröße im Zaum und verliere keine relevanten Details.

Einstellung	Zweck	Startwert	Hinweise
slowlog	Pfad zur Logdatei	/var/log/php-fpm/www-slow.log	Pfade je nach Distribution prüfen; Schreibrechte für www-data sicherstellen
request_slowlog_timeout	Schwelle für „langsam“	5s	Erst hoch starten, später senken (z. B. 2–3s)
request_slowlog_trace_depth	Max. Tiefe des Backtraces	20–30	Halte Traces lesbar, ohne Kerninfos zu verlieren

Logdatei finden und schnell sichten

Ich prüfe zuerst die konfigurierten Pfade und öffne das Log mit less oder kontrolliere die letzten Zeilen mit tail -40. So sehe ich sofort, ob Einträge ankommen und welche Skripte wiederholt auffallen. Für eine rasche Orientierung achte ich auf Dateinamen, betroffene Pools und auffällige URIs. Finde ich keine Einträge, aktiviere ich die Optionen im Pool, lade den Dienst neu und prüfe Besitzer sowie Rechte. Unter Managed-Umgebungen konsultiere ich zudem das Panel oder die Startskripte, damit der Slowlog wirklich mitläuft.

Blöcke erkennen und Muster zählen

Jeder Eintrag erscheint als Block, häufig getrennt durch eine Leerzeile, was das Zählen erleichtert. Ich orientiere mich an den „#0“-Zeilen, denn sie markieren den aktuellen Ausführungspunkt, an dem Zeit verpufft. Über einfache Shell-Pipelines filtere ich die Top-Funktionen heraus und sehe, welche Stellen am häufigsten ausbremsen. So priorisiere ich gezielt die Funktionen, die in Summe die meiste Zeit kosten. Anschließend prüfe ich, ob diese Hotspots nur zu Lastspitzen auftreten oder durchgängig Probleme machen. Diese Einordnung bestimmt die Reihenfolge meiner Maßnahmen.

Einträge lesen: vom Frame #0 bis zum Einstieg

Beim Lesen der Einträge starte ich oben bei #0 und gehe schrittweise nach unten, um den Weg vom Einstiegspunkt zur aktuellen Stelle zu verstehen. Lange Template-Ketten deuten auf aufwendiges Rendering, viele Hooks auf Plugin-Ballast und hohe SQL-Anteile auf fehlende Indexe. Ich markiere mir Zeilennummern, Funktionsnamen und Dateipfade, damit ich den Code schnell finde. Sieht der Stack nach Warteschleifen oder wiederholten Operationen aus, prüfe ich Zwischenspeicher und Caching. So verliere ich keine Zeit bei der Lokalisierung des Problems im Code.

Slowlog mit Access-Logs korrelieren

Ich verknüpfe den Slowlog mit Webserver-Logs, damit ich die langsamen Requests einer konkreten URL zuordnen kann. Über Zeitstempel und optional PIDs finde ich die passenden Einträge im Nginx- oder Apache-Log. Dadurch erkenne ich Parameter, User-Agents und Antwortzeiten außerhalb von PHP. Zeigen sich wiederkehrende Aufrufer oder identische Query-Strings, starte ich mit genau diesen Szenarien einen Testlauf. So stoße ich zügig auf reproduzierbare Fälle und halte die Analysezeit kurz.

Schwellenwert iterativ senken

Ich starte mit einer großzügigen Schwelle, behebe erst die größten Ausreißer und senke dann in Stufen. Dieser Ablauf reduziert das Logvolumen und lenkt meine Energie auf lohnende Fixes. Nach jeder Optimierungsrunde wähle ich eine niedrigere Schwelle und sammle erneut Datensätze. So arbeite ich mich vom groben Schnitt zum Feintuning vor, ohne mich in Rauschen zu verlieren. Das Ergebnis sind zielgerichtete Anpassungen und eine klare Sicht auf verbleibende Bottlenecks.

Vom Slowlog zur Lösung: typische Fixes

Zeigt der Top-Frame Datenbankfunktionen, prüfe ich die SQLs mit EXPLAIN, setze fehlende Indexe und begrenze Resultsets. Bei entfernten Diensten reduziere ich Timeouts, führe Antworten asynchron weiter oder cache Ergebnisse. Finde ich kostspielige Schleifen, vereinfache ich die Logik, reduziere Durchläufe und setze effizientere Strukturen ein. In WordPress markiere ich wiederkehrende Hooks, tausche schwere Erweiterungen aus und setze auf ein leichteres Theme. Blockiert die PHP-Prozessanzahl die Abarbeitung, behalte ich Wartezeiten im Auge und lese ergänzend zu Backtraces auch Warteschlangen, etwa über PHP-Request-Queueing.

Dauerbetrieb: sauberes Log-Management

Ich drehe das Logging nicht dauerhaft voll auf, damit die I/O-Last beherrschbar bleibt. Stattdessen arbeite ich in Phasen: aktiv auswerten, optimieren, dann wieder auf moderates Niveau gehen. Mit Logrotate halte ich Dateien schlank und archiviere Altdaten komprimiert. Nach Abschluss einer Analyse hebe ich die Schwelle an oder schalte das Slowlogging vorübergehend ab. Zusätzlich dokumentiere ich Erkenntnisse und Fixes, damit spätere Audits eine klare Spur vorfinden.

Hosting-Diagnose: Server gegen Anwendung abgrenzen

Viele identische Slowlog-Frames bei hoher CPU-Last sprechen für Anwendungscode, während fehlende Einträge bei träger Seite eher auf I/O, Netzwerk oder Datenbankserver hindeuten. In solchen Fällen vergleiche ich TTFB, PHP-Zeiten und Upstream-Latenz, um die Engstelle zu lokalisieren. Sehe ich Warteschlangen und hohe Wartezeiten vor Ausführung, prüfe ich Limits und Prozessanzahl. Dazu ergänze ich meine Diagnose mit Informationen zur Abarbeitung von Anfragen und berücksichtige etwaige Limits, die die Verarbeitung verlangsamen. Für eine fundierte Einordnung lese ich ergänzend zu Logs auch Hinweise zu pm.max_children richtig einstellen oder wartezeitenbezogene Artikel, damit ich die Kapazität sinnvoll abstimme.

Praxisbeispiel: langsames WordPress-Backend

Ich setze request_slowlog_timeout zunächst auf 5 Sekunden, lade PHP-FPM neu und sammle 30 bis 60 Minuten Daten unter realer Last. Danach zähle ich die häufigsten „#0“-Funktionen und suche nach wiederkehrenden Hooks oder teuren WP_Query-Aufrufen. Treten externe Dienste auf, messe ich Antwortzeiten und cachte Ergebnisse gezielt. Werden Seitenaufrufe durch Sitzungszugriffe ausgebremst, prüfe ich Locking-Verhalten und verschiebe, wenn möglich, sitzungsrelevante Arbeit aus dem kritischen Pfad. Gerade bei Logins und Admin-Aktionen teste ich Einstellungen und setze Hinweise aus PHP-Session-Locking um, damit mein Backend schneller reagiert.

Pool-Design und Rechte: saubere Basis für verwertbare Slowlogs

Ich trenne Anwendungen in eigene Pools mit klaren Namen (z. B. www, admin, api), setze eindeutige listen-Sockets und individuelle slowlog-Pfade. Damit korreliere ich Einträge leichter und verhindere Vermischungen. Wichtig sind konsistente Dateirechte: Der Pool-User (oft www-data) braucht Schreibrechte am Logpfad und im Verzeichnis. In Container- oder chroot-Setups prüfe ich, ob Pfade im Namespace existieren und persistiert sind – sonst verschwinden Logs beim Neustart.

Ein Slowlog-Block im Detail lesen und maschinell auswerten

Typisch beginnen Einträge mit Zeitstempel, Pool, Script-Filename und Request-URI, gefolgt von den Frames. Ich zähle „#0“-Zeilen und gruppiere nach Funktionsnamen, um Hotspots sichtbar zu machen. Mit einfachen Pipes extrahiere ich die Bremsklötze:

grep -E "^#0|request.uri|script_filename" /var/log/php-fpm/www-slow.log | sed 's/  */ /g'

Oder ich zähle die häufigsten Top-Frames:

grep "^#0" /var/log/php-fpm/www-slow.log | awk -F": " '{print $2}' | awk '{print $1}' | sort | uniq -c | sort -nr | head

Wenn ich URL und Datei mit aufnehmen möchte, bereite ich Blöcke per awk auf und schreibe mir die Top-Kombinationen aus Funktion, URI und Script heraus. So priorisiere ich die Fixes, die am meisten Nutzen bringen.

Timeout-Landkarte: wie Slowlog, PHP und Webserver zusammenspielen

Für eine saubere Diagnose ordne ich alle Timeouts: request_slowlog_timeout löst den Snapshot aus, max_execution_time begrenzt PHP-Laufzeit im Skript, request_terminate_timeout kann den FPM-Worker hart beenden. Auf Webserver-Seite greifen fastcgi– bzw. proxy-Timeouts (z. B. fastcgi_read_timeout) und Client-Timeouts. Setze ich den Slowlog oberhalb der Server-Timeouts, verschenke ich Daten; liegt er darunter, bekomme ich nützliche Snapshots, bevor Requests abreißen. Ich halte die Reihenfolge deshalb bewusst: Webserver-Timeout > PHP-Terminate > Slowlog > Ziel-Latenz.

FPM-Status, Queue und Prozessmanagement einbeziehen

Der Slowlog zeigt, wo Zeit verbrannt wird – der FPM-Status verrät, warum Anfragen warten. Ich aktiviere den Status-Endpunkt, beobachte idle, active und listen queue und vergleiche sie mit den Slowlog-Zeitstempeln. Wächst die Queue, während viele Worker in denselben Funktionen hängen, ist Code der Engpass; steigt die Queue ohne Slowlog-Zuwachs, fehlt Kapazität oder ein Upstream bremst. Darauf aufbauend justiere ich pm-Einstellungen (dynamic/ondemand), pm.max_children und ggf. pm.max_requests, um Memory-Leaks oder Fragmentierung einzufangen.

Besonderheiten in Containern und Managed-Umgebungen

In Docker/Kubernetes loggt FPM oft nach stdout/stderr oder in Pfade, die von Log-Aggregatoren eingesammelt werden. Ich entscheide mich bewusst für einen einen Weg, damit ich keine doppelten oder fehlenden Einträge habe. Mit error_log = /proc/self/fd/2 und einem dedizierten slowlog-Pfad, der in ein persistentes Volume zeigt, bleiben Snapshots verfügbar. In Managed-Setups prüfe ich, ob der Hoster Slowlogs aktiviert oder einschränkt – und passe Intervalle an, damit ich nicht gegen Rotationen laufe.

Datenschutz und Sicherheit: Logs ohne Risiko

Backtraces können sensible Parameter, Dateipfade oder Session-IDs enthalten. Ich minimiere Risiken, indem ich Query-Strings in Access-Logs spare, Debug-Ausgaben im Code deaktiviere und den Kreis der Leseberechtigten klein halte. Für den Austausch mit Dritten anonymisiere ich Pfade und entferne Tokens. In produktiven Umgebungen definiere ich kurze Aufbewahrungsfristen und setze systemweit Logrotation und Kompression durch.

WordPress: wiederkehrende Muster schnell erkennen

• WP_Query/WP_Meta_Query: Fehlen Indexe auf postmeta oder wird nach nicht indizierten Feldern gefiltert, kippt die Laufzeit. Ich reduziere Meta-Abfragen, nutze Taxonomien oder setze gezielte Indexe.
• Transients und Object-Cache: Viele gleichartige Berechnungen deuten auf fehlenden persistenten Cache. Ich aktiviere Object-Cache, optimiere Cache-Keys und TTLs.
• Hooks/Filters: Lange Ketten im Stack weisen auf Plugin-Ballast hin. Ich messe teuerste Hooks und entferne oder ersetze Erweiterungen.
• HTTP-Requests: Interne API-Calls (wp_remote_get) sollten timeouts, keep-alive und Caching nutzen; Antworten nicht im Request-Thread blockieren, wenn möglich.
• Template-Rendering: Tiefe get_template_part-Kaskaden mit Dateizugriffen profitieren von Caching und weniger Fragmentierung.

Fehlinterpretationen vermeiden: was der Slowlog nicht zeigt

Der Snapshot ist eine Momentaufnahme. Er erklärt nicht die gesamte Lebenszeit des Requests, sondern den Zustand zum Auslösezeitpunkt. Häufige Fallen:

• Sampling-Bias: Seltene, aber extrem teure Pfade können untergehen, wenn das Timeout zu niedrig ist oder die Phase kurz war.
• Blockierende System-Calls: fopen, stat oder DNS-Lookups erscheinen als PHP-Funktionen, die eigentliche Wartezeit passiert im Kernel oder Netzwerk.
• Autoloading: Viele kleine Includes ohne Opcache verursachen Streuverluste, die im Stack harmlos wirken. Ein Blick auf Opcache-Hitrate hilft bei der Einordnung.

CLI, Cron und Webhooks im Blick behalten

Nicht alle Performance-Probleme laufen über FPM. Schwergewichtige Cronjobs (z. B. wp-cron), Queue-Worker oder Webhooks blockieren CPU, I/O oder Datenbank und verschlechtern so indirekt Antwortzeiten. Ich isoliere solche Last in eigene Prozesse, plane sie außerhalb von Peaks und prüfe, ob sie via FPM-triggered HTTP statt CLI laufen – das verzerrt sonst die Slowlog-Sicht.

Logrotation praxisnah umsetzen

Damit Slowlogs nicht ausufern, rotiere ich sie häufig und komprimiere Altbestände. Eine typische Rotation hält wenige Generationen vor, signalisiert FPM ein Reopen und vermeidet Lücken. Wichtig: Nach der Rotation FPM neu öffnen lassen (HUP), damit neue Einträge nicht ins Nirwana schreiben. Die konkreten Einstellungen richte ich an Traffic, Timeout und Trace-Tiefe aus.

Checkliste für schnelle Ergebnisse

• Slowlog pro Pool aktivieren, Pfade und Rechte prüfen.
• Mit 5s starten, Einträge sammeln, Top-Frames zählen.
• Mit Access-Logs korrelieren: Zeitstempel, URI, User-Agent.
• Upstream- und Webserver-Timeouts gegenprüfen.
• FPM-Status und Queue beobachten, pm-Limits justieren.
• Hotspots zuerst fixen: SQL-Indexe, Caching, teure Hooks, I/O.
• Timeout schrittweise senken, erneut messen.
• Logs rotieren, Erkenntnisse dokumentieren, Änderungen nachhalten.

Kurz zusammengefasst: dein Weg zur besseren Performance

Ich aktiviere den Slowlog, lese die Top-Frames, korreliere mit den Access-Logs und behebe zuerst die größten Ausreißer. Danach senke ich die Schwelle, prüfe wiederkehrende Muster und setze gezielte Fixes in Code, Konfiguration und Caching um. Mit Logrotation und moderaten Timeouts halte ich die Betriebsbelastung niedrig. Für WordPress fokussiere ich teure Queries, Plugins, Hooks und mögliche Session-Locks. So finde ich verlässlich die echten Bottlenecks und liefere spürbar schnellere Antworten.