Isaac.

devops

Logging Best Practices

Implement comprehensive logging for debugging and monitoring.

By Emem IsaacNovember 15, 20233 min read
#logging#serilog#structured logging#debugging
Share:

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.

Share:

Written by Emem Isaac

Expert Software Engineer with 15+ years of experience building scalable enterprise applications. Specialized in ASP.NET Core, Azure, Docker, and modern web development. Passionate about sharing knowledge and helping developers grow.

Ready to Build Something Amazing?

Let's discuss your project and explore how my expertise can help you achieve your goals. Free consultation available.

💼 Trusted by 50+ companies worldwide | ⚡ Average response time: 24 hours