Laden...

"Richtiges" loggen: Welche Ereignisse/Informationen sollten geloggt werden? Nur Exceptions?

Erstellt von Palin vor 9 Jahren Letzter Beitrag vor 9 Jahren 12.910 Views
Hinweis von herbivore vor 9 Jahren

Abgeteilt von abhängige private assembly einer private dll wieder finden, weil sich das Thema Logging verselbständigt hat.

P
Palin Themenstarter:in
1.090 Beiträge seit 2011
vor 9 Jahren
"Richtiges" loggen: Welche Ereignisse/Informationen sollten geloggt werden? Nur Exceptions?

Die Grundlagen um den Logger und EF zu verwenden hat dir Abt ja schon geliefert.

Mir ist an der Stelle nur nicht klar wieso du sie Brauchst, beschreibe doch mal näher was du machen möchtest.

Im allgemeinen halte ich es für sinnvoller bei Klassen Bibliotheken, keinen Logger zu verwenden, sondern Aussagekräftige Exceptions zuschmeißen. Und dann den Benutzer entscheiden zu lassen wie er darauf Reagiert. Für dich ist es dann sinnvoll Unit Tests zu schreiben.

Auch sollte dir Egal sein wo die Daten herkommen. Hier kannst du Passende Objekte oder Schnittellen bereitstellen. Die gefüllt oder implementiert werden müssen.

Ohne genauer zu wissen was du eigentlich machen Möchtest, ist es Problematisch da eine Sinnvolle Antwort zu geben.

Sollte man mal gelesen haben:

Clean Code Developer
Entwurfsmuster
Anti-Pattern

16.806 Beiträge seit 2008
vor 9 Jahren

Es macht für Anwendungs-abhängige DLLs schon sinn, zusätzlich zu passenden Exceptions einen Logger zu übergeben - ich mach das übrigens auch so 😉
Für allgemeine Bibliotheken zur freien Verfügung; da eher nicht.

F
10.010 Beiträge seit 2004
vor 9 Jahren

@Palin:
Wer nur Exceptions Loggt hat den Sinn von Logging nicht so ganz verstanden.

Logging soll nicht nur Ausnahmen zeigen sondern ggf ( schaltbar!! ) ganze Wege und Abläufe aufzeichnen.

P
Palin Themenstarter:in
1.090 Beiträge seit 2011
vor 9 Jahren

@FZelle:
Nun ich benutze normaler weise einen Logger so, das er mir bei bedarf die nötigen Informationen liefern kann, die ich Brauche um einen Fehler/Problem beim Kunden zu finden. Was in 80-90% der Fälle einfach die Exceptions sind. Es gibt natürlich Stellen an denen ich bei Bedarf zusätzliche Informationen brauche, dann werden auch die geloggt. Z.B. habe ich einen Service geschrieben an den Maschinen Produktionsdaten schicken und der diese dann weiter Verarbeitet, hier wird bei bedarf mit geschrieben, welche Maschine was gesendet hat.

Das Logging ganze Abläufe aufzeichnet, habe ich bis jetzt nur bei einer Firma erlebt. Die haben wirklich jeden Methoden einstiegt und ausstieg, mit Übergabewerten geloggt (Wenn der Logger eingeschaltet war). Das hatte zufolge, das die Software irre langsam war und ein Zusätzliches Tool geschrieben wurde um die Logs zu Analysieren, da die wirklich groß wurden.
Damit sollte dann bei bedarf dem Kunden nachgewiesen werden das er Fehler gemacht hat.
Code zu schreiben um den Kunden Fehler nachzuweisen halte ich nicht für Sinnvoll. Ich stecke die Zeit lieber in Code, der Verhindert dass der Kunde Fehler machen kann.

Und wer so viel Logt, das er die ganzen „Wege und Abläufe“ aufzeichnet. Zeigt nicht das er sich Gedanken dazu gemacht hat welche Informationen er oder andere braucht um den Fehler zu finden. Sondern dass er die „Wege und Abläufe“ in seinen Programm nicht verstanden hat. Oder das er zu faul ist sich darüber Gedanken zu machen und deshalb einfach alles Logt. Auch wenn keine Irgendwas mit den Informationen anfangen kann.

@Abt:
Ich würde aber jetzt auch davon ausgehen, dass du es nicht so Implementiert hast, dass das Logging eine Eigenschaft all deiner Klassen ist. Sondern die Abhängigkeiten intern Aufgelöst werden. Sei es jetzt ein Bootstraper der eine Logger Faktory instanziert oder ein IOC Container. Außerdem gehe ich davon aus das deine Klassen im Zweifel ohne den Logger auskommen.

Sollte man mal gelesen haben:

Clean Code Developer
Entwurfsmuster
Anti-Pattern

49.485 Beiträge seit 2005
vor 9 Jahren

Hallo Palin,

auch ich halte es nicht für sinnvoll, Code zu schreiben, um dem Kunden den Schwarzen Peter zuzuschieben.

Aber auch ohne diese Ziel kann es praktisch durchaus nötig sein, mehr als die Exception zu loggen. Der StackTrace einer Exception zeigt nur die aktuelle Aufrufhierarchie, nicht aber, welche Methoden vor dem aktuellen Aufruf aufgerufen und schon wieder verlassen wurden. Außerdem stehen im StackTrace nicht die aktuellen Werte der Übergabeparameter. Beide Informationen können aber erforderlich sein, um Fehler eingrenzen und finden zu können. Entsprechend kann es Sinn machen, sie zu loggen.

In deiner Ablehnung bist du aus meiner Sicht über das Ziel hinausgeschossen, erst recht, wenn du Entwickler, die solche Informationen loggen, auf der persönlichen Ebene angreifst. Das ist weder nötig noch erwünscht. Ich bitte dich und alle anderen, auf der sachlichen Ebene zu bleiben bzw. sofort wieder dahin zurückzukehren. Vielleicht hat dich die Aussage von FZelle, die - je nachdem wie man sie auffasst - ebenfalls unnötigerweise schon auf der Grenze zum Persönlichen war, veranlasst. Das ist allerdings letztlich keine wirkliche Entschuldigung.

Wie dem auch sein. Ab hier bitte nur noch sachliche Argumente.

herbivore

W
872 Beiträge seit 2005
vor 9 Jahren

