How Things Work

Structured Logging & Diagnostics

Why Console.WriteLine is killing your production debuggability — and how ILogger, Serilog, and OpenTelemetry actually work.

How It Works

ASP.NET Core's logging abstraction (ILogger<T>) is a structured event pipeline, not a string writer. Every log call captures a message template, structured properties, and context — then fans out to multiple sinks that each apply their own level filters. Understanding this pipeline is the difference between an incident that takes 5 minutes to diagnose and one that takes 5 hours.

ILogger<T> captures a log event — not a string

When you call _logger.LogInformation("User {UserId} logged in", userId), the framework creates a LogEntry with EventId, LogLevel, message template (a constant), and a structured properties dictionary — before any string is built.

Level filter gate — the first firewall

The minimum level configured for each category is checked first. If the event's level is below the threshold, the entire pipeline short-circuits with zero allocations. This is why message templates (not $-strings) are critical.

Log providers (sinks) receive the raw event

Each registered ILoggerProvider receives the LogEntry and decides how to serialize it. The Console provider renders to text. Serilog serializes to JSON. Application Insights converts to a TraceTelemetry object. Each sink applies its own level filter.

Log scopes carry ambient context

BeginScope() pushes key-value pairs onto an async-local stack. Serilog and other providers automatically enrich every log entry written inside the scope with these values. Use scopes for RequestId, UserId, OrderId — not per-message parameters.

OpenTelemetry bridges logs, traces, and metrics

With .AddOpenTelemetry(), ILogger events are automatically correlated with the current Activity (trace span). TraceId and SpanId are injected into every log entry, letting you jump from a log line directly to the distributed trace in Jaeger or Tempo.

Key Concepts

📝ILogger<T>

Generic logger interface injected via DI. The T parameter sets the log category (usually the class name), enabling per-category level overrides in config.

🔧Message Templates

Constant strings with named holes like {UserId}. Serilog and Microsoft.Extensions.Logging preserve these as structured properties — not interpolated text. Enables querying by property in Seq, Kibana, etc.

📊LogLevel

Ordered severity: Trace(0) < Debug(1) < Information(2) < Warning(3) < Error(4) < Critical(5). Production typically uses Warning or Information. MinimumLevel.Override allows per-namespace tuning.

🔭Log Scopes

BeginScope() creates an async-local context that enriches all logs within its using block. Ideal for request-level context (TraceIdentifier, UserId) that shouldn't be repeated on every line.

✨Serilog Enrichers

Automatically attach properties to every event: machine name, thread ID, correlation ID, environment name, assembly version. Configured once in Program.cs, available everywhere.

🔗Activity / OpenTelemetry

System.Diagnostics.Activity maps to OTel Spans. Activity.Current?.TraceId gives you the W3C trace ID. When using AddOpenTelemetry(), log entries are automatically tagged with the active span context.

🆔TraceIdentifier

HttpContext.TraceIdentifier is the per-request ID generated by ASP.NET Core. Always include this in error responses and logs — it's the first thing you need when a user reports a bug.

🏗️Structured Output

Instead of a flat string, structured logs are JSON objects with typed fields. Allows queries like: level:Error AND OrderId:8821 AND ElapsedMs:[500 TO *] in any log aggregation system.

Structured Logging with Serilog + OpenTelemetry (ASP.NET Core 9)

tsx

1// Program.cs — Serilog with structured logging
2builder.Host.UseSerilog((ctx, lc) => lc
3    .MinimumLevel.Information()
4    .MinimumLevel.Override("Microsoft", LogEventLevel.Warning)
5    .Enrich.FromLogContext()
6    .Enrich.WithMachineName()
7    .Enrich.WithCorrelationId()   // from Serilog.Enrichers.CorrelationId
8    .WriteTo.Console(new RenderedCompactJsonFormatter())
9    .WriteTo.Seq("http://seq:5341")
10    .WriteTo.ApplicationInsights(
11        ctx.Configuration["ApplicationInsights:InstrumentationKey"],
12        TelemetryConverter.Traces));
13
14// In a controller or service — DO use ILogger<T>, NOT static fields
15public class OrderService(ILogger<OrderService> _logger)
16{
17    public async Task<Order> ProcessAsync(
18        Guid orderId,
19        CancellationToken cancellationToken)
20    {
21        // Use log scopes for correlation across calls
22        using var scope = _logger.BeginScope(new Dictionary<string, object>
23        {
24            ["OrderId"] = orderId,
25            ["TraceId"] = Activity.Current?.TraceId.ToString()
26                          ?? HttpContext.TraceIdentifier,
27        });
28
29        _logger.LogInformation(
30            "Processing order {OrderId} for user {UserId}",
31            orderId, userId);   // structured — NOT $"Processing order {orderId}"
32
33        try
34        {
35            var result = await _paymentGateway.ChargeAsync(orderId, cancellationToken);
36            _logger.LogInformation(
37                "Order {OrderId} charged successfully. Amount: {Amount:C}, Gateway: {Gateway}",
38                orderId, result.Amount, result.GatewayName);
39            return result.Order;
40        }
41        catch (PaymentGatewayException ex)
42        {
43            // Log the exception object — Serilog captures the full stack trace
44            _logger.LogError(ex,
45                "Payment failed for order {OrderId}. Gateway status: {GatewayStatus}",
46                orderId, ex.StatusCode);
47            throw;
48        }
49    }
50}
51
52// OpenTelemetry — correlate logs, traces, metrics together
53builder.Services.AddOpenTelemetry()
54    .WithTracing(b => b
55        .AddAspNetCoreInstrumentation()
56        .AddHttpClientInstrumentation()
57        .AddOtlpExporter())
58    .WithMetrics(b => b
59        .AddAspNetCoreInstrumentation()
60        .AddOtlpExporter());

