Problem mit DOIF nach dem letzten Update

PatrickR · 06 November 2019, 20:51:51

Guten Abend zusammen,

ich habe gestern (nach mehreren Wochen) FHEM mal wieder auf den aktuellen Stand gebracht. Ich verwende zwei DOIFs die bspw. mein Garagenfenster öffnen wenn sie zuvor entsperrt wurden:

Code Auswählen


Internals:
   DEF        ([?$SELF:P_Locked, "locked"] eq "unlocked" and [$SELF:"(open|close)"])
	(set AU.GR.Fensteroeffner $EVENT)
	(set $SELF cmd_2_1)

DOELSEIF ([$SELF:P_Locked, "locked"] eq "unlocked")
	()
	(set $SELF P_Locked locked)

   FUUID      5d86cf58-f33f-5676-72c5-8481244ca2ea3bbb
   MODEL      FHEM
   NAME       D_L_AU.GR.Fensteroeffner
   NOTIFYDEV  global,D_L_AU.GR.Fensteroeffner
   NR         372
   NTFY_ORDER 50-D_L_AU.GR.Fensteroeffner
   STATE      locked
   TYPE       DOIF
   VERSION    20423 2019-10-29 18:50:08
   READINGS:
     2019-11-06 20:45:11   P_Locked        locked
     2019-11-06 20:45:11   cmd             2.2
     2019-11-06 20:45:11   cmd_event       D_L_AU.GR.Fensteroeffner
     2019-11-06 20:45:11   cmd_nr          2
     2019-11-06 20:45:11   cmd_seqnr       2
     2019-11-06 20:45:01   e_D_L_AU.GR.Fensteroeffner_P_Locked unlocked
     2019-11-06 20:45:01   e_D_L_AU.GR.Fensteroeffner_events P_Locked: unlocked
     2019-11-06 20:41:56   mode            enabled
     2019-11-06 20:45:11   state           locked
     2019-11-06 20:45:11   wait_timer      no timer
   Regex:
     accu:
     cond:
       D_L_AU.GR.Fensteroeffner:
         0:
           &STATE     ^D_L_AU.GR.Fensteroeffner$
         1:
           P_Locked   ^D_L_AU.GR.Fensteroeffner$:^P_Locked: 
   attr:
     cmdState:
       0:
         command sent
         command sent
       1:
         unlocked
         locked
     wait:
       0:
         0
         0
       1:
         0
         10
     waitdel:
   condition:
     0          ::ReadingValDoIf($hash,'D_L_AU.GR.Fensteroeffner','P_Locked',' "locked"') eq "unlocked" and ::EventDoIf('D_L_AU.GR.Fensteroeffner',$hash,'(open|close)',1)
     1          ::ReadingValDoIf($hash,'D_L_AU.GR.Fensteroeffner','P_Locked',' "locked"') eq "unlocked"
   do:
     0:
       0          set AU.GR.Fensteroeffner $EVENT
       1          set D_L_AU.GR.Fensteroeffner cmd_2_1
     1:
       0          
       1          set D_L_AU.GR.Fensteroeffner P_Locked locked
     2:
   helper:
     DEVFILTER  ^global$|^D_L_AU.GR.Fensteroeffner$
     NOTIFYDEV  global|D_L_AU.GR.Fensteroeffner
     event      P_Locked: unlocked
     globalinit 1
     last_timer 0
     sleepdevice D_L_AU.GR.Fensteroeffner
     sleepsubtimer -1
     sleeptimer -1
     timerdev   D_L_AU.GR.Fensteroeffner
     timerevent P_Locked: unlocked
     triggerDev D_L_AU.GR.Fensteroeffner
     timerevents:
       P_Locked: unlocked
       cmd_seqnr: 1
       cmd: 2.1
       unlocked
       wait_timer: 06.11.2019 20:45:11 cmd_2_2 D_L_AU.GR.Fensteroeffner
     timereventsState:
       P_Locked: unlocked
       cmd_seqnr: 1
       cmd: 2.1
       unlocked
       wait_timer: 06.11.2019 20:45:11 cmd_2_2 D_L_AU.GR.Fensteroeffner
     triggerEvents:
       P_Locked: unlocked
       cmd_seqnr: 1
       cmd: 2.1
       unlocked
       wait_timer: 06.11.2019 20:45:11 cmd_2_2 D_L_AU.GR.Fensteroeffner
     triggerEventsState:
       P_Locked: unlocked
       cmd_seqnr: 1
       cmd: 2.1
       unlocked
       wait_timer: 06.11.2019 20:45:11 cmd_2_2 D_L_AU.GR.Fensteroeffner
   internals:
   perlblock:
   readings:
     all         D_L_AU.GR.Fensteroeffner:P_Locked 
   trigger:
     all         D_L_AU.GR.Fensteroeffner 
   uiState:
   uiTable:
