WooCommerce dubbele afschrijvingen: payment_complete hook

Om 14:12 op een dinsdag pingde een Nederlands bureau waar we mee samenwerken ons met een korte Loom. Hun klant, een middelgrote shop op WooCommerce 8.4 met PHP 8.1, had sinds de lunch zeven bestellingen binnengekregen. Op elke bestelling stonden twee Stripe-afschrijvingen, negentig seconden uit elkaar, zelfde bedrag, zelfde kaart, allebei gecaptured. De klantenservice-inbox stond al zes mails diep. De lead van het bureau had twintig minuten voor een call en stelde de enige nuttige vraag: ligt het aan Stripe of aan ons.

Aan hen. Bijna altijd. Een betaalprovider die negen miljoen bedrijven draait, begint niet op een willekeurige dinsdagmiddag opeens kaarten dubbel te belasten; een legacy site die in achttien maanden vier freelancers en drie plugin-updates heeft gezien, wel. Dit is de walkthrough van de volgende twee uur: hoe we een WooCommerce-dubbele afschrijving terugbrachten tot een dubbele payment_complete hook, wat de database vertelde voordat de logs dat deden, en welke kleine aanpassingen in .htaccess en PHP de schade stopten voordat de middag voorbij was.

De eerste negentig seconden: de vorm van de bug bevestigen

Voordat we ook maar één regel code aanraakten, wilden we weten of dit een Stripe-side retry was of een WooCommerce-side dubbele uitvoering. Dat verschil is belangrijk. Een Stripe-retry laat alleen in pathologische gevallen twee PaymentIntents met verschillende ID's zien; de meeste retries hergebruiken hetzelfde pi_-ID, want dat is precies waar een idempotency key voor bedoeld is: voorbijgaande netwerkfouten overleven zonder dubbel af te schrijven. Een WooCommerce-dubbele uitvoering laat twee PaymentIntents aan dezelfde order hangen, elk apart gecaptured. Hetzelfde symptoom; totaal andere oorzaak, totaal andere impact.

We openden de wpdb-tabellen wp_woocommerce_order_items en wp_postmeta en draaiden een snelle check op het laatste uur aan orders. We hadden geen zin in SSH of in de analytics van WooCommerce zelf; de MySQL editor gaat regelrecht op de data af:

SELECT post_id AS order_id,
       meta_value AS stripe_charge_id,
       COUNT(*)   AS hits
FROM   wp_postmeta
WHERE  meta_key = '_stripe_charge_id'
  AND  post_id IN (
    SELECT ID FROM wp_posts
    WHERE  post_type = 'shop_order'
      AND  post_date > NOW() - INTERVAL 2 HOUR
  )
GROUP BY post_id, meta_value
HAVING hits > 1;

Nul rijen. Op zich al informatief. De charge-ID's verschilden per poging; geen enkele charge-ID werd dubbel weggeschreven. Dus we trokken de blik wat breder en vroegen de tabel om elke charge-gerelateerde rij op de meest recente getroffen order, in volgorde van invoegen:

SELECT post_id, meta_key, meta_value
FROM   wp_postmeta
WHERE  meta_key IN ('_stripe_charge_id', '_transaction_id', '_paid_date')
  AND  post_id = 48217
ORDER BY meta_id;

Order 48217 had twee _stripe_charge_id-rijen en twee _paid_date-rijen, tweeënnegentig seconden uit elkaar. Twee aparte PaymentIntents, allebei gecaptured, allebei gekoppeld aan dezelfde WooCommerce-order. Daarmee viel een Stripe-netwerk-retry af; hun idempotency-model zou twee identieke pogingen tot één hebben gemaakt. Iets binnen de site verwerkte dezelfde checkout twee keer en vroeg Stripe om voor allebei te incasseren.

De order notes lezen als een vluchtrecorder

WooCommerce schrijft bij bijna elke statuswijziging een order note weg. De notes-tabel is wat het platform het dichtst bij een vluchtrecorder heeft, en hij wordt tijdens incidenten misdadig weinig gebruikt. De meeste bureaus grijpen eerst naar het access log of het PHP error log; allebei vertellen ze je dat de pagina is opgevraagd, geen van beide vertelt wat het order-object binnen die request heeft gedaan. De order notes wel. We trokken ze op voor 48217:

SELECT comment_date, comment_content
FROM   wp_comments
WHERE  comment_post_ID = 48217
  AND  comment_type   = 'order_note'
ORDER BY comment_date;

De output vertelde het hele verhaal in acht regels. Geparafraseerd:

• 14:03:11 — Orderstatus gewijzigd van pending naar processing.
• 14:03:11 — Stripe charge complete (Charge ID: ch_3PA...XQ).
• 14:03:12 — Voorraad verlaagd voor product #882.
• 14:03:12 — Orderstatus gewijzigd van processing naar processing (geen wijziging).
• 14:04:43 — Stripe charge complete (Charge ID: ch_3PA...ZK).
• 14:04:43 — Voorraad verlaagd voor product #882.

