DOIF: zweiter Ausführungsteil wird doppelt ausgeführt. Aber warum?

Begonnen von WhyTea, 05 Juni 2023, 11:45:07

Vorheriges Thema - Nächstes Thema

WhyTea

Hallo
Ich habe hier ein eigentlich recht simples DOIF aber wennder zweite Ausführungsteil wahr wird dann wird Dieser zweimal ausgeführt und ich verstehe nicht warum.

Hier ein List:
Internals:
   CFGFN      /var/fhem/FHEM/EG_Wohnzimmer.cfg
   DEF        (([EG_WZ_AV_Receiver:state] eq "on") and ([WOL_Shutdown_hyperion:state] ne "on"))
({Log 3, "AV_Receiver ist an: Hyperion gestartet"}, set WOL_Shutdown_hyperion on)
DOELSEIF (([EG_WZ_AV_Receiver:state] eq "off") and ([WOL_Shutdown_hyperion:state] ne "off"))
({Log 3, "AV_Receiver ist seit 5 Minuten aus: Hyperion ausgeschaltet"}, set WOL_Shutdown_hyperion off)
   FUUID      632c0cf9-f33f-a5a6-d914-b4fcb0219f0cb9a8
   MODEL      FHEM
   NAME       di.hyperion_schalter
   NOTIFYDEV  EG_WZ_AV_Receiver,global,WOL_Shutdown_hyperion
   NR         713
   NTFY_ORDER 50-di.hyperion_schalter
   STATE      cmd_2
   TYPE       DOIF
   VERSION    27616 2023-05-25 17:55:36
   eventCount 75
   READINGS:
     2023-06-05 11:29:31   Device          WOL_Shutdown_hyperion
     2023-06-05 07:33:51   cmd             2
     2023-06-05 07:33:51   cmd_event       WOL_Shutdown_hyperion
     2023-06-05 07:33:51   cmd_nr          2
     2023-06-05 11:28:56   e_EG_WZ_AV_Receiver_state off
     2022-09-22 12:06:42   e_WOL_Shutdown_hyperion_STATE off
     2023-06-05 11:29:31   e_WOL_Shutdown_hyperion_state off
     2023-06-03 01:06:47   mode            enabled
     2023-06-05 07:33:51   state           cmd_2
     2023-06-05 07:33:48   wait_timer      no timer
   Regex:
     accu:
     bar:
     barAvg:
     collect:
     cond:
       EG_WZ_AV_Receiver:
         0:
           state      ^EG_WZ_AV_Receiver$:^state:
         1:
           state      ^EG_WZ_AV_Receiver$:^state:
       WOL_Shutdown_hyperion:
         0:
           state      ^WOL_Shutdown_hyperion$:^state:
         1:
           state      ^WOL_Shutdown_hyperion$:^state:
   attr:
     cmdState:
     cmdpause:
       180
       180
     repeatsame:
     wait:
       0:
         0
       1:
         300
     waitdel:
   condition:
     0          (::ReadingValDoIf($hash,'EG_WZ_AV_Receiver','state') eq "on") and (::ReadingValDoIf($hash,'WOL_Shutdown_hyperion','state') ne "on")
     1          (::ReadingValDoIf($hash,'EG_WZ_AV_Receiver','state') eq "off") and (::ReadingValDoIf($hash,'WOL_Shutdown_hyperion','state') ne "off")
   do:
     0:
       0          {Log 3, "AV_Receiver ist an: Hyperion gestartet"}, set WOL_Shutdown_hyperion on
     1:
       0          {Log 3, "AV_Receiver ist seit 5 Minuten aus: Hyperion ausgeschaltet"}, set WOL_Shutdown_hyperion off
     2:
   helper:
     NOTIFYDEV  EG_WZ_AV_Receiver,global,WOL_Shutdown_hyperion
     event      isRunning: false,off
     globalinit 1
     last_timer 0
     sleepdevice WOL_Shutdown_hyperion
     sleepsubtimer -1
     sleeptimer -1
     timerdev   EG_WZ_AV_Receiver
     timerevent power: off,off,volumeStraight: -55.5,volume: 25,mute: off,input: hdmi1,inputName: FireTV,straight: on,enhancer: on,dsp: 5chstereo,3dCinemaDsp: auto,adaptiveDrc: auto,sleep: off,direct: off
     triggerDev WOL_Shutdown_hyperion
     bm:
       DOIF_Attr:
         cnt        7
         dmx        -1000
         dtot       0
         dtotcnt    0
         mTS        05.06. 10:59:27
         max        0.0246739387512207
         tot        0.0278451442718506
         mAr:
           set
           di.hyperion_schalter
           repeatsame
           1
       DOIF_Get:
         cnt        3
         dmx        -1000
         dtot       0
         dtotcnt    0
         mTS        05.06. 10:58:42
         max        0.0005340576171875
         tot        0.000567197799682617
         mAr:
           HASH(0x55578a73da78)
           di.hyperion_schalter
           ?
       DOIF_Notify:
         cnt        24833
         dmx        -1000
         dtot       0
         dtotcnt    0
         mTS        05.06. 06:38:22
         max        0.0601329803466797
         tot        21.8609974384308
         mAr:
           HASH(0x55578a73da78)
           HASH(0x55578a41f5f8)
       DOIF_Set:
         cnt        152
         dmx        -1000
         dtot       0
         dtotcnt    0
         mTS        05.06. 07:28:44
         max        0.000315189361572266
         tot        0.00624585151672363
         mAr:
           HASH(0x55578a73da78)
           di.hyperion_schalter
           ?
     timerevents:
       power: off
       off
       volumeStraight: -55.5
       volume: 25
       mute: off
       input: hdmi1
       inputName: FireTV
       straight: on
       enhancer: on
       dsp: 5chstereo
       3dCinemaDsp: auto
       adaptiveDrc: auto
       sleep: off
       direct: off
     timereventsState:
       power: off
       state: off
       volumeStraight: -55.5
       volume: 25
       mute: off
       input: hdmi1
       inputName: FireTV
       straight: on
       enhancer: on
       dsp: 5chstereo
       3dCinemaDsp: auto
       adaptiveDrc: auto
       sleep: off
       direct: off
     triggerEvents:
       isRunning: false
       off
     triggerEventsState:
       isRunning: false
       state: off
   hmccu:
   internals:
   readings:
     all         EG_WZ_AV_Receiver:state WOL_Shutdown_hyperion:state
   trigger:
   uiState:
   uiTable:
