. Net worker service adding a serial log record

We learned about  .NET Worker Service Introduction to   and   How to exit gracefully Worker Service [2], Today we'll go on to talk about how to make Worker Service add to Serilog logging .

In the actual production environment , Logging in an application is very valuable . in many instances , Developers have no direct access to the production environment to debug problems . High quality logging provides clues and basis for solving online problems .

Logging is the process of recording the operation and state of an application to a secondary interface .

.NET Logging framework

.NET There are many default logging providers in [3], They can output logs to the console 、Debug、EventSource and EventLog etc. , For example, in the example in the previous article , The default implementation is to output logging to the console window .

however .NET There is no built-in provider that can help us export log information to files and databases , This is a very common application scenario in our production environment . In order to achieve this function , We need to .NET Implement a custom logging provider [4], It takes a lot of time , Because there's a lot to think about , For example, read-write performance 、 Storage space 、 The configuration, etc. .

Fortunately, , Some excellent third-party packages can help us ,.NET The three most popular logging frameworks in are ：log4net、NLog、Serilog, We just need to go from NuGet Get them from the package Repository , Then you can use them happily with a simple configuration .

log4net

log4net[5]  It's a beginning 2001 The leading logging framework of the year , Initially Java frame log4j The port of . these years ,Apache Logging Services The project continues to develop , There's no other framework like log4net It's been tested as well .log4net It's all modern .NET The originator of the logging framework , In the logging framework , The level of logging （log levels）、 Recorder (logger) And output module (appenders/targets/sinks) And so on are almost universal [6]. I believe all of them have been used for many years .NET Programming friends are right log4net They are quite familiar with .

log4net To use 、 Stable and flexible , But its configuration is relatively complicated , And it's hard to implement structured logging .

NLog

NLog[7]  It's also a fairly old project , The earliest version was released in 2006 year , But it's still under active development .NLog from v4.5 At the beginning of the release, support for structured logging has been added .

And log4net comparison ,NLog It's easier to configure , And the code based configuration is also relatively simple .NLog The default setting in is better than log4net The default settings in are more reasonable . One thing to note is that , When using these two frameworks , You may have the same problem , That's the configuration problem （ Forget to copy the configuration file, for example ） when , I don't get any hints , It doesn't output log information . If you encounter this situation after you deploy the application online , It will be fatal , Because a lot of problem checking depends on logging . Of course , The original purpose of this design is to prevent the application from crashing due to log problems .

Serilog

Serilog[8]  The logging framework is published in 2013 year , It's a relatively new framework . Unlike other logging frameworks ,Serilog Powerful structured event data is considered in the design , Provides out of the box structured logging implementation . therefore Serilog Very good support for structured logging , And the configuration is simple .Serilog Logs in can be sent to many terminals ,Serilog Call these terminals “ Output module library (sinks)”. You can go to https://github.com/serilog/serilog/wiki/Provided-Sinks Page to see a very comprehensive list .

Serilog There's another powerful concept in this book that is Enricher, You can enrich the properties of log events in various ways , To add new information to the log .NuGet There are some pre built Enricher, You can also achieve  ILogEventEnricher  Build your own Enricher.

Structured logging

Perhaps you have noticed , I mentioned many times before Structured logging , So what is structured logging , Why should I emphasize structured logging ？

Usually , You will find that the log information basically contains two parts ： The message template and value , and .NET Usually only accept such as  string.Format(...)  Such an input string . such as ：

var position = new { Latitude = 25, Longitude = 134 };
var elapsedMs = 34;

log.Information("Processed Position, Latitude:{0}, Longitude: {1} in Elapsed:{2} ms.", position.Latitude, position.Longitude, elapsedMs);

This log is simply converted to text and output to the log file ：

[INF] Processed Position, Latitude:25, Longitude: 134 in Elapsed:34 ms.

It looks good , But it can be better ！

When we have problems , We need to retrieve log records based on some known information . such as , Suppose we know Latitude by 25,Longitude by 134, If we want to find this log , How do you do that ？ Because the log information output above is simple text , Experienced you may immediately think of using regular expressions or simple string matching , But it's not just not intuitive , It's more difficult to realize . Is there a better way ？

If we're storing logs , The part containing the value is extracted as a feature , Form a structured structure of bonds and values JSON object , As an attribute of each log record (properties)：

{"Position": {"Latitude": 25, "Longitude": 134}, "Elapsed": 34}

then , When we search, we only need to look up the log records  properties  That's all right. , It's structured , Retrieval is convenient and intuitive .

Serilog Helped us achieve this , You only need to change one line of code ：

log.Information("Processed {@Position} in {Elapsed:000} ms.", position, elapsedMs);

Position Ahead  @  yes Deconstruction operators , It tells Serilog You need to serialize the incoming object , Instead of calling  ToString()  Convert it .

Elapsed After that  :000  It's a standard .NET Format string , It determines how the property is rendered .

by Worker Service add to Serilog journal

Now? , You have a general idea of Serilog, And why I chose it . Let me introduce its usage with an example .

