Structured Logging with ILogger
Write log events with message templates, levels and LoggerMessage methods so every value is a queryable property, not text.
logger.LogInformation("Order {OrderId} placed for {Total}", order.Id, order.Total);
[LoggerMessage(EventId = 2001, Level = LogLevel.Information, Message = "Order {OrderId} shipped")]
static partial void OrderShipped(ILogger logger, int orderId);An ILogger call does not produce a string; it produces an event: a level, an event id, a category, an optional exception and a state object. ILogger<OrderService> uses the full type name as the category, and every provider registered on the host (console, OpenTelemetry, Serilog, Application Insights) receives the same event. What a provider does with it is its business; what you control is how much structure the event carries.
Message templates
logger.LogInformation("Order {OrderId} placed for {Total}", order.Id, order.Total) passes a template and an argument array. The template is parsed once and cached, and the state handed to providers is a list of key/value pairs: OrderId = 10482, Total = 249.90, plus {OriginalFormat} holding the template. A backend that stores properties can answer "every event for order 10482" or "count per template" without a regex over text. Holes bind by position, not by name: "{CustomerId} {OrderId}" with the arguments swapped labels each value with the wrong name and nothing complains. Use PascalCase names and keep them stable, because dashboards and alerts query by them.
Why interpolation is wrong here
logger.LogInformation($"Order {order.Id} placed") prints the same text, but the template is now a different string for every order: the event has no OrderId property, the template cache fills with one-off entries, and the string is built even when Information is filtered out. Analyzer CA2254 flags a non-constant template; treat it as an error.
Levels and filtering
| Level | Use it for |
|---|---|
Trace (0) | Step-by-step detail for one component while debugging; never on in production |
Debug (1) | Diagnostic detail in development |
Information (2) | Business events and lifecycle: order placed, worker started |
Warning (3) | Unexpected but handled: a retry, a fallback, a rejected payment |
Error (4) | The operation failed and someone may need to act |
Critical (5) | The process or a required dependency is unusable |
Filtering happens in the LoggerFactory before any provider sees the event. Rules come from Logging:LogLevel; the longest matching category prefix wins, so "Microsoft.AspNetCore": "Warning" beats "Default": "Information" for framework categories (the webapi template ships exactly those two). Change levels in configuration, for example Logging__LogLevel__Shop.Payments=Debug, not in code.
The LoggerMessage source generator
The LogInformation(string, params object?[]) extension allocates the argument array and boxes value types before the level check runs. A [LoggerMessage] method on a partial class gets a generated body that checks IsEnabled first, takes typed parameters without boxing, and pins the event id and level in one place. CA1848 flags every LoggerExtensions call (LogInformation and the rest) and suggests LoggerMessage; enforce it at least where logging sits on a hot path. One static partial class per feature doubles as a catalogue of what the feature logs.
Production failure modes
- Passing the exception as a template argument instead of the first parameter: the stack trace becomes a string property and error tracking cannot group it.
- Logging whole request bodies or customer objects: PII and secrets land in a store with weaker access control than the database.
- Log-and-rethrow at every layer: one failure, five Error events, five alerts. Log where you handle.
- Information events inside loops: volume, and the bill, scale with traffic.
Example
When to use it
- Find every event for order 10482 across three services by querying the OrderId property instead of grepping message text.
- Raise Shop.Payments to Debug in production through one environment variable for an hour while a payment provider misbehaves.
- Log 5,000 stock-level checks per second at Debug with LoggerMessage methods so the disabled level costs no allocations.
More examples
LoggerMessage methods on a service instance
Instance <code>[LoggerMessage]</code> methods find the <code>ILogger</code> field on the class, so call sites read like domain events: <code>InvoiceIssued(...)</code>. The generated body checks <code>_logger.IsEnabled(LogLevel.Information)</code> before touching any argument, so the <code>decimal</code> is never boxed when the level is off. Leaving <code>Level</code> out of the attribute and adding a <code>LogLevel</code> parameter lets the caller pick the level while the event id stays fixed, which keeps alert rules keyed on event id 3101 working.
using Microsoft.Extensions.Logging;
public sealed record Invoice(string Number, string CustomerId, decimal Amount, string Currency);
public interface IInvoiceStore
{
Task SaveAsync(Invoice invoice, CancellationToken ct);
}
public sealed partial class InvoiceIssuer
{
private readonly ILogger<InvoiceIssuer> _logger;
private readonly IInvoiceStore _store;
public InvoiceIssuer(ILogger<InvoiceIssuer> logger, IInvoiceStore store)
{
_logger = logger;
_store = store;
}
public async Task IssueAsync(Invoice invoice, CancellationToken ct)
{
await _store.SaveAsync(invoice, ct);
InvoiceIssued(invoice.Number, invoice.CustomerId, invoice.Amount, invoice.Currency);
}
// The generator finds the ILogger field, so the method needs no logger parameter.
[LoggerMessage(EventId = 3100, Level = LogLevel.Information,
Message = "Invoice {InvoiceNumber} issued to {CustomerId} for {Amount} {Currency}")]
private partial void InvoiceIssued(string invoiceNumber, string customerId, decimal amount, string currency);
// Level chosen by the caller: same event id, Warning in one place and Error in another.
[LoggerMessage(EventId = 3101, Message = "Invoice {InvoiceNumber} rejected by the tax service: {Reason}")]
public partial void InvoiceRejected(LogLevel level, string invoiceNumber, string reason);
}
Per-category levels in appsettings.json
Rules match by category prefix and the longest match wins, so <code>Shop.Payments</code> at Debug does not raise <code>Shop.Orders</code>. The same keys work as environment variables, <code>Logging__LogLevel__Shop.Payments=Debug</code>, which is how you raise one feature in a running Kubernetes deployment. The JSON console formatter writes one JSON object per event with the template properties under <code>State</code>, which log shippers can index without parsing text.
{
"Logging": {
"LogLevel": {
"Default": "Information",
// Framework categories log several lines per request at Information; Warning keeps only problems
// (add HTTP logging or your own summary event if you want one line per request).
"Microsoft.AspNetCore": "Warning",
// EF Core logs every SQL command at Information under this category.
"Microsoft.EntityFrameworkCore.Database.Command": "Warning",
// Turn one feature up during an incident without touching the rest.
"Shop.Payments": "Debug"
},
"Console": {
"FormatterName": "json",
"FormatterOptions": {
"IncludeScopes": true,
"UseUtcTimestamp": true,
"TimestampFormat": "yyyy-MM-ddTHH:mm:ss.fffZ"
}
}
}
}
Pitfall: the exception inside the template
Providers put the exception argument in a dedicated field: OpenTelemetry maps it to <code>exception.type</code>, <code>exception.message</code> and <code>exception.stacktrace</code>, and error trackers group by type and stack. Interpolating <code>{ex}</code> into the message hides all of that inside one long string and produces a unique template per payment id. The wrong line also triggers CA2254, which is worth enforcing in the build with <code>dotnet_diagnostic.CA2254.severity = error</code>.
using Microsoft.Extensions.Logging;
public sealed class PaymentCapture(ILogger<PaymentCapture> logger)
{
public void Capture(string paymentId, decimal amount)
{
try
{
throw new HttpRequestException("503 from payment provider");
}
catch (HttpRequestException ex)
{
// Wrong: the exception becomes a string property, the stack trace is lost to grouping,
// and the interpolated text is a new template on every call.
logger.LogError($"Capture failed for {paymentId}: {ex}");
// Right: exception first, constant template, values as properties.
logger.LogError(ex, "Capture of {Amount} failed for payment {PaymentId}", amount, paymentId);
}
}
}
Discussion