46 Sekunden in einem 30-Sekunden-Webhook

TL;DR

In EventDrop kann man ein Recap kaufen, ein automatisch geschnittenes Video aus den Fotos eines Events. Der Render wurde direkt im Stripe-Webhook ausgelöst, awaited, mitten im Request-Pfad. Stripe meldet die Zahlung per Webhook, also über einen automatischen Rückruf an meinen Server, für den ein enges Zeitbudget gilt. Nachgerechnet am Quelltext braucht dieser Aufruf im schlechtesten Fall rund 46 Sekunden. Das Zeitbudget der Webhook-Route steht auf 30. Das war der erste Befund. Der zweite war schlimmer: ein roter Health-Check schrieb sofort den Status failed, und die nächtliche Wiederherstellung greift ausschließlich Zeilen mit Status paid. Ein Renderer-Neustart von zwei Minuten tötete damit jedes in diesem Fenster bezahlte Recap dauerhaft.

Was ein Recap ist und warum der Webhook ihn ausgelöst hat

Ein Recap ist ein kostenpflichtiges Extra: aus den Fotos eines Events wird automatisch ein kurzes Video geschnitten, mit Musik, in einer Reihenfolge, die halbwegs Sinn ergibt. Der Rendervorgang selbst läuft nicht in der Web-Anwendung, sondern in einem eigenen Dienst. Die Web-Anwendung stößt ihn nur an.

Der naheliegende Ort dafür ist der Moment der Bezahlung. Stripe meldet per Webhook, dass die Zahlung durch ist, und genau dort stand der Aufruf, der den Render startet. Unmittelbarkeit war die Absicht: der Kunde zahlt, das Video beginnt zu entstehen, niemand muss warten oder pollen. Und das sah lange gut aus, weil dieser Dispatch im Normalfall Millisekunden dauert. Ein POST an den Renderdienst, eine Bestätigung zurück, fertig.

Das Problem war nie der Normalfall. Es war die Frage, was passiert, wenn der Renderdienst nicht sofort antwortet, und diese Frage hatte ich nie ausgerechnet, sondern geschätzt. Meine Werkzeuge und meine Arbeitsweise dahinter beschreibe ich im Abschnitt Werkzeug, aber der beste Werkzeugkasten ersetzt nicht die eine Rechnung, die man nicht gemacht hat.

Der Versuch

Die Funktion, um die es geht, heißt triggerRecapRender. Sie hatte drei awaitende Aufrufer:

1. den Stripe-Webhook, wenn ein Recap bezahlt wurde,
2. eine Server Action, mit der ein kostenloses Recap eingelöst wird,
3. die nächtliche Wiederherstellung, Phase 4b, die liegengebliebene Fälle nachholt.

Von diesen drei hatte genau einer ein Zeitbudget, das zur Sache passte. Die nächtliche Wiederherstellung darf 300 Sekunden laufen. Die anderen beiden nicht. Das ist die ganze Bauart des Fehlers: dieselbe Funktion, dreimal aufgerufen, aber nur an einer Stelle war überhaupt Platz für ihr Verhalten.

Als ich das gebaut habe, dachte ich in Verantwortlichkeiten statt in Zeitbudgets: hier wird bezahlt, also wird hier gestartet. Eine saubere Erzählung und ein schlechter Entwurf, weil sie eine langsame Fremdoperation in einen Pfad legt, der schnell sein muss.

Die Wand

Die Rechnung steht komplett im Quelltext, man muss sie nur einmal zusammenzählen:

Health-Precheck          5 s   (HEALTH_TIMEOUT_MS = 5_000)
Versuch 1 bis 4       4 x 10 s (RENDER_TIMEOUT_MS = 10_000)
Backoff dazwischen   2 + 4 + 8 s (baseDelay 2_000, maxDelay 8_000, Jitter bis +50 %)
------------------------------------------------
schlechtester Fall     rund 46 s

Dagegen steht eine Zeile in der Deployment-Konfiguration: die Stripe-Webhook-Route hat maxDuration 30.

46 gegen 30. Das ist nicht knapp. Im Entscheidungsdokument habe ich es später so festgehalten: "Damit ist der schlechteste Fall im 30-s-Webhook nicht knapp, sondern strukturell nicht einhaltbar. Ein Timeout dort ist keine kosmetische Verzögerung: der Webhook antwortet mit 5xx bzw. gar nicht, und Stripe redelivert drei Tage lang."

Die drei Tage machen aus einem Performance-Thema ein Betriebsthema. Ein Webhook im Timeout ist aus Sicht des Zahlungsanbieters ein fehlgeschlagener Zustellversuch. Er kommt wieder. Und wieder. Ein einzelner langsamer Renderdienst hätte drei Tage lang Wiederzustellungen produziert, gegen einen Endpunkt, der jedes Mal dasselbe Ergebnis liefert. Der Fehler lag ausschließlich bei mir: 30 Sekunden sind ein vernünftiges Budget für einen Webhook. Ich hatte nur etwas hineingelegt, das dort nicht hineingehört.

Die Diagnose

