Was sind einige Muster und Anti-Muster der Anwendungsprotokollierung? [geschlossen]

66

Ich musste kürzlich ein Feldproblem für unsere Großunternehmensanwendung untersuchen. Ich war entsetzt über die Protokolle , die ich durchkämmen musste, um das Problem zu finden, und am Ende des Tages halfen die Protokolle überhaupt nicht, den Fehler zu identifizieren / zu isolieren.

Hinweis: Ich verstehe, dass nicht alle Fehler durch Protokolle auffindbar sind. Dies ändert nichts an der Tatsache, dass die Protokolle schrecklich sind.

Es gibt einige offensichtliche Probleme mit unserer Protokollierung, die wir bereits beheben können. Ich möchte diese hier nicht auflisten und kann Ihnen nicht einfach unsere Protokolldateien anzeigen, damit Sie Ratschläge geben können, was zu tun ist.

Stattdessen würde ich gerne wissen, um zu beurteilen, wie schlecht wir es mit der Protokollierung machen:

  1. Was sind einige Richtlinien , wenn überhaupt, wenn es um die Anmeldung kommt für eine Anwendung, vor allem große Anwendung.
  2. Gibt es Muster, denen wir folgen sollten, oder Anti-Muster, die uns bewusst sein sollten?
  3. Ist es wichtig, das Problem zu beheben, oder kann es sogar behoben werden, oder alle Protokolldateien sind einfach riesig und Sie benötigen zusätzliche Skripte, um sie zu analysieren?

Randnotiz: Wir verwenden log4j.

c_maker
quelle

Antworten:

55

Ein paar Punkte, die sich in meiner Praxis als nützlich erwiesen haben:

  • Behalten Sie den gesamten Protokollcode in Ihrem Produktionscode. Ermöglichen Sie eine detailliertere Protokollierung in der Produktion, vorzugsweise pro Subsystem und ohne Neustart Ihres Programms.

  • Machen Sie das Parsen von Protokollen nach grepund nach einfach . Halten Sie sich an mehrere gemeinsame Felder am Anfang jeder Zeile. Identifizieren Sie die Zeit, den Schweregrad und das Subsystem in jeder Zeile. Formulieren Sie die Nachricht klar und deutlich. Vereinfachen Sie die Zuordnung jeder Protokollnachricht zu ihrer Quellcodezeile.

  • Wenn ein Fehler auftritt, versuchen Sie, so viele Informationen wie möglich zu sammeln und zu protokollieren. Es kann lange dauern, aber es ist in Ordnung, da die normale Verarbeitung trotzdem fehlgeschlagen ist. Es ist von unschätzbarem Wert, nicht warten zu müssen, wenn derselbe Zustand in der Produktion mit einem angeschlossenen Debugger auftritt.

Protokolle werden hauptsächlich zur Überwachung und Fehlerbehebung benötigt. Versetzen Sie sich in die Lage eines Fehlersuchers und überlegen Sie, welche Art von Protokollen Sie haben möchten, wenn etwas nicht stimmt oder mitten in der Nacht passiert ist.

9000
quelle
10
Diese Antwort gefällt mir, aber ich möchte hinzufügen, dass es wichtig ist zu protokollieren, welche Auswahl an Entscheidungspunkten getroffen wurde. Ich habe viele Systeme gesehen, auf denen viel Junk protokolliert wurde, aber wichtige Entscheidungen nicht protokolliert wurden. 95% der Protokollierung ist also im Grunde unbrauchbar. Auch für Systeme mit Anforderungs- / Antworttyp ist es wichtiger, pro Anforderung protokollieren zu können als nach Subsystem.
Kevin
4
+1. Ich mag es, wenn Sie sich in die Lage versetzen, Fehler zu beheben. Es hört sich so an, als ob Log-Anweisungen viel mehr Qualitätsmeldungen enthalten sollten, als wir bisher getan haben ...
c_maker
1
Es ist wichtig zu beachten, dass die Fehlerprotokollierung im entsprechenden Ereignisprotokoll sowie in den Anwendungsprotokollen protokolliert werden sollte.
Steven Evers
2
@SnOrfus: Es gibt mehrere Möglichkeiten zum Speichern von Protokollen, aber das Wesentliche ist, dass Protokollnachrichten bis zur letzten Sekunde verfügbar sein müssen, in der das System abgestürzt ist - wie bei einer Flugzeug-Blackbox. Wenn Sie eine Art Puffer verwenden, können Sie diese Option aktivieren, um jede Nachricht zu umgehen oder zu leeren.
rwong
1
@Rig: Auf der anderen Seite implementierten viele einheimische Logger keine Pufferung (und löschten pflichtgemäß jede Nachricht), was zu einer sehr schlechten Leistung führte. Aus diesem Grund muss es optional gemacht werden.
Rwong
28

