Code mithilfe von global eindeutigen Nachrichten-IDs auffindbar machen

Ein allgemeines Muster zum Auffinden eines Fehlers folgt diesem Skript:

1. Beachten Sie Verrücktheit, zum Beispiel keine Ausgabe oder ein hängendes Programm.
2. Suchen Sie die relevante Meldung in der Protokoll- oder Programmausgabe, z. B. "Foo konnte nicht gefunden werden". (Das Folgende ist nur relevant, wenn dies der Pfad ist, auf dem der Fehler gefunden wurde. Wenn ein Stack-Trace oder andere Debugging-Informationen verfügbar sind, ist das eine andere Geschichte.)
3. Suchen Sie den Code, in dem die Nachricht gedruckt wird.
4. Debuggen Sie den Code zwischen der ersten Stelle, an der Foo das Bild eingibt (oder eingeben sollte), und der Stelle, an der die Nachricht gedruckt wird.

In diesem dritten Schritt kommt der Debugging-Prozess häufig zum Erliegen, da der Code an vielen Stellen "Foo nicht gefunden" (oder eine Zeichenfolge mit Vorlagen Could not find {name}) enthält. Tatsächlich hat mir ein Rechtschreibfehler mehrmals geholfen, den tatsächlichen Standort viel schneller zu finden, als ich es sonst getan hätte. Dadurch wurde die Nachricht systemweit und häufig weltweit eindeutig, was zu einem sofortigen Treffer in einer relevanten Suchmaschine führte.

Die offensichtliche Schlussfolgerung daraus ist, dass wir global eindeutige Nachrichten-IDs im Code verwenden, diese als Teil der Nachrichtenzeichenfolge fest codieren und möglicherweise überprüfen sollten, dass nur ein Vorkommen jeder ID in der Codebasis vorhanden ist. Was hält diese Community im Hinblick auf die Wartbarkeit für die wichtigsten Vor- und Nachteile dieses Ansatzes und wie würden Sie dies implementieren oder auf andere Weise sicherstellen, dass die Implementierung niemals erforderlich wird (vorausgesetzt, die Software weist immer Fehler auf)?

Insgesamt ist dies eine gültige und wertvolle Strategie. Hier sind einige Gedanken.

Diese Strategie wird auch als "Telemetrie" bezeichnet. Wenn alle diese Informationen kombiniert werden, können sie die Ausführungsablaufverfolgung "triangulieren" und es einem Ratgeber ermöglichen, einen Eindruck davon zu gewinnen, was der Benutzer / die Anwendung zu erreichen versucht und was tatsächlich passiert ist .

Einige wesentliche Daten, die gesammelt werden müssen (die wir alle kennen), sind:

• Position des Codes, dh Aufrufstapel und ungefähre Codezeile
  • "Ungefähre Codezeile" wird nicht benötigt, wenn Funktionen in angemessen kleine Einheiten zerlegt werden.
• Alle Daten, die für den Erfolg / Misserfolg der Funktion relevant sind
• Ein "Befehl" auf hoher Ebene, mit dem genau festgelegt werden kann, was der Benutzer / externe Agent / API-Benutzer erreichen möchte.
  • Die Idee ist, dass eine Software Befehle von irgendwoher akzeptiert und verarbeitet.
  • Während dieses Vorgangs haben möglicherweise Dutzende bis Hunderte bis Tausende von Funktionsaufrufen stattgefunden.
  • Wir möchten, dass jede während dieses Prozesses erzeugte Telemetrie bis zum Befehl auf höchster Ebene zurückverfolgt werden kann, der diesen Prozess auslöst.
  • Bei webbasierten Systemen wären die ursprüngliche HTTP-Anforderung und ihre Daten ein Beispiel für solche "Informationen über Anforderungen auf hoher Ebene".
  • Für GUI-Systeme würde der Benutzer, der auf etwas klickt, dieser Beschreibung entsprechen.

Häufig scheitern herkömmliche Protokollierungsansätze daran, dass eine Protokollnachricht auf niedriger Ebene nicht zum Befehl auf höchster Ebene zurückverfolgt werden kann, der sie auslöst. Ein Stack-Trace erfasst nur die Namen der übergeordneten Funktionen, mit denen der Befehl auf höchster Ebene ausgeführt wurde, und nicht die Details (Daten), die manchmal zur Charakterisierung dieses Befehls erforderlich sind.

