Observer-Rekursion in Magento 2: die versteckten Kosten von sales_order_save_after

Der Kunde klickt auf „Jetzt bestellen" und wartet. Fünf Sekunden. Sieben Sekunden. Zehn. Das Stripe-Token ging in 600 Millisekunden durch, wurde auf Stripes Seite freigegeben, im Dashboard geloggt. Der Kunde starrt auf einen Spinner, während Magento damit beschäftigt ist, mit sich selbst zu sprechen.

Du öffnest Blackfire. Irgendwo im Call-Graph taucht Magento\Sales\Model\Order::save() einmal, zweimal, viermal auf, jeweils ineinander verschachtelt. Jeder Aufruf lässt alle Observer auf sales_order_save_after erneut laufen. Jeder Observer speichert den Order erneut. Und jeder dieser Saves lässt alle Observer wieder laufen.

Wir finden das auf den meisten Magento-2-Shops mit Custom-Checkout-Logik. Niemand hat die Schleife absichtlich geschrieben. Drei Entwickler haben über drei Jahre je einen völlig vernünftigen Observer ergänzt. Wenn alle drei in derselben Codebasis geladen sind, speichern die Observer den Order in den Callbacks der anderen, und die Kaskade schreibt sich von selbst.

Magentos Event-System ist synchron. Wenn dein Code $order->save() aufruft, läuft die AbstractModel::save()-Pipeline durch ihr _beforeSave, schreibt die Zeile, und dispatched dann sales_order_save_after. Jeder auf dieses Event subscribete Observer läuft inline, bevor save() zurückkehrt.

Wenn einer dieser Observer im Rahmen seiner Arbeit $order->save() aufruft, passiert der Dispatch erneut. Alle Observer laufen erneut. Wenn einer dieser Observer ebenfalls $order->save() aufruft, passiert der Dispatch ein drittes Mal. Es gibt keinen eingebauten Rekursions-Schutz. AbstractModel::save() verschachtelt sich fröhlich so tief, wie PHPs Stack es zulässt.

Der Grund, warum das auf Magento-2-Shops immer wieder vorkommt, ist, dass „den Order speichern, wenn der Order gespeichert wird" sich wie der naheliegende Ort für Post-Save-Bookkeeping anfühlt. Ein Entwickler hängt sich an sales_order_save_after, schreibt etwas in ein Order-Attribut und ruft save(), um es zu persistieren. Für sich allein ist ein Observer, der das tut, in Ordnung. Die Schleife ist unsichtbar. Die Performance-Kosten sind ein zusätzlicher Save, unangenehm, aber nicht katastrophal.

Die Katastrophe tritt auf, wenn ein zweites Team einen zweiten Observer ergänzt und ein drittes Team einen dritten. Keiner der drei weiß von den anderen. Niemand fährt einen Blackfire-Trace auf dem Checkout. Und eines Tages fragt jemand, warum der Production-Checkout eine zehnsekündige TTFB hat, und der erste Reflex aller ist, das Payment-Gateway zu beschuldigen.

Das Muster, generisch konstruiert: drei Observer aus drei verschiedenen Modulen, jeder für sich vernünftig.

 1<?php
 2// app/code/Acme/Checkout/Observer/SplitOrderData.php
 3final class SplitOrderData implements ObserverInterface
 4{
 5    public function execute(Observer $observer): void
 6    {
 7        $order = $observer->getEvent()->getOrder();
 8        $order->setData('acme_split_segments', $this->splitter->forOrder($order));
 9        $order->save(); // feuert sales_order_save_after erneut
10    }
11}

 1<?php
 2// app/code/Acme/Notifications/Observer/SyncExternalCustomer.php
 3final class SyncExternalCustomer implements ObserverInterface
 4{
 5    public function execute(Observer $observer): void
 6    {
 7        $order = $observer->getEvent()->getOrder();
 8        $this->notifications->push($order);           // HTTP an Freshdesk
 9        $order->setData('acme_notified_at', time());
10        $this->orderRepository->save($order);         // feuert sales_order_save_after erneut
11    }
12}

 1<?php
 2// app/code/Acme/Warehouse/Observer/CheckOrderItems.php
 3final class CheckOrderItems implements ObserverInterface
 4{
 5    public function execute(Observer $observer): void
 6    {
 7        $order = $observer->getEvent()->getOrder();
 8        foreach ($order->getAllVisibleItems() as $item) {
 9            $item->getProduct()->getStockItem(); // N+1 pro Child
10        }
11        $order->setData('acme_items_checked', 1);
12        $order->save(); // feuert sales_order_save_after erneut
13    }
14}

