Userreading wird aus Notify nicht ausgelöst

[timtom2000]

Hallo,

bei mir tritt folgendes Verhalten auf, was ich nicht verstehe (und bis jetzt auch unplausibel finde).

Ich habe ein Userreading u_RDG definiert, das auf ein Geräte-Reading d_RDG reagiert:

Code Auswählen Erweitern

attr DEV userReadings u_RDG:d_RDG.* {...}
Userreading und Gerätereading sind als event-on-update-reading definiert.

Wenn ich manuell über

Code Auswählen Erweitern

get DEV d_RDG
das Geräte-Reading auslese, wird wie erwartet das o.g. Userreading u_RDG getriggert und aktualisiert.

Ebenso wird das Userreading getriggert und aktualisiert, wenn das Geräte-Reading per "at" ausgelesen wird, z.B. stündlich:

Code Auswählen Erweitern

define at_test at +*01:00:00 get DEV d_RDG

Wenn das Geräte-Reading allerdings per Notify ausgelesen wird, wird das Userreading u_RDG entgegen meiner Erwartung NICHT aktualisiert:

Code Auswählen Erweitern

define notify_test notify DEV:u_RDG_2.* get DEV d_RDG

Es liegt übrigens nicht daran, dass das notify gar nicht ausgelöst wird. Im Logfile sehe ich das Auslösen des notifys und den Rückgabewert des get.

Kann mir jemand auf die Sprünge helfen, warum das "get" im Zusammenhang mit dem notify das Userreading nicht triggert? Oder wo liegt hier mein Denkfehler?

[jhohmann]

Keine Ahnung, ob es daran liegt, das das Notify vom selben Device ausgelöst worden ist wie dein get.
Versuche mal, das ganze mit einem sleep zu entkoppeln.

Code Auswählen Erweitern

define notify_test notify DEV:u_RDG_2.* sleep 0.2;get DEV d_RDG

[Elektrolurch]

Wenn ein reading sich ändert, kann dadurch ja ein notify angestossen werden. Sollte das notify wiederum ein reading ändern, würde dies ja zu einer Endlosschleife führen, daher gibt es wohl diese Einschränkung.

Elekitrolurch

[timtom2000]

Danke für die Anregungen!

sleep habe ich probiert, bringt leider keine Änderung

Zur Idee mit der vermiedenen Endlosschleife...ist das irgendwo dokumentiert? Dann müsste ich gar nicht weiter nach möglichen Lösungen suchen.
Grundsätzlich könnte das zwar sein, fände ich persönlich aber unverständlich. Endlosschleifen bekommt man trotzdem hin, wenn man blöd programmiert. Das müsste man m.E. durch solche Einschränkungen nicht unbedingt verhindern, mein Usecase ist ja nicht so ungewöhnlich, denke ich?!

Oder denke ich zu quer und es gibt sinnvollere Umsetzungen für meine Idee?

[amenomade]

Was ist u_RDG_2 ?

Code Auswählen Erweitern

define notify_test notify DEV:u_RDG_2.* sleep 0.2;get DEV d_RDG

Sowas in der Kommandozeile führt nicht zu einem notify mit einem sleep + ein Kommando, sondern definiert ein notify mit nur sleep.

Wäre es möglich ein "list DEV" und ein "list notify_test" zu sehen? Ein Blick im Eventmonitor könnte auch helfen.

[timtom2000]

Das u_RDG_2 ist ein beliebiges anderes Userreading des Device, das das notify auslöst.
Ich hatte das sleep auch mit "sleep 0.2;;" versehen, dann tauchte auch das folgende get mit auf.

Aber was soll ich sagen...gerade funktioniert es wie erwartet. Und das, obwohl ich dasselbe mache wie seit 2-3 Tagen... ich weiß, kann nicht sein, es ist eine Maschine...aber ich habe grad keine Erklärung. In jedem Fall erstmal sorry für den wsl. unnötigen Aufwand. Wobei, jetzt funktioniert es ja, auch wenn ich nicht weiß warum.

[timtom2000]

Update...ich weiß nun warum es plötzlich ging und ein anderes Mal nicht.

Ist aber ein EXTREM merkwürdiges Verhalten, aber es ist reproduzierbar. Kann eigentlich nur ein Bug sein.

1) Definiere ich das notify wie folgt, funktioniert es:
define Compr notify Mythz:sGlobal:.* get Mythz sHeatDHWDay

2) Lasse ich den Namen des notifys mit "N" anfangen, funktioniert es nicht:
define NCompr notify Mythz:sGlobal:.* get Mythz sHeatDHWDay

Im ersten Fall wird
- das notify ausgelöst
- das reading sHeatDHWDay gelesen
- der get-Befehl im Event-Monitor angezeigt
- der Wert des readings sHeatDHWDay im Logfile protokolliert