Normalerweise wurde keine Software geschrieben, um diese Art von Rückverfolgbarkeitsanforderungen zu implementieren. Dies erschwert das Korrelieren der Nachricht auf niedriger Ebene mit dem Befehl auf hoher Ebene. Das Problem ist besonders schlimmer bei Systemen mit mehreren Threads, bei denen sich viele Anforderungen und Antworten überlappen können und die Verarbeitung möglicherweise auf einen anderen Thread als den ursprünglichen Thread für den Empfang von Anforderungen verlagert wird.

Um den größtmöglichen Nutzen aus der Telemetrie zu ziehen, müssen Änderungen an der gesamten Softwarearchitektur vorgenommen werden. Die meisten Schnittstellen und Funktionsaufrufe müssen geändert werden, um ein "Tracer" -Argument zu akzeptieren und weiterzugeben.

Sogar Dienstprogrammfunktionen müssen ein "Tracer" -Argument hinzufügen, damit die Protokollnachricht, falls dies fehlschlägt, mit einem bestimmten übergeordneten Befehl korreliert werden kann.

Ein weiterer Fehler, der die Telemetrieverfolgung erschwert, sind fehlende Objektreferenzen (Nullzeiger oder Referenzen). Wenn wichtige Daten fehlen, kann es unmöglich sein, irgendetwas Nützliches für den Fehler zu melden.

In Bezug auf das Schreiben der Protokollnachrichten:

• Einige Softwareprojekte erfordern möglicherweise eine Lokalisierung (Übersetzung in eine Fremdsprache), auch für Protokollnachrichten, die nur für Administratoren bestimmt sind.
• Einige Softwareprojekte benötigen möglicherweise eine klare Trennung zwischen vertraulichen und nicht vertraulichen Daten, auch zum Zwecke der Protokollierung, und Administratoren haben keine Chance, bestimmte vertrauliche Daten versehentlich zu sehen.
• Versuchen Sie nicht, die Fehlermeldung zu verschleiern. Das würde das Vertrauen der Kunden untergraben. Die Administratoren der Kunden erwarten, dass sie diese Protokolle lesen und verstehen. Machen Sie ihnen nicht das Gefühl, dass es ein proprietäres Geheimnis gibt, das den Administratoren der Kunden verborgen bleiben muss.
• Erwarten Sie, dass Kunden ein Stück Telemetrieprotokoll mitbringen und Ihre Mitarbeiter des technischen Supports grillen. Sie erwarten es zu wissen. Wenden Sie sich an Ihren technischen Support, um das Telemetrieprotokoll richtig zu erklären.

Stellen Sie sich vor, Sie haben eine einfache Hilfsprogrammfunktion, die an Hunderten von Stellen in Ihrem Code verwendet wird:

decimal Inverse(decimal input)
{
    return 1 / input;
}

Wenn wir tun würden, was Sie vorschlagen, könnten wir schreiben

decimal Inverse(decimal input)
{
    try 
    {
        return 1 / input;
    }
    catch(Exception ex)
    {
        log.Write("Error 27349262 occurred.");
    }
}

Ein Fehler, der auftreten kann, liegt vor, wenn die Eingabe Null ist. Dies würde zu einer Division durch Null führen.

Nehmen wir also an, Sie sehen 27349262 in Ihrer Ausgabe oder Ihren Protokollen. Wo suchen Sie nach dem Code, der den Nullwert überschritten hat? Denken Sie daran, dass die Funktion mit ihrer eindeutigen ID an Hunderten von Stellen verwendet wird. Während Sie also wissen, dass eine Division durch Null stattgefunden hat, haben Sie keine Ahnung, wem 0es gehört.

Scheint mir, wenn Sie sich die Mühe machen, die Nachrichten-IDs zu protokollieren, können Sie auch den Stack-Trace protokollieren.

