FieldLog developer guide

Diese Dokumentation bietet Nutzern der FieldLog-Bibliothek einen Überblick der Programmierschnittstelle und fasst die Funktionen in Gruppen zusammen.

Please bring about 25 minutes to read this page in peace.

Woraus besteht FieldLog?

FieldLog ist eine Klassenbibliothek, die entweder als separate DLL-Datei referenziert oder mit ihren Quelltextdateien in die Anwendung integriert wird. Welche Methode gewählt wird, hängt von den Anforderungen der Anwendung ab. Die DLL-Datei ist einfacher zu verwenden und zu aktualisieren, muss aber mit der Anwendung weitergegeben werden. Bei der Integration des Quelltextes ist zur Laufzeit keine separate Datei erforderlich.

Der wesentliche Bestandteil von FieldLog ist die statische FL-Klasse, die alle Protokollierungsmethoden bereitstellt. Diese Klasse wird in der Regel von Anwendungen genutzt. Beim Anwendungsstart wird ein separater Thread gestartet, der das Schreiben der Protokolldateien durchführt. Alle Protokolleinträge werden vorbereitet und über Warteschlangen an diesen Thread übergeben.

Was wird geschrieben?

FieldLog unterstützt die Protokollierung verschiedener Eintragstypen. Dazu gehören Text, Variablen (einfache und strukturierte Daten), Ausnahmefehler, verschiedene Bereichsangaben und Zeitmessung/Zähler.

Schreibt einen Eintrag in die Protokolldatei. Dies ist die allgemeinste Protokollierungsmethode, die normalerweise nicht verwendet wird. Es gibt für jeden der nachfolgend beschriebenen Eintragstypen eine von FieldLogItem abgeleitete Klasse:

• FieldLogTextItem – Text
• FieldLogDataItem – Daten
• FieldLogExceptionItem – Ausnahmefehler
• FieldLogScopeItem – Bereichsangaben

Für diese Eintragstypen gibt es auch Methoden in der FL-Klasse, die mit einer spezifischen Signatur den Aufruf vereinfachen.

Text

Texteinträge bestehen aus einem String, der direkt ins Protokoll geschrieben wird. Der String kann Zeilenumbrüche enthalten und mehrere Millionen Zeichen lang sein, im Log-Viewer wird er in der Liste aber immer nur einzeilig dargestellt. Um längere Texte wie z. B. XML-Dokumente oder SQL-Abfragen zu protokollieren, sollte der optionale zweite String genutzt werden. Der erste String sollte dann nur eine beschreibende Zusammenfassung enthalten. Beide Strings (Text und Details) werden im Log-Viewer vollständig dargestellt, wenn der Eintrag ausgewählt ist.

Es gibt eine allgemeine Methode für Text-Einträge sowie separate Methoden für Text-Einträge einer bestimmten Priorität. Diese Methoden sind teilweise für andere Eintragstypen überladen.

Schreibt einen Text-Eintrag mit der Priorität, die der Methodenname beschreibt (Trace, Checkpoint, Info, Notice, Warning, Error, Critical). Diese Methoden werden in der Anwendung wohl am häufigsten verwendet.

Schreibt einen Text-Eintrag mit der angegebenen Priorität.

Variablen

Um zur Laufzeit bestimmte Variablen zu beobachten und deren Inhalt zu prüfen, können ähnlich dem Debugger Variablen mit ihrem Namen und Wert ins Protokoll geschrieben werden. Diese Einträge erhalten im Log-Viewer ein eigenes Symbol und eine Darstellung von Name und Wert in der Liste.

Der Variablenwert wird der Log-Funktion als object übergeben, in der Protokolldatei aber immer als String gespeichert. Skalare Werte wie Zahlen oder Strings werden direkt gespeichert. Für strukturierte Werte werden mittels Reflection alle öffentlichen Instanzeigenschaften und -felder ermittelt und deren Wert gespeichert. Diese Formatierung folgt auch weiteren strukturierten Werten.

Es gibt eine allgemeine Methode für Daten-Einträge sowie separate Methoden für Daten-Einträge einer bestimmten Priorität.

Schreibt einen Daten-Eintrag mit der Priorität, die der Methodenname beschreibt.

Schreibt einen Daten-Eintrag mit der angegebenen Priorität.

Ausnahmefehler

Ausnahmefehler (Exceptions) enthalten eine ganze Reihe von wichtigen Angaben, die zur Fehlersuche benötigt werden können. Dazu gehört nach dem Fehlertyp und dem Meldungstext der Stacktrace, der die Reihenfolge der aufgerufenen Methoden beschreibt, als der Fehler aufgetreten ist. In klassischen Logsystemen wird dieser Typ mehrzeilig dargestellt und hat dadurch eine ganz andere Struktur als einfache Texteinträge. FieldLog kann aufgrund der strukturierten Protokolldateien alle Detailinformationen aufzeichnen und dennoch eine übersichtliche Listenansicht bereitstellen. Alle Details werden angezeigt, wenn der Eintrag ausgewählt ist.

Ein Ausnahmefehler-Eintrag umfasst die folgenden Daten:

• Ausnahmetyp (vollständiger Klassenname)
• Meldungstext (Exception.Message)
• Code
• Zusätzliche Daten (Exception.Data sowie weitere Eigenschaften des konkreten Ausnahmetyps, mittels Reflection ermittelt)
• Stacktrace
• Verschachtelte Ausnahmefehler (Exception.InnerException)
• Kontext (zusätzliche Angabe der Anwendung zur Beschreibung des Fehlerorts)
• Umgebungsdaten

Die Umgebungsdaten sind eine weitere Besonderheit von FieldLog. Diese Daten werden auch zum Anwendungsstart aufgezeichnet und erlauben eine Analyse des Systems, in dem die Anwendung ausgeführt wird. Dazu gehören die folgenden Daten:

• Betriebssystem: Typ, Version, Edition, Service Pack, …
• Architektur (32/64 Bit) des Systems und Prozess, Anzahl der CPUs
• Sprache: Betriebssystem, aktuelle Kultur
• Anwendungskompatibilität
• CLR-Typ (.NET, Mono) und -Version
• Maustasten, Touch-Eingabe
• Bildschirm: Größe, Arbeitsfläche, Auflösung (dpi), Anzahl
• Programmpfad und Kommandozeile
• Anwendungsversion
• Arbeitsverzeichnis, Umgebungsvariablen
• Rechner- und Benutzername, Administratorkonto, Interaktive Sitzung
• Speicherverbrauch des Prozess (aktuell, Spitze), verfügbarer Speicher
• Lokale Zeitzone, Boot-Zeitpunkt, abgesicherter Modus