Du solltest Dich meiner Meinung nach mit Semantic Logging beschäftigen, damit Du eine Idee bekommst, wohin sich das Logging gerade weiterentwickelt. Dieser Trend aus der Dev Ops Bewegung führt im Moment zu neuen Logging Frameworks. Selbst wenn Du bei einem alten Logging Framework bleibst, hilft Dir die Idee bestimmt weiter.

F
10.010 Beiträge seit 2004
vor 9 Jahren

@Palin:
Das hat nichts mit Faulheit zu tun, sondern damit das man nach 30 Jahren SW Entwicklung weis, das man immer genau das vergessen hat mitzuloggen was man für den aktuellen Fehler benötigt.
Wenn du mal grössere Server SW erstellen und warten musst, oder Firmware auf embedded Systemen dann wirst du feststellen, das nicht nur Fehlersuche durch loggen gemacht wird.
Man kann mit vernünftigem und durchdachtem viel mehr machen als Du es dir im Moment vorstellen möchtest.
Und eine Exception zeigt dir selten wie es zu dem Fehler gekommen ist.

Hinweis von gfoidl vor 9 Jahren

Bitte bleibt sachlich und rutscht nicht auf die persönliche Ebene ab. Jeder hat seine Erfahrungen gemacht und es ist reine Spekulation welche Erfahrungen andere machen werden. Es ist keinesfalls zwangsläufig so, dass die gleichen Erfahrungen gemacht werden (müssen). Also respektiert die Erfahrungen anderer.

Die hier erwähnten Informationen sind sehr wertvoll und reich an Erfahrung - diese können eben auch sachlich mit der Community geteilt werden. Danke.

49.485 Beiträge seit 2005
vor 9 Jahren

Hallo zusammen,

man darf natürlich auch nicht vergessen, dass es von der Architektur, Größe und Komplexität der Anwendung abhängt, wie leicht oder schwer es ist, darin Fehler zu finden. Das wirkt sich wiederum darauf aus, wieviel Informationen für das Auffinden von Fehlern nötig sind. Insofern wird ohnehin keine pauschale Aussage möglich sein, was geloggt werden muss und was nicht.

Ich kann mir grundsätzlich auch große Anwendungen vorstellen, bei denen relativ wenig geloggt werden muss und trotzdem genug Informationen für das Auffinden von Fehlern zur Verfügung stehen. Wenn man z.B. Flow-based programming verwendet, kann man aus dem StackTrace einer Exception u.U. viel mehr Informationen ableiten, als bei strukturierter Programmierung.

herbivore

P
40 Beiträge seit 2011
vor 9 Jahren

