So halten wir die Performance im Auge

Ich habe ja schon häufiger darauf hingewiesen, das wir jeden Tag einige Tausend Dokumente jeweils mit der 32bit und der 64bit Version der Baustatik durchrechnen, damit sichergestellt ist, das tagesaktuelle Änderungen keine Fehler eingeführt haben. Dabei werden die aktuellen Berechnungen mit Referenzergebnissen verglichen, und die dürfen sich nicht geändert haben – sonst ist was “ungünstiges” passiert.

Diese Testläufe sind aber nicht nur dafür da, Fehler zu vermeiden. Wir prüfen damit auch die Performance und andere Messpunkte der Baustatik.

Für Performance-Optimierungen hat Visual Studio – unser hauptsächliches Entwicklungswerkzeug – einen “Profiler” eingebaut: Damit kann man quasi auf Funktionsebene ausmessen, wo die meiste Zeit bei der Abarbeitung des Programms verwendet wird, und solche Stellen dann genauer untersuchen, um dort Verbesserungen vorzunehmen. Das hilft aber natürlich nicht dabei, die Gesamtperformance im Auge zu behalten. Das tun wir statt dessen mit unseren Testläufen.

Im Normalfall produzieren die jeden Tag einen Report, und aus dem ersten Report kann man dann schon entnehmen, wie viel Zeit der Testlauf benötigt hat. Diese Information kommt einfach als eMail von den Testservern, und sieht in etwa so aus:

Damit sieht man natürlich nicht, wie sich das Laufzeitverhalten verändert hat: Man bekommt aber sofort mit, wenn irgendwas dramatisches passiert ist: Brauchen irgendwelche Testfälle plötzlich mehr als ein paar Minuten, ist mit recht großer Sicherheit irgendwas nicht in Ordnung.

Um das genauer anzusehen, gibt es weitere Diagramme. Eines davon gibt Ausschluss darüber, wie lange die einzelnen Testläufe der letzten Tage benötigt haben. Das sieht dann ungefähr so aus:

Hier sind kleinere Schwankungen immer zu erwarten: Der Testserver braucht ja nur irgend ein Update zu installieren während die Tests laufen – schon dauert der Testlauf etwas länger. Auf dem Testserver von dem die Graphik stammt laufen die Testfälle mit nur einer CPU und einer relativ langsamen Festplatte und brauchen dann immer so um die 60 Minuten. Wenn hier Ausreißer auftreten, kann man sofort sehen, das irgendwas nicht in Ordnung ist – und auch, ab welchem Tag in der Vergangenheit das passiert ist. So einen Fall gibt es in dieser Graphik nicht. Was man aber sehen kann ist, das die Testfälle in der Anfangsperiode grundsätzlich über 60 Minuten gebraucht haben – größenordnungsmäßig waren die so um die 65 Minuten. In den letzten Durchläufen hingegen ist die Laufzeit immer unter 60 Minuten, so ungefähr bei 58: Der Grund ist hier eine Optimierung von vor circa einer Woche. (Die meisten Optimierungen der letzten Zeit betrafen die Parallelisierung, die auf dem Single-Core Testserver nicht durchschlägt. Man kann halt keine Arbeit auf mehrere CPUs verteilen, wenn man nur eine hat )

Soweit dient die Sache in erster Linie dazu, das wir plötzlich auftretende Veränderungen im Verhalten der Baustatik bemerken. Es geht aber weiter: Natürlich können wir die Testläufe nicht nur automatisiert auf den Testservern laufen lassen, sondern auch auf unseren normalen Workstations.

Da gibt es dann ein weiteres Tool, das ich gern bei der Performance-Optimierung verwende: Das Werkzeug stellt im Prinzip die gleichen Daten da, wie die, die ich schon abgebildet habe – gibt einem aber bessere Vergleichsmöglichkeiten. Wenn also eine Änderung durchgeführt wurde, kann man einen Testlauf von vor der Änderung mit einem nach der Änderung vergleichen – und überprüfen, ob die Änderung was gebracht hat. Dabei werden Informationen sowohl über die verbrauchte Zeit, als auch über den verbrauchten Speicher angezeigt.

Da kann man dann auch reinzoomen, falls man sich nur für einen bestimmten Teil interessiert. So was es bei einer meiner letzten Änderungen: Die betrag die Testfälle rund um die Nummer 500:

Vor der Änderung (obere gelbe Kurve) brauchten die Testläufe konsistent 10-20 Sekunden, mit einigen Ausrutschern, die über 60 Sekunden brauchten. Nach der Änderung (obere blaue Kurve) dauert das immer deutlich unter 5 Sekunden: Diese Änderung hat es also gebracht