Ich arbeite mit sicherheitskritischen Echtzeitsystemen und Protokollierung ist oft die einzige Möglichkeit, seltene Fehler zu finden, die an jedem 53. Dienstag, wenn es Vollmond ist, einmal als blauer Mond auftauchen, wenn Sie meine Abweichung bemerken. Diese Art von macht Sie besessen über das Thema, so dass ich mich jetzt entschuldigen werde, wenn ich anfange, am Mund zu schäumen. Das Folgende wurde für native Code-Debug-Protokolle geschrieben, aber das meiste davon gilt auch für die verwaltete Welt ...

Verwenden Sie Textprotokolldateien. Scheint offensichtlich, aber einige Leute versuchen, binäre Protokolldateien zu generieren: Das ist einfach dumm, weil ich nicht nach einem Reader-Tool suchen muss, wenn ich auf dem Feld bin. Wenn es sich um Text handelt und das Debugging ausführlich ist, besteht eine gute Chance, dass der Außendiensttechniker die Datei lesen und das Problem diagnostizieren kann, ohne jemals zu mir zurückzukehren. Jeder gewinnt.

Ich entwerfe Systeme, die so ziemlich alles protokollieren können, aber ich schalte nicht standardmäßig alles ein. Die Debug-Informationen werden an einen verborgenen Debug-Dialog gesendet, der sie mit einem Zeitstempel versehen und in einer Listbox (vor dem Löschen auf ca. 500 Zeilen begrenzt) ausgibt. Über diesen Dialog kann ich sie anhalten, automatisch in einer Protokolldatei speichern oder umleiten ein angehängter Debugger. Diese Umleitung ermöglicht es mir, die Debug-Ausgabe mehrerer Anwendungen sauber zu serialisieren, was manchmal lebensrettend sein kann. Früher habe ich numerische Protokollierungsstufen verwendet (je höher die Stufe eingestellt ist, desto mehr wird erfasst):

off
errors only
basic
detailed
everything

Dies ist jedoch zu unflexibel - wenn Sie sich auf einen Fehler zuarbeiten, ist es viel effizienter, sich auf das zu konzentrieren, was Sie benötigen, ohne durch Tonnen von Abfällen waten zu müssen. Dies kann eine bestimmte Art von Transaktion oder Operation sein das verursacht den Fehler. Wenn Sie dafür alles einschalten müssen, erschweren Sie nur Ihren eigenen Job. Sie brauchen etwas Feinkörnigeres.

Jetzt bin ich also dabei, auf die Protokollierung basierend auf einem Flaggensystem umzusteigen. Alles, was protokolliert wird, hat eine Markierung, die angibt, um welche Art von Operation es sich handelt, und es gibt eine Reihe von Kontrollkästchen, mit denen ich definieren kann, was protokolliert wird. Normalerweise sieht diese Liste folgendermaßen aus:

#define DEBUG_ERROR          1
#define DEBUG_BASIC          2
#define DEBUG_DETAIL         4
#define DEBUG_MSG_BASIC      8
#define DEBUG_MSG_POLL       16
#define DEBUG_MSG_STATUS     32
#define DEBUG_METRICS        64
#define DEBUG_EXCEPTION      128
#define DEBUG_STATE_CHANGE   256
#define DEBUG_DB_READ        512
#define DEBUG_DB_WRITE       1024
#define DEBUG_SQL_TEXT       2048
#define DEBUG_MSG_CONTENTS   4096

Dieses Protokollierungssystem wird mit dem Release- Build geliefert , ist aktiviert und wird standardmäßig in einer Datei gespeichert. Es ist zu spät, um herauszufinden, ob Sie nach dem Auftreten des Fehlers protokolliert haben sollten, wenn dieser Fehler im Durchschnitt nur einmal alle sechs Monate auftritt und Sie keine Möglichkeit haben, ihn zu reproduzieren. Protokollierung, die nur mit Debugbuilds funktioniert, ist gerecht. einfach. Dumm.