Die Firma für die ich arbeite hat sich auf die Migration von 4GL Sprachen nach Java (bzw. auch schon C#) spezalisiert.

Dazu wurde ein Framework entwickelt welches als Basis für die Anwendungen und Schirme dient.
Wird der Log auf DEBUG gestellt ist es uns möglich den ganzen Ablauf der Applikationen inkl Framework mitzuverfolgen bzw. nachzuvollziehen.

Folgendes wird geloggt:*eine Methode wird betreten bzw. verlassen (im Framework nur teilweise, bei den migrierten Anwendungen bei jeder Methode *welcher Wert auf welches Item gesetzt wird was davor auf diesem Item stand *welches SQL Statement wird mit welchen Parametern ausgeführt *in welchen Strukturen wird nach welchen Items mit welchen Wert gesucht *.....

Klar dadurch wird viel Log aber wir können genau nach vollziehen welche Methoden wurde davor betreten (welche nicht im StackTrace auftauchen würden). Aber da wir zum Vergleich auch oft Logs von den 4GL Sprachen bekommen ist es recht praktisch, da dort auch viel geloggt wird und man meist 1:1 vergleichen kann.

Gerade sitzen wir an (TIBCO) ObjectStar -> Java
ObjectStar arbeitet nur mit Rules (->Methoden) und kann ähnlich PHP dynamische Aufrufe.
Sprich ich lese aus der Datenbank welche Rules als nächstes aufgerufen werden soll usw. .
Ohne ein entsprechend ausführliches Logging wäre dieser Source Code nicht zu verstehen.

Wie andere schon sagten, es kommt halt ganz darauf an ob man mehr als den StackTrace braucht um einen Fehler zu beheben.
Aber ich schreibe von Anfang an lieber ein paar Logausgaben mehr in das Programm und miste später aus als im nachhinein welche hinzuzufügen 😉

C
1.214 Beiträge seit 2006
vor 9 Jahren

Fehler sind nicht unbedingt Exceptions und die haben sowieso wenig mit dem Logging zu tun. Ich bin C++ Entwickler und wir verwenden in unserer Software überhaupt keine Exceptions.
Komplette Abläufe zu loggen finde ich wichtig. Wir können z.B. parametrische 3D Modelle für verschiedene CAD Systeme generieren und in verschiedene PDM Systeme einchecken und dabei mit Daten aus verschiedenen Datenquellen, z.B. anderen PDM Systemen oder SAP anreichern. Das sind komplexe Abläufe mit dutzenden unabhängiger Komponenten, die vielleicht Stunden dauern können. Dabei kann es sehr viele Sonderfälle geben und die Fehler sind auch öfter mal nicht reproduzierbar. Nicht alle Komponenten sind von uns, einige werden von Partnern oder Consultants oder den Kunden selbst geschrieben. Für viele Schitte gibt es verschiedene Möglichkeiten und Fallbacks. Wenn am Ende etwas rauskommt, was vielleicht nicht ganz richtig ist, kann es sehr viele Ursachen haben. Da ist es schon wichtig, wenn man ins Log schauen und genau nachvollziehen kann, was eigentlich passiert ist. Und ich meine dabei nicht mal, dass der Einstieg und der Ausstieg jeder Methode protokolliert wird, das wär zu viel und zu uninteressant. Aber die einzelnen Komponenten protokollieren schon ziemlich genau, was sie machen.
Nachweisen zu können, dass ein Fehler beim Kunden liegt, ist oft auch erstaunlich wichtig. Unsere Hauptzielgruppe sind größere Konzerne und die treten kleineren Zulieferern gegenüber oft gleich ziemlich aggressiv auf, wenn sie bei denen einen Fehler vermuten. Da kann es auch um hohe Schadensersatzforderungen gehen. Da ist es wichtig, wenn man in Log sieht, dass die falschen Daten von einem Kundenscript falsch berechnet wurden und nicht von uns.

P
157 Beiträge seit 2014
vor 9 Jahren

Wenns um Geld geht werden Menschen zu Schweinen 😉

Der Ansatz ein ganzen Ablauf zu loggen...ist meines erachten Wahnsinn...zu mal man da innerhalb von 2 Sekunden monströse Dateien produzieren kann. Da hatte ich vor einigen Monaten wieder eine Diskussion mit einem meiner Kollegen...

Wenn man jeden Methoden Ein- und Ausgang logt, gehe ich ganz stark davon aus, dass Clean-Code Principles , UnitTests und Code-Reviews absolute Fremdbegriffe sind, da wäre man mit Refactorings und Schulungen besser dran, als nachträgliche Flickschusterei und Schuldzuweisungen über Loggings - leider ist dieser Kindergartenkram immernoch Realität - "Investmentbanker, die wissen wie mans macht" -> BWLer-Projektleiter:D...das selbe. Ist am Ende viel billiger, spart nerven und Stress und schlechte Laune bei allen Beteiligten. Ist auch verständlich, dass der Kunde sauer wird, wenn man ihn als Betatester missbraucht...

Weil:wenn mans richtig macht braucht man keine 20000 Zeilen Logs um einen Fehler zu finden. Der Stacktrace reicht meist aus.

Ich persönlich nutze den Traceschalter 😉 Der reicht meist für das was ich mache aus, jedes Logging kostet Performance, genauso wie jeder andere redundante Aufruf. Wenn Fehler auftreten brauch man meist nur die Exception und wenns richtig übel ist -> MemoryDumps...die Dinger sind Gold und Diamanten Wert.

Unterm Strich ist es meistens so, dass man monster-logs nur dann braucht, wenn man nicht weiß was los ist. Wenn man an einen Punkt angekommen ist, wo man alles erdenkliche protokolliert, nur um dann nen 2 min Bugfix auszuliefern, hat man von Anfang n bisschen unfug bei der Planung gemacht. Einigermaßen gut durchdachte Konzepte lassen Platz für ein ordentliches Exceptionhandling und entsprechende Fehlermeldungen zu.

Nachvollziehbar ist aber der rechtliche Aspekt um die "Schuldfrage" zu klären, ein heiß geliebtes Thema im Projektgeschäft. Da gilt : Absicherung vor Performance...Vertragsstrafen sind teilweise so enorm, die können ne Firma locker ruinieren.

vg

Wenn's zum weinen nicht reicht, lach drüber!

16.806 Beiträge seit 2008
vor 9 Jahren

Der Ansatz ein ganzen Ablauf zu loggen...ist meines erachten Wahnsinn...zu mal man da innerhalb von 2 Sekunden monströse Dateien produzieren kann.

Tja, dann arbeite mal mit großen, Prozess-orientierten Systemen.
Ohne Filter kann so nen großes Web-Log gern mal 5GB pro Minute erzeugen, dann ist der I/O am Ende.
Deswegen baut man ein Logging-System mit Filtern.

Vertragsstrafen sind teilweise so enorm, die können ne Firma locker ruinieren.

Für sowas gibts Versicherungen.

C
1.214 Beiträge seit 2006
vor 9 Jahren

Wenn man jeden Methoden Ein- und Ausgang logt, gehe ich ganz stark davon aus, dass Clean-Code Principles , UnitTests und Code-Reviews absolute Fremdbegriffe sind, da wäre man mit Refactorings und Schulungen besser dran, als nachträgliche Flickschusterei und Schuldzuweisungen über Loggings

Ich meinte übrigens nicht, dass wir jede Methode loggen. Das geht eh nicht, da gibts auch viel zu viele Low Level Methoden, bei denen es auf Performance ankommt und man mit den Daten eh nichts anfangen könnte (z.B. Featureerkennung in Meshes, was will man da großartig loggen?). Aber der grundsätzliche Abflauf wird schon geloggt, so in der Art, habe vom System eine Datei bekommen, ist eine STEP Datei -> Variante 1, Features sind schon drin. STL Datei bekommen -> Variante 2, Features müssen erkannt werden. Bei Variante 2 Mesh schaut kaputt aus -> Untervariante: versuchen Mesh zu reparieren. Dann gehts z.B. irgendwo weiter und man muss irgendwas mit Daten aus SAP anreichern, dann wird es auch geloggt und hier dann vielleicht auch die Daten selber, die man bekommen hat.
Wie der Code bei Leuten ausschaut, die jede Methode loggen, weiß ich nicht, aber grundsätzlich finde ich Ablauflogging schon wichtig und das auch nichts mit Unit Tests oder Reviews zu tun. Das sind keine "Fehler". Das sind hochkomplexe Prozesse, die unmöglich grundsätzlich absolut "fehlerfrei" laufen können. Fehler hab ich absichtlich in Anführungszeichen geschrieben, weil es müssen keine Fehler in der Software oder im Prozess sein. Das Endergebnis mag vielleicht in einigen Punkten von den Erwartungen abweichen. Und es muss auch nicht gleich um Schuldzuweisungen gehen, sondern vielleicht darum, auf Probleme aufmerksam zu machen und die zu beheben. Wenn die Normierungsstelle etwas falsch einträgt und das erst dem Ingenieur auffällt, ist es vielleicht nicht uninteressant zu wissen, wo die falschen Daten herkamen. Oder könnte sein, dass wir z.B. ein CAD Modell erzeugen, dass irgenwelche Quaitätsnormen (VDA usw.) nicht erfüllt. Kann auch viele Gründe haben, warum das Modell so erzeugt wurde.

P
Palin Themenstarter:in
1.090 Beiträge seit 2011
vor 9 Jahren

@Fzelle: Da hab ich dich sicher missverstanden, aber in meiner Ausbildung war es wirklich so das ich bei JEDER Methode, den ein und Ausstieg mit Loggen musste. Deshalb habe ich, da vielleicht ein wenig Überreagiert. Und ich denke es ist einfach sinnvoll, davon Abzuraten.

Wie im einzelnen geloggt werden sollte, hängt meist von den Anwendungsszenarien ab. Und die können sich, wie sicher jeder von uns weiß, drastisch unterscheiden.

Ein Beispiel ist ja, das eingangs Szenario. Klassen Bibliotheken, die ich 3. zur Verfügung stelle.
Diese sollten, meines Erachtens, im allgemeinen nicht Loggen sondern, besser eine Exception werfen. Wenn der Entwickler meint, sie sollten auch Loggen, muss er es meines Erachtens begründen können.

Mein Allgemeinen Logging Ansatz, habe ich ich ja schon Beschrieben. Ich denke einen wirklichen Mehrwert aus der Diskussion bekommen wir, wenn man mal Beschreibt wie und warum man in seinem Szenario so Loggt.

Mit freundlichen Grüßen
Björn

Sollte man mal gelesen haben:

Clean Code Developer
Entwurfsmuster
Anti-Pattern

F
10.010 Beiträge seit 2004
vor 9 Jahren

Ich denke da hast du aber den Sinn von loggen nicht gut beigebracht bekommen.

Beim Loggen geht es nicht ( nur ) darum Fehler "aufzuschreiben" sondern darum einen code den man nicht sieht nachvollziehen zu können.
Gerade nebenläufiger Code geht fast gar nicht vernünftig zu debuggen
oder bei Server Software oder einem Dienst ist das meist die einzige Möglichkeit einen Fehler oder auch nur einen Bottleneck zu finden.
Und bei Firmware ( mache u.a. FW für Türschlösser ) kannst du sowieso das meiste vergessen was du auf dem PC machst.

Auch bietet fast jede vernünftige Bibliothek verschiedene LogLevel an, wobei der Error meist eine sehr hohe Priorität hat, aber darunter gibt es von Info über Verbose fast alles.
Schau dir mal den Enum System.Diagnostics.TraceEventType an.
Das zusammen mit TraceFilter und TraceSource kann dir zur Laufzeit keine oder alles deine SW anzeigen.

49.485 Beiträge seit 2005
vor 9 Jahren

Hallo zusammen,

während der Ausbildung kann es durchaus sinnvoll sein, jede Methode zu loggen. Die Projekte sind klein und die Ah-Effekte gerade am Anfang besonders groß. Daraus würde ich aber nicht schließen, das der Ausbilder damit die Aussage treffen sollte, dass man später in der Praxis immer so loggen sollte.

Ich wollte aber noch auf einen anderen Punkt hinweisen: Wenn man (Arbeits-)Abläufe loggt, sollte man immer den Betriebsrat einbeziehen. Solche Logs eignen sich dann oft zur Mitarbeiterüberwachung und die ist in zumindest Deutschland in vielen Fällen verboten und nur in Ausnahmesituationen gestattet. Wenn es eine Betriebvereinbarung gibt oder eine solche ausgehandelt wird, weiß jeder, woran er ist und was erlaubt und verboten ist, u.a. was genau geloggt werden darf und wer die Logs zu welchen Zwecken einsehen darf.

herbivore

P
Palin Themenstarter:in
1.090 Beiträge seit 2011
vor 9 Jahren

@herbivore:
Ich rede da schon vom Produktive Code, der zu den Kunden gegangen ist und jeder Entwickler war dazu angehalten.

@FZelle:
Loggen verändert das Laufzeit verhalten des Quellcodes. Und je mehr du Loggst je stärker ändert sich das Verhalten. Also wenn ich Race Conditions oder andere Probleme bei neben läufigen Qellcode habe, ist es nicht zielführend viel zu Loggen, sondern gezielt zu Loggen. Das gleiche gilt auch für Bottelnecks.

Für mich ist es durch aus sinnvoll zu sagen je schlechter ein System zugänglich ist je mehr Logge ich.
Soviel zu Loggen, das ich den Ablauf immer verfolgen kann, würde ich aber nicht zu einem Standard erheben. Und wirklich jeden Methoden Aufruf zu Loggen halte, ich für grundlegend Falsch. Aber soweit ich es verstanden habe macht es hier ja auch keiner.

MFG
Björn

Sollte man mal gelesen haben:

Clean Code Developer
Entwurfsmuster
Anti-Pattern

16.806 Beiträge seit 2008
vor 9 Jahren

Loggen verändert das Laufzeit verhalten des Quellcodes.

a) viel weniger als Du denkst
b) Kosten-/Nutzen-Faktor

