Serilog: Serilog là gì? - Part 1

Trong bài viết này, chúng ta sẽ tìm hiểu cách thực hiện ghi log có cấu trúc bằng Serilog trong asp.net core 7.0.

Logging là một phần thiết yếu của một ứng dụng. Nó giúp chúng ta theo dõi ứng dụng và thậm chí giúp chúng ta tìm ra nguyên nhân root cause sau khi triển khai ứng dụng lên production.

Serilog là gì?

Serilog là một thư viện ghi log cực kỳ mạnh mẽ, linh hoạt, dễ cài đặt và tương thích với nhiều nền tảng khác nhau. Chúng ta có thể cấu hình Serilog ghi ra file, hiển thị ra console, debug, lưu vào database, ...

Cài đặt

Trong bài viết này, mình minh họa bằng console application nên sẽ cài đặt thêm package: Serilog.Sinks.Console

Install-Package Serilog
Install-Package Serilog.Sinks.Console

Trong file Program.cs, bạn thêm đoạn code sau:

using Serilog;

using (var log = new LoggerConfiguration()
	.WriteTo.Console()
	.CreateLogger())
{
	log.Information("Hello, Serilog!");
	log.Warning("Goodbye, Serilog.");
}

Trước khi tìm hiểu về đoạn code WriteTo.Console(), chúng ta tìm hiểu về Sink

Sink là gì

Sink trong Serilog là một khái niệm chỉ các thư viện cho phép ghi các sự kiện log vào các định dạng và nơi lưu trữ khác nhau.
Ví dụ: có thể sử dụng sink để ghi log ra màn hình console, file, email, database, hay các dịch vụ như Application Insight, Elasticsearch, AWS, v.v.
Tham khảo: https://github.com/serilog/serilog/wiki/Provided-Sinks

Mỗi sink có một tên và một gói NuGet tương ứng. Để sử dụng một sink, ta cần thêm gói NuGet của nó vào dự án và cấu hình Serilog để ghi log vào sink đó. Bạn có thể xem danh sách các sink có sẵn tại GitHub hoặc tự phát triển một sink theo hướng dẫn tại GitHub.

Sink được thiết lập để sử dụng object WriteTo. Ở ví dụ trên là sử dụng Console().

Bạn có thể thiết lập với nhiều output khác nhau

Log.Logger = new LoggerConfiguration()
    .WriteTo.Console()
    .WriteTo.File("log-.txt", rollingInterval: RollingInterval.Day)
    .CreateLogger();

Output template

Output template trong Serilog là một khái niệm chỉ cách định dạng các sự kiện log khi ghi vào các đầu ra như console, file, email, v.v. Output template cho phép bạn chọn các trường và văn bản để hiển thị trong log output, và sử dụng cú pháp căn chỉnh và chiều rộng theo kiểu .NET format string1. Ví dụ, để điều khiển đầu ra console, bạn có thể sử dụng output template như sau:

Log.Logger = new LoggerConfiguration() .WriteTo.Console(outputTemplate: "[{Timestamp:HH:mm:ss} {Level:u3}] {Message:lj}{NewLine}{Exception}") .CreateLogger();

Giải thích

• Exception - Hiển thị exception trên nhiều dòng, trường hợp không có exception sẽ hiển thị trống.
  
• Level - Hiển thị level của log line. {Level:u3} hoặc{Level:w3} cho 3 ký tự viết hoa hoặc 3 ký tự viết thường
  
• Message - log message.
  :l hiển thị quote text, và :j uses JSON-style
• NewLine - Thêm dòng mới
  
• Properties - All event property values that don't appear elsewhere in the output. Use the :j format to use JSON rendering.
• Timestamp - The event's timestamp, as a DateTimeOffset.

Ví dụ

using Serilog;

using (var log = new LoggerConfiguration()
	.WriteTo.Console(outputTemplate: "{Timestamp:yyyy-MM-dd HH:mm:ss.fff zzz} [{Level:u3}] {Message:lj}{NewLine}{Exception}")
	.CreateLogger())
{
	log.Information("Hello, Serilog!");
	log.Warning("Goodbye, Serilog.");
}

Kết quả

2023-07-27 20:43:21.397 +07:00 [INF] Hello, Serilog!
2023-07-27 20:43:21.424 +07:00 [WRN] Goodbye, Serilog.

Lưu ý

@ trong Serilog là một toán tử đặc biệt để chỉ định rằng giá trị của tham số được truyền vào nên được ghi lại dưới dạng đối tượng có cấu trúc, thay vì sử dụng phương thức ToString() của nó. Ví dụ, nếu bạn có một đối tượng như sau:

public class User
{
	public int Id { get; set; }
	public string Name { get; set; }
	public DateTime Created { get; set; }
}

In thông tin user

using (var log = new LoggerConfiguration()
	.WriteTo.Console()
	.CreateLogger())
{
	var exampleUser = new User { Id = 1, Name = "Adam", Created = DateTime.Now };
	var person = new { Name = "Alice", Age = 25 };
	log.Information("Created {person} {@exampleUser} on {Created}", person,exampleUser, DateTime.Now);
}

Kết quả

[21:01:35 INF] Created { Name = Alice, Age = 25 } {"Id": 1, "Name": "Adam", "Created": "2023-07-27T21:01:35.4166660+07:00", "$type": "User"} on 07/27/2023 21:01:35