Attributes:
   cmdIcon    open:fts_window_1w_tilt close:fts_window_1w stop:time_manual_mode
   cmdState   command sent,command sent|unlocked,locked
   do         resetwait
   event-on-change-reading .*
   group      Locks
   icon       secur_locked
   readingList P_Locked
   room       Auto
   setList    P_Locked:locked,unlocked open close stop
   wait       0,0:0,10
   webCmd     P_Locked:open:close:stop

Seit dem o. g. Update kann ich das DOIF zwar entsperren (cmdState unlocked) aber keinen Command senden.

Code Auswählen


2019-11-06 20:49:40.156 DOIF D_L_AU.GR.Fensteroeffner P_Locked: unlocked
2019-11-06 20:49:40.156 DOIF D_L_AU.GR.Fensteroeffner cmd_seqnr: 1
2019-11-06 20:49:40.156 DOIF D_L_AU.GR.Fensteroeffner cmd: 2.1
2019-11-06 20:49:40.156 DOIF D_L_AU.GR.Fensteroeffner unlocked
2019-11-06 20:49:40.156 DOIF D_L_AU.GR.Fensteroeffner wait_timer: 06.11.2019 20:49:50 cmd_2_2 D_L_AU.GR.Fensteroeffner
2019-11-06 20:49:41.227 DOIF D_L_AU.GR.Fensteroeffner open
2019-11-06 20:49:50.153 DOIF D_L_AU.GR.Fensteroeffner wait_timer: no timer
2019-11-06 20:49:50.158 DOIF D_L_AU.GR.Fensteroeffner P_Locked: locked
2019-11-06 20:49:50.165 DOIF D_L_AU.GR.Fensteroeffner cmd_seqnr: 2
2019-11-06 20:49:50.165 DOIF D_L_AU.GR.Fensteroeffner cmd: 2.2
2019-11-06 20:49:50.165 DOIF D_L_AU.GR.Fensteroeffner locked

Wie man sieht, wechselt das DOIF zwar in den entsperrten Zustand (2.1) und nach dem Timeout dann in (2.2), nicht aber in die Status, die den Command durchreichen (1.1/1.2).

Das Problem trat das letzte Mal mit der Integration von NOTIFYDEV auf und bis gestern funktionierte alles einwandfrei.

Patrick

Damian · 06 November 2019, 21:04:08

Welche Version lief denn zuletzt noch korrekt?

Ich verstehe das Problem nicht. Was verstehst du unter?

Zitat.. nicht aber in die Status, die den Command durchreichen (1.1/1.2)

Der Status ist doch locked, was 2.2 entspricht.

PatrickR · 07 November 2019, 17:32:22

Hi!

Zitat von: Damian am 06 November 2019, 21:04:08
Welche Version lief denn zuletzt noch korrekt?

So weit ich das aus den Backups rekonstruieren kann die Version vom 2019-09-28 21:00 (lt. $Id).

Zitat von: Damian am 06 November 2019, 21:04:08
Ich verstehe das Problem nicht. Was verstehst du unter?

Der Status ist doch locked, was 2.2 entspricht.

Ich verstehe ehrlich gesagt nicht, warum Du das Problem nicht verstehst.

Da nach dem Wechsel zu 2.1 (unlocked) das Event "on" kommt müsste er in 1.1 springen. Das tut er aber nicht sondern verharrt in 2.1 (unlocked) und nach Ablauf des wait in 2.2 (locked).