Im zweiten Fall wird
- das notify ausgelöst
- das reading sHeatDHWDay gelesen
- der get-Befehl im Event-Monitor angezeigt
- der Wert des readings sHeatDHWDay im Logfile nicht protokolliert

Hört sich unglaubhaft an, aber es ist so...

Ich habe meine notifys alle umbenannt und kann damit leben. Aber gewollt ist sicher was anderes?!

Anmerkung: Hier wurde das auch mal thematisiert (aber nicht auf die Ursache zurückgeführt):
https://forum.fhem.de/index.php/topic,74347.0.html

[amenomade]

Im ersten Fall wird
- das notify ausgelöst
- das reading sHeatDHWDay gelesen
- der Wert des readings sHeatDHWDay im Logfile protokolliert

Im zweiten Fall wird
- das notify ausgelöst
- das reading sHeatDHWDay gelesen
- der Wert des readings sHeatDHWDay im Logfile nicht protokolliert

Wenn in beiden Fällen das reading gelesen wird, funktioniert doch das notify und das get. Dann ist die Ursache eher in Mythz zu suchen.

[timtom2000]

Wieso Ursache in Mythz? Das Logfile hat mit dem Device doch gar nichts zutun?!

So ist es definiert:

Code Auswählen Erweitern

define FileLog_HeatDHWDay FileLog /var/media/ftp/usb_data/log_signals/HeatDHWDay-%Y-KW%W.log Mythz:sHeatDHWDay.*

[amenomade]

Wieso Ursache in Mythz? Das Logfile hat mit dem Device doch gar nichts zutun?!

Natürlich doch. Das Device generiert (oder nicht) die Events, die ggf in der Logfile landen.
Was siehst Du im EventMonitor?

[timtom2000]

Im Event-Monitor sieht in beiden Fällen alles identisch aus, da taucht das get immer zuverlässig auf (habe ich oben im Text grad mal ergänzt). Genau deswegen denke ich, dass es mit dem Device nichts zutun hat.

[amenomade]

Kommt ein Event "Mythz sHeatDHWDay" in beiden Fällen oder nicht? Zeig bitte wie es aussieht wenn es geht und wenn es nicht geht

[timtom2000]

Gerne. Unten ein durchgehender Auszug aus Event-Monitor sowie Auszug aus Logfile.

Ich habe einmal ein notify "NCompr_Not_Ok" (17:56:31) und einmal ein notify "Compr_Ok" definiert (17:57:58).
Das triggernde sGlobal kommt zu 17:57:18 bzw. 17:59:15, sHeatDHWDay wird zeitgleich ausgelesen (sGlobal triggert noch weitere Readings).
Im Logfile taucht aber nur der Eintrag von 17:59:15 auf.

Code Auswählen Erweitern