Trường hợp bạn bỏ @ ra

using (var log = new LoggerConfiguration()
	.WriteTo.Console()
	.CreateLogger())
{
	var exampleUser = new User { Id = 1, Name = "Adam", Created = DateTime.Now };
	var person = new { Name = "Alice", Age = 25 };
	log.Information("Created {person} {exampleUser} on {Created}", person,exampleUser, DateTime.Now);
}

[21:05:39 INF] Created { Name = Alice, Age = 25 } SerilogDemo.ConsoleDemo.User on 07/27/2023 21:05:39

Enrichment

Serilog cho phép bạn thêm các thuộc tính vào các sự kiện log một cách dynamic, dựa trên context thực thi hiện tại. Để làm được điều này, bạn cần sử dụng Enrich.FromLogContext() khi cấu hình logger

var log = new LoggerConfiguration()
	.Enrich.FromLogContext()
	.Enrich.WithProperty("Prop1", "ABC123")
	.Enrich.WithProperty("Prop2", "1.00")
	.Enrich.WithProperty("PID", Process.GetCurrentProcess().Id) // 9840
	.WriteTo.Console(
		outputTemplate: "{Timestamp:HH:mm:ss} {Level:u3} {Message} {Prop1} {Prop2} {PID}{NewLine}{Exception}"
	)
	.CreateLogger();

log.Information("Test log");

Kết quả

01:38:24 INF Test log ABC123 1.00 30884

Custom Enrichment

Để custom enricher trong Serilog, chúng ta cần định nghĩa 1 class implement ILogEventEnricher interface.

public interface ILogEventEnricher
{
    void Enrich(LogEvent logEvent, ILogEventPropertyFactory propertyFactory);
}

Implement UserInfoEnricher

public class UserInfoEnricher : ILogEventEnricher
{
	static readonly string _userInfo;

	/// <summary>
	/// static constructor to load the environment variable
	/// </summary>
	static UserInfoEnricher()
	{
		_userInfo = Guid.NewGuid().ToString();
	}

	public void Enrich(
		LogEvent logEvent,
		ILogEventPropertyFactory propertyFactory)
	{
		var enrichProperty = propertyFactory
			.CreateProperty(
				"UserId",
				_userInfo);

		logEvent.AddOrUpdateProperty(enrichProperty);
	}
}

Hàm Enrich được gọi cho mỗi log event, và chúng ta có thể thêm custom properties vào logEvent parameter. PropertyFactory parameter có thể được dùng để thêm properties mới.

var log = new LoggerConfiguration()
	.MinimumLevel.Information()
	.Enrich.FromLogContext()
	.Enrich.With(new UserInfoEnricher())
	.WriteTo.Console(
		outputTemplate: "[{Timestamp:HH:mm:ss} {Level:u3} (UserId: {UserId})] {Message:lj}{NewLine}{Exception}")
	.CreateLogger();

log.Information("Test log {UserId}");

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

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

Kết quả

[19:03:09 INF (UserId: 5d833687-220f-43b7-8787-2ddbee79e9c3)] Test log 5d833687-220f-43b7-8787-2ddbee79e9c3
[19:03:09 INF (UserId: 5d833687-220f-43b7-8787-2ddbee79e9c3)] Processed {"Latitude": 25, "Longitude": 134} in 034 ms.

Custom Serilog Sink

Một custom Serilog Sink là một class implement từ interface ILogEventSink, nhận các sự kiện log từ Serilog và xử lý chúng theo cách riêng của bạn

Để tạo một custom Serilog Sink, bạn cần làm các bước sau:

1. Tạo lớp MySink kế thừa từ ILogEventSink và viết phương thức Emit để xử lý các sự kiện log.
2. Tạo lớp MySinkExtensions để cung cấp một phương thức mở rộng cho LoggerSinkConfiguration. Phương thức này sẽ trả về một LoggerConfiguration với sink mới của bạn 
3. Sử dụng sink của bạn khi cấu hình Serilog, ví dụ: WriteTo.MySink()
   

public class MySink : ILogEventSink
{
	private readonly IFormatProvider _formatProvider;

	public MySink(IFormatProvider formatProvider)
	{
		_formatProvider = formatProvider;
	}

	public void Emit(LogEvent logEvent)
	{
		var message = logEvent.RenderMessage(_formatProvider);
		Console.WriteLine(DateTimeOffset.Now.ToString() + " " + message);
	}
}
public static class MySinkExtensions
{
	public static LoggerConfiguration MySink(
			  this LoggerSinkConfiguration loggerConfiguration,
			  IFormatProvider formatProvider = null)
	{
		return loggerConfiguration.Sink(new MySink(formatProvider));
	}
}

Ở file program, bạn thêm đoạn code như sau:

var log = new LoggerConfiguration()
	.MinimumLevel.Information()
	.WriteTo.MySink()
	.CreateLogger();

log.Information("Test log");

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

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

Kết quả

7/28/2023 9:19:31 AM +07:00 Test log
7/28/2023 9:19:31 AM +07:00 Processed { Latitude: 25, Longitude: 134 } in 034 ms.

Tham khảo

https://github.com/serilog/serilog/wiki/Developing-a-sink