Der zweite Befund kam beim Lesen desselben Codes, und er ist der eigentliche Grund für diesen Artikel.

Wenn der Health-Precheck rot war, wenn der Renderdienst also gerade nicht antwortete, dann schrieb die Funktion sofort den Status failed in die Recap-Zeile. Nicht pending, nicht retry, sondern failed. Das klingt vernünftig, bis man die zweite Hälfte kennt: die nächtliche Wiederherstellung, Phase 4b, sucht ausschließlich Zeilen mit Status paid. Sie fragt nach dem, was bezahlt und noch nicht erledigt ist. Eine Zeile, die auf failed steht, taucht in dieser Abfrage nie wieder auf.

Damit war failed eine Einbahnstraße. Im Entscheidungsdokument steht es so: "Eine so abgeräumte Zeile wird also nie nachgeholt, der Kunde hat bezahlt, das Video existiert nicht, und der einzige Weg zurück ist ein Admin-Retry von Hand. Ein RS-Neustart von zwei Minuten kostete damit jedes in diesem Fenster bezahlte Recap."

Zwei Minuten. Ein Deployment des Renderdienstes dauert länger als das. Jeder gewöhnliche Neustart, jedes Update, jede kurze Nichterreichbarkeit hätte alles, was in diesem Fenster bezahlt wurde, dauerhaft in den Endzustand failed geschrieben, ohne Alarm und ohne dass es jemand bemerkt hätte außer dem Kunden, dessen Video nie kam.

Genau das ist der Unterschied, um den es hier geht. Die Zeitüberschreitung war das sichtbare Problem. Die stille Endgültigkeit war das teure. Gefunden habe ich beides nicht durch einen Ausfall, sondern durch das Nachrechnen am Quelltext, dieselbe Übung wie damals, als ich Agenten auf meine eigene Website losgelassen habe: messen statt annehmen.

Der erste Befund kostete Sekunden. Der zweite machte aus einem zwei Minuten langen Neustart einen dauerhaften Verlust für jeden, der in diesem Fenster bezahlt hatte.

Die Lösung: der Trigger verlässt den Request-Pfad

Die Antwort ist alt und unspektakulär: eine Outbox. Der Request macht nur noch eine Sache, nämlich eine Zeile schreiben. Ein Worker, der alle zwei Minuten läuft, nimmt sich diese Zeile und führt den Dispatch aus, mit dem Zeitbudget, das dazu passt.

Die naheliegende Variante wäre gewesen, die bereits existierende Outbox für Upload-Nebeneffekte mitzubenutzen. Das ist an zwei Stellen gescheitert. Ihre Spalte upload_id ist NOT NULL, ein Recap hat aber keinen Upload als Elternteil. Und schlimmer: der Verarbeitungspfad dort behandelt eine Zeile ohne auffindbaren Upload als erledigt. "Eine Recap-Zeile mit upload_id IS NULL fällt sofort in genau diesen Zweig, der Dispatch wäre ein stiller No-op, gemeldet als Erfolg." Einen nullable Fremdschlüssel einzuführen hätte den Fehler also nicht behoben, sondern unsichtbar gemacht.

Geworden ist es eine Schwestertabelle, recap_side_effects, mit derselben Form wie die bestehende und einem eigenen Elternteil:

CREATE TABLE recap_side_effects (
  recap_id      uuid NOT NULL REFERENCES recap_videos(id) ON DELETE CASCADE,
  effect_type   text NOT NULL,
  status        text NOT NULL DEFAULT 'pending',
  attempts      int  NOT NULL DEFAULT 0,
  next_attempt_at timestamptz NOT NULL DEFAULT now(),
  UNIQUE (recap_id, effect_type)
);

Der UNIQUE-Schlüssel macht das Einreihen idempotent, also so gebaut, dass ein zweiter Anlauf nichts doppelt tut: ein zweiter Webhook für dieselbe Zahlung legt keine zweite Zeile an. Das Claiming läuft über eine Datenbankfunktion mit FOR UPDATE SKIP LOCKED, damit zwei parallele Worker sich nicht dieselbe Zeile schnappen. Und next_attempt_at steht standardmäßig auf now, weil dies hier der einzige Pfad ist und nicht ein Nachzügler neben einem Direktaufruf.

Der zweite Teil der Lösung ist ein Fehlervertrag. Vorher gab es nur Fehler. Jetzt gibt es transiente und permanente. Health rot, Netzwerkfehler, Timeout und ein 5xx des Renderdienstes sind transient und führen zu einem neuen Versuch. Ein 4xx, eine fehlende Konfiguration, ein nicht gefundenes Event, zu wenige Fotos sind permanent. Nur der Dead-Pfad nach fünf Versuchen schreibt noch failed.

Die Voreinstellung ist dabei bewusst die konservative: "Alles, was nicht ausdrücklich als transient klassifiziert ist, bleibt permanent, der Default ist damit das heutige Verhalten, und eine neue Fehlerquelle verhält sich, bis jemand sie einordnet, genau wie vorher." Eine neue Fehlerklasse soll sich nicht schlimmer benehmen als der Stand vor dem Umbau, nur weil sie noch niemand eingeordnet hat.

