Die Warteschlange stand vier Tage still

Beim Durchsehen der Protokolle meines Shop-Dienstes ist mir etwas aufgefallen: Das Protokoll der Warteschlange endete am 8. August. Der Container lief seit dem 8. August. Wir hatten den 12.

Vier Tage, in denen keine Hintergrundaufgabe mehr abgearbeitet wurde.

Was da eigentlich läuft

Anwendungen dieser Art schieben alles, was dauern kann, in eine Warteschlange: Bestätigungsmails, Bildbearbeitung, Abgleiche mit anderen Diensten. Ein Arbeiterprozess holt sich Aufträge und arbeitet sie ab.

Bei mir waren es zwei Hintergrundprozesse: der Arbeiter und ein Zeitplaner, der regelmäßig wiederkehrende Dinge anstößt.

Der Startbefehl sah — verkürzt — so aus:

php artisan queue:work --max-time=3600 &
while true; do php artisan schedule:run; sleep 60; done &
php artisan serve

Und da ist der Fehler. Der Zeitplaner läuft in einer Schleife. Der Arbeiter nicht.

Die Eigenheit, die das auslöst

Ein solcher Arbeiter beendet sich planmäßig nach einer eingestellten Laufzeit. Das ist kein Fehler, sondern ein Feature: Langlaufende Prozesse in einer Sprache mit gemeinsam genutztem Zustand neigen dazu, Speicher zu sammeln. Ein regelmäßiger Neustart ist die einfache Lösung — und die übliche Erwartung ist, dass ein Prozessmanager davor sitzt und ihn neu startet.

In meinem Aufbau gab es diesen Manager nicht. Der Arbeiter lief eine Stunde und war dann weg. Der Container lief weiter, weil der Webserver im Vordergrund lief — für das Panel sah alles gesund aus.

Warum es vier Tage gedauert hat

Der Dienst war erreichbar. Die Seite lud, Produkte waren sichtbar, man konnte kaufen.

Es gibt keinen Fehler. Die Aufträge lagen in der Datenbank und warteten. Sie waren nicht verloren, sie wurden nur nicht abgearbeitet.

Es gab wenig Betrieb. Wenn täglich hunderte Bestellungen liefen, wäre es innerhalb einer Stunde aufgefallen.

Das ist die Kombination, die mir inzwischen dreimal begegnet ist: Ein Teilausfall in einem System, dessen sichtbare Teile funktionieren, bei geringer Nutzung. Genau dafür ist Überwachung da — und meine hat diesen Fall nicht abgedeckt, weil sie fragt „läuft der Dienst?" und nicht „arbeitet er?".

Die Behebung

Der Arbeiter bekommt dieselbe Schleife wie der Zeitplaner:

while true; do php artisan queue:work --max-time=3600; sleep 5; done &

Dazu zwei Ergänzungen:

Der Rückstau lässt sich ohne Neustart abarbeiten — mit einer Variante, die läuft, bis nichts mehr da ist. Ein Detail dabei: Diese Variante nimmt standardmäßig nur die Standard-Warteschlange. Aufgaben auf einer eigenen Warteschlange bleiben liegen und brauchen einen eigenen Aufruf. Bei mir lag die Bildoptimierung auf einer solchen — und wäre sonst weiter unbearbeitet geblieben, obwohl ich dachte, ich hätte abgeräumt.

Eine Prüfung in der Überwachung: Wie viele unbearbeitete Aufträge liegen in der Warteschlange, und wie alt ist der älteste? Ein Auftrag, der älter ist als ein paar Minuten, ist ein Signal. Diese eine Abfrage hätte den Fehler nach zwanzig Minuten sichtbar gemacht statt nach vier Tagen.

Der Nebenschauplatz mit den Anführungszeichen

Beim Ändern des Startbefehls bin ich in eine zweite Falle gelaufen, die zum Thema passt: Der Befehl wird als Zeichenkette im Panel gespeichert und durch mehrere Ebenen gereicht, die alle ihre eigenen Vorstellungen von Anführungszeichen und Variablen haben.

Ein Schleifenkonstrukt mit Statusabfragen darin wird dabei zerlegt, wenn man es als doppelt gequoteten Ausdruck übergibt — die inneren Variablen werden von der falschen Ebene ausgewertet. Die Lösung war, den Ablauf in eine Datei zu legen und im Startbefehl nur diese Datei aufzurufen.

Das ist eine allgemeine Regel geworden: Alles, was mehr als eine Zeile Logik ist, gehört in ein Skript und nicht in ein Textfeld.

Was ich seitdem an Hintergrundprozessen prüfe

Aus diesem Fall sind vier Kontrollen entstanden, die für jeden Dienst mit Hintergrundarbeit gelten.

Tiefe der Warteschlange. Wie viele unbearbeitete Aufträge liegen an? Ein Wert über null ist normal, ein dauerhaft steigender nicht.

Alter des ältesten Auftrags. Die aussagekräftigste Einzelzahl. Ein Auftrag, der älter ist als ein paar Minuten, bedeutet Stillstand — unabhängig von der Menge.

Laufzeit des Arbeiters. Wenn ein Prozess sich planmäßig beendet und neu gestartet wird, sollte man wissen, wie lange er üblicherweise lebt. Ein Arbeiter, der seit Tagen läuft, ist genauso verdächtig wie einer, der jede Minute neu startet.

Fehlgeschlagene Aufträge. Sie landen meistens in einer eigenen Tabelle, die niemand ansieht. Bei mir wird sie mitgezählt.

Das Alter des ältesten Auftrags ist die Kontrolle, die diesen Fehler nach zwanzig Minuten statt nach vier Tagen sichtbar gemacht hätte. Sie ist eine Abfrage und kostet nichts.

Warum ich Startbefehle jetzt in Skripte auslagere

Der Nebenschauplatz mit den Anführungszeichen hat zu einer Regel geführt, die mir seitdem viel Ärger erspart hat.

Ein Startbefehl in einem Textfeld durchläuft mehrere Ebenen, die alle ihre eigenen Vorstellungen von Anführungszeichen, Variablen und Sonderzeichen haben. Was am Ende ausgeführt wird, ist selten genau das, was man geschrieben hat.

Also: Das Textfeld enthält einen Aufruf, mehr nicht. Die Logik liegt in einer Datei im Volume.

Der Gewinn ist größer als nur die Vermeidung von Zeichenproblemen:

• Das Skript ist lesbar und kann Kommentare enthalten.
• Es kann Fehler abfangen und eigene Meldungen ausgeben.
• Es lässt sich einzeln testen, ohne den Dienst neu zu starten.
• Es kann versioniert werden.

Das letzte ist der eigentliche Punkt. Ein Startbefehl in einer Oberfläche hat keine Historie. Wenn jemand ihn ändert, ist der vorherige Zustand weg — und niemand kann sagen, was vorher dort stand.

Was ich mitnehme

Wer einen Prozess ohne Manager startet, muss dessen Lebenszyklus kennen. Ein Prozess, der sich planmäßig beendet, ist in einer Umgebung mit Manager richtig und ohne Manager ein Fehler. Die Software ist in beiden Fällen dieselbe.

Überwachung muss die Arbeit prüfen, nicht die Anwesenheit. „Der Dienst antwortet" und „der Dienst arbeitet" sind zwei verschiedene Aussagen. Bei allem, was Hintergrundaufgaben hat, braucht es die zweite.