Ich bin eher dafür Bibliotheken früher zu aktualisieren. Ich finde der Gesamtaufwand ist niedriger als bei großen Migrationsprojekten. Und man erhält bereits früher den Wert von neuer Funktion oder auch Performanceverbesserungen.
Aber natürlich muss man diese erst messen! Und genau das habe ich kürzlich für einen Kunden getan. Dieser Kunde wollte Drools 5.0.1 nach Drools 5.2 aktualisieren.
Zu meiner Überraschung war das Laden und Ausführen der Regelbasis viel langsamer in 5.2. In der Anwendung dieses Kunden gibt es einen Cache, welcher pro Regeldatei eine StatelessSession enthält. Bei Systemstart werden alle Regeln eingelesen, damit der Endbenutzer auch schon beim ersten Aufruf einer Berechnung schnelle Ergebnisse erhält. Doch das Laden vieler Regeln war bereits Grund für Besorgnis. Also hoffte ich auf Verbesserungen in 5.2 und wurde enttäuscht. Die ersten Unit Tests zeigten schon erhebliche Verzögerungen und benötigten 3 mal so lange wie noch unter 5.0.1. Natürlich ist die Ausführungszeit von Unit Tests nur eine recht ungenaue Metrik, doch muss man bei diesem Faktor nicht über Genauigkeit reden.
Also begab ich mich auf Spurensuche und verband JProfiler mit meinen Unit Tests und führte 21 Drools Decisiontables basierend auf XLS aus. Das Ergebnis war durchaus interessant: [singlepic id=348 w=320 h=240 float=center]
Es ist offensichtlich was unser Performance Problem verursacht. ClassLoading ist hier der Flaschenhals. Ein einziger Aufruf ist zwar noch schnell, doch die ungeheure Menge macht einen entscheidenden Faktor aus. Aber es gibt noch einen interessanten Punkt. Könnt ihr ihn finden?
Genau: System.gc() wird 42 mal aufgerufen (eine verdächtige Zahl). JProfiler behauptet dort werden 8% der Gesamtzeit verbraucht. Aber wir wissen ja, dass Garbage Collection auch weitere unerwünschte Nebeneffekte haben kann. Warum haben wir überhaupt so viel Garbage Collection? Gelistet sind ja sogar nur die expliziten Aufrufe und nichtmal die Gesamtaktivität.
Wie ich schon häufiger beobachten konnte wirkt sich der manuelle Aufruf von System.gc() schlecht aus (jedenfalls meistens).
[singlepic id=350 w=320 h=240 float=center]
Warum wird es überhaupt aufgerufen? Welcher Code ist dafür verantwortlich? JProfiler kann uns dies sehr einfach beantworten:
[singlepic id=352 w=320 h=240 float=center]
Auch das habe ich bereits häufiger gesehen. Für mich ein klarer Fehler in der verbreiteten Java Excel API . Hier wird System.gc() nach jedem Lesen von Daten aufgerufen. Ich denke wirklich nicht, dass dies überhaupt Sinn macht. Und hier hätte ich einen weiteren Beweis dafür. Glücklicherweise gibt es in jxl eine Konfigurationsmöglichkeit die in WorkbookSettings beschrieben ist:
/**
* Flag to indicate whether the system hint garbage collection
* is enabled or not.
* As a rule of thumb, it is desirable to enable garbage collection
* when reading large spreadsheets from a batch process or from the
* command line, but better to deactivate the feature when reading
* large spreadsheets within a WAS, as the calls to System.gc() not
* only garbage collect the junk in JExcelApi, but also in the
* webservers JVM and can cause significant slowdown
* GC deactivated using -Djxl.nogc=true on the JVM command line
* Activated by default or by using -Djxl.nogc=false on the JVM
* command line
*/
Ok, versuchen wir es mal mit diesen Sytem Property. Schauen wir mal ob es einen Einfluss hatte
[singlepic id=349 w=320 h=240 float=center]
und hier die gesamte GC Aktivität mit dem nogc Flag
[singlepic id=351 w=320 h=240 float=center]
Zwar behob dies nicht das offensichtliche Classloading Problem, jedoch war dies eine „lowhanging fruit“. Die gesamte GC Aktivität hat abgenommen und die gesamte Ausführungszeit hat sich von 338 Sekunden auf 315 Sekunden verkürzt (beide Male im voll instrumentierten Profilemodus). Das ist zwar nett aber nicht besonders beeindruckend. Die wahre Qualität dieser Änderung zeigt sich auf dem Integrationstestsystem. Hier hat sich das initiale Laden des Caches von etwa 740 Sekunden auf etwa 240 Sekunden doch erheblich verkürzt. In einem echtem System kommen auf größeren Heaps natürlich andere Charakteristiken zu tragen als bei kleinen Unit Tests.
Doch ich denke ich kann noch mehr herausholen, wenn ich verstehe wie das Classloading zu korrigieren ist. Dies werde ich in einem zweiten Post genauer anschauen.
War dieser Beitrag hilfreich?
Weitere Beiträge
von Fabian Lange
26.3.2015 Dein Job bei codecentric?
Jobs
Agile Developer und Consultant (w/d/m)
Alle Standorte
Weitere Artikel in diesem Themenbereich
Entdecke spannende weiterführende Themen und lass dich von der codecentric Welt inspirieren.
Gemeinsam bessere Projekte umsetzen.
Wir helfen deinem Unternehmen.
Du stehst vor einer großen IT-Herausforderung? Wir sorgen für eine maßgeschneiderte Unterstützung. Informiere dich jetzt.
Hilf uns, noch besser zu werden.
Wir sind immer auf der Suche nach neuen Talenten. Auch für dich ist die passende Stelle dabei.
Blog-Autor*in
Fabian Lange
Du hast noch Fragen zu diesem Thema? Dann sprich mich einfach an.
Du hast noch Fragen zu diesem Thema? Dann sprich mich einfach an.