Een query van 30 seconden die ik zes maanden te laat draaide

Meer dan zes maanden lang ging de WorkWear4All storefront elke nacht een paar minuten offline. Ik wist dat het gebeurde. Het bureau dat het platform had gebouwd wist het. Onze hosting provider wist het. Drie externe Magento integrators die we op verschillende momenten in die periode raadpleegden wisten het. Geen van hen kon me vertellen waarom, en ik kon de tijd om door te blijven graven niet rechtvaardigen — er stond altijd iets zichtbaarders op de queue, de outage was klein genoeg om op te vangen, en de gedeeltelijke fix die we al hadden draaien was net stabiel genoeg om de urgentie weg te nemen.

De daadwerkelijke oorzaak was een query van dertig seconden tegen information_schema. Ik had hem in de eerste maand moeten draaien.

Magento 2 is niet gebouwd voor een catalogus van de omvang die wij draaien. Met 800K+ producten, waarbij elk product dagelijks wordt aangeraakt voor voorraad- en prijssync vanuit leveranciers, kan de indexer de _cl changelog tabellen niet sneller leegmaken dan het platform erin schrijft, en de storefront betaalt uiteindelijk voor die mismatch — in ons geval met een korte outage elke nacht, op het moment dat iets in de indexing pipeline het opgaf, herstartte, en opnieuw inhaalde. Het platform zelf geeft geen signaal dat dit gebeurt. Er is geen waarschuwing in de admin UI, geen indexer status die rood kleurt voordat het symptoom op de storefront verschijnt, geen log line die naar de root cause wijst. En de fix — als je hem eenmaal hebt gevonden — staat op minstens drie publieke plekken gedocumenteerd, en geen daarvan komt naar boven als je een Magento expert vraagt om naar het symptoom te kijken.

Dat is het deel van het verhaal dat ik wil opschrijven. Niet “ik vond een slimme fix” — de fix is bekend als je vanuit de operationele kant gaat zoeken. Wat het waard is om te benoemen is dat het antwoord bestaat, dat geen enkele expert die ik vroeg het kon ophalen, en dat dat een failure mode is van het ecosysteem rond het platform die het waard is om eerlijk over te schrijven.

De vorm van de install

Over de WorkWear4All stack heb ik geschreven in de introductiepost op deze site — multi-store Magento 2 over een half dozijn Europese domeinen (workwear4all.nl, workwear4all.be, workwear4all.de, workwear4all.com, workwear4all.pl en nog een aantal meer gespecialiseerde sub-stores), een gedeelde backend op Apache + Varnish + PHP-FPM + Redis. Het stuk dat voor dit verhaal van belang is, is de catalogus-schaal en het update-patroon.

De catalogus is 800K+ producten, een mix van simple en configurable, opgehaald via de dagelijkse exports van leveranciers. Elk product wordt één keer per dag aangeraakt voor voorraad- en prijssync vanuit de leveranciers-feeds. Dat zijn minstens 800K product updates per dag op het bronniveau, en omdat Magento’s catalogus-indexers ingeschreven staan op productwijzigingen — price, category-product, catalogsearch_fulltext, stock, de lijst gaat door — waaiert elk van die bron-updates uit naar een _cl-rij voor elke ingeschreven indexer. Het write-volume per dag in de changelog tabellen loopt op tot in de miljoenen.

De most-pinned indexer was altijd catalogsearch_fulltext. Hij was degene die als eerste achterop raakte, het hardst achterop raakte, en bovenaan de indexer status stond zodra er iets misging. Wij zitten op Magento 2.4.7, de minor release direct voor de 2.4.8 default-omschakeling naar Update by Schedule — dus het schedule-mode gedrag dat hieronder beschreven wordt, is iets dat we bewust hebben aangezet, niet iets dat we als default hebben geërfd.

Wat we als eerste probeerden, en waarom de gedeeltelijke fix het slechtst mogelijke resultaat was

