Alle Methodenaufrufe protokollieren zwecks Behebung von Bugs

Hallo Leute,

ich habe folgende Problemstellung:
Ich möchte alle Methodenaufrufe protokollieren können um nicht direkt nachstellbare Probleme/Bugs in unserer Software leichter beheben zu können. Aktuell können wir den internen Loglevel erhöhen und alle Methodenaufrufe werden in eine Logdatei geschrieben. Das ist im Alltag nicht praktikabel, weil dadurch die ganze Software langsam wird.

Ich könnte alle Methodenaufrufe auch in eine Queue schreiben, welche dann in einem separaten Thread irgendwohin geschrieben wird. Das bringt mir aber nichts, wenn das Programm abstürzt und die Einträge aus der Queue zum Zeitpunkt des Absturzes noch nicht vollständig weggeschrieben sind.

Wie machen das andere Programme? Bei List & Label gibt es beispielsweise die debwin3.exe in der in Echtzeit alles angezeigt wird was in List & Label gerade passiert.
Ich dachte daran, vielleicht eine Art Logserver zu schreiben, der beispielsweise mittels SignalR die Methodenaufrufe mitgeteilt bekommt und sie dann wegschreibt.

Wie würdet Ihr das lösen?

Gruß hypersurf

Einen extra Logserver schreiben kannst du dir sparen.
Wir nutzen z.B. syslog-ng als Logserver und schicken die Logdaten via Log4Net rüber.
Damit loggen wir z.B. in Echtzeit empfangene Daten von GPS Ortungseinheiten.
Entsprechend funktioniert das ganze auch bei großen Datenmengen ohne Probleme.

Habt ihr keine Exception/Stacktrace für die ursachen Forschung?
Was für einen Fehler habt ihr?
Gibt es ggf. im Systemlog (Event Log) keine Einträge mit StackTrace oder Informationen zu dem Fehler?

Nachtrag:
Ich bin mir auch nicht sicher ob der Ansatz wirklich hilfreich ist.
Gerade wenn ihr asynchronen Code habt, dürften sich die Aufrufe im Log vermischen.
Hier müsstest ihr nicht nur pro Instanz der Anwendung ein Log führen sondern innerhalb des Logs dann zwischen den Threads unterscheiden.
Ob das für eure Ursachenforschung so hilfreich ist, müsst ihr dann prüfen.

Nachtrag 2:
Was ich auch empfehlen kann, wäre z.B. mit Sentry zu arbeiten.
Dies haben wir in den letzten Monaten in unsere wichtigsten Produkte eingebaut, was beim protokollieren von Fehlern/Exception ungemein hilft.
Dies wäre vielleicht auch ein Ansatz um dem Problem auf die Schliche zu kommen.
Der Einbau ist sogar relativ einfach und gut dokumentiert.

T-Virus

Alle Methoden zu protokollieren ist der völlig falsche Weg. Das hat noch nie wirklich sinnhaftig funktioniert.

Der moderen Weg des Loggings nennt sich Full Structured Logging; eine Implementierung im .NET Ökosystem ist zB. Serilog — simple .NET logging with fully-structured events
Weiterhin sollte ein Logging auch immer Teil der Software Architektur sein, zB über Operation based Logging.
Operation based Logging wird zB auch in AWS, Google Cloud, Azure ... verwendet, um die genauen Abläufe in der Cloud zu protokollieren, zB auf Basis von Application Insights.
Wie wir das umgesetzt haben ist in [Artikel] Die myCSharp.de Infrastruktur beschrieben (so wende ich das auch in allen Kundenprojekten sowohl Architektur wie auch Implementierung an).

Bibliotheken wie Log4Net sind Full Structured Logging Bibliotheken klar technologisch unterlegen und werden mittlerweile durchaus auch als veraltet bezeichnet.

Gerade wenn ihr asynchronen Code habt, dürften sich die Aufrufe im Log vermischen.
Hier müsstest ihr nicht nur pro Instanz der Anwendung ein Log führen sondern innerhalb des Logs dann zwischen den Threads unterscheiden.

Das ist genau das, was man unbedingt NICHT tun sollte!

Im Log darf alles gemischt sein; das ist sogar gewollt so, um zB. Race Conditions zu erkennen.
Die Trennung erfolgt in der Log Analyse, zB Anhand von Correlation Ids.

Diese werden teilweise - je nach Technologie - automatisch Erzeugt und dem Log Context angereichert (zB. ASP.NET Core) oder können manuell angereichert werden, zB in Serilog mit https://github.com/ekmsystems/serilog-enrichers-correlation-id

Correlation Ids eigenen sich auch hervorragend um Operations eindeutig zu identifizieren und ist ein Standard-Mechanismus.
Siehe: Korrelation

Beispiel aus GitLab: https://docs.gitlab.com/ee/administration/troubleshooting/tracing_correlation_id.html
Beispiel aus Application Insights: https://docs.microsoft.com/de-de/azure/azure-monitor/app/correlation
Beispiel aus Sentry: https://blog.sentry.io/2019/04/04/trace-errors-through-stack-using-unique-identifiers-in-sentry

