Isaac.

Logging Best Practices

Implement comprehensive logging for debugging and monitoring.

By EMEPublished: February 20, 2025
loggingserilogstructured loggingdebugging

A Simple Analogy

Good logging is like a flight recorder. When something goes wrong, it contains the full history to understand what happened.


Why Logging?

  • Debugging: Understand what happened
  • Monitoring: Detect issues
  • Auditing: Track user actions
  • Performance: Identify bottlenecks
  • Compliance: Legal requirements

Serilog Setup

using Serilog;

Log.Logger = new LoggerConfiguration()
    .MinimumLevel.Debug()
    .WriteTo.Console()
    .WriteTo.File("logs/app-.txt", 
        rollingInterval: RollingInterval.Day,
        outputTemplate: "{Timestamp:yyyy-MM-dd HH:mm:ss.fff zzz} [{Level:u3}] {Message:lj}{NewLine}{Exception}")
    .WriteTo.Seq("http://localhost:5341")
    .Enrich.FromLogContext()
    .Enrich.WithProperty("Application", "MyApp")
    .CreateLogger();

builder.Host.UseSerilog();

app.Run();

Structured Logging

public class OrderService
{
    private readonly ILogger<OrderService> _logger;
    
    public OrderService(ILogger<OrderService> logger)
    {
        _logger = logger;
    }
    
    public async Task<Order> CreateOrderAsync(CreateOrderRequest request)
    {
        using (_logger.BeginScope("CreateOrder_{OrderId}", Guid.NewGuid()))
        {
            try
            {
                _logger.LogInformation(
                    "Creating order for customer {CustomerId} with {ItemCount} items",
                    request.CustomerId,
                    request.Items.Count);
                
                var order = new Order { CustomerId = request.CustomerId };
                order.Items.AddRange(request.Items);
                
                _logger.LogInformation(
                    "Order {OrderId} created with total {Total}",
                    order.Id,
                    order.Total);
                
                return order;
            }
            catch (Exception ex)
            {
                _logger.LogError(ex,
                    "Failed to create order for customer {CustomerId}",
                    request.CustomerId);
                throw;
            }
        }
    }
}

Log Levels

_logger.LogTrace("Entering method");        // Most verbose
_logger.LogDebug("Variable value: {@Value}", value);
_logger.LogInformation("Order created: {OrderId}", orderId);
_logger.LogWarning("High memory usage: {UsagePercent}%", usage);
_logger.LogError(ex, "Failed to save order");
_logger.LogCritical(ex, "Database connection failed");  // Most severe

Context and Enrichment

// Add context to all logs in a scope
using (_logger.BeginScope(new Dictionary<string, object>
{
    { "UserId", user.Id },
    { "TraceId", HttpContext.TraceIdentifier },
    { "RequestPath", HttpContext.Request.Path }
}))
{
    _logger.LogInformation("Processing user request");
    // Logs include all context
}

// Automatic enrichment
.Enrich.WithProperty("Environment", env)
.Enrich.WithMachineName()
.Enrich.WithThreadId()
.Enrich.FromLogContext()

Exceptions

public async Task<IActionResult> ProcessAsync(string id)
{
    try
    {
        var data = await FetchDataAsync(id);
        return Ok(data);
    }
    catch (NotFoundException ex)
    {
        _logger.LogWarning(ex,
            "Data not found: {DataId}",
            id);
        return NotFound();
    }
    catch (Exception ex)
    {
        _logger.LogError(ex,
            "Unexpected error processing {DataId}: {Message}",
            id,
            ex.Message);
        return StatusCode(500);
    }
}

Performance Logging

public class PerformanceMiddleware
{
    private readonly RequestDelegate _next;
    private readonly ILogger<PerformanceMiddleware> _logger;
    
    public async Task InvokeAsync(HttpContext context)
    {
        var stopwatch = System.Diagnostics.Stopwatch.StartNew();
        
        try
        {
            await _next(context);
        }
        finally
        {
            stopwatch.Stop();
            
            if (stopwatch.ElapsedMilliseconds > 1000)
            {
                _logger.LogWarning(
                    "Slow request: {Method} {Path} took {ElapsedMilliseconds}ms",
                    context.Request.Method,
                    context.Request.Path,
                    stopwatch.ElapsedMilliseconds);
            }
            else
            {
                _logger.LogInformation(
                    "Request: {Method} {Path} completed in {ElapsedMilliseconds}ms",
                    context.Request.Method,
                    context.Request.Path,
                    stopwatch.ElapsedMilliseconds);
            }
        }
    }
}

Best Practices

  1. Structured logging: Use properties, not string concatenation
  2. Log levels: Use appropriate levels
  3. Context: Include user, request, transaction IDs
  4. Avoid PII: Don't log passwords or sensitive data
  5. Performance: Async logging to avoid bottlenecks

Related Concepts

  • Distributed tracing
  • Log aggregation
  • Metrics and monitoring
  • Application insights

Summary

Structured logging with context provides invaluable debugging information and enables proactive monitoring. Use Serilog with appropriate log levels and enrichment for comprehensive coverage.