Start Debugging

Von ILogger-String-Interpolation zu Message-Templates für strukturiertes Logging in .NET 11 migrieren

Eine Schritt-für-Schritt-Anleitung, um $-interpolierte ILogger-Aufrufe in Message-Templates und [LoggerMessage]-generierte Methoden unter .NET 11 zu überführen: was bricht, wie Sie eine Codebasis mit CA2254 durchkämmen, wie Sie den JSON-State prüfen und wie Sie zurückrollen.

Jedes _logger.LogInformation($"Order {orderId} failed for {customerId}") in Ihrer Codebasis wirft genau die beiden Felder weg, die Sie beim nächsten Alarm brauchen werden. Diese Anleitung stellt eine .NET-11-Codebasis (SDK 11.0.100-preview.6, C# 14) von interpolierten Log-Aufrufen auf Message-Templates um und wandelt danach die heißen Pfade in [LoggerMessage]-generierte Methoden. In einem mittelgroßen Service kostet der Template-Durchlauf einen halben Tag weitgehend mechanischer Änderungen, gesteuert von CA2254, und der Durchgang mit dem Source Generator noch einen Tag, wenn Sie ihn sauber machen. Riskant ist daran nichts: die Korrektur ist nicht breaking, jeder Schritt lässt sich einzeln zurücknehmen, und der Gewinn ist, dass Ihr Log-Backend endlich nach OrderId filtern kann statt nach gerenderten Sätzen zu greppen.

Warum Interpolation genau die Daten verliert, die Sie brauchen

Wenn noch nicht entschieden ist, wohin die Logs gehen, klären Sie das zuerst. Strukturierte Protokollierung mit Serilog und Seq und OpenTelemetry mit .NET 11 und einem kostenlosen Backend setzen beide voraus, dass die Templates aus dieser Anleitung bereits korrekt sind.

Was die beiden Formen tatsächlich erzeugen

Das ist die kleinste Reproduktion. Gleiche Absicht, zwei Aufrufstile, durch den JsonConsole-Formatter unter .NET 11.

// .NET 11 preview 6, C# 14
int orderId = 4711;
string customerId = "acme-inc";

// Interpolated: the template IS the rendered sentence.
_logger.LogInformation($"Order {orderId} failed for {customerId}");

// Message template: placeholders survive as named properties.
_logger.LogInformation("Order {OrderId} failed for {CustomerId}", orderId, customerId);

Der erste Aufruf erzeugt einen State mit einem einzigen nutzlosen Eintrag:

{
  "LogLevel": "Information",
  "Message": "Order 4711 failed for acme-inc",
  "State": {
    "Message": "Order 4711 failed for acme-inc",
    "{OriginalFormat}": "Order 4711 failed for acme-inc"
  }
}

Der zweite Aufruf erzeugt die Felder:

{
  "LogLevel": "Information",
  "Message": "Order 4711 failed for acme-inc",
  "State": {
    "Message": "Order 4711 failed for acme-inc",
    "OrderId": 4711,
    "CustomerId": "acme-inc",
    "{OriginalFormat}": "Order {OrderId} failed for {CustomerId}"
  }
}

Die gerenderte Message ist identisch. Alles, was das Log abfragbar macht, steckt im Unterschied.

Was bricht

BereichÄnderungSchweregrad
Aufrufstellen mit $"..."Müssen zu einem konstanten Template plus Argumenten werdenhoch (Menge, nicht Risiko)
Log-Abfragen und DashboardsGespeicherte Suchen auf gerendertem Text laufen weiter; neue Filter auf Eigenschaften müssen gebaut werdenmittel
Alarmregeln auf {OriginalFormat}Der Template-String ändert sich, exakte Treffer auf den alten gerenderten Text greifen nicht mehrmittel
String-Verkettung in Templates"Order " + id + " failed" ist derselbe Defekt und wird von derselben Regel erkanntmittel
Umstellung auf [LoggerMessage]Enthaltende Klasse und Methode müssen partial werden; die Methode muss void zurückgebenniedrig
EventId-WerteDoppelte IDs innerhalb der Assembly erzeugen Generator-Warnungenniedrig
Serilog-@-DestructuringDie Semantik von {@Order} unterscheidet sich von der State-Enumeration in Microsoft.Extensions.Loggingniedrig

Nichts davon ist ein Breaking Change zur Laufzeit. Die Roslyn-Regel, die den Durchlauf steuert, CA2254, ist ausdrücklich als nicht breaking dokumentiert.

Checkliste vorab

Migrationsschritte

Die Reihenfolge zählt: erst den Analyzer laut werden lassen, dann alles beheben, was er findet, und erst danach den Source Generator auf den Pfaden einsetzen, wo Allokation tatsächlich etwas kostet.

  1. CA2254 zu einem Build-Fehler machen. Tragen Sie die Regel zunächst als warning in .editorconfig ein, um den Umfang zu sehen, und heben Sie sie auf error, sobald die Zahl null erreicht. Prüfung: dotnet build meldet beim ersten Lauf eine CA2254-Anzahl größer null.
  2. Interpolierte und verkettete Aufrufe in Message-Templates umwandeln. Ziehen Sie jeden Wert aus dem String heraus und übergeben Sie ihn als Argument, mit einem Platzhalternamen in PascalCase. Prüfung: dotnet build meldet null CA2254-Diagnosen.
  3. Argumentreihenfolge korrigieren, denn die Bindung ist positionsbasiert. LoggerExtensions bindet Argumente von links nach rechts an Platzhalter, nicht über Namen. Prüfung: Anwendung starten und prüfen, dass jede Eigenschaft im JSON-State den Wert enthält, den ihr Name verspricht.
  4. [LoggerMessage]-Methoden für heiße Pfade ergänzen. Wandeln Sie Log-Aufrufe pro Anfrage und pro Element in partial Methoden einer partial Klasse um, damit das Template nur einmal zur Kompilierzeit geparst wird. Prüfung: dotnet build ist sauber und die generierte Datei erscheint unter obj/**/Microsoft.Extensions.Logging.Generators/.
  5. Pro Nachricht eine stabile EventId vergeben und eindeutig halten. Prüfung: keine SYSLIB-Warnungen zu doppelten Event-IDs im Build-Log.
  6. SkipEnabledCheck plus manuelle Absicherung verwenden, wo die Auswertung der Argumente teuer ist. Prüfung: Kategorie auf Information setzen und prüfen, dass der teure Aufruf nicht läuft.
  7. Objekte mit [LogProperties] statt ToString() aufklappen. Prüfung: die öffentlichen Eigenschaften des Objekts erscheinen als einzelne Einträge im Log-State, nicht als ein einziger flacher String.

1. CA2254 zu einem Build-Fehler machen

CA2254 ist ab .NET 10 standardmäßig als Vorschlag aktiviert, was bedeutet, dass die Regel in CI unsichtbar ist. Stufen Sie sie hoch:

# .editorconfig -- .NET 11, analyzers at latest
[*.{cs,vb}]

# CA2254: Template should be a static expression
dotnet_diagnostic.CA2254.severity = warning

Kompilieren und zählen, womit Sie es zu tun haben:

dotnet build -warnaserror:CA2254 --no-incremental

Aktivieren Sie CA1848 noch nicht. Diese Regel schlägt bei jedem LogInformation-Aufruf der Codebasis an, auch bei den korrekten, und begräbt das Signal von CA2254. Sie kommt in Schritt 4 zurück.

2. Auf Message-Templates umstellen

Die mechanische Umformung in drei häufigen Ausprägungen:

// .NET 11, C# 14 -- before
_logger.LogInformation($"Order {order.Id} failed for {order.CustomerId}");
_logger.LogWarning("Retry " + attempt + " of " + maxAttempts);
_logger.LogError(ex, $"Import of {file.Name} aborted after {sw.ElapsedMilliseconds} ms");

// after
_logger.LogInformation("Order {OrderId} failed for {CustomerId}", order.Id, order.CustomerId);
_logger.LogWarning("Retry {Attempt} of {MaxAttempts}", attempt, maxAttempts);
_logger.LogError(ex, "Import of {FileName} aborted after {ElapsedMs} ms", file.Name, sw.ElapsedMilliseconds);

Drei Namensregeln, die sich später auszahlen:

3. Die Argumentbindung ist positionsbasiert, nicht namensbasiert

Das ist der eine Fehler, den der Durchlauf einschleppen kann, und CA2254 fängt ihn nicht:

// .NET 11 -- compiles, no analyzer warning, WRONG
_logger.LogInformation("Order {OrderId} for {CustomerId}", customerId, orderId);

Microsoft.Extensions.Logging ordnet Platzhalter den Argumenten der Reihe nach zu. Die Namen sind Beschriftungen für die entstehenden Eigenschaften, kein Bindungsschlüssel. Die Log-Zeile rendert die Kunden-ID unter OrderId, und niemand merkt es, bis drei Wochen später eine Abfrage Unsinn liefert. Lesen Sie jede umgestellte Zeile einmal mit genau diesem Fehlerbild im Kopf, und stellen Sie lieber eine ganze Methode auf einmal um, statt das Ergebnis eines massenhaften Suchen-und-Ersetzens zu übernehmen.

Der [LoggerMessage]-Generator aus Schritt 4 hat dieses Problem nicht: Er ordnet Template-Platzhalter den Parameternamen ohne Beachtung der Groß- und Kleinschreibung zu, die Parameterreihenfolge ist dort also irrelevant.

4. [LoggerMessage] auf den heißen Pfaden ergänzen

Message-Templates haben die Struktur repariert. Die Kosten pro Aufruf haben sie nicht repariert: LoggerExtensions.LogInformation boxt Werttypen weiterhin in object, alloziert ein params object?[] und parst das Template bei jedem Aufruf neu. Der [LoggerMessage] Source Generator entfernt alle drei Punkte, indem er zur Kompilierzeit einen stark typisierten LoggerMessage.Define-Wrapper erzeugt.

// .NET 11 preview 6, C# 14
using Microsoft.Extensions.Logging;

public partial class OrderProcessor(ILogger<OrderProcessor> logger, OrderPipeline pipeline)
{
    public async Task ProcessAsync(Order order, CancellationToken ct)
    {
        try
        {
            await pipeline.RunAsync(order, ct);
            OrderProcessed(order.Id, order.CustomerId);
        }
        catch (PaymentDeclinedException ex)
        {
            OrderFailed(ex, order.Id, order.CustomerId);
        }
    }

    [LoggerMessage(
        EventId = 1001,
        Level = LogLevel.Information,
        Message = "Order {OrderId} processed for {CustomerId}")]
    private partial void OrderProcessed(int orderId, string customerId);

    [LoggerMessage(
        EventId = 1002,
        Level = LogLevel.Warning,
        Message = "Order {OrderId} failed for {CustomerId}")]
    private partial void OrderFailed(Exception ex, int orderId, string customerId);
}

Seit .NET 9 liest der Generator den ILogger auch aus einem Primary-Constructor-Parameter, deshalb hat das Beispiel oben kein explizites _logger-Feld. Existieren Feld und Primary-Constructor-Parameter gleichzeitig, gewinnt das Feld.

Die Einschränkungen, die man sich merken sollte, laut der Dokumentation zur Source-Generierung: Methoden müssen partial sein und void zurückgeben, weder Methoden- noch Parameternamen dürfen mit einem Unterstrich beginnen, und Parameter dürfen weder params, scoped noch out verwenden und keine ref struct-Typen sein. Statische Methoden brauchen den ILogger als Parameter; mit this werden daraus Erweiterungsmethoden.

Schalten Sie jetzt CA1848 für die umgestellten Projekte ein, eng begrenzt, damit es den Rest nicht überflutet:

# .editorconfig, in the hot-path project folder only
[*.cs]
# CA1848: Use the LoggerMessage delegates
dotnet_diagnostic.CA1848.severity = warning

CA1848 ist auch in .NET 10 und neuer standardmäßig nicht aktiviert und bewusst aggressiv: Sie markiert jeden Aufruf im Stil von LogInformation. Aktivieren Sie sie pro Projekt, nicht solutionweit, sofern Sie nicht wirklich jede Nachricht generieren lassen wollen.

5. Event-IDs stabil und eindeutig halten

EventId ist die stabile Identität einer Log-Nachricht. Sie überlebt Umformulierungen des Templates, was sie zum richtigen Anker für Alarmregeln macht. Legen Sie die IDs pro Assembly an einer Stelle ab, damit Kollisionen auffallen:

// .NET 11 -- one file, one range per subsystem
internal static class LogEvents
{
    public const int OrderProcessed = 1001;
    public const int OrderFailed    = 1002;
    public const int PaymentRetried = 1003;
}

Der Generator warnt bei doppelten Event-IDs innerhalb einer Klasse. Klassenübergreifend warnt er nicht, die Konstantendatei leistet also echte Arbeit.

6. SkipEnabledCheck für teure Argumente

Standardmäßig ruft die generierte Methode zuerst ILogger.IsEnabled auf, ein deaktivierter Level kostet also einen virtuellen Aufruf. Was sie nicht kann: den Aufrufer davon abhalten, die Argumente zu berechnen. Wenn ein Argument teuer ist, ziehen Sie die Abfrage nach oben:

// .NET 11, C# 14
[LoggerMessage(
    EventId = 2001,
    Level = LogLevel.Debug,
    Message = "Request body: {Body}",
    SkipEnabledCheck = true)]
private partial void RequestBody(string body);

// call site
if (logger.IsEnabled(LogLevel.Debug))
{
    RequestBody(await SerializeAsync(request, ct));  // only runs when Debug is on
}

Das ist das Muster, das den Durchsatz zurückholt, den interpolierte LogDebug-Aufrufe still gekostet haben.

7. Objekte mit [LogProperties] aufklappen

Message = "Processing {Order}" mit einem Order-Parameter liefert eine einzige Eigenschaft mit der ToString()-Ausgabe. Um die Felder des Objekts als getrennte Eigenschaften zu bekommen, fügen Sie Microsoft.Extensions.Telemetry.Abstractions hinzu und annotieren den Parameter:

// .NET 11, Microsoft.Extensions.Telemetry.Abstractions
[LoggerMessage(
    EventId = 1004,
    Level = LogLevel.Information,
    Message = "Processing order")]
private partial void ProcessingOrder([LogProperties] Order order);

Jede öffentliche Eigenschaft von Order landet als order.Id, order.CustomerId und so weiter im Log-State. Dasselbe Paket ermöglicht die Redaktion klassifizierter Parameter, und das ist die richtige Antwort, wenn jemand ein Request-Objekt mit einer E-Mail-Adresse protokolliert haben will.

Verifikation

Arbeiten Sie diese Liste nach jeder Phase ab, nicht einmal am Ende:

Rollback-Plan

Jeder Schritt lässt sich einzeln mit git revert zurücknehmen, und kein Schritt ändert eine öffentliche API oder ein Wire-Format. Ein Vorbehalt gehört laut gesagt: Sobald Ihr Log-Backend die neuen Eigenschaftsnamen indiziert, brechen darauf gebaute Dashboards und Alarme, wenn Sie den Code zurücknehmen. Erst den Code zurückrollen, dann die Dashboards, und beide Änderungen in getrennten Commits halten, damit die Reihenfolge verfügbar bleibt.

Die höhere Severity in .editorconfig lohnt sich auch dann, wenn Sie die Codeänderungen zurücknehmen. CA2254 auf warning zu belassen verhindert, dass während Ihrer Entscheidung neue interpolierte Aufrufe hinzukommen.

Stolpersteine aus der Praxis

Geschweifte Klammern in Daten werfen eine FormatException. Die interpolierte Form hat einen Fehlerfall, den die meisten Teams zuerst in Produktion kennenlernen. Microsoft.Extensions.Logging behandelt das message-Argument als Formatstring und schickt es durch LogValuesFormatter, der {Name} zu {0} umschreibt und string.Format aufruft. Enthält Ihr interpoliertes Ergebnis Klammern, etwa weil Sie ein JSON-Payload protokolliert haben, sieht der Formatter Platzhalter ohne passende Argumente und wirft (aspnet/Logging#351 ist der kanonische Report). Message-Templates sind immun: Das JSON ist ein Argument und nie Teil des Formatstrings.

// .NET 11 -- throws FormatException at runtime when json contains { }
_logger.LogInformation($"Response: {json}");

// safe
_logger.LogInformation("Response: {Json}", json);

Serilogs {@Property} ist kein Feature von Microsoft.Extensions.Logging. Unter Serilog zerlegt {@Order} das Objekt in einen strukturierten Wert. Der [LoggerMessage]-Generator akzeptiert das Template, aber das @ ist eine Serilog-Konvention, umgesetzt von Serilog.Extensions.Logging. Nehmen Sie nicht an, dass es bei einem einfachen OTLP- oder Console-Provider irgendetwas bewirkt. Nutzen Sie [LogProperties], wenn Sie providerunabhängiges Aufklappen wollen.

Tests, die auf Log-Text prüfen. Assert.Contains("Order 4711 failed", sink.Messages) besteht die Migration unverändert, weil sich die gerenderte Nachricht nicht ändert. Das ist eine Falle: Sie können die Codebasis umstellen, ohne dass Ihre Tests je belegen, dass die Eigenschaften existieren. Ergänzen Sie pro Subsystem mindestens einen Test, der auf den State-Schlüssel prüft.

Die Logs von EF Core selbst sind bereits als Template formuliert. Bitte nicht “reparieren”. Wenn Sie lesbares SQL vom Provider wollen, ist das von EF Core 11 erzeugte SQL zu protokollieren ein Konfigurationsproblem, kein Problem der Aufrufstelle.

Eine Backend-Migration ist eine andere Aufgabe. Aufrufstellen umzustellen verschiebt keine Logs. Wenn OTLP das Ziel ist, machen Sie zuerst diese Migration, damit die Templates stimmen, und folgen Sie danach dem Wechsel von Serilog zu OpenTelemetry-Logging. Beides gleichzeitig zu tun heißt, dass Sie nicht sagen können, welche Änderung ein Dashboard zerstört hat.

Quellen

Comments

Sign in with GitHub to comment. Reactions and replies thread back to the comments repo.

< Zurück