Modern Structured Logging With Serilog and Seq - p-patel/software-engineer-knowledge-base GitHub Wiki

https://app.pluralsight.com/library/courses/modern-structured-logging-serilog-seq/

Introduction to Structured Logging

Module Overview

  • Logging of structured data instead of traditional simple text logging
  • Enables querying of structured logged data instead of just regex-based searches of text logs
  • Using Serilog write:
  1. unstructured log data to traditional text file
  2. structured log data to a NoSQL store
  • Log using named properties and values
  • Log to multiple log stores
  • Write structured log data to Seq using Serilog and query using Seq web user interface

Why Structured Logging?

  • Simple, unstructured, textual data is restricted to searches using regex. It may also be across multiple files/disks/data centres (e.g. text file per day/ per data centre)
  • Structured logging enable more sophisticated querying

Introducing Serilog

  • Serilog can be configured to log to text files, NoSQL store and even multiple stores
  • Example Log.Information("Added user {NewUser}", userObject)
  • Can then query based on values of NewUser properties
  • Logging stores inc. console, (rolling) text files, SQL dbs, NoSQL dbs

Introducing Seq

  • Seq server enables logging to be stored using http/https and includes a web interface for browsing and querying log messages

Module Summary

  • Why structured logging?, introducing Serilog, introducing Seq

Serilog Fundamentals

Getting Started With Serilog

  • Install Serilog nuget package
  • Create a configured ILogger to log messages, e.g.
ILogger logger = new LoggerConfiguration()
  .WriteTo.Console()  // configures a sink
  .CreateLogger();
logger.Information("Add user");

Log.Logger = logger; // stores logger in Serilog static property

// can instead now log using...
Log.Logger.Information("Added user");

Logging to a Single Text File

  • use WriteTo.File("logfile.txt")' in fluent syntax to log to file instead of console
  • create custom log format using template string e.g. "{Timestamp:yyyy-MMM-dd HH:mm:ss.fff zzz} [{Level}] {Message}{NewLine}{Exception}"; and use custom template in configuration e.g. .WriteTo.File("logfile.txt", outputTemplate: customTemplate).CreateLogger();
  • change default log file max size e.g. WriteTo.File("logfile.txt", fileSizeLimitBytes: 300); can also set to null for no limit size

