From f88382671317dd424a62f6bb0b879de8726afdd2 Mon Sep 17 00:00:00 2001 From: Chad Peters Date: Wed, 24 Jul 2024 12:55:14 -0400 Subject: [PATCH] Updated post --- .../posts/2024-07-24-logging-messages.md | 24 +++++++++---------- 1 file changed, 11 insertions(+), 13 deletions(-) diff --git a/src/content/posts/2024-07-24-logging-messages.md b/src/content/posts/2024-07-24-logging-messages.md index 7b6319a..4038a83 100644 --- a/src/content/posts/2024-07-24-logging-messages.md +++ b/src/content/posts/2024-07-24-logging-messages.md @@ -17,7 +17,7 @@ twitter_text: "ASP.NET Core Logger messages matter" Recently I was reviewing some code and I noticed something that seemed a little strange 😕 -``` csharp +```csharp catch (Exception ex) { _logger.LogError("Unable to retrieve Lead {0} : {1}", leadId, ex); @@ -25,13 +25,13 @@ catch (Exception ex) } ``` -Admittedly, I didn't know as much about logging as I should have 🤷🏻‍♂️. It's just something that was always there that someone else setup. It did seem strange that you would stuff the exception into the message. So as they say, there is no time like the present! +Admittedly, I didn't know as much about logging as I should have 🤷🏻‍♂️. It's just something that was always there that someone else setup. It did seem strange that you would stuff the exception into the message. So as they say, there is no time like the present! ⛏ ASP.NET Core makes it easy to connect to a variety of logging providers. You can find out more about setting up logging [here](https://learn.microsoft.com/en-us/aspnet/core/fundamentals/logging/?view=aspnetcore-8.0). I want to focus on the messages you pass to the logger. The messages get passed using a message template. This allows for structured logging. I read that was important because logging providers can store the parameters in the message template as fields. What does that look like and why is that important? Sometimes I need to see it in action to cement my understanding. -I ran `dotnet new webapp` and in the project's Program.cs file I added this contrived endpoint: +I ran `dotnet new webapp` to setup a new ASP.NET Core project. In the project's Program.cs file I added this contrived endpoint: ```csharp app.MapGet("/log/{id}", async (int id, ILogger logger, HttpResponse response) => @@ -53,26 +53,24 @@ app.MapGet("/log/{id}", async (int id, ILogger logger, HttpResponse res ``` -🔎 Let's first compare the first two `logger.LogError`. The first one uses the message template as recommended. This looks like what you would see in the `string.Format` method. This might lead you to think, "why don't we use string interpolation instead?". I configured my logger to write to App Insights so I could see the difference. I found my two errors in the LogManagement.AppTraces table of my Log Analytics workspace Logs. I've eliminated some properties for brevity. +🔎 Let's compare the first two `logger.LogError`. The first one uses the message template as recommended. This looks like what you would see in the `string.Format` method. This might lead you to think, "Why don't we use string interpolation instead?" like we see in the second log. + +I configured my logger in my sample app to write to Azure Application Insights (see [Using Application Insights in ASP.NET Core](https://learn.microsoft.com/en-us/azure/azure-monitor/app/asp-net-core)). After running my app and hitting the endpoint, I found my two errors in the LogManagement.AppTraces table of my Log Analytics workspace Logs. I've eliminated some properties for brevity. ![Message Template](/images/logging/messagetemplate.jpg) ![String Interpolation](/images/logging/stringinterpolation.jpg) -Comparing the two, you can spot a few difference. The Properties.OriginalFormat in the message template example shows the templated message. In the string interpolation example it shows the dynamic, interpolated string. The message template example also includes the two parameters, id and exception, as properties. +Comparing the two, you can spot a few differences. The Properties.OriginalFormat in the message template example shows the templated message. In the string interpolation example it shows the dynamic, interpolated string. The message template example also includes the two parameters, `id` and `exception`, as Properties. -Why is this important? 💡 It's important because now querying my logs becomes much easier. If we use the message template, I can now query Properties.OriginalFormat for the message template and get all instances of this error. If we use string interpolation the OriginalFormat is dynamic because it will have different ids. We can also narrow our queries further by using the id and exception properties in our queries. +Why is this important? 💡 It's important because now querying my logs becomes much easier. If we use the message template, I can now query Properties.OriginalFormat for the message template and get all instances of this error. If we use string interpolation the OriginalFormat is dynamic because it will have different ids. We can also narrow our queries further by using the `id` and `exception` properties in our queries. Let's look at the third example. `Microsoft.Extensions.Logging` has many overload for ILogger.LogError. One of those extensions takes the exception as the first parameter and the message template as the second. What do we get for this? -My message now appears in the LogManagement.AppExceptions table and I get more properties related to the exception that I can now query. +My log message now appears in the LogManagement.AppExceptions table and I get more properties related to the exception that I can now query. ![Exception and Message Template](/images/logging/exception.jpg) -One other tip, since the message template does look like the `string.format` method it might also be tempting to use numbers for your parameter placeholders. This was common practice for `string.format` i.e. `{0}`. However, as you realize now, having a bunch of different log message types with a property whose name is `0` isn't going to benefit you. - -It helped me to see this for myself in Log Analytics. If you've never seen this before either, hopefully it helped you too. - -[Using Application Insights in ASP.NET Core](https://learn.microsoft.com/en-us/azure/azure-monitor/app/asp-net-core) - +One other tip, since the message template does look like the `string.Format` method it might also be tempting to use numbers for your parameter placeholders. This was common practice for `string.Format` i.e. `{0}`. However, as you realize now, having a bunch of different log message types with a property whose name is `0` isn't going to benefit you. +It helped me to see this for myself in Log Analytics. If you've never seen this before either, hopefully it helped you too. \ No newline at end of file