Der erste Save des Orders stößt alle drei Observer an. Jeder speichert. Jeder Save lässt alle drei erneut laufen. Je nach Daten-Flags und Short-Circuits in der Logik jedes Observers landest du irgendwo zwischen vier und einem Dutzend voller Order::save()-Zyklen pro einzelnem platzierten Order. Und wenn einer dieser Observer einen synchronen HTTP-Aufruf macht (der Freshdesk-Push oben zum Beispiel), zahlt jede Kaskadenebene den Netzwerk-Roundtrip erneut.

Du brauchst keinen vollen Performance-Audit, um das zu entdecken. Zwei Optionen.

Option A: Blackfire-Call-Graph. Fahr einen Production-Blackfire-Trace gegen einen platzierten Order (Stage-Environment mit echtem Payment-Gateway im Testmodus tut es). Such im Call-Tree nach Magento\Sales\Model\Order::save. Zähl die inklusiven Aufrufe. Alles über zwei ist wahrscheinlich eine Kaskade; alles über fünf garantiert. Der Call-Graph zeigt dir auch die Observer-Klassen innerhalb jedes Saves, und damit dein Refactor-Ziel.

Option B: ein zehnzeiliger Counter. Wenn du kein Blackfire auf dem Environment hast, dropp dieses Plugin in ein Dev-Modul und leere den DI-Cache:

 1<?php
 2// app/code/Acme/Debug/Plugin/OrderSaveCounter.php
 3final class OrderSaveCounter
 4{
 5    public function beforeSave(\Magento\Sales\Model\Order $order): void
 6    {
 7        error_log(sprintf(
 8            '[order-save-counter] order=%s backtrace=%s',
 9            (string) $order->getIncrementId(),
10            (new \Exception())->getTraceAsString()
11        ));
12    }
13}

Einen Order platzieren. var/log/system.log (oder wohin dein error_log landet) nach order-save-counter greppen. Eine Zeile pro Treffer = ein Order::save()-Aufruf. Vier oder mehr Treffer für eine increment_id und du hast deine Kaskade. Der Backtrace pro Zeile sagt dir genau, welcher Observer die nächste Ebene ausgelöst hat.

Entfern das Plugin wieder, sobald du deine Zahlen hast. Ein Stacktrace-Dump in Production-Observern ist keine gute Idee, außer für gezieltes Debugging.

Das meiste, was deine Observer tun, muss den Kunden nicht blockieren. Freshdesk-Syncs, Order-Split-Berechnungen, Inventar-Benachrichtigungen, systemübergreifende Audit-Logs, all das kann laufen, nachdem die Checkout-Response schon beim Browser ist. Wenn das Business nicht braucht, dass der Sync fertig ist, bevor der Kunde die Danke-Seite sieht, gehört die Arbeit nicht dorthin.

Die Form:

 1<?php
 2final class SyncExternalCustomer implements ObserverInterface
 3{
 4    public function __construct(
 5        private readonly PublisherInterface $publisher,
 6    ) {}
 7 
 8    public function execute(Observer $observer): void
 9    {
10        $order = $observer->getEvent()->getOrder();
11        $this->publisher->publish(
12            'acme.order.sync_external_customer',
13            (int) $order->getId(),
14        );
15    }
16}

Der Handler auf der Queue-Seite lädt den Order frisch, macht den HTTP-Call, aktualisiert das Attribut, speichert einmal. Keine Kaskade. Der Kunde bekommt die Danke-Seite in der Zeit, die es braucht, eine Nachricht auf RabbitMQ zu serialisieren, und das sind auf einem gesunden Cluster einstellige Millisekunden.

Das richtige Event zum Hooken ist sales_order_place_after. Es feuert einmal pro platziertem Order, nicht einmal pro Model-Save. Du bist nicht in einer Schleife, und du musst dir keine Gedanken machen, in welchem der vier kaskadierenden Saves dein Observer gerade landet.

Für Arbeit, die wirklich synchron sein muss, ist der Fix meistens das Event, nicht die Logik. Magentos Checkout-Flow feuert checkout_submit_all_after einmal, nachdem Quote und Order beide committed sind, innerhalb der ursprünglichen Transaktion. Das ist das korrekte Event für jede „im Moment der Order-Platzierung"-Arbeit, die den Order schreibt und atomar mit dem Checkout sein muss.

1<event name="checkout_submit_all_after">
2    <observer name="acme_split_order_data" instance="Acme\Checkout\Observer\SplitOrderData"/>
3</event>

