BIS News

Nach den Störungen im Web-Login am ersten Tag des Sommersemesters waren wir zu optimistisch, als wir danach diese Meldung veröffentlicht haben: Auch am Dienstag kam es noch einmal zu Verzögerungen und langen Wartezeiten beim Zugriff auf alle nun am großen Loginsystem angeschlossenen Services. Die am Vortag eingebauten, zusätzlichen Protokollierungen zum zeitlichen Verlauf eines einzelnen Loginvorgangs haben uns dann aber schnell zu weiteren, problematischen Stellen geführt:

Programmcode, der nach 20 Jahren zu Problemen führt 

Eine dieser Stellen war eine Überraschung, denn sie lag in ein paar Zeilen Programmcode, die schon seit mindestens 20 Jahren tief im Kern der BIS Anwendungen arbeiten und jeden Tag unzählige Male aufgerufen werden, bisher immer ohne Probleme zu verursachen:

Hier wird einfach eine Zahl generiert, die noch niemals zuvor geliefert wurde. Solche eindeutigen Zahlen werden z. B. für die Kennzeichnung neu angelegter Datensätze benötigt und die entstehen in den BIS Anwendungen pausenlos. Beim Loginvorgang wird so eine Zahl zum Beispiel für den entsprechenden Protokolleintrag benötigt, der den Loginvorgang dokumentiert und der sich in der Kontenverwaltung einsehen lässt.

Dieser Vorgang braucht eine kurze Verbindung zur Datenbank und ist normalerweise in Millisekunden erledigt. Am Dienstag gab es aber Fälle, bei denen dieser Schritt allein 20 bis 30 Sekunden brauchte. Das Problem wurde dabei durch die Verwendung eines synchronisierten Programmabschnitts - dafür sorgt das synchronized-Schlüsselwort - verschärft, da dadurch pro Server nur eine Anfrage zugleich bearbeitet wurde.

Der Grund, warum hier so vorgegangen wurde, ist 20 Jahre später nicht mehr ganz klar. Vermutlich war die Idee etwas Speicherplatz zu sparen. Das spielt heute aber keine Rolle mehr, so haben wir während der Problemsuche den Speicher der Server einfach einmal verdoppelt (was aber keine wesentliche Verbesserung brachte).

Der schnelle Umbau des Codes zu einer nicht-synchronisierten Variante hat dann am Dienstag augenblicklich zu einer Entspannung der Lage geführt und die Server konnten danach die Loginanfragen viel schneller bearbeiten.

Abhängigkeiten zwischen Datenbanken 

Trotzdem haben wir an dieser Stelle nicht aufgehört und weiter nach den Gründen gesucht, warum die Generierung der eindeutigen Zahlen überhaupt so lange gebraucht haben kann. Hier wurden vom Datenbankteam Stellen gefunden, bei denen Datenbankabfragen in einer ineffizienten Weise ausgeführt und zu Kopplungen zwischen eigentlich getrennten Datenbankbereichen geführt haben, deren negative Effekte im Normalbetrieb keine störenden Auswirkungen hatten.

Wir haben dann bis Donnerstag schrittweise Optimierungen durchgeführt, die sowohl Verbesserungen an den Abfragen an sich, aber durch Zwischenspeicherungen auch zu einer weitgehenden Entkopplung der Datenbanken geführt haben.

Schneller als jemals zuvor 🚀

Seit Donnerstag sind damit die Logins nun spürbar schneller geworden: Haben sie zuvor ca. 2 Sekunden benötigt, sind es nun nur noch selten mehr als 500 Millisekunden. Ca. 300 Millisekunden werden dabei allein schon für die Kryptierung des Passworts verwendet. Damit wurde nicht nur der Zugriff für alle schneller, die Loginsysteme sind auch rascher wieder frei für die nächsten Vorgänge und erzeugen insgesamt viel weniger Last auf den nachgelagerten Systemen wie den Datenbanken.

Da die Anzahl der Loginvorgänge pro Tag dabei nicht wesentlich geringer geworden ist sind wir uns sehr sicher gut aufgestellt zu sein für die nächste Hochlastphase, die uns beim Start des Wintersemesters erwartet.