Att korrekt analysera PHP-FPM:s slowlog: hitta prestandaflaskhalsar på ett säkert sätt

Jag ska visa dig hur du gör PHP-FPM:s slowlog analyserar målinriktat, tolkar backtraces korrekt och utleder tydliga åtgärder för att minska latensen. På så sätt kan du på ett tillförlitligt sätt hitta prestandaflaskhalsar, prioritera åtgärder och göra laddningstiderna märkbart snabbare för användarna.

Centrala punkter

• Backtrace Läs: Ram #0 visar den aktuella bromsbelägget.
• Tidsgräns Välj: börja högt och sänk sedan gradvis.
• Korrelation Med åtkomstlogg: säkert identifiera långsamma URL:er.
• Prov räkna: prioritera återkommande funktioner.
• Kodkorrigeringar utleda: Arbeta målmedvetet med databaser, API:er, loopar och plugins.

Vad är PHP-FPM:s slowlog?

Slowlog skriver in en Backtrace i en loggfil och registrerar därmed den aktuella körningspunkten utan att avbryta förfrågan. Jag ser omedelbart vilket skript, vilken URL och vilken funktion som blockerar vägen. Posterna innehåller tidsstämpel, pool, skriptfilnamn, begäran-URI och kedjan av funktionsanrop. Därmed skiljer sig slowloggen tydligt från klassiska felloggar, eftersom den dokumenterar prestanda, inte fel. För hårt belastade sidor som WordPress-backends ger den snabbt användbara ledtrådar om kostsamma förfrågningar, omfattande rendering eller blockerande I/O-operationer. Den som förstår dessa ögonblicksbilder kan mycket snabbt Huvudorsak avgränsa och planera åtgärder.

Så här fungerar Slowlog i vardagen

Efter aktivering skriver PHP-FPM ut en Ögonblicksbild från stacken till loggen medan begäran fortsätter. Varje post börjar vanligtvis med „#0“, det vill säga vid den punkt där tid just går förlorad. Mellan blocken ser jag ofta tomma rader, vilket underlättar avgränsningen av händelserna. Metoden ger stickprov istället för fullständiga profiler, men däremot träffsäkra indikationer på verkliga flaskhalsar såsom krångliga mallvägar, övergivna hookar eller tröga nätverksanrop. Under perioder med hög belastning kopplar jag dessa indikationer till belastningstoppar och kan på så sätt tydligt klassificera kodavsnitt. Så snart jag ser återkommande mönster anpassar jag till exempel pm.max_barn och använd informationen från Ställa in pm.max_children korrekt.

Aktivera och konfigurera Slowlog

Jag aktiverar funktionen i respektive pool och anger sökväg, timeout och spårningsdjup så att Utvärdering förblir hanterbar. Därefter startar jag om PHP-FPM och kontrollerar om loggfilen går att skriva till med poolanvändarens behörigheter. Som utgångsvärde sätter jag ofta 5 sekunder för att först fånga upp grova avvikelser utan att översvämma systemet med loggdata. Därefter sänker jag värdet stegvis så snart de största problemen är lösta. För överskådliga loggar begränsar jag spårningsdjupet till 20 till 30 ramar, vilket i praktiken oftast räcker. På så sätt håller jag Filstorlek under kontroll och missar inga viktiga detaljer.

Inställning	Syfte	Startvärde	Anteckningar
slowlog	Sökväg till loggfilen	/var/log/php-fpm/www-slow.log	Kontrollera sökvägarna beroende på distribution; skrivrättigheter för www-data säkerställa
begäran_slowlog_timeout	Tröskelvärde för „långsamt“	5 sekunder	Börja högt, senare sänka (t.ex. 2–3 s)
request_slowlog_trace_depth	Max. djup för bakåtspårningen	20–30	Se till att spåren förblir läsbara, utan att Viktig information att förlora

Hitta loggfilen och granska den snabbt

Jag kontrollerar först de konfigurerade sökvägarna och öppnar loggen med mindre eller kontrollera de sista raderna med tail -40. På så sätt ser jag direkt om det kommer in poster och vilka skript som återkommande sticker ut. För att snabbt få en överblick tittar jag på filnamn, berörda pooler och URI:er som sticker ut. Om jag inte hittar några poster aktiverar jag alternativen i poolen, laddar om tjänsten och kontrollerar ägare och behörigheter. I hanterade miljöer konsulterar jag dessutom panelen eller startskripten för att säkerställa att slowloggen verkligen följer med.