Wie gesagt. Selbst sehr breit aufgestellte Software im Server-Bereich lässt sich super effizient und performant loggen.
Das, was Zeit frisst, ist nicht das loggen selbst, sondern der Commit zB auf das Dateisystem.
Deswegen nutzt man in solchen Umgebungen abgekoppelte Systeme, die _quasi _=0 Peformance kosten.

Also wenn ich Race Conditions oder andere Probleme bei neben läufigen Qellcode habe, ist es nicht zielführend viel zu Loggen, sondern gezielt zu Loggen. Das gleiche gilt auch für Bottelnecks.

Denke ich nicht. Es macht durchaus kurzfristig sinn einen gesamten Bereich zu loggen. Vor allem bei mehreren Threads.
Da sieht man einfach viel mehr, als wenn man irgendeine Weiche nicht loggt und dann was übersieht. Es tut auch nicht weh, mehr zu loggen. Meist schmerz es vor allem den Support, wenn man etwas nicht loggt.

In großen Umgebungen wie Amazon es darstellt wird so gut wie jeder Request "gemonitort".
Ist der Vorgang nicht wie in der Definition, blinkt eine Lampe Rot und alles in diesem Bereich wird für die Zeit X geloggt. In solchen Umgebungen gibt es keine Zufälle.

W
872 Beiträge seit 2005
vor 9 Jahren

Wie vorher schon gesagt, geht der Trend zu Semantic Logging.
Gibt jetzt auch einen Semantic Logging Application Block vom Patterns & Practice Team von Microsoft - da findet sich auch einige Videos zu dem Thema - den Vergleich mit der Telemetrie bei Fahrzeugen finde ich sehr gelungen für das Ziel des Loggings.

P
40 Beiträge seit 2011
vor 9 Jahren

Und wirklich jeden Methoden Aufruf zu Loggen halte, ich für grundlegend Falsch. Aber soweit ich es verstanden habe macht es hier ja auch keiner.