Es gibt eine allgemeine Methode für Ausnahmefehler-Einträge sowie separate Methoden für Ausnahmefehler-Einträge einer bestimmten Priorität. Diese Methoden sind teilweise für andere Eintragstypen überladen.

Schreibt einen Ausnahmefehler-Eintrag mit der Priorität, die der Methodenname beschreibt. Der Kontext kann von der Anwendung angegeben werden, um den Protokolleintrag schneller einer bestimmten Aktivität zuzuordnen, z. B. „Schreiben der Datei“ oder „Herstellen der Netzwerkverbindung“. Optional kann auch der Anwendungsfehlerdialog angezeigt werden, der dem Benutzer erklärt, was passiert ist, wie er fortfahren kann und wo sich die Protokolldateien befinden.

Schreibt einen Ausnahmefehler-Eintrag mit der angegebenen Priorität.

Bereichsangaben

Es gibt verschiedene Arten von Bereichsangaben, mit denen Beginn und Ende eines Codeabschnitts markiert werden können. Neben allgemeinen Bereichen, die für Methoden oder Teile davon verwendet werden können, gibt es Markierungen für Threads, Web-Zugriffe und die ganze Anwendung. Beginn und Ende der Anwendung (LogStart und LogShutdown) werden von FieldLog automatisch ins Protokoll geschrieben. Mit dem LogStart-Eintrag werden auch die gleichen Umgebungsdaten wie bei Ausnahmefehlern (siehe oben) erfasst. Andere Bereichsarten müssen per Code protokolliert werden.

Die Markierung allgemeiner Bereiche führt im Log-Viewer zur Einrückung der Protokolleinträge, die innerhalb des Bereichs geschrieben wurden. Dadurch lässt sich schnell erkennen, wann eine Methode wieder verlassen wurde oder welche Einträge von einem Unteraufruf verursacht wurden. Die Einrückungsebene wird dabei für jeden Thread separat mitgezählt.

Durch die Protokolleinträge zum Beginn und Ende eines Bereichs ist im Log-Viewer über deren Zeitstempel auch eine Zeitmessung des Codeabschnitts möglich.

Schreibt einen Eintrag zum Beginn bzw. Ende eines allgemeinen Bereichs. Der Name kann ein Methodenname oder eine andere Bezeichnung sein, die der Entwickler zuordnen kann.

Schreibt einen Bereichs-Eintrag, dessen Art und Beginn/Ende mit dem ersten Parameter festgelegt wird: Enter, Leave, ThreadStart, ThreadEnd, WebRequestStart, WebRequestEnd, LogStart, LogShutdown. (Die letzten beiden Werte sollten nicht direkt von der Anwendung geschrieben werden.)

Neben den Methoden, die einen einzelnen Eintrag protokollieren, gibt es die Hilfsklassen FieldLogScope und FieldLogThreadScope, die durch Implementierung der IDisposable-Schnittstelle sicherstellen, dass das Verlassen des Bereichs nicht übersprungen wird. Diese Klassen werden in Anwendungen nicht direkt verwendet, sondern durch Methoden der FL-Klasse bereitgestellt.

Schreibt Bereichs-Einträge um den Codeabschnitt herum. Diese Schreibweise stellt sicher, dass auch bei auftretenden Ausnahmefehlern im Codeabschnitt oder vorzeitigen return-Anweisungen dessen Ende protokolliert wird. Wenn der Name nicht angegeben wird, wird der Name der aufrufenden Methode aus dem Stacktrace mittels Reflection ermittelt. Das ist einfacher zu schreiben, benötigt aber mehr Zeit während der Ausführung (ca. 6 µs statt 1 µs). Dasselbe ist auch mit der FL.ThreadScope-Methode zur Markierung von Threads möglich, sofern ein Thread in einer Einstiegsmethode zusammengefasst wird.

Führt den angegebenen Delegat (Action oder Func) aus und schreibt Bereichs-Einträge um dessen Ausführung herum. Diese Schreibweise vereinfacht die Kennzeichnung für den Aufruf einzelner Methoden. Der Rückgabewert von Funktionen wird weitergegeben. Wenn der Name nicht angegeben wird, wird der Name der aufgerufenen Methode mittels Reflection ermittelt. (Diese Methoden sind nur ab .NET 4 verfügbar.) Das folgende Beispiel zeigt, wie ein bestehender Funktionsaufruf markiert werden kann:

Zeitmessung/Zähler

Spezielle Methoden zur Zeitmessung ermöglichen die Erfassung und Protokollierung der aufsummierten und durchschnittlichen Dauer, die ein bestimmter Codeabschnitt oder mehrere Codeabschnitte, die gemeinsam betrachtet werden sollen, zur Ausführung benötigen. Die Verwendung ist ähnlich der Methoden zu Bereichsangaben. FieldLog verwaltet CustomTimerInfo-Instanzen, auf die mit einem Schlüssel zugegriffen werden kann. Beim Starten eines Timers wird dessen Zähler um 1 erhöht. Nach Anhalten eines Timers wird die gemessene Zeit zusammen mit dem Zählerstand nach einer kurzen Verzögerung ins Protokoll geschrieben. Bei schnell aufeinanderfolgenden Zeitmessungen wird nur der letzte Stand geschrieben.

Startet einen Timer mit dem angegebenen Schlüssel, hält ihn an oder setzt ihn zurück. Der Parameter incrementCounter gibt an, ob der Zähler erhöht werden soll (Vorgabe: true). Der Parameter writeNow gibt an, ob der Messwert ohne Verzögerung sofort protokolliert werden soll (Vorgabe: false).

Startet einen Timer mit dem angegebenen Schlüssel, bevor der Codeabschnitt ausgeführt wird, und hält ihn an, sobald der Codeabschnitt verlassen wird. Diese Schreibweise stellt sicher, dass auch bei auftretenden Ausnahmefehlern im Codeabschnitt der Timer angehalten wird. Der Parameter writeImmediately gibt an, ob der Messwert nach Verlassen des Codeabschnitts ohne Verzögerung sofort protokolliert werden soll.

Führt den angegebenen Delegat (Action oder Func) aus und startet einen Timer um dessen Ausführung herum. Diese Schreibweise vereinfacht die Messung einzelner Methoden. Der Rückgabewert von Funktionen wird weitergegeben. Wenn der Schlüssel nicht angegeben wird, wird der Name der aufgerufenen Methode mittels Reflection ermittelt. Die Parameter incrementCounter und writeImmediately sind hier nicht dargestellt. (Diese Methoden sind nur ab .NET 4 verfügbar.) Das folgende Beispiel zeigt, wie ein bestehender Funktionsaufruf gemessen werden kann:

