Profiling des SJF

Um die Performance des Frameworks mit seinen verschiedenen Konfigurationen messen zu können, reichen bereits bestehende SJF-Fähigkeiten wie z. B. Dynamic Proxy nicht aus. Neben der eigentlichen Performance der Algorithmen sollte noch der Speicherverbrauch , Anzahl der geladenen Objekte, GC Verhalten usw. gemessen werden. Aus dem Grund werde ich hier ein kommerzielles Programm JProbe vorstellen, mit dem das SJF selber getestet wurde. Mit dieser Software ist es möglich, alle oben genannte Features zu testen. Neben JProbe (http://www.sitraka.com/) gibt es noch eine Reihe anderer Tools wie OptimizeIt oder NuMega mit ähnlichem Leistungsumfang.

Interessant dabei ist, dass die if-Abfrage 15,2 % der Gesamtzeit verbraucht hat. Nach genaueren Untersuchung der geladenen Objekte hat sich gezeigt, dass nur die wenigsten das Marker-Interface com.abien.framework.base.NotWrappable implementieren. Die if-Abfrage wurde somit leicht modifiziert, damit das geladene Objekte zuerst auf den Typ NotWrappable überprüft wird. Da nur wenige Objekte dieses Interface implementieren, wird meistens die isWrapping()- Prüfung gar nicht mehr stattfinden.

Diese Maßnahme hat die Performance der if-Abfrage nahezu verdoppelt. Nach der Modifikation verbraucht die if-Abfrage lediglich 6,2 % der Zeit.

Als Nächstes wird die Methode getName() der ConfigurableFactory untersucht.

public Name getName() {
String name = this.getPropertiesManager().getPropertiesForObject(this).getProperty(NAME_KEY);
try {
if (name != null)
return new CompositeName(name);
else
return null;
} catch (Exception e) {
return null;
}
}

Die relativ teure Methode getPropertiesForObject() wird hier 24-mal aufgerufen. Die Parameter des Aufrufs bleiben aber dieselben. Die Methode getPropertiesForObject des com.abien.framework.util.PropertiesManager s verbraucht hier ganze 100%.

Da sich die Parameter des getPropertiesForObject nicht ändern, stimmen auch die Rückgabewerte des Aufrufs überein. Die Idee ist es, diese Funktionalität der Methode in den Konstruktor auszulagern. Sie wird dann ein einziges Mal aufgerufen. Nur eine Referenz auf das Objekt javax.naming.Name wird bei jedem Aufruf der Methode zurückgegeben.

Die leicht modifizierte ConfigurableFactory sieht dann so aus:

public abstract class ConfigurableFactory extends ReConfigurable implements ConfigurableFactoryIF, NamingRegistable {

private Name name = null;
public ConfigurableFactory(PropertiesManagerIF propertiesManager) throws RemoteException {
super(propertiesManager);
this.init();
}
public ConfigurableFactory(PropertiesManagerIF propertiesManager, String name) throws RemoteException {
super(propertiesManager, name);
this.init();
}
private void init(){
String tempName = this.getPropertiesManager().getPropertiesForObject(this).getProperty(NAME_KEY);
try {
if (tempName != null)
name = new CompositeName(tempName);
else
name = null;
} catch (Exception e) {
name = null;
}

}
public Name getName() {
return this.name;
}

//..
}

Diese Modifizierung bewirkt, dass nahezu überhaupt keine Prozessorzeit in der Methode getName »verbraten« wird. Stattdessen hat man diese Funktionalität in die private Methode init() ausgelagert. Die Methode init() wird nur einmal, beim Aufruf von einem der Konstruktoren, aufgerufen. Dieser relativ teure Aufruf findet also bei der Initialisierung der ConfigurableFactory statt. Die Rechnung geht hier auf, da die Methode getName mindestens einmal aufgerufen wird. Sie wird insgesamt sogar 24-mal aufgerufen, die private Methode init() nur 9-mal. Wir haben uns also ganze 15 teure Aufrufe gespart.

Nach der Umschaltung von »Cumulative Time « auf »Method Time « finden wir die Methode getPropertiesForObject des PropertiesManager an der ersten Stelle. Nach der genauen Untersuchung des Sourcecodes stellen wir fest, dass sich der Code nicht mehr spürbar optimieren lässt, da man hier »teure« Stringoperationen benötigt. Der Aufruf key.startsWith(prefix) benötigt 50 % der Gesamtzeit, die in der Methode getPropertiesForObject verbracht wurde. Dieser Aufruf ist aber absolut notwendig, da man nur so die benötigte Konfiguration objektbezogen extrahieren kann.

Zugegebenermaßen kann die Optimierung des Startverhaltens des Frameworks in Frage gestellt werden. Da das SJF eher auf dem Server zum Einsatz kommt, ist die Länge der Startphase des Frameworks nahezu egal. Allerdings ermöglichen solche Untersuchungen den Einblick in die internen Abläufe des Servers.

Ferner ist das Speichern beinahe doppelt so aufwändig wie das Lesen der Werte. Dieses Verhalten hängt aber von der Implementierung des Services ab.

public class DurablePersistenceService extends Configurable implements PersistenceServiceIF {

public Object getValue(Object entry) throws StorageException {
FSystem.sys.println("----------------------Trying to find: " + entry.toString());
if (this.storage.containsKey(entry))
FSystem.sys.println("---------------------------------entry found ➥!!!!");
return this.storage.get(entry);
}
public void store(Object entry, Object value) throws StorageException {
synchronized(this.storage) {
try {
this.storage.put(entry, value);
this.serialSupport.storeObject(this.storage, this.fileName, true);
} catch (Exception e) {
throw new StorageException(this, e.toString());
}
FSystem.sys.println("Entry " + entry.toString() + " Value :" + value + ➥" successfull stored !");
}
}
}

Beim Lesen wird lediglich die interne Struktur java.util.Hashtable abgefragt. Dieses Objekt übernimmt hier die Cache-Funktionalität der Implementierung. Um die Konsistenz der Daten zu gewährleisten, wird bei jedem Schreibzugriff der Inhalt des Caches auf die Festplatte geschrieben. Die Instanz der Klasse Hashtable wird serialisiert. Zu diesem Zweck wird die Utility-Klasse com.abien.framework.util.SerializationSupport verwendet, die diese Aufgabe übernimmt.

public class SerializationSupport {
//..
public static synchronized void storeObject( Object o,String fileName,
➥boolean override) throws Exception{

File objectFile = new File( fileName );
if(objectFile.exists() && !override )
throw new Exception("SerialSupport.storeObject(Object object,String path)" + fileName + " already exists !");
ObjectOutputStream stream = new ObjectOutputStream(new FileOutputStream(fileName));
stream.writeObject(o);
stream.flush();
stream.close();
}

Die Implementierung der Methode storeObject ist auch alles andere als optimal. Bei jedem Zugriff wird zuerst eine Instanz der Klasse java.io.File erzeugt. Dieser Vorgang benötigt bereits 27,3 % der Gesamtzeit der Methode storeObject. Fast die ganze verbleibende Zeit wird für das Erzeugen der Instanz java.io.ObjectOutputStream benötigt (72,7%). Da es sich in unserem Beispiel nur um kleine Objekte handelt, fällt das Schreiben ( writeObject ) gar nicht mehr ins Gewicht. Die Implementierung des DurablePersistenceService hat noch ein anderes Problem. Diese Implementierung »cached« alle Einträge in einem Hashtable . Die Schlüssel mit ihren Werten werden einfach im Speicher gehalten. Bei sehr großen Datenmengen kann es zu Speicherproblemen kommen, was sich sogar durch die java.lang.OutOfMemoryException äußern kann. Interessant wäre es hier, nur diesen Cache, ohne die Zugriffe auf den Sekundärspeicher, zu testen. Zu diesem Zweck stellen wir die Konfiguration des Frameworks um:

com.abien.framework.persistence.PersistenceServiceFactory. persistenceServiceType =
➥com.abien.framework.persistence.VolatilePersistenceService

An Stelle des DurablePersistenceServices wird com.abien.framework.persistence. VolatilePersistenceService geladen. Dieser kann als Wrapper oder Adapter für die Hashtable gesehen werden. Die Implementierung dieses Services besteht lediglich aus der Umsetzung der PersistenceServiceIF- Aufrufe auf die Hashtable- Aufrufe.

public class VolatilePersistenceService extends Configurable implements PersistenceServiceIF {

private HashMap hashMap = null;
public VolatilePersistenceService(PropertiesManagerIF properties) throws RemoteException{
super(properties);
this.hashMap = new HashMap();
}

public VolatilePersistenceService(PropertiesManagerIF properties, String name) throws Exception {
super(properties, name);
this.hashMap = new HashMap();
}

public Object getValue(Object entry){
return this.hashMap.get(entry);
}
public void store(Object entry, Object value){
this.hashMap.put(entry,value);
}

public void removeAll(){
this.hashMap = new HashMap();
}

public void remove( Object entry ){
this.hashMap.remove(entry);
}
public int size(){ return this.hashMap.size(); }
public boolean containsKey( Object entry ){
return this.hashMap.containsKey(entry);
}

}

Das Laufzeitverhalten ändert sich drastisch. Ganze 88,5 % der Zeit werden für die Erzeugung der Klasse VolatilePersistenceService benötigt .

Die Schreibzugriffe brauchen lediglich 2,3 % der Methodenzeit und die Lesezugriffe sind kaum messbar. Die eigentliche Ursache muss in der Art der Erzeugung des DurablePersistenceService liegen. Seine Konstruktoren sollten aus diesem Grund näher untersucht werden.

public VolatilePersistenceService(PropertiesManagerIF properties) throws ➥RemoteException{
super(properties);
this.hashMap = new HashMap();
}

public VolatilePersistenceService(PropertiesManagerIF properties, String name) ➥throws Exception {
super(properties, name);
this.hashMap = new HashMap();
}

Diese sind aber fast leer, sie beschränken sich lediglich auf die Initialisierung der java.util.HashMap . Warum ist die Instanziierung des VolatilePersistenceServices so teuer? Die Antwort finden wir wieder in der Implementierung. Diesmal ist nicht der VolatilePersistenceService selber, sondern seine Factory der Übeltäter. Der folgende Aufruf PersistenceServiceFactory.getExistingInstance().getPersistenceService("hugo") veranlasst unsere com.abien.framework.peristence.PersistenceServiceFactory zur Erzeugung einer neuen Instanz der Implementierung. Eine neue Instanz der VolatitePersistenceService- Klasse wird also zu Laufzeit, und zwar dynamisch, mit der ConfigurableFactory erzeugt.

public PersistenceServiceIF getPersistenceService() {
return this.persistenceService;
}
public PersistenceServiceIF getPersistenceService(String name) throws DynamicInstantiationException {
return (PersistenceServiceIF)getConfigurableForKey(PERSISTENCE_SERVICE_TYPE,name);
}

In diesem Fall wird die Methode getPersistenceService(String name) der PersistenceServiceFactory aufgerufen. Diese erzeugt eine neue Instanz der aktuellen Implementierung des Interfaces PersistenceServiceIF . Zunächst wird noch der Name (»hugo«) an die Instanz übergeben, damit der PropertiesManager die Gelegenheit erhält, die speziellen Properties für das gerade erzeugte Objekt zu lesen. Im Fall von »hugo« werden die folgende Informationen gelesen.

hugo*com.abien.framework.persistence.VolatilePersistenceService.jndiName=
➥VolatileService
hugo*com.abien.framework.persistence.VolatilePersistenceService.loadOnStartup=1

Wir führen noch mal eine Messung, diesmal ohne eine neue Instanz zu erzeugen, durch.

Der Messung nach kostet die Erzeugung der Instanz VolatilePersistenceService rein gar nichts. Diese Aussage ist nur teilweise richtig, da die Instanz bereits beim Hochfahren des Servers erzeugt wurde. Wie wir gerade feststellen, verteilt sich aber die übrige Zeit genauso auf die Methodenaufrufe wie im vorherigen Experiment. Insgesamt wird diese Methode also schneller abgearbeitet. Um die Implementierung DurablePersistenceService und die VolatilePersistenceService miteinander zu vergleichen, wird noch mal die gleiche Messung mit der persistenten Variante durchgeführt.

Auch hier wird einfach die bestehende Instanz der Implementierung DurablePersistenceService zurückgegeben. Der erste Schreibzugriff ist allerdings doppelt so teuer wie die folgenden. Dieses Phänomen lässt sich mit Optimierungen des Betriebssystems erklären.

Die relativen Messungen eignen sich hervorragend für Vergleiche der eingesetzten Algorithmen. Bei dem Vergleich der beiden Implementierungen wäre es besser, die echte, nicht die CPU-Zeit zu messen. Wir führen diese Messung also noch mal für die beiden Implementierungen durch. Allerdings wird die Messmethode des JProbe Profilers von CPU Time auf »Elapsed Time « umgeschaltet.

Die Messung zeigt, dass der VolatilePersistenceService bis zu Faktor 25,6 schneller ist als der DurablePersistenceService . Besonders langsam sind im DurablePersistenceService die Schreibzugriffe. Die Lesezugriffe sind aber auch bis zu Faktor 25,6 langsamer als die des VolatilePersistenceServices . Eigentlich sollten hier die Laufzeiten identisch sein, da die »Leselogik« der beiden Implementierungen identisch ist. Woran liegt es? Die Antwort liegt wiederum in der Implementierung des DurablePersistenceServices .

Die Loggingausgaben des DurablePersistenceServices verbrauchen insgesamt fast 90% der Methodenzeit. Die eigentliche Arbeit wird hier in 31,6 Mikrosekunden erledigt. Vergleichsweise verbraucht der VolatilePersistenceService 34,9 Mikrosekunden.

Wie wir gerade festgestellt haben, spielt aus Clientsicht die serverseitige Implementierung des Services fast keine Rolle. Über 80% der Gesamtzeit wird benötigt, um die entfernte Referenz überhaupt zu finden. Dieser Aufruf wäre beispielsweise ein Kandidat für die Auslagerung in den Initialisierungsblock der Komponenten. Das könnte die Methode init des Servlets oder des Framelets übernehmen. Die Geschäftslogikaufrufe sind nicht mehr so teuer. Allerdings sind sie viel aufwändiger als in der lokalen Konfiguration.

Wie wir gerade festgestellt haben, ist in unserem Fall der Mehraufwand des Remote-Aufrufs viel höher als die auf dem Server erledigte Arbeit. Besonders teuer ist die »Implementierungssuche« mit dem Aufruf Naming.lookup . Der Aufruf lookup ist sogar um ein Vielfaches teurer als die Erzeugung der Implementierung in der Startphase des Servers. Die Auslagerung der Funktionalität aus einem gewöhnlichen Client auf einen leistungsfähigen Server würde sich hier nicht lohnen. Erst bei komplizierteren Algorithmen wäre die Auslagerung sinnvoll. Die Implementierungen des Interfaces PersistenceServiceIF spielen hier eine besondere Rolle. Mit diesen ist erst die zentrale Datenhaltung möglich. Um diese Funktionalität nutzen zu können, muss man in diesem Fall leider den Performanceoverhead in Kauf nehmen. Da der Mehraufwand bei jedem Aufruf entsteht, wäre hier der Einsatz des » Value-Object «-Patterns möglich. Dazu müsste man auf der Clientseite die Parameter in einem Container-Objekt zusammenfassen. Zu diesem Zweck eignet sich besonders gut die HashMap- oder Properties- Klasse. Beide sind serialisierbar, was die »per-Value«-Übergabe voraussetzt.

Unsere Anwendung TestStarter hat bis jetzt jeden Wert einzeln gespeichert und dann gelesen.

hugo.store("test1","hallo1");
hugo.store("test2","hallo2");
hugo.store("huge",test);
hugo.getValue("test1");
hugo.getValue("test2");
hugo.getValue("huge");

Da hier immer ein Stub aufgerufen wird, handelt es sich um echte »Remote«-Aufrufe. Diese Aufrufe sind, im Vergleich zu den lokalen Aufrufen, ziemlich teuer. Um die Performance der Anwendung zu steigern, nimmt man hier oft Codierungsoverhead in Kauf. Die »Remote«-Aufrufe sollten vermieden werden. Zu diesem Zweck wird ein »Value Object« definiert, das die Parameter mehrerer Aufrufe sammelt. Dieses »Value Object« wird dann durch einen »Remote«-Aufruf übergeben. Diese Vorgehensweise erfordert aber mehr Handarbeit. Die teuren, »Remote«-Aufrufe werden durch mehrere, aber schnellere lokale Aufrufe ersetzt.

Da in unserem Beispiel die RMI-Aufrufe bis Faktor 30 teurer sind als die lokalen, geht die Rechnung auf. Die Gesamtzeit, die in der Methode test() benötigt wurde, beträgt jetzt 206213,0 und nicht 296882,1 Mikrosekunden.