Doch bei uns in der Firma wird bei den migrierten Anwendungen jeder Methodenaufruf geloggt (beim Betreten und Verlassen der Methode). Ebenso einige Methoden in unserem Framework (auf dem die Anwendungen aufbauen).
Ebenso werden Zuweisungen geloggt (Name des Items, alter Wert, neuer Wert).
Leider ist es notwendig da wir nicht die Entwickler der Anwendungen sind. Bei Fehler können wir leichter nachvollziehen welcher Code ausgeführt wurde und wo ein Wert möglicherweise geändert wurde und wie sich der Wert geändert hat.

Gerade haben wir ein Projekt bei dem wir ObjectStar nach Java migrieren -> ObjectStar erlaubt ähnlich PHP dynamische Aufrufe anhand des Wertes den eine Variable hat.

Dieses "intensive" Logging ist natürlich nur während der Entwicklung und zum Testen aufgedreht. In der Produktion werden dann nur noch kritische Stellen und Fehler geloggt.
Bei uns eben den Vorteil: ohne die Anwendung wirklich zu kennen können wir diese nachvollziehen. Bei Fragen an die eigentlichen Entwickler können wir leichter erklären/zeigen wo wir das Problem vermuten usw.

P
Palin Themenstarter:in
1.090 Beiträge seit 2011
vor 9 Jahren

Ebenso einige Methoden in unserem Framework (auf dem die Anwendungen aufbauen).

einige Methoden << wirklich jeden Methoden

@Abt
Wie schon mehrfach erwähnt, beziehen sich meine Aussagen auf Standardszenarien.

Ich hab jetzt mal gegoogelt, ob ich da was passendes zu finde. Für das ist zwar jetzt für Java, aber für C# erwarte ich da ähnliche Tendenzen. Apache Log4j 2: Performance
Log4 2 Deaktiviertes Loggen: 3ns Logeintrag: 1542ns. Das ist um den Faktor 500 Langsamer.

Wenn du jetzt viel Loggst (jeden z.B. Methoden Aufruf), sagen wir 0,1% der Zeit, also bei 1000ms eine ms und du dann denn Logger aktivierst brauch er 500ms (1499 ms Gesamtzeit), was dann ca. 33% der Zeit ist. Das ist meines Erachtens schon ein gewaltiger unterschied.

Hier eine Artikel zur Responszeit von ASP Seiten, verglichen wird ohne Logging (74 ms) und mit Logging (134 ms), da der Code nicht eingesehen werden kann ist die Aussagekraft des Artikels schwer zu bewerten. APPDynamics:The Real Cost of Logging

MFG
Björn

Sollte man mal gelesen haben:

Clean Code Developer
Entwurfsmuster
Anti-Pattern

16.806 Beiträge seit 2008
vor 9 Jahren

Jo - und in .NET kannst Du das equivalente nLog auf auf async=true stellen und Du hast an dieser Stelle "keine" Performance-Einbußen; max 1.5x
Was bei dem jLog es eben langsam macht ist, dass dort direkt commited wird. Und das ist überall der Flaschenhals. Nimsmt ne Queue dazwischen und nen exta Trask zum Write hast das Problem nahezu behoben.

Kleine Schalter, große Wirkung.

P
Palin Themenstarter:in
1.090 Beiträge seit 2011
vor 9 Jahren

Artikel gelesen?

Nur durch das Concate des String und die erst zu Prüfen ob geloggt werden soll vergehen grob 188 ns. Ok ist dann nur noch der Faktor 60. Erleitere doch bitte mal wie du auf den Faktor 1.5 kommst.

Und ob das mit der Queue, so eine gute Idee ist weiß ich nicht. Da sind im Zweifel die Logeinträge weg. Ob wohl Grade der letzte Logeintrag wichtig sein könnte?

Sollte man mal gelesen haben:

Clean Code Developer
Entwurfsmuster
Anti-Pattern

16.806 Beiträge seit 2008
vor 9 Jahren

Da wären wir beim Thema Verhältnismäßigkeit und Kosten/Nutzen.
Eine Addition loggt man nicht. Das Beispiel ist mehr als utopisch. Äpfel und Birnen-Vergleich quasi.

In einer normalen Welt loggst Du Prozesse/Stellen im ms-Bereich und da fallen 50ns nicht auf.

Ich denke da hast du aber den Sinn von loggen nicht gut beigebracht bekommen.

P
Palin Themenstarter:in
1.090 Beiträge seit 2011
vor 9 Jahren

Mit den 0,1% meine ich natürlich im Verhältnis zum eigenen Code und Grundlegenden Standard Operationen.

Das ist dann eher 1 Logeintrag pro 2.000.000 Additionen.

Sollte man mal gelesen haben:

Clean Code Developer
Entwurfsmuster
Anti-Pattern

O
79 Beiträge seit 2011
vor 9 Jahren

Logging ist doch nur während der Entwicklungsphase und in den ersten Laufzeit-Tagen bzw. -Wochen wirklich noch für die Fehlersuche.

Danach dient das Logging als Nachweis, das die eigene Software sauber funktioniert und somit "andere" Schuld sind, das es plötzlich nicht mehr funktioniert. Darum sind die Logfiles auch Anfangs kompakt, nur für den Entwickler verständlich 😉 und schnell geschrieben. Ist man dann in der "Beweisphase" angekommen, explodieren die Logfiles, weil man plötzlich wirklich alles mitloggen muß und das auch noch so verständlich, das die Troubleshooter, die nun mit der Software umgehen sollen, das auch kapieren.

49.485 Beiträge seit 2005
vor 9 Jahren

Hallo OlafSt,

dass Logging nur zur Anfang zur Fehlersuche ist, ist mir eine zu statische Sicht. Nach jeder Wartung und jedem Update können potenziell neue Fehler auftreten. Außerdem treten auch schon lange enthaltene Fehler manchmal erst nach einem geänderten Nutzungsverhalten auf, z.B. wenn ein neuer Mitarbeiter die Software anders nutzt.

In einer idealen Welt würden gar keine Fehler auftreten. In der realen Welt können sie zu jedem Zeitpunkt auftreten.

herbivore

P
Palin Themenstarter:in
1.090 Beiträge seit 2011
vor 9 Jahren

Hallo OladSt,