Development tools needed ：

• Visual Studio Code：(https://code.visualstudio.com/)

• Abreast of the times .NET SDK：(https://dotnet.microsoft.com/download)

• DBeaver：(https://dbeaver.io/)

This example is based on... In the previous article Worker Service Source code [9] modify , If you have git, You can get it with the following command ：

git clone [email protected]:ITTranslate/WorkerServiceGracefullyShutdown.git

then , Use Visual Studio Code Open this project , Run it , To make sure everything is OK ：

dotnet build
dotnet run

You are in Serilog Many examples can be seen in the official documents , However, most of the examples are configured using encoding Serilog, Or with xml The way to configure in the old project AppSettings In file .

In the example of this article , I will be JSON The way to put Serilog The configuration is placed in the popular  appsettings.json  In profile . We just need to modify it  Program.cs  and  appsettings.json, It doesn't need to be modified  Worker.cs.

Install dependent packages

First , Install the packages we need ：

dotnet add package Serilog
dotnet add package Serilog.Settings.Configuration
dotnet add package Serilog.Extensions.Hosting
dotnet add package Serilog.Sinks.Console
dotnet add package Serilog.Sinks.RollingFile

modify  Program

then , modify  Program  Medium  Main  Method , from  appsettings.json  Read the configuration and build on it Serilog Examples of loggers ：

public static void Main(string[] args)
{
    var configuration = new ConfigurationBuilder()
        .SetBasePath(Directory.GetCurrentDirectory())
        .AddJsonFile("appsettings.json")
        .AddJsonFile($"appsettings.{Environment.GetEnvironmentVariable("DOTNET_ENVIRONMENT") ?? "Production"}.json", true)
        .Build();

    //  Global shared loggers 
    Log.Logger = new LoggerConfiguration()
        .ReadFrom.Configuration(configuration)
        .Enrich.FromLogContext()
        .CreateLogger();

    try
    {
        var separator = new string('-', 30);

        Log.Information($"{separator} Starting host {separator} ");

        CreateHostBuilder(args).Build().Run();

        Log.Information($"{separator} Exit host {separator} ");
    }
    catch (Exception ex)
    {
        Log.Fatal(ex, "Host terminated unexpectedly");
    }
    finally
    {
        Log.CloseAndFlush(); //  Release resources 
    }
}

modify  Program  Medium  CreateHostBuilder  Method , take Serilog Set to log provider ：

public static IHostBuilder CreateHostBuilder(string[] args) =>
    Host.CreateDefaultBuilder(args)
        .ConfigureServices((hostContext, services) =>
        {
            services.AddHostedService<Worker>();
        })
        .UseSerilog(); // take  Serilog  Set to log provider 

§ Modify the configuration file  appsettings.json

Modify application configuration file  appsettings.json, add to  Serilog  node (Section).

Serilog The required configuration node name defaults to  Serilog; Of course , You can also change it , But specify the node name when reading .

{
  "Serilog": {
    "Using": [
      "Serilog.Sinks.Console",
      "Serilog.Sinks.RollingFile"
    ],
    "MinimalLevel": {
      "Default": "Information",
      "Override": {
        "System": "Warning",
        "Microsoft": "Information"
      }
    },
    "WriteTo": [
      {
        "Name": "Console"
      },
      {
        "Name": "RollingFile",
        "Args": {
          "pathFormat": "Logs\\{Hour}.txt",
        }
      }
    ]
  }
}

Take a look at what we've all configured ：

You can go to  Serilog.Settings.Configuration package [10]  Instructions for these configurations can be found in the .

Using node

Using The node contains the required list of assemblies , For automatic discovery  WriteTo  and  Enrich  The assembly to which the method configured in the .

about .NET Core project , The build tool generates  .deps.json  file , also  Serilog.Settings.Configuration  Package usage  Microsoft.Extensions.DependencyModel  It's an agreement , So that you can have... Anywhere from the name Serilog  Find the right package in the dependency package of , And extract the configuration method from it . therefore , In the example above Using Nodes can be omitted .

MinimalLevel node

MinimumLevel Object to configure the lowest level of output logging . add to MinimalLevel.Override term , You can override the minimum level of some specific namespace .

WriteTo node

Use WriteTo Object configuration output module (sinks), Multiple output modules can be configured and activated at the same time . In this example, we configure  Console  and  RollingFile, The former outputs logs to the console , The latter outputs the log to a scrolling file .

Output log to file , You can also use it Serilog.Sinks.File Package , It also supports scrolling files .

Args  Used for configuration Sink The option to . In this case  pathFormat  The location of the log file is configured , In the value of this item  {Hour}  It's a scrolling log file   File name format specifier . The output module supports three different file name format specifiers （ Case sensitive ）：

• {Date}： Create a file every day . The file name uses  yyyyMMdd  Format .

• {Hour}： Create a file every hour . The file name uses  yyyyMMddHH  Format .

• {HalfHour}： Create a file every half an hour . The file name uses  yyyyMMddHHmm  Format .

After completing the above configuration , We run the app ：

dotnet build
dotnet run

You will find that there is one more in the root of the application  Logs  Folder , The log information can be output to the file normally . meanwhile , The console also has output logs . The output formats of the two are slightly different , The output in the console is simpler .

§ add to Enricher And formatting output

I mentioned earlier that Serilog There's another powerful concept in this book that is Enricher, Here I'll take the pre built Enricher Here's an example of how it works .

Add the following dependent packages ：

dotnet add package Serilog.Enrichers.Thread
dotnet add package Serilog.Enrichers.Environment
dotnet add package Serilog.Enrichers.Process

These three Enricher Different information is provided to enrich the properties of log events .

• Serilog.Enrichers.Environment  Provide  WithMachineName()  and  WithEnvironmentUserName()

• Serilog.Enrichers.Process  Provide  WithProcessId()

• Serilog.Enrichers.Thread  Provide  WithThreadId()

modify  appsettings.json, towards Serilog Configuration objects add  Enrich  Configuration node , To enrich the information of log events ：

"Enrich": [
  "WithMachineName",
  "WithProcessId",
  "WithProcessName",
  "WithThreadId"
]

modify  appsettings.json, towards WriteTo Under the RollingFile Object node  Args  Add one  outputTemplate  Options , To customize the output message template ：

{
  "Name": "RollingFile",
  "Args": {
    "pathFormat": "Logs\\{HalfHour}.txt",
    "outputTemplate": "{Timestamp:o} [{Level:u3}] ({MachineName}/{ProcessId}/{ProcessName}/{ThreadId}) {Message}{NewLine}{Exception}"
  }
}

After modifying the configuration , Rerun application ：

dotnet build
dotnet run

Check the log file again , You will find that the log has been output in our custom format , And more we use Enricher Information obtained ：( Computer name / process ID/ Process name / Threads ID).

2021-05-27T18:15:40.2992230+08:00 [INF] (DESKTOP-6LTYU3O/54376/MyService/1) Worker running at: 05/27/2021 18:15:40 +08:00

Save log to database

I mentioned the properties of log files earlier (properties), Why haven't you seen it until now ？

This is because , When Serilog When writing log events to a file or console , Message templates and properties will only be rendered as friendly text that is easy to read . And when we send log events to a cloud based log server 、 Database and message queue output module (sinks) when , It can be saved as structured data .

For the sake of simplicity , I take SQLite Database as an example to introduce .

add to SQLite Dependent packages ：

dotnet add package Serilog.Sinks.SQLite

modify  appsettings.json, stay Serilog The configuration of the WriteTo Add the following configuration node under node , In order to SQLite Output log ：

{
  "Name": "SQLite",
  "Args": {
    "sqliteDbPath": "Logs\\log.db",
    "tableName": "Logs",
    "maxDatabaseSize": 1,
    "rollOver": true
  }
}

Explain it.  Args  The role of each option ：

• sqliteDbPath： SQLite Database path .

• tableName：  For storing logs SQLite The name of the table .

• maxDatabaseSize：  The maximum file size of the database , We can use MB Add... To the unit . The default is 10MB, The maximum is 20GB. For testing purposes , I set it here to 1MB.

• rollOver：  If the file size exceeds the maximum database file size , Create a rolling backup , The default is true.

here , Run the application again ：

dotnet build
dotnet run

You will be in the application directory Logs I see one in the folder SQLite Database files  log.db. Use DBeaver Open it and check ：

  You can see ,SQLite The output module automatically creates databases and tables for us , Logging succeeded .

We configured the database file to be larger than 1MB Automatically scrolling the backup when it's done , You can output more logs to test , See if it has an automatic rolling backup . My test results are as follows ：

Look again. Serilog Properties of captured log events (properties)：

Serilog Using message templates 、 And named and positional parameter extensions .NET Format string for , however Serilog Capture the value associated with each named parameter , Instead of formatting the event directly as text . Let's add a few lines of code , Test it Serilog Capture log events ：

var position = new { Latitude = 25, Longitude = 134 };
var elapsedMs = 34;
Log.Information("Processed {@Position} in {Elapsed:000} ms.", position, elapsedMs);

The above example records two properties in the log event ：Position  and  Elapsed,Position  Ahead  @  The operator tells Serilog To serialize incoming objects . Finally, the structured data we store in the database  Properties  As shown below ：

{"Position":{"Latitude":25,"Longitude":134},"Elapsed":34,"MachineName":"DESKTOP-6LVG1OL","ProcessId":54332,"ProcessName":"MyService","ThreadId":1}

Serilog Deep and rich support for structured event data , It creates a huge diagnostic possibility that traditional loggers don't have .

summary

In this paper , I introduced .NET Structured event logging framework commonly used in Serilog, And the reasons and benefits of using it ; And through a .NET Worker Service example , Describes how to save logs to scrolling files and databases .

Serilog It's a stable one 、 Simple configuration 、 Powerful 、 Extensible 、 Support structured log events .NET Logging provider , It's worthy of our wide application .