Attributes:
   DbLogExclude .*
   cmdpause   180:180
   do         always
   room       Erdgeschoss->Wohnzimmer
   wait       0:300

Und ein Auszug aus dem Log:
2023.06.05 06:38:22 3: AV_Receiver ist an: Hyperion gestartet
2023.06.05 07:28:44 3: AV_Receiver ist seit 5 Minuten aus: Hyperion ausgeschaltet
2023.06.05 07:28:47 3: Shutdown: hyperion
2023.06.05 07:28:48 1: [Freezemon] freezemon: possible freeze starting at 07:28:45, delay is 3.031 possibly caused by: tmr-DOIF_SleepTrigger(di.hyperion_schalter) tmr-PRESENCE_StartLocalScan(presence.Solaranlage)
2023.06.05 07:33:48 3: AV_Receiver ist seit 5 Minuten aus: Hyperion ausgeschaltet
ssh: connect to host 192.168.6.46 port 22: No route to host
2023.06.05 07:33:51 3: Shutdown: hyperion
2023.06.05 07:33:51 1: [Freezemon] freezemon: possible freeze starting at 07:33:49, delay is 2.469 possibly caused by: tmr-DOIF_SleepTrigger(di.hyperion_schalter)

Die Freezmon Meldungen kommen auch immer. Ich gehe davon aus das dies an der ssh-Session liegt die einfach zu lange braucht um aufgebaut zu werden.

Die IP 192.168.6.46 ist der PC der per ssh runter gefahren wird.

Es funktioniert alles wie gewünscht nur verstehe ich nicht warum der zweite Teil immer zweimal ausgeführt wird.

Gruß und Danke
Daniel

Per

