Sådan analyseres PHP-FPM-slowloggen korrekt: Sådan finder du sikkert flaskehalse i ydeevnen

Jeg viser dig, hvordan du PHP-FPM-slowlog udlæser målrettet, fortolker backtraces korrekt og udleder deraf klare trin til at reducere latenstiden. På den måde finder du pålideligt flaskehalse i ydeevnen, prioriterer tiltag og gør indlæsningstiderne mærkbart hurtigere for brugerne.

Centrale punkter

• Backtrace Læs: Frame #0 viser den aktuelle bremseklods.
• Timeout Vælg: Start først højt og sænk derefter gradvist.
• Sammenhæng Med adgangslog: Sikker identifikation af langsomme URL'er.
• Prøve tælle: prioritere tilbagevendende funktioner.
• Kodeændringer udlede: målrettet håndtering af DB, API'er, sløjfer og plugins.

Hvad er PHP-FPM-slowloggen?

Slowlog skriver en for lange forespørgsler Backtrace i en logfil og registrerer dermed det aktuelle udførelsespunkt uden at afbryde forespørgslen. Jeg kan straks se, hvilket script, hvilken URL og hvilken funktion der blokerer forløbet. Indtastningerne indeholder tidsstempel, pool, scriptfilnavn, anmodnings-URI og kæden af funktionskald. Dermed adskiller slowloggen sig tydeligt fra klassiske fejllogfiler, da den dokumenterer ydeevne, ikke fejl. For stærkt belastede sider som WordPress-backends leverer den hurtigt brugbare oplysninger om ressourcekrævende forespørgsler, tidskrævende rendering eller blokerende I/O-operationer. Den, der forstår disse øjebliksbilleder, kan meget hurtigt Hovedårsag afgrænse problemet og planlægge foranstaltninger.

Sådan fungerer Slowlog i hverdagen

Når funktionen er aktiveret, skriver PHP-FPM en, når en defineret tærskel overskrides, en Øjebliksbillede fra stakken til loggen, mens anmodningen fortsætter. Hver post starter typisk med „#0“, altså på det sted, hvor der netop går tid tabt. Mellem blokkene ser jeg ofte tomme linjer, hvilket gør det nemmere at adskille begivenhederne. Metoden leverer stikprøver i stedet for fuldstændige profiler, men til gengæld giver den præcise indikationer på reelle flaskehalse, såsom omfattende skabelonstier, forladte hooks eller træge netværksopkald. I perioder med høj belastning sammenholder jeg disse indikationer med belastningstoppe og inddeler dermed kodestykkerne overskueligt. Så snart jeg ser tilbagevendende mønstre, tilpasser jeg for eksempel pm.max_børn og brug oplysningerne fra Indstil pm.max_children korrekt.

Aktivering og konfiguration af Slowlog

Jeg aktiverer funktionen i den pågældende pool og angiver sti, timeout og sporingsdybde, så Evaluering forbliver håndterbar. Derefter genstarter jeg PHP-FPM og kontrollerer, om logfilen kan skrives til med pool-brugerens rettigheder. Som udgangspunkt indstiller jeg ofte 5 sekunder for først at fange grove afvigelser uden at oversvømme systemet med logdata. Derefter sænker jeg værdien trinvist, så snart de største problemer er løst. For at holde logfilerne overskuelige begrænser jeg sporingsdybden til 20 til 30 frames, hvilket i praksis som regel er tilstrækkeligt. På den måde holder jeg Filstørrelse under kontrol og går ikke glip af relevante detaljer.

Indstilling	Formål	Startværdi	Noter
slowlog	Sti til logfilen	/var/log/php-fpm/www-slow.log	Kontroller stierne afhængigt af distributionen; skriverettigheder til www-data sikre
request_slowlog_timeout	Tærskel for „langsom“	5s	Start højt, senere sænke (f.eks. 2–3 sekunder)
request_slowlog_trace_depth	Maks. dybde af backtrace	20–30	Sørg for, at sporene forbliver læselige, uden Vigtige oplysninger at miste

Find logfilen og gennemse den hurtigt

Først tjekker jeg de konfigurerede stier og åbner logfilen med mindre eller tjek de sidste linjer med tail -40. På den måde kan jeg straks se, om der kommer nye poster, og hvilke skripter der gentagne gange vækker opmærksomhed. For hurtigt at få overblik kigger jeg på filnavne, de berørte puljer og mistænkelige URI’er. Hvis jeg ikke finder nogen poster, aktiverer jeg indstillingerne i puljen, genindlæser tjenesten og tjekker ejere samt rettigheder. I administrerede miljøer tjekker jeg desuden panelet eller startskripterne, så slowloggen virkelig følger med.

