TheLazy.Dev
Portfolio GitHub

Blog

tutorial |serilog |dotnet |csharp

Playing with serilog and dotnetcore

mandrewcito

Andrés Baamonde Lozano

Posted on April 4, 2020

Playing with serilog and dotnetcore

Logging it's a must on any application. Making a simmilitude with the journalism when a event appears on our application, we need to answer some questions before writing it This is not strict at all but that i try to say is that an event alone means nothing, we need enrich it with some context. With that a log line will be more usefull:

  • Who: Method that generates our event.
  • What: Kind of event.
  • Where: Context of event, class, request ...
  • When: Timestamp of the event.
  • Why: Inner exception, data asociated to the event ...

And one thing that i concider very usefull wich is very personal, is that we need wrapping with quotes all parameter that we log, becouse there is a huge difference between this two log lines:

12-12-1988 Warning query paramters id = 12341
Enter fullscreen mode Exit fullscreen mode 
12-12-1988 Warning query paramters id = '12341    '
Enter fullscreen mode Exit fullscreen mode

Setup application

I will start with something very simple. The simplest app is a console application, so we create a folder and open a terminal on the folder.

dotnet new console
Enter fullscreen mode Exit fullscreen mode

Add serilog to our csproj and restore packages

<ItemGroup>
  <PackageReference Include="Serilog.AspNetCore" Version="3.2.0" />
</ItemGroup>
Enter fullscreen mode Exit fullscreen mode 
dotnet restore
Enter fullscreen mode Exit fullscreen mode

My first log

Using serilog is very simple, so next snippet is a fast configuration, you can fount it on the serilog github doc. Let's modify our program.cs


namespace AspnetcoreSerilog
{
    class Program
    {
        static void Main(string[] args)
        {  
            Log.Logger = new LoggerConfiguration()
                .MinimumLevel.Debug()
                .MinimumLevel.Override("Microsoft", LogEventLevel.Information)
                .WriteTo.Console()
                .CreateLogger();
            Log.Information("Hello world!");
        }
    }
}
Enter fullscreen mode Exit fullscreen mode

Output of the previous program:

PS D:\Workspace\dev.to\AspnetcoreSerilog> dotnet run
[23:21:53 INF] Hello world!
Enter fullscreen mode Exit fullscreen mode

Configure via appsettings.json

Ok, but serilog's configuration will grow a lot. In a real world app we want a log with a lot of features, subloggers... and if we need changing a configuration section we will need recompile library, we dont want that.

So lets introduce the package serilog-configuration. As a dependency, we will need adding some packages.Reading configuration from a json file can be easly done with microsoft extensions this post may be helpfull. I directly add new dependencies to our csproj:

  <ItemGroup>
    <PackageReference Include="Serilog.AspNetCore" Version="3.2.0" />
    <PackageReference Include="Serilog.Settings.Configuration" Version="3.1.0" />
    <PackageReference Include="Microsoft.Extensions.Configuration" Version="3.1.3" />
    <PackageReference Include="Microsoft.Extensions.Configuration.Json" Version="3.1.3" />
    <PackageReference Include="Microsoft.Extensions.Configuration.CommandLine" Version="3.1.3" />
    <PackageReference Include="Microsoft.Extensions.Configuration.EnvironmentVariables " Version="3.1.3" />
  </ItemGroup>
  <ItemGroup>
      <None Update="appsettings.json" CopyToOutputDirectory="PreserveNewest" />
  </ItemGroup>
Enter fullscreen mode Exit fullscreen mode

Our program.cs will load configuration and provide it to the logger.

namespace AspnetcoreSerilog
{
    class Program
    {
        static void Main(string[] args)
        {  
            var configuration = new ConfigurationBuilder()
                .AddJsonFile("appsettings.json")
                .Build();

            Log.Logger = new LoggerConfiguration()
                .ReadFrom.Configuration(configuration)
                .CreateLogger();
            Log.Information("Hello world!");
        }
    }
}
Enter fullscreen mode Exit fullscreen mode

Now, we can configure serilog with via appsettings.json

{
    "Serilog": {
        "Using": [],
        "MinimumLevel": {
            "Default": "Debug",
            "Override": {
                "Microsoft": "Information",
                "System": "Warning"
            }
        },
        "WriteTo": [
            { "Name": "Console" }
        ]
    }
}
Enter fullscreen mode Exit fullscreen mode

If we run again the program, output is the same:

PS D:\Workspace\dev.to\AspnetcoreSerilog> dotnet run
[23:24:34 INF] Hello world!
Enter fullscreen mode Exit fullscreen mode

I need customizing output

Serilog output can be easily configured with output template parameter:

{
 ... Take a look to previous json 
        "WriteTo": [
            {
                 "Name": "Console",
                 "Args": {
                    "outputTemplate": "{Timestamp:dd/MM/yy HH:mm:ss,fff} [{Level:u3}] {Message}{NewLine:1}"
                 }
            }
        ]
    }
}
Enter fullscreen mode Exit fullscreen mode

Output will the following:

PS D:\Workspace\dev.to\AspnetcoreSerilog> dotnet run
04/04/20 23:39:09,387 [INF] Hello world!
Enter fullscreen mode Exit fullscreen mode

This information it´is not enough, i want more. Enrich helps you

There are a lot of enrichers, depending on your needs, you can add its packages to your csproj file. For my example i will use thread enricher:

Add your dependency on csproj and restore:

    <PackageReference Include="Serilog.Enrichers.Thread" Version="3.1.0" />
Enter fullscreen mode Exit fullscreen mode

