Add Observability

Add Observability Skill

Add metrics, structured logging, and distributed tracing to NovaTune services.

Project Context

• Metrics: Custom metrics via System.Diagnostics.Metrics
• Logging: Serilog with structured JSON output
• Tracing: OpenTelemetry via Aspire ServiceDefaults
• Location: src/NovaTuneApp/NovaTuneApp.ApiService/Infrastructure/Observability/

Steps

1. Create Metrics Class

Location: src/NovaTuneApp/NovaTuneApp.ApiService/Infrastructure/Observability/NovaTuneMetrics.cs

using System.Diagnostics.Metrics;

namespace NovaTuneApp.ApiService.Infrastructure.Observability;

/// <summary>
/// Custom metrics for NovaTune track management.
/// </summary>
public sealed class NovaTuneMetrics
{
    public const string MeterName = "NovaTune.ApiService";

    private readonly Counter<long> _trackListRequestsTotal;
    private readonly Histogram<double> _trackListDurationMs;
    private readonly Counter<long> _trackGetRequestsTotal;
    private readonly Counter<long> _trackUpdateRequestsTotal;
    private readonly Counter<long> _trackDeleteRequestsTotal;
    private readonly Counter<long> _trackRestoreRequestsTotal;
    private readonly Counter<long> _trackSoftDeletionsTotal;
    private readonly Counter<long> _trackPhysicalDeletionsTotal;
    private readonly Histogram<double> _trackPhysicalDeletionDurationMs;
    private readonly Counter<long> _storageFreedBytesTotal;

    public NovaTuneMetrics(IMeterFactory meterFactory)
    {
        var meter = meterFactory.Create(MeterName);

        _trackListRequestsTotal = meter.CreateCounter<long>(
            "track_list_requests_total",
            unit: "{requests}",
            description: "Total track list requests");

        _trackListDurationMs = meter.CreateHistogram<double>(
            "track_list_request_duration_ms",
            unit: "ms",
            description: "Track list request duration in milliseconds");

        _trackGetRequestsTotal = meter.CreateCounter<long>(
            "track_get_requests_total",
            unit: "{requests}",
            description: "Total track get requests");

        _trackUpdateRequestsTotal = meter.CreateCounter<long>(
            "track_update_requests_total",
            unit: "{requests}",
            description: "Total track update requests");

        _trackDeleteRequestsTotal = meter.CreateCounter<long>(
            "track_delete_requests_total",
            unit: "{requests}",
            description: "Total track delete requests");

        _trackRestoreRequestsTotal = meter.CreateCounter<long>(
            "track_restore_requests_total",
            unit: "{requests}",
            description: "Total track restore requests");

        _trackSoftDeletionsTotal = meter.CreateCounter<long>(
            "track_soft_deletions_total",
            unit: "{tracks}",
            description: "Total tracks soft-deleted");

        _trackPhysicalDeletionsTotal = meter.CreateCounter<long>(
            "track_physical_deletions_total",
            unit: "{tracks}",
            description: "Total tracks physically deleted");

        _trackPhysicalDeletionDurationMs = meter.CreateHistogram<double>(
            "track_physical_deletion_duration_ms",
            unit: "ms",
            description: "Physical deletion duration in milliseconds");

        _storageFreedBytesTotal = meter.CreateCounter<long>(
            "storage_freed_bytes_total",
            unit: "By",
            description: "Total storage bytes freed by physical deletions");
    }

    public void RecordTrackListRequest(string status)
        => _trackListRequestsTotal.Add(1, new KeyValuePair<string, object?>("status", status));

    public void RecordTrackListDuration(double durationMs)
        => _trackListDurationMs.Record(durationMs);

    public void RecordTrackGetRequest(string status)
        => _trackGetRequestsTotal.Add(1, new KeyValuePair<string, object?>("status", status));

    public void RecordTrackUpdateRequest(string status)
        => _trackUpdateRequestsTotal.Add(1, new KeyValuePair<string, object?>("status", status));

    public void RecordTrackDeleteRequest(string status)
        => _trackDeleteRequestsTotal.Add(1, new KeyValuePair<string, object?>("status", status));

    public void RecordTrackRestoreRequest(string status)
        => _trackRestoreRequestsTotal.Add(1, new KeyValuePair<string, object?>("status", status));

    public void RecordSoftDeletion()
        => _trackSoftDeletionsTotal.Add(1);

    public void RecordPhysicalDeletion(string status)
        => _trackPhysicalDeletionsTotal.Add(1, new KeyValuePair<string, object?>("status", status));

    public void RecordPhysicalDeletionDuration(double durationMs)
        => _trackPhysicalDeletionDurationMs.Record(durationMs);

    public void RecordStorageFreed(long bytes)
        => _storageFreedBytesTotal.Add(bytes);
}

2. Register Metrics in Program.cs

// Register metrics
builder.Services.AddSingleton<NovaTuneMetrics>();

// Configure OpenTelemetry to export custom metrics
builder.Services.AddOpenTelemetry()
    .WithMetrics(metrics =>
    {
        metrics.AddMeter(NovaTuneMetrics.MeterName);
    });

3. Use Metrics in Services

public class TrackManagementService : ITrackManagementService
{
    private readonly NovaTuneMetrics _metrics;
    private readonly ILogger<TrackManagementService> _logger;

    public TrackManagementService(
        NovaTuneMetrics metrics,
        ILogger<TrackManagementService> logger)
    {
        _metrics = metrics;
        _logger = logger;
    }

