TheSwamp

Code Red => .NET => Topic started by: CADbloke on April 23, 2015, 06:31:02 PM

Title: Logging with Serilog + Seq
Post by: CADbloke on April 23, 2015, 06:31:02 PM
Serilog (http://serilog.net/) is a .NET logging framework that writes log events in a structured, queryable manner. Seq (http://getseq.net/) is a http receiver for Serilog. There are plenty of other built-in receivers, called "Sinks" (https://github.com/serilog/serilog/wiki/Provided-Sinks), for Serilog so you can write logs (https://github.com/serilog/serilog/wiki/Writing-Log-Events) to a file, console, database...in any combination. Seq is just one of the receivers, there are plenty of others you can plug into it (https://www.nuget.org/packages?q=Tags%3A%22serilog%22).

The beauty of Seq is that it can give you a real-time feed of your log events in a localhost page. Have a look at the screenshots at http://getseq.net/ and also http://nblumhardt.com/ <== he wrote it ...read some words too if you have time.

The beauty of Serilog is the structured event data (https://github.com/serilog/serilog/wiki/Structured-Data). The screenshots in the links above will show you what I mean by that. My "wow" moment came when I grokked the whole structured, queryable aspect of it.

Seq is free for a single user, you only need  paid license if you deploy to multi-user multi-tier environments where you need API keys to manage traffic.

Serilog is on Github and is free (https://github.com/serilog/serilog).

I found it very easy to install and get up and running, just install Seq and add the Serilog Nuget package to your Visual Studio solution and you're right to go.

Here's a snippet of code that will make little sense out of context but it's an illustration of structured logging....

Code - C#: [Select]
  1. if (cableNumberAttribute == null)
  2. {
  3.   if (!OffSheetBlocksWithNoCableAttribute.Contains(block.Name))
  4.   {
  5.     Log.Warning("{DwgFileName} - block : {BlockName} has no attribute for a cable number. {OffSheets} {@Tags}",
  6.                 Path.GetFileName(db.Filename),
  7.                 block.Name,
  8.                 OffSheets,
  9.                 attributeRefs.Select(a => a.Tag).ToList());
  10.  
  11.     OffSheetBlocksWithNoCableAttribute.Add(block.Name);
  12.   }
  13. }

Notice the {@Tags} property, it will serialize that list into the log so your receiver(s) can deserialize it and display it in a manner native to the receiver.

TLDR; (yes, irony) If you want logging, this is the most awesome logging thing I have seen.
Title: Re: Logging with Serilog + Seq
Post by: Keith Brown on July 14, 2015, 03:08:27 PM
Hi CADBloke,


I just wanted to mentioned that based on your post I went ahead and implimented logging into my apps utilizing Serilog.  It does work incredibly well and depending on if you want to take the time to implement it correctly can give you a great understanding of what your program is actually doing without having to step through code.  Currently I am only logging to a file but plan on using Seq for all in house logging and will continue to log to a file(s) for any distributed apps.


Anyway I just wanted to thank you for bringing Serilog to the communities attention.
Title: Re: Logging with Serilog + Seq
Post by: CADbloke on July 16, 2015, 05:50:39 PM
Hi Keith

Glad to hear it works for you too. I've met the author - he made autofac as well. He is plenty clever and nice bloke too. I tend to use the Seq http sink (receiver) and watch the logging in real time in the browser but I can definitely see the value in logging to a file. You can, of course, do both just by changing the constructor call.

Glad to hear it was useful.
:)
Title: Re: Logging with Serilog + Seq
Post by: CADbloke on February 27, 2017, 09:34:32 PM
Greetings from the past / future. An update to this, I still use Serilog everywhere, these days I watch the logs in real time using https://github.com/RolandPheasant/TailBlazer (which is also a great study of WPF and Reactive Extensions).
Title: Re: Logging with Serilog + Seq
Post by: Keith Brown on March 02, 2017, 10:31:41 AM
Greetings from the past / future. An update to this, I still use Serilog everywhere, these days I watch the logs in real time using https://github.com/RolandPheasant/TailBlazer (https://github.com/RolandPheasant/TailBlazer) (which is also a great study of WPF and Reactive Extensions).


How is watching it in real time different than doing so with Seq?  I use Serilog and Seq in all of my coding and have found it to be a great help in debugging.  I am just wondering how using TailBlazer would enhance that.
Title: Re: Logging with Serilog + Seq
Post by: CADbloke on March 02, 2017, 09:08:56 PM
How is watching it in real time different than doing so with Seq? 
In real time it's pretty-much the same thing with a few differences like filtering, tag handling etc. Tailblazer can open any log so you can review older logs in the same app. You also don't need to install and run Seq. You can also tail logs in Notepad++ these days but I haven't found that to be a smooth experience.

It has been a couple of months since I used either (damn that day job!) but yeah, they're both awesome.
Title: Re: Logging with Serilog + Seq
Post by: CADbloke on October 25, 2017, 11:10:20 PM
I found an interesting race-condition with Serilog and AutoCAD plugins which I posed at https://stackoverflow.com/questions/46900488/serilog-logger-for-each-plugin-dll-in-one-application

If you use the static Serilog.Log with more than one plugin then they each create the same one static Log in turn, the last one to create it owns it and determines the logging settings for all plugins that use that one static logger. Here is how I fixed that. In each plugin ....

Code - C#: [Select]
  1. public class App {
  2.  
  3. /// <summary> The Logger for this plugin. </summary>
  4. /// <remarks> Cannot use the Static <see cref="Serilog.Log"/> because each plugin needs its own <see cref="Logger"/>
  5. ///  <para /> https://stackoverflow.com/questions/46900488/serilog-logger-for-each-plugin-dll-in-one-application </remarks>
  6. internal static Logger Log;
  7.  
  8. //  ....
  9.  
  10.  
  11. public void Initialize()
  12.      {
  13.       string logFileName = Environment.GetFolderPath
  14.                               (Environment.SpecialFolder.ApplicationData) + "\\CADbloke\\CADtools\\Logs\\CADfindReplace-{Date}.log";
  15.  
  16.      Assembly assembly = Assembly.GetAssembly(typeof(App));  //  <== "App" is the class name here, use your class name
  17.      FileVersionInfo fvi = FileVersionInfo.GetVersionInfo(assembly.Location);
  18.      string version = fvi.FileVersion;
  19.  
  20.      Log = new LoggerConfiguration()
  21. #if DEBUG
  22.      .MinimumLevel.Verbose()
  23. #endif
  24.      .Enrich.WithProperty("Version", version)
  25.      .WriteTo.RollingFile(logFileName, outputTemplate: "[v{Version}] {Timestamp:yyyy-MM-dd HH:mm:ss.fff} [{Level}] {Message}{NewLine}{Exception}")
  26.      .CreateLogger();
  27. // ...
  28. }
  29.  
  30. // when you use it ....
  31.  
  32. App.Log.Information("CAD find Replace woke up");
  33.  
  34. //  ...
  35.  
  36. catch (Exception ex)
  37. {
  38.    App.Log.Error
  39.         (ex,
  40.          messageTemplate: "Failed setting Implied Selection. Dwg: {Dwg}, Refedit Block Name: {Refedit}",
  41.          propertyValue0: filename,
  42.          propertyValue1: refEditBlockName());   // I don't usually put the parameter names in, that's to clarify how Serilog works
  43. ...
  44. }
  45.  
  46. // when you are closing the app
  47.  
  48. public void Terminate()
  49. {
  50.  
  51.  App.Log.Dispose(); // Flushes the logger
  52. // ...
  53. }
  54.  


I also have an unhandled exception catcher that cleans up the logger. See https://msdn.microsoft.com/en-us/library/system.appdomain.unhandledexception(v=vs.90).aspx


Code - C#: [Select]
  1. // goes in public void Initialize(
  2.  
  3. // https://msdn.microsoft.com/en-us/library/system.appdomain.unhandledexception(v=vs.90).aspx
  4. AppDomain currentDomain = AppDomain.CurrentDomain;
  5. currentDomain.UnhandledException += new UnhandledExceptionEventHandler(UnhandledExceptionCatcher);
  6. } // ...
  7. internal static void UnhandledExceptionCatcher(object sender, UnhandledExceptionEventArgs args)
  8.         {
  9.             // https://msdn.microsoft.com/en-us/library/system.appdomain.unhandledexception(v=vs.90).aspx
  10.             Exception e = (Exception)args.ExceptionObject;
  11.  
  12.            App.Log.Error(e, "Unhandled Exception catcher caught this. IsTermination: {Died}", args.IsTerminating);
  13.            App.Log.Dispose(); // Flushes the logger - it will crash before Terminate() gets to run so it won't dispose twice. Hey, if it does, what have you got to lose?
  14.  
  15.  
  16. }

I use Automatic Versions from https://marketplace.visualstudio.com/items?itemName=PrecisionInfinity.AutomaticVersions to set the Update Assembly File version to none, none, Date (yyddd), increment. That's why I log the version number, it changes with each build. The code to get the version is from https://stackoverflow.com/a/12528418/492