Modify serilog configuration file adding enricher's using and modifying output template to include it:

{
    "Serilog": {
        "Using": [],
        "Enrich":["WithThreadId"],
        "MinimumLevel": {...},
        "WriteTo": [
            {
                 "Name": "Console",
                 "Args": {
                    "outputTemplate": "{Timestamp:dd/MM/yy HH:mm:ss,fff} [{Level:u3}] Thread:{ThreadId} {Message}{NewLine:1}"
                 }
            }
        ]
    }
}
Enter fullscreen mode Exit fullscreen mode

Test output:

PS D:\Workspace\dev.to\AspnetcoreSerilog> dotnet run
04/04/20 23:48:37,002 [INF] Thread:1 Hello world!
Enter fullscreen mode Exit fullscreen mode

Logger it's cool but i need sending my output to various sources

With WriteTo(subloggers) you can send log to any resource, and there are a lot of Sinks already implemented. So the only decisiton you have to take is where you want to place log. For simplicity i will store my log messages in two files and console. So the only sink i need is file sink.

 <PackageReference Include="Serilog.Sinks.File" Version="4.1.0" />
Enter fullscreen mode Exit fullscreen mode

Add this 2 nodes to WriteTo section:

 {
                "Name":"File",
                "Args": {
                    "path": "./log1.log"
                }

            },
            {
                "Name":"File",
                "Args": {
                    "path": "./log2.log"
                }
            }
Enter fullscreen mode Exit fullscreen mode

Output on powershell continue being the same but if we check content of the files will be the same too.

PS D:\Workspace\dev.to\AspnetcoreSerilog> dotnet run
05/04/20 00:01:16,177 [INF] Thread:1 Hello world!
PS D:\Workspace\dev.to\AspnetcoreSerilog> type .\log1.log
2020-04-05 00:01:16.177 +02:00 [INF] Hello world!
PS D:\Workspace\dev.to\AspnetcoreSerilog> type .\log2.log
2020-04-05 00:01:16.177 +02:00 [INF] Hello world!
Enter fullscreen mode Exit fullscreen mode

Information it's duplicate! expressions to the rescue

On a real world app, we will probably need sending logs to diferent files or resources.On this example i will send error logs to one file and information to another. There are a lot of choices for log filtering you can find it here:

First, lets make some changes on our program.cs adding an error log.

namespace AspnetcoreSerilog
{
    class Program
    {
        static void Main(string[] args)
        {  
            // Configuration here
            Log.Information("Hello world!");
            Log.Warning("Oops!! ");
            Log.Error("Ouch!!!! ");
        }
    }
}
Enter fullscreen mode Exit fullscreen mode

Add package to our csproj:

    <PackageReference Include="Serilog.Filters.Expressions" Version="2.1.0" />
Enter fullscreen mode Exit fullscreen mode

Now our json file will change significally, despite of having 2 file sinks we will have 2 subloggers filtered with file sinks. I will show appsettings.json file complete:

{
    "Serilog": {
        "Using": [
        ],
        "Enrich": [
            "WithThreadId"
        ],
        "MinimumLevel": {
            "Default": "Debug"
        },
        "WriteTo": [
            {
                "Name": "Console",
                "Args": {
                    "outputTemplate": "{Timestamp:dd/MM/yy HH:mm:ss,fff} [{Level:u3}] Thread:{ThreadId} {Message}{NewLine:1}"
                }
            },
            {
                "Name": "Logger",
                "Args": {
                    "configureLogger": {
                        "Filter": [
                            {
                                "Name": "ByIncludingOnly",
                                "Args": {
                                    "expression": "@Level = 'Warning'"
                                }
                            }
                        ],
                        "WriteTo": [
                            {
                                "Name": "File",
                                "Args": {
                                    "path": "./warning.log"
                                }
                            }
                        ]
                    }
                }
            },
            {
                "Name": "Logger",
                "Args": {
                    "configureLogger": {
                        "Filter": [
                            {
                                "Name": "ByIncludingOnly",
                                "Args": {
                                    "expression": "@Level = 'Error'"
                                }
                            }
                        ],
                        "WriteTo": [
                            {
                                "Name": "File",
                                "Args": {
                                    "path": "./error.log"
                                }
                            }
                        ]
                    }
                }
            }
        ]
    }
}
Enter fullscreen mode Exit fullscreen mode

Output must be the following: Log writes all messages, warning.log file only has warnings logs and error.log only has errors.

PS D:\Workspace\dev.to\AspnetcoreSerilog> dotnet run
05/04/20 00:33:51,927 [INF] Thread:1 Hello world!
05/04/20 00:33:51,948 [WRN] Thread:1 Oops!! 
05/04/20 00:33:51,954 [ERR] Thread:1 Ouch!!!! 
PS D:\Workspace\dev.to\AspnetcoreSerilog> type .\error.log
2020-04-05 00:33:51.954 +02:00 [ERR] Ouch!!!!
PS D:\Workspace\dev.to\AspnetcoreSerilog> type .\warning.log
2020-04-05 00:33:51.948 +02:00 [WRN] Oops!!
Enter fullscreen mode Exit fullscreen mode

That's all! fell free to leave a comment below!

Resouces

Example repository:

Serilog´s documentation it is enough:

💖 💪 🙅 🚩
mandrewcito
Andrés Baamonde Lozano

Posted on April 4, 2020

Join Our Newsletter. No Spam, Only the good stuff.

Sign up to receive the latest update from our blog.

Related

Playing with serilog and dotnetcore
tutorial Playing with serilog and dotnetcore

April 4, 2020