Wie wird geschrieben?

Prioritäten

Jeder Protokolleintrag hat eine Priorität, die aussagt, wie wichtig der Eintrag ist. Die Priorität wird im Log-Viewer deutlich hervorgehoben und sie legt wesentlich die Vorhaltezeit des Eintrags im Protokoll fest. Die spezifischen Methoden für Prioritäten wurden oben bereits beschrieben. Die folgenden Erklärungen dienen dazu, die geeignete Priorität für einen Protokolleintrag zu wählen.

• Trace: Detaillierte Informationen zur Ablaufverfolgung, für den Entwickler.
  Beispiele: Benutzer will eine Datei laden. / 5 Dateien zur Auswahl gefunden. / (Die meisten Daten-Einträge)
• Checkpoint: Informationen zur Ablaufverfolgung, für den Entwickler.
  Beispiele: Durchsuchen weiterer Verzeichnisse abgeschlossen. / Erster Teil der Datei wurde verarbeitet.
• Info: Informative Meldung bei normalem Ablauf.
  Beispiele: Die Datei wurde geladen.
• Notice: Besondere informative Meldung.
  Beispiele: Die Datei ist in einem alten Format und hätte längst aktualisiert werden sollen.
• Warning: Warnung, möglicherweise liegt ein Fehler vor.
  Beispiele: Unbekannte Einträge in der Datei wurden ignoriert, aber sie könnten eine wichtige Bedeutung haben.
• Error: Fehlerzustand, der normal behandelt werden kann.
  Beispiele: Datei kann nicht geschrieben werden, der Benutzer wurde informiert und hat alternative Möglichkeiten.
• Critical: Kritischer Fehlerzustand, der die (richtige) Funktion der Anwendung oder eines wesentlichen Teils davon verhindert.
  Beispiele: Zu wenig Speicher verfügbar oder Assembly-Datei fehlt, das Programm kann nicht fortgesetzt werden.

Dateiaufteilung

Die Einträge werden in verschiedene Dateien geschrieben, die nach Priorität aufgeteilt sind und jeweils eine Maximalgröße einhalten. Die Protokolldateien haben dabei folgendes Namensschema: ‹Präfix›-‹Priorität›-‹Anfangszeit›.fl Der Präfix wird aus dem Anwendungsnamen abgeleitet und kann per API-Aufruf oder Konfigurationsdatei festgelegt werden. Die Priorität ist der nummerische Wert von 0 (Trace) bis 6 (Critical). Die Anfangszeit ist die Zahl der Ticks des DateTime-Werts zum Zeitpunkt der Erstellung der Datei.

Der Inhalt der Protokolldateien wird in einem optimierten Binärformat geschrieben. Es sind also keine Textdateien. Zum Lesen der Dateien wird die Anwendung FieldLogViewer benötigt, die Teil dieses Projekts ist. Die Dateiformatspezifikation ist im Quelltext enthalten.

Protokolldateien werden automatisch gelöscht, wenn ihre Vorhaltezeit abgelaufen ist. Außerdem wird die konfigurierte maximale Datenmenge der Protokolldateien eingehalten. Die Gesamtgröße des Protokolls berücksichtigt die Dateigröße auf dem Datenträger, wenn NTFS-Komprimierung aktiviert ist. Bei Überschreiten des Grenzwerts werden die ältesten Dateien (ungeachtet der Priorität) gelöscht, bis die Datenmenge unter dem Grenzwert liegt.

Wann wird geschrieben?

Protokolleinträge werden meist sofort und bedingungslos ins Protokoll geschrieben. (Aufgrund der Verteilung der Threads und der Optimierung der Pufferzugriffe treten Verzögerungen von 200 ms bis zum Erreichen der internen Schreibpuffergröße auf.) Daneben können Einträge aber auch vorgehalten werden, wobei sie nur dann in die Datei geschrieben werden, wenn ein anderer (normaler) Eintrag geschrieben wird. Außerdem ist die Protokollierung von Timeouts möglich, wobei der Eintrag nur nach Ablauf einer bestimmten Zeit geschrieben wird, z. B. wenn eine blockierende Funktion nicht zurückkehrt. Für WPF-Anwendungen stehen Methoden bereit, mit denen das Erreichen einer bestimmten DispatcherPriority protokolliert werden kann. Im Rahmen der Behandlung ansonsten unbehandelter Ausnahmefehler werden die auftretenden Fehler automatisch ins Protokoll geschrieben.

Vorhaltespeicher

Normalerweise werden alle Einträge in die Protokolldatei geschrieben. Das kann sehr umfangreich werden. Reduziert man den Detailgrad der Protokollierung, fehlen im Fehlerfall möglicherweise interessante Verarbeitungsdaten. Hier lässt sich der Vorhaltespeicher einsetzen. Mit der LogRetained-Methode wird ein Protokolleintrag in einem Zwischenspeicher abgelegt. Dort werden alle Einträge gesammelt, die mit dieser Methode erstellt wurden. Dieser Speicher kann jetzt entweder mit der ClearRetained-Methode komplett verworfen werden. Dann wird kein einziger der vorgehaltenen Einträge ins Protokoll geschrieben. Oder es wird ein Eintrag regulär geschrieben. Dann werden davor noch alle vorgehaltenen Einträge geschrieben und der Zwischenspeicher geleert. Dadurch lassen sich sehr detailliert die verarbeiteten Daten protokollieren, die aber nur im Fall eines Problems (Ausnahmefehler wird in anderer Funktion behandelt) tatsächlich gespeichert werden und so die Lesbarkeit des Protokolls deutlich verbessern.

Schreibt einen Eintrag in den Zwischenspeicher. Daneben gibt es noch viele weitere Log-Methoden, deren Name auf „Retained“ endet. Sie sind etwa in der gleichen Vielfalt wie die oben beschriebenen Methoden verfügbar.

Löscht den Zwischenspeicher mit vorgehaltenen Einträgen. Diese Methode darf dafür nicht im finally-Block aufgerufen werden, sondern soll beim außerplanmäßigen Verlassen der Funktion sogar explizit nicht aufgerufen werden, um den Zwischenspeicher nicht verfrüht wieder zu löschen.

Der catch-Block im Beispiel ist optional; Ausnahmefehler werden dann vor einer anderen Funktion behandelt und ClearRetained wird gar nicht aufgerufen. Wichtig ist aber, dass im Fehlerfall (oder generell, wenn ClearRetained umgangen wird) ein weiterer (normaler) Eintrag geschrieben wird, denn nur dann werden die vorgehaltenen Einträge geschrieben und der Zwischenspeicher geleert.

