Lurgle.Logging v1.2.1 - More logging patterns for your Lurgle convenience

Table of Contents

Lurgle approach compared to Serilog

Following on from the v1.2.0 multi-threaded correlation release, I thought about whether we could further improve how we interface with Lurgle.Logging. 

The general approach was to maintain a static interface to logging that would allow us to capture key properties for logging, that would provide nicely structured logs across a variety of applications and implementations. A good goal to have for a common log library, but I hadn't baked much flexibility into this - hence my musing and contemplation. The approach was ultimately based on my original implementation of a Serilog logger, and it was reasonable - perhaps high time - to review. 

Up until now, the approach has typically looked like:

Log.Level(LurgLevel.Error).Add("An Error");
Log.Exception(ex).Add("An Exception - {Message}", ex.Message);
Log.Add("A simple event entry");
Log.Level().AddProperty("PropertyName", "PropertyValue").Add("Message");

Which is functional but perhaps somewhat limiting. If you're familiar with Serilog, you know that it allows for patterns like:

Log.Information("Test");
Log.Error(ex, "Test");
Log.ForContext("PropertyName", "PropertyValue").Write(LogLevel.Error, ex, "Message");

and so on. 

Adding more convenience to Lurgle

The advantage of Lurgle.Logging as an implementation of Serilog is that it automatically adds common properties like AppName, AppVersion, MethodName, SourceFile, and LineNumber, along with a number of properties from enrichers, such as ThreadId, MachineName, and MemoryUsage. It also allows you to automatically mask properties, and provides a correlation id implementation that is now rather flexible.

NOTE: After percolating on this for a while, I've made some changes to how the static methods work for these new logging patterns. You can still explicitly specify Log.Information(), but it will always be followed by a .Add - you can't combine the log template and arguments anymore, because it didn't really work as well as it could have. You can read about the changes, and see the updated examples, here

I wanted to more closely approximate how Serilog log patterns work, but still retain these advantages ... so I've now exposed a number of new patterns;

  • Log.Add - existing method, but now allows arguments using the named argument args:
  • Log.Information
  • Log.Verbose
  • Log.Debug
  • Log.Warning
  • Log.Error
  • Log.Fatal

along with Fluent implementations (for example: Log.Level().Fatal("Argh!") or Log.AddProperty(dictionary).Fatal("Argh!)) and overloads that allow you to pass exceptions and log levels where appropriate.

For each of these static implementations, you can pass arguments, but because we have the correlation id  parameter in addition to the capture of caller members, you will need to explicitly specify args: as a named argument, eg.

Log.Add("Test {Args1} {Args2}", args: "Test", "Test2");

We also add a static implementation of AddProperty, which allows you to start with adding properties, and includes overloads to pass exceptions and log levels.

Log.AddProperty("TestProperty", "TestValue").Error("An Error adding {TestProperty}");

Results of Lurgle tinkering

The overall effect makes for a lot of flexibility, which allow you to decide how you want to use Lurgle. The additions to my LurgleTest app probably illustrate this best:

            Log.Add("Simple information log");
            Log.Add(LurgLevel.Debug, "Simple debug log");
            Log.Add("Log with {Properties:l}", args: "Properties");
            Log.Information("Information event");
            Log.Information("Information event with {Properties:l}", args: "Properties");
            Log.Verbose("Verbose event");
            Log.Verbose("Verbose event with {Properties:l}", args: "Properties");
            Log.Debug("Debug event");
            Log.Debug("Debug event with {Properties:l}", args: "Properties");
            Log.Warning("Warning event");
            Log.Warning("Warning event with {Properties:l}", args: "Properties");
            Log.Error("Error event");
            Log.Error("Error event with {Properties:l}", args: "Properties");
            Log.Fatal("Fatal event");
            Log.Fatal("Fatal event with {Properties:l}", args: "Properties");
            Log.AddProperty("Barry", "Barry").Warning("Warning event with {Barry:l}");
            Log.Error(new ArgumentOutOfRangeException(nameof(test)), "Exception: {Message:l}", args: "Error Message");
            Log.AddProperty(LurgLevel.Error, "Barry", "Barry").Add("Log an {Error:l}", "Error");
            Log.AddProperty(LurgLevel.Debug, "Barry", "Barry").Add("Just pass the log template with {Barry:l}");
            Log.AddProperty(new ArgumentOutOfRangeException(nameof(test)), "Barry", "Barry")
                .Add("Pass an exception with {Barry:l}");
            Log.AddProperty(test).AddProperty("Barry", "Barry").Add(
                "{Barry:l} wants to pass a dictionary that results in the TestDictKey property having {TestDictKey}");
            Log.Level().Warning("Override the event level and specify params like {Test:l}", "Test");

But of course, we still also allow for the old patterns:

            Log.Level().Add("Configured Logs: {LogCount}, Enabled Logs: {EnabledCount}", Logging.Config.LogType.Count,
                Logging.EnabledLogs.Count);
            Log.Level().Add("Configured Log List:");
            foreach (var logType in Logging.Config.LogType) Log.Level().Add(" - {LogType}", logType);

The goal was to give a similar degree of flexibility as a standard Serilog implementation, while retaining the added features of Lurgle.Logging. I think this is overall achieved - needing to specify arguments as an explicitly named argument gave me pause for thought, but the benefit seems to outweight the inconvenience.

I also exposed Logging.SetCorrelationId to allow another way of managing the correlation id. Generally speaking, you can do this within the static log interface, such as the examples below of generating a new correlation id or passing your own.

Log.Error(ex, "Oh no! An error! {Message}", Logging.NewCorrelationId(), args: ex.Message);
Log.Error(ex, "Oh no! Barry had an error! {Message)", "Barry", args: ex.Message);

But this also provides opportunity to simply call:

Logging.SetCorrelationId("Barry");

if or when you need it.

Get the latest Lurgle!

This release is all about convenience, and I think that's readily achieved. If you've already implemented Lurgle, nothing should break, but you now have more flexibility in how you log with Lurgle!

You can update to v1.2.1 via Nuget, and of course fancy links are a way of life around these parts:

 

Comments

You may also like:

Structured Logging with Seq and Serilog

A few years back, I picked up an old "unloved" business application for document handling, and brought it into the modern era. I completed some work on adding automated OCR, running as a service, and then started to enhance it well beyond its original capabilities, such as moving a manual...

Lurgle.Logging - a standardised Serilog implementation with extra goodies!

Logging is important Logging is a really important, oft-neglected, aspect of business applications. I can't state that enough. If you don't have good logging, you can't troubleshoot and debug problems, and you have little chance of seeing what's actually going on in your enterprise. In Structured Logging with Seq and...

Lurgle.Logging v1.2.0 - Multi-threaded correlation ids are now a thing

Implementing Multi-Threaded Lurgles If we revisit my example from earlier, we'll see a much simpler implementation for multi-threaded code; Log.Level().Add("Here is my log entry"); Log.Level(LurgLevel.Error).Add("Oh no! An error!"); Log.Level().Add("Phew ... moment passed"); Log.Level(correlationId: Logging.NewCorrelationId()).Add("After all that, I'd really like a different correlation id"); Log.Level(LurgLevel.Debug).Add("CorrelationId is {CorrelationId}"); You can see...