Microservice-Debugging mit Lambdas: Eine Detektivgeschichte

Hier bei FloQast verwenden wir gerne AWS Lambdas. Lambdas eignen sich hervorragend für die Skalierung der modularen Entwicklung und bieten eine Menge großartiger Tools im Rahmen des AWS-Ökosystems, darunter Ebenen für gemeinsam genutzte Code-Abhängigkeiten, CloudWatch für die Überwachung oder X-Ray für die verteilte Nachverfolgung (weitere Informationen finden Sie in diesem Beitrag oder in diesem Beitrag ). Eine Sache, die beim Einrichten von Lambdas zu beachten ist, ist die Konfiguration von Timeouts.

Situation

Das folgende Diagramm zeigt eine ähnliche Situation, wie wir sie bei der Verwendung von Lambdas erlebt haben.

Wir haben ein Warteschlangensystem, das das Einfügen von Nachrichten in die Warteschlange den Aufrufen der entsprechenden Lambdas zuordnet. Wenn eine Nachricht zur Warteschlange hinzugefügt wird, wird sie abgeholt und ihre Nutzlast wird mithilfe von AWS SDK an den Lambda übergeben. Sobald eine Nachricht zur Verarbeitung abgeholt wurde, wird ein "Sichtbarkeitsfenster" für die Nachricht festgelegt. Falls die Nachricht erneut versucht werden muss, wird dies erst nach Ablauf dieses Fensters geschehen. Weitere Informationen zu dieser Warteschlangenarchitektur finden Sie in diesem früheren Beitrag.

Diese Warteschlange ist für eine 6,5-minütige Sichtbarkeit konfiguriert, die der Zeitüberschreitung von Lambda 1 entspricht. Dies entspricht der maximalen Gesamtzeit eines beliebigen Auftrags, wobei die maximale Zeit, die für jedes nachgeschaltete Lambda benötigt wird, aggregiert wird. Jeder Lambda ist mit einer eigenen Zeitüberschreitung für die geschätzte Höchstdauer seiner Arbeitslast konfiguriert. Dies gilt nicht für Lambda 4 (das etwa eine Minute benötigt) mit einer maximalen Zeitüberschreitung von 15 Minuten, warum auch nicht, aber dazu später mehr.

Die Instanz Lambda 1 des SDK ist auf eine 3-minütige Zeitüberschreitung eingestellt, die die direkten Aufrufe der Lambdas 2, 3 und 5 abdeckt. Es gibt Protokolle, um zu signalisieren, wann jedes Lambda startet und ob es erfolgreich ist oder nicht. Wir erwarten, dass diese Protokolle in der Reihenfolge des Aufrufs erscheinen, wobei alle nachgelagerten Lambdas ihren Abschluss vor ihrem vorgelagerten Lambda protokollieren (das vorgelagerte Lambda muss warten, bis das nachgelagerte Lambda seine Ausführung beendet hat).

Dieses System wurde getestet, indem wir Nachrichten in die Warteschlange einfügten und beobachteten, wie Nachrichten abgezogen und verarbeitet wurden. Die Dinge liefen wie erwartet reibungslos, bis wir einen plötzlichen Anstieg der gleichzeitigen Ausführungen der einzelnen Lambdas feststellten. In Anbetracht der Tatsache, dass die maximale Anzahl der von der Warteschlange zu verarbeitenden Aufträge auf 25 festgelegt ist, würde man erwarten, dass jedes Lambda in diesem System höchstens 25 gleichzeitige Ausführungen haben würde. Einige Lambdas erreichten jedoch fast 80 gleichzeitige Ausführungsvorgänge.

Ein Besuch bei den guten alten Baumstämmen

Wir begannen mit der Verfolgung von Protokollen für Aufträge, die sich in einem schlechten Zustand befanden, um zu sehen, ob die Dinge in der erwarteten Reihenfolge der Operationen ausgeführt wurden.

09:00:00 Lambda 1 für Unternehmen A gestartet...
09:00:03 Lambda 2 für Unternehmen A gestartet...
09:00:37 Lambda 2 abgeschlossen für Unternehmen A...
09:00:48 Lambda 3 für Unternehmen A gestartet...
09:00:52 Lambda 4 für Unternehmen A gestartet...

Es sieht so aus, als ob die Nachricht erfolgreich aus der Warteschlange abgeholt wurde und Lambda 1 gestartet wird. Toll! Dann werden die ersten nachgelagerten Lambdas wie erwartet in der richtigen Reihenfolge aufgerufen... Sieht gut aus. Sieht gut aus. Weiter geht's.