Voordat we bij de daadwerkelijke fix uitkwamen, probeerden we het voor de hand liggende. We installeerden Advanced Index Manager by Magefine, die het indexing-proces in batches verwerkt zodat hij niet probeert in één tick door de hele changelog heen te kauwen. De indexer werd er stabieler door. De outages werden korter en minder frequent. Ze stopten niet helemaal.

Die gedeeltelijke fix is het moment dat ik wil markeren. Zodra de storefront genoeg overeind stond om niet langer een dagelijkse brand te zijn, viel de druk om de daadwerkelijke oorzaak te vinden weg. De Magefine module leverde ons zes maanden op van “stabiel genoeg dat de outage niets urgents blokkeert” — wat klinkt als een goede uitkomst en achteraf het slechtst mogelijke resultaat is, omdat het wegnemen van de urgentie ook het tijdsbudget wegneemt voor het diepere onderzoek dat het probleem daadwerkelijk had opgelost. We zijn er niet mee gestopt. Het verloor het alleen steeds van de volgende brand.

Ik wist, na zes maanden, dat ik dit niet snel zou vinden. Ik werkte ongeveer net zo lang met Magento 2, en ik wist genoeg om te weten dat zoiets diagnosticeren, zo diep in de indexer pipeline, significant veel tijd zou gaan kosten die ik niet had. Het bureau dat het platform had gebouwd had het niet gevonden. Onze hosting provider, die zelf Magento ervaring heeft, had het niet gevonden. De drie externe integrators die we in die periode hebben aangeschreven hadden het ook niet gevonden. De gesprekken eindigden allemaal op dezelfde manier: iemand keek even, kon zijn vinger er niet op leggen, en ging door.

Achteraf gezien was de diagnose niets meer dan goed naar de database kijken voor een afwijking. Ik weet nog steeds niet zeker waarom niemand — ik zelf incluis, zes maanden lang — dat heeft gedaan.

Wat er daadwerkelijk gebeurde

De fix is operationeel simpel zodra je hem ziet.

Magento 2’s “Update by Schedule” indexing mode is gebouwd rondom materialised view changelogs. Elke indexer subscribet zich op een set source tables; zodra er een rij in een source table wijzigt, wordt er een entry weggeschreven naar een corresponderende _cl table voor elke ingeschreven indexer. De indexer cron leest op een tick de nieuwe entries uit elke _cl table, verwerkt ze, en ruimt ze op. Het geheel hoort zichzelf in evenwicht te houden: writes stromen de changelog in, de cron draint ze, en de indexes blijven actueel.

Het model gaat ervan uit dat de cron kan bijhouden. Met 800K+ producten die dagelijks worden geüpdatet, tegenover het half dozijn indexers dat ingeschreven staat op productwijzigingen, loopt het write-volume per dag in de changelog tabellen op tot in de miljoenen. De indexer cron, die entries sequentieel via PHP verwerkt, kan op de hardware waar hij op zit niet zo snel drainen. De tabellen groeien. Ze blijven groeien. Elke dagelijkse catalogus-import voegt een laag backlog toe die de cron niet meer gaat inhalen, omdat de import van morgen er al aankomt.

Wat er gebeurt zodra een _cl table voorbij de specifieke drempel groeit die de bijbehorende indexer niet meer aankan — te veel geheugen opgeslokt door de in-flight batch, een query timeout, een lock die nooit vrijkomt, een indexer-proces dat door de OOM killer wordt afgeschoten — is dat de indexer uiteindelijk faalt, herstart, en probeert in te halen vanaf waar hij was gebleven. Tijdens die inhaalslag is de storefront kort inconsistent of niet meer responsief, afhankelijk van welke indexer is omgevallen. In ons geval was de most-pinned altijd catalogsearch_fulltext, en dat is ook de indexer waarbij een stall het meest zichtbaar is voor een klant, omdat hij de productzoekfunctie van de storefront afsluit.