Niemals getrennte Logs für mehrere Instanzen (/ Threads etc...) des gleichen Systems!

Was Du schreibst, klingt ein bisschen so, als wär euer Logging selbst geschrieben?
Wenn das so ist: Lasst es bleiben. Ich habe schon ein paar solcher Lösungen gesehen und die hatten bisher alle mehr oder weniger große Probleme, die sich teilweise nicht mal richtig beseitigen ließen und meist erst aufgefallen sind, wenn es am wenigsten passt.
Nutzt ein vorhandenes Logging-Framework, die kümmern sich auch um Performance. Serilog ist z.B. sehr beliebt, oder Microsoft.Extensions.Logging (quasi alle Logging-Frameworks unterstützen das), was in ASP.NET Core mit dabei ist. Oder log4net, ich mag's aber nicht.
Und ich würde nicht auf eine Queue verzichten. Exceptions kannst Du global abfangen und in diesem Ausnahmefall die Queue abarbeiten lassen. Die paar Fälle, wo das nicht geht, sind selten und bei z.B. einer StackOverflowException ist auch egal, dass nicht alles im Log steht, Du hast das sowieso zigfach wiederholt drin stehen.

Für z.B. Serilog und Microsofts Logging gibt's garantiert auch Erweiterungen, die an einen Logging-Server senden, entsprechende Server-Software vorausgesetzt, damit habe ich aber keine Erfahrung.
Ansonsten tut's auch eine simple ASP.NET Core API, die das entgegen nimmt und weg schreibt.

Ich persönlich würde schauen, was es bereits für Lösungen für Serilog gibt und dann ggf. die verwenden.
Alternativ setze ich die kleine ASP.NET Core API hin, den Sink für Serilog zu schreiben ist danach kaum Arbeit.

Danke für Eure Antworten und sorry für meine späte Antwort, hatte einfach noch keine Gelegenheit ausführlich zu antworten 🙂

Habt ihr keine Exception/Stacktrace für die ursachen Forschung?

Doch haben wir, manchmal sind die Abläufe aber komplexer, oder es entstehen einfach durch die einzigartige Bedienweise der Software durch die Benutzer Unhandled Exceptions deren Ursache wir nicht ohne weiteres nachvollziehen können.
Klar sehen wir anhand der Exception wo es zum Fehler kommt, der Weg dahin ist aber nicht immer reproduzierbar. Ich stelle mir eine Lösung vor die einfach permanent loggt, so dass wir im Fehlerfall viel schneller nachvollziehen können, was der Benutzer direkt vor dem Fehler gemacht hat.

Was für einen Fehler habt ihr?

Zuletzt hatten wir einen Deadlock durch nicht ganz sauber umgesetzte asynchrone Abläufe. Das ließ sich letztendlich einfach beheben, nachdem wir wussten an welcher Stelle die Problematik auftritt. Da hätten wir durch vorhandenes, permanentes Logging viel Zeit sparen können.

Was ich auch empfehlen kann, wäre z.B. mit Sentry zu arbeiten.
Der Einbau ist sogar relativ einfach und gut dokumentiert.

Finde ich sehr interessant und werden wir uns definitiv anschauen.

Was Du schreibst, klingt ein bisschen so, als wär euer Logging selbst geschrieben?

Jop ist es. Und es ist an der Zeit das durch eine vernünftige Lösung zu ersetzen, die uns Fehlersuche erleichtert und dadurch letztendlich Zeit spart.

Alle Methoden zu protokollieren ist der völlig falsche Weg. Das hat noch nie wirklich sinnhaftig funktioniert.

Wenn ich aber den Ablauf durch den ein Fehler entsteht nachvollziehen kann, komme ich meiner Erfahrung nach viel schneller an die Ursache.

Der moderen Weg des Loggings nennt sich Full Structured Logging; eine Implementierung im .NET Ökosystem ist zB.
>
Weiterhin sollte ein Logging auch immer Teil der Software Architektur sein, zB über Operation based Logging.
Operation based Logging wird zB auch in AWS, Google Cloud, Azure ... verwendet, um die genauen Abläufe in der Cloud zu protokollieren, zB auf Basis von Application Insights.
Wie wir das umgesetzt haben ist in
> beschrieben (so wende ich das auch in allen Kundenprojekten sowohl Architektur wie auch Implementierung an).

Danke, genau das habe ich gesucht. Hab' mir Serilog heute Mittag schonmal zwei Stunden angeschaut und werd's morgen mal mit den Kollegen besprechen.

PS: Gebt mir bitte mal einen Tipp wie ich mich technologisch besser auf dem aktuellen Stand halten kann. D. h. welche Quellen sind gut um sich über aktuelle Entwicklungen und Vorgehensweisen auf dem aktuellen Stand zu halten? Ich hab' durch die viele Arbeit öfter mal das Gefühl hinterher zu hinken.

Gruß hypersurf