Jeder Thread hat einen separaten Zwischenspeicher. Die LogRetained-Methode kann also nicht genutzt werden, wenn Einträge aus mehreren Threads vorgehalten werden sollen.

Timeout

Eine weitere Möglichkeit, Protokolleinträge unter bestimmten Bedingungen zeitverzögert zu schreiben, bietet die Timeout-Funktion. Damit lassen sich ohne aufwändige zusätzliche Multithreading-Arbeiten Protokolleinträge schreiben, die mitteilen, dass eine bestimmte Funktion länger als erwartet blockiert. Auch dann, wenn sie gar nicht zurückkehrt. Auf der Suche nach Deadlocks kann man so im laufenden Programm erkennen, in welcher Funktion sich die Ausführung gerade befindet.

DispatcherPriority

Für Performance-Messungen oder zur Analyse der Ausführungsreihenfolge bestimmter Vorgänge in WPF-Anwendungen gibt es eine Reihe von Methoden, die die Protokollierung von DispatcherPriority unterstützen. (Diese Methoden sind nur ab .NET 4 verfügbar.)

Schreibt einen Text-Eintrag mit der angegebenen Priorität, sobald alle anstehenden Aufgaben der angegebenen Dispatcher-Priorität ausgeführt wurden.

Schreibt einen Text-Eintrag mit Trace-Priorität, sobald alle anstehenden Aufgaben der angegebenen Dispatcher-Priorität ausgeführt wurden.

Schreibt einen Text-Eintrag mit Trace-Priorität, sobald alle anstehenden Aufgaben der Dispatcher-Priorität, die der Methodenname beschreibt (Background, Input, Loaded, Render, DataBind), ausgeführt wurden.

Hält einen Timer mit dem angegebenen Schlüssel an, sobald alle anstehenden Aufgaben der angegebenen Dispatcher-Priorität ausgeführt wurden.

Startet einen Timer mit dem angegebenen Schlüssel und hält ihn wieder an, sobald alle anstehenden Aufgaben der angegebenen Dispatcher-Priorität ausgeführt wurden.

Ausnahmefehler

FieldLog registriert automatisch Methoden, um unbehandelte Ausnahmefehler in diversen Situationen abzufangen und zu protokollieren. Unbehandelt führen diese Fehler meistens entweder zum sofortigen Beenden der Anwendung oder sie bleiben unerkannt und führen zu beliebigem Fehlverhalten der Anwendung im weiteren Verlauf. Die folgenden Ereignisse werden unterstützt:

• AppDomain.CurrentDomain.UnhandledException
  Tritt bei Ausnahmefehlern in Nicht-UI-Threads auf.
  Kontext: „AppDomain.UnhandledException“
• AppDomain.CurrentDomain.FirstChanceException (.NET 4)
  Tritt bei nahezu jedem Ausnahmefehler auf, auch wenn er behandelt wird. Bei diesem Ereignis werden keine Umgebungsdaten erfasst, da das in manchen Situationen zu weiteren Fehlern führt. Die Protokollierung dieses Ereignisses kann mit der FL.LogFirstChanceExceptions-Eigenschaft gesteuert werden.
  Kontext: „AppDomain.FirstChanceException“
• System.Windows.Forms.Application.ThreadException
  Tritt bei Ausnahmefehlern im UI-Thread von Windows-Forms-Anwendungen auf.
  Kontext: „WinForms.ThreadException“
• Dispatcher.CurrentDispatcher.UnhandledException (.NET 4)
  Tritt bei Ausnahmefehlern im UI-Thread von WPF-Anwendungen auf.
  Kontext: „WPF.DispatcherUnhandledException“
• System.Threading.Tasks.TaskScheduler.UnobservedTaskException (.NET 4)
  Tritt bei Ausnahmefehlern in Tasks auf. Aufgrund der Art und Weise, wie diese Fehler erkannt werden, tritt dieses Ereignis praktisch nie auf.
  Kontext: „TaskScheduler.UnobservedTaskException“

PresentationFramework-Meldungen

In WPF-Anwendungen gibt es eine Reihe von Meldungsquellen, die üblicherweise in das Ausgabefenster des Visual-Studio-Debuggers schreiben. Dazu gehören die bekannten Fehler- und Warnmeldungen zum Data-Binding, die über falsche Datentypen oder nicht vorhandene Eigenschaften informieren. Diese „Fehler“ führen nicht zum Absturz des Programms, deuten jedoch meistens auf Fehlfunktionen hin, die korrigiert werden müssen.

WPF-Anwendungen können die Protokollierung dieser Meldungen bei Bedarf mit der FL.Register­Presentation­Tracing-Methode aktivieren (siehe Initialisierung weiter unten). Viele häufig auftretende Meldungen werden von FieldLog besonders unterstützt und mit einer Kurzfassung gut lesbar aufbereitet. In Visual Studio sind die Meldungstexte dagegen eher unübersichtlich und schwer zu analysieren.

Initialisierung

Die Protokollierung steht der Anwendung unmittelbar ab dem Start zur Verfügung. Allerdings besteht für die Anwendung noch die Möglichkeit, das Protokollverzeichnis abweichend von den automatisch gewählten Optionen festzulegen. Bevor dieses Verzeichnis festgelegt ist, können keine Einträge in die Protokolldateien geschrieben werden. Deshalb muss die Anwendung gleich zu Beginn entweder ein neues Verzeichnis oder einen abweichenden Protokoll-Präfix festlegen oder die Standardstrategie akzeptieren. Erst danach werden Einträge (auch bereits gesammelte, wie der LogStart-Eintrag) geschrieben. Wenn diese Initialisierung bis zum Programmende nicht erfolgt (z. B. wenn bereits vorher ein kritischer Fehler auftritt), werden alle gesammelten Einträge nach der Standardstrategie gespeichert.

Die Behandlung von Ausnahmefehlern wird im Typinitialisierer (statischer Konstruktor) der FL-Klasse aktiviert. Aufgrund der verzögerten Typinitialisierung in .NET wird die Ausführung dieser Methode nicht vor der ersten Verwendung des FL-Typs garantiert. Der Aufruf eines beliebigen Members der FL-Klasse ist dafür ausreichend. Falls gleich zum Programmstart keine FL-Methode sinnvoll aufgerufen werden kann, kann die Use-Methode dafür genutzt werden. Diese Methode tut nichts, außer dass sie vom Aufrufer genannt wird.