Logging to Multiple Rolling Text Files

  • create a new rolling daily log file with date appended to filename: .WriteTo.RollingFile("rollinglogfile.txt").CreateLogger();
  • set retained file count limit: .WriteTo.RollingFile("rollinglogfile.txt", retainedFileCountLimit: ").CreateLogger();

Logging Structured Data

  • log structured data using named properties e.g. Log.Information("Added user {UserName}, Age {UserAge}", name, age); stores properties as structured data that can be queried if the underlying sink/data store supports it, otherwise data value is stored in the log
  • storing scalar data: boolean, numbers, strings, dates/times and others categories.
  • storing collections and objects: IEnumerable, Dictionary<string, int> (where dictionary key must be a scalar type); objects that is not a scalar type or supported collection type will be logged using the .ToString() representation of the object
  • retaining object structure: use destructuring operator (individual properties of the class will be stored) Log.Information("Color is: {@Color}", faveColor);

Simple Scalar Values

  • Log string uses named properties e.g. {UserAge}
  • scalar types include int, string, datetime, guid

Collections and Objects

  • collections are enumerated and logged (ensure key in a Dictionary is a scalar type)
  • objects are stored using ToString() which can be over-ridden (alternatively use destructuring operator)

Destructured Objects

  • syntax {@Color} in log format string which will destructure the object type into its properties which will be queryable when stored in a compatible sink
  • can specifying destructuring in logger configuration e.g. new LoggerConfiguration().Destructure.ByTransforming<Color>(x => new {x.Red, x.Green}).WriteTo.Console().CreateLogger();

Provided Logging Sinks

  • Sinks are a place to store log messages
  • Examples: azure table storage, console, couchdb, elasticsearch, file/rollingfile, log4net, mongodb, seq, windows event log etc. (file sinks, on-premise service or hosted service)

Writing and Querying Structured Log Data With RavenDB

  • install RavenDB Serilog sink Nuget package and dependencies
  • configure and initialise RavenDB DocumentStore
  • configure Serilog logger ILogger logger = new LoggerConfiguration().WriteTo.RavenDB(logDocumentStore);
  • example log Log.Information("Added user {@NewUser}", userToAdd);
  • logged data is now queryable in RavenDB

Serilog - Beyond the Fundamentals

Message Templates and Formatting

  • literal formatting: e.g. string with no quote marks {Name:l}, number decimal places {PI:0.00}

Logging Levels

  • Verbose, Debug, Information, Warning, Error, Fatal

Configuring Minimum Logging Severity Levels

  • configure minimum logging level in Logger configuration, e.g. ILogger logger = new LoggerConfiguration().MinimumLevel.Verbose()

Sink Specific Minimum Severity Levels

  • configure logging level per sink, e.g. `.WriteTo.File("verboselog.txt", restrictedToMinimumLevel: LogEventLevel.Verbose)
  • can configure an overall level as well as per-sink level

Log Storage and Retention Strategy

  • common strategy is to log to files locally
  • may log debug level to rolling files and information to NoSQL db
  • considerations: audit/legal requirements - what? retention requirement? log content/security - what? who has access? redundancy - off-box remote + on-box files fault investigation / resolution - minimum level, typical support incident period (will need logs to be kept for at least this period, also may mean queryable data may only need to be kept in NoSQL db for this period with file-based logging maintained for longer if required)

Adding Log Context

  • create contextual logger, e.g.
var contextLogger = Log.Logger.ForContext<Program>();

contextLogger.Information(...);

{
  ...
  "Properties": {
    "FirstNumber: 10,
    "SecondNumber": 5,
    "Result": 2,
    "SourceContext": "Console.Application.Program"
  }
}

Custom Filtering Which Events to Log

  • configure per sink, e.g. .Filter.ByExcluding(x => x.Properties.ContainsKey("CommandLineArguments") and similarly .Filter.ByIncludingOnly(x => x.MessageTemplate.Text.Contains("Attempting to divide")) and also .Filter.ByExcluding(Matching.WithProperty("CommandLineArguments")) can also filter by Matching.FromSource()`

Correlating Log Entries

  • add correlation properties to a logger, e.g. `var corrLog = Log.Logger.ForContext("OrderId", orderId);
  • all logs created with this logger will contain the added correlation data

Enriching Log Events With Additional Data

  • add enrichment properties to a logger that will be included in all log messages added with this logger, e.g.
var logger = new LoggerConfiguration()
  .Enrich.WithProperty("ApplicationName", "PlaceOrder")
  ...
  • can also create custom enricher, e.g.
public class ApplicationsDetailsEnricher : ILogEventEnricher
{
  public void Enrich(LogEvent logEvent, ILogEventPropertyFactory propertyFactory){
    var applicationAssembly = Assembly.GetEntryAssembly();

    var name = applicationAssembly.GetName().Name;
    var version = applicationAssembly.GetName().Version;

    logEvent.AddPropertyIfAbsent(propertyFactory.CreateProperty("ApplicationName", name);
    logEvent.AddPropertyIfAbsent(propertyFactory.CreateProperty("ApplicationVersion", version);
  }
}

usage: .Enrich.With(new ApplicationDetailsEnricher())

Serilog Extras Overview

  • Serilog.Extras.AppSettings Nuget - web.config, app.config
  • Serilog.Extras.Web Nuget - ASP.NET enrichers, custom HttpModule
  • Serilog.Extras.Timing Nuget - time blocks of code - [Information]beginning..., [Inforamtion]completed..., [Warning]Took longer than expected...

Debugging Configuration Problems

  • enable Serilog debugging output with Serilog.Debugging.SelfLog.Out = Console.Out; //logs Serilog errors to console
⚠️ **GitHub.com Fallback** ⚠️