Gleiche Observer-Klasse. Anderes Event. Der Observer läuft jetzt genau einmal. $order->save() darin feuert sales_order_save_after erneut, was immer noch die Observer auf diesem Event laufen lässt, aber der Observer, den du gerade refactored hast, nimmt nicht mehr an der Kaskade teil, weil er nicht mehr an diesem Event hängt.

Die Falle zum Umgehen: sales_order_save_commit_after. Das Event feuert ebenfalls auf jedem Save. Von sales_order_save_after auf sales_order_save_commit_after umzuziehen, mischt die Stühle auf der Titanic neu, fixt aber die Kaskade nicht. Der einzige Fix ist, die save-after-Event-Familie komplett zu verlassen.

Manchmal ist der problematische Observer in Vendor-Code, den du nicht refactoren kannst, ausgeliefert von einem Marketplace-Modul mit einem Support-Vertrag, der Patches verbietet. In solchen Fällen ist der letzte taktische Patch, den äußeren Save davon zu überzeugen, dass er nichts zu schreiben hat, sodass der Dispatch kurzgeschlossen wird.

1$order->setDataChanges(false);
2$order->save();

Wenn data_changes false ist und das Dirty-Attribute-Tracking des Models zustimmt, überspringt die save()-Pipeline das tatsächliche UPDATE und, entscheidend, überspringt das Dispatchen des _save_after-Events komplett. Die Observer-Kette läuft nicht.

Die andere Schwäche dieses Musters: es ist ein Verhaltensänderungs-Patch ohne offensichtlichen Namen. Sechs Monate später schaut ein anderer Entwickler auf die Zeile, hält sie für toten Code und entfernt sie. Die Kaskade kommt zurück. Wenn du das auslieferst, liefer es mit einem Kommentar aus, der das Warum erklärt, einem Link zu diesem Artikel, der Blackfire-Baseline oder dem internen Ticket.

Faustregel: Wenn die Arbeit zum platzierten Order gehört und nicht zu jedem Order-Save, ist das Event falsch. Fix das Event, nicht die Kaskade.

1. 01

   Eine Order-Platzierung tracen

   Blackfire oder Tideways auf einem Staged-Checkout auf dem untersuchten Pfad. Den inklusiven Aufrufcount von Magento\Sales\Model\Order::save notieren. Alles über zwei ist verdächtig.

2. 02

   Jeden Observer auf der save-Event-Familie auflisten

   grep -rn --include='*.xml' -E 'sales_order_save_after|sales_order_save_commit_after' app/code/. Jeder Treffer ist ein Audit-Kandidat. Jeden lesen; jeder Observer, der $order->save() oder $this->orderRepository->save($order) aufruft, steckt in der Kaskade.

3. 03

   Jeden Observer nach seiner Arbeit klassifizieren

   Async-fähig (Webhook, E-Mail, Audit-Log) vs. synchron (Order-Attribut-Mutation, die atomar mit der Platzierung sein muss). Die Klassifizierung bestimmt die Refactor-Wahl.

4. 04

   Async-fähige Arbeit in einen Queue-Job verschieben

   Trigger auf sales_order_place_after hooken, Message publishen, in einem Handler verarbeiten, der den Order frisch lädt und einmal speichert. RabbitMQ oder MySQL-Queue, deine Wahl.

5. 05

   Synchrone Arbeit von sales_order_save_after wegziehen

   checkout_submit_all_after für Checkout-Zeit-Arbeit, sales_order_place_after für Platzierungs-Zeit-Arbeit. Beide feuern einmal pro Order. Keins erzeugt eine Schleife.

6. 06

   setDataChanges(false) nur dort anwenden, wo Refactor nicht möglich ist

   Vendor-Code ohne Patching-Pfad, knappe Deadline, geringe Sicherheit im Fix-Fenster. Das Warum als Kommentar. Nicht zur Default-Strategie machen.

7. 07

   Nach jedem Refactor erneut tracen

   Gleicher Blackfire-Trace auf demselben Pfad. Order::save-Inklusivcount sollte auf eins fallen. Platzierter-Order-TTFB sollte um das sinken, was die Kaskade gekostet hat, meistens im Bereich zwei bis fünf Sekunden auf belebten Shops.

8. 08

   Einen CI-Guard ergänzen

   Eine statische Analyseregel oder ein Grep in der CI-Config, der den Build scheitern lässt, wenn jemand einen neuen Observer auf sales_order_save_after ergänzt, der save() aufruft. Günstige Versicherung gegen den nächsten Entwickler, der die Kaskade wieder aufbaut.