Die folgenden Methoden dienen zum Festlegen des Protokollpfads.

Setzt den Präfix für die Protokolldateien. Vorgabe ist der Dateiname der Anwendung ohne Erweiterung.

Setzt das Verzeichnis, in das die Protokolldateien geschrieben werden.

Akzeptiert die Standardstrategie zum Ermitteln des Protokollverzeichnisses. Diese Methode wird von den meisten Anwendungen gleich zu Beginn aufgerufen.

Registriert Handler für die Ablaufverfolgung in WPF-Anwendungen. Diese Methode ist nur in WPF-Anwendungen relevant und kann unmittelbar nach einer der drei zuvor genannten Methoden zum Beginn der Anwendung aufgerufen werden.

Auswahl des Protokollverzeichnisses

FieldLog versucht automatisch, ein geeignetes Verzeichnis zur Speicherung der Protokolldateien zu finden. Dabei werden folgende Verzeichnisse betrachtet und das erste, in dem Schreibzugriffe möglich sind, wird verwendet. Es wird versucht, das Verzeichnis zu erstellen, wenn es noch nicht existiert.

1. Das Verzeichnis, das mit der FL.SetCustomLogFileBasePath-Methode oder mit der path-Einstellung in der Konfigurationsdatei (siehe unten) angegeben wurde.
2. Das Unterverzeichnis „log“ im Verzeichnis der Programmdatei. Das ist der empfohlene Speicherort für Protokolldateien. Wenn die Anwendung im Programme-Verzeichnis installiert wird, sollte das Installationsprogramm dieses Verzeichnis mit Benutzerschreibzugriff erstellen.
3. Das Verzeichnis der Programmdatei.
4. Das Unterverzeichnis „(Programmdatei)-log“ im Verzeichnis „Eigene Dokumente“ des aktuellen Benutzers. Falls sich dieses Verzeichnis unterhalb des Windows-Verzeichnisses befindet, handelt es sich um ein Systemkonto. Da selbst Administratoren nicht ohne Weiteres Zugriff auf diese System-Profilverzeichnisse haben, wird dieses Verzeichnis nicht verwendet.
5. Das Unterverzeichnis „(Programmdatei)-log“ im Verzeichnis für temporäre Dateien.

Wenn selbst nach allen Optionen kein geeignetes Verzeichnis gefunden wurde, werden keine Protokolldateien geschrieben.

ASP​.NET-Webanwendungen

Zur Unterstützung der Protokollierung in ASP​.NET-Webanwendungen werden spezielle Methoden bereitgestellt. Da diese Methoden Typen verwenden müssen, die nicht im Client Profile des .NET-Frameworks 4.0 enthalten sind, gibt es eine separate DLL-Datei für ASP​.NET-Umgebungen.

Da in ASP​.NET-Anwendungen kein Einstiegs-Assembly (EntryAssembly) verfügbar ist, muss der Dateiname und Pfad der Anwendung mit anderen Methoden ermittelt werden. Dafür ist es erforderlich, eine der Initialisierungsmethoden direkt aus dem Anwendungs-Assembly aufzurufen. Die Standard-Strategie ist außerdem dahingehend geändert, dass das log-Verzeichnis für Protokolldateien im App_Data-Verzeichnis statt dem bin-Verzeichnis erstellt wird, da ansonsten bei jedem Schreiben in eine Protokolldatei die Anwendung beendet würde (Dateiänderung im bin-Verzeichnis). Die FieldLog-Konfigurationsdatei heißt außerdem Web.flconfig und liegt im Anwendungsverzeichnis neben der Datei Web.config.

Die Protokollierung von Web-Zugriffen und Anwendungsfehlern erfolgt in der Datei Global.asax.cs. Hier werden in verschiedenen Application-Ereignissen die passenden FieldLog-Methoden aufgerufen, wie folgendes Beispiel veranschaulicht.

Durch die Protokollierung von Beginn und Ende eines Web-Zugriffs wird jedem Zugriff eine fortlaufende Nummer zugewiesen, mit der alle anderen Protokolleinträge, die im Kontext dieses Zugriffs geschrieben werden, markiert sind. Dadurch lassen sich im Log-Viewer alle Einträge nach Request gruppieren und filtern.

Die einzelnen Methoden werden im Folgenden beschrieben.

Protokolliert den Beginn eines Web-Zugriffs. Die optionalen Parameter geben an, ob ein DNS-Reverse-Lookup durchgeführt werden soll, ob auf den Sitzungszustand zugegriffen werden soll, und wie die anwendungsspezifische Benutzer-ID und der Benutzername lauten. Ein DNS-Lookup kann mehrere Sekunden dauern und ist üblicherweise nicht erforderlich. Der Sitzungszustand ist erst ab dem AcquireRequestState-Ereignis verfügbar. Diese Methode sollte im BeginRequest-Ereignis aufgerufen werden, um eine vollständige Zeitmessung zu ermöglichen. Folgende Ereignisse können außerdem ausgelassen werden, wenn vorher ein Fehler auftritt.

Aktualisiert den Protokolleintrag zum Beginn eines Web-Zugriffs. Manche Informationen (Sitzungs-ID oder Benutzername) werden erst im Verlauf der weiteren Ereignisse verfügbar. Diese Methode kann im PreRequestHandlerExecute-Ereignis aufgerufen werden.

Protokolliert das Ende eines Web-Zugriffs.

Protokolliert die Daten, die im POST-Request übertragen wurden. Wenn die HTTP-Methode des aktuellen Web-Request nicht „POST“ ist, wird kein Protokolleintrag geschrieben.

Gibt alle Fehler zurück, die während der Verarbeitung der HTTP-Anfrage aufgetreten sind. Mehrere Fehler werden in einer Aggregate­Exception zusammengefasst.

Schreibt eine Fehlerseite in die HTTP-Antwort, die allgemeine Hinweise und Angaben zum aufgetretenen Fehler darstellt.

Konfiguration

Protokollierung

Das Verhalten von FieldLog, wie lange die Protokolleinträge aufbewahrt werden, wie groß das Protokoll werden darf usw., kann sowohl von der Anwendung als auch durch eine Konfigurationsdatei angepasst werden. Diese Datei ist nach der Programmdatei benannt und hat die zusätzliche Erweiterung „.flconfig“.

Die Konfigurationsdatei ist so einfach aufgebaut, dass der Endanwender sie mit minimaler Anleitung bearbeiten kann, um bei Bedarf die Vorhaltezeit zu erhöhen. Falls diese Datei bereits vom Setup-Programm erstellt werden soll, bietet es sich an, Schreibrechte für den Benutzer zu erteilen. Alle Konfigurationsmaßnahmen sind optional, es gibt für jede Einstellung einen Vorgabewert.