💡

Why This Matters

Structured logging is what makes your system observable in production. When an order fails at 2 AM, you need to query: show me all logs for OrderId=8821 across all services in the last 10 minutes. That query is only possible if OrderId was logged as a structured property — not interpolated into a string. The 30 minutes you spend setting up Serilog properly will save hours of incident response time.

Common Pitfalls

⚠String interpolation ($"User {userId} logged in") allocates a string on every call, even when the log level is filtered out. At high request rates this causes measurable GC pressure. Always use message templates: _logger.LogInformation("User {UserId} logged in", userId).

⚠Capturing ILogger in a static field bypasses the category system and breaks structured context injection. Always inject ILogger<T> via the constructor — never store it in a static variable or resolve it via a static service locator.

⚠Logging passwords, tokens, PII, or connection strings is a compliance violation waiting to happen. Use [LoggerMessage] source-generated methods which support redaction, or implement a destructuring policy in Serilog to scrub sensitive properties before they reach any sink.

⚠Missing TraceIdentifier in error responses means support tickets say 'it didn't work' with no way to find the relevant log entry. Include HttpContext.TraceIdentifier (or Activity.Current.TraceId) in every Problem Details error response and every exception log entry.

Real-World Use Cases

15-Minute Outage With No Useful Logs

Scenario

Black Friday. The checkout service spiked to 500 errors for 5 minutes. The on-call engineer opened Kibana and found 50,000 log lines saying 'Payment processing failed' — all identical strings, no order IDs, no user context, no exception details.

Problem

Developers used string interpolation ($"Payment failed for {orderId}") but the logger category was set to Warning minimum. The Error logs that did come through were swallowed by a try/catch that called _logger.LogError("Payment failed") with no exception object and no structured properties. Finding the root cause required a 2-hour war room.

Solution

Switch every log call to message templates with structured properties. Pass the Exception object as the first parameter to LogError. Add BeginScope with OrderId and TraceIdentifier at the service method entry. Configure minimum level per namespace: Microsoft.* at Warning, your own namespace at Information. The next incident had a TraceId in every log line — RCA took 8 minutes.

💡

Takeaway: Structured logging is a production readiness requirement, not a nice-to-have. The investment in setting it up correctly pays back on your very first post-deployment incident.

2Debug Logs Flooding Production — 40GB/Day

Scenario

A new service deployed to production kept hitting Azure Log Analytics storage limits within 6 hours. Ingestion costs spiked from $12/day to $280/day. The culprit: Microsoft.EntityFrameworkCore.Database.Command was logging every SQL query at Debug level.

Problem

The appsettings.Production.json had 'Default': 'Debug' — likely copy-pasted from development config. ASP.NET Core and EF Core emit hundreds of Debug/Trace events per request. At 10,000 requests/hour, that's millions of log entries per day that no one ever reads.

Solution

Use MinimumLevel.Override() to suppress noisy framework categories in production: Microsoft.EntityFrameworkCore at Warning, Microsoft.AspNetCore at Warning, System.Net.Http at Warning. Keep your own namespace at Information. Use a tiered approach: local dev at Debug, staging at Information, prod at Warning (with Error going to a separate high-priority sink).

💡

Takeaway: Always configure category-level overrides in production. 'Default: Debug' in production is a billing disaster waiting to happen, and it makes real errors unfindable in the noise.

3Correlation IDs Lost Across Service Boundaries

Scenario

A microservices system had perfect per-service logs — but when an order failed, tracing the flow across 4 services required manual timeline reconstruction across 4 different Kibana dashboards, correlating timestamps by hand. Incidents averaged 45 minutes of log archaeology.

Problem

Each service generated its own RequestId independently. No W3C traceparent header was propagated between services. When Service A called Service B via HttpClient, the logs in B had no connection to the logs in A. Even though both services used Serilog, they were isolated islands of observability.

Solution

Add OpenTelemetry with AddAspNetCoreInstrumentation() and AddHttpClientInstrumentation(). HttpClient automatically injects traceparent/tracestate headers. The receiving service picks them up and continues the trace. Add .Enrich.WithSpanId().Enrich.WithTraceId() to Serilog. Now every log line in every service carries the same root TraceId — a single query in Grafana Tempo or Jaeger shows the full distributed trace.

💡

Takeaway: Correlation IDs are not a logging concern — they are a distributed systems concern. Set up W3C trace context propagation at the infrastructure level (OpenTelemetry) rather than manually threading request IDs through every method signature.