Identifiera block och räkna mönster

Varje post visas som ett block, ofta åtskilda av en Tom rad, vilket underlättar räkningen. Jag utgår från „#0“-raderna, eftersom de markerar den aktuella exekveringspunkten där tid går åt. Med hjälp av enkla shell-pipelines filtrerar jag fram de viktigaste funktionerna och ser vilka ställen som oftast bromsar ner systemet. På så sätt prioriterar jag specifikt de funktioner som sammantaget tar mest tid. Därefter kontrollerar jag om dessa flaskhalsar endast uppstår vid belastningstoppar eller om de orsakar problem genomgående. Denna klassificering avgör Sekvens mina åtgärder.

Läsa poster: från ram #0 till början

När jag läser inläggen börjar jag högst upp vid #0 och går steg för steg nedåt för att förstå vägen från startpunkten till den aktuella platsen. Långa mallkedjor tyder på resurskrävande rendering, många hooks på onödiga plugins och en hög andel SQL-kod på saknade index. Jag markerar radnummer, funktionsnamn och filvägar så att jag snabbt kan hitta koden. Om stacken ser ut att innehålla vänteslingor eller upprepade operationer kontrollerar jag mellanlagring och caching. På så sätt slösar jag inte tid på att Lokalisering problemet i koden.

Korrelera Slowlog med åtkomstloggar

Jag kopplar ihop Slowlog med webbserverns loggar så att jag kan se de långsamma förfrågningarna från en specifik URL kan koppla ihop. Med hjälp av tidsstämplar och, i förekommande fall, PID:er hittar jag de relevanta posterna i Nginx- eller Apache-loggen. På så sätt kan jag identifiera parametrar, användaragenter och svarstider utanför PHP. Om återkommande besökare eller identiska frågesträngar dyker upp startar jag en testkörning med just dessa scenarier. På så sätt hittar jag snabbt reproducerbara fall och håller Analystid kort.

Sänk tröskelvärdet stegvis

Jag börjar med en generös tröskel och åtgärdar först de största Utbrytare och sänker sedan stegvis. Denna process minskar loggvolymen och riktar min energi mot värdefulla korrigeringar. Efter varje optimeringsomgång väljer jag en lägre tröskel och samlar in data igen. På så sätt arbetar jag mig fram från grovjustering till finjustering utan att fastna i bruset. Resultatet blir målinriktade justeringar och en klar Översikt över kvarvarande flaskhalsar.

Från slowlog till lösning: typiska åtgärder

Om toppramen visar databasfunktioner kontrollerar jag SQL-kommandona med FÖRKLARA, lägger till saknade index och begränsar resultatuppsättningarna. Vid avlägsna tjänster minskar jag tidsgränserna, hanterar svaren asynkront eller cachelagrar resultaten. Om jag hittar resurskrävande loopar förenklar jag logiken, minskar antalet genomgångar och använder effektivare strukturer. I WordPress markerar jag återkommande hooks, byter ut tunga tillägg och väljer ett lättare tema. Om antalet PHP-processer blockerar bearbetningen håller jag koll på väntetiderna och läser kompletterande information om Bakspår även köer, till exempel via Köhantering av PHP-förfrågningar.

Kontinuerlig drift: effektiv logghantering

Jag ställer inte in loggningen på max hela tiden, så att I/O-belastning förblir hanterbar. Istället arbetar jag i faser: aktiv utvärdering, optimering, för att sedan återgå till en måttlig nivå. Med Logrotate håller jag filerna smidiga och arkiverar gamla data i komprimerat format. När en analys är klar höjer jag tröskeln eller stänger av slowlogging tillfälligt. Dessutom dokumenterar jag insikter och korrigeringar så att senare granskningar ger en tydlig spår finna.

Diagnos av webbhotell: Skilja mellan server och applikation

Många identiska Slowlog-ramar vid hög CPU-belastning tyder på Applikationskod, medan saknade poster på en trög sida snarare tyder på problem med I/O, nätverket eller databasservern. I sådana fall jämför jag TTFB, PHP-tider och uppströmslatens för att lokalisera flaskhalsen. Om jag ser köer och långa väntetider före exekvering kontrollerar jag gränsvärden och antalet processer. Dessutom kompletterar jag min diagnos med information om hur förfrågningarna hanteras och tar hänsyn till eventuella gränsvärden som saktar ner bearbetningen. För en välgrundad bedömning läser jag, utöver loggarna, även information om Ställa in pm.max_children korrekt eller artiklar som handlar om väntetider, så att jag kan Kapacitet på ett meningsfullt sätt.