die Fehlerfreiheit von komplexen Softwaresystemen ist nicht nachweisbar. Nur das vorhanden sein von Fehlern. 😉

Ich denke mal die Bash Lücke (ShellShock), die nach 25 Jahren gefunden wurde, ist ein Beispiel dafür, das egal wie Lange etwas schon läuft es immer noch Fehler Enthalten kann. (Fehler sind für mich auch Sicherheitslücken und verhalten von Software welches so nicht vorgesehen/geplant war, das mag aber jeder so Interpretieren wie er will).

Ich habe auch noch keinen Entwickler kennengelernt der keine Fehler macht. Ich habe nur Entwickler kennengelernt, die Behaupteten keine Fehler zu machen und deshalb keine Unit Tests schreiben wollten. Und Entwickler die wussten, das sie Fehler machten und deshalb Unit Test schrieben. (Und natürlich viele Fassetten dazwischen.) Erstere hatten, dann im Allgemeinen mehr Fehler in ihrem Quellcode.

Was mich angeht, ja ich mache Fehler, dessen bin ich mir auch bewusst und deshalb schreibe ich Unit Test. Ich bin mir aber auch im klaren darüber, das trotzdem noch Fehler in meiner Software sein können / sind. Deshalb mache ich mir auch Gedanken, wie ich sinnvoll mit Exception und Logging umgehen.

MFG
Björn

p.s.
Bei der Gelegenheit ist mir ein alter „Witz“ wieder eingefallen:
Im Rahmen einer Qualitätsstudie, werden alle Entwickler zu einem Seminar geschickt.
Nach der obligatorischen Vorstellung, stellt die Leiterin die Frage: „Wenn Sie ein Flugzeug so konstruieren würden, wie Sie ihre Softwareprogrammieren. Wer von ihnen würde mit dem Flugzeug fliegen?“.
Die meisten Entwickler senken verschämt den Blick. Nur einer hebt, zu ihrer Überraschung, die Hand. Worauf sie verdutzt nachfragt, wie so er den Einsteigen würde.
Worauf er Antwortet: „Mein Flugzeug, würde gar nicht erst Starten, wenn noch ein Fehler drin ist.“

p.p.s.
@Abt:
Eigentlich bist du mir noch einen Beleg dafür schuldig, das du es hinbekommst einen sinnvolle Aufruf für einen Log-Eintrag in maximal dem 1.5x Fachen, einer Boolean Prüfung hinzubekommen. Ich betrachte, dass als einfach nicht Machbar (beim aktuellen technischen Stand.).

Sollte man mal gelesen haben:

Clean Code Developer
Entwurfsmuster
Anti-Pattern

49.485 Beiträge seit 2005
vor 9 Jahren

Hallo Palin,

Abt hat im Grunde schon geschrieben, wie seine Aussage gemeint war. Auf den Faktor (oder in die Größenordnung) kommt man, wenn man einerseits die reine Logging-Operation optimiert und anderseits die Nutzoperation im Schnitt nicht nur aus einer oder wenigen Elementaroperationen besteht. Letztlich zählt aber nicht der Faktor, sondern die resultierende Performance. Wenn also tatsächlich eine Benutzeraktion nur eine einzige Elementaroperation erfordert, und die Laufzeit der Benutzeraktion sich durch Logging um Faktor 1000 verlängert, dass ist nichts mal 1000 meistens immer noch nichts. Letztlich war die Kernaussage von Abt, dass angemessenes Logging zu vertretbarem (Laufzeit-)Kosten realisieren kann. Über konkrete Faktoren kann man sowieso nur sprechen, wenn man es auf dem entsprechenden Zielsystem probiert. Und ich glaube da hat Abt ganz andere im Sinn als du (Stichwort: große Umgebungen).

herbivore

16.806 Beiträge seit 2008
vor 9 Jahren

Als erstes muss ich mal sagen, dass ich niemanden irgendetwas schuldig bin - vor allem wenn er es nicht versteht 😉

die Fehlerfreiheit von komplexen Softwaresystemen ist nicht nachweisbar. Nur das vorhanden sein von Fehlern. 😉

Ist ein irrglaube. Mit entsprechendem Aufwand sind einige Firmen diesbezüglich sogar verpflichtet. Rate mal, wieso die NASA derzeit massenhaft CPUs aus den 90er Jahren sucht.
Und ich will jetzt kein "das ist aber eine Ausnahme" hören. Das gilt für alle Bereiche. Nur steigt der Aufwand diesbezüglich eben exponentiell.

Aber mein Beispiel dennoch (beides simpel ohne Optimierungen):
Synchrones Logging mit einem Zeitverlust von 7,8ms

private static void Main( string[ ] args )
{
    var sw = Stopwatch.StartNew( );

    Trace.WriteLine( "Log" );

    var total = sw.Elapsed;

    Console.ReadKey( );
}

Und die asynchrone Variante mit einem Zeitverlst von 0,0021ms

private static BlockingCollection<String> logBag = new BlockingCollection<string>( );

private static void Main( string[ ] args )
{
    var sw = Stopwatch.StartNew( );

    logBag.Add( "Log" );

    var total = sw.Elapsed;

    Console.ReadKey( );
}

Sinn: Logs werden an einen sehr schnellen Container weiter gereicht und dort gepuffert. Ein Task (im Beispiel nicht vorhanden, da hier irrelevant) würde nun die Elemente aus der Collection holen und comitten. Somit hat das Logging keine nennenswerten Auswirkungen auf das Laufzeitverhalten.

Resultat
7,8ms gegenüber 0,0021 ms = Faktor 3714,286 (inkl. potenzielle Messfehler von Stopwatch) wenn ich mich nirgends verrechnet habe.
Und Trace gehört noch zu den schnellen Wegen. Je langsamer der synchrone commit desto höher natürlich der Einspar-Faktor durch asynchrones Verhalten.
Mit einer einfachen Datei kann das schnell mal Faktor >100.000 sein.

Wenn man das mit einer simplen Addition vergleicht, die bei mir 0,0016 ms dauert (= x1,3), finde ich das gar nicht so schlecht und kommt meiner "Behauptung" von x1.5 recht nahe bzw. unterbietet diese sogar; nicht?
Abweichungen bei anderen Rechnern natürlich möglich - habs jetzt auf einem simplen Notebook und nicht auf einem Echtsystem (Server) getestet; mein Rechner ist ein Latitude E6430 (i7)