Patrick

Damian · 08 November 2019, 09:39:44

An der neuen Version kann es nicht liegen, da zu Version vom 2019-09-28 nur eine Zeile für die Zeitumstellung geändert wurde.

Das Problem habe ich bei mir nicht reproduzieren können:

Zitat2019-11-08 09:34:18.669 DOIF di_set P_Locked: unlocked
2019-11-08 09:34:18.669 DOIF di_set e_di_set_P_Locked: unlocked
2019-11-08 09:34:18.669 DOIF di_set e_di_set_events: P_Locked: unlocked,e_di_set_P_Locked: unlocked
2019-11-08 09:34:18.669 DOIF di_set cmd_nr: 2
2019-11-08 09:34:18.669 DOIF di_set cmd_seqnr: 1
2019-11-08 09:34:18.669 DOIF di_set cmd: 2.1
2019-11-08 09:34:18.669 DOIF di_set cmd_event: di_set
2019-11-08 09:34:18.669 DOIF di_set cmd_2_1
2019-11-08 09:34:18.669 DOIF di_set wait_timer: 08.11.2019 09:35:58 cmd_2_2 di_set
2019-11-08 09:34:20.206 CUL_HM TH_WZ_HM desired-temp: 17.0
2019-11-08 09:34:20.206 CUL_HM TH_WZ_HM humidity: 57
2019-11-08 09:34:20.206 CUL_HM TH_WZ_HM measured-temp: 21.4
2019-11-08 09:34:20.206 CUL_HM TH_WZ_HM T: 21.4 desired: 17.0
2019-11-08 09:34:22.372 DOIF di_set open
2019-11-08 09:34:22.372 DOIF di_set e_di_set_events: open
2019-11-08 09:34:22.372 DOIF di_set wait_timer: no timer
2019-11-08 09:34:22.372 DOIF di_set cmd_nr: 1
2019-11-08 09:34:22.372 DOIF di_set cmd_seqnr: 1
2019-11-08 09:34:22.372 DOIF di_set cmd: 1.1
2019-11-08 09:34:22.372 DOIF di_set cmd_event: di_set
2019-11-08 09:34:22.372 DOIF di_set cmd_1_1
2019-11-08 09:34:22.372 DOIF di_set wait_timer: 08.11.2019 09:34:23 cmd_1_2 di_set
2019-11-08 09:34:23.732 DOIF di_set wait_timer: no timer
2019-11-08 09:34:23.735 DOIF di_set cmd_nr: 1
2019-11-08 09:34:23.735 DOIF di_set cmd_seqnr: 2
2019-11-08 09:34:23.735 DOIF di_set cmd: 1.2
2019-11-08 09:34:23.735 DOIF di_set cmd_event: di_set
2019-11-08 09:34:23.735 DOIF di_set cmd_1

Test-DOIF

Code Auswählen

Internals:
   CFGFN      
   DEF        ([?$SELF:P_Locked, "locked"] eq "unlocked" and [$SELF:"(open|close)"])