Die folgende Konfigurationsdatei beschreibt den generellen Aufbau der Datei und nennt gleichzeitig die Vorgabewerte:

Jede Zeile enthält eine Einstellung und deren Wert, getrennt durch „=“. Leerzeilen und unbekannte Einstellungen werden nicht beachtet. Groß-/Kleinschreibung wird nicht unterschieden. Die folgenden Einstellungen sind definiert:

• path – Pfad zu den Logdateien. Besteht aus einem vollständigen Verzeichnis und einem Dateinamenpräfix. Beispiel: C:\Log\App (schreibt Dateien „App-*.fl“ ins Verzeichnis C:\Log) Relative Pfadangaben werden relativ zur Konfigurationsdatei interpretiert.
• maxfilesize – Maximale Größe einzelner Logdateien. Kleinere Werte erlauben eine feinere Aufteilung bei der Übertragung und schnelleres Löschen alter Ereignisse.
• maxtotalsize – Maximale Größe aller Logdateien zusammen. Beschränkt den Speicherplatzbedarf des Protokolls exkl. Screenshots.
• keeptrace – Vorhaltezeit für Ereignisse der Priorität Trace.
• keepcheckpoint – Vorhaltezeit für Ereignisse der Priorität Checkpoint.
• keepinfo – Vorhaltezeit für Ereignisse der Priorität Info.
• keepnotice – Vorhaltezeit für Ereignisse der Priorität Notice.
• keepwarning – Vorhaltezeit für Ereignisse der Priorität Warning.
• keeperror – Vorhaltezeit für Ereignisse der Priorität Error.
• keepcritical – Vorhaltezeit für Ereignisse der Priorität Critical.
• checktimethreshold – Grenzwert für Protokollierung von Zeitsprüngen, in Millisekunden. Siehe Zeitüberwachung.
• maxscreenshotsize – Maximale Größe aller Screenshot-Dateien zusammen.
• keepscreenshot – Vorhaltezeit für Screenshot-Dateien.

Dateigrößen werden in Bytes angegeben. Die Buchstaben k, M und G stehen für Kilo-, Mega- und Gigabytes. Zeitangaben (außer 0) müssen mit dem Buchstaben s (Sekunden), m (Minuten), h (Stunden) oder d (Tage) gekennzeichnet werden.

Änderungen an der Konfigurationsdatei werden automatisch auch während der Laufzeit übernommen. Ein Neustart der Anwendung ist nicht erforderlich. Es kann allerdings ein paar Sekunden dauern, bis die Änderung erkannt und verarbeitet wird.

Eine Beispiel-Konfigurationsdatei mit den Vorgabewerten wird mit FieldLogViewer als „FieldLogViewer.exe.flconfig“ installiert. Diese Datei kann als Vorlage für eigene Anwendungen genutzt werden. Mit dem dazugehörigen Eintrag im InnoSetup-Installationsskript werden dem Benutzer für diese Datei außerdem Schreibrechte erteilt, damit er die Einstellungen ohne großen Aufwand ändern kann.

TODO: Konfigurations-API ist noch nicht verfügbar

Anwendungsfehlerdialog

Bei Auftreten eines unbehandelten Ausnahmefehlers wird das Exception-Objekt protokolliert und ein allgemeiner Anwendungsfehlerdialog angezeigt. Dieses Fenster gibt an, dass ein unerwarteter Fehler aufgetreten ist und die Anwendung möglicherweise nicht korrekt fortgesetzt werden kann. Die Meldung enthält auch eine Kurzfassung der Fehlermeldung(en) und nennt den Pfad der Protokolldateien. Der Benutzer hat in diesem Dialog die Möglichkeit, das Programm entweder sofort zu beenden oder fortzusetzen, falls es die Situation erlaubt. (Screenshots des Dialogs)

Bei interaktiven Konsolenanwendungen mit sichtbarem Konsolenfenster wird die Fehlermeldung im Konsolenfenster ausgegeben. Bei nicht-interaktiven Sitzungen (z. B. in Windows-Diensten) erfolgt keine Ausgabe und die Anwendung wird sofort beendet. Reagiert der Benutzer nicht innerhalb von 3 Minuten auf die Meldung, wird das Programm zur Sicherheit automatisch beendet.

Die Standardimplementierung des Fehlerdialogs kann auch durch eine anwendungsspezifische Version ersetzt werden:

Gibt die Methode zurück, die einen Anwendungsfehler anzeigt, oder legt sie fest.

Daneben gibt es eine Reihe von Eigenschaften, mit denen die Texte, die der Standarddialog anzeigt, geändert oder in andere Sprachen übersetzt werden kann. Zur Übersetzung kann die Anwendung beim Programmstart entsprechende Texte in der gewünschten Sprache aus dem Wörterbuch laden und in der FL-Klasse speichern.

Diese Eigenschaften geben die Texte zurück, die im Anwendungsfehlerdialog verwendet werden, oder legt sie fest. Das englische Beispiel zeigt die Standardtexte, das deutsche entsprechende Übersetzungen.

Setzt alle Texte des Fehlerdialogs mithilfe einer Übersetzerfunktion, hier am Beispiel von TxLib. So können die Texte ohne großen Aufwand in einem vorhandenen Projektwörterbuch gepflegt und hier angewendet werden.

FieldLog.txd4.3 KiBTx-Wörterbuch mit den FieldLog-Texten auf deutsch und englisch, kann in ein Projektwörterbuch importiert werden

Legt fest, ob im Anwendungsfehlerdialog Details zur Exception und Umgebung abgerufen werden können. Vorgabe ist true. Wenn Obfuscation verwendet wird, enthält diese Darstellung aber keine verwertbaren Angaben und sollte daher deaktiviert werden. Mit dem folgenden Code lässt sich das dynamisch ermitteln. Dafür muss ein Typname verwendet werden (im Beispiel: MyClass), der später umbenannt wird.

Dieser Fehlerdialog ist auch zur Verwendung durch Anwendungscode verfügbar. In diesem Fall wird kein Countdown gestartet und die Anwendung nicht automatisch beendet. Hinweis: Der Dialog blockiert den Programmablauf nicht. Falls im weiteren Verlauf neue Fehler auftreten, bei denen dieser Dialog angezeigt werden soll, werden sie dem noch geöffneten Dialog normal hinzugefügt und können mit der Schaltfläche „Nächster“ durchgeblättert werden.