Den Rest hat herbivore korrekt wieder gegegeben.

49.485 Beiträge seit 2005
vor 9 Jahren

Hallo Abt,

gemeint war wohl die allgemein anerkannte Aussage, dass sich alleine durch Testen von (nicht-trivialen) Softwaresystemen nur die Anwesenheit, aber nicht die Abwesenheit von Fehlern nachweisen lässt.

Und selbst wenn die Korrektheit eines Systems durch formale Methoden bewiesen wird, gibt es immer noch die - nicht nur theoretische - Möglichkeit, dass der Beweis (oder die verwendenden Werkzeuge) fehlerhaft sind. Die Korrektheit von Beweisen kann man nicht beweisen, bzw. beißt sich die Katze da in den Schwanz. Absolute Sicherheit gibt es also tatsächlich nie, aber man kann den 100% zumindest sehr nahe komme.

herbivore

P
Palin Themenstarter:in
1.090 Beiträge seit 2011
vor 9 Jahren

@Abt
An dem Punkt hast du die Kosten für den Kontext wechsle der Daten noch nicht berücksichtigt, die sollen ja in einem anderen Thread geschrieben werden.

Auch ging es um Sinnvolle Log Einträge, da bei einer FiFo Liste nicht sicher gestellt ist, in welcher Reihenfolge und wann die Einträge erstellt werden, brauchst du noch in Irgendeiner Form einen TimeStamp. Den Faktor 1,5 im Vergleich zu einer Boolean Prüfung halte ich für nicht Realisierbar.

Sollte man mal gelesen haben:

Clean Code Developer
Entwurfsmuster
Anti-Pattern

16.806 Beiträge seit 2008
vor 9 Jahren

Die Kosten für den Kontextwechsel sind irrelevant, da es - im Prinzip - keinen gibt.
Es wird in eine Queue geschrieben, die davon unberührt ist; klassisches Producer Consumer Verhalten - und die BlockingCollection ist hier die schnellste in Sachen Thread-Sicherheit.
Nach dem Add() spielt es für die aktive Umgebung keine Rolle mehr. Das Schreiben hat KEINE Auswirkungen auf die Anwendung, da in einem extra Task.

Das Beispiel zeigt bzw. misst alle ausführenden, relevanten Informationen und Vorgänge.

Die Reihenfolge bei einer BlockingCollection ist garantiert.
Wie die Logs gestaltet sind; dazu gibt es keine pauschale Antwort; die einen Loggen den kompletten Trace, die anderen nur einen Text (Stichwort: Kosten/Nutzen. Wozu den Stack loggen wenn es mir zB um die Reihenfolge geht?) Da brauchen wir nun auch nicht das Haar in der erstklassigen Suppe suchen.

Den Faktor 1,5 im Vergleich zu einer Boolean Prüfung halte ich für nicht Realisierbar.

Wie loggst Du denn bitte?

if( myBool == true )
{
   Log("Meine Variable hat den tolle Wert true");
}
else
{
   Log("Meine Variable hat den tolle Wert false");
}

oder

   Log("Meine Variable hat den tolle Wert " + myBool);

🤔

Komm ich immer noch auf einen Faktor von 1,2-1,4 bei einem einfachen Text-Log.

P
Palin Themenstarter:in
1.090 Beiträge seit 2011
vor 9 Jahren

Ich hatte eher an so was gedacht.