()
()
DOELSEIF ([$SELF:P_Locked, "locked"] eq "unlocked")
()
(set $SELF P_Locked locked)
   FUUID      5dc3280e-f33f-63f4-0194-7bb59d5826f67b83
   MODEL      FHEM
   NAME       di_set
   NOTIFYDEV  global,di_set
   NR         10629
   NTFY_ORDER 50-di_set
   STATE      cmd_1
   TYPE       DOIF
   VERSION    20241 2019-09-24 22:00:09
   READINGS:
     2019-11-08 09:34:18   P_Locked        unlocked
     2019-11-08 09:34:23   cmd             1.2
     2019-11-08 09:34:23   cmd_event       di_set
     2019-11-08 09:34:23   cmd_nr          1
     2019-11-08 09:34:23   cmd_seqnr       2
     2019-11-08 09:34:18   e_di_set_P_Locked unlocked
     2019-11-08 09:34:22   e_di_set_events open
     2019-11-07 18:38:59   mode            enabled
     2019-11-08 09:34:23   state           cmd_1
     2019-11-08 09:34:23   wait_timer      no timer
   Regex:
     accu:
     cond:
       di_set:
         0:
           &STATE     ^di_set$
         1:
           P_Locked   ^di_set$:^P_Locked: 
   attr:
     cmdState:
     wait:
       0:
         0
         1
       1:
         0
         100
     waitdel:
   condition:
     0          ::ReadingValDoIf($hash,'di_set','P_Locked',' "locked"') eq "unlocked" and ::EventDoIf('di_set',$hash,'(open|close)',1)
     1          ::ReadingValDoIf($hash,'di_set','P_Locked',' "locked"') eq "unlocked"
   do:
     0:
       0          
       1          
     1:
       0          
       1          set di_set P_Locked locked
     2:
   helper:
     DEVFILTER  ^global$|^di_set$
     NOTIFYDEV  global|di_set
     event      open
     globalinit 1
     last_timer 0
     sleepdevice di_set
     sleepsubtimer -1
     sleeptimer -1
     timerdev   di_set
     timerevent open
     triggerDev di_set
     timerevents:
       open
       e_di_set_events: open
       wait_timer: no timer
       cmd_nr: 1
       cmd_seqnr: 1
       cmd: 1.1
       cmd_event: di_set
       cmd_1_1
       wait_timer: 08.11.2019 09:34:23 cmd_1_2 di_set
     timereventsState:
       open
       e_di_set_events: open
       wait_timer: no timer
       cmd_nr: 1
       cmd_seqnr: 1
       cmd: 1.1
       cmd_event: di_set
       cmd_1_1
       wait_timer: 08.11.2019 09:34:23 cmd_1_2 di_set
     triggerEvents:
       open
       e_di_set_events: open
       wait_timer: no timer
       cmd_nr: 1
       cmd_seqnr: 1
       cmd: 1.1
       cmd_event: di_set
       cmd_1_1
       wait_timer: 08.11.2019 09:34:23 cmd_1_2 di_set
     triggerEventsState:
       open
       e_di_set_events: open
       wait_timer: no timer
       cmd_nr: 1
       cmd_seqnr: 1
       cmd: 1.1
       cmd_event: di_set
       cmd_1_1
       wait_timer: 08.11.2019 09:34:23 cmd_1_2 di_set
   internals:
   readings:
     all         di_set:P_Locked 
   trigger:
     all         di_set 
   uiState:
   uiTable:
Attributes:
   do         always
   readingList P_Locked
   room       DOIF
   setList    P_Locked:locked,unlocked open close stop
   wait       0,1:0,100

PatrickR · 08 November 2019, 13:38:23

Hi!

Zitat von: Damian am 08 November 2019, 09:39:44
An der neuen Version kann es nicht liegen, da zu Version vom 2019-09-28 nur eine Zeile für die Zeitumstellung geändert wurde.

Das Problem habe ich bei mir nicht reproduzieren können:

Ich habe gestern beide betroffene DOIFs gelöscht und durch erneutes Hinzufügen der Raw Definitions (Nur defmod und attr, aber ohne setstates) wieder angelegt. Ergebnis: Sie funktionieren wieder. Das ist natürlich insofern unbefriedigend, dass ich damit rechnen muss, dass nach einem Neustart das Problem wieder auftritt und ggf. noch weitere defekte DOIFs in meiner Installation lauern.

Patrick

PatrickR · 08 November 2019, 14:07:51

Hi!

Ich hänge mal zwei lists an, mit denen man hoffentlich die Unterschiede sieht. Leider gibt es diverse Abweichungen (teilweise natürlich Zeitstempel).

Patrick

Damian · 08 November 2019, 22:57:33

War ne harte Nuss, teste mal Version im Anhang.

Edit: Version eingecheckt

PatrickR · 09 November 2019, 14:22:27

Hi!

Zitat von: Damian am 08 November 2019, 22:57:33
War ne harte Nuss, teste mal Version im Anhang.

Danke. Werde ich tun. Ich wüsste nur leider nicht, wie ich das Problem rekonstruieren soll. Bewirkt der Fix, dass "defekte" Geräte wieder funktionieren oder dass sie zukünftig nicht mehr in den defekten Zustand wechseln?