Genkende blokke og tælle mønstre

Hver post vises som et afsnit, ofte adskilt af en Tom linje, hvilket gør det lettere at tælle. Jeg orienterer mig efter „#0“-linjerne, da de markerer det aktuelle udførelsespunkt, hvor tiden går tabt. Ved hjælp af enkle shell-pipelines filtrerer jeg de vigtigste funktioner ud og ser, hvilke steder der oftest bremser processen. På den måde prioriterer jeg målrettet de funktioner, der samlet set tager mest tid. Derefter tjekker jeg, om disse hotspots kun opstår ved belastningsspidser eller skaber problemer hele tiden. Denne inddeling bestemmer Sekvens mine foranstaltninger.

Læs indlæg: fra ramme #0 til starten

Når jeg læser indlæggene, starter jeg øverst ved #0 og går trin for trin nedad for at forstå vejen fra startpunktet til det aktuelle sted. Lange skabelonkæder tyder på omfattende rendering, mange hooks på unødvendig plugin-byrde og en høj andel af SQL-kode på manglende indekser. Jeg markerer linjenumre, funktionsnavne og filstier, så jeg hurtigt kan finde koden. Hvis stakken ligner venteløkker eller gentagne operationer, tjekker jeg mellemhukommelsen og caching. På den måde spilder jeg ikke tid på at Lokalisering problemet i koden.

Korrelering af Slowlog med adgangslogfiler

Jeg sammenkæder Slowlog med webserverlogfilerne, så jeg kan se de langsomme forespørgsler fra en bestemt URL kan tilordne. Ved hjælp af tidsstempler og eventuelt PID’er finder jeg de relevante poster i Nginx- eller Apache-loggen. På den måde kan jeg identificere parametre, user-agents og svartider uden for PHP. Hvis der dukker tilbagevendende besøgende eller identiske forespørgselsstrenge op, starter jeg en testkørsel med netop disse scenarier. På den måde finder jeg hurtigt reproducerbare tilfælde og holder Analysetid kort sagt.

Sænk tærskelværdien iterativt

Jeg starter med en generøs tærskel og løser først de største problemer Afvigere og sænker den derefter trinvist. Denne fremgangsmåde reducerer logfilens størrelse og fokuserer min energi på de mest værdifulde rettelser. Efter hver optimeringsrunde vælger jeg en lavere tærskel og indsamler igen datasæt. På den måde arbejder jeg mig frem fra den grove udvælgelse til finjusteringen, uden at jeg drukner i støj. Resultatet er målrettede justeringer og en klar Oversigt over de resterende flaskehalse.

Fra slowlog til løsning: typiske løsninger

Hvis top-rammen viser databasefunktioner, tjekker jeg SQL-sætningerne med FORKLAR, opretter manglende indekser og begrænser resultatsæt. Ved fjernbetjente tjenester reducerer jeg timeout-tider, behandler svar asynkront eller cacher resultater. Hvis jeg finder ressourcekrævende sløjfer, forenkler jeg logikken, reducerer antallet af gennemløb og anvender mere effektive strukturer. I WordPress markerer jeg tilbagevendende hooks, udskifter tunge udvidelser og vælger et lettere tema. Hvis antallet af PHP-processer blokerer behandlingen, holder jeg øje med ventetiderne og læser supplerende til Backtraces også køer, f.eks. via Køhåndtering af PHP-anmodninger.

Kontinuerlig drift: effektiv loghåndtering

Jeg skruer ikke logningen helt op hele tiden, så den I/O-belastning forbliver håndterbar. I stedet arbejder jeg i faser: aktivt evaluerer og optimerer jeg, hvorefter jeg vender tilbage til et moderat niveau. Med Logrotate holder jeg filerne slanke og arkiverer gamle data i komprimeret form. Når en analyse er afsluttet, hæver jeg tærsklen eller deaktiverer slowlogging midlertidigt. Derudover dokumenterer jeg indsigter og rettelser, så senere revisioner får et klart spor finde.

Hosting-diagnose: Skelne mellem server og applikation

Mange identiske Slowlog-rammer ved høj CPU-belastning tyder på Anvendelseskode, mens manglende poster på den langsomme side snarere tyder på problemer med I/O, netværk eller databaseserveren. I sådanne tilfælde sammenligner jeg TTFB, PHP-tider og upstream-latens for at lokalisere flaskehalsen. Hvis jeg ser køer og lange ventetider før udførelse, tjekker jeg begrænsninger og antallet af processer. Derudover supplerer jeg min diagnose med oplysninger om behandlingen af anmodninger og tager højde for eventuelle begrænsninger, der bremser behandlingen. For at kunne danne mig et velunderbygget overblik læser jeg ud over logfilerne også oplysninger om Indstil pm.max_children korrekt eller artikler om ventetider, så jeg kan Kapacitet tilpasser det på en fornuftig måde.