2021-07-04 17:56:31 notify NCompr_Not_Ok active
2021-07-04 17:56:31 Global global DEFINED NCompr_Not_Ok
2021-07-04 17:57:18 THZ Mythz sGlobal: outsideTemp: 20.3 flowTemp: 30.4 returnTemp: 31 hotGasTemp: 31.7 dhwTemp: 47.3 flowTempHC2: -60 evaporatorTemp: 31.2 condenserTemp: 27.4 mixerOpen: 0 mixerClosed: 0 heatPipeValve: 0 diverterValve: 0 dhwPump: 0 heatingCircuitPump: 0 solarPump: 0 compressor: 0 boosterStage3: 0 boosterStage2: 0 boosterStage1: 0 highPressureSensor: 0 lowPressureSensor: 0 evaporatorIceMonitor: 0 signalAnode: 0 evuRelease: 1 ovenFireplace: 1 STB: 0 outputVentilatorPower: 0 inputVentilatorPower: 0 mainVentilatorPower: 0 outputVentilatorSpeed: 0 inputVentilatorSpeed: 0 mainVentilatorSpeed: 0 outside_tempFiltered: 21.7 relHumidity: 0 dewPoint: 0 P_Nd: 10.76 P_Hd: 11.01 actualPower_Qc: 0.000 actualPower_Pel: 0.000 collectorTemp: -60 insideTemp: 25.6 windowOpen: 0 quickAirVent: 0 flowRate: 0 p_HCw: 1.66 humidityAirOut: 41.27
2021-07-04 17:57:18 THZ Mythz uOutsideTemp: 20.3
2021-07-04 17:57:18 THZ Mythz uFlowTemp: 30.4
2021-07-04 17:57:18 THZ Mythz uDHWTemp: 47.3
2021-07-04 17:57:18 THZ Mythz uAussenTFilt: 21.7
2021-07-04 17:57:18 THZ Mythz uHumidityAirOut: 41.27
2021-07-04 17:57:18 THZ Mythz uSpreizung: -0.600000000000001
2021-07-04 17:57:18 THZ Mythz sHeatDHWDay: 7458 Wh
2021-07-04 17:57:44 Global global DELETED NCompr_Not_Ok
2021-07-04 17:57:58 notify Compr_Ok active
2021-07-04 17:57:58 Global global DEFINED Compr_Ok
2021-07-04 17:58:09 THZ Mythz sHC1: outsideTemp: 20.3 x08: 0 returnTemp: 31 integralHeat: 0 flowTemp: 30.4 heatSetTemp: 8 heatTemp: 30.8 seasonMode: summer integralSwitch: 200 hcOpMode: setback roomSetTemp: 15 x60: 0 x64: 0 insideTempRC: 21.5 x72: 0 x76: 0 onHysteresisNo: 0 offHysteresisNo: 0 hcBoosterStage: 0
2021-07-04 17:58:09 THZ Mythz uInsideTemp: 21.5
2021-07-04 17:59:15 THZ Mythz sGlobal: outsideTemp: 20.3 flowTemp: 30.5 returnTemp: 31.1 hotGasTemp: 31.6 dhwTemp: 47.3 flowTempHC2: -60 evaporatorTemp: 31.2 condenserTemp: 27.4 mixerOpen: 0 mixerClosed: 0 heatPipeValve: 0 diverterValve: 0 dhwPump: 0 heatingCircuitPump: 0 solarPump: 0 compressor: 0 boosterStage3: 0 boosterStage2: 0 boosterStage1: 0 highPressureSensor: 0 lowPressureSensor: 0 evaporatorIceMonitor: 0 signalAnode: 0 evuRelease: 1 ovenFireplace: 1 STB: 0 outputVentilatorPower: 0 inputVentilatorPower: 0 mainVentilatorPower: 0 outputVentilatorSpeed: 0 inputVentilatorSpeed: 0 mainVentilatorSpeed: 0 outside_tempFiltered: 21.7 relHumidity: 0 dewPoint: 0 P_Nd: 10.81 P_Hd: 11.01 actualPower_Qc: 0.000 actualPower_Pel: 0.000 collectorTemp: -60 insideTemp: 25.5 windowOpen: 0 quickAirVent: 0 flowRate: 0 p_HCw: 1.66 humidityAirOut: 40.95
2021-07-04 17:59:15 THZ Mythz uFlowTemp: 30.5
2021-07-04 17:59:15 THZ Mythz uReturnTemp: 31.1
2021-07-04 17:59:15 THZ Mythz uHumidityAirOut: 40.95
2021-07-04 17:59:15 THZ Mythz sHeatDHWDay: 7458 Wh
2021-07-04 17:59:29 THZ Mythz sDHW: dhwTemp: 47.3 outsideTemp: 20.2 dhwSetTemp: 41 compBlockTime: 0 out: 0000 heatBlockTime: 1123 dhwBoosterStage: 0 pasteurisationMode: 0 dhwOpMode: normal x36: 3C4C
2021-07-04 17:59:31 at at_Handbetrieb Next: 18:04:30
2021-07-04 17:59:39 Global global DELETED Compr_Ok

Code Auswählen Erweitern

2021-07-04_09:30:14 sHeatDHWDay: 3776 Wh
2021-07-04_14:18:11 sHeatDHWDay: 3777 Wh
2021-07-04_14:53:14 sHeatDHWDay: 7458 Wh
2021-07-04_17:59:14 sHeatDHWDay: 7458 Wh

[amenomade]

Hmm. In der Tat merkwürdig.
Hättest Du bitte ein komplettes "list" vom FileLog Device?

[timtom2000]

Ja, wenn ich das nicht selber sehen würde, würde ich es auch nicht glauben...unten das list.

Hast du dir mal den Spaß gemacht und solche zwei notifys + logfile definiert? Der Trigger kann irgendwas sein, ebenso das per get ausgelesene reading. Wäre mal interessant, ob du das nachstellen kannst...

Code Auswählen Erweitern

Internals:
   DEF        /var/media/ftp/usb_data/log_signals/HeatDHWDay-%Y-KW%W.log Mythz:sHeatDHWDay.*
   FD         34
   FUUID      60d4f670-f33f-a459-4002-3c2df15cdfcfa936
   NAME       FileLog_HeatDHWDay
   NOTIFYDEV  Mythz
   NR         136
   NTFY_ORDER 50-FileLog_HeatDHWDay
   REGEXP     Mythz:sHeatDHWDay.*
   STATE      active
   TYPE       FileLog
   currentlogfile /var/media/ftp/usb_data/log_signals/HeatDHWDay-2021-KW26.log
   logfile    /var/media/ftp/usb_data/log_signals/HeatDHWDay-%Y-KW%W.log
   READINGS:
     2021-07-04 17:59:14   linesInTheFile  79
Attributes:
   archivedir /var/media/ftp/usb_data/log_signals/archive/
   nrarchive  2
   outputFormat "$TIMESTAMP $EVENT\n"