PHP error logs lezen als bloedonderzoek: een triage-gids

Vrijdag, 16:47. Een bericht van een klant: "De site geeft op de checkout-pagina soms 500s. Niet altijd. Kun je er voor het weekend nog naar kijken?" Je SSH't in, tailt het log, en ziet ruwweg achthonderd regels rood. Een deel ervan is het echte probleem. Het meeste is ruis die er al maanden staat. Triage begint met weten wat wat is.

Dit is het deel van het werk dat minder aandacht krijgt dan het verdient. Een PHP error log is een vitale-functies-paneel voor een draaiende site. Het vertelt je wat er stuk is, wat bijna stuk gaat, en wat al stuk was voordat je inlogde. Lees het zoals een arts bloedonderzoek leest: niet regel voor regel, maar op patroon, ernst en verandering over tijd.

Zoek eerst het log

De helft van het werk op een onbekende server is uitvinden waar PHP eigenlijk naartoe schrijft. Het geconfigureerde pad staat in de geladen php.ini. Vraag het PHP zelf:

php -i | grep -E 'error_log|log_errors|display_errors'

De output ziet er ongeveer zo uit:

error_log => /var/log/php/error.log => /var/log/php/error.log
log_errors => On => On
display_errors => Off => Off

Op een CMS-installatie is er meestal een tweede log. WordPress schrijft naar wp-content/debug.log als WP_DEBUG_LOG aanstaat. Drupal slaat entries standaard op in de watchdog-tabel, te bekijken op /admin/reports/dblog. Magento verdeelt over var/log/system.log, var/log/exception.log en var/log/debug.log. Tail ze allemaal tegelijk, anders mis je de helft van het verhaal:

tail -F /var/log/php/error.log \
  /var/www/wp-content/debug.log \
  /var/log/nginx/error.log

De severity-ladder

PHP groepeert errors in categorieën die ertoe doen bij triage. Een PHP error log als één ongedifferentieerde brij behandelen is dezelfde fout als kijken naar een volledig bloedbeeld en alleen opmerken dat "een paar waarden buiten de range vallen". Elke categorie wijst op een ander soort falen.

• E_PARSE: het bestand compileerde niet. Een deploy ging fout. De site ligt hard plat.
• E_ERROR / E_FATAL: runtime gestopt. Ontbrekende class, undefined function, geheugen op, max execution time gehaald. Een deel van de requests geeft een 500.
• E_WARNING: PHP ging door, maar de operatie faalde. Bestand niet gevonden, database connection geweigerd, deling door nul op oudere versies. Vaak het eigenlijke signaal.
• E_NOTICE: undefined index, undefined variable. Meestal ruis, maar een vloedgolf ervan is een aanwijzing dat code state leest die nooit geschreven is.
• E_DEPRECATED: werkt vandaag, breekt op de volgende PHP-minor. Lees deze door voor elke 8.x-upgrade.
• E_USER_*: iemand riep trigger_error() aan in applicatiecode. Behandel als bewust geplaatst.

De officiële constants-reference bevat de volledige lijst. Zet hem in je bookmarks.

Tempo, niet absoluut aantal

Eén fatal om 03:14 betekent één gebruiker, één bug, waarschijnlijk allang weg. Vierduizend warnings per uur betekent dat er iets in een hot path stuk is, en het is stuk sinds het tempo begon te stijgen. Het eerste wat je berekent bij het lezen van een PHP error log is het tempo, niet het aantal.

awk '{print substr($0, 1, 13)}' /var/log/php/error.log \
  | sort | uniq -c | tail -24