De diagnose die ik uiteindelijk draaide, was één enkele query tegen information_schema die alle _cl tables listte op rij-aantal, aflopend gesorteerd. De grootste changelog tabellen kwamen terug op zo’n 902 miljoen rijen — een getal uit mijn hoofd, want ik heb de originele output niet bewaard en de tabellen zijn allang getruncate. De vorm was onmiskenbaar: de indexer cron was niet aan het drainen; hij werd elke dag ingehaald door de catalogus-import van de volgende dag.

De cron, en wat hij wel en niet oplost

De standaard index cron group draait niet op deze server. De schedule-mode incremental processing die hij zou doen — uit _cl tables lezen, ze drainen, ze opruimen — is precies het ding dat onze update-volume sowieso niet bijhoudt; de cron group is uitgeschakeld, en een nachtelijke full reindex from source doet het werk waarvan de incremental drain verondersteld werd het te doen. Die nachtelijke run is de cron die ik wil doorlopen.

Hij voert drie operaties uit, in deze volgorde:

1. Full reindex — bin/magento indexer:reindex herbouwt elke index direct vanuit de source tables, en omzeilt het changelog mechanisme volledig.
2. Truncate elke _cl table — zodra de reindex authoritative indexes heeft geproduceerd, zijn de opgehoopte changelog entries obsoleet en is de ruimte die ze innamen dead weight.
3. Reset elke mview_state cursor — UPDATE mview_state SET version_id = 0 voor elke rij. Dit is precies de stap waar de waarschuwingspost van Max Chadwick over gaat; zonder die stap breekt post-truncate changelog tracking in stilte.

De volgorde doet ertoe. Door de reindex eerst te doen, blijven — als de reindex zelf faalt: out-of-memory, lock contention, een query timeout — de opgehoopte changelog entries op hun plek staan en heeft het schedule-mode mechanisme (voor zover het werkt) nog steeds zijn baseline state om op terug te vallen. Als we eerst zouden truncaten en de reindex zou falen, zouden we achterblijven met lege changelog tabellen en indexes in de kapotte staat van vóór de cron, wat strikt slechter is dan waar we begonnen. De destructieve operaties na de reindex sequencen, zet een gedeeltelijke failure om in een silent no-op in plaats van een outage.

Ontdaan van de interne wrapper waar ik hem doorheen draai, zien de operaties er zo uit:

#!/usr/bin/env bash
set -euo pipefail

# Run from the Magento root, with DB credentials configured (e.g. via
# ~/.my.cnf or environment) so the mysql calls below pick them up.

# 1. Full reindex — rebuild every index directly from source.
php bin/magento indexer:reindex

