Logs in fhem
Boris Neubert
die offenen Punkte unter http://fhemwiki.de/index.php/DevelopmentOpenIssues sind nun fast alle durchgesprochen. Da notify eng mit Logs verbunden ist, moechte ich gerne das Thema Logs noch thematisieren.
Derzeit erfuellen Logs u.a. zwei grundverschiedene Aufgaben:
- der Benutzer kann sehen, was zu einem bestimmten Zeitpunkt passiert ist
- ein Frontend kann daraus eine Zeitreihe ableiten fuer eine Grafik
Die jetzigen Logs funktionieren grob so, dass eine Aenderung an
einem Reading ein Event (device:text) ausloest, und der entsprechende
Wert ins Log geschrieben wird, wenn das beim Log angegebene Pattern auf
das Event passt. So kann man schoen sehen, wenn ein Geraet einen oder
mehrere neue Werte liefert. Das sollte erhalten bleiben.
Offene Punkte:
1. Kuenftig gibt es nur noch einen Wert pro Reading. Waehrend die
Wetterstation KS300 bisher
T: 26.5 H: 51 W: 5.0 R: 1142.7 IR: no
als text liefert, wuerden kuenftig simultan 5 Events gesendet. Will
man jetzt 5 Zeilen im Log?
Oder 1 Zeile mit 5 oder 10 Spalten?
2. Fuer Auswertungen von Zusammenhaengen (z.B. wie warm war es im
Wohnzimmer, als die Helligkeit draussen 50000 lux betrug?) waere es
sinnvoll, die Werte mehrerer Sensoren in ein Log zu schreiben. Dafuer
schwebt mir etwas der Form
define myLog FileLog "/data/Homeautomation/logs/meinLog.log"
define myEventLogger on lichtSensor:lux log MyLog "lichtSensor:lux
wohnZimmerFuehler:T"
Uebersetzung: wenn Geraet bs eine Aenderung im Reading lux hat, wird
das Reading lux von lichtSensor und das Reading T von wohnzimmerFuehler
in das Log geschrieben.
Damit bekaeme man auch Punkt 1 geloest.
Was meint Ihr?
Gruesse,
Boris
Rudolf Koenig
>
> Was meint Ihr?
Die Idee gefaellt mir sehr gut, mit der Ausfuehrung hadere ich noch. Mein
Problem ist, dass einfache FileLogs damit zwei definitionen brauchen.
Wie waere es mit folgende Alternative: Kein neues device (EventLog) einfuehren,
sondern optionale Parameter fuer FileLog:
define myLog FileLog <filename> <filter1> <loglist1> <filter2> <loglist2> ...
Fuer Hardcore-Programmierer kann <loglist> ein perl Ausdruck sein {$defs...}
> Probleme sehe ich eventuell mit dem "Alter" der Werte. Solange die
> Energiemonitore und die Temperatursensoren so alle 3-5 min senden
> passt das schon. Wenn ich aber wirklich mehrere exakte Werte zum
> Zeitpunkt x brache, m��te ich pollen.
Nicht mt dem obigen Vorschlag, da es die Daten nicht aus dem "CHANGED"
sondern aus dem "READINGS" nimmt.
> @Martin: Wie kommen die Frontends mit den sporadisch vorhandenen
> zus�tzlichen Werte zu recht? Geht sowas mit gnuplot �berhaupt ?
Gnuplot und SVG filtern die Daten fuer jede Spalte, gnuplot mit awk,
gnuplot-scroll und SVG mit FileLog/get().
Dr. Boris Neubert
> Wie waere es mit folgende Alternative: Kein neues device (EventLog) einfuehren,
> sondern optionale Parameter fuer FileLog:
>
> define myLog FileLog <filename> <filter1> <loglist1> <filter2> <loglist2> ...
Was bedeuten <filterN> und <loglistN>? Ist es so gemeint:
define myLog FileLog "/data/Homeautomation/logs/meinLog.log" \
lichtSensor:lux "lichtSensor:lux wohnZimmerFuehler:T" \
wohnZimmerFuehler:T "lichtSensor:lux wohnZimmerFuehler:T"
Dann waeren die mehreren loglist-Eintraege redundant.
> Fuer Hardcore-Programmierer kann <loglist> ein perl Ausdruck sein {$defs...}
Das gaebe maximale Flexibilitaet!
Gruesse,
Boris
Rudolf Koenig
Ja, wobei evtl auch folgendes reichen wuerde:
define myLog FileLog "/data/Homeautomation/logs/meinLog.log" \
wohnZimmerFuehler:T.* "lichtSensor:lux wohnZimmerFuehler:T"
> Dann waeren die mehreren loglist-Eintraege redundant.
Ich kann aus diesem Satz nicht rauslesen, ob das jetzt ein Problem fuer Dich ist
oder nicht :) Sowas aehnliches kann man z.Zt auch mit
define myLog FileLog (wohnZimmerFuehler:T|lichtSensor:lux) ...
realisieren, ich verwende das auch ausgiebig.
Kai 'wusel' Siering
On 06/11/2010 03:38 PM, Boris Neubert wrote:
> Derzeit erfuellen Logs u.a. zwei grundverschiedene Aufgaben:
>
> * der Benutzer kann sehen, was zu einem bestimmten Zeitpunkt
> passiert ist
> * ein Frontend kann daraus eine Zeitreihe ableiten fuer eine Grafik
Den Ansatz halte ich tendentiell für fraglich; in einer idealen Welt würde
ich dafür einen Datenbank-Ansatz mir wünschen, anstatt daß bei jedem Auf-
ruf ein (über die Zeit länger werdendes) Logfile wieder und wieder geparst
werden müßte. Mir fehlt der Überblick einerseits, wie verbreitet Berkeley DB
auf »kleinen Plattformen« ist und andererseits, welchen Performancvorteil
deren Nutzung (statt reinen Textdateien) mit sich brächte, würde aber ten-
dentiell votieren, diesen Weg für diese Nutzung einzuschlagen.
> Die jetzigen Logs funktionieren grob so, dass eine Aenderung an einem
> Reading ein Event (device:text) ausloest, und der entsprechende Wert ins
> Log geschrieben wird, wenn das beim Log angegebene Pattern auf das Event
> passt. So kann man schoen sehen, wenn ein Geraet einen oder mehrere neue
> Werte liefert. Das sollte erhalten bleiben.
Das sehe ich anders; diese Information ab einem (zu definierenden?) Log-
level ins FHEM-Log zu schreiben, ist sicherlich hilfreich. Aber für die
spätere Auswertung sind reine Textdateien imho nur der allerkleinste ge-
meinsame Nenner ...
> 2. Fuer Auswertungen von Zusammenhaengen (z.B. wie warm war es im
> Wohnzimmer, als die Helligkeit draussen 50000 lux betrug?) waere es
> sinnvoll, die Werte mehrerer Sensoren in ein Log zu schreiben. Dafuer
> schwebt mir etwas der Form
>
> define myLog FileLog "/data/Homeautomation/logs/meinLog.log"
> define myEventLogger on lichtSensor:lux log MyLog "lichtSensor:lux
> wohnZimmerFuehler:T"
Und für den umgekehrten Fall, wenn ich wissen will, wie hell es draußen
war, als 20 °C im Wohnzimmer unter- oder überschritten wurden, benötige
ich zwei weitere Definition, richtig?
Ich würde da anders rangehen und je Sensorwert eine "Tabelle" (derzeit
also: Logfile; später vielleicht: Berkely DB?) führen. Dann kann man be-
liebige Auswertungen fahren, und die Temperatur zur Helligkeit X ist
entsprechend dann der Mittelwert zwischen dem letzten Datum vor der Mes-
sung der Helligkeit X und dem ersten danach. (Nichts anderes macht obiges
Statement, nein, schlimmer, es nimmt den letzten gespeicherten Wert, auch
wenn er 1h alt sein mag ...)
> Uebersetzung: wenn Geraet bs eine Aenderung im Reading lux hat, wird das
> Reading lux von lichtSensor und das Reading T von wohnzimmerFuehler in
> das Log geschrieben.
Wobei das imho in die Irre führt. Faktisch jeder Sensor in FHEM hat ein
anderes zeitliches Raster, von Empfangsausfällen bei funkbasierten Sen-
soren ganz zu schweigen. Ich empfange Sensoren im Wohnzimmer und Arbeits-
zimmer sowie direkt angrenzende (<5m von CUL/CUN/FHZ entfernt) recht zu-
verlässig. Alle anderen (Funk-)Sensoren sind schon bei nur noch 50-25%,
die Aussagekraft eines Readings X zum Zeitpunkt Y muß daher eigentlich immer
in Relation zum Zeitpunkt Z für Reading X gesehen werden -- ein Logfile,
welches X aus Z zum Zeitpunkt Y ohne Hinweis auf Z loggt ist mindestens
mit Vorsicht zu genießen. IMHO, YMMV ...
kai
Dr. Boris Neubert
> Ja, wobei evtl auch folgendes reichen wuerde:
>
> define myLog FileLog "/data/Homeautomation/logs/meinLog.log" \
> wohnZimmerFuehler:T.* "lichtSensor:lux wohnZimmerFuehler:T"
wohnZimmerFuehler:T.* ist ein Filter wie in fhem 4.x? Auf welches
Ereignis passt das Pattern T.*? Genuegt es nicht, nun wegen der
Eindeutigkeit der Readings nur noch den Bezeichner des Readings anzugeben.
> Ich kann aus diesem Satz nicht rauslesen, ob das jetzt ein Problem fuer Dich ist
> oder nicht :) Sowas aehnliches kann man z.Zt auch mit
> define myLog FileLog (wohnZimmerFuehler:T|lichtSensor:lux) ...
> realisieren, ich verwende das auch ausgiebig.
M.E. sollte jede Zeile im Log dasselbe Format haben. Deswegen wollte ich
verstehen, ob durch die verschiedenen loglist-Eintraege je Event
unterschiedliche Zeilen ins Log geschrieben werden koennen.
Wir haetten jetzt also
define <name> FileLog <pattern> <expression>
mit
<pattern>:= <primitive|pattern>
<primitive>:= <device>:<reading>
<expression>:= Liste von <primitive> oder { <perl-code> }
Merkposten: was wir fuer FileLog diskutieren, soll auch fuer DBLog und
PachubeLog etc. funktionieren.
Gruesse,
Boris
Dr. Boris Neubert
Kai 'wusel' Siering schrieb:
> Den Ansatz halte ich tendentiell für fraglich; in einer idealen Welt würde
> ich dafür einen Datenbank-Ansatz mir wünschen, anstatt daß bei jedem Auf-
> ruf ein (über die Zeit länger werdendes) Logfile wieder und wieder geparst
fuer den meschlichen Benutzer halte ich Text-Logs fuer ideal, weil ich
mit less und tail -f gleich sehen kann, was Sache ist. Fuer die
Frontends sollten wir in der Tat Alternativen diskutieren. Neben einer
DB draengt sich mir die Frage auf, ob nicht fhem auf Anfrage einen
Ausschnitt aus der Historie an den Aufrufer gibt. Wo fhem dann die
Historie speichert (DB?) waere dann eine Frage, die gesondert geklaert
werden soll. Ich erinnere mich daran, dass auf den "kleinen Plattformen"
die Performancethematik auch eine wesentliche Rolle spielt.
> Ich würde da anders rangehen und je Sensorwert eine "Tabelle" (derzeit
> also: Logfile; später vielleicht: Berkely DB?) führen. Dann kann man be-
Ack. Ich wuerde DBLog nutzen, um Daten fuer groessere Auswertungen zu
sammeln.
Gruesse,
Boris
Rudolf Koenig
> ich dafür einen Datenbank-Ansatz mir wünschen, anstatt daß bei jedem Auf-
> ruf ein (über die Zeit länger werdendes) Logfile wieder und wieder geparst
> werden müßte.
Versionen im contrib. Man koennte sogar FHEMWEB mit geringen Aufwand
anpassen (wuerde ich uebernehmen) _FALLS_ DbLog eine dem FileLog
entsprechende get Funktion bieten wuerde. Btw: FileLog/get() liest
nicht die ganze Datei durch: es wird eine binaere Suche durchgefuehrt,
und die letzten Offsets werden gemerkt.
BerkeleyDB halte ich fuer problematisch, da es mWn keine
Kommandozeilen-Tools bietet um Daten zu pruefen/nachtraeglich zu
korriegieren/etc. Weiterhin ist beim Bibliothek-Versionsupgrade auch
ein Upgrade der DB durchzufuehren, womit ich einmal schon ernsthafte
Probleme hatte. Wenn, dann eher mysql, obwohl der mehr "Ballast"
mitbringt als bdb, und auch nicht jeder Anfaenger mit SQL sich gut
auskennt. Um die Nerven der Anfaenger und die der Support-Truppe zu
schonen, moechte ich FileLog als default behalten. Aber ich faende es
toll, wenn einer der beiden DbLog's ins FHEM Verzeichnis schaffen
wuerden, und gegen einen BDBLog habe ich auch nichts einzuwenden.
> Auf welches Ereignis passt das Pattern T.*? Genuegt es nicht, nun wegen der
> Eindeutigkeit der Readings nur noch den Bezeichner des Readings anzugeben.
die Sammellogs mit prefix.* gewoehnt. Damit kann ich auch neue Geraete
in Betrieb nehmen, ohne die Logs aendern zu muessen.
Dr. Boris Neubert
> schonen, moechte ich FileLog als default behalten. Aber ich faende es
> toll, wenn einer der beiden DbLog's ins FHEM Verzeichnis schaffen
> wuerden, und gegen einen BDBLog habe ich auch nichts einzuwenden.
was muss an DBLog (ausser einem FileLog-artigen getter) dafuer noch
getan werden?
>> Auf welches Ereignis passt das Pattern T.*? Genuegt es nicht, nun wegen der
>> Eindeutigkeit der Readings nur noch den Bezeichner des Readings anzugeben.
>
> Ich wuerde die Filter gerne so behalten wie jetzt, ich hab mich so an
> die Sammellogs mit prefix.* gewoehnt. Damit kann ich auch neue Geraete
> in Betrieb nehmen, ohne die Logs aendern zu muessen.
Hilf' mir bitte mal aufs Pferd: in fhem 4.x matchen die Filter m.W.
gegen STATE, welches mehrere Readings enthalten konnte. Kuenftig wird es
aber keine kombinierte Readings mehr geben. Gegen was soll der Filter
matchen?
Gruesse,
Boris
Rudolf Koenig
> getan werden?
Ein "Komplettdump" und evtl. eine Auflistung aller archivierten "Dateien". Ich
muss fhemweb abgewoehnen, die Daten manchmal (z.Bsp Text-Ansicht) direkt aus
dem Filesystem zu holen.
> Hilf' mir bitte mal aufs Pferd: in fhem 4.x matchen die Filter m.W.
> gegen STATE, welches mehrere Readings enthalten konnte. Kuenftig
> wird es aber keine kombinierte Readings mehr geben. Gegen was soll
> der Filter matchen?
In 4.x ist es nicht STATE, sondern die Liste aller CHANGED Eintraege. Ich
hatte vor in FileLog diesen Aspekt fuer den Benutzer unveraendert zu lassen,
d.h. FileLog "erzeugt" dann aus einem Event der Reihe nach alle geaenderten
Felder, es sei denn der Benutzer will nur ausgewaehlte.
Ein Regexp ist sowohl zum Filtern von Geraeten gut, als auch beim exotischen
Geraeten wie der KM271, der 60 verschiedene Ereignisse kennt. Die will ich
nicht einzeln aufzaehlen, bzw ich will eine Hilfe haben, um nur ausgewaehlte zu
loggen.
Dr. Boris Neubert
>> was muss an DBLog (ausser einem FileLog-artigen getter) dafuer noch
>> getan werden?
-> in DevelopmentOpenIssues auf fhemwiki.de geparkt
> In 4.x ist es nicht STATE, sondern die Liste aller CHANGED Eintraege. Ich
> hatte vor in FileLog diesen Aspekt fuer den Benutzer unveraendert zu lassen,
> d.h. FileLog "erzeugt" dann aus einem Event der Reihe nach alle geaenderten
> Felder, es sei denn der Benutzer will nur ausgewaehlte.
Ist es so gemeint?
Beispiel FHT80b:
$defs{myFHT80b}{internals}{changed}= \
"measuredTemperature:actuator";
=>
a) Filter myFHT80b:desiredTemperature fuehrt zu keinem Log-Eintrag
b) Filter myFHT80b:.* fuehrt zu einem Log-Eintrag.
c) Filter myFHT80b:(desiredTemperature|measuredTemperature) fuehrt zu
einem Log-Eintrag.
Was dann geloggt wird, entscheidet die loglist?
Gruesse,
Boris
Rudolf Koenig
[...]
Ich habe es noch nicht ganz zu Ende gedacht, aber vielleicht tun wir das jetzt.
Grundform (auch in 4.x gueltig), wird die gleichen Daten (d.h. alle Daten aller
Geraete, deren Name mit fht anfaengt) auch in 5.x liefern:
define fhtlog FileLog ./log/fht-%Y.log fht.*
Das erzugt eine Zeile fuer jeden Event (auch beim Sammelevents), wie bisher.
Erweitert, immer noch kompatibel zu 4.x, actuator und desired-temp geloggt:
define fhtlog FileLog ./log/fht-%Y.log fht.*:(actuator|desired-temp)
Neu waere mit Deinem Vorschlag in 5.x
define fhtlog FileLog ./log/fht-%Y.log fht.*:(actuator|desired-temp)\
content "actuator desired-temp lichtSensor:lux"
Falls mehrere Werte in einem Sammelevent geliefert werden (wie beim S300
ueblich), dann wird nur ein Eintrag erzeugt. Bei einem FHT, der diese Events
einzeln liefert, werden actuator und desired-temp mit alten Werten geloggt,
wenn das jeweils andere Event eintrifft.
Folgende Formulierung loggt nicht den alten actuator/desired-temp:
define fhtlog FileLog ./log/fht-%Y.log\
fht.*:actuator content "actuator lichtSensor:lux"\
fht.*:desired-temp content "desired-temp lichtSensor:lux"
Das Wort content ist mir deswegen wichtig, damit man diesen Optional halten
kann, und folgendes auch moglich ist:
define fhtlog FileLog ./log/fht-%Y.log\
fht.*:actuator fht.*:desired-temp
Schliesslich ist auch folgendes erlaubt (@ und % werden wie im notify ersetzt):
define fhtlog FileLog ./log/fht-%Y.log\
fht.*:actuator content {"@ % $defs{lichtSensor}{readings}{lux}{value}"}
Insgesamt bin ich von der Erweiterung noch nicht voellig ueberzeugt.
Dr. Boris Neubert
> Insgesamt bin ich von der Erweiterung noch nicht voellig ueberzeugt.
Ich auch nicht. Ich glaube mittlerweile (Begruendung unten), dass die
Erweiterung schwer zu durchschauen sein wird und wir daher FileLog
besser so lassen, wie es ist, und eine andere Loesung suchen, wie man
sich effizient kombinierte Historien (neuer Thread) verschaffen kann.
Gruesse,
Boris
*** Begruendung:
Eine formale Beschreibung unterstuetzt manchmal den Denkprozess:
A.
Ein _Event_ tritt ein, wenn ein oder mehrere Readings eines Geraetes
aktualisiert werden, weil z.B. ein Datagramm empfangen oder
zeitgesteuert Werte eingelesen wurden. Es wird durch drei Angaben
(device, timestamp, { reading1, ..., readingN } )
beschrieben:
- das Geraet device
- der Zeitpunkt der Aktualisierung timestamp
- die Menge der N>= 1 geaenderten Readings reading1, .. readingN
Wenn N> 1, dann handelt es sich um ein _Sammelevent_, wie es z.B. von
KS300 generiert wird.
B.
Ein Filter filtert Events. Er hat die Form deviceNamePattern bzw.
deviceNamePattern:readingNamePattern. Ein Filter passt auf ein Event,
wenn deviceNamePattern den Namen des device matcht und, sofern
vorhanden, readingNamePattern mindestens irgendeinen Namen von reading1
bis readingN matcht.
Rekapitulieren wir nun den Mechanismus:
0. Fuer das Geraet device namens deviceName wird ein Datagramm empfangen
oder es werden zeitgesteuert Werte eingelesen.
1. Die Readings werden aktualisiert.
Fuer X= 1..N:
$defs{deviceName}{readings}{readingX}{value}= valueX;
$defs{deviceName}{readings}{readingX}{time}= timestamp;
2. Das Event wird erstellt und an DoTrigger uebergeben.
3. Das Event wird nacheinander an alle NotifyFn gereicht. Darunter auch
jene vom Log.
4. Wenn der Filter des Logs auf das Event passt, wird ein Log-Eintrag
der Form
timestamp deviceName reading1: value1 reading2: value2 ... readingN: valueN
erzeugt.
[Falls das nicht korrekt oder unvollstaendig ist, bitte ich um
Korrektur, da ich gerne zumindest den Mechanismus im Wiki dokumentieren
moechte.]
M.E. darf die Definition des Filters keine Auswirkungen auf den Inhalt
des Logs haben. Ausserdem ist es fuer den Anwender intransparent, was
ueberhaupt geloggt wird, da er i.d.R. nicht weiss, welche Events von dem
Geraet erzeugt werden bzw. welche Readings darin enthalten sind.
Fazit: FileLog sollte so bleiben wie es ist, mit dem Verstaendnis, dass
es dazu dient, primaer fuer einen Menschen (die gewuenschte Teilmenge
von) _Events_ zu protokollieren.
Dr. Boris Neubert
> Ich würde da anders rangehen und je Sensorwert eine "Tabelle" (derzeit
> also: Logfile; später vielleicht: Berkely DB?) führen. Dann kann man be-
> liebige Auswertungen fahren, und die Temperatur zur Helligkeit X ist
die Ueberlegungen im anderen Zweig dieses Threads haben mich davon
ueberzeugt, von der Idee abzuruecken, FileLog aufzubohren, und
stattdessen die Idee einer "Tabelle" (Historie) weiterzuverfolgen.
Dabei wuerde ich allerdings die Frage der Funktionalitaet (z.B. "gib
Historie der Werte fuer x, y, z im Zeitraum von t1 bis t2") zum
Verwender (Frontend; Benutzer, der wissen will, wie hell es war, als im
Wohnzimmer die Temperatur ueber 22 Grad stieg; ...) hin von der Frage
des darunterliegenden Speichermechanismus (Textdatei, Datenbank, trennen
wollen.
Wir sollte dafuer dann einen neuen Thread aufmachen.
Gruesse,
Boris
Rudolf Koenig
> Korrektur, da ich gerne zumindest den Mechanismus im Wiki
> dokumentieren moechte.]
Korrekt.
Anmerkungen:
- DoTrigger benachrichtigt zuerst alle Clients mit inform Wunsch.
- die Notify-Benachrichtigung laeuft nach alphabetische Folge der Geraetenamen.