dotnet-cqrs/Svrnty.CQRS.Events/Logging/README.md

7.7 KiB

Event Streaming Structured Logging

This directory contains high-performance structured logging for event streaming operations.

Features

  • Zero-allocation logging using LoggerMessage source generators
  • Correlation ID propagation across async operations
  • Strongly-typed log parameters with compile-time safety
  • Consistent log structure across all operations
  • Distributed tracing support with correlation IDs
  • Comprehensive event coverage for all lifecycle events

Quick Start

Basic Logging

public class MyEventHandler
{
    private readonly ILogger<MyEventHandler> _logger;

    public MyEventHandler(ILogger<MyEventHandler> logger)
    {
        _logger = logger;
    }

    public async Task HandleAsync(MyEvent evt)
    {
        // Log event consumption
        var stopwatch = Stopwatch.StartNew();

        try
        {
            // Process event
            await ProcessEventAsync(evt);

            // Log success
            _logger.LogEventConsumed(
                evt.EventId,
                evt.GetType().Name,
                "my-subscription",
                "consumer-123",
                stopwatch.ElapsedMilliseconds);
        }
        catch (Exception ex)
        {
            // Log failure
            _logger.LogEventConsumptionFailed(
                evt.EventId,
                evt.GetType().Name,
                "my-subscription",
                "consumer-123",
                ex.Message,
                ex);

            throw;
        }
    }
}

Correlation ID Propagation

public async Task PublishWithCorrelationAsync(MyEvent evt)
{
    // Start a correlation context
    using (CorrelationContext.Begin(evt.CorrelationId))
    {
        // All logs within this scope will include the correlation ID
        _logger.LogEventPublished(
            evt.EventId,
            evt.GetType().Name,
            "my-stream",
            CorrelationContext.Current);

        await _streamStore.AppendAsync("my-stream", evt);

        // Correlation ID automatically propagates through async calls
        await NotifyConsumersAsync(evt);
    }
}

Stream Lifecycle Logging

// Log stream creation
_logger.LogStreamCreated(
    streamName: "user-events",
    streamType: "Persistent",
    streamScope: "Internal",
    deliverySemantics: "AtLeastOnce");

// Log subscription registration
_logger.LogSubscriptionRegistered(
    subscriptionId: "email-notifications",
    streamName: "user-events",
    subscriptionMode: "Broadcast");

// Log consumer connection
_logger.LogConsumerConnected(
    consumerId: "email-service-1",
    subscriptionId: "email-notifications",
    streamName: "user-events");

Consumer Health Logging

// Log consumer lag
if (lag > 1000)
{
    _logger.LogConsumerLagging(
        consumerId: "slow-consumer",
        subscriptionId: "analytics",
        lag: lag);
}

// Log stalled consumer
if (timeSinceUpdate > TimeSpan.FromMinutes(5))
{
    _logger.LogConsumerStalled(
        consumerId: "stalled-consumer",
        subscriptionId: "analytics",
        timeSinceUpdate: timeSinceUpdate,
        lag: lag);
}

Retry and Dead Letter Logging

// Log retry attempt
_logger.LogEventRetry(
    eventId: evt.EventId,
    eventType: evt.GetType().Name,
    subscriptionId: "order-processing",
    attemptNumber: 3,
    maxAttempts: 5);

// Log dead letter
_logger.LogEventDeadLettered(
    eventId: evt.EventId,
    eventType: evt.GetType().Name,
    subscriptionId: "order-processing",
    reason: "Max retry attempts exceeded");

Schema Evolution Logging

// Log schema registration
_logger.LogSchemaRegistered(
    schemaName: "UserRegistered",
    version: 2,
    eventType: "Svrnty.Events.UserRegisteredV2");

// Log event upcast
_logger.LogEventUpcast(
    eventId: evt.EventId,
    schemaName: "UserRegistered",
    fromVersion: 1,
    toVersion: 2);

Cross-Service Logging

// Log external send
_logger.LogEventSentExternal(
    eventId: evt.EventId,
    eventType: evt.GetType().Name,
    exchange: "svrnty.events",
    routingKey: "user.registered");

// Log external receive
_logger.LogEventReceivedExternal(
    eventId: evt.EventId,
    eventType: evt.GetType().Name,
    queueName: "service-b.user-events");

Log Event IDs

All log messages have consistent event IDs for filtering and alerting:

Stream Lifecycle (1000-1999)

  • 1001: Stream created
  • 1002: Stream deleted

Subscription Lifecycle (2000-2999)

  • 2001: Subscription registered
  • 2002: Subscription unregistered
  • 2003: Subscription paused
  • 2004: Subscription resumed

Consumer Lifecycle (3000-3999)

  • 3001: Consumer connected
  • 3002: Consumer disconnected
  • 3003: Consumer offset reset
  • 3004: Consumer lagging
  • 3005: Consumer stalled

Event Publishing (4000-4999)

  • 4001: Event published
  • 4002: Event batch published
  • 4003: Event publish failed

Event Consumption (5000-5999)

  • 5001: Event consumed
  • 5002: Event consumption failed
  • 5003: Event retry
  • 5004: Event dead lettered

Schema Evolution (6000-6999)

  • 6001: Schema registered
  • 6002: Event upcast
  • 6003: Event upcast failed

Exactly-Once Delivery (7000-7999)

  • 7001: Duplicate event skipped
  • 7002: Deduplication cleanup

Cross-Service (8000-8999)

  • 8001: Event sent external
  • 8002: Event received external
  • 8003: Message broker connected
  • 8004: Message broker disconnected

Integration with Logging Providers

Serilog

Log.Logger = new LoggerConfiguration()
    .MinimumLevel.Debug()
    .Enrich.FromLogContext()
    .Enrich.WithProperty("Application", "MyService")
    .WriteTo.Console(
        outputTemplate: "[{Timestamp:HH:mm:ss} {Level:u3}] {Message:lj} {Properties:j}{NewLine}{Exception}")
    .WriteTo.Seq("http://localhost:5341")
    .CreateLogger();

builder.Host.UseSerilog();

Application Insights

builder.Services.AddApplicationInsightsTelemetry();
builder.Logging.AddApplicationInsights();

Elasticsearch

builder.Logging.AddElasticsearchLogger(options =>
{
    options.Url = "http://localhost:9200";
    options.Index = "event-streaming-logs";
});

Correlation ID Best Practices

  1. Always use correlation IDs for event publishing and consumption
  2. Propagate correlation IDs across service boundaries
  3. Use CorrelationContext.Begin() at the start of workflows
  4. Include correlation ID in event metadata for automatic propagation
// Good: Correlation ID propagates through entire workflow
using (CorrelationContext.Begin(command.CorrelationId))
{
    await _commandHandler.HandleAsync(command);
    await _eventPublisher.PublishAsync(evt);
    await _workflowEngine.ExecuteAsync(workflow);
}

// Bad: No correlation context, logs are disconnected
await _commandHandler.HandleAsync(command);
await _eventPublisher.PublishAsync(evt);

Querying Logs

Find all events for a correlation ID

CorrelationId = "abc-123-def"

Find all failed event consumption

EventId = 5002

Find all consumer lag warnings

EventId = 3004 AND Lag > 1000

Find all events for a specific stream

StreamName = "user-events"

Performance

LoggerMessage source generators provide:

  • Zero allocations for log message formatting
  • Compiled delegates instead of reflection
  • ~10x faster than string interpolation
  • Type-safe parameters validated at compile time

See Also