unerwünschtes/unerwartetes verhalten bei gesetztem $hash->{NotifyOrderPrefix}

[Der_Tom]

Hallo,

ich habe ein Verhalten beim setzen dieses Hashes , welches dem 'DevelopmentModuleIntro' so nicht zu entnehmen ist .
Ich ging davon aus , das ein setzen des Präfixes nur die Reihenfolge des Auslieferns von Events an Module beeinflusst .

Jetzt habe ich bemerkt, das ich (einige) Events schlicht nicht mehr erhalte , wenn ich hier eine Präfix von "45-" setze. Ist dieses Bekannt oder Erklärbar ?

Konkret erhate ich kein Event (DEFINED) mehr wenn ich das angegebene Device lösche und es danach von auocreate neu angelegt wird.

EVENT   ->  global:DEFINED.MQTT2_DVES_29FA8D

alle anderen Events von "global" kommen problemlos an , ändere ich das Präfix auf 50 kommt auch dieses wieder an.

Da ich eingehenden Event direkt am Anfang der "X_Notify" habe ausgeben lassen , dürfte hier auch der weitere Code des Moduls keine Rolle spielen.

Code Auswählen Erweitern

sub MSwitch_Notify($$) {
    my $testtoggle = '';
    my ( $own_hash, $dev_hash ) = @_;
    my $ownName = $own_hash->{NAME};   
    my $devName;
    $devName = $dev_hash->{NAME};
my $devType = $dev_hash->{TYPE};
    my $events = deviceEvents( $dev_hash, 1 );
    my $statistic=0;
    delete $data{MSwitch}{$ownName}{setdata};
   

if ($ownName eq "globetest")
{

foreach my $event (@{$events})
  {
  MSwitch_LOG( $ownName, 0,"MSWITCH AKTEVENT: $event " . __LINE__ );
  }
}


Für mich ist dieses Problem mit setzen des Präfixes 50 aber im Grunde behoben , ich kann es mir halt nur nicht erklären.


gruss Thomas

[rudolfkoenig]

So ein Verhalten ist weder geplant, noch bekannt, und ich habe dafuer auf Anhieb keinen Grund im Code gefunden.
Da das Problem anhand des Textes hier nachzustellen nicht trivial ist: kannst Du mir dabei helfen, mit Anleitung und/oder Beispiel-fhem.cfg?

[Der_Tom]

Gerne, schaffe ich aber erst morgen früh da was nachvollziehbares zusammenzustellen.

Gruss Thomas

[Der_Tom]

das verhalten ist auch mit einem Notify reproduzierbar .

ich setze den Trigger eines notifys auf das DEFINED eines beliebigen mqtt devices ( eines , welches regelmässig daten empfängt, um autocreate auszulösen) - in diesem Fall "MQTT2_DVES_29FA8D".

Das Notify lasse ich nur einen Logeintrag erstellen bei Triggerung:

raw notify:

Code Auswählen Erweitern

defmod global_notify_1 notify global:DEFINED.MQTT2_DVES_29FA8D {Log3 "test", 0, "NOTIFY eingehendes event defined" }

setstate global_notify_1 2021-12-08 20:21:19
setstate global_notify_1 2021-12-08 20:25:08 state active
setstate global_notify_1 2021-12-08 20:21:19 triggeredByDev global
setstate global_notify_1 2021-12-08 20:21:19 triggeredByEvent DEFINED MQTT2_DVES_29FA8D


Nun lösche ich das MQTT Device und warte auf den Empfang von daten ( kein fhemneustart ) , um den autocreate auszulösen.

Erwartungsgemäss triggert das Notify und schreibt den Logeintrag .


Wenn ich nun im 90_notify.pm folgende Zeile ergänze :

Code Auswählen Erweitern

(Zeile 36) $hash->{NotifyOrderPrefix} = "45-";

und Fhem neustarte ( jetzt: NTFY_ORDER 45-global_notify_1) und das ganze wiederhole wird dieses Notify nicht mehr getriggert , da entprechendes Event nicht an das Modul verteilt wird.

ist bei mir jederzeit Reproduzierbar , habe es allerdings nur mit MQTT_Devices probiert - was aber an der Grundproblematik wohl keine Rolle spielen sollte .

Hoffe ich habe es reproduzierbar beschrieben , auf Notify bin ich ausgewichen um andere Ursachen (MSwitch ) von Vornherein auszuschliessen .

gruss Thomas

[Der_Tom]

Hier noch die Logs der eingehenden Events des triggernden Devices über den kompletten Ablauf:

Raw Notify:

Code Auswählen Erweitern

defmod global_notify_1 notify global:.*MQTT2_DVES_29FA8D {Log3 "test", 0, "NOTIFY eingehendes event $EVENT" }
attr global_notify_1 room DOIF

setstate global_notify_1 2021-12-09 05:32:59
setstate global_notify_1 2021-12-09 05:32:50 state active
setstate global_notify_1 2021-12-09 05:32:59 triggeredByDev global
setstate global_notify_1 2021-12-09 05:32:59 triggeredByEvent DELETED MQTT2_DVES_29FA8D

----


bei Notify mit Präfix 45  (NTFY_ORDER 45-global_notify_1) :

list notify:

Code Auswählen Erweitern

Internals:
   DEF        global:.*MQTT2_DVES_29FA8D.* {Log3 "test", 0, "NOTIFY eingehendes event $EVENT" }
   FUUID      61b1048d-f33f-d26a-e380-d4c6cec6a2fce734
   NAME       global_notify_1
   NOTIFYDEV  global
   NR         424
   NTFY_ORDER 45-global_notify_1
   REGEXP     global:.*MQTT2_DVES_29FA8D.*
   STATE      2021-12-09 05:38:09
   TRIGGERTIME 1639024689.55925
   TYPE       notify
   READINGS:
     2021-12-09 05:37:49   state           active
     2021-12-09 05:38:09   triggeredByDev  global
     2021-12-09 05:38:09   triggeredByEvent DELETED MQTT2_DVES_29FA8D
Attributes:
   room       DOIF

Log:

Code Auswählen Erweitern

2021.12.09 05:38:09 0: NOTIFY eingehendes event DELETED MQTT2_DVES_29FA8D
2021.12.09 05:41:27 0: NOTIFY eingehendes event UNDEFINED MQTT2_DVES_29FA8D MQTT2_DEVICE DVES_29FA8D myBroker
2021.12.09 05:41:27 0: NOTIFY eingehendes event ATTR MQTT2_DVES_29FA8D readingList DVES_29FA8D:tele/DVES_29FA8D/STATE:.* { json2nameValue($EVENT) }



----


bei Notify mit Präfix 50  ( NTFY_ORDER 50-global_notify_1) :
list notify:

Code Auswählen Erweitern

Internals:
   DEF        global:.*MQTT2_DVES_29FA8D.* {Log3 "test", 0, "NOTIFY eingehendes event $EVENT" }
   FUUID      61b1048d-f33f-d26a-e380-d4c6cec6a2fce734
   NAME       global_notify_1
   NOTIFYDEV  global
   NR         424
   NTFY_ORDER 50-global_notify_1
   REGEXP     global:.*MQTT2_DVES_29FA8D.*
   STATE      2021-12-09 05:43:36
   TRIGGERTIME 1639025016.74622
   TYPE       notify
   READINGS:
     2021-12-09 05:43:06   state           active
     2021-12-09 05:43:36   triggeredByDev  global
     2021-12-09 05:43:36   triggeredByEvent ATTR MQTT2_DVES_29FA8D readingList DVES_29FA8D:tele/DVES_29FA8D/STATE:.* { json2nameValue($EVENT) }
DVES_29FA8D:tele/DVES_29FA8D/LWT:.* LWT
DVES_29FA8D:cmnd/DVES_29FA8D/POWER:.* POWER
DVES_29FA8D:tasmota/discovery/DC4F2229FA8D/config:.* { json2nameValue($EVENT) }
DVES_29FA8D:tasmota/discovery/DC4F2229FA8D/sensors:.* { json2nameValue($EVENT) }
Attributes:
   room       DOIF

Log:

Code Auswählen Erweitern

2021.12.09 05:45:22 0: NOTIFY eingehendes event DELETED MQTT2_DVES_29FA8D
2021.12.09 05:46:30 0: NOTIFY eingehendes event UNDEFINED MQTT2_DVES_29FA8D MQTT2_DEVICE DVES_29FA8D myBroker
---> 2021.12.09 05:46:30 0: NOTIFY eingehendes event DEFINED MQTT2_DVES_29FA8D
2021.12.09 05:46:30 0: NOTIFY eingehendes event DEFINED FileLog_MQTT2_DVES_29FA8D
2021.12.09 05:46:31 0: NOTIFY eingehendes event ATTR MQTT2_DVES_29FA8D readingList DVES_29FA8D:tele/DVES_29FA8D/STATE:.* { json2nameValue($EVENT) }



gruss Thomas


PS: aufgefallen ist das ganze im übrigen im Zusammenhang mit diesem Thread :
https://forum.fhem.de/index.php?topic=124618.msg1191850#msg1191850
da es 87Insane nicht möglich war per MSwitch auf das eingehende Reading "DEFINED" zu reagieren, per Notify schon.
Der einzig in Frage kommende Unterschied war das Präfix.

[rudolfkoenig]

Ablauf:
- MQTT2_DEVICE erzeugt ein "global UNDEFINED" event
- autocreate (mit NTFY_ORDER 50-autocreate) ruft define auf, was an die gerade aktive CHANGED Liste von global ein DEFINE Eintrag hinten _anhaengt_
- notify kommt wegen NTFY_ORDER 50-global_notify_1 nach autocreate, kriegt die CHANGED Liste mit UNDEFINED _und_ DEFINED, und reagiert.

Wenn notify (oder MSwitch, usw) wegen NotifyOrderPrefix 45- vor dem autocreate aufgerufen wird, dann ist in der Liste noch kein DEFINED Eintrag.

Oder auch: man kann nicht erwarten, dass man alles mitkriegt, wenn man sich nach vorne draengelt.

[Beta-User]

...wobei sich die Frage stellt, warum autocreate sich nicht noch weiter nach vorne drängelt ...

[Der_Tom]

Hmm,

Ist für mich zwar bis zu einem gewissen Punkt nachvollziehbar , aber ....

Da es aber eine dokumentierte Funktion gibt , die explizit dafür gedacht ist sich "vorzudrängeln" klingt das ganze für mich irgendwie nach einer komplizierteren Umschreibung für "hier gibt es ein Problem" , aber selber Schuld , wenn man diese Funktion nutzt..

Aber , wie gesagt , das Problem ist ja durch "nicht nutzen" dieser Funktion behoben.


Ein Hinweis in der Doku auf den Umstand, dass bei Nutzung dieser Funktion ggf. Events "verschluckt" werden wäre evtl.  nicht verkehrt.

Danke für die Erklärung.

Gruss Thomas

[87insane]

Ich verweise auch mal in die andere Richtung.... Sehe hier durchaus das gleiche Thema.

Gruß,
87insane

[Beta-User]

Aber , wie gesagt , das Problem ist ja durch "nicht nutzen" dieser Funktion behoben.

Sicher?

Benenne mal dein autocreate um nach "ZZ_autocreate" oder den davon abhängigen Eventhandler nach "1n_handler"...

Das eigentliche Problem ist, dass diese Zusammenhänge zu wenig bekannt sind...

[Der_Tom]

Sicher?

Benenne mal dein autocreate um nach "ZZ_autocreate" oder den davon abhängigen Eventhandler nach "1n_handler"...

Das eigentliche Problem ist, dass diese Zusammenhänge zu wenig bekannt sind...

Nein, nicht sicher . Ich werde es heute Abend Mal versuchen.

Unabhängig davon, wem welche Zusammenhänge bekannt oder nicht bekannt sind , könnte ich eine hier auftretende Problematik ja
Sowieso nicht ändern (mein System evtl. ausgenommen).

Es funktioniert nun in MSwitch genauso gut oder genauso schlecht wie in allen weiteren Eventhändlern .

Reicht mir nach meinen Erfahrungen aus ..
Muss ausreichen.

Gruss thomas

[rudolfkoenig]

Da es aber eine dokumentierte Funktion gibt , die explizit dafür gedacht ist sich "vorzudrängeln" klingt das ganze für mich irgendwie nach einer komplizierteren Umschreibung für "hier gibt es ein Problem" ,

Klar gibts ein Problem: manche Module moechten die Events mit weiteren erweitern, und damit gibts ein Reihenfolgenproblem: wer soll vor wem bei der Benachrichtigung drankommen. Mir ist schon klar, dass diese Loesung nicht perfekt ist, ist aber z.Zt. in meinem Augen der beste Kompromiss.

aber selber Schuld , wenn man diese Funktion nutzt..

Das klingt fuer mich so, als ob der Erfinder des Lenkrads dran Schuld sein sollte, wenn jemand den Wagen gegen den Baum lenkt.

[Beta-User]

...wobei sich die Frage stellt, warum autocreate sich nicht noch weiter nach vorne drängelt ...

Klar sind das eher seltene Fälle, aber sauberer wäre das, denn ohne Device keine weiteren Verarbeitungsschritte... (eigentlich sogar noch vor readingsChange).

[Der_Tom]

Nunja .. zum letzten Zitat..

Das war ja im Grunde eher Deine Aussage , nicht meine.

Ich finde Diese Argumentation halt nicht wirklich Zielführend.

Oder auch: man kann nicht erwarten, dass man alles mitkriegt, wenn man sich nach vorne draengelt.

Die Aussage das es so ist ... Und es ist so weil ...
Ist ja absolut OK und das Thema war erledigt.

Lassen wir es auf sich beruhen und Falls andere Mal ein ähnliches Problem haben werden Sie es ja ggf. Diesen Thread finden.

Gruss Thomas

[Beta-User]

Das war ja im Grunde eher Deine Aussage , nicht meine.
[...]
Lassen wir es auf sich beruhen und Falls andere Mal ein ähnliches Problem haben werden Sie es ja ggf. Diesen Thread finden.

Klar war das meine Aussage, was anderes war nicht behauptet.

Es ist nur leider nicht so, dass nicht hin und wieder User über das Problem stolpern... Sonst hätte ich das Thema auch nicht aufgegriffen, und z.B. auch nicht für MQTT_GENERIC_BRIDGE vorgeschlagen, eine hohe Zahl zu vergeben (=> nach außen irgendwelche Reading-Werte zu versenden ist in der Verarbeitungskette eher ganz hinten, und es macht (eher sehr gelegentlich, aber vom grundsätzlichen Ablauf her gedacht) Sinn zu warten, ob nicht irgendjemand meint, noch ein "setreading" per anderem Eventhandler absetzen zu müssen).