Zeigt den Anwendungsfehlerdialog mit den angegebenen Details an. Die Meldung wird aus dem Exception-Objekt generiert. In der zweiten Überladung ist detailsObject ein Objekt, das visualisiert wird. Das sollte kein allzu komplexes Objekt sein, da beim unkontrollierten Abruf von dessen Eigenschaften weitere Fehler auftreten können.

Protokollübertragung

Mit dem separaten Programm LogSubmit können Protokolldateien vom Benutzer ausgewählt und an den Entwickler zurückgesendet werden, um ein Problem zu analysieren. Dieses Programm wird direkt aus dem Anwendungsfehlerdialog gestartet. Es kann aber auch manuell aufgerufen werden. Die Option „Logs senden“ im Fehlerdialog ist nur verfügbar, wenn das Programm LogSubmit.exe im Anwendungsverzeichnis existiert. Diese Datei sollte also mit der Anwendung verteilt bzw. durch das Setup installiert werden.

Die Konfiguration des Empfängers der Protokolldateien wird in der Datei submit.config angegeben. Diese Datei muss mit dem LogSubmit-Programm ausgeliefert werden, damit alle Übertragungsarten zur Verfügung stehen. Das folgende Beispiel beschreibt den generellen Aufbau der Datei und zeigt die verfügbaren Einstellungen:

Jede Zeile enthält eine Einstellung und deren Wert, getrennt durch „=“. Leerzeilen und unbekannte Einstellungen werden nicht beachtet. Groß-/Kleinschreibung wird nicht unterschieden. Die folgenden Einstellungen sind definiert:

• transport.http.token – Identifikations-Token für den LogSubmit-Webservice. Der Webservice-Versand steht nur zur Verfügung, wenn ein Token konfiguriert ist.
• transport.http.url – URL des LogSubmit-Webservice.
• transport.mail.address – E-Mail-Adresse des Empfängers für den Versand per E-Mail. Der E-Mail-Versand steht nur zur Verfügung, wenn eine Adresse konfiguriert ist.

Die oben angegebene URL ist der Standardwert, falls keine Konfiguration vorgenommen wird. Eine PHP-Implementierung des Webservice ist im FieldLog-Repository enthalten. Wenn du den Webservice (inkl. SSL-Verschlüsselung) auf der Standard-URL nutzen möchtest, sende mir bitte eine E-Mail zur Registrierung eines Tokens.

LogSubmit.exe wird für die Architekturen x86 (nur 32 Bit) und Any CPU (32 und 64 Bit) erstellt. Da der Versand per E-Mail eine wichtige Übertragungsart ist, das dafür verwendete MAPI aber nur 32 Bit gut unterstützt, sollte nur die x86-Version verwendet werden. Falls MAPI fehlschlägt und Microsoft Outlook installiert ist, wird Outlook über die Automation-Schnittstelle verwendet (funktioniert auch für x64).

Fehlerseite für Webanwendungen

Eine ähnliche Implementierung einer Fehlerseite steht auch für ASP.NET-Webanwendungen zur Verfügung. Der Aufruf erfolgt in der Application_­Error-Methode. Eine eventuell bereits geschriebene Ausgabe wird gelöscht und durch diese Fehlerseite ersetzt. Außerdem wird der HTTP-Antwortcode auf 500 gesetzt. Weitere Informationen dazu sind unter ASP.NET-Webanwendungen zu finden.

Welche Extras gibt es?

Neben den reinen Protokollfunktionen bietet die FieldLog-Bibliothek zusätzliche Funktionen, die teilweise auch für die Protokollierung genutzt werden und so auch direkt für die Anwendung zur Verfügung stehen. Dazu gehören Screenshots der laufenden Anwendung, Informationen zur Anwendung und Systemumgebung, eine hochauflösende aktuelle Uhrzeit und die Überwachung der Systemzeitkontinuität.

Screenshots

Screenshots können dem Entwickler einen besseren Eindruck von der Situation vermitteln, die zum Zeitpunkt des Fehlers vorlag. Die Bilder werden im PNG- oder JPEG-Format gespeichert, je nach Qualitäts-/Größenverhältnis, und im aktuellen Protokollverzeichnis abgelegt. Screenshot-Dateien werden bei der Protokollübertragung mit berücksichtigt.

Screenshots werden aber nie automatisch erstellt, sie müssen also immer explizit vom Anwendungsentwickler angefordert werden. Ein Screenshot sollte insbesondere erstellt werden, bevor Fehlermeldungen angezeigt werden und bevor Fenster geschlossen werden, die relevante Ansichten enthalten. Es gibt verschiedene Methoden, die Screenshots von verschiedenen Bereichen erstellen und im Protokollverzeichnis speichern.

Screenshot-Dateien werden ebenfalls nach der eingestellten Zeit oder Platzbedarf wieder gelöscht. Die Einstellungen sind für die Konfigurationsdatei beschrieben.

Erstellt einen Screenshot von allen aktiven Bildschirmen.

Erstellt einen Screenshot vom primären Bildschirm.

Erstellt einen Screenshot von dem Bildschirm, auf dem das angegebene Fenster liegt.

Erstellt einen Screenshot von dem Bildschirm, auf dem das Hauptfenster der Anwendung liegt.

Erstellt einen Screenshot vom angegebene Fenster. Überlappende Fenster verdecken die Sicht, Inhalte außerhalb des Fensterrechtecks sind nicht enthalten.

Erstellt einen Screenshot vom Hauptfenster der Anwendung. Überlappende Fenster verdecken die Sicht, Inhalte außerhalb des Fensterrechtecks sind nicht enthalten.

Informationen zur Anwendung und Systemumgebung

Gibt die verstrichene Zeitspanne seit dem Start der Anwendung zurück.

Gibt die kurze Versionsnummer der Anwendung zurück. Dieser Wert wird aus den Assembly-Attributen Assembly­File­Version­Attribute oder Assembly­Version­Attribute des Einstiegsassemblys gelesen, sofern vorhanden.

Gibt die vollständige Versionsangabe der Anwendung zurück. Dieser Wert wird aus den Assembly-Attributen Assembly­Informational­Version­Attribute, Assembly­File­Version­Attribute oder Assembly­Version­Attribute des Einstiegsassemblys gelesen, sofern vorhanden. Sie kann auch beschreibende Angaben enthalten, die nicht dem nummerischen Schema (1.2.3.4) entsprechen.

