Obgleich es möglich ist durch Konstruktor-Aufrufe entsprechende Tracer-Objekte zu erzeugen, sollte man üblicherweise hiervon absehen, da auf diese Weise die Nutzung spezieller Tracer "hart kodiert" wird. Dennoch kann man an diesem Beispiel einige der Grundprinzipien bei der Verwendung der Tracer erkennen:

In Zeile 1 wird ein FileTracer erzeugt. Der Name eines Tracer wird bei FileTracern als Logfilename wiederverwendet. Die open()-Methode in Zeile 2 wird demnach versuchen im Verzeichnis ./log das File Example.log anzulegen wobei das Verzeichnis ./log existieren muss. Mittels setLogDirPath(...) kann diese Voreinstellung überschrieben werden. Es empfiehlt sich das zugehörige close() - wie dargestellt - in einem finally-Block unterzubringen. In diesem Beispiel möchten wir die Methode bar() der Klasse Foo beobachten. Hierzu dienen die entry(...)- und wayout()-Aufrufe in den Zeilen 6 und 11. Es ist von entscheidender Bedeutung, dass jedes entry(...) mit einem wayout() in einem finally-Block wieder geschlossen wird. Der Aufruf foo.bar() in Zeile 16 wird keine Ausgabe zur Folge haben da für den ausführenden Thread noch kein Tracing-Kontext zur Verfügung steht. Zeile 17 erzeugt nun einen Tracing-Kontext der besagt, dass wir für diesen Thread bis zu einer Stapeltiefe von 2 an Ausgaben interessiert sind. Nachdem der Tracer wieder geschlossen wurde, enthält das File Example.log nachstehendes Tracing:

In den Zeilen 1 bis 4 ist vermerkt worden zu welcher Zeit und mit welchen Einstellungen der Tracer geöffnet wurde. In Zeile 6 ist notiert, dass die Methode bar() der Klasse Foo vom main-Thread mit der Id 1 aufgerufen wurde. Die Foo-Instanz hatte den System-Identity-Hashcode 12275192. Entsprechendes sehen wir in Zeile 8 als die Methode die Steuerkontrolle wieder abgegeben hatte. Es ist keine messbare Zeit zwischen Aufruf und Verlassen der Methode verstrichen.

[Oben]

Bei Verwendung der TracerFactory können Tracer per Namen angefordert werden. Die entsprechende Methode gibt einen (polymorphen) AbstractTracer zurück. Ohne den Code zu ändern kann der Typ des Tracers via Konfiguration ausgetauscht werden. Statt ins lokale Filesystem zu tracen, kann bspw. völlig transparent auch übers Netzwerk an ein Logging-Server gesendet werden.

Beginnend mit Zeile 4 wird in obiger Konfiguration ein FileTracer mit Namen "ExampleTracer" definiert. Dessen zugehöriges Logfile wird ./log/ExampleTracer.log sein. Jedesmal wenn eine Methode wieder vom Stapel geholt wird, wird der PrintStream des Tracers "geflusht" werden. Nach etwa einem MebiByte (= 1024*1024 Byte) wird ein Backup des Logfile durchgeführt. Der Tracer ist an Ausgaben vom main-Thread bis zu einer Stapeltiefe von 5 interessiert. Weitere Tracer sind im Pool nicht definiert. Diese Konfiguration kann unter der Annahme, dass sie im File ./config/ExampleConfig.xml abgelegt ist, wie folgt genutzt werden:

Dies wird zu folgender Ausgabe führen:

Diese Vorgehensweise ist sinnvoll wenn man einzelne Klassen in einer Single-Thread-Anwendung analysieren möchte. In einer Multi-Thread-Umgebung würden Tracing-Ausgaben hier nur erfolgen wenn die betreffenden Code-Teile vom main-Thread ausgeführt werden. Es ist möglich einen Tracer für mehrere Threads zu registrieren. Dann muss man aber die Zugriffe auf den Ausgabestream via tracer.getSyncObject() selbst synchronisieren. Stattdessen sind die nachstehenden Verfahren anzuraten:

