Some checks failed
Docs CI / lint-and-preview (push) Has been cancelled
Policy Lint & Smoke / policy-lint (push) Has been cancelled
Concelier Attestation Tests / attestation-tests (push) Has been cancelled
AOC Guard CI / aoc-guard (push) Has been cancelled
AOC Guard CI / aoc-verify (push) Has been cancelled
- Implemented MigrationCategoryTests to validate migration categorization for startup, release, seed, and data migrations. - Added tests for edge cases, including null, empty, and whitespace migration names. - Created StartupMigrationHostTests to verify the behavior of the migration host with real PostgreSQL instances using Testcontainers. - Included tests for migration execution, schema creation, and handling of pending release migrations. - Added SQL migration files for testing: creating a test table, adding a column, a release migration, and seeding data.
699 lines
20 KiB
Markdown
699 lines
20 KiB
Markdown
# Step 22: Logging & Tracing
|
|
|
|
**Phase 6: Observability & Resilience**
|
|
**Estimated Complexity:** Medium
|
|
**Dependencies:** Step 19 (Microservice Host Builder)
|
|
|
|
---
|
|
|
|
## Overview
|
|
|
|
Structured logging and distributed tracing provide observability across the gateway and microservices. Correlation IDs flow from HTTP requests through the transport layer to microservice handlers, enabling end-to-end request tracking.
|
|
|
|
---
|
|
|
|
## Goals
|
|
|
|
1. Implement structured logging with consistent context
|
|
2. Propagate correlation IDs across all layers
|
|
3. Integrate with OpenTelemetry for distributed tracing
|
|
4. Support log level configuration per component
|
|
5. Provide sensitive data filtering
|
|
|
|
---
|
|
|
|
## Correlation Context
|
|
|
|
```csharp
|
|
namespace StellaOps.Router.Common;
|
|
|
|
/// <summary>
|
|
/// Provides correlation context for request tracking.
|
|
/// </summary>
|
|
public static class CorrelationContext
|
|
{
|
|
private static readonly AsyncLocal<CorrelationData> _current = new();
|
|
|
|
public static CorrelationData Current => _current.Value ?? CorrelationData.Empty;
|
|
|
|
public static IDisposable BeginScope(CorrelationData data)
|
|
{
|
|
var previous = _current.Value;
|
|
_current.Value = data;
|
|
return new CorrelationScope(previous);
|
|
}
|
|
|
|
public static IDisposable BeginScope(string correlationId, string? serviceName = null)
|
|
{
|
|
return BeginScope(new CorrelationData
|
|
{
|
|
CorrelationId = correlationId,
|
|
ServiceName = serviceName ?? Current.ServiceName,
|
|
ParentId = Current.CorrelationId
|
|
});
|
|
}
|
|
|
|
private sealed class CorrelationScope : IDisposable
|
|
{
|
|
private readonly CorrelationData? _previous;
|
|
|
|
public CorrelationScope(CorrelationData? previous)
|
|
{
|
|
_previous = previous;
|
|
}
|
|
|
|
public void Dispose()
|
|
{
|
|
_current.Value = _previous;
|
|
}
|
|
}
|
|
}
|
|
|
|
public sealed class CorrelationData
|
|
{
|
|
public static readonly CorrelationData Empty = new();
|
|
|
|
public string CorrelationId { get; init; } = "";
|
|
public string? ParentId { get; init; }
|
|
public string? ServiceName { get; init; }
|
|
public string? InstanceId { get; init; }
|
|
public string? Method { get; init; }
|
|
public string? Path { get; init; }
|
|
public string? UserId { get; init; }
|
|
public Dictionary<string, string> Extra { get; init; } = new();
|
|
}
|
|
```
|
|
|
|
---
|
|
|
|
## Structured Log Enricher
|
|
|
|
```csharp
|
|
namespace StellaOps.Router.Common;
|
|
|
|
/// <summary>
|
|
/// Enriches log entries with correlation context.
|
|
/// </summary>
|
|
public sealed class CorrelationLogEnricher : ILoggerProvider
|
|
{
|
|
private readonly ILoggerProvider _inner;
|
|
|
|
public CorrelationLogEnricher(ILoggerProvider inner)
|
|
{
|
|
_inner = inner;
|
|
}
|
|
|
|
public ILogger CreateLogger(string categoryName)
|
|
{
|
|
return new CorrelationLogger(_inner.CreateLogger(categoryName));
|
|
}
|
|
|
|
public void Dispose() => _inner.Dispose();
|
|
|
|
private sealed class CorrelationLogger : ILogger
|
|
{
|
|
private readonly ILogger _inner;
|
|
|
|
public CorrelationLogger(ILogger inner)
|
|
{
|
|
_inner = inner;
|
|
}
|
|
|
|
public IDisposable? BeginScope<TState>(TState state) where TState : notnull
|
|
{
|
|
return _inner.BeginScope(state);
|
|
}
|
|
|
|
public bool IsEnabled(LogLevel logLevel) => _inner.IsEnabled(logLevel);
|
|
|
|
public void Log<TState>(
|
|
LogLevel logLevel,
|
|
EventId eventId,
|
|
TState state,
|
|
Exception? exception,
|
|
Func<TState, Exception?, string> formatter)
|
|
{
|
|
var correlation = CorrelationContext.Current;
|
|
|
|
// Create enriched state
|
|
using var scope = _inner.BeginScope(new Dictionary<string, object?>
|
|
{
|
|
["CorrelationId"] = correlation.CorrelationId,
|
|
["ServiceName"] = correlation.ServiceName,
|
|
["InstanceId"] = correlation.InstanceId,
|
|
["Method"] = correlation.Method,
|
|
["Path"] = correlation.Path,
|
|
["UserId"] = correlation.UserId
|
|
});
|
|
|
|
_inner.Log(logLevel, eventId, state, exception, formatter);
|
|
}
|
|
}
|
|
}
|
|
```
|
|
|
|
---
|
|
|
|
## Gateway Request Logging
|
|
|
|
```csharp
|
|
namespace StellaOps.Router.Gateway;
|
|
|
|
/// <summary>
|
|
/// Middleware for request/response logging with correlation.
|
|
/// </summary>
|
|
public sealed class RequestLoggingMiddleware
|
|
{
|
|
private readonly RequestDelegate _next;
|
|
private readonly ILogger<RequestLoggingMiddleware> _logger;
|
|
private readonly RequestLoggingConfig _config;
|
|
|
|
public RequestLoggingMiddleware(
|
|
RequestDelegate next,
|
|
ILogger<RequestLoggingMiddleware> logger,
|
|
IOptions<RequestLoggingConfig> config)
|
|
{
|
|
_next = next;
|
|
_logger = logger;
|
|
_config = config.Value;
|
|
}
|
|
|
|
public async Task InvokeAsync(HttpContext context)
|
|
{
|
|
var correlationId = context.Request.Headers["X-Correlation-ID"].FirstOrDefault()
|
|
?? context.TraceIdentifier;
|
|
|
|
// Set correlation context
|
|
using var scope = CorrelationContext.BeginScope(new CorrelationData
|
|
{
|
|
CorrelationId = correlationId,
|
|
ServiceName = "gateway",
|
|
Method = context.Request.Method,
|
|
Path = context.Request.Path
|
|
});
|
|
|
|
var sw = Stopwatch.StartNew();
|
|
|
|
try
|
|
{
|
|
// Log request
|
|
if (_config.LogRequests)
|
|
{
|
|
LogRequest(context, correlationId);
|
|
}
|
|
|
|
await _next(context);
|
|
|
|
sw.Stop();
|
|
|
|
// Log response
|
|
if (_config.LogResponses)
|
|
{
|
|
LogResponse(context, correlationId, sw.ElapsedMilliseconds);
|
|
}
|
|
}
|
|
catch (Exception ex)
|
|
{
|
|
sw.Stop();
|
|
LogError(context, correlationId, sw.ElapsedMilliseconds, ex);
|
|
throw;
|
|
}
|
|
}
|
|
|
|
private void LogRequest(HttpContext context, string correlationId)
|
|
{
|
|
var request = context.Request;
|
|
|
|
_logger.LogInformation(
|
|
"HTTP {Method} {Path} started | CorrelationId={CorrelationId} ClientIP={ClientIP} UserAgent={UserAgent}",
|
|
request.Method,
|
|
request.Path + request.QueryString,
|
|
correlationId,
|
|
context.Connection.RemoteIpAddress,
|
|
SanitizeHeader(request.Headers.UserAgent));
|
|
}
|
|
|
|
private void LogResponse(HttpContext context, string correlationId, long elapsedMs)
|
|
{
|
|
var level = context.Response.StatusCode >= 500 ? LogLevel.Error
|
|
: context.Response.StatusCode >= 400 ? LogLevel.Warning
|
|
: LogLevel.Information;
|
|
|
|
_logger.Log(
|
|
level,
|
|
"HTTP {Method} {Path} completed {StatusCode} in {ElapsedMs}ms | CorrelationId={CorrelationId}",
|
|
context.Request.Method,
|
|
context.Request.Path,
|
|
context.Response.StatusCode,
|
|
elapsedMs,
|
|
correlationId);
|
|
}
|
|
|
|
private void LogError(HttpContext context, string correlationId, long elapsedMs, Exception ex)
|
|
{
|
|
_logger.LogError(
|
|
ex,
|
|
"HTTP {Method} {Path} failed after {ElapsedMs}ms | CorrelationId={CorrelationId}",
|
|
context.Request.Method,
|
|
context.Request.Path,
|
|
elapsedMs,
|
|
correlationId);
|
|
}
|
|
|
|
private static string SanitizeHeader(StringValues value)
|
|
{
|
|
var str = value.ToString();
|
|
return str.Length > 200 ? str[..200] + "..." : str;
|
|
}
|
|
}
|
|
|
|
public class RequestLoggingConfig
|
|
{
|
|
public bool LogRequests { get; set; } = true;
|
|
public bool LogResponses { get; set; } = true;
|
|
public bool LogHeaders { get; set; } = false;
|
|
public bool LogBody { get; set; } = false;
|
|
public int MaxBodyLogLength { get; set; } = 1000;
|
|
public HashSet<string> SensitiveHeaders { get; set; } = new(StringComparer.OrdinalIgnoreCase)
|
|
{
|
|
"Authorization", "Cookie", "X-API-Key"
|
|
};
|
|
}
|
|
```
|
|
|
|
---
|
|
|
|
## OpenTelemetry Integration
|
|
|
|
```csharp
|
|
namespace StellaOps.Router.Common;
|
|
|
|
/// <summary>
|
|
/// Configures OpenTelemetry tracing for the router.
|
|
/// </summary>
|
|
public static class OpenTelemetryExtensions
|
|
{
|
|
public static IServiceCollection AddStellaTracing(
|
|
this IServiceCollection services,
|
|
IConfiguration configuration)
|
|
{
|
|
var config = configuration.GetSection("Tracing").Get<TracingConfig>()
|
|
?? new TracingConfig();
|
|
|
|
services.AddOpenTelemetry()
|
|
.WithTracing(builder =>
|
|
{
|
|
builder
|
|
.SetResourceBuilder(ResourceBuilder.CreateDefault()
|
|
.AddService(config.ServiceName))
|
|
.AddSource(StellaActivitySource.Name)
|
|
.AddAspNetCoreInstrumentation(options =>
|
|
{
|
|
options.Filter = ctx =>
|
|
!ctx.Request.Path.StartsWithSegments("/health");
|
|
options.RecordException = true;
|
|
})
|
|
.AddHttpClientInstrumentation();
|
|
|
|
// Add exporter based on config
|
|
switch (config.Exporter.ToLower())
|
|
{
|
|
case "jaeger":
|
|
builder.AddJaegerExporter(o =>
|
|
{
|
|
o.AgentHost = config.JaegerHost;
|
|
o.AgentPort = config.JaegerPort;
|
|
});
|
|
break;
|
|
|
|
case "otlp":
|
|
builder.AddOtlpExporter(o =>
|
|
{
|
|
o.Endpoint = new Uri(config.OtlpEndpoint);
|
|
});
|
|
break;
|
|
|
|
case "console":
|
|
builder.AddConsoleExporter();
|
|
break;
|
|
}
|
|
});
|
|
|
|
return services;
|
|
}
|
|
}
|
|
|
|
public static class StellaActivitySource
|
|
{
|
|
public const string Name = "StellaOps.Router";
|
|
|
|
private static readonly ActivitySource _source = new(Name);
|
|
|
|
public static Activity? StartActivity(string name, ActivityKind kind = ActivityKind.Internal)
|
|
{
|
|
return _source.StartActivity(name, kind);
|
|
}
|
|
|
|
public static Activity? StartRequestActivity(string method, string path)
|
|
{
|
|
var activity = _source.StartActivity("HandleRequest", ActivityKind.Server);
|
|
activity?.SetTag("http.method", method);
|
|
activity?.SetTag("http.route", path);
|
|
return activity;
|
|
}
|
|
|
|
public static Activity? StartTransportActivity(string transport, string serviceName)
|
|
{
|
|
var activity = _source.StartActivity("Transport", ActivityKind.Client);
|
|
activity?.SetTag("transport.type", transport);
|
|
activity?.SetTag("service.name", serviceName);
|
|
return activity;
|
|
}
|
|
}
|
|
|
|
public class TracingConfig
|
|
{
|
|
public string ServiceName { get; set; } = "stella-router";
|
|
public string Exporter { get; set; } = "console";
|
|
public string JaegerHost { get; set; } = "localhost";
|
|
public int JaegerPort { get; set; } = 6831;
|
|
public string OtlpEndpoint { get; set; } = "http://localhost:4317";
|
|
public double SampleRate { get; set; } = 1.0;
|
|
}
|
|
```
|
|
|
|
---
|
|
|
|
## Transport Trace Propagation
|
|
|
|
```csharp
|
|
namespace StellaOps.Router.Transport;
|
|
|
|
/// <summary>
|
|
/// Propagates trace context through the transport layer.
|
|
/// </summary>
|
|
public sealed class TracePropagator
|
|
{
|
|
/// <summary>
|
|
/// Injects trace context into request payload.
|
|
/// </summary>
|
|
public void InjectContext(RequestPayload payload)
|
|
{
|
|
var activity = Activity.Current;
|
|
if (activity == null)
|
|
return;
|
|
|
|
var headers = new Dictionary<string, string>(payload.Headers);
|
|
|
|
// Inject W3C Trace Context
|
|
headers["traceparent"] = $"00-{activity.TraceId}-{activity.SpanId}-{(activity.Recorded ? "01" : "00")}";
|
|
|
|
if (!string.IsNullOrEmpty(activity.TraceStateString))
|
|
{
|
|
headers["tracestate"] = activity.TraceStateString;
|
|
}
|
|
|
|
// Create new payload with updated headers
|
|
// (In real implementation, use record with 'with' expression)
|
|
}
|
|
|
|
/// <summary>
|
|
/// Extracts trace context from request payload.
|
|
/// </summary>
|
|
public ActivityContext? ExtractContext(RequestPayload payload)
|
|
{
|
|
if (!payload.Headers.TryGetValue("traceparent", out var traceparent))
|
|
return null;
|
|
|
|
if (ActivityContext.TryParse(traceparent, payload.Headers.GetValueOrDefault("tracestate"), out var ctx))
|
|
{
|
|
return ctx;
|
|
}
|
|
|
|
return null;
|
|
}
|
|
}
|
|
```
|
|
|
|
---
|
|
|
|
## Microservice Logging
|
|
|
|
```csharp
|
|
namespace StellaOps.Microservice;
|
|
|
|
/// <summary>
|
|
/// Request logging for microservice handlers.
|
|
/// </summary>
|
|
public sealed class HandlerLoggingDecorator : IRequestDispatcher
|
|
{
|
|
private readonly IRequestDispatcher _inner;
|
|
private readonly ILogger<HandlerLoggingDecorator> _logger;
|
|
private readonly TracePropagator _propagator;
|
|
|
|
public HandlerLoggingDecorator(
|
|
IRequestDispatcher inner,
|
|
ILogger<HandlerLoggingDecorator> logger,
|
|
TracePropagator propagator)
|
|
{
|
|
_inner = inner;
|
|
_logger = logger;
|
|
_propagator = propagator;
|
|
}
|
|
|
|
public async Task<ResponsePayload> DispatchAsync(
|
|
RequestPayload request,
|
|
CancellationToken cancellationToken)
|
|
{
|
|
// Extract and restore trace context
|
|
var parentContext = _propagator.ExtractContext(request);
|
|
using var activity = StellaActivitySource.StartActivity(
|
|
"HandleRequest",
|
|
ActivityKind.Server,
|
|
parentContext ?? default);
|
|
|
|
activity?.SetTag("http.method", request.Method);
|
|
activity?.SetTag("http.route", request.Path);
|
|
|
|
// Set correlation context
|
|
var correlationId = request.TraceId ?? activity?.TraceId.ToString() ?? Guid.NewGuid().ToString("N");
|
|
using var scope = CorrelationContext.BeginScope(new CorrelationData
|
|
{
|
|
CorrelationId = correlationId,
|
|
Method = request.Method,
|
|
Path = request.Path,
|
|
UserId = request.Claims.GetValueOrDefault("sub")
|
|
});
|
|
|
|
var sw = Stopwatch.StartNew();
|
|
|
|
try
|
|
{
|
|
_logger.LogDebug(
|
|
"Handling {Method} {Path} | CorrelationId={CorrelationId}",
|
|
request.Method, request.Path, correlationId);
|
|
|
|
var response = await _inner.DispatchAsync(request, cancellationToken);
|
|
|
|
sw.Stop();
|
|
activity?.SetTag("http.status_code", response.StatusCode);
|
|
|
|
var level = response.StatusCode >= 500 ? LogLevel.Error
|
|
: response.StatusCode >= 400 ? LogLevel.Warning
|
|
: LogLevel.Debug;
|
|
|
|
_logger.Log(
|
|
level,
|
|
"Completed {Method} {Path} with {StatusCode} in {ElapsedMs}ms | CorrelationId={CorrelationId}",
|
|
request.Method, request.Path, response.StatusCode, sw.ElapsedMilliseconds, correlationId);
|
|
|
|
return response;
|
|
}
|
|
catch (Exception ex)
|
|
{
|
|
sw.Stop();
|
|
activity?.SetStatus(ActivityStatusCode.Error, ex.Message);
|
|
|
|
_logger.LogError(
|
|
ex,
|
|
"Failed {Method} {Path} after {ElapsedMs}ms | CorrelationId={CorrelationId}",
|
|
request.Method, request.Path, sw.ElapsedMilliseconds, correlationId);
|
|
|
|
throw;
|
|
}
|
|
}
|
|
}
|
|
```
|
|
|
|
---
|
|
|
|
## Sensitive Data Filtering
|
|
|
|
```csharp
|
|
namespace StellaOps.Router.Common;
|
|
|
|
/// <summary>
|
|
/// Filters sensitive data from logs.
|
|
/// </summary>
|
|
public sealed class SensitiveDataFilter
|
|
{
|
|
private readonly HashSet<string> _sensitiveFields;
|
|
private readonly Regex _cardNumberRegex;
|
|
private readonly Regex _ssnRegex;
|
|
|
|
public SensitiveDataFilter(IOptions<SensitiveDataConfig> config)
|
|
{
|
|
var cfg = config.Value;
|
|
_sensitiveFields = new HashSet<string>(cfg.SensitiveFields, StringComparer.OrdinalIgnoreCase);
|
|
_cardNumberRegex = new Regex(@"\b\d{4}[\s-]?\d{4}[\s-]?\d{4}[\s-]?\d{4}\b");
|
|
_ssnRegex = new Regex(@"\b\d{3}-\d{2}-\d{4}\b");
|
|
}
|
|
|
|
public string Filter(string input)
|
|
{
|
|
var result = input;
|
|
|
|
// Mask card numbers
|
|
result = _cardNumberRegex.Replace(result, m =>
|
|
m.Value[..4] + "****" + m.Value[^4..]);
|
|
|
|
// Mask SSNs
|
|
result = _ssnRegex.Replace(result, "***-**-****");
|
|
|
|
return result;
|
|
}
|
|
|
|
public Dictionary<string, string> FilterHeaders(IReadOnlyDictionary<string, string> headers)
|
|
{
|
|
return headers.ToDictionary(
|
|
h => h.Key,
|
|
h => _sensitiveFields.Contains(h.Key) ? "[REDACTED]" : h.Value);
|
|
}
|
|
|
|
public object FilterObject(object obj)
|
|
{
|
|
// Deep filter for JSON objects
|
|
var json = JsonSerializer.Serialize(obj);
|
|
var filtered = FilterJsonProperties(json);
|
|
return JsonSerializer.Deserialize<object>(filtered)!;
|
|
}
|
|
|
|
private string FilterJsonProperties(string json)
|
|
{
|
|
var doc = JsonDocument.Parse(json);
|
|
using var stream = new MemoryStream();
|
|
using var writer = new Utf8JsonWriter(stream);
|
|
|
|
FilterElement(doc.RootElement, writer);
|
|
|
|
writer.Flush();
|
|
return Encoding.UTF8.GetString(stream.ToArray());
|
|
}
|
|
|
|
private void FilterElement(JsonElement element, Utf8JsonWriter writer)
|
|
{
|
|
switch (element.ValueKind)
|
|
{
|
|
case JsonValueKind.Object:
|
|
writer.WriteStartObject();
|
|
foreach (var property in element.EnumerateObject())
|
|
{
|
|
writer.WritePropertyName(property.Name);
|
|
if (_sensitiveFields.Contains(property.Name))
|
|
{
|
|
writer.WriteStringValue("[REDACTED]");
|
|
}
|
|
else
|
|
{
|
|
FilterElement(property.Value, writer);
|
|
}
|
|
}
|
|
writer.WriteEndObject();
|
|
break;
|
|
|
|
case JsonValueKind.Array:
|
|
writer.WriteStartArray();
|
|
foreach (var item in element.EnumerateArray())
|
|
{
|
|
FilterElement(item, writer);
|
|
}
|
|
writer.WriteEndArray();
|
|
break;
|
|
|
|
default:
|
|
element.WriteTo(writer);
|
|
break;
|
|
}
|
|
}
|
|
}
|
|
|
|
public class SensitiveDataConfig
|
|
{
|
|
public HashSet<string> SensitiveFields { get; set; } = new(StringComparer.OrdinalIgnoreCase)
|
|
{
|
|
"password", "secret", "token", "apiKey", "api_key",
|
|
"authorization", "creditCard", "credit_card", "ssn",
|
|
"socialSecurityNumber", "social_security_number"
|
|
};
|
|
}
|
|
```
|
|
|
|
---
|
|
|
|
## YAML Configuration
|
|
|
|
```yaml
|
|
Logging:
|
|
LogLevel:
|
|
Default: "Information"
|
|
"StellaOps.Router": "Debug"
|
|
"Microsoft.AspNetCore": "Warning"
|
|
|
|
RequestLogging:
|
|
LogRequests: true
|
|
LogResponses: true
|
|
LogHeaders: false
|
|
LogBody: false
|
|
MaxBodyLogLength: 1000
|
|
SensitiveHeaders:
|
|
- Authorization
|
|
- Cookie
|
|
- X-API-Key
|
|
|
|
Tracing:
|
|
ServiceName: "stella-router"
|
|
Exporter: "otlp"
|
|
OtlpEndpoint: "http://otel-collector:4317"
|
|
SampleRate: 1.0
|
|
|
|
SensitiveData:
|
|
SensitiveFields:
|
|
- password
|
|
- secret
|
|
- token
|
|
- apiKey
|
|
- creditCard
|
|
- ssn
|
|
```
|
|
|
|
---
|
|
|
|
## Deliverables
|
|
|
|
1. `StellaOps.Router.Common/CorrelationContext.cs`
|
|
2. `StellaOps.Router.Common/CorrelationLogEnricher.cs`
|
|
3. `StellaOps.Router.Gateway/RequestLoggingMiddleware.cs`
|
|
4. `StellaOps.Router.Common/OpenTelemetryExtensions.cs`
|
|
5. `StellaOps.Router.Common/StellaActivitySource.cs`
|
|
6. `StellaOps.Router.Transport/TracePropagator.cs`
|
|
7. `StellaOps.Microservice/HandlerLoggingDecorator.cs`
|
|
8. `StellaOps.Router.Common/SensitiveDataFilter.cs`
|
|
9. Correlation propagation tests
|
|
10. Trace context tests
|
|
|
|
---
|
|
|
|
## Next Step
|
|
|
|
Proceed to [Step 23: Metrics & Health Checks](23-Step.md) to implement observability metrics.
|