ILogger in ASP.NET Core — Structured Logging Patterns

Trace:       Verbose detail — execution flow, variable values. Dev only.
Debug:       Diagnostic detail useful during development and troubleshooting.
Information: Normal operation milestones — request received, order processed.
Warning:     Unexpected but recoverable — retry happened, fallback used.
Error:       Operation failed — exception, data not found, external service down.
Critical:    System-level failure — database down, process crashing.

Production minimum level: Information
  Trace and Debug are too verbose and expensive for production.
  Filter by category to enable Debug for specific namespaces only.

// BAD: string interpolation — message is unstructured text, not searchable properties
_logger.LogInformation($"Patient {patient.Id} prescription {prescriptionId} created");
// Log sink receives: "Patient 3f4... prescription 9a2... created"
// Cannot search by PatientId or PrescriptionId independently

// GOOD: message template with named properties
_logger.LogInformation(
    "Prescription {PrescriptionId} created for patient {PatientId} by {UserId}",
    prescriptionId, patientId, userId);
// Log sink receives:
//   Message: "Prescription {PrescriptionId} created for patient {PatientId}..."
//   Properties: { PrescriptionId: "9a2...", PatientId: "3f4...", UserId: "u1..." }
// Query by PatientId alone in Seq, Application Insights, or Kibana

// Constructor injection — preferred
public sealed class PrescriptionService
{
    private readonly ILogger<PrescriptionService> _logger;

    public PrescriptionService(ILogger<PrescriptionService> logger)
        => _logger = logger;

    public async Task<Result> CreateAsync(CreatePrescriptionCommand command, CancellationToken ct)
    {
        _logger.LogInformation(
            "Creating prescription for patient {PatientId}, medication {Medication}",
            command.PatientId, command.MedicationName);

        try
        {
            // ... business logic
            _logger.LogInformation(
                "Prescription {PrescriptionId} created successfully",
                prescriptionId);
            return Result.Success();
        }
        catch (Exception ex)
        {
            _logger.LogError(ex,
                "Failed to create prescription for patient {PatientId}",
                command.PatientId);
            return Result.Failure(DomainErrors.Prescription.CreationFailed);
        }
    }
}

// LogScope: attach contextual properties to all log entries within a scope
using (_logger.BeginScope(new Dictionary<string, object>
{
    ["PatientId"]  = patientId,
    ["RequestId"]  = httpContext.TraceIdentifier,
    ["ClinicianId"] = currentUser.UserId,
}))
{
    // All log entries within this using block include PatientId, RequestId, ClinicianId
    _logger.LogInformation("Starting INR review");
    await ProcessInrAsync(patientId, ct);
    _logger.LogInformation("INR review complete");
}
// These properties are no longer attached after the using block ends

// For hot paths: avoid string allocation on every log call
// The [LoggerMessage] attribute generates a static method at compile time
// No boxing, no string interpolation overhead

public static partial class Log
{
    [LoggerMessage(
        EventId = 1001,
        Level   = LogLevel.Information,
        Message = "Prescription {PrescriptionId} dispensed for patient {PatientId}")]
    public static partial void PrescriptionDispensed(
        this ILogger logger,
        Guid prescriptionId,
        Guid patientId);

    [LoggerMessage(
        EventId = 2001,
        Level   = LogLevel.Error,
        Message = "Failed to dispense prescription {PrescriptionId}: {Reason}")]
    public static partial void PrescriptionDispenseFailed(
        this ILogger logger,
        Guid prescriptionId,
        string reason,
        Exception exception);
}

// Usage — no allocations at all if the log level is filtered out
_logger.PrescriptionDispensed(prescriptionId, patientId);
_logger.PrescriptionDispenseFailed(prescriptionId, ex.Message, ex);

// appsettings.json
{
  "Logging": {
    "LogLevel": {
      "Default":                        "Information",
      "Microsoft.AspNetCore":           "Warning",
      "Microsoft.EntityFrameworkCore":  "Warning",
      "SystemForge.Infrastructure":     "Debug",
      "SystemForge.Domain":             "Information"
    }
  }
}

// Override with environment-specific configuration
// appsettings.Production.json: reduce verbosity
// appsettings.Development.json: increase verbosity for debugging

// Avoid computing expensive values if the log level is filtered out
if (_logger.IsEnabled(LogLevel.Debug))
{
    // Only compute the diagnostic summary if Debug is actually going to be logged
    var diagnosticSummary = await BuildDetailedDiagnosticSummaryAsync(patientId, ct);
    _logger.LogDebug("Patient {PatientId} diagnostic: {Summary}", patientId, diagnosticSummary);
}

// The [LoggerMessage] source generator handles this automatically —
// it skips the entire call without evaluation if the level is filtered out.

// ANTI-PATTERN: Logging and rethrowing adds noise without value
catch (Exception ex)
{
    _logger.LogError(ex, "Error occurred");  // logged here
    throw;  // and again up the stack if the caller also logs
}
// Fix: log once at the top-level handler (middleware/filter), not at every level

// ANTI-PATTERN: Logging sensitive data
_logger.LogInformation("Patient {Mrn} {Name} DOB: {Dob}", mrn, fullName, dateOfBirth);
// PII in logs violates GDPR/HIPAA. Log identifiers (patient ID), not PII.

// ANTI-PATTERN: Using exception.ToString() in the message
_logger.LogError($"Error: {ex.ToString()}");
// Pass exception as first argument — log sinks handle it properly
_logger.LogError(ex, "Error processing prescription {Id}", prescriptionId);

// ANTI-PATTERN: Catching and swallowing exceptions to avoid log noise
catch (Exception) { /* do nothing */ }
// Silent failures are worse than noisy failures.