Vielleicht gibt es einen weiteren State als off (set_off?), und du fragst ja beide Devices triggernd an.

WhyTea

Okay verstehe was Du meinst.
Ich habe das jetzt mal umgebaut.

Zum einen die etwas schwammigen "ne" in "eq" umgebaut und das Abfragen des WOL-Devices als nicht triggernd.
Mal sehen ob das so besser funktioniert.

(([EG_WZ_AV_Receiver:state] eq "on") and ([?WOL_Shutdown_hyperion:state] eq "off"))
({Log 3, "AV_Receiver ist an: Hyperion gestartet"}, set WOL_Shutdown_hyperion on)
DOELSEIF (([EG_WZ_AV_Receiver:state] eq "off") and ([?WOL_Shutdown_hyperion:state] eq "on"))
({Log 3, "AV_Receiver ist seit 5 Minuten aus: Hyperion ausgeschaltet"}, set WOL_Shutdown_hyperion off)

Gruß und Danke

Per

Statt der nicht triggernden Abfragen kannst du auch mit Filter im set arbeiten, dann ändert zwar das DOIF den Status, set schickt aber nichs raus.

WhyTea

Hallo nochmal. ;-)

Leider brachte die Änderung nicht den gewünschten Erfolg.
defmod di.hyperion_schalter DOIF (([EG_WZ_AV_Receiver:state] eq "on") and ([?WOL_Shutdown_hyperion:state] eq "off"))\
({Log 3, "AV_Receiver ist an: Hyperion gestartet"}, set WOL_Shutdown_hyperion on)\
DOELSEIF (([EG_WZ_AV_Receiver:state] eq "off") and ([?WOL_Shutdown_hyperion:state] eq "on"))\
({Log 3, "AV_Receiver ist seit 5 Minuten aus: Hyperion ausgeschaltet"}, set WOL_Shutdown_hyperion off)
attr di.hyperion_schalter DbLogExclude .*
attr di.hyperion_schalter cmdpause 180:180
attr di.hyperion_schalter do always
attr di.hyperion_schalter room Erdgeschoss->Wohnzimmer
attr di.hyperion_schalter wait 0:300

Der Vollständigkeithalber hier das WOL Device welches abgefragt und auf "off" gesetzt wird.
defmod WOL_Shutdown_hyperion WOL 50:9A:4C:2A:C0:84 192.168.6.46 EW
attr WOL_Shutdown_hyperion DbLogExclude .*
attr WOL_Shutdown_hyperion interval 30
attr WOL_Shutdown_hyperion room Erdgeschoss->Wohnzimmer,Zentralsysteme->System
attr WOL_Shutdown_hyperion shutdownCmd { system("ssh hyperion\@192.168.6.46 sudo systemctl poweroff") };;{Log 3, "Shutdown: hyperion" }
attr WOL_Shutdown_hyperion sysCmd /usr/sbin/etherwake -i ens3
attr WOL_Shutdown_hyperion verbose 2
Nach wie vor wird der zweite Ausführungsteil im Abstand von 5 Minuten doppelt ausgeführt.

Auszug aus dem Log:
2023.06.15 14:18:02 3: AV_Receiver ist seit 5 Minuten aus: Hyperion ausgeschaltet
2023.06.15 14:18:05 3: Shutdown: hyperion
2023.06.15 14:23:12 3: AV_Receiver ist seit 5 Minuten aus: Hyperion ausgeschaltet
ssh: connect to host 192.168.6.46 port 22: No route to host
2023.06.15 14:23:15 3: Shutdown: hyperion

Natürlich könnte ich das reine absetzen des Befehls per Filter abfangen aber ich verstehe nach wie vor nicht warum der zweite Teil überhaupt zweimal ausgeführt wird und bitte um Erleuchtung.

rabehd

Auch funktionierende Lösungen kann man hinterfragen.

Frank_Huber

#6
und vielleicht mal ein List aller beteiligten Devices im Fehlerzustand. also nach der zweiten Ausführung.
daran sollte man dann sehen wer triggert.
evtl fehlt irgendwo ein "event-on-change-reading" Attribut...