Praktiskt exempel: långsam WordPress-administrationspanel

Jag ställer in begäran_slowlog_timeout Inledningsvis ställer jag in tiden på 5 sekunder, startar om PHP-FPM och samlar in data under 30 till 60 minuter under verklig belastning. Därefter räknar jag de vanligaste „#0“-funktionerna och letar efter återkommande hooks eller kostsamma WP_Query-anrop. Om externa tjänster förekommer mäter jag svarstider och cachelagrar resultaten på ett målinriktat sätt. Om sidvisningar bromsas av sessionsåtkomst kontrollerar jag låsningsbeteendet och flyttar, om möjligt, sessionsrelaterat arbete bort från den kritiska vägen. Särskilt vid inloggningar och administratörsåtgärder testar jag inställningar och inaktiverar vissa meddelanden Låsning av PHP-session för att min Backend reagerar snabbare.

Pool-design och rättigheter: en ren grund för användbara slowloggar

Jag delar upp applikationerna i separata pooler med tydliga namn (t.ex. www, admin, api), ange unika lyssna-uttag och individuella slowlog-sökvägar. På så sätt kan jag lättare koppla ihop poster och undvika att de blandas ihop. Det är viktigt med konsekventa Filrättigheter: Poolanvändaren (ofta www-data) behöver skrivrättigheter till loggvägen och i katalogen. I container- eller chroot-miljöer kontrollerar jag om vägarna finns i namnområdet och är permanenta – annars försvinner loggarna vid omstart.

Att läsa och automatiskt analysera ett Slowlog-inlägg i detalj

Vanligtvis inleds posterna med tidsstämpel, pool, skriptfilnamn och begäran-URI, följt av ramarna. Jag räknar „#0“-raderna och grupperar dem efter funktionsnamn för att synliggöra flaskhalsar. Med enkla piper extraherar jag bromsblocken:

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

Eller så räknar jag upp de vanligaste toppramarna:

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

Om jag vill inkludera URL och fil förbereder jag block med hjälp av awk och skriv ner de bästa kombinationerna av funktion, URI och skript åt mig. På så sätt prioriterar jag de korrigeringar som ger störst nytta.

Timeout-karta: hur Slowlog, PHP och webbservern samverkar

För att ställa en korrekt diagnos ordinerar jag alla Timeouts: begäran_slowlog_timeout utlöser ögonblicksbilden, max_exekveringstid begränsar PHP-körningstiden i skriptet, begäran_avsluta_timeout kan avsluta FPM-arbetaren på ett tvärt sätt. På webbserverns sida fastcgi– eller. proxy-Timeouts (t.ex. fastcgi_read_timeout) och klient-timeouts. Om jag sätter slowlog ovanför om serverns tidsgränser överskrids, släpper jag ut data; om den bland annat, får jag användbara ögonblicksbilder innan förfrågningarna avbryts. Jag håller därför medvetet fast vid följande ordning: webbserverns timeout > PHP-avslutning > slowlog > mållatens.

Inkludera FPM-status, kö och processhantering

Slowlog visar att, där tid går till spillo – FPM-statusen avslöjar, varför Förfrågningar väntar. Jag aktiverar status-ändpunkten och övervakar tomgång, aktiv och lyssna kö och jämför dem med Slowlog-tidsstämplarna. Om kön växer medan många arbetare fastnar i samma funktioner är koden flaskhalsen; om kön växer utan att Slowlog-värdena ökar saknas kapacitet eller så bromsar något uppströms. Utifrån detta justerar jag pm-Inställningar (dynamisk/på begäran), pm.max_barn och eventuellt. pm.max_förfrågningar, för att upptäcka minnesläckor eller fragmentering.

Särdrag i containrar och hanterade miljöer

I Docker/Kubernetes loggar FPM ofta till stdout/stderr eller i sökvägar som samlas in av loggaggregatorer. Jag väljer medvetet en en Bort, så att jag inte får dubbla eller saknade poster. Med error_log = /proc/self/fd/2 och en särskild slowlog-Snapshots förblir tillgängliga på en sökväg som pekar på en persistent volym. I hanterade miljöer kontrollerar jag om värdleverantören har aktiverat eller begränsat slowlogs – och justerar intervallen så att jag inte stöter på rotationsscheman.

Dataskydd och säkerhet: Loggar utan risk