Die Software wird normalerweise mit aktiviertem ERROR, BASIC, STATE_CHANGE und EXCEPTION ausgeliefert. Dies kann jedoch im Feld über das Debug-Dialogfeld (oder über eine Registrierung / ini / cfg-Einstellung, in der diese Dinge gespeichert werden) geändert werden.

Ach ja, mein Debug-System generiert eine Datei pro Tag. Ihre Anforderungen können unterschiedlich sein. Stellen Sie jedoch sicher, dass Ihr Debug-Code jede Datei mit dem Datum, der Version des von Ihnen ausgeführten Codes und, falls möglich, einem Marker für die Kunden-ID, den Standort des Systems oder was auch immer startet . Sie können eine ganze Menge von Protokolldateien aus dem Feld abrufen, und Sie benötigen Aufzeichnungen darüber, was von wo kam und welche Version des Systems, auf dem sie ausgeführt wurden, tatsächlich in den Daten selbst enthalten ist, und Sie können dem Kunden nicht vertrauen / Außendiensttechniker, um Ihnen zu sagen, welche Version sie haben - sie können Ihnen nur sagen, welche Version sie DENKEN, dass sie haben. Schlimmer noch, sie melden möglicherweise die exe-Version, die sich auf der Festplatte befindet, aber die alte Version wird noch ausgeführt, da sie nach dem Ersetzen vergessen haben, einen Neustart durchzuführen. Lassen Sie sich von Ihrem Code erzählen.

Schließlich möchten Sie nicht, dass Ihr Code eigene Probleme erzeugt. Verwenden Sie daher eine Timer-Funktion, um die Protokolldateien nach so vielen Tagen oder Wochen zu löschen (überprüfen Sie einfach den Unterschied zwischen dem aktuellen Zeitpunkt und dem Zeitpunkt der Dateierstellung). Dies ist in Ordnung für eine Server-App, die ständig ausgeführt wird. Auf einer clientseitigen App können Sie beim Start alle alten Daten löschen. In der Regel wird das System nach etwa 30 Tagen gelöscht. Bei einem System ohne häufige Technikerbesuche möchten Sie es möglicherweise länger belassen. Dies hängt natürlich auch von der Größe Ihrer Protokolldateien ab.

Bob Moore
quelle
1
+1 Im Allgemeinen sehr gute Antwort, aber vor allem, um die Anwendungs-ID und die Versionsinformationen in die Protokolldatei aufzunehmen, wird dies leider so oft übersehen.
Binary Worrier
27

Meine bevorzugte öffentliche Ressource für Richtlinien zur Protokollierung sind Apache JCL Best Practices .

Best Practices für JCL werden in zwei Kategorien dargestellt: Allgemein und Unternehmen. Die allgemeinen Grundsätze sind ziemlich klar. Unternehmenspraktiken sind etwas komplizierter und es ist nicht immer klar, warum sie wichtig sind.

Die Best-Practice-Grundsätze für Unternehmen gelten für Middleware-Komponenten und -Tools, deren Ausführung in einer Umgebung auf Unternehmensebene erwartet wird. Diese Probleme betreffen die Protokollierung als Internationalisierung und die Fehlererkennung. Unternehmen erfordern mehr Aufwand und Planung, werden jedoch in Systemen auf Produktionsebene nachdrücklich empfohlen (falls nicht erforderlich). Unterschiedliche Unternehmen / Umgebungen haben unterschiedliche Anforderungen, daher hilft Flexibilität immer ...

Trotz der Ausrichtung auf JCL scheinen diese generisch genug zu sein, um für die Protokollierung im Allgemeinen übernommen zu werden.

  • Meine persönlichen "Richtlinien" für die Protokollierung sind, dass ich auf Debug-Ebene versuche, meine Protokolle wie eine Story zu lesen - mit verständlicher Logik und ausreichenden (aber nicht überladenen) Details.

Das bekannteste Anti-Pattern ist wahrscheinlich das "Verschlucken von Ausnahmen" - suchen Sie einfach im Web danach.

