Laufzeit Fehler aufzeigen: Logging mit .net core

Dieser  Blogartikel fällt in die Kategorie, Lösung für Probleme die ich nie hatte. Meine guten alten ASP.NET Webforms Anwendungen kennen ein Trace Write un Trace Warn. Damit lassen sich zur Laufzeit Infos in einen Tracelistener über den Zustand der Anwendung schreiben. Das Feature wird ganz einfach in der web.config an oder ausgeschalten. Der Webserver IIS logged und gibt bei Anfrage per trace.axd die Infos aus.

Coole Microservices Kids brettern auf unzähligen Docker Containern durch die Gegend. Wenn ein IIS für mich so eine Art Fiat 500 ist, dann ist Docker die bebretterte Seifenkoste ohne Bremsen. Logging oder Profiling ist Standard eines Application Servers.

Man wäre nicht ganz fair, wenn man .net core die Bremsen absprechen würde, kommt in Form eines Ankers daher, den man aus seiner rasenden Seifenkiste wirft. ILogger ist bereits als API implementiert und wird per üblichen DI Referenz nutzbar. Ilogger ist mulitversell ausgelegt und kann doch fast nichts anständig.

Man erkennt die Unzulänglichkeiten an der blosen Existenz von unzähligen Logging Frameworks wie log4net, Nlog oder Serilog. Nun bin ich wirklich skeptisch. Wer sich ein 3rd Party Tool in seine Software holt, wird dieses nie wieder los. Eine Technologieentscheidung fußt aber auf dem Heute und man weis nie wie es in Zukunft so sein wird.

Kestrel und die pseudo Shell

Am einfachsten (mal wieder) ist der Einstieg mit Kestrel als Web Server. In Visual Studio wird die Exe als Startumgebung ausgewählt.

image

Mit F5 gestartet, erscheint dann eine Art Command Window von Kestrel. Darin zu sehen allerlei Meldungen.

image

Die beiden letzten Meldungen wurden von  mit per Code ausgegeben. In diesem speziellen Fall, wird der Weatherforecast api Controller aus dem Blazor Client asp.net server hostet Template verwendet,

Dem Grunde nach ist es egal. In jedem Fall braucht man die Referenz auf Ilogger und dei erhält man unter anderem per Konstruktor Injection.

   1:   private readonly ILogger<WeatherForecastController> logger;
   2:   
   3:   public WeatherForecastController(ILogger<WeatherForecastController> logger)
   4:   {
   5:      this.logger = logger;
   6:   }

Bezogen auf den vorigen Screenshot, geben wir einen Fehler und eine Warnung aus.

   1:  logger.LogWarning("warning");
   2:  logger.LogError("Error", Summaries);

Es gibt sechs Loglevel, nach denen man auch filtern kann. Mehr ist es im Grunde für den Anfang nicht.

Wären da nicht die brennenden Fragen.

Wie konfiguriert man das Logging und lenkt die Ausgabe um?