/Edit: Gerade 98_DOIF.pm getauscht und FHEM durchgestartet. Sieht gut aus. Aber kann wie gesagt den Fehler nicht reproduzieren...

Patrick

Damian · 09 November 2019, 15:02:06

Zitat von: PatrickR am 09 November 2019, 14:22:27
Hi!
Danke. Werde ich tun. Ich wüsste nur leider nicht, wie ich das Problem rekonstruieren soll. Bewirkt der Fix, dass "defekte" Geräte wieder funktionieren oder dass sie zukünftig nicht mehr in den defekten Zustand wechseln?

/Edit: Gerade 98_DOIF.pm getauscht und FHEM durchgestartet. Sieht gut aus. Aber kann wie gesagt den Fehler nicht reproduzieren...

Patrick

Der Fehler war schwierig zu finden, war aber eindeutig. Es fehlte eine Initialisierung einer Variablen. Das machte sich, je nach Speicherbelegung nur dann bemerkbar, wenn man mehrere Triggerdefinitionen zum gleichen Device hatte und eine davon ein Ereignistrigger war, wie in deiner Definition [$SELF:"(open|close)"]. Das Problem hatte aber nichts mit NOTIFYDEV-Umstellung zu tun.

Damian · 09 November 2019, 20:41:22

Korrigierte Version wurde eingecheckt.

PatrickR · 10 November 2019, 10:25:00

Zitat von: Damian am 09 November 2019, 20:41:22
Korrigierte Version wurde eingecheckt.

Danke für den schnellen Fix!

Von unterwegs gesendet.

Phiolin · 11 November 2019, 15:00:19

Ich bin gespannt, ob das auch meine merkwürdigen Probleme behebt.

In letzter Zeit habe ich immer mal die Situation, das einige DOIFs nicht auslösen obwohl definitiv das passende Event generiert wurde (andere DOIFs reagieren auf das Event auch, also lag es nicht an der Generierung des Events selber). In den Readings des DOIF sind dann teilweise tatsächlich falsche "e_" Readings, die nicht die Werte haben, die das passende Device gerade hat.
Beispielsweise habe ich einige DOIFs die beim Event "rgr_Bewohner gotosleep" laufen sollten. Manche davon laufen, eines lief gestern aber nicht.
Dort war im "e_rgr_Bewohner_STATE" Reading tatsächlich auch nicht "gotosleep" vermerkt, sondern "home". So als hätte das DOIF das Event irgendwie verpasst.
Ich habe dann bisher genau wie PatrickR das DOIF einfach neu erstellt, das hat das Problem in der Regel behoben.
Da das leider immer schwierig zu reproduzieren war, hab ich dazu bisher keinen Thread aufgemacht.

Beschreibt das zufällig das hier gelöste Problem?

Damian · 11 November 2019, 15:48:46

Zitat von: Phiolin am 11 November 2019, 15:00:19
Ich bin gespannt, ob das auch meine merkwürdigen Probleme behebt.

In letzter Zeit habe ich immer mal die Situation, das einige DOIFs nicht auslösen obwohl definitiv das passende Event generiert wurde (andere DOIFs reagieren auf das Event auch, also lag es nicht an der Generierung des Events selber). In den Readings des DOIF sind dann teilweise tatsächlich falsche "e_" Readings, die nicht die Werte haben, die das passende Device gerade hat.
Beispielsweise habe ich einige DOIFs die beim Event "rgr_Bewohner gotosleep" laufen sollten. Manche davon laufen, eines lief gestern aber nicht.
Dort war im "e_rgr_Bewohner_STATE" Reading tatsächlich auch nicht "gotosleep" vermerkt, sondern "home". So als hätte das DOIF das Event irgendwie verpasst.
Ich habe dann bisher genau wie PatrickR das DOIF einfach neu erstellt, das hat das Problem in der Regel behoben.
Da das leider immer schwierig zu reproduzieren war, hab ich dazu bisher keinen Thread aufgemacht.

Beschreibt das zufällig das hier gelöste Problem?

Es konnte immer dann passieren, wenn du innerhalb eines DOIFs mehrfach das gleiche Device angegeben hast.