if( IsDebug)
{
    _logger.Debug(String.Format("{0} : Dieser Text wird nur geschrieben wenn IsDebug True ist", DateTime.Now());  
}

Und das sich da Laufzeitunterschiede ergeben, zwischen IsDebug True und Fals, denke ich ist ersichtlich. Weswegen ich es nicht für unbedingt für sinnvoll halte, das Loggen zu benutzen um z.B. Race Conditions aufzuspüren.

Sollte man mal gelesen haben:

Clean Code Developer
Entwurfsmuster
Anti-Pattern

49.485 Beiträge seit 2005
vor 9 Jahren

Hallo Palin,

je mehr sich das Laufzeitverhalten durch das Logging ändert, desto eher findet man Race-Conditions, die ohne Logging verborgen geblieben wären. 😃 Wenn das Logging eh standardmäßig an ist, dann ist das Laufzeitverhalten mit Logging auch das normale. Und dann werden auch genau die Race-Conditions protokolliert, die unter diesen Umständen nunmal auftreten. Und für genau die interessiert man sich letztlich auch. Race-Conditions, die unter diesen Umständen nicht auftreten, sind genau so viel oder wenig interessant, wie andere vorhandene Fehler, die in der Praxis dann aber eben doch nicht auftreten.

Race Conditions systematisch finden, kann man eh nicht oder nur begrenzt durch Tests, sondern da braucht man andere Analysen. Durch permanentes Logging kann man immerhin die tatsächlichen auftretenden Race-Conditions protokollieren.

herbivore

EDIT: Mit "Analysen" im vorigen Absatz sind genau die "analytisches Ansätze" gemeint, die du im folgenden ansprichst. [EDITEDIT]Anscheinend meinen wir doch nicht das gleiche; ich meinte u.a. solche (WorstCase-)Analysen, wie ich sie z.B. in SyncQueue <T> - Eine praktische Job-Queue durchgeführt habe.[/EDITEDIT] Nur reden wir ja beim Logging in Produktion immer über die in der Software trotz alle Anstrengung bei der Entwicklung und der Qualitätssicherung verbliebenen Fehler. Außerdem liegt es in der Natur der Sache, dass man Race Condition gerade nicht einfach und verlässlich "ausschalten" (und auch nicht "einschalten") kann, sondern dass sie oft sporadisch und in Abhängigkeit vieler verschiedener Faktoren eintreten (oder nicht eintreten). Weder durch das Einschalten noch durch das Ausschalten von Logging kann man Race Conditions verhindern. Durch permanentes Logging kann man sie aber zumindest protokollieren.

P
Palin Themenstarter:in
1.090 Beiträge seit 2011
vor 9 Jahren

Was du findest sind Race Conditions, die durch das Logging entstanden sind.
Die zu beheben ist ganz Einfach, stell das Logging ab.

Ich ziehe da andere Analytische ansetze vor.

Sollte man mal gelesen haben:

Clean Code Developer
Entwurfsmuster
Anti-Pattern

16.806 Beiträge seit 2008
vor 9 Jahren

Irgendwie redest Du wirres Zeug.
Wenn durch Logging Race Conditions entstehen, kann das auch durch alle anderen Elemente passieren.
Manchmal hast Du wirklich gute Beiträge aber bei diesem Thema irgendwie.. anders 🤔

49.485 Beiträge seit 2005
vor 9 Jahren

Hallo Palin,

ich bin auf deine Einwände ernsthaft eingegangen. Deine letzte Antwort zeigt jedoch keine Anzeichen von Ernsthaftigkeit. Eine weitere Diskussion auf dieser Ebene nützt wohl keinem. Zumal Racing Conditions nur ein Randproblem des Thema eigentlichen Thema Loggings sind.

herbivore

P
Palin Themenstarter:in
1.090 Beiträge seit 2011
vor 9 Jahren
Hinweis von herbivore vor 9 Jahren

Was in dem folgenden Beitrag behautet wird, ist offensichtlich nicht das, was vorgeschlagen wurde, zumal das Zitat sinnentstellend gekürzt wurde. Gekürztes Zitats durch die vollständige - natürlich ironisch gemeinte - Originalaussage ersetzt.

Davon abgesehen entsteht eine Race Conditions überhaupt nicht durch das Logging (weshalb sich ein solcher Nachweis auch nicht führen lässt), sondern durch fehlende Synchronisation im Code. Auch wenn Race Conditions durch das Ein- oder Ausschalten von Logging ihre negativen Auswirkungen zeigen oder nicht mehr zeigen, sind sie doch in jedem Fall weiterhin vorhanden, solange der Code nicht korrigiert wird.

Das bezieht sich natürlich auf herbivores Ausage.

je mehr sich das Laufzeitverhalten durch das Logging ändert, desto eher findet man Race-Conditions, die ohne Logging verborgen geblieben wären. 😃

Der Klassiker ist natürlich beim Kunden treten Race-Conditions auf, man aktiviert das Logging und sie treten nicht mehr auf.
herbivore schlägt ja hier vor, das Laufzeitverhalten durch Logging, so weit zu ändern das Race-Conditions auftreten. Ja ich habe dann Nachweislich Race-Conditions, die sind aber durch das Logging entstanden. Diese verschwinden aber auch wieder, wenn ich das Logging entferne.

Und ja auch weitere Elemente, können das Laufzeitverhalten des Codes ändern. Es macht ja auch schon einen unterschied ob ich einen StringBuilder verwende oder Strings einfach "Addiere".

Meiner Meinung nach ist es bei Problemen die mit dem Laufzeitverhalten zusammen hängen (z.B. Race-Conditions, Preformancem u.s.w). Ziel führender das Laufzeitverhalten, möglichst wenig zu beeinflussen. Also nicht viel zu Loggen, sondern gezielt.

Bei dem Analytischen Ansatz stimme ich dir Komplett zu. Probiere das Problem zu erkennen und schreibe Log-Eintrage, die dir dabei helfen es zu Lösen.

Danke auch noch für das versteckte Kompliment. Ich weiß es sehr zu schätzen, da ich dich für sehr Kompetent halte.
Ich gehöre zu den Typischen Leuten, die nicht schlecht im naturwissenschaftlichen- und technischen Bereich sind. Aber auf dem Kriegsfuß mit Rechtschreibung und Grammatik stehen. Was gerade bei Foren Beiträgen, doch zu Missverständnissen führen kann. Aber ich denke, das ich hier schon grundlegend richtige Ratschläge gebe.

Sollte man mal gelesen haben:

Clean Code Developer
Entwurfsmuster
Anti-Pattern

C
1.214 Beiträge seit 2006
vor 9 Jahren

je mehr sich das Laufzeitverhalten durch das Logging ändert, desto eher findet man Race-Conditions, die ohne Logging verborgen geblieben wären. 😃

Der Klassiker ist natürlich beim Kunden treten Race-Conditions auf, man aktiviert das Logging und sie treten nicht mehr auf.

Ich muss sagen, zumindest gefühlt ist das auch der Fall, der viel häufiger auftritt. Wir haben auch öfter mal Timing Probleme. Kaum versucht man das irgendwie einzugrenzen und baut paar zusätzliche Logausgaben ein, schon lässt sich das Problem nicht mehr nachvollziehen.

Gelöschter Account
vor 9 Jahren

Logging scheint ja ein ziemliches Reizthema zu sein(und irgendwie auch zurecht)

Ich glaube FZelle hat es schon richtig bemerkt. Logging dient dazu einen fehlerhaften Ablauf zu diagnostizieren, also so eine Art Runtime(Stack Trace) Ersatz für den Debugger. Logging dient dazu das der Entwickler anhand der Log Einträge darauf schliessen kann was aufgrund eines fehlerhaft designten Ablauflogik falsch gelaufen ist.
Ich als Entwickler muss anhand der Log Einträge den Fehler diagnosztieren können, das ist zumindest der Wunsch hinter dem Logging.
Solche Ablaufprotokolle können aber aus meiner Sicht keine Auskunft über QA Issues, also NullReferenceExeption, ArgumentNullException oder ähnliches geben. Das Logging kann immer nur erwartet Fehler ausreichend hilfreich protokollieren.

Leider wird nach meiner Erfahrung das Logging zu oft genau dafür verwendet, irgendwelche unerwarteten Fehler zu diagnostizieren was in der Regel nicht klappt. Der Entwicker muss jetzt den Debugger anschmeissen und der Kunde muss jetzt noch am besten seine Datenbank rüberschieben.....

Das krasse Gegenmodell ist das man einfach jede Methode mit einem Begin und einem End Log versieht(sowas würde ich mir von der .NET Runtime ehrlich gesagt wünschen, gerade in den Szenarios wo Logging zeitkritisch ist wie hier schon angemerkt wurde. Also so eine Art Diagnostic Build)

16.806 Beiträge seit 2008
vor 9 Jahren

Beim Azure Friday wurde das Security Logging and Audit Log Collection within Azure behandelt - für Entwickler in größeren Umgebungen ziemlich interessant.