Nun da Logging schon das ist (Magie!) ist die Startup.cs nicht die richtige Stelle. Man muss in program.cs. Wir müssen so früh wie möglich, also direkt beim Hostbuilder, Infos über das System weiter reichen können.

   1:   Host.CreateDefaultBuilder(args)
   2:     .ConfigureWebHostDefaults(webBuilder =>
   3:       {
   4:          webBuilder.UseStartup<Startup>();
   5:       });
   6:     .ConfigureLogging(logging =>
   7:     {
   8:       logging.ClearProviders();
   9:       logging.AddConsole();

Das Code Besipiel zeigt dem Grunde nach nur die Default Konfiguration. Die Ausgabe in die Console ist eine der sechs Provider. Mit dem Eventlog Provider wird per AddEventlog, na raten sie mal, ja richtig – in das Eventlog (Ereignisanzeige geschrieben), Ist auch eine Default Einstellung. Nicht ganz schlüssig bin ich mit Adddebug. Soll die Ausgabe ins Visual Studio Debug Window umleiten. Tut es sowieso. Laut Doku schreibt .net core auf LINUX dann in /var/log/message.

Wie schreibt man ILogger Ausgaben in eine Textdatei?

Komisch, aber wahr. Das ist nicht so recht implementiert. Ich habe wirklich lange gebraucht um das in seiner Gesamtheit zu verifizieren. Zuerst bin ich in der Microsoft Doku über folgendes C# Snippet gestolpert. WriteTo.File. Dafür braucht man aber das Nuget Paket von Serilog. Nichts von Microsoft!

Dann habe ich AddtraceSource gefunden. Dort kann als Parameter über einen Zwischenschritt ein TextWriterTraceListener Filestream zugewiesen werden. Obwohl der Compiler das anstandslos akzeptiert, s klappt das aber nur in Klassik .net. Unter .net core läuft der Code fehlerfrei und Ergebnislos. Im besten Fall erhalten sie ein leeres Logfile.
Es ist mir also nicht gelungen ohne Zusatz Bibliotheken in eine Text Datei Log Einträge zu schreiben.

Wo schreibt der IIS die Log Ausgaben hin?

Die klassischen W3C Logs schreibt der IIS als Application Server. Für alles andere muss man die web.config bemühen und den Bereich aspnetcore.

Zunächst auf der lokalen Developer Maschine steht mir nur IISExpress zur Verfügung. Also Visual Studio umstellen um IIS Express als Host auszuwählen (Bild #1). Im Kern muss man nur zwei Einstellungen vornehmen. stdoutLogEnabled  auf true setzen und stdoutLogFile  einen Pfad zuweisen. In jedem Fall muss das Directory existieren, es wird nicht automatsich angelegt.

Die Web.Config eines IIS Express wird unter applicationhost.config unterhalb des versteckten Verzeichnisses .vs gespeichert. Bei mir also

C:\blazor\BlazorAppLogging3\.vs\BlazorAppLogging3\config

Ich verwende immer Agent Ransack zur Volltextsuche, weil dieser auch in versteckten und nicht indizierten Verzeichnissen sucht.

   1:  <aspNetCore processPath="%LAUNCHER_PATH%" 
   2:  stdoutLogEnabled="true" 
   3:  stdoutLogFile=".\logs\stdout" 
   4:  startupTimeLimit="3600" 
   5:  requestTimeout="23:00:00" 
   6:  hostingModel="InProcess">

Durch das Setting stdout werden automatisch Log Dateien in einem bestimmten Namenschema erzeugt um die Ilogger Ausgaben zu speichern.

image

Man erkennt viele der IIS Ilogger Dateien sind leer, haben 0 Bytes Größe. In meinen Fall hilft, die Zeile 6 zu entfernen und das Hosting Model so auf Out Of Process umzustellen. Das bewirkt wieder das Kestrel die Arbeit macht und der IIS nur als Proxy fungiert. Ob das mit dem echten IIS auch so ist, konnte ich nicht verifizieren.

Der Inhalt einer logging Textdatei analog zum Kestrel Screenshot

info: Microsoft.Hosting.Lifetime[0]
      Now listening on:
http://127.0.0.1:13557
info: Microsoft.Hosting.Lifetime[0]
      Application started. Press Ctrl+C to shut down.
info: Microsoft.Hosting.Lifetime[0]
      Hosting environment: Development
info: Microsoft.Hosting.Lifetime[0]
      Content root path: C:\blazor\BlazorAppLogging3\BlazorAppLogging3\Server
warn: BlazorAppLogging3.Server.Controllers.WeatherForecastController[0]
      warning
fail: BlazorAppLogging3.Server.Controllers.WeatherForecastController[0]
      Error

Laut Doku sollte das im IIS auch mit Inprocess erfolgreich sein. Hinweis der Benutzer der im Application Pool eingetragen ist, braucht natürlich Schreibrechte.

Kommentare sind geschlossen