Twee "Stripe charge complete"-notes, tweeënnegentig seconden uit elkaar. Twee voorraadverlagingen. En daartussen een statusovergang van processing naar processing die helemaal niets had moeten doen. Dat is de handtekening van payment_complete() die twee keer wordt aangeroepen op een order die al betaald is. WooCommerce' WC_Order::payment_complete() hoort idempotent te zijn ten opzichte van dezelfde orderstatus, maar alleen als de gateway de huidige status van de order respecteert. Komt er een tweede aanroep binnen met een ander transaction-ID, dan vuurt hij vrolijk de woocommerce_payment_complete action opnieuw af, inclusief alle hooks die eraan hangen, gateway-captures incluis.

De dubbele voorraadverlaging in de notes is het rokende pistool. Eén legitieme overgang van pending naar processing verlaagt de voorraad één keer. Een tweede passage door dezelfde hook verlaagt hem nog eens, en bij een SKU met krappe voorraad is dat hoe een gezond product tegen lunchtijd al oververkocht is. Drie dagen later had het bureau aan een andere call gezeten over voorraadafwijkingen; we hebben het er nog op tijd uitgevangen.

De notes zijn makkelijk over het hoofd te zien omdat ze in de wp_comments-tabel staan, niet in een voor de hand liggende order-namespace. WordPress hergebruikt wp_comments voor productreviews, order notes en gewone blogreacties; tools die alleen wp_posts en wp_postmeta indexeren, missen ze. WP-CLI's wc shop_order get slaat ze ook over. De snelste manier om ze op een live site te lezen is de SQL hierboven of het orderbewerkscherm, en de SQL wint elke keer dat je twee orders naast elkaar wilt vergelijken.

De tweede aanroeper vinden

Twee aanroepers, allebei met payment_complete. De eerste is de Stripe-webhookhandler, het canonieke en ondersteunde pad. Wat is dan de tweede? We grepten het actieve thema, de mu-plugins map en eventuele drop-ins op de voor de hand liggende verdachten, met uitzondering van de gateway-plugin zelf zodat we ons op de clientcode konden richten:

grep -rn "payment_complete" wp-content/ \
  --include="*.php" \
  --exclude-dir=woocommerce \
  --exclude-dir=woocommerce-gateway-stripe

Drie matches. Twee waren voor ons relevant:

// wp-content/plugins/woocommerce-gateway-stripe/includes/class-wc-stripe-webhook-handler.php
$order->payment_complete( $intent->id );

// wp-content/mu-plugins/abandoned-cart-recovery.php
$order->payment_complete( $charge_id );

// wp-content/themes/clientchild/inc/checkout-confirm.php
WC()->cart->empty_cart();
$order->payment_complete( $txn );

Twee aanroepers in clientcode. Allebei geschreven door een eerdere freelancer. De mu-plugin was op zich onschuldig; hij werd afgeschermd door een orderstatuscheck (if ( $order->has_status( 'pending' ) )) die de tweede aanroep kortsluitte zodra de webhook de order al als betaald had gemarkeerd. Het themabestand niet. checkout-confirm.php werd geïnclude door een bedankpagina-template dat bij elk bezoek aan /checkout/order-received/ draaide. Als een klant de pagina ververste, of als Stripe's redirect een fractie eerder binnenkwam dan de webhook, vuurde de tweede payment_complete() af met een nieuw transaction-ID, en de gateway capturede plichtsgetrouw een verse PaymentIntent.

Een git blame op de regel in kwestie leverde de verantwoordelijke commit op, de PR-omschrijving en de datum waarop de aanroep was toegevoegd: elf maanden eerder, door een freelancer die het bureau inmiddels had verlaten. De PR-titel verraadde het al: "fix order received page sometimes blank". Wie die regel had geschreven, had een bedankpagina die niet rendeerde en greep naar payment_complete() omdat hij of zij dat elders in de codebase had zien werken. Het was beter geweest om uit te zoeken waarom de pagina leeg was, maar de freelancer was er vrijdag uit en de regel bleef staan.

De vingerafdruk zat in het tijdsverschil. Negentig seconden is ongeveer hoe lang het een afgeleide klant kost om de bevestigingspagina te verversen omdat ze zich afvragen of de bestelling wel is doorgekomen. Lang genoeg dat de webhook is binnengekomen en de order als betaald heeft gemarkeerd; kort genoeg dat de klant nog op het tabblad zit als de tweede afschrijving binnenkomt. Bij mobiele gebruikers was het erger; op een telefoon was het gat krapper, omdat Safari's back-button restore de request opnieuw afvuurt zonder vooraf om bevestiging te vragen.

De noodgreep en de echte fix

De bloeding moest stoppen voordat we over architectuur konden praten. De kleinste veilige wijziging was het dubbele pad kortsluiten. We wilden het themabestand niet hard uitschakelen, voor het geval downstream code in dezelfde include legitiem werk deed ná de payment_complete-regel, en een harde verwijdering had op dat moment een volledige thema-deploy betekend, terwijl elke wijziging risico droeg. We maakten een back-up van het bestand, plakten er bovenaan een guard in en pushten het:

// wp-content/themes/clientchild/inc/checkout-confirm.php
if ( $order->is_paid() || $order->get_date_paid() ) {
    return;
}

// Originele regel, nu onbereikbaar voor betaalde orders.
$order->payment_complete( $txn );

De is_paid()-check dekt de gedocumenteerde betaalde statussen van WooCommerce (processing, completed en eventuele custom statussen die via het filter woocommerce_order_is_paid_statuses zijn geregistreerd). De get_date_paid()-check is de bretels op de riem, want sommige Stripe-flows markeren de order als betaald vóórdat de statusovergang volledig commit, en er bestaat een korte window waarin is_paid() false meldt terwijl _paid_date al gevuld is. Samen sluiten de twee checks de race.

We overwogen om in plaats daarvan de Stripe-gateway-plugin te patchen, zodat die een tweede payment_complete op een al betaalde order zou weigeren, ongeacht het transaction-ID. Dat is de architectonisch juiste fix en het had elke aanroeper in één klap dichtgetimmerd. We hebben het niet gedaan. Een onderhouden plugin-bestand patchen betekent bij elke release leven met een merge conflict, en het bureau liep al drie versies van de Stripe-gateway achter. De lokale guard was omkeerbaar, lokaal in te dammen en oplosbaar door wie er als volgende naar het bestand kijkt.

Daarna voegden we een .htaccess-regel toe zodat de bevestigingspagina niet meer met POST aanroepbaar was via een stale formulier-resubmit, het derde theoretische pad naar een dubbele fire:

<LocationMatch "^/checkout/order-received/">
    <LimitExcept GET HEAD>
        Require all denied
    </LimitExcept>
</LocationMatch>

De Apache-documentatie over LimitExcept is om de paar jaar het herlezen waard; het is een van de weinige directives die letterlijk doet wat de naam zegt. Alles wat niet in de toegestane werkwoordenlijst staat, krijgt een 403, en daar hoeft de order-received pagina niets mee te doen, want niks legitiems POST'et er nog naartoe nadat de eerste gateway-rondreis is voltooid.

Met de noodgreep live deden we een testcheckout. Eén afschrijving. Bevestigingspagina acht keer ververst. Eén afschrijving. Met de terugknop terug naar het formulier en opnieuw verstuurd; Apache gaf 403 terug en de order bleef schoon. We hielden de order notes tien minuten lang in de gaten over negen echte klant-checkouts heen. Eén afschrijving per order. Om 16:09 was het incident voorbij.

Wat we hebben teruggestort, en hoe we iedereen vonden

De schade van de middag werd ingekaderd door de SQL die we als eerste hadden gedraaid. We trokken elke order uit de laatste achtenveertig uur op met meer dan één _stripe_charge_id, kruisten ze via de order-ID's in het description-veld met het Stripe-dashboard, en stortten de tweede capture op elke order terug. Drieëntwintig orders. We kozen voor de latere van de twee afschrijvingen om terug te storten (in plaats van de eerdere), zodat het bankafschrift van de klant een directe terugbetaling van de meest recente regel liet zien in plaats van een vertraagde terugbetaling van iets dat ze mentaal al hadden geaccepteerd.

De eigenaar mailde elke klant persoonlijk voordat ze er zelf om hoefden te vragen. Twee reageerden met dank. De andere eenentwintig hadden het nog niet gemerkt, omdat de tweede afschrijving nog niet op hun afschrift stond; pending autorisaties bij de meeste banken settelen binnen achtenveertig uur, en we waren ze voor met de breedte van een koffiepauze. Dat is de enige manier waarop je uit een dubbele-afschrijvingsincident komt met goodwill nog intact: terugstorten voor de chargeback, mailen voor de klacht.

Voor de langere-termijnopruiming maakten we van de diagnostische SQL een cron die elke vijf minuten draait en het #incidents-kanaal van het bureau pingt bij elke order met meer dan één _stripe_charge_id. In de acht weken sindsdien is hij nul keer afgegaan. Het themabestand is uiteindelijk herschreven om payment_complete() er volledig uit te halen; de bevestigingspagina leest nu order state, hij schrijft er niet meer in. Maar de guard blijft staan, want de volgende freelancer voegt de regel misschien weer toe en dan zien we liever dat hij op een no-op stuit dan op een afschrijving.

De vorm die blijft terugkomen

Toen we Pier bouwden, kwamen we precies deze vorm bug in één kwartaal op drie verschillende klantsites tegen, en dat is de reden dat de database en de bestands-editor naast elkaar in één venster zitten, met elke save getagd in de version history voor een rollback met één klik. De twee vragen die je tijdens een afschrijvingsincident stelt, wat zegt de order-tabel en wie roept deze functie aan, zouden geen twee SSH-sessies en een koffie hoeven kosten.

Als je een WooCommerce-site draait die je niet zelf hebt opgebouwd, grep dan vandaag je thema en de mu-plugins map op payment_complete. Alles buiten de gateway-plugin heeft een paid-status guard nodig of het moet weg. Dat is het tien-minutenklusje dat je de slechte middag bespaart.