# 2. Truncate every changelog table; the freshly rebuilt indexes have
#    made the accumulated changelog entries irrelevant.
TABLES=$(mysql -N -e "
  SELECT TABLE_NAME
  FROM information_schema.tables
  WHERE table_schema = DATABASE()
    AND TABLE_NAME REGEXP '_cl\$';
")

for t in $TABLES; do
  mysql -e "TRUNCATE TABLE \`$t\`;"
done

# 3. Reset every mview_state cursor to zero. This is the step Chadwick's
#    warning is about — without it, post-truncate changelog tracking
#    silently breaks.
mysql -e "UPDATE mview_state SET version_id = 0;"

Dit draait elke nacht. De storefront is stabiel sinds we het hebben uitgerold, en zelfs na ongeveer een week normale operatie zit de grootste _cl table op zo’n 9 miljoen rijen — ruwweg een honderdste van de 902 miljoen die we vonden op het moment van ontdekking. Een paar neveneffecten klaarden in dezelfde periode ook op — het meest opvallend een terugkerend probleem dat we hadden met prijsupdates die niet doorkwamen naar de storefront, waarbij de price indexer in stilte achterop raakte en klanten oude prijzen te zien kregen. Dat is ook gestopt met gebeuren. Ik kan het niet volledig aan de cron toeschrijven — het kan het oorspronkelijke schedule-mode mechanisme zijn geweest dat achterop raakte, het kan gerelateerd zijn geweest aan de Chadwick failure mode voordat de version_id-reset op zijn plek stond, het kan een ongerelateerde coïncidentie zijn geweest met een server- of SQL-restart — maar het is niet teruggekomen sinds de huidige setup draait.

Ik wil eerlijk zijn over wat deze fix is. Het is geen root-cause fix. De root cause is dat de indexer-architectuur van Magento 2 niet ontworpen is voor een catalogus van deze omvang met dit update-patroon. De cron koopt tijd door elke nacht als schone lei te behandelen; de onderliggende mismatch tussen het indexing-model van het platform en onze operationele realiteit blijft hetzelfde. Als de catalogus blijft groeien of het dagelijkse update-volume nog verder oploopt, stopt ook dit met werken. De cron is een workaround.

Naast deze fix hoort ook een serieuze waarschuwing. Max Chadwick heeft een post met de titel “Don’t TRUNCATE the _cl tables” waarin hij — terecht — beargumenteert dat naïef truncaten van de changelog tabellen zonder de version_id in mview_state te resetten, de install in een staat brengt waarin changelog-based indexing in stilte breekt, en zich manifesteert als updates die nooit de storefront bereiken. De cron hierboven doet de version_id-reset expliciet, als stap drie; de reset is het stuk dat de specifieke failure mode van Chadwick afsluit. Een lezer die de truncate-stap kopieert zonder de reset, stelt zichzelf bloot aan precies de bug waarvoor Chadwick waarschuwt.

Er is nog één operationele tradeoff die het waard is om expliciet te benoemen, voorbij de “het is een workaround”-framing hierboven. Met de standaard incremental indexer cron group uitgeschakeld en een nachtelijke full reindex die al het werk doet, worden de indexes overdag niet actueel gehouden — ze halen 's nachts in. Dat betekent dat er een bekend staleness window is van tot vierentwintig uur voor elke catalogus-wijziging die tussen reindex runs in wordt gemaakt. Voor ons update-patroon, waar leveranciers-feeds op een dagelijkse cadans draaien en de storefront ruim tolerant is voor licht verouderde categorie- en zoekresultaten, zijn dat acceptabele kosten. Voor een shop waarbij de catalogus wijzigingen binnen minuten moet weerspiegelen — flash sales, time-limited inventory, alles waar intra-day freshness toe doet — werkt deze setup niet; je zou óf de incremental cron group moeten laten draaien en een andere manier moeten vinden om het changelog-volume af te handelen, óf vaker dan één keer per nacht moeten rebuilden.

De eerlijke conclusie: ik weet nog steeds niet zeker of dit precies de juiste manier is om het aan te pakken. Hij werkt en de uptime is drastisch verbeterd. Die zin is de echte rand van mijn begrip, en de post is met die zin op de pagina nuttiger dan zonder.

Waarom geen van de experts hem vond

Ik wil terugkomen op het sociale deel van dit verhaal, want dat is het deel dat verder strekt dan deze specifieke bug.

Vijf aparte partijen hebben naar het probleem gekeken voordat ik het oploste. Het bureau dat het platform had gebouwd. Onze hosting provider. Drie externe Magento integrators. Geen van hen kwam met de changelog-table-invalshoek. De fix is niet obscuur — toen ik het achteraf nakeek, stond hij gewoon op de eerste pagina van de zoekresultaten voor “magento truncate _cl tables.” Max Chadwick heeft erover geschreven (er overigens tegen gewaarschuwd). De mgt-commerce knowledge base heeft een stap-voor-stap tutorial die bijna exact de cron doorloopt die ik heb gebouwd. De Magento GitHub repository heeft een open issue (#29789) waarin het probleem upstream wordt erkend. Er is zelfs een Packagist module die de fix in een extensie verpakt. De fix is gedocumenteerd.

Hij is alleen onbereikbaar vanaf de symptoomkant. Zoek op “magento storefront down at night” of “magento intermittent outage” of “magento indexer stuck” en de changelog-table-invalshoek komt niet naar boven. De expert die je om hulp vraagt komt er vanaf jouw symptoom ook niet, omdat hun mentale model vertrekt vanuit dezelfde set zoektermen als die van jou. De vindbaarheid stort in op de symptoomlaag, niet op de documentatielaag. Het antwoord ligt in het volle zicht onder een zoekterm waar je niet aan hebt gedacht om te proberen, en de experts hebben er niet aan gedacht om hem voor jou te proberen omdat het niet de term is die zij zouden associëren met wat je beschreef.

De les die ik hieruit haal — en wat ik anders had gedaan als ik die zes maanden over kon doen — is: minder tijd aan experts vragen besteden en meer tijd kijken naar wat het platform daadwerkelijk voor zich heeft staan. De query tegen information_schema was dertig seconden werk. De Magefine module, die ik in plaats daarvan installeerde, was een echte uitgave en een gedeeltelijke fix die zes maanden zelfgenoegzaamheid opleverde. Eerst naar de database kijken had het grootste deel van die tijd bespaard.

Dit gaat vaker voorkomen, niet minder. Magento 2.4.8 wordt geleverd met een default-wijziging die alle nieuwe indexers out-of-the-box op Update by Schedule zet, en dat is precies de modus waarin dit hele patroon toeslaat. Meer shops staan op het punt een versie van dit verhaal mee te maken.

Waar dit nu staat

De cron is de operationele modus. Er is geen migratie-tijdlijn. De storefront is stabiel, de indexer houdt het bij, en de fix doet zijn werk.

Op de lange termijn denk ik dat het platform niet de juiste match is voor onze use case en gaan we er iets anders omheen ontwerpen. De vorm die ik in gedachten heb is een A/B-style cutover — het nieuwe systeem starten op een van de kleinere storefronts, bewijzen dat het onder live verkeer werkt, en pas daarna nadenken over de grotere migreren. Onze interne tooling heeft de catalogus-data al in een MongoDB backing store staan, dus de data layer voor het nieuwe systeem ligt er; de storefront en de operationele stukken eromheen niet. Er zijn nog geen vaste plannen.

De details van de vervangingsarchitectuur zijn niet iets dat ik nu al publiekelijk wil vastleggen. Wat ik publiekelijk wel zeg, is wat ik heb leren weg te ontwerpen: een indexer-patroon dat een generiek flexibility-first datamodel materialiseert in een set gedenormaliseerde indexes via een cron die een changelog moet drainen. Die hele vorm — de EAV-naar-indexer pipeline die Magento 2’s catalogus-architectuur definieert — is het ding waar de cron in deze post omheen patcht, en het is precies wat ik niet wil meenemen in iets nieuws. Wat ik er wél in ontwerp, komt in een aparte post, zodra er iets draait om naar te wijzen, niet eerder. Ik schrijf de tweede poging liever op nadat hij contact met de realiteit heeft overleefd dan dat ik me van tevoren aan details commit.

Het deel waar ik steeds op terugkom

Het principe waar ik op dit punt steeds op terugkom, is dat een gedeeltelijke fix die de urgentie wegneemt, slechter is dan helemaal geen fix. De Magefine module was echt een stuk engineering, hij deed echt werk, en hij maakte de storefront stabieler dan hij was geweest. Hij leverde ons ook zes maanden op van “this is fine,” en tijdens die zes maanden stopte ik met kijken naar het echte probleem, omdat het echte probleem mij geen slaap meer kostte. De volgende brand wint altijd van de smeulende, en de gedeeltelijke fix is wat de brand tot smeulen terugbrengt.

Ik heb geen schone regel die dit in het volgende systeem voorkomt. Het dichtst dat ik bij iets kan komen is: als iets maandenlang te dragen is geweest maar je niet écht hebt begrepen wat het is, behandel dan de tolerantie zelf als het waarschuwingssignaal. De cron in deze post had vijf maanden eerder moeten bestaan dan hij deed. De reden dat hij dat niet deed, is dat er niets genoeg in brand stond om me ertoe aan te zetten hem te bouwen.