ich habe irgendwie keinen Bock mehr auf "Logging to file".
Mag sein, dass das Unix-Konzept die letzten hundert Jahr gut funktioniert hat, aber zB Apache Logs zeilenweise in eine Datei zu schreiben hat deutlich Nachteile.
1: Logrotate. Nervt.
2: Unstrukturiert. Das Log ist eine einfach ascii-Zeile. Ich hätte aber gerne Key-Value Paare.
Auch im open source Bereich ist die Werbemaschine kräftig am Laufen, so dass unklar ist, was sinnvolle Technik ist und was Marketing-Bla-Bla ist.
Frage 1: Könnt ihr die Aussage (Keinen Bock mehr auf "Logging to file") nachvollziehen?
Frage 2: Hat jemand schon eine Alternative zu Logfiles ausprobiert. Ein Erfahrungsbereicht aus der Praxis wäre interessant.
Gruß, Thomas
Hi Thomas,
wie sehen denn Anforderungen und Umgebung aus? Grundsätzlich:
Am 10.04.19 um 09:54 schrieb Thomas Güttler:
Frage 1: Könnt ihr die Aussage (Keinen Bock mehr auf "Logging to file") nachvollziehen?
Jein. "Logging to file" ist für mich eigentlich nur Implementationsfrage. Manchmal passt die besser zu den Anforderungen, manchmal schlechter. Zweitens ist daher interessanter:
Frage 2: Hat jemand schon eine Alternative zu Logfiles ausprobiert. Ein Erfahrungsbereicht aus der Praxis wäre interessant.
Wir nutzen Elastic-Stack für Logging zusammen mit mannigfaltigen serverseitigen Anwendungen. Insgesamt sieht das wie folgt aus:
- Java-Module laufen in docker-Containern und sprechen via logstash direkt mit dem Logging-Server. Das ist elegant, weil dort Log-Nachrichten als JSON-Strukturen übergeben werden und serverseitig relativ leicht verarbeitbar sind.
- Nicht-Java-Module, Unix-Systemdienste, ... laufen wie gehabt lokal, dazu lebt auf jeder Maschine ein filebeat-Dienst, der einige dedizierte Logfiles beobachtet, Nachrichten dort 'rausnimmt und an den Logging-Server weiterleitet. Serverseitig gibt es hier Filter-/Vorverarbeitungsprozesse im logstash, die aus den Logfile-Zeileneinträgen auswertbare Dokumente machen.
Das funktioniert insgesamt *relativ* gut. Der Log-Server ist im Allgemeinen extrem robust und die Suche über alle Log-Daten über die Weboberfläche vereinfacht den Prozess erheblich.
Schmerzpunkte, die ich dort sehe:
- Zum einen (deswegen tendiere ich in unserem Use Case auch zu "logging to file ist nervig"): Man ist sehr schnell an einem Punkt, an dem man relativ viele und relativ komplexe Regeln hat, wie serverseitig die Logfiles zu zerlegen sind (speziell konfigurierte Logfiles im apache sind dort ein Standardbeispiel, bei denen ein Entwickler 'mal eben das LogFormat ändert und plötzlich der gesamte Prozess umfällt, weil die Information, die Du brauchst, plötzlich weiter vorn oder hinten in der Zeile steht). Dort ist das Logging von JSON-Strukturen schlicht etwas robuster und besser zu debuggen.
- Zum zweiten: Zugriff auf den Elastic Stack läuft als relativ schwere Anwendung über Kibana, respektive den Browser. Das ist eine andere Nummer, als an der Shell mal schnell ein Logfile durch verschiedene Tools zu pipen. Bietet mehr Möglichkeiten, aber kommt zu einem Preis.
- Der Elastic-Stack ist eine Infrastruktur, die man aufsetzen und pflegen will. Im *Allgemeinen* läuft der extrem robust, aber wenn man den updaten möchte oder *irgendwo* innerhalb des technischen Zoos dann doch mal Probleme auftreten, wird es schnell anstrengend.
Viele Grüße, Kristian
Hi,
ich spiele mal Advokat für den netten Herrn mit Dreizack im roten Jacket...
On Wednesday, 10 April 2019 09:54:55 CEST Thomas Güttler wrote:
ich habe irgendwie keinen Bock mehr auf "Logging to file".
Wer hat schon Bock auf Log.
Zeilenweise schreiben ist für uns Programmierer aber nun mal am einfachsten. Was nicht einfach ist wird nur gemacht wenn es dringend notwendig ist. Wenn Du Logs haben willst, dann lebe mit Files!
Mag sein, dass das Unix-Konzept die letzten hundert Jahr gut funktioniert hat, aber zB Apache Logs zeilenweise in eine Datei zu schreiben hat deutlich Nachteile.
1: Logrotate. Nervt.
Besser als kein Logrotate (Riesendatei) oder Windows Event-Logs.
2: Unstrukturiert. Das Log ist eine einfach ascii-Zeile. Ich hätte aber gerne Key-Value Paare.
Und ich hätte gerne ein Einhorn mit schottischer Flagge am Horn! ;-) (Gestern war "National Unicorn Day".)
Im wesentlichen werden Logs aus zwei Gründen geschrieben:
a) weil es ab und zu Ereignisse gibt, die für's Audit wichtig sind (Server hochfahren, Server runterfahren, Server umkonfiguriert, fataler Fehler).
b) Debugging: weil kein Programmierer fehlerfrei arbeitet, auch wenn er es nur ungern zugibt.
Bei a) kannst Du Joe Durchschnittsprogrammierer noch überreden das irgendwohin strukturiert zu schreiben. Seine Auffassung von "Wichtig" wird aber nur einen Bruchteil von dem abdecken was Du als wichtig betrachtest. Bei fatalen Fehlern gibt es aber keine Garantien!
Bei b) kannst Du entweder eine ganz einfache Lösung oder keine Lösung bekommen. Je schwieriger es ist ein Log zu schreiben umso unwahrscheinlicher ist es dass Du ein Log bekommst.
Das ist der Idealfall für den Programmierer: syslog(LOG_DEBUG,"frobnicating the fnord: %i -> %i",size,resultSize);
Das ist die Grenze des Erträglichen:
mLog = Logger.getLogObject(); mLog.print(LOG_DEBUG,"frobnicating the fnord: %i -> %i",size,resultSize);
Wenn ich sowas machen muss:
mCategory = LogManager.createCategory(LOG_APP|LOG_WEBSERVICE, "Frobnification Service",stringList{"size","resultSize"}); mLog = LogManager.getCategory(mCategory).getLogger(LOG_DEBUGLOGGER); values=mLog.createValues(); values.insert("size",size); values.insert("resultSize",resultSize); values.insert(LOG_TEXT,"frobnicating the fnord"); mLog.sendToDataBase(values);
...dann nehme ich als Programmierer printf und entferne die Anweisungen wieder bevor ich liefere. Soll der LUser doch core-Files schreiben!
Auch im open source Bereich ist die Werbemaschine kräftig am Laufen, so dass unklar ist, was sinnvolle Technik ist und was Marketing-Bla-Bla ist.
Na logisch muss man mächtig Werbung machen wenn man auch nur einen winzigen Bruchteil der Entwickler von einzeiligen Log-Anweisungen weglocken will!
Frage 1: Könnt ihr die Aussage (Keinen Bock mehr auf "Logging to file") nachvollziehen?
Im ersten Augenblick als Admin: ja, das klingt verführerisch.
Wenn ich darüber nachdenke: im Gottes Willen! Bleib mir mit diesem Teufelszeug vom Leib! ;-)
Frage 2: Hat jemand schon eine Alternative zu Logfiles ausprobiert. Ein Erfahrungsbereicht aus der Praxis wäre interessant.
Ich habe es noch nicht ausprobiert, aber: beim letzten Server-Crash war ich froh dass ich einfache ASCII-Logs hatte, sonst wären die Logs Schrott gewesen - Datenbanken (egal welcher Art) vertragen es im Allgemeinen nicht sehr gut wenn einzelne Blöcke durch Binär-Schrott ersetzt werden, weil das Dateisystem die Synchronisation nicht geschafft hat oder weil die Platte Probleme hatte. Ich als Admin mit grep und less bewaffnet kann leise vor mich hin fluchen und einfach weiterlesen...
Konrad
Hallo Konrad, *;
Du hast an einigen Punkten durchaus recht, nur zwei kurze Einwürfe:
Am 10.04.19 um 13:15 schrieb Konrad Rosenbaum:
Bei b) kannst Du entweder eine ganz einfache Lösung oder keine Lösung bekommen. Je schwieriger es ist ein Log zu schreiben umso unwahrscheinlicher ist es dass Du ein Log bekommst.
Doch. Die Lösung gibt es durchaus - nämlich genau dann, wenn dem Programmierer sehr gut verdeutlicht wird, daß *er* im Zweifelsfall derjenige ist, der die Anwendung debuggen muss, wenn sie sich in Production schief verhält, und daß das Logging, das er implementiert hat, dann das einzige Werkzeug ist, das *er* zur Verfügung hat. Das ändert diese Diskussionslage erfahrungsgemäß relativ schnell und diszipliniert durchaus ein wenig. ;)
Wenn ich sowas machen muss:
mCategory = LogManager.createCategory(LOG_APP|LOG_WEBSERVICE, "Frobnification Service",stringList{"size","resultSize"}); mLog = LogManager.getCategory(mCategory).getLogger(LOG_DEBUGLOGGER); values=mLog.createValues(); values.insert("size",size); values.insert("resultSize",resultSize); values.insert(LOG_TEXT,"frobnicating the fnord"); mLog.sendToDataBase(values);
...dann nehme ich als Programmierer printf und entferne die Anweisungen wieder bevor ich liefere. Soll der LUser doch core-Files schreiben!
Hmmmm. Erwartungshaltung wäre hier, daß sich das Logging-Framework Deiner Programmiersprache/-umgebung um diesen Kram kümmert. Mit slf4j+logback+logstash unter Java *ist* es im Zweifelsfall ein Einzeiler, und ob "hinten" die Statements als Zeile in ein Logfile oder als Key/Value-JSON in einen Logging-Server geschrieben werden, bekommt der Nutzer gar nicht mit. Das ist aber weniger eine Frage des Logging-Outputs denn vielmehr eine Frage der Fähigkeiten des Werkzeugs auf Entwicklerseite.
Interessant by the way: Bei Kram, der in docker-Containern läuft, scheint es insgesamt mehr und mehr Standard zu werden, aus der Anwendung heraus auch nicht mehr in Log*files*, sondern tatsächlich nur noch nach STDOUT/STDERR zu schreiben und sich darauf verlassen, daß docker die Logs in geeigneter Weise $IRGENDWOHIN tut - im Standardfall syslog.
Viele Grüße, Kristian
Hi,
On Wednesday, 10 April 2019 13:40:39 CEST Kristian Rink wrote:
Am 10.04.19 um 13:15 schrieb Konrad Rosenbaum:
Bei b) kannst Du entweder eine ganz einfache Lösung oder keine Lösung bekommen. Je schwieriger es ist ein Log zu schreiben umso unwahrscheinlicher ist es dass Du ein Log bekommst.
Doch. Die Lösung gibt es durchaus - nämlich genau dann, wenn dem Programmierer sehr gut verdeutlicht wird, daß *er* im Zweifelsfall derjenige ist, der die Anwendung debuggen muss, wenn sie sich in Production schief verhält, und daß das Logging, das er implementiert hat, dann das einzige Werkzeug ist, das *er* zur Verfügung hat. Das ändert diese Diskussionslage erfahrungsgemäß relativ schnell und diszipliniert durchaus ein wenig. ;)
Das funktioniert in kommerziellen Umgebungen unter zwei möglichen Vorraussetzungen:
a) Du hast genug Druckmittel gegenüber den Programmierern - aber auf der Negativseite hast Du dann auch eine große Fluktuation. Zumindest wenn der Rest der Arbeitsumgebung nicht absolut phantastisch ist.
b) Du hast hinreichende Mengen an Bestechungsschokolade. Und dann funktioniert das auch nur für kurze Fristen.
Programmierer sind eine Spezies die mehr Energie investiert faul sein zu können als andere in harte Arbeit. Auf diese Weise haben wir Programme mit so wunderbar lesbaren Namen wie "rm", "ls" oder "awk" bekommen... ;-)
Wenn ich sowas machen muss:
mCategory = LogManager.createCategory(LOG_APP|LOG_WEBSERVICE,
"Frobnification Service",stringList{"size","resultSize"});
mLog = LogManager.getCategory(mCategory).getLogger(LOG_DEBUGLOGGER); values=mLog.createValues(); values.insert("size",size); values.insert("resultSize",resultSize); values.insert(LOG_TEXT,"frobnicating the fnord"); mLog.sendToDataBase(values);
...dann nehme ich als Programmierer printf und entferne die Anweisungen wieder bevor ich liefere. Soll der LUser doch core-Files schreiben!
Hmmmm. Erwartungshaltung wäre hier, daß sich das Logging-Framework Deiner Programmiersprache/-umgebung um diesen Kram kümmert. Mit slf4j+logback+logstash unter Java *ist* es im Zweifelsfall ein Einzeiler, und ob "hinten" die Statements als Zeile in ein Logfile oder als Key/Value-JSON in einen Logging-Server geschrieben werden, bekommt der Nutzer gar nicht mit. Das ist aber weniger eine Frage des Logging-Outputs denn vielmehr eine Frage der Fähigkeiten des Werkzeugs auf Entwicklerseite.
Wenn man diesen Koloss in eine einzige Zeile packen kann, dann gerne.
Also sowas: Logging.debug("frobnicating...",LV(size),LV(resultSize));
Die Menge an Templates, Macros und anderen unschönen Konstrukten hinter "LV" kehren wir mal ganz gekonnt unter den Teppich...
Wie Du schon festgestellt hast hängt das alles stark vom Framework ab.
Der einzige Hinderungsgrund ist dass es bisher keinen neuen passenden Standard gibt. Der existierende Standard ist syslog und/oder dumme Dateien.
Interessant by the way: Bei Kram, der in docker-Containern läuft, scheint es insgesamt mehr und mehr Standard zu werden, aus der Anwendung heraus auch nicht mehr in Log*files*, sondern tatsächlich nur noch nach STDOUT/STDERR zu schreiben und sich darauf verlassen, daß docker die Logs in geeigneter Weise $IRGENDWOHIN tut - im Standardfall syslog.
Du wirst mich gleich hassen: ich liebe diese Lösung! Das ist doch mal was für faule Programmierer! Ich brauche noch nicht einmal ein minimales Log-Framework lernen.
Konrad
Hi auch;
Am 10.04.19 um 17:54 schrieb Konrad Rosenbaum:
a) Du hast genug Druckmittel gegenüber den Programmierern - aber auf der Negativseite hast Du dann auch eine große Fluktuation. Zumindest wenn der Rest der Arbeitsumgebung nicht absolut phantastisch ist.
b) Du hast hinreichende Mengen an Bestechungsschokolade. Und dann funktioniert das auch nur für kurze Fristen.
Carrot and sticks, glaube ich... Kekse und Schokolade schaden zumindest nie. Aber wenn im x-ten Sprint vor Release *wieder* ein kritischer Blocker in die Entwicklung eskaliert wird, Deine Planung zerschlägt, die internen Nutzer mit Fackeln vor der Bürotür stehen und Köpfe fordern (unter Umständen auch Deinen), Du *wiederkehrend* in kurzer Folge die 500er-Meldungen in den Logs des Loadbalancers siehst (jede ein unzufriedener Nutzer) und Du *überhaupt* keine Idee hast, warum das genau passiert, dann kann das auch läuternd sein.
Auf diese Weise haben wir bei uns sogar vergleichsweise verwegene Wünsche ins Logging bekommen, etwa eine Request-ID, die über Systemgrenzen hinweg mitgegeben wird, um am Ende irgendwie zusammenbekommen, *welche* Komponente an welcher Stelle denn nun in dem Prozess Ärger gemacht hat. Oder auch zipkin quer über den Stack, um bekannt problematischen Stellen zu messen, wo wieviel Zeit verbrennt. Verteiltes Profiling ist mindestens genau so wenig erfreulich wie verteiltes Logging, das war Frickelei par excellence, hat sich aber mehr als gelohnt. ;)
Wenn man diesen Koloss in eine einzige Zeile packen kann, dann gerne.
Also sowas: Logging.debug("frobnicating...",LV(size),LV(resultSize));
Die Menge an Templates, Macros und anderen unschönen Konstrukten hinter "LV" kehren wir mal ganz gekonnt unter den Teppich...
Ja. Schon. Aber (um in Java zu bleiben): Wenn ich
System.err.println("ERR: FOO failed... " + ex.getMessage());
schreibe, habe ich genau das: "FOO failed..." in einer Zeile Text, bestenfalls noch mit einem Timestamp, wenn ich gegen syslog oder via docker logge, schlimmstenfalls nichtmal das. Und ich muss den Loglevel händisch mitgeben.
Wenn ich ein Framework wie logback nutze, wird daraus etwas wie
LOG.error("FOO failed...", ex);
und in der Konsequenz auch nur eine Textnachricht, aber das Logging-Framework hat out of the box schon *deutlich* mehr Kontext, der an dieser Nachricht hängt und den ich auswerten kann (auch wenn ich das zeilenorientiert in ein Textfile wegschreibe): Klassenname, Thread des Prozesses, definierte Loglevel, Handling der 'reingestopften Exception und dergleichen mehr. Wenn ich das bei der STDOUT-Variante in jedem Aufruf mitgeben müsste, wäre das auch beizeiten nervig, würden die Entwickler wohl anfangen, sich Wrapper um STDOUT/STDERR zu bauen und damit letztlich ein eigenes Logging-Framework implementieren. Die Mühe kann man sich wohl schenken. ;)
Darüber hinaus habe ich auch "Vereinfachungen", die mir erlauben, eben Konstrukte wie die oben benannte Request-Id für einen bestimmten Scope einmal in den Logger zu packen und nicht jedes Mal wieder schreiben zu müssen. Das ist Einmal-Aufwand im Einstieg, der sich aber, glaube ich, relativ schnell lohnt.
Interessant by the way: Bei Kram, der in docker-Containern läuft, scheint es insgesamt mehr und mehr Standard zu werden, aus der Anwendung heraus auch nicht mehr in Log*files*, sondern tatsächlich nur noch nach STDOUT/STDERR zu schreiben und sich darauf verlassen, daß docker die Logs in geeigneter Weise $IRGENDWOHIN tut - im Standardfall syslog.
Du wirst mich gleich hassen: ich liebe diese Lösung! Das ist doch mal was für faule Programmierer! Ich brauche noch nicht einmal ein minimales Log-Framework lernen.
Du wirst überrascht sein, aber dort bin ich voll bei Dir. Eigentlich sollte man in 2019 über Logging als Entwickler nicht mehr diskutieren müssen. So gesehen finde ich den Weg, eine Komponente wie docker oder andere Infrastruktur für Logging-Ausgabe verantwortlich zu machen, auch gar nicht abwegig, auch in der Anbindung an so etwas wie Logstash/ElasticSearch als Alternative oder auch parallel zu lokalen Logfiles. Auch docker kann Logs in andere Systeme ausliefern und andere Formate als nur textuelle Logfiles bedienen.
Das Framework kann aber (siehe oben) dem Entwickler helfen, "schlankeren" Code zu schreiben, wenn viele Informationen geloggt werden müssen. Und am Ende des Tages ist ja auch die Frage: Ist Logfile zwingend gleich zeilenorientiertes ASCII? Man könnte ja auch JSON-Strings in lange Log-Zeilen schreiben oder (*hüstel*) kryptisches XML, wie unsere SAP MaxDB das zu tun pflegt. Wenn ich es "richtig" anstelle, dann ist aber auch nichts, womit sich der Entwickler zwingend behängen muss. Dann habe ich aber daraus auch keinen Ärger, weil es außerhalb der Einflußnahme von denen ist, die den Prozess dahinter potentiell nicht vorsätzlich, aber unbedacht kaputtmachen. Das hilft auch allen. ;)
Viele Grüße, Kristian
Am Mittwoch, 10. April 2019, 09:54:55 CEST schrieb Thomas Güttler:
ich habe irgendwie keinen Bock mehr auf "Logging to file".
Mag sein, dass das Unix-Konzept die letzten hundert Jahr gut funktioniert hat, aber zB Apache Logs zeilenweise in eine Datei zu schreiben hat deutlich Nachteile.
Ich würde vor dem Hintergrund 100-jähriger Geschichte empfehlen, die Kirche im Dorf zu lassen. In ein ASCII-File hinein geht es gut und zuverlässig. Heraus ebenfalls. Und man kann es (meistens) sogar ohne spezielle Hilfsmittel lesen.
Bei Key-Value-Paaren wird es sehr schnell sehr spannend, den nötigen EXAKTEN Match (a priori) zu kennen / zu haben.
Auch wenn ein Stockholm-Syndrom nicht von der Hand zu weisen ist, ist eine grep -Regex einfach geil. Per grep -C10 bekommt man sogar ohne speziellen Aufwand die Meinung der Nachbarn zum Vorfall mitgeteilt. Das ist gelegentlich hilfreich. grep -R fragt bei Bedarf gleich noch den ganzen Block ab.
Die Mittel, aus einem Textfile eine Datenbank zu machen, gibt es. Der Speicherdarf wird i.a. 10-fach größer. Die notwendigen Kenntnisse auch. Ausser dem Marketingwert ("Die nicht vorhandenen Fehler werden in einer Datenbank erfasst!" nota bene: Keiner spricht von Auswertung!) wird dadurch aber nicht einziges Bit neue Information entstehen.
NB: Kennst Du den Aufruhr, als systemd (natürlich ganz im Sinne des Fortschritts) anfing, die Logs in einem Binärformat zu speichern? Sie tun es heute (noch?). Ich lese aber immer (noch?) Logs in menschlicher Sprache.
Tja, hier schreibt halt ein ewig Gestriger ;-) Viel Erfolg bei Deiner Suche!
Bernhard
Hallo,
wenn du Logs anders konsumieren willst, dann wirf mal einen Blick auf Kibana. Da kannst du sie grafisch visualisieren wie immer du magst.
Das ist unabhängig von der Logspeicherung. Die kannst du nach wie vor als Logdatei vorliegen haben, in einer DB mit "richtigen" records oder wofür auch immer du eine Konverterfunktion schreiben willst (40 Zeilen Java).
Rsyslog kann auch nach MySQL speichern.
Beste Grüße Fabian
Am 10. April 2019 09:54:55 MESZ schrieb "Thomas Güttler" guettliml@thomas-guettler.de:
ich habe irgendwie keinen Bock mehr auf "Logging to file".
Mag sein, dass das Unix-Konzept die letzten hundert Jahr gut funktioniert hat, aber zB Apache Logs zeilenweise in eine Datei zu schreiben hat deutlich Nachteile.
1: Logrotate. Nervt.
2: Unstrukturiert. Das Log ist eine einfach ascii-Zeile. Ich hätte aber gerne Key-Value Paare.
Auch im open source Bereich ist die Werbemaschine kräftig am Laufen, so dass unklar ist, was sinnvolle Technik ist und was Marketing-Bla-Bla ist.
Frage 1: Könnt ihr die Aussage (Keinen Bock mehr auf "Logging to file") nachvollziehen?
Frage 2: Hat jemand schon eine Alternative zu Logfiles ausprobiert. Ein Erfahrungsbereicht aus der Praxis wäre interessant.
Gruß, Thomas
-- Thomas Guettler http://www.thomas-guettler.de/ I am looking for feedback: https://github.com/guettli/programming-guidelines
lug-dd@mailman.schlittermann.de