Vergleicht zwei nummerische Versionen. Im Gegensatz zu System.Version.CompareTo(Version) interpretiert diese Methode fehlende Teile als Null. „1.0“ und „1.0.0“ sind demnach gleich. Das ist entscheidend, da Assembly­Version­Attribute immer alle 4 Nummern enthält, die Anwendung diese lange Versionsnummer aber nicht unbedingt so darstellen möchte.

Vergleicht FL.AppVersion mit der angegebenen Version. Siehe FL.Compare­Versions.

Gibt den Namen der Anwendung zurück. Dieser Wert wird aus den Assembly-Attributen Assembly­Product­Attribute oder Assembly­Title­Attribute des Einstiegsassemblys gelesen, sofern vorhanden.

Gibt die Kurzbeschreibung der Anwendung zurück. Dieser Wert wird aus dem Assembly-Attribut Assembly­Description­Attribute des Einstiegsassemblys gelesen, sofern vorhanden.

Gibt die Copyright-Angabe der Anwendung zurück. Dieser Wert wird aus dem Assembly-Attribut Assembly­Copyright­Attribute des Einstiegsassemblys gelesen, sofern vorhanden.

Gibt die Windows-Version des laufenden Systems zurück. Beispiele: WindowsServer2012R2, WindowsXP, Windows7

Gibt die Windows-Edition des laufenden Systems zurück. Beispiele: Windows7HomePremium, Windows8Pro, WindowsServer2008SmallBusiness

Gibt einen Wert zurück, der angibt, ob das Betriebssystem ein 64-Bit-System ist.

Gibt den vollständigen Produktnamen des Betriebssystems zurück.

Gibt die Sprache des installierten Betriebssystems zurück.

Gibt einen Wert zurück, der angibt, ob das Betriebssystem im abgesicherten Modus gestartet wurde.

Gibt die Anzahl der vom System unterstützten Touch-Punkte des Touchscreens zurück. Wenn keine Touch-Eingabe verfügbar ist, ist der Wert 0.

Gibt die logische Bildschirmauflösung des Systems zurück. Der Standardwert von 100 % ist 96 dpi.

Gibt Informationen über das aktuelle Benutzerkonto und dessen Gruppenzugehörigkeit zurück.

Gibt Informationen über den Speicherverbrauch der Anwendung und den im Computer installierten Arbeitsspeicher zurück.

Die OSInfo-Klasse enthält noch weitere Eigenschaften, die Informationen über das Windows-Betriebssystem, die CLR-Ausführungsumgebung, den eigenen Prozess und die Hardwareausstattung des Computers bereitstellen. Diese Klasse ist unabhängig von anderen Bestandteilen des FieldLog-Assemblys und kann auch separat verwendet werden.

Hochauflösende aktuelle Uhrzeit

Gibt die aktuelle Zeit in hoher Auflösung und UTC-Zeitzone zurück. Während der Wert von DateTime.Now bzw. UtcNow nur alle 1 bis 16 Millisekunden aktualisiert wird, basiert diese Eigenschaft auf einer Stopwatch-Instanz, die mit der aktuellen Systemzeit kalibriert wurde, und stellt die Zeit oft mit einer Auflösung von Mikrosekunden bereit. Der Aufruf dieser Eigenschaft dauert im Vergleich zu DateTime.UtcNow gut doppelt so lange (ca. 50 ns statt 20 ns).

Die Stopwatch-Zeit (QueryPerformanceCounter-Funktion) ist stetig und monoton steigend (außer bei einer protokollierten Rekalibrierung), aber nicht unbedingt synchron mit der Systemzeit. Auf physikalischen Rechnern ist die Abweichung über einen Tag oft kleiner als eine Sekunde. Auf virtualisierten Rechnern wurden aber auch schwankende Abweichungen in einem Bereich von 10 Sekunden beobachtet. FL.UtcNow ist also für sich genommen eine hochauflösende Zeitquelle, die aber konsistent verwendet werden muss, um vergleichbare Ergebnisse zu erhalten. Die gemischte Nutzung zusammen mit DateTime.UtcNow wird nicht empfohlen.

Um die Kalibrierung dieser Zeitangabe einigermaßen zu erhalten, wird die Kontinuität der Systemzeit überwacht und bei zu großen Abweichungen oder einem Zeitsprung die Kalibrierung wiederholt. Dieses Ereignis wird automatisch mit einem Protokolleintrag der Priorität Info festgehalten, inklusive der beobachteten Zeitdifferenz. Protokollierte Werte knapp über der Meldegrenze deuten auf eine akkumulierte Abweichung hin, die jetzt ausgeglichen wurde. Größere Sprünge, wie beim Ändern der Systemzeit, können aber zeitgesteuerte Abläufe in einer Anwendung durcheinander bringen und sind deshalb besonders erwähnenswert.

Gibt die Zeit in Millisekunden zurück, ab der Zeitunterbrechungen protokolliert werden, oder legt sie fest. Vorgabe ist 100 ms. Um die Protokolldatei übersichtlicher zu halten, kann der Grenzwert angepasst werden. Dazu kann auch die Option checktimethreshold in der FieldLog-Konfigurationsdatei genutzt werden.

Performance

A benchmark application is included in the solution. It allows you to run your own tests. Here are the numbers I determined on a 2013 office PC, using minimum values of multiple benchmark runs.

FieldLog text message	427 ns/call
FieldLog scope helper	935 ns/call
Synchronised StreamWriter.WriteLine	1 215 ns/call
Trace.WriteLine (no listener)	2 852 ns/call
FieldLog scope helper with reflection	5 944 ns/call
NLog 2.1 async file	6 305 ns/call
Synchronised File.AppendAllText (SSD)	110 484 ns/call
Trace.WriteLine (VS/DbgView)	272 942 ns/call
Synchronised File.AppendAllText (HDD)	2 232 278 ns/call

The scope logging helper generates an Enter and a Leave message and takes about twice the time of writing a single text message. So you can calculate something around one microsecond for each logged method or other scope. Determining the method name through reflection takes considerably longer though and may not be an option in performance-critical loops.

Flushing 1 million FieldLog text messages	6352 ms / 7440 ms with NTFS compression
Flushing 1 million StreamWriter.WriteLine	2 ms
Flushing 500000 FieldLog scope messages	4130 ms
Flushing 500000 FieldLog scope messages	1607 ms (with reflection)
Flushing 1 million NLog messages	1950 ms

Flushing FieldLog items to the log files happens on a separate thread. That is why submitting the log messages is so fast. But if large amounts of log items are submitted in a very short time, like in this benchmark which actually doesn’t do anything else, flushing can take a moment to complete. The longer the logging methods take in advance, the more items have already been written and the less time the final flush takes. So these numbers are just informative but normally not relevant.