Backtraces kan innehålla känslig Parametrar, filvägar eller sessions-ID:n. Jag minimerar riskerna genom att undvika att spara frågesträngar i åtkomstloggar, inaktivera felsökningsutdata i koden och begränsa kretsen av personer med läsbehörighet. Vid utbyte med tredje part anonymiserar jag sökvägar och tar bort token. I produktionsmiljöer fastställer jag korta lagringstider och inför loggrotation och komprimering i hela systemet.

WordPress: snabbt upptäcka återkommande mönster

• WP_Query/WP_Meta_Query: Saknas index på postmeta eller om man filtrerar efter fält som inte är indexerade, ökar körtiden kraftigt. Jag minimerar metaförfrågningar, använder taxonomier eller skapar riktade index.
• Transienter och objektcache: Många likartade beräkningar tyder på att det saknas en permanent cache. Jag aktiverar objektcachen och optimerar cache-nycklarna och TTL-värdena.
• Hooks/filter: Långa kedjor i stacken tyder på onödiga plugins. Jag mäter de dyraste hookarna och tar bort eller byter ut tillägg.
• HTTP-förfrågningar: Interna API-anrop (wp_remote_get) bör utnyttja timeout, keep-alive och caching; svaren bör om möjligt inte blockera begärandetråden.
• Mallrendering: Djup get_template_part-Kaskader med filåtkomst drar nytta av cachelagring och mindre fragmentering.

Undvika feltolkningar: vad Slowlog inte visar

Snapshot är en Ögonblicksbild. Den beskriver inte hela begäranens livslängd, utan dess tillstånd vid den tidpunkt då den utlöses. Vanliga fallgropar:

• Samplingsfel: Sällsynta men extremt dyra vägar kan gå förlorade om tidsgränsen är för kort eller om fasen var kort.
• Systemanrop som blockerar: fopen, stat eller DNS-uppslag visas som PHP-funktioner, men den egentliga väntetiden äger rum i kärnan eller i nätverket.
• Automatisk inläsning: Många små inkluderingar utan Opcache orsakar spridningsförluster som verkar ofarliga i stacken. En titt på Opcache-hitrate hjälper till att sätta detta i sitt sammanhang.

Hålla koll på CLI, Cron och webhooks

Det är inte alla prestandaproblem som hanteras via FPM. Tunga Cronjobs (t.ex. wp-cron), köhanterare eller webbhooks belastar CPU, I/O eller databasen och försämrar därmed indirekt svarstiderna. Jag isolerar sådan belastning i egna processer, schemalägger dem utanför trafiktopparna och kontrollerar att de körs via FPM-triggad HTTP istället för CLI – annars snedvrider det slowlog-vyn.

Att genomföra logrotation på ett praktiskt sätt

För att förhindra att loggfilerna växer sig för stora roterar jag dem ofta och komprimerar äldre data. En typisk rotation behåller några generationer, signalerar till FPM att öppna filen på nytt och undviker luckor. Viktigt: Efter rotationen måste FPM öppnas på nytt (HUP) så att nya poster inte hamnar i tomrummet. De konkreta inställningarna anpassar jag efter trafik, timeout och spårningsdjup.

Checklista för snabba resultat

• Aktivera Slowlog per pool, kontrollera sökvägar och behörigheter.
• Starta med 5 sekunder, samla in poster, räkna de bästa bildrutorna.
• Korrelera med Access-loggar: tidsstämpel, URI, User-Agent.
• Kontrollera tidsgränserna för uppströms- och webbservrar.
• Övervaka FPM-status och kö, pm- Justera gränserna.
• Åtgärda först de kritiska punkterna: SQL-index, caching, resurskrävande hookar, I/O.
• Sänk timeout-tiden stegvis och mät igen.
• Rotera loggar, dokumentera insikter, spåra ändringar.

I korthet: din väg till bättre prestanda

Jag aktiverar Slowlog och läser Toppramar, jämför med åtkomstloggarna och åtgärdar först de största avvikelserna. Därefter sänker jag tröskelvärdet, kontrollerar återkommande mönster och genomför riktade korrigeringar i koden, konfigurationen och cachelagringen. Med loggrotation och rimliga tidsgränser håller jag driftsbelastningen låg. För WordPress fokuserar jag på resurskrävande sökfrågor, plugins, hooks och eventuella sessionslås. På så sätt hittar jag på ett tillförlitligt sätt de verkliga Flaskhalsar och ger märkbart snabbare svar.