Ich habe ein Notify, welches das fhem-Log überwacht.
Leider löst es nicht aus. Regex-Test ist offenbar ok.
Die Logzeile:
[pre]2023.12.14 17:56:39.743 3: XiaomiBTLESens (TH_HeizungSz) - ExecGatttool_Run: errorcode: "2", ErrorString: ""[/pre]
Auslösen soll der Zeileninhalt ExecGatttool_Run
Tut er aber nicht. Warum?
Notify:
define LogUeberwachung notify LogUeberwachung:.*ExecGatttool_Run.* set GATKILL cmd_1
attr LogUeberwachung readLog 1
attr LogUeberwachung room 1_TEST
# DEF LogUeberwachung:.*ExecGatttool_Run.* set GATKILL cmd_1
# FUUID 6572bfe4-f33f-8098-c241-2fa60631d9489fcb
# NAME LogUeberwachung
# NOTIFYDEV LogUeberwachung
# NR 588
# NTFY_ORDER 50-LogUeberwachung
# REGEXP LogUeberwachung:.*ExecGatttool_Run.*
# STATE
# TRIGGERTIME 1702572076.95454
# TYPE notify
# eventCount 19
# READINGS:
# 2023-12-14 07:42:37 state active
# 2023-12-14 17:48:34 triggeredByDev LogUeberwachung
# 2023-12-14 17:48:34 triggeredByEvent 2023.12.14 17:41:16.952 1: Timeout for FHEM::XiaomiBTLESens::ExecGatttool_Run reached, terminated process 327
#
setstate LogUeberwachung 2023-12-14 07:42:37 state active
setstate LogUeberwachung 2023-12-14 17:48:34 triggeredByDev LogUeberwachung
setstate LogUeberwachung 2023-12-14 17:48:34 triggeredByEvent 2023.12.14 17:41:16.952 1: Timeout for FHEM::XiaomiBTLESens::ExecGatttool_Run reached, terminated process 327
setstate LogUeberwachung stammt aus verschiedenen Experimenten und ist nicht aktuell.
Besten Dank im Voraus für die Hilfe.
Bei mir funktioniert Dein notify problemlos.
2023.12.14 20:37:08 1: DEBUG>XiaomiBTLESens (TH_HeizungSz) - ExecGatttool_Run: errorcode: "2", ErrorString: ""
2023.12.14 20:37:08 3: LogUeberwachung return value: Please define GATKILL first
Die Fehlermeldung bezüglich "Please define..." ist logisch, ich habe kein device mit dem Namen GATKILL.
Aber grundsätzlich wird das notify getriggered und versucht zumindest, den set Befehl auszuführen.
Was steht denn bei Dir im Logfile?
Im Log steht in meinem Fall dann gar nichts.
Ich habe in GATKILL einen Eintrag ins Log drinnen. Es wird aber nicht GATKILL wird aber nicht aufgerufen, was ich am fehlenden Logeintrag sehe.
Das Notify reagiert bei mir z.B. einwandfrei auf folgende Logmeldung:
[pre]2023.12.15 05:54:56.641 1: Timeout for FHEM::XiaomiBTLESens::ExecGatttool_Run reached, terminated process 31813
2023.12.15 05:55:08.988 3: ▀ GATKILL ausgelöst.[/pre]
Aber nicht auf die Meldung:
[pre]2023.12.15 07:04:43.818 3: XiaomiBTLESens (TH_HeizungSz) - ExecGatttool_Run: errorcode: "1", ErrorString: "connect to 4C:65:A8:D2:53:8C: Connection timed out (110)
"[/pre]
Da steht nach dem Eintrag halt keine Meldung von GATKILL.
Ich verstehe nicht, warum das so ist.
Die Meldung
2023.12.14 20:37:08 1: DEBUG>XiaomiBTLESens (TH_HeizungSz) - ExecGatttool_Run: errorcode: "2", ErrorString: ""
Hab ich leider nicht mehr, weil ich das Log gelöscht habe. Sollte aber bald neu auftauchen.
EDIT:
Ich habe mal fhem neu gestartet. Mal sehen, was passiert. Vielleicht habe ich durch das viele Herumprobieren was zerstört.
Zitat von: Invers am 15 Dezember 2023, 07:37:18Es wird aber nicht GATKILL wird aber nicht aufgerufen,
Ist dopplete Verneinung hier richtig?
Ich war wohl etwas unkonzentriert. Ich meinte, dass GATKILL nicht auferufen wird und ich das daran erkenne, dass GATKILL nichts ins Log geschrieben hat.
Der Neustart hat leider nichts gebracht.
Funktioniert:
2023.12.15 11:56:42.184 1: Timeout for FHEM::XiaomiBTLESens::ExecGatttool_Run reached, terminated process 15289
2023.12.15 11:56:54.612 3: ▀ GATKILL ausgelöst.
Funktioniert nicht:
2023.12.15 16:05:10.464 3: XiaomiBTLESens (TH_HeizungSz) - ExecGatttool_Run: errorcode: "1", ErrorString: "connect to 4C:65:A8:D2:53:8C: No route to host (113)
"
Ich habe noch einmal etwas experimentiert.
Wenn ich eingebe:
trigger LogUeberwachung 2023.12.14 13:47:07.683 3: XiaomiBTLESens (TH_HeizungSz) - ExecGatttool_Run: errorcode: "1", ErrorString: "connect to 4C:65:A8:D2:53:8C: Function not implemented (38) "
Dann löst das Notify auch aus:
[pre]2023.12.16 10:04:55.136 5: Triggering LogUeberwachung
2023.12.16 10:04:55.137 4: LogUeberwachung exec set GATKILL cmd_1
2023.12.16 10:05:07.538 3: ▀ GATKILL ausgelöst.[/pre]
Wird die Fehlerzeile aber von XiaomiBTLESens ins Log geschrieben, wird nicht ausgelöst und es gibt auch keine Anzeige " 2023.12.16 10:05:07.538 3: ▀ GATKILL ausgelöst. " im Log.
Hat vielleicht noch jemand eine Idee?
Warum steht eigentlich oft vor und hinter meinem eingefügten Code hier im Forum? Ich hab die Logzeilen ganz normal kopiert und hier eingefügt. Aber ok, das ist ein anderes Problem
Das wäre meine Vorangehensweise gewesen -> Logeintrag manuell einfügen und schauen, ob dann dein Notfiy triggert (was es ja macht). Poste doch mal dein devlist vom XiaomiBTLESens device.
Ich hab mir das mal durchgelesen...
Frage: wie hast du das notify erstellt? "Selbst ausgedacht"? Oder einfach den EventMonitor machen lassen?
(ich schätze: "selbst ausgedacht")
Zitat von: Invers am 14 Dezember 2023, 18:36:33Leider löst es nicht aus. Regex-Test ist offenbar ok.
Woher weißt du das?
Wie hast du denn die RegEx getestet?
Wenn ich mir deine Regex so ansehe: LogUeberwachung:.*ExecGatttool_Run.*
dann frage ich mich wie das überhaupt auslösen kann, weil doch in deinen Logeinträgen nie nicht "LogUeberwachung" vorkommt?
Weil das "LogUeberwachung" ist doch der Name des notify?
Also kann das notify (so wie von dir formuliert) doch nur auf Events triggern, die "von sich selbst kommen"?
Weil:
define nName notify RegEx Ausführung
Bei dir sieht es so aus als hättest du:
define nName notify nName:RegEx Ausführung
Zitat von: betateilchen am 14 Dezember 2023, 20:40:34Bei mir funktioniert Dein notify problemlos.
Hier wäre ein list interessant, also ob das notify tatsächlich so heißt:
define LogUeberwachung notify LogUeberwachung:.*ExecGatttool_Run.* set GATKILL cmd_1
oder evtl. so:
define LogUeberwachung notify .*ExecGatttool_Run.* set GATKILL cmd_1
Zweiteres kann nat. auslösen...
Weil das hier glaube ich (auch) nicht:
Zitat von: Invers am 15 Dezember 2023, 07:37:18Das Notify reagiert bei mir z.B. einwandfrei auf folgende Logmeldung:
Code Auswählen Erweitern
[pre]2023.12.15 05:54:56.641 1: Timeout for FHEM::XiaomiBTLESens::ExecGatttool_Run reached, terminated process 31813
2023.12.15 05:55:08.988 3: ▀ GATKILL ausgelöst.[/pre]
Denn das würde bedeuten, dass das notify 12 Sekunden "überlegt" hat...
...oder in cmd_1 irgendwas 12 Sekunden braucht.
Für mich sieht es so aus als würdest du ein cmd eines DOIF (GATKILL) aufrufen: set GATKILL cmd_1
von dem es kein list gibt...
Ich denke eher, dass der Eintrag, den du vermeintlich deinem notify zuordnest einfach vom DOIF selbst kommt?
Aber ohne list kann man da nat. nichts sagen...
Um festzustellen, dass das notify auslöst, ist es besser DORT eine Logausgabe einzubauen statt in einer "aufgereufenen Methode".
Weil es kann viel passieren zwischen notify löst (doch) aus aber "Methode" schreibt nichts ins Log...
Warum also nicht einfach den EventMonitor nehmen und sich das notify passend zum Event erzeugen lassen?
Bzw. denke ich, dass folgendes notify (verm.) auslöst, u.U. allerdings zu oft:
define LogUeberwachung notify .*ExecGatttool_Run.* set GATKILL cmd_1
attr LogUeberwachung readLog 1
Wie geschrieben, das sind nur meine Überlegungen beim Lesen des ganzen Threads hier...
Gruß, Joachim
Trigger erzeugt ein Event, das wird anders verarbeitet als die Zeilen aus dem FHEM-Log.
Letzteres kann man mit
{ Log 3, "XiaomiBTLESens..." }
simulieren.
ZitatAlso kann das notify (so wie von dir formuliert) doch nur auf Events triggern, die von sich selbst kommen?
Da Logzeilen keine erkennbare "Verursacher"-Instanz haben, wird beim Lesen aus dem FHEM-Log der Verursacher auf die notify-Instanz gesetzt.
Zitat von: MadMax-FHEM am 16 Dezember 2023, 10:47:59Zitat von: betateilchen am 14 Dezember 2023, 20:40:34Bei mir funktioniert Dein notify problemlos.
Hier wäre ein list interessant, also ob das notify tatsächlich so heißt:
define LogUeberwachung notify LogUeberwachung:.*ExecGatttool_Run.* set GATKILL cmd_1
Das notify heißt bei mir exakt so, wie es hier im ersten Beitrag steht, dort habe ich einfach die zwei Zeilen kopiert:
define LogUeberwachung notify LogUeberwachung:.*ExecGatttool_Run.* set GATKILL cmd_1
attr LogUeberwachung readLog 1
und dann mit
{Debug 'XiaomiBTLESens (TH_HeizungSz) - ExecGatttool_Run: errorcode: "2", ErrorString: ""'}
getestet, was zur Meldung im Log führte:
2023.12.16 11:15:23 3: LogUeberwachung return value: Please define GATKILL first
Das ist logisch, da es GATKILL bei mir nicht gibt.
Aber zumindest wurde das notify getriggered und hat den set Befehl ausgeführt.
Zitat von: rudolfkoenig am 16 Dezember 2023, 10:51:57Letzteres kann man mit
{ Log 3, "XiaomiBTLESens..." }
simulieren.
Deshalb hatte ich Debug() zum Testen verwendet, was ja letztlich ein "Log 1, ..." ausführt.
Oh, das waren viele Antworten.
@betateilchen:
Genau dieses passiert exakt bei mir auch, mit gleichen Meldungen, wenn ich es per debug mache.
Das ist der Grund für meine Verwunderung. Eigentlich sollte es doch dann auch funktionieren, wenn die Meldung von XiaomiBTLESens erzeugt und ausgegeben wird.
@Aurel_B
Das sind mehrere Devices. 2 Thermometer und ein Blumensensor. Die Devices antworten nicht korrekt auf die Anfragen vom Modul XiaomiBTLESens, welches dann die Fehlermeldungen ausspuckt.
@MadMax-FHEM
Ich habe das nicht selber erdacht, sondern (ich glaube) aus dem Wiki übernommen.
Notify mit Log funktionieren ja etwas anders, s. rudolfkoenig.
getestet habe ich die Regex mit Onlinetestern und in der Praxis dann wie bereits geschrieben.
ZitatDenn das würde bedeuten, dass das notify 12 Sekunden "überlegt" hat...
...oder in cmd_1 irgendwas 12 Sekunden braucht.
Das stimmt nicht. GATKILL hat die Zeit benötigt, um sich abzuarbeiten und den Logeintrag zu machen.
Es wird nämlich Gatttool neu gestartet, weil es sich ja vielleicht verhaspelt hat.
ZitatWarum also nicht einfach den EventMonitor nehmen und sich das notify passend zum Event erzeugen lassen?
Das ist fast unmöglich, da diese Logeinträge nicht oft kommen (zum Glück).
Übrigens - durch viele andere Logzeilen wird ja das Notify abgearbeitet.
define GATKILL DOIF (aa) \
("sudo invoke-rc.d bluetooth restart")\
("sudo hciconfig hci0 reset") \
({Log 3, "▀ GATKILL ausgelöst."})\
DOELSE()
attr GATKILL room System
attr GATKILL wait 0,6,6
# DEF (aa)
# ("sudo invoke-rc.d bluetooth restart")
# ("sudo hciconfig hci0 reset")
# ({Log 3, "▀ GATKILL ausgelöst."})
# DOELSE()
# FUUID 5f4ce4c4-f33f-8098-805f-f5baa39c7b082c6d
# MODEL FHEM
# NAME GATKILL
# NOTIFYDEV global
# NR 347
# NTFY_ORDER 50-GATKILL
# STATE cmd_1
# TYPE DOIF
# VERSION 27740 2023-07-10 09:31:11
# eventCount 446
# READINGS:
# 2023-12-16 13:41:28 cmd 1.3
# 2023-12-16 13:41:28 cmd_event set_cmd_1
# 2023-12-16 13:41:28 cmd_nr 1
# 2023-12-16 13:41:28 cmd_seqnr 3
# 2023-09-06 16:51:01 mode enabled
# 2023-12-16 13:41:28 state cmd_1
# 2023-12-16 13:41:28 wait_timer no timer
# Regex:
# accu:
# bar:
# barAvg:
# collect:
# attr:
# cmdState:
# wait:
# 0:
# 0
# 6
# 6
# waitdel:
# condition:
# 0 aa
# do:
# 0:
# 0 "sudo invoke-rc.d bluetooth restart"
# 1 "sudo hciconfig hci0 reset"
# 2 {Log 3, "▀ GATKILL ausgelöst."}
# 1:
# 0
# helper:
# NOTIFYDEV global
# event
# globalinit 1
# last_timer 0
# sleepdevice set_cmd_1
# sleepsubtimer -1
# sleeptimer -1
# triggerDev
# triggerEvents
# triggerEventsState
# DOIF_eventa:
# cmd_nr: 1
# cmd_seqnr: 3
# cmd_event: set_cmd_1
# cmd_1
# DOIF_eventas:
# cmd_nr: 1
# cmd_seqnr: 3
# cmd_event: set_cmd_1
# state: cmd_1
# perlblock:
# uiState:
# uiTable:
#
setstate GATKILL cmd_1
setstate GATKILL 2023-12-16 13:41:28 cmd 1.3
setstate GATKILL 2023-12-16 13:41:28 cmd_event set_cmd_1
setstate GATKILL 2023-12-16 13:41:28 cmd_nr 1
setstate GATKILL 2023-12-16 13:41:28 cmd_seqnr 3
setstate GATKILL 2023-09-06 16:51:01 mode enabled
setstate GATKILL 2023-12-16 13:41:28 state cmd_1
setstate GATKILL 2023-12-16 13:41:28 wait_timer no timer
Ich danke euch für die Antworten und hoffe, niemanden vergessen / überlesen zu haben.
EDIT:
readLog
Das notify wird für Meldungen, die im FHEM-Log erscheinen, ausgegeführt. Das "Event-Generierende-Gerät" wird auf dem notify selbst gesetzt. Z.Bsp. kann man mit folgendem notify auf die Startup Meldung reagieren:
define n notify n:.*Server.started.* { Log 1, "Wirklich" }
attr n readLog
Zitat von: Invers am 16 Dezember 2023, 14:03:55@betateilchen:
Genau dieses passiert exakt bei mir auch, mit gleichen Meldungen, wenn ich es per debug mache.
Das ist der Grund für meine Verwunderung. Eigentlich sollte es doch dann auch funktionieren, wenn die Meldung von XiaomiBTLESens erzeugt und ausgegeben wird.
Tut es auch, zumindest bei mir.
In meiner 99_myUtils.pm habe ich die Fehlerausgabe aus dem Modul "nachgebaut" und dann aufgerufen.
sub logtest {
Log3( "global", 3, "XiaomiBTLESens (name) - ExecGatttool_Run: errorcode: \"returnCode\", ErrorString: \"returnString\"")
}
Ergebnis im Log:
2023.12.16 17:29:07 3: XiaomiBTLESens (name) - ExecGatttool_Run: errorcode: "returnCode", ErrorString: "returnString"
2023.12.16 17:29:07 3: LogUeberwachung return value: Please define GATKILL first
Also auch in dieser Konstellation wird das notify korrekt getriggert.
(Und jetzt mache ich mich mal auf die Suche, warum "help XiaomiBTLESens" mir nicht das Ergebnis lieferte, das ich erwartet habe. Aber das ist ein anderes Thema.)
Zitat von: betateilchen am 16 Dezember 2023, 17:33:33(Und jetzt mache ich mich mal auf die Suche, warum "help XiaomiBTLESens" mir nicht das Ergebnis lieferte, das ich erwartet habe. Aber das ist ein anderes Thema.)
Erledigt. Der Modulautor hatte in der MAINTAINER.txt das .pm im Dateinamen seines Moduls vergessen.
Ich habe nun folgendes versucht:
Löschen des Notify
Neustart fhem
Anlegen Notify
Neustart des gesamten Pi (scheint zwar sinnlos, aber war sowieso mal fällig)
Ergebnis:
[pre]2023.12.17 06:14:57.247 3: XiaomiBTLESens (TH_HeizungSz) - ExecGatttool_Run: errorcode: "1", ErrorString: "connect to 4C:65:A8:D2:53:8C: No route to host (113)
"
2023.12.17 06:14:57.250 5: Triggering LogUeberwachung
2023.12.17 06:14:57.252 4: LogUeberwachung exec set GATKILL cmd_1
2023.12.17 06:15:09.158 3: ▀ GATKILL ausgelöst.[/pre]
Scheint also erfolgreich gewesen zu sein. Mal sehen, ob das ein Zufall ist.
Erst einmal danke ich euch allen für die Unterstützung zu diesem Problem.
Sollte der Fehler wieder auftreten, melde ich mich noch einmal oder ich gehe einen anderen Weg, ohne Notify. Es gibt ein DOIF, welches das Lesen des fhem-Log wohl auch beherrscht, oder ich löse GATKILL zeitgesteuert aus.
Leider zu früh gefreut.
Ich habe nun, nachdem ich feststellen musste, dass es wohl doch nicht funktioniert. die Triggerung auf das Logfile per DOIF realisiert, was aber auch nicht funktioniert.
Es funktioniert nur mit {Log 3,(...)} und mit debug.
Erfolgt die Eintragung im Log per XiaomiBTLESens - Modul im Fehlerfall eines Devices, wird leider nicht getriggert.
Es muss also ein grundlegendes Problem sein. Könnte das Problem im Modul XiaomiBTLESens liegen?
Kann ich mir zwar nicht vorstellen, aber eine andere Idee gibt es meinerseits nicht.
Ich werde also GATKILL nun zeitgesteuert durchführen. Ist zwar doof, aber nicht zu ändern.
ZitatKönnte das Problem im Modul XiaomiBTLESens liegen?
Ansichtsache :)
Diese Meldung wird in einem geforkten Prozess erzeugt.
Wenn das notify Attribut nach dem Fork (d.h. BlockingCall) gesetzt wird, dann wird das "Hook" in dem geforkten Prozess nicht nachtraeglich uebernommen.
Falls man die Reihenfolge korrigiert, ist noch zu beachten, dass notify in dem geforkten Prozess ausgefuehrt wird, damit auch "set GATKILL cmd_1". Weiss nicht, ob das auch da klappt.
Ein Fix waere im geforkten Prozess (aka BlockigCall):
- die Log Funktion ueberschreiben, damit die Ausgabe ueber dem Haupt-FHEM-Prozess laeuft.
- %informLog (Grundlage fuer readLog) loeschen.
Kann die Nebenwirkungen nicht abschaetzen.
Meinungen?