Die nächtliche Phase 4b ist nicht verschwunden. Sie wurde umgebaut: statt selbst zu triggern, legt sie eine fehlende Outbox-Zeile nach oder weckt eine steckengebliebene wieder auf. Sie ist jetzt der Rückfallschirm für das eine Loch, das offen bleibt.

Was das Outbox-Muster allgemein löst

Der Trick ist eine Trennung, die im Nachhinein trivial klingt. "Der Auftrag ist angenommen" und "der Auftrag ist ausgeführt" sind zwei verschiedene Zusagen, und der Request muss nur die erste garantieren. Damit werden Retry, Backoff und Aufgeben zu Eigenschaften von Daten statt zu Ablaufsteuerung in einem Handler, dessen Zeitbudget jemand anderer festlegt.

Der zweite Gewinn ist Sichtbarkeit. Ein hängender Nebeneffekt war vorher ein Zustand in einem beendeten Prozess, also nichts. Jetzt ist er eine Zeile mit Versuchszähler und nächstem Termin, die man anschauen und wieder scharfschalten kann. Das ist verwandt mit dem, was mich am DevWatchdog interessiert hat: Zustände, die niemand mehr anfasst, sind nur deshalb harmlos, weil sie unsichtbar sind.

Die Kosten stehen daneben: bis zu zwei Minuten Wartezeit für den Kunden, ein kleines Fenster zwischen Zahlung und Zeile, und Leichen im Status processing, wenn ein Worker mitten im Lauf stirbt. Dafür gibt es eine Schwelle von 15 Minuten und einen Rearm-Pfad: "Das Fenster ist damit nicht null, aber beschränkt und selbstheilend, vorher war es unbeschränkt und heilte nie."

Und eine Grenze gehört dazu. Das ist keine Ideologie über Message-Queues. Es ist die Antwort auf genau eine Frage, nämlich wer die Verantwortung für einen langsamen Nebeneffekt trägt. Wo der Nebeneffekt schnell und verlässlich ist, ist der Direktaufruf weiterhin die einfachere und bessere Lösung.

Was ich daraus mitnehme

1. Ein Zeitbudget ist ein Vertrag, kein Richtwert. Wer eine Retry-Schleife in eine Funktion mit 30 Sekunden Budget hängt, muss die Schleife ausrechnen, nicht abschätzen. Fünf Sekunden plus viermal zehn plus vierzehn Sekunden Warten ist eine Rechnung, die zwei Minuten dauert und die ich nie gemacht habe.

2. Die teure Frage ist nicht, was bei einem Fehler passiert. Die teure Frage ist, was passiert, wenn dieser Fehlerzustand endgültig ist. failed war hier eine Einbahnstraße, und die einzige Wiederherstellung, die es gab, sah in eine andere Richtung.

3. Ein Fehler braucht eine Klasse, bevor er eine Reaktion bekommt. Transient und permanent verlangen entgegengesetztes Verhalten. Und die Voreinstellung für alles noch nicht Eingeordnete muss das alte, bekannte Verhalten sein, sonst verschlechtert der Umbau still etwas, das vorher funktioniert hat.

4. Zwei Dinge mit verschiedenen Eltern gehören in zwei Tabellen. Der nullable Fremdschlüssel hätte hier keine Zeile gespart, sondern den Dispatch in einen stillen Erfolg verwandelt. Eine zweite Tabelle mit derselben Form ist billiger als eine gemeinsame mit einer Ausnahme.

5. Eine grüne Pipeline belegt nicht, dass die Migration gelaufen ist. Deshalb ging der Deploy migration-first: erst der Workflow, dann das Ledger anschauen, dann der Push. Dieselbe Haltung wie in Verifikation statt Tippen, nur mit Datenbank statt Editor.

Fazit

Der Umbau umfasste 24 Dateien, 2.436 eingefügte Zeilen, eine Migration mit 178 Zeilen und 33 Tests, die gegen den alten Stand rot waren. Das klingt nach viel für einen Aufruf, der an die falsche Stelle gehängt war. Es war aber nicht der Aufruf, der teuer war, sondern der Zustand dahinter.

Und die Grenze gehört dazu, sonst wäre dieser Artikel eine Erfolgsmeldung statt ein Bericht. Die Migration konnte lokal nur statisch geprüft werden, weil Docker auf der Maschine an diesem Abend nicht lief. Der Worker verarbeitet bewusst nur ein Recap pro Lauf, weil ein einzelner Dispatch bis zu 46 Sekunden gegen 60 Sekunden Budget kostet. Und das Einreihen ist weiterhin nicht transaktional. Das sind offene Punkte, keine gelösten.

Was ich beim nächsten Mal zuerst frage, hat sich geändert. Nicht mehr "was passiert, wenn das fehlschlägt", sondern "was passiert, wenn dieser Zustand endgültig ist, und wer schaut jemals wieder hin". Der Weg von einem Bastelstück zu etwas, das jeden Tag laufen muss, besteht ziemlich genau aus solchen Fragen, wie ich an anderer Stelle schon beschrieben habe.