09:00:48 Lambda 3 für Unternehmen A gestartet...
09:00:52 Lambda 4 für Unternehmen A gestartet...
09:01:46 Lambda 4 abgeschlossen für Unternehmen A...
09:01:51 Lambda 3 abgeschlossen für Unternehmen A...
09:01:55 Lambda 5 für Unternehmen A gestartet...
09:02:00 Lambda 1 für Unternehmen A gestartet...
09:02:04 Lambda 2 für Unternehmen A gestartet...

Sieht so aus, als ob die nächsten nachgeschalteten Lambdas aufgerufen werden. Sieht gut aus... Dann wird der Job wieder von Lambda 1 losgeschickt. Sieht aus wie... Warte, was?

Das Sichtbarkeitsfenster wurde bei der Nachricht korrekt angegeben, und wenn die Nachricht um 09:00:00 Uhr abgeholt wurde, sollte der früheste nachfolgende Wiederholungsversuch frühestens um 09:06:30 Uhr beginnen. Außerdem ist die maximale Anzahl der Wiederholungsversuche für Nachrichten in dieser Warteschlange explizit auf 0 gesetzt. Die Nachricht hätte von vornherein nicht erneut versucht werden dürfen. Bei einer weiteren Überprüfung der Protokolle gab es mehrere Fälle, in denen derselbe Prozess von Lambda 1 genau alle 2 Minuten bis zu dreimal erneut gestartet wurde.

09:00:00 Lambda 1 für Unternehmen A gestartet...
09:00:03 Lambda 2 für Unternehmen A gestartet...
...
09:01:55 Lambda 5 für Unternehmen A gestartet...
09:02:00 Lambda 1 für Unternehmen A gestartet...
...
09:04:00 Lambda 1 für Unternehmen A gestartet...
...
09:06:00 Lambda 1 für Unternehmen A gestartet...

Wir haben einige Zeit damit verbracht, die Protokolle und Warteschlangen-Nachrichtenaufzeichnungen für verschiedene Aufträge zu durchsuchen, um ein ähnliches Verhalten festzustellen.

Entdeckung

Die Genauigkeit dieser 2-Minuten-Lücken führte uns zu der Annahme, dass dieses Problem nicht darauf zurückzuführen war, dass die Nachricht aus der Warteschlange erneut gezogen wurde. Vielmehr verwendete der erste SDK-Aufruf von Lambda 1 im Auftrag die Standardzeitüberschreitung von 2 Minuten mit drei automatischen Wiederholungsversuchen und ignorierte die Zeitüberschreitung, die direkt für Lambda 1 festgelegt wurde, sowie die maximale Anzahl der Wiederholungsversuche, die für den Auftrag festgelegt wurde.

Die nachgelagerten Lambdas liefen weiter, während Lambda 1 nach 2 Minuten "ausläuft" und automatisch über das SDK erneut versucht, dieselbe Nachricht zu verarbeiten und dieselben nachgelagerten Lambdas erneut aufruft. So kam es, dass wir manchmal 4x so viele Lambda-Aufrufe hatten wie erwartet. Dies erforderte lediglich eine kleine Aktualisierung der Konfiguration des SDK.

// maxRetries: retry count / timeout: socket timeout / connectTimeout: new connection timeout

var AWS = require('aws-sdk');

AWS.config.update({
    maxRetries: 0,
    httpOptions: {
        timeout: 390000,
        connectTimeout: 5000
    }
});

Notizen zum Mitnehmen

Der Timeout eines Lambdas muss mindestens auf die Summe aller nachgelagerten Lambda-Timeouts gesetzt werden (mit einem gewissen Puffer für Kaltstarts usw.). In diesem Fall ist das System nach der Korrektur des SDK-Aufrufs von Lambda 1 immer noch anfällig dafür, dass die Ausführungszeit von Lambda 4 die von Lambda 3 überschreitet.

Selbst wenn ein Lambda mit der korrekten Zeitüberschreitung konfiguriert ist, muss der Aufruf des Lambdas diese Zeitüberschreitung ebenfalls berücksichtigen. Dies kann über das SDK konfiguriert werden. Wenn ein Lambda jedoch über eine HTTP-Anforderung an API Gateway aufgerufen wird, beträgt das Standardzeitlimit 30 Sekunden. Dieses Limit ist derzeit nicht konfigurierbar.

Alles in allem gibt es eine Menge großartiger Anwendungsfälle für Lambdas, aber sie haben auch ihre Einschränkungen und Konfigurationsprobleme. Hier ist eine großartige Ressource, die einige dieser Vor- und Nachteile umreißt. Berücksichtigen Sie diese auf jeden Fall, wenn Sie evaluieren, ob sie für Ihren Anwendungsfall geeignet sind. In diesem Sinne wünsche ich Ihnen "Good Luck" und "Happy Scaling!"

Calvin Ton

Software-Ingenieur bei FloQast. Musikliebhaber und begeisterter Cratedigger.