Skip to content

Commit

Permalink
[docs] Add exception logging best practices (#6037)
Browse files Browse the repository at this point in the history
  • Loading branch information
CodeBlanch authored Jan 16, 2025
1 parent f7df3e1 commit dcdaaae
Showing 1 changed file with 145 additions and 35 deletions.
180 changes: 145 additions & 35 deletions docs/logs/README.md
Original file line number Diff line number Diff line change
Expand Up @@ -25,33 +25,17 @@ OpenTelemetry .NET:
* [Getting Started - Console Application](./getting-started-console/README.md)
* [Logging with Complex Objects](./complex-objects/README.md)

## Structured Logging

:heavy_check_mark: You should use structured logging.

* Structured logging is more efficient than unstructured logging.
* Filtering and redaction can happen on individual key-value pairs instead of
the entire log message.
* Storage and indexing are more efficient.
* Structured logging makes it easier to manage and consume logs.

:stop_sign: You should avoid string interpolation.

> [!WARNING]
> The following code has bad performance due to [string
interpolation](https://learn.microsoft.com/dotnet/csharp/tutorials/string-interpolation):

```csharp
var food = "tomato";
var price = 2.99;
## Logging API

logger.LogInformation($"Hello from {food} {price}.");
```
### ILogger

Refer to the [logging performance
benchmark](../../test/Benchmarks/Logs/LogBenchmarks.cs) for more details.
.NET supports high performance, structured logging via the
[`Microsoft.Extensions.Logging.ILogger`](https://docs.microsoft.com/dotnet/api/microsoft.extensions.logging.ilogger)
interface (including
[`ILogger<TCategoryName>`](https://learn.microsoft.com/dotnet/api/microsoft.extensions.logging.ilogger-1))
to help monitor application behavior and diagnose issues.

## Package Version
#### Package Version

:heavy_check_mark: You should always use the
[`ILogger`](https://docs.microsoft.com/dotnet/api/microsoft.extensions.logging.ilogger)
Expand All @@ -69,16 +53,6 @@ package, regardless of the .NET runtime version being used:
backward compatibility on `Microsoft.Extensions.Logging` even during major
version bumps, so compatibility is not a concern here.

## Logging API

### ILogger

.NET supports high performance, structured logging via the
[`Microsoft.Extensions.Logging.ILogger`](https://docs.microsoft.com/dotnet/api/microsoft.extensions.logging.ilogger)
interface (including
[`ILogger<TCategoryName>`](https://learn.microsoft.com/dotnet/api/microsoft.extensions.logging.ilogger-1))
to help monitor application behavior and diagnose issues.

#### Get Logger

In order to use the `ILogger` interface, you need to first get a logger. How to
Expand Down Expand Up @@ -125,7 +99,38 @@ are not super expensive, they still come with CPU and memory cost, and are meant
to be reused throughout the application. Refer to the [logging performance
benchmark](../../test/Benchmarks/Logs/LogBenchmarks.cs) for more details.

#### Use Logger
#### Write log messages

:heavy_check_mark: You should use structured logging.

* Structured logging is more efficient than unstructured logging.
* Filtering and redaction can happen on individual key-value pairs instead of
the entire log message.
* Storage and indexing are more efficient.
* Structured logging makes it easier to manage and consume logs.

```csharp
var food = "tomato";
var price = 2.99;

logger.LogInformation("Hello from {food} {price}.", food, price);
```

:stop_sign: You should avoid string interpolation.

> [!WARNING]
> The following code has bad performance due to [string
interpolation](https://learn.microsoft.com/dotnet/csharp/tutorials/string-interpolation):

```csharp
var food = "tomato";
var price = 2.99;

logger.LogInformation($"Hello from {food} {price}.");
```

Refer to the [logging performance
benchmark](../../test/Benchmarks/Logs/LogBenchmarks.cs) for more details.

:heavy_check_mark: You should use [compile-time logging source
generation](https://docs.microsoft.com/dotnet/core/extensions/logger-message-generator)
Expand Down Expand Up @@ -222,6 +227,111 @@ code is now depending on which logger is being enabled, not to mention the
argument evaluation might have significant side effects that are now depending
on the logging configuration.

:heavy_check_mark: You should use a dedicated parameter to log exceptions when
using the compile-time source generator.

```csharp
var food = "tomato";
var price = 2.99;

try
{
// Execute some logic
logger.SayHello(food, price);
}
catch (Exception ex)
{
logger.SayHelloFailure(ex, food, price);
}

internal static partial class LoggerExtensions
{
[LoggerMessage(Level = LogLevel.Information, Message = "Hello from {food} {price}.")]
public static partial void SayHello(this ILogger logger, string food, double price);

[LoggerMessage(Level = LogLevel.Error, Message = "Could not say hello from {food} {price}.")]
public static partial void SayHelloFailure(this ILogger logger, Exception exception, string food, double price);
}
```

> [!NOTE]
> When using the compile-time source generator the first `Exception` parameter
> detected is automatically given special handling. It **SHOULD NOT** be part of
> the message template. For details see: [Log method
> anatomy](https://learn.microsoft.com/dotnet/core/extensions/logger-message-generator#log-method-anatomy).
:heavy_check_mark: You should use the dedicated overloads to log exceptions when
using the logging extensions methods.

```csharp
var food = "tomato";
var price = 2.99;

try
{
// Execute some logic
logger.LogInformation("Hello from {food} {price}.", food, price);
}
catch (Exception ex)
{
logger.LogError(ex, "Could not say hello from {food} {price}.", food, price);
}
```

:stop_sign: You should avoid adding exception details into the message template.

You want to use the correct `Exception` APIs because the OpenTelemetry
Specification [defines dedicated
attributes](https://github.com/open-telemetry/semantic-conventions/blob/main/docs/exceptions/exceptions-logs.md)
for `Exception` details. The following examples show what **NOT** to do. In
these cases the details won't be lost, but the dedicated attributes also won't
be added.

```csharp
var food = "tomato";
var price = 2.99;

try
{
// Execute some logic
logger.SayHello(food, price);
}
catch (Exception ex)
{
logger.SayHelloFailure(food, price, ex.Message);
}

internal static partial class LoggerExtensions
{
[LoggerMessage(Level = LogLevel.Information, Message = "Hello from {food} {price}.")]
public static partial void SayHello(this ILogger logger, string food, double price);

// BAD - Exception should not be part of the message template. Use the dedicated parameter.
[LoggerMessage(Level = LogLevel.Error, Message = "Could not say hello from {food} {price} {message}.")]
public static partial void SayHelloFailure(this ILogger logger, string food, double price, string message);
}
```

```csharp
var food = "tomato";
var price = 2.99;

try
{
// Execute some logic
logger.LogInformation("Hello from {food} {price}.", food, price);
}
catch (Exception ex)
{
// BAD - Exception should not be part of the message template. Use the dedicated parameter.
logger.LogError("Could not say hello from {food} {price} {message}.", food, price, ex.Message);
}
```

## LoggerFactory

In many cases, you can use [ILogger](#ilogger) without having to interact with
Expand Down

0 comments on commit dcdaaae

Please # to comment.