    public async Task<PagedResult<TrackListItem>> ListTracksAsync(
        string userId,
        TrackListQuery query,
        CancellationToken ct)
    {
        var stopwatch = Stopwatch.StartNew();
        try
        {
            var result = await DoListTracksAsync(userId, query, ct);
            _metrics.RecordTrackListRequest("success");
            return result;
        }
        catch (Exception)
        {
            _metrics.RecordTrackListRequest("error");
            throw;
        }
        finally
        {
            _metrics.RecordTrackListDuration(stopwatch.Elapsed.TotalMilliseconds);
        }
    }
}

4. Configure Structured Logging

Location: Program.cs or service setup

using Serilog;
using Serilog.Events;
using Serilog.Formatting.Compact;

// Bootstrap logger (before builder)
Log.Logger = new LoggerConfiguration()
    .MinimumLevel.Override("Microsoft", LogEventLevel.Warning)
    .Enrich.FromLogContext()
    .WriteTo.Console(new RenderedCompactJsonFormatter())
    .CreateBootstrapLogger();

// Full configuration (in builder)
builder.Services.AddSerilog((services, configuration) => configuration
    .ReadFrom.Configuration(builder.Configuration)
    .ReadFrom.Services(services)
    .MinimumLevel.Information()
    .MinimumLevel.Override("Microsoft", LogEventLevel.Warning)
    .MinimumLevel.Override("Microsoft.AspNetCore.Hosting", LogEventLevel.Warning)
    .MinimumLevel.Override("Microsoft.AspNetCore.Routing", LogEventLevel.Warning)
    .Enrich.FromLogContext()
    .Enrich.WithEnvironmentName()
    .Enrich.WithMachineName()
    .Enrich.WithProperty("Service", "NovaTune.ApiService")
    .WriteTo.Console(new RenderedCompactJsonFormatter()));

5. Implement Structured Logging

// Good: Structured with semantic properties
_logger.LogInformation(
    "Track {TrackId} soft-deleted for user {UserId}, scheduled deletion at {ScheduledAt}",
    trackId,
    userId,
    scheduledDeletionAt);

// Good: Using scopes for correlation
using (_logger.BeginScope(new Dictionary<string, object>
{
    ["CorrelationId"] = correlationId,
    ["TrackId"] = trackId
}))
{
    _logger.LogInformation("Starting track deletion process");
    // ... operations
    _logger.LogInformation("Track deletion completed successfully");
}

// Good: Different levels for different scenarios
_logger.LogDebug("Track list requested: {Search}, {Status}, {Limit}", search, status, limit);
_logger.LogInformation("Track {TrackId} updated by user {UserId}", trackId, userId);
_logger.LogWarning("Access denied: User {UserId} attempted to access track {TrackId} owned by {OwnerId}",
    userId, trackId, ownerId);
_logger.LogError(ex, "Failed to physically delete track {TrackId}", trackId);

6. Add Distributed Tracing

using System.Diagnostics;

public class TrackManagementService : ITrackManagementService
{
    private static readonly ActivitySource ActivitySource = new("NovaTune.TrackManagement");

    public async Task DeleteTrackAsync(string trackId, string userId, CancellationToken ct)
    {
        using var activity = ActivitySource.StartActivity("track.delete");
        activity?.SetTag("track.id", trackId);
        activity?.SetTag("user.id", userId);

        try
        {
            // Step 1: Update status
            using (var dbActivity = ActivitySource.StartActivity("db.update_status"))
            {
                await UpdateStatusAsync(trackId, ct);
            }

            // Step 2: Write outbox
            using (var outboxActivity = ActivitySource.StartActivity("outbox.write"))
            {
                await WriteOutboxAsync(trackId, ct);
            }

            // Step 3: Invalidate cache
            using (var cacheActivity = ActivitySource.StartActivity("cache.invalidate"))
            {
                await InvalidateCacheAsync(trackId, ct);
            }

            activity?.SetStatus(ActivityStatusCode.Ok);
        }
        catch (Exception ex)
        {
            activity?.SetStatus(ActivityStatusCode.Error, ex.Message);
            activity?.RecordException(ex);
            throw;
        }
    }
}

7. Register Tracing in ServiceDefaults

The ServiceDefaults project configures OpenTelemetry tracing:

// In AddServiceDefaults extension
builder.Services.AddOpenTelemetry()
    .WithTracing(tracing =>
    {
        tracing
            .AddSource("NovaTune.TrackManagement")
            .AddSource("NovaTune.Streaming")
            .AddAspNetCoreInstrumentation()
            .AddHttpClientInstrumentation()
            .AddRavenDBInstrumentation();
    });

Logging Guidelines

Redaction (NF-4.5)

Never log sensitive data:

// BAD - Don't log object keys
_logger.LogInformation("Deleting object {ObjectKey}", objectKey);

// GOOD - Log identifiers only
_logger.LogInformation("Deleting storage objects for track {TrackId}", trackId);

Metrics Summary

Testing Observability

[Fact]
public void Metrics_Should_RecordTrackListRequest()
{
    // Arrange
    var meterFactory = new TestMeterFactory();
    var metrics = new NovaTuneMetrics(meterFactory);

    // Act
    metrics.RecordTrackListRequest("success");

    // Assert
    var measurements = meterFactory.GetMeasurements("track_list_requests_total");
    measurements.Should().ContainSingle()
        .Which.Value.Should().Be(1);
}