Warum löst mein Notify nicht aus?

[Invers]

Ich habe ein Notify, welches das fhem-Log überwacht.
Leider löst es nicht aus. Regex-Test ist offenbar ok.

Die Logzeile:

Code Auswählen Erweitern

[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:

Code Auswählen Erweitern

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.

[betateilchen]

Bei mir funktioniert Dein notify problemlos.

Code Auswählen Erweitern

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?

[Invers]

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:

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]

Aber nicht auf die Meldung:

Code Auswählen Erweitern

[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

Code Auswählen Erweitern

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.

[rabehd]

Es wird aber nicht GATKILL wird aber nicht aufgerufen,

Ist dopplete Verneinung hier richtig?

[Invers]

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:

Code Auswählen Erweitern

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:

Code Auswählen Erweitern

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)
"


[Invers]

Ich habe noch einmal etwas experimentiert.

Wenn ich eingebe:

Code Auswählen Erweitern

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:

Code Auswählen Erweitern

[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

[Aurel_B]

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.

[MadMax-FHEM]

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")

Leider 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

Bei mir funktioniert Dein notify problemlos.

Hier wäre ein list interessant, also ob das notify tatsächlich so heißt:

Code Auswählen Erweitern

define LogUeberwachung notify LogUeberwachung:.*ExecGatttool_Run.* set GATKILL cmd_1

oder evtl. so:

Code Auswählen Erweitern

define LogUeberwachung notify .*ExecGatttool_Run.* set GATKILL cmd_1
Zweiteres kann nat. auslösen...

Weil das hier glaube ich (auch) nicht:

Das Notify reagiert bei mir z.B. einwandfrei auf folgende Logmeldung:
Code Auswählen Erweitern

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:

Code Auswählen Erweitern

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

[rudolfkoenig]

Trigger erzeugt ein Event, das wird anders verarbeitet als die Zeilen aus dem FHEM-Log.
Letzteres kann man mit

Code Auswählen Erweitern

{ Log 3, "XiaomiBTLESens..." }
simulieren.

Also 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.

[betateilchen]

Bei mir funktioniert Dein notify problemlos.

Hier wäre ein list interessant, also ob das notify tatsächlich so heißt:

Code Auswählen Erweitern

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:

Code Auswählen Erweitern

define LogUeberwachung notify LogUeberwachung:.*ExecGatttool_Run.* set GATKILL cmd_1
attr LogUeberwachung readLog 1

und dann mit

Code Auswählen Erweitern

{Debug 'XiaomiBTLESens (TH_HeizungSz) - ExecGatttool_Run: errorcode: "2", ErrorString: ""'}

getestet, was zur Meldung im Log führte:

Code Auswählen Erweitern

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.

Letzteres kann man mit

Code Auswählen Erweitern

{ Log 3, "XiaomiBTLESens..." }
simulieren.

Deshalb hatte ich Debug() zum Testen verwendet, was ja letztlich ein "Log 1, ..." ausführt.

[Invers]

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.

Denn 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.

Warum 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.

Code Auswählen Erweitern

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

[betateilchen]

@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.

Code Auswählen Erweitern

sub logtest {
        Log3( "global", 3, "XiaomiBTLESens (name) - ExecGatttool_Run: errorcode: \"returnCode\", ErrorString: \"returnString\"")
}

Ergebnis im Log:

Code Auswählen Erweitern

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.)

[betateilchen]

(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.

[Invers]

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:

Code Auswählen Erweitern

[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.

[Invers]

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.