[Oben]

Diese Vorgehensweise empfiehlt sich für Multi-Thread-Anwendungen bei denen man die Kontrolle über die Thread-Erzeugung hat. Für jeden Thread wird dann ein Tracer definiert auf den man via TracerFactory.getInstance().getCurrentPoolTracer() zugreifen kann. Bei der Erzeugung der Threads ist darauf zu achten, dass diese eindeutige Namen erhalten. Intern werden die Tracer durch eine Map<Long, AbstractTracer> organisiert. Vor der Programmausführung existieren jedoch noch keine Thread-Objekte (oder Thread-Ids) und deswegen muss die Assoziation zwischen Thread und Tracer in der Konfiguration über den Namen erfolgen:

In obiger Konfiguration definieren wir drei Tracer (WorkerTracer-0, WorkerTracer-1, WorkerTracer-2) die an Ausgaben dreier Worker-Threads (Worker-0, Worker-1, Worker-2) interessiert sind. Außerdem definieren wir eine Abbildung zwischen Thread und Tracer (Worker-0 => WorkerTracer-0, Worker-1 => WorkerTracer-1, Worker-2 => WorkerTracer-2). Nachstehendes Code-Snippet verdeutlicht wie obige Konfiguration ausgenutzt werden kann:

Zunächst definieren wir die Klasse Foo welches die Callable<V>-Schnittstelle implementiert. Auf diese Weise können Instanzen von Foo einem ExecutorService zur nebenläufigen Ausführung übergeben werden. Zusätzlich implementiert die Klasse Foo die Schnittstelle Traceable. Über die Indirektion getCurrentTracer() kann die Konfiguration überschrieben werden. Schreiben wir in Zeile 41 etwa return TracerFactory.getInstance().getDefaultTracer(); statt return TracerFactory. getInstance().getCurrentPoolTracer(); so wird für das Tracing ein NullTracer verwendet der lediglich das Logstatement in Zeile 12 an den JDK-Logger weiterleitet und ansonsten alle Tracing-Ausgaben verwirft. Ebenso wird die Methode getCurrentPoolTracer() der TracerFactory uns einen NullTracer liefern falls kein Tracer für den gegenwärtigen Thread definiert ist. Einen ExecutorService besorgen wir uns über die Executors-Factory in Zeile 52. Dieser ExecutorService arbeitet mit drei Threads die wir mit einer eigenen ThreadFactory erzeugen. So können wir den Threads die gewünschten Namen (und ggf. weitere Eigenschaften) verleihen. Als nächstes bekommt ExecutorService der Reihe nach 100 Foo-Instanzen zur Ausführung. Welcher der drei Threads welchen Auftrag bekommt ist nicht-deterministisch, d.h. die Ausgaben der 100 Foo-Instanzen werden sich mehr oder weniger unvorhersehbar auf die drei Logs aufteilen - allerdings werden Ausgaben die aus dem Worker-0-Thread getätigt wurden immer im Log des WorkerTracer-0 landen, usw. Einen Auszug der Tracing-Ausgaben aus dem Log des WorkerTracer-0 sehen Sie nachstehend:

Manchmal haben wir jedoch die Thread-Erzeugung nicht wie in diesem Beispiel unter Kontrolle. Dann sind wir weder in der Lage die Eindeutigkeit der Thread-Namen zu garantieren noch kennen wir diese vor Ausführung der Anwendung und können deshalb auch kein Mapping von Thread(name) auf Tracer definieren. In diesem Fall kann die Tracer-Queue benutzt werden, siehe nachstehendes Beispiel:

[Oben]