Bei großen Protokolldateien war dies in meiner Praxis meistens der Normalfall. Und ja, ergänzende Skripte, wie Sie sie nennen, und / oder Werkzeuge wie Kettensäge sehen für mich ebenfalls normal aus.

  • Oben bedeutet jedoch nicht, dass Sie immer alle Protokolle blind in einer großen Datei ablegen müssen. Manchmal kann es nützlich sein, einige der Protokolle in separate Dateien zu schreiben / kopieren. In meinem letzten Projekt haben QA-Mitarbeiter beispielsweise nach speziellen Dateien für Metriken und Zeitdaten sowie nach kurzen Berichten über den Systembetrieb gefragt. Sie sagten, dass sie davon profitieren werden und Entwickler haben es getan (Nutzen aus einer kurzen Berichtsdatei, die sich tatsächlich als bedeutend herausstellte).

PS. In Bezug auf Anti-Muster sind andere, die mir in den Sinn kommen, "überschwemmende" und sinnlose Botschaften.

  • Ich nenne es Flooding, wenn ich mehrere ähnliche Nachrichten aus einer Schleife mit vielen Iterationen sehe. Überschwemmungen sind für mich ärgerlich genug, um sie loszuwerden, wenn ich sie im Quellcode finde. Normalerweise erfordert das Verbessern etwas Kunst - denn Dinge, die innerhalb der Schleife passieren, können interessant sein. Wenn ich keine Zeit habe, um es tiefer zu verbessern, versuche ich, die Protokollierungsstufe solcher Nachrichten auf die niedrigste zu ändern, um das Herausfiltern zu vereinfachen.

  • Sinnlose Botschaften scheinen ziemlich populärer Müll zu sein. Diese sehen beim Einlesen des Quellcodes harmlos aus - ich schätze, man muss sich die Mühe machen, die Debug-Ausgabe so zu analysieren, dass sie aussieht wie ...

    step #1
    step #2
    step #3
    

    ... um ihre inhärente Hässlichkeit zutiefst zu würdigen. Meine bevorzugte Heuristik zur Erkennung dieser Art von Problemen auf Quellcodeebene (vorgeschlagen von einem Kollegen in einem meiner früheren Projekte) ist die Berechnung der Anzahl von Leerzeichensymbolvorkommen in Zeichenfolgenliteralen, die bei der Protokollierung verwendet werden. Meiner Erfahrung nach garantiert null Leerzeichen, dass die Protokollierungsanweisung sinnlos ist, ein Leerzeichen ist auch ein guter Indikator für das potenzielle Problem.

Mücke
quelle
4
Um Überschwemmungen zu vermeiden, sammle ich normalerweise die Heuristiken der Schleife und gebe sie nach der Schleife aus. Bedeutet, dass alles, was in der Schleife interessant ist, in einer Variablen (wie somethingSpecialHappenedCount) gespeichert und dann an den Logger ausgegeben werden sollte.
Spoike
@Spoike guter Punkt! Das Speichern in einer Variablen ist in der Tat einer meiner persönlichen Lieblingstricks, um Überschwemmungen zu bekämpfen
Mücke
1
Ich gebe alle verschiedenen Zähler nach Beendigung der Schleife als ASCII-Tabelle im Protokoll an den Logger aus, damit sie leicht verglichen werden können. Die Tabellenidee wurde von der Idee inspiriert, die Spring mit StopWatch.prettyPrint () generiert hat. Davon abgesehen ist es immer noch eine "Kunst", den Protokolltext lesbar und relevant zu machen, wie bereits in der Antwort erwähnt.
Spoike
@Spoike: (und @gnat) Das ist interessant. Fügen Sie der Geschäftslogik also im Grunde genommen tatsächlichen Code nur zum Zweck der Protokollierung hinzu? Ich habe noch nie davon gehört oder dies getan und bin mir nicht sicher, wie ich es meinen Mitarbeitern rechtfertigen würde. Ich fürchte, wenn wir damit beginnen, werden einige unserer Entwickler den Quellcode so überladen, dass die Geschäftslogik verwickelt und schwer lesbar wird. Das einfache Protokollieren einer Anweisung lässt die Quelle bereits hässlicher aussehen.
c_maker
2
@c_maker Ihre Überlegung, die Protokollierung mit der Geschäftslogik zu mischen, ist eine spezielle Frage wert. Persönlich habe ich noch keine feste Meinung zu diesen Angelegenheiten. Theoretisch kann man sich einige Trennungsverbesserungen mit AOP und iirc vorstellen. Es gibt sogar praktische Anwendungen für diesen Ansatz. In der Praxis bleibe ich jedoch bei "gemischtem" Ansatz und hatte bisher keine größeren Probleme damit. Wirrer Quellcode ist eine echte Gefahr, aber bisher konnte ich ihn wieder ganz "friedlich" mit dem Protokollierungscode koexistieren lassen. Dies erfordert natürlich einen gewissen Aufwand.
gnat
11

