DEV Community

Andrés Baamonde Lozano
Andrés Baamonde Lozano

Posted on

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:

Top comments (0)