Praktisk eksempel: langsomt WordPress-backend

Jeg sætter request_slowlog_timeout Først indstiller jeg tiden til 5 sekunder, genstarter PHP-FPM og indsamler data i 30 til 60 minutter under reel belastning. Derefter tæller jeg de hyppigst forekommende „#0“-funktioner og leder efter tilbagevendende hooks eller ressourcekrævende WP_Query-kald. Hvis der er eksterne tjenester involveret, måler jeg svartiderne og cacher resultaterne målrettet. Hvis sidevisninger bremses af sessionstilgange, tjekker jeg låseadfærden og flytter, hvis det er muligt, sessionsrelateret arbejde væk fra den kritiske sti. Især ved logins og administratorhandlinger tester jeg indstillinger og slår advarsler fra Låsning af PHP-sessioner for at, så min Backend reagerer hurtigere.

Pool-design og rettigheder: et solidt grundlag for brugbare slowlogs

Jeg opdeler programmer i separate Pools med tydelige navne (f.eks. www, admin, api), angiv entydige lytte-stik og individuelle slowlog-stier. Det gør det lettere for mig at sammenholde poster og undgå sammenblandinger. Det er vigtigt med ensartede Rettigheder til filer: Pool-brugeren (ofte www-data) skal have skriverettigheder til logstien og i mappen. I container- eller chroot-opsætninger tjekker jeg, om stierne findes i navneområdet og er gemt permanent – ellers forsvinder logfilerne ved genstart.

At læse et Slowlog-indlæg i detaljer og analysere det automatisk

Indtastningerne starter typisk med et tidsstempel, en pool, et scriptfilnavn og en anmodnings-URI, efterfulgt af rammerne. Jeg tæller „#0“-linjer og grupperer dem efter funktionsnavne for at synliggøre hotspots. Ved hjælp af enkle pipes udtrækker jeg de flaskehalse:

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

Eller jeg tæller de hyppigst forekommende top-frames:

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

Hvis jeg vil medtage URL og fil, opretter jeg blokke ved hjælp af awk Gå igennem det og skriv de bedste kombinationer af funktion, URI og script ned til mig. På den måde prioriterer jeg de rettelser, der giver størst udbytte.

Timeout-oversigt: hvordan Slowlog, PHP og webserveren spiller sammen

For at stille en præcis diagnose ordinerer jeg alle Timeouts: request_slowlog_timeout udløser snapshotet, max_udførelsestid begrænser PHP-kørselstiden i scriptet, request_terminate_timeout kan afbryde FPM-workeren brat. På webserverens side griber fastcgi– henholdsvis. proxy-Timeouts (f.eks. fastcgi_read_timeout) og klient-timeouts. Hvis jeg indstiller slowloggen over hvis serveren går i timeout, mister jeg data; hvis den herunder, får jeg nyttige øjebliksbilleder, inden anmodningerne bryder af. Derfor holder jeg bevidst rækkefølgen: Webserver-timeout > PHP-afbrydelse > Slowlog > mållatens.

Inddrag FPM-status, kø og processtyring

Slowlog viser, hvor Tid går til spilde – FPM-status afslører, hvorfor Der er forespørgsler, der venter. Jeg aktiverer status-endepunktet og overvåger i tomgang, aktiv og lyttekø og sammenligner dem med Slowlog-tidsstemplerne. Hvis køen vokser, mens mange arbejdsprocesser hænger fast i de samme funktioner, er koden flaskehalsen; hvis køen vokser uden at Slowlog-værdierne stiger, mangler der kapacitet, eller også er der en opstrøms faktor, der bremser. Med udgangspunkt i dette justerer jeg pm-Indstillinger (dynamisk/efter behov), pm.max_børn og eventuelt. pm.max_anmodninger, for at opdage hukommelseslækager eller fragmentering.

Særlige forhold i containere og administrerede miljøer

I Docker/Kubernetes logger FPM ofte til stdout/stderr eller i stier, der indsamles af log-aggregatorer. Jeg vælger bevidst en en Væk, så jeg ikke har dobbelte eller manglende poster. Med error_log = /proc/self/fd/2 og en dedikeret slowlog-Snapshots forbliver tilgængelige på en sti, der peger på et permanent volumen. I administrerede opsætninger tjekker jeg, om udbyderen har aktiveret eller begrænset slowlogs – og tilpasser intervallerne, så jeg ikke kommer i konflikt med rotationerne.