Ausnahme nur einmal protokollieren!

Einer der häufigsten Probleme, die mir aufgefallen sind, ist das Protokollieren und erneutes Auslösen einer Ausnahme. Infolgedessen enthalten die Protokolldateien dieselben Ausnahmen mehrmals auf mehreren Stapelebenen.

Nayaki
quelle
5

Hier ist ein Anti-Muster: Erstellen Sie zwei Dutzend "generische Variablen" -Felder in einer Datenbanktabelle, um alles Mögliche nachzuverfolgen, und führen Sie dann 88 verschiedene Aufzählungswerte für verschiedene Arten von Protokollen durch (und zählen sie).

Wayne Molina
quelle
+1 - Ich habe das gesehen. "Fehlertabellen" mit Spalten wie "string1", "string2", "string3", "string4" und "string5", bei denen das Verknüpfen aller Spalten zu einem Fehlercode führt, auf den in keiner Dokumentation verwiesen wird. Das Ergebnis ist eine verwirrende und nutzlose Protokollierung. auch bekannt als "3rd-Party-Enterprise-App-mit-Custom-Development-Debugging-Hölle".
Morgan Herlocker
In meinem Fall ist es "handgerolltes Protokollierungssystem, ohne eine Vorstellung davon zu haben, um was es sich bei der Protokollierung handelt"
Wayne Molina,
4

Meine Erfahrung mit Protokollen ist umso größer, je besser, aber so konsistent, dass sie maschinell gefiltert werden können, und dass für jede Komponente Ihrer Anwendung individuell ein Schweregrad konfiguriert werden kann.

Außerdem ist es sehr schwierig vorherzusagen, welche Protokollierung Sie benötigen, um einen zukünftigen Fehler zu finden. Die meisten offensichtlichen Fehlerquellen werden behoben, bevor das Produkt aus der Tür geht. Es ist nicht ungewöhnlich, dass Sie als Ergebnis eines Fehlerberichts die Protokollierung hinzugefügt haben, um die Diagnose zu vereinfachen, falls es erneut auftritt.

Karl Bielefeldt
quelle
2

Ein paar Notizen von der Operationsseite des Hauses hier:

1) Stellen Sie sicher, dass die Protokolle lokal konfigurierbar sind, vorzugsweise mit einem Tool, das nicht schwerer als ein Texteditor ist. Die meiste Zeit wollen wir keine Protokollierung auf TRACE-Ebene, aber wir lieben es, sie einschalten zu können.

2) Stellen Sie nach Möglichkeit sicher, dass die Protokolle mit einem Tool gelesen werden können, das nicht schwerer als ein Texteditor ist. Nichts ist schlimmer, als zu einer ungeraden Stunde auf Werkzeugsuche gehen zu müssen, wenn das Produktionssystem ausfällt.

Wyatt Barnett
quelle
1

Aus eigener Erfahrung mit Webanwendungen:

(& wenn man bedenkt, dass Speicher heutzutage sehr billig ist)

  • Protokollieren Sie so viele verfügbare Informationen wie möglich (zu diesem Zeitpunkt).
  • Ich füge DateTime.Now immer in meine Log-Strings ein.
  • Ich protokolliere immer (wenn es möglich ist) die Zeitdauer einer bestimmten "Aktion".
  • Seien Sie konsistent mit Ihren Log-Strings. Da ich immer diese Art von Muster benutze:

    • [Info X] [Info Y] [Info Z] [usw.]
Sabiland
quelle
1

Protokollieren Sie neben dem Stacktrace den aktuellen Anwendungsstatus und die Eingabe.

Software ist deterministisch, diese beiden sind normalerweise das einzige, was Sie brauchen, um den Fehler zu reproduzieren. Das Speichern des vollständigen Zustands kann in einigen Fällen problematisch sein, daher sind auch Möglichkeiten zum Reproduzieren des aktuellen Zustands, beispielsweise durch vorherige Eingaben, gut.

Natürlich sind mehr Daten immer besser, aber mindestens diese beiden sind ein guter Anfang für die einfachsten Abstürze.

ladida
quelle
3
"Software ist deterministisch" => leider nicht immer. Denken Sie zum Beispiel an Parallelitätsfehler.
Assylias