Java EE-Anwendungen laufen unter der Kontrolle eines Java EE Anwendungsservers der selbst Thread-Pools verwaltet um eingehende Anforderungen zu bearbeiten oder Nachrichten weiterzuleiten. Obgleich es in gewissem Umfang möglich sein kann die Thread-Pools in unserem Sinne zu konfigurieren, ist dies manchmal nicht ausreichend. In solchen Fällen definieren wir eine Queue mit uniformen Tracern aus der wir uns bedienen wenn wir einen Request nachverfolgen wollen. Die Queue wird blockieren wenn kein Tracer mehr vorrätig ist. Dies beschränkt die Anzahl der Requests die der Java EE Anwendungsserver parallel bearbeiten kann ungeachtet der Größe seiner Thread-Pools. Wird die letzte Methode aus dem Anwendungsstapel eines Tracers wieder herausgenommen, wird der gegenwärtige Tracing-Kontext gelöscht und der Tracer wird automatisch an die Queue zurückgegeben. Betrachten wir zunächst nachstehende Konfiguration einer Queue mit fünf Tracern:

Beachten Sie die Vereinbarung bzgl. des Log-Verzeichnisses in Zeile 8. Da die Beispielanwendung unter Verwendung eines Tomcat 7 entwickelt wurde, benutzen wir dessen catalina.base-System-Eigenschaft um das logs-Verzeichnis der Tomcat-Distribution zu referenzieren. Unter der Annahme, dass diese Konfiguration der Anwendung als Resource dem Package de.christofreichardt.infraservlet beiliegt, können wir nachstehenden WebFilter implementieren:

In Zeile 21 besorgen wir uns durch die init()-Methode des Servlets die XML-Konfigurations-Resource als InputStream und initialisieren die TracerFactory entsprechend. Anschließend werden die Ausgabestreams der (Queue-)Tracer geöffnet. Umgekehrt werden beim Herunterfahren der Tomcat-Servlet-Engine - wenn die destroy()-Methode aufgerufen wird - die Ausgabestreams der Tracer wieder geschlossen, siehe Zeile 46. Die eigentliche Nachverfolgung des Requests findet in der doFilter()-Methode statt. Zunächst besorgen wir uns in Zeile 6 einen Tracer aus der Queue. Die Methode takeTracer() wird blockieren falls momentan kein Tracer vorrätig ist. Anschließend müssen wir einen aktuellen Tracing-Kontext erzeugen. Dann legen wir ein Bild der doFilter()-Methode auf den Aufrufstapel dieses Tracing-Kontextes. Da die doFilter()-Methode den Anfang des Callstacks bzgl. des Requests definiert wird umgekehrt in Zeile 15 nicht nur das Bild der doFilter()-Methode wieder vom Stapel genommen sondern zugleich auch der Tracing-Kontext gelöscht und der Tracer an die Queue zurückgegeben.

Dieser WebFilter ist nachstehendem Servlet mit dem Namen "MyTracingServlet" vorgeschaltet. Die Idee ist es, dass wir das Tracing ausschalten können, einfach indem wir das "MyTracingServlet" aus der servletNames-Vereinbarung des obigen WebFilters in Zeile 1 herausnehmen. Es werden dann lediglich Log-Meldungen an den JDK-Logger weitergereicht.

Das Servlet implementiert wieder die Traceable-Schnittstelle. So können wir die Konfiguration ggf. in Zeile 30 überschreiben. Die Methode processRequest() bearbeitet die GET-Anforderung. In Zeile 5 besorgen wir uns (nicht-blockierend) den Tracer für den Thread der dem Request zugeteilt wurde. Die Zeilen 3, 6 und 7 zählen die Anforderungen und loggen die entsprechende Request-Id. Bei aktivem Trace-Filter sieht die Nachverfolgung eines Request wie unten gezeigt aus:

Nun ist auch die Zuordnung zwischen Tracer und Thread nicht-deterministisch. Schalten wir jetzt das Tracing für das Servlet aus - durch entsprechende Konfiguration des WebFilters - wird lediglich die Log-Meldung aus Zeile 7 an den JDK-Logger weitergereicht. Geeignete logging.properties vorausgesetzt, könnte das konventionelle Logging dann so aussehen:

[Oben]