Databeskyttelse og sikkerhed: Logfiler uden risiko

Backtraces kan indeholde følsomme Parametre, filstier eller sessions-ID’er. Jeg minimerer risici ved at udelade query-strings i adgangslogfiler, deaktivere fejlfindingsudskrifter i koden og holde kredsen af personer med læseadgang lille. Ved udveksling med tredjeparter anonymiserer jeg stier og fjerner tokens. I produktive miljøer fastlægger jeg korte opbevaringsperioder og gennemfører logrotation og komprimering på tværs af hele systemet.

WordPress: hurtigt at genkende tilbagevendende mønstre

• WP_Query/WP_Meta_Query: Manglende indekser på postmeta eller hvis der filtreres efter felter, der ikke er indekseret, stiger køretiden markant. Jeg reducerer meta-forespørgsler, bruger taksonomier eller opretter målrettede indekser.
• Transienter og objektcache: Mange ensartede beregninger tyder på, at der mangler en vedvarende cache. Jeg aktiverer objektcachen og optimerer cache-nøgler og TTL'er.
• Hooks/filtre: Lange kæder i stakken tyder på unødvendige plugins. Jeg analyserer de dyreste hooks og fjerner eller erstatter udvidelser.
• HTTP-anmodninger: Interne API-kald (wp_remote_get) bør udnytte timeout, keep-alive og caching; svarene bør om muligt ikke blokere i anmodningstråden.
• Skabelonvisning: Dybde get_template_part-Kaskader med filadgang drager fordel af caching og mindre fragmentering.

Undgå fejltolkninger: hvad Slowlog ikke viser

Snapshot er en Øjebliksbillede. Den beskriver ikke hele anmodningens levetid, men tilstanden på det tidspunkt, hvor den udløses. Almindelige faldgruber:

• Samplingsskævhed: Sjældne, men ekstremt dyre stier kan gå tabt, hvis timeout-værdien er for lav, eller hvis fasen var kort.
• Blokerende systemkald: fopen, stat eller DNS-opslag fremstår som PHP-funktioner, men den egentlige ventetid finder sted i kernen eller i netværket.
• Automatisk indlæsning: Mange små inkluderinger uden Opcache medfører spild, der virker harmløst i stakken. Et kig på Opcache-hitrate hjælper med at sætte det i perspektiv.

Hold øje med CLI, Cron og webhooks

Ikke alle ydeevneproblemer skyldes FPM. Tunge Cronjobs (f.eks. wp-cron), kø-arbejdere eller webhooks belaster CPU, I/O eller databasen og forværrer dermed indirekte svartiderne. Jeg isolerer sådanne belastninger i egne processer, planlægger dem uden for spidsbelastningsperioder og kontrollerer, om de kører via FPM-udløst HTTP i stedet for CLI – ellers forvrænger det visningen i slowloggen.

Praktisk implementering af logrotation

For at undgå, at slowlogs vokser sig for store, roterer jeg dem ofte og komprimerer gamle data. En typisk rotation opbevarer få generationer, signalerer til FPM, at den skal genåbnes, og undgår huller. Vigtigt: Efter rotationen skal FPM genåbnes (HUP), så nye poster ikke ender i intetheden. De konkrete indstillinger tilpasser jeg efter trafik, timeout og sporingsdybde.

Tjekliste til hurtige resultater

• Aktivér Slowlog pr. pool, kontroller stier og rettigheder.
• Start med 5s, indsaml data, tæl de bedste frames.
• Korrelering med adgangslogfiler: tidsstempel, URI, brugeragent.
• Kontroller tidsgrænserne for upstream- og webserverne.
• Overvåge FPM-status og kø, pm-Juster grænserne.
• Løs først de kritiske punkter: SQL-indekser, caching, ressourcekrævende hooks, I/O.
• Sænk timeout-tiden gradvist, og mål igen.
• Roter logfiler, dokumenter indsigter, spor ændringer.

Kort sagt: din vej til bedre præstationer

Jeg aktiverer Slowlog og læser Top-rammer, sammenholder jeg det med adgangslogfilerne og løser først de største afvigelser. Derefter sænker jeg tærsklen, undersøger tilbagevendende mønstre og implementerer målrettede rettelser i koden, konfigurationen og caching. Med logrotation og moderate timeouts holder jeg driftsbelastningen lav. For WordPress fokuserer jeg på ressourcekrævende forespørgsler, plugins, hooks og mulige session-locks. På den måde finder jeg pålideligt de reelle Flaskehalse og leverer mærkbart hurtigere svar.