Disclaimer: Dieser Thread wurde aus dem alten Forum importiert. Daher werden eventuell nicht alle Formatierungen richtig angezeigt. Der ursprüngliche Thread beginnt im zweiten Post dieses Threads.
Wie funktioniert gutes Logging?
Hey Leute,
mich interessiert, wie gutes Logging in einem Software-Projekt aussieht, bzw. wann man am besten was loggt.
Ich frage mich bspw. ob es sinnvoll ist Aufrufzeit, Funktion(sname) und übergebene Parameter (sofern es nicht zu komplexe Objekte sind) zu loggen, bzw. ob das überhaupt sinnvoll ist und ob das bei jeder Funktion gemacht werden sollte. Des Weiteren kann ich mir vorstellen, dass try-catch-Blöcke geloggt werden sollten bzw. dass sie für das Logging per se interessant sind aber auch hier gilt wieder: Wie man das in diesem Fall genau macht und ob das überhaupt sinnvoll ist, weiß ich nicht.
Ich gehe davon aus, dass die Methoden (stark) von der Anwendung abhängen aber vielleicht gibt es ein paar Faustregeln, die eine solide Grundlage darstellen können.
Auch wenn mich prinzipiell das Thema im Allgemeinen interessiert, werde ich es allen voran in python umsetzen, dh. falls es diesbezüglich etwas zu beachten gibt, bin ich auch für Antworten dankbar. Die Dokumentation habe ich mir teilweise schon durchgelesen, dh. ich weiß im Groben wie ich Logging-Mechanismen implementiere − nur eben nicht wo und wann.
Ein paar Faustregeln die mir einfallen:
- Benutz verschiedene Loglevel und mach es einfach, den Loglevel idealerweise zur Laufzeit zu ändern. Nutze einen individuellen Loglevel für alle (größeren!) Komponenten. Je nach Loglevel können dann mehr Details (z.B. ganze Objekte) geloggt werden.
- Logge möglichst viel Datenfluss statt Programmfluss. Der Programmfluss lässt sich durch Studie des Codes bei guter Datenlage recht einfach sicher rekonstruieren. Ein unerwarteter Programmfluss und Fehlerfall ist ohne die relevanten Daten oft nicht nachvollziehbar.
- Logge keine Trivialitäten. Programme laufen deterministisch ab. Müll dir den Code nicht mit Logging zu sondern logge da, wo es Sinn macht (siehe auch Punkt 2). Benutze Logging nicht als Ersatz für den Debugger.
Generell würde ich ans Herz legen, ein existierendes Modul mit der Umsetzung zu betreuen, wie z.B. das in Python mitgelieferte Logging-Modul. Es bietet passende Interfaces zu Logleveln, speziellen Logformatten (z.B. wie von dir angesprochen inkl. Zeitstempel, aber auch Kontextinformationen) und andere Ausgabeanpassungen (z.B. Filter).
Top! Meine Programmiererfahrung reicht aus, um deine Tipps direkt in einen passenden Kontext setzen zu können! 
Die Dokumentation des python-Moduls habe ich mir durchgelesen und ist auch geplant zu nutzen − ausnahmsweise bin ich mal selbst auf die Idee gekommen, dass man manchmal das Rad nicht neu erfinden muss.
Meine persönliche Erfahrung und Meinung.
- Nur zwei Loglevel sind sinvoll: Production und Debug, bzw. Public (Kunde sieht es) und Private (Kunde sieht es nicht) bei Corposoftware. So FATAL/ERR/WARN/INFO/DEBUG Balkanisierung hat mir noch nie geholfen sondern immer nur gestört. Es stört beim Debuggen (oh Mist INFO war nicht an) und es stört beim Entwickeln (ist das jetzt INFO oder DEBUG?).
- Dateiname + Zeile in das Log. Super nützlich beim Debuggen.
Muss man freilich nicht so machen.
Wie setzt du „Dateiname + Zeile“ um? Gerade Letzteres konsistent zu halten, stelle ich mir super schwierig vor, weil eine oberhalb eingefügte Zeile (ein erklärender Kommentar ist schnell und gerne geschrieben) diese Information sofort ungültig macht, ergo man muss es manuell korrigieren.
Sowas macht man nicht manuell, das wäre der totale Krampf. Python-Logging bietet das z.B. über die bereits angesprochenen Formattoren an.
1 „Gefällt mir“
Sowas wie „Alle (deserialisierten) Nachrichten“ vs „Logic Flow“ helfen schon gelegentlich erheblich.
Gerade im Kontext von „ich brauch logging von der einen aktion“ vs „ich brauch ein verständnis von abfolge an events die zu $problem führen“
Ich kann den unterschiedlichen Log-Levels nichts abgewinnen. Dauernd fehlt irgendwo eine Information im Log-File weil jemand nicht das passende Log-Level gesetzt hat. Blöd wenn ein Fehler schwierig zu reproduzieren ist.
Filtern kann man immer auch nachher. Bei Python gibts allerdings noch das Performance-Argument: Wenn man DEBUG Logging einschaltet ists zu langsam, weil in Python ist ja alles langsam.
Hängt von der Anwendung ab. In einigen Szenarien kann man nicht einfach alles rausloggen. Tiefere Loglevel können dort nur bei Bedarf aktiviert werden, aufgrund von Performanzeinbußen oder mangelndem Speicher.