Wenn Sie die Ausführlichkeit der Stapelablaufverfolgung stört, müssen Sie sie nicht wie von der Laufzeit als Zeichenfolge ausgeben. Sie können es anpassen. Wenn Sie beispielsweise einen abgekürzten Stack-Trace nur für nEbenen benötigen, können Sie Folgendes schreiben (wenn Sie c # verwenden):

static class ExtensionMethods
{
    public static string LimitedStackTrace(this Exception input, int layers)
    {
        return string.Join
        (
            ">",
            new StackTrace(input)
                .GetFrames()
                .Take(layers)
                .Select
                (
                    f => f.GetMethod()
                )
                .Select
                (
                    m => string.Format
                    (
                        "{0}.{1}", 
                        m.DeclaringType, 
                        m.Name
                    )
                )
                .Reverse()
        );
    }
}

Und benutze es so:

public class Haystack
{
    public static void Needle()
    {
        throw new Exception("ZOMG WHERE DID I GO WRONG???!");
    }

    private static void Test()
    {
        Needle();
    }

    public static void Main()
    {
        try
        {
            Test();
        }
        catch(System.Exception e)
        {
            //Get 3 levels of stack trace
            Console.WriteLine
            (
                "Error '{0}' at {1}", 
                e.Message, 
                e.LimitedStackTrace(3)
            );  
        }
    }
}

Ausgabe:

Error 'ZOMG WHERE DID I GO WRONG???!' at Haystack.Main>Haystack.Test>Haystack.Needle

Möglicherweise einfacher als die Verwaltung von Nachrichten-IDs und flexibler.

Stehlen Sie meinen Code von DotNetFiddle

SAP NetWeaver tut dies seit Jahrzehnten.

Es hat sich als wertvolles Werkzeug bei der Fehlerbehebung im gewaltigen Code-Ungetüm erwiesen, das das typische SAP-ERP-System ist.

Fehlermeldungen werden in einem zentralen Repository verwaltet, in dem jede Nachricht anhand ihrer Nachrichtenklasse und Nachrichtennummer identifiziert wird.

Wenn Sie eine Fehlermeldung ausgeben möchten, geben Sie nur Klassen-, Zahlen-, Schweregrad- und nachrichtenspezifische Variablen an. Die Textdarstellung der Nachricht wird zur Laufzeit erstellt. Normalerweise sehen Sie die Nachrichtenklasse und -nummer in jedem Kontext, in dem Nachrichten erscheinen. Dies hat mehrere nette Effekte:

• In der ABAP-Codebasis finden Sie automatisch Codezeilen, die eine bestimmte Fehlermeldung erzeugen.

• Sie können dynamische Debugger-Haltepunkte festlegen, die ausgelöst werden, wenn eine bestimmte Fehlermeldung generiert wird.

• Sie können Fehler in den SAP-Knowledge Base-Artikeln nachschlagen und relevantere Suchergebnisse erhalten, als wenn Sie nach "Foo konnte nicht gefunden werden" suchen.

• Die Textdarstellungen von Nachrichten sind übersetzbar. Wenn Sie also die Verwendung von Nachrichten anstelle von Zeichenfolgen fördern, erhalten Sie auch i18n-Funktionen.

Ein Beispiel für ein Fehler-Popup mit der Nachrichtennummer:

Suchen Sie diesen Fehler im Fehler-Repository:

Finden Sie es in der Codebasis:

Es gibt jedoch Nachteile. Wie Sie sehen, sind diese Codezeilen nicht mehr selbstdokumentierend. Wenn Sie den Quellcode lesen und eine MESSAGEAussage wie die im obigen Screenshot sehen, können Sie nur aus dem Kontext schließen, was dies tatsächlich bedeutet. Außerdem implementieren Benutzer manchmal benutzerdefinierte Fehlerbehandlungsroutinen, die zur Laufzeit die Nachrichtenklasse und -nummer erhalten. In diesem Fall kann der Fehler nicht automatisch oder nicht an der Stelle gefunden werden, an der der Fehler tatsächlich aufgetreten ist. Die Problemumgehung für das erste Problem besteht darin, es sich zur Gewohnheit zu machen, dem Quellcode immer einen Kommentar hinzuzufügen, der dem Leser mitteilt, was die Nachricht bedeutet. Der zweite Fehler wird behoben, indem ein toter Code hinzugefügt wird, um sicherzustellen, dass die automatische Nachrichtensuche funktioniert. Beispiel:

" Do not use special characters
my_custom_error_handler->post_error( class = 'EU' number = '271').
IF 1 = 2.
   MESSAGE e271(eu).
ENDIF.    

Es gibt jedoch Situationen, in denen dies nicht möglich ist. Es gibt beispielsweise einige UI-basierte Geschäftsprozessmodellierungstools, mit denen Sie Fehlermeldungen konfigurieren können, die bei Verstößen gegen Geschäftsregeln angezeigt werden. Die Implementierung dieser Tools erfolgt vollständig datengesteuert, sodass diese Fehler nicht im Verwendungsnachweis aufgeführt werden. Das bedeutet, dass es ein roter Hering sein kann, sich bei der Suche nach der Fehlerursache zu sehr auf den Verwendungsnachweis zu verlassen.

Das Problem bei diesem Ansatz ist, dass die Protokollierung immer detaillierter wird. 99,9999% davon werden Sie nie sehen.

Stattdessen empfehle ich, den Status zu Beginn Ihres Prozesses und den Erfolg / Misserfolg des Prozesses zu erfassen.

Auf diese Weise können Sie den Fehler lokal reproduzieren, den Code schrittweise durchlaufen und die Protokollierung auf zwei Stellen pro Prozess beschränken. z.B.

OrderPlaced {id:xyz; ...order data..}
OrderPlaced {id:xyz; ...Fail, ErrorMessage..}

Jetzt kann ich genau denselben Status auf meinem Entwicklungscomputer verwenden, um den Fehler zu reproduzieren, den Code in meinem Debugger durchzugehen und einen neuen Komponententest zu schreiben, um die Fehlerbehebung zu bestätigen.

Außerdem kann ich bei Bedarf weitere Protokollierungen vermeiden, indem ich nur Fehler protokolliere oder den Status an anderer Stelle beibehalte (Datenbank? Nachrichtenwarteschlange?).

Natürlich müssen wir besonders vorsichtig sein, wenn es darum geht, sensible Daten zu protokollieren. Dies funktioniert also besonders gut, wenn Ihre Lösung Nachrichtenwarteschlangen oder das Ereignisspeichermuster verwendet. Da das Protokoll nur "Nachricht xyz fehlgeschlagen" sagen muss

Ich würde vorschlagen, dass die Protokollierung nicht der richtige Weg ist, sondern dass dieser Umstand als außergewöhnlich angesehen wird (Ihr Programm wird gesperrt) und eine Ausnahme ausgelöst werden sollte. Angenommen, Ihr Code war:

public Foo GetFoo() {

     //Expecting that this should never by null.
     var aFoo = ....;

     if (aFoo == null) Log("Could not find Foo.");

     return aFoo;
}

Es hört sich so an, als ob Ihr Anrufcode nicht dafür eingerichtet ist, mit der Tatsache umzugehen, dass Foo nicht existiert und Sie möglicherweise Folgendes tun könnten:

public Foo GetFooById(int id) {
     var aFoo = ....;

     if (aFoo == null) throw new ApplicationException("Could not find Foo for ID: " + id);

     return aFoo;
}

Und dies gibt einen Stack-Trace zurück, zusammen mit der Ausnahme, die zum Debuggen verwendet werden kann.

Wenn wir alternativ erwarten, dass Foo beim Empfang null sein kann und das in Ordnung ist, müssen wir die aufrufenden Sites reparieren:

void DoSomeFoo(Foo aFoo) {

    //Guard checks on your input - complete with stack trace!
    if (aFoo == null) throw new ArgumentNullException(nameof(aFoo));

    ... operations on Foo...
}

Die Tatsache, dass Ihre Software unter unerwarteten Umständen "seltsam" hängt oder sich "seltsam" verhält, scheint mir falsch zu sein. Wenn Sie ein Foo brauchen und nicht damit umgehen können, dass es nicht da ist, dann ist es besser, wenn Sie abstürzen, als einen Pfad zu beschreiten, der möglicherweise verläuft beschädigen Sie Ihr System.

Ordnungsgemäße Protokollbibliotheken bieten Erweiterungsmechanismen. Wenn Sie also wissen möchten, auf welche Weise eine Protokollnachricht erstellt wurde, können sie dies sofort tun. Dies hat Auswirkungen auf die Ausführung, da für den Prozess ein Stack-Trace generiert und durchlaufen werden muss, bis Sie die Protokollbibliothek verlassen haben.

Das heißt, es hängt wirklich davon ab, was Ihre ID für Sie tun soll:

• Korrelieren Sie die Fehlermeldungen, die der Benutzer erhalten hat, mit Ihren Protokollen?
• Geben Sie an, welcher Code ausgeführt wurde, als die Nachricht generiert wurde.
• Maschinenname und Serviceinstanz nachverfolgen?
• Verfolgen Sie die Thread-ID?

All diese Dinge können sofort mit der richtigen Protokollierungssoftware erledigt werden (dh nicht Console.WriteLine()oder Debug.WriteLine()).

Was persönlich wichtiger ist, ist die Fähigkeit, Ausführungspfade zu rekonstruieren. Dafür wurden Tools wie Zipkin entwickelt. Eine ID, um das Verhalten einer Benutzeraktion im gesamten System zu verfolgen. Indem Sie Ihre Protokolle in eine zentrale Suchmaschine stellen, können Sie nicht nur die Aktionen mit der längsten Laufzeit finden, sondern auch die Protokolle aufrufen, die für diese eine Aktion gelten (z. B. den ELK-Stapel ).

Undurchsichtige IDs, die sich mit jeder Nachricht ändern, sind nicht sehr nützlich. Eine konsistente ID, die verwendet wird, um das Verhalten einer ganzen Reihe von Mikrodiensten nachzuverfolgen ... immens nützlich.