Dat geeft je uurbuckets voor de afgelopen dag. Een regel als [26-May-2026 14 met 3812 ervoor is het uur waarop de piek begon. Vergelijk met het deploy-log, de cron-schedule en het traffic-dashboard. Negen van de tien keer valt de piek samen met één van die drie.

Om de grootste vervuilers per bericht te vinden:

grep -oE 'PHP [A-Z][a-z]+( [a-z]+)*:.*' /var/log/php/error.log \
  | sed 's/line [0-9]\+/line N/' \
  | sort | uniq -c | sort -rn | head -20

De sed normaliseert regelnummers, zodat dezelfde error uit een templated loop in één bucket valt. Anders krijg je tachtig varianten van dezelfde warning en verdwijnt het signaal.

Veelvoorkomende syndromen en wat ze betekenen

Na een paar honderd sites worden bepaalde foutmeldingen diagnostische shortcuts. Net zoals een laag MCV plus laag ferritine vrij betrouwbaar op ijzergebreksanemie wijst, wijzen bepaalde PHP-meldingen betrouwbaar op één onderliggende oorzaak.

Geheugen en tijd

Allowed memory size of 268435456 bytes exhausted (tried to allocate 4194304 bytes). Het getal tussen haakjes is de diagnose. Probeerde PHP bij het sneuvelen vier megabyte te allokeren, dan is het lek geleidelijk: een loop die objecten ophoopt, een recursieve walk die niets vrijgeeft. Probeerde hij in één klap 200MB te alloceren, dan laad je iets ongebreidelds in, meestal een query zonder LIMIT of een CSV die compleet in het geheugen wordt gelezen.

Maximum execution time of 30 seconds exceeded. Meestal een trage query, soms een blokkerende HTTP-call naar een externe API die uit timing liep. De stack trace vertelt je welke van de twee. Eindigt het spoor in PDOStatement->execute(), dan is het de database. Eindigt het in stream_socket_client of curl_exec, dan is het het netwerk.

Headers en output

Cannot modify header information - headers already sent by (output started at /path/to/file.php:1). Die "line 1" wijst bijna altijd op een UTF-8 BOM of whitespace vóór de openings-<?php-tag. Open het bestand in een hex viewer als je het niet ziet:

head -c 8 /path/to/file.php | xxd

Zijn de eerste drie bytes ef bb bf, dan heeft het bestand een BOM. Strip hem en de error is weg.

Database

MySQL server has gone away betekent dat de connection halverwege de query stierf. Twee gangbare oorzaken: een query duurde langer dan wait_timeout (vaak 28800 seconden, maar veel managed hosts zetten het op 60), of de query overschreed max_allowed_packet. Het MySQL-errorlog op de databasehost vertelt je welke van de twee.

SQLSTATE[HY000] [2002] No such file or directory betekent dat PDO probeerde te verbinden via een Unix-socket die niet bestaat. De fix is wijzen naar 127.0.0.1 in plaats van localhost, of expliciet unix_socket in de DSN zetten. De PDO MySQL DSN-reference beschrijft het stap voor stap.

Classes en autoloading

Class "App\Foo\Bar" not found op een site die gisteren nog werkte, betekent vrijwel altijd een Composer-autoload die na een deploy niet opnieuw is gegenereerd. Draai composer dump-autoload -o en het symptoom verdwijnt. Zo niet, dan ontbreekt het bestand echt, en moet je kijken naar wat het deploy-script deed, niet naar wat de applicatiecode doet.

Het triage-werkblad

Als het PHP error log overweldigend is, werk je deze vijf vragen op volgorde af. Sla niets over. Meestal valt het antwoord al bij stap twee of drie uit.

1. Verdeling per severity. Hoeveel fatals, warnings, notices in het laatste uur? Zijn er nul fatals, dan staat de site overeind en kijk je naar chronische ruis, niet naar een outage.
2. Clustering in tijd. Veranderde het tempo? Wanneer? Matchen tegen deploys en cron.
3. Clustering per URL. Leg het errorlog naast het access log op dezelfde timestamps. Welk endpoint faalt?
4. Clustering per gebruiker. Is het één gebruiker (kijk naar session-cookies of IP's in het access log) of iedereen? Eén gebruiker betekent meestal input die de code niet verwachtte.
5. Stack-trace-fingerprint. Delen drie traces dezelfde top-frame, dan heb je één bug, geen drie.

Wat je mag dempen, en wat nooit

Na een triage-sessie wil je de ruis wegpoetsen. Hou je in voorbij een bepaald punt. error_reporting in productie staat minstens op E_ALL & ~E_DEPRECATED & ~E_STRICT. display_errors blijft uit in productie. log_errors blijft aan. De error handling configuration-reference is de canonieke bron.

Wat je nooit dempt:

• E_DEPRECATED in de zes maanden vóór een PHP-major-upgrade. Dit is de upgrade-backlog, gratis aangeleverd.
• E_WARNING uit database- of filesystem-aanroepen. Dat zijn de vroege signalen dat een credential, een pad of een permission stuk is.
• Alles uit trigger_error() in code die je zelf bezit. Je vroegere zelf zette die er met reden neer.

Wat veilig te dempen is:

• E_NOTICE over undefined indexes in third-party-plugincode die je niet bezit en niet kunt patchen. Filter ze met een custom error handler, in plaats van de hele categorie globaal uit te zetten.

Het log bruikbaar houden over de tijd

Een errorlog van 2GB is een teken dat er al een jaar niemand naar gekeken heeft. Roteer hem. Op een Debian- of Ubuntu-host zet je een bestand in /etc/logrotate.d/php:

/var/log/php/error.log {
    daily
    rotate 14
    compress
    delaycompress
    missingok
    notifempty
    create 0640 www-data adm
    postrotate
        /usr/sbin/service php8.2-fpm reload > /dev/null 2>&1 || true
    endscript
}

Twee weken bewaartermijn is genoeg om met de meeste deploys te correleren. Heb je langer nodig, ship dan naar een centrale loghost in plaats van het bestand voorbij een gigabyte te laten groeien.

Op een draaiende legacy site is het PHP-errorlog ook de goedkoopst denkbare monitoring. Een nachtelijke cron die op nieuwe fatal-patronen grept en de diff mailt, vangt de trage afwijking op die een uptime-monitor nooit ziet, omdat de site nog netjes 200s blijft serveren.

Hoe wij dit zijn gaan oplossen

Toen we Pier bouwden, liepen we op klantsites precies hier tegenaan: bureaus die een PHP-applicatie erven met een log waar sinds het vertrek van de oorspronkelijke developer niemand meer naar gekeken heeft. Wat we uiteindelijk deden, is van het errorlog een eersteklas-paneel maken in de app, naast de MySQL editor en de version history, zodat een vrijdagmiddag-500 triëren geen drie SSH-sessies en een privé-cheatsheet meer vereist.

Eén klein ding dat je vandaag kunt doen

Open het PHP errorlog op één productiesite die je beheert. Draai de uurtempo-awk-oneliner hierboven. Heeft het hoogste uur in de laatste 24 meer dan honderd entries, dan heb je iets dat tien minuten onderzoek waard is voordat de week om is. Dat is de hele veldtest.