Falscher Garagentor-Zustand nach Neustart

[robbyHuelsi]

Halli Hallo 👋

Auf meinem RasPi läuft ein Cronjob, der den Homebridge-Docker-Container jede Nacht neustartet. Da Homebridge sich sonst immer wieder mal aufhängt. Nach jedem Neustart aber wird in HomeKit angezeigt, dass das Garagentor geöffnet wird. Tatsächlich ist aber weiterhin geschlossen. Interessanterweise wird bei den Homebridge Accessories das Tor als geschlossen angezeigt. Über das kleine Zahnrad erhalte ich die Info, dass Current Door State = 1, aber Target Door State = 0 ist.

Nachdem das Tor über HomeKit einmal geöffnet und wieder geschlossen wird, stimmt der Status in HomeKit wieder. Außerdem ist dann Current Door State = Target Door State = 1

Ist das ein Bug oder habe ich etwas falsch konfiguriert? Ich würde mich sehr über Hinweise freuen! 😊

Viele Grüße Robert

Verwandte Issues

• Ich bin mir nicht ganz sicher, ob mein Problem mit diesem Issue in Verbindung steht: #608 (Falscher Status durch HomeMaticHomeKitGarageDoorService vs HomeMaticCacheManager)
• Vielleicht gibt es auch einen Bezug zu #641 (HM-SCI-3-FM After 1 Day change Status)
• Im Zusammenhang zu meinem Problem steht das Verhalten, dass nach jedem Neustart eine Pushmitteilung versendet wird, wie hier beschrieben: #606 (Initiale Meldung „Standardraum Garage wurde geschlossen“ unterdrücken). Darüberhinaus ist in meinem Fall die Mitteilung logischerweise falsch.
  • Edit: Zunächst kommt ein Push mit falschem Status und wenige Sekunden später einer mit “richtigem” Status (siehe Bild). In der App stehts dann aber wieder falsch: “Opening...” 😕

Verwendete Versionen

homebridge: 1.1.7 homebridge-homematic: 0.0.219

Verwendete Konfiguration

"special":[
  {
    "name":"Tor",
    "type":"HM-THKL-GARAGEDOOR",
    "parameter":{
      "address_sensor_close":"BidCos-RF.QEQ0013012:1.STATE",
      "state_sensor_close":false,
      "address_sensor_open":"BidCos-RF.QEQ0013012:2.STATE",
      "state_sensor_open":false,
      "address_actor_open":"BidCos-RF.QEQ1334168:1.STATE",
      "message_actor_open":{
        "on":true,
        "off":false
      },
      "address_actor_close":"BidCos-RF.QEQ1334168:1.STATE",
      "message_actor_close":{
        "on":true,
        "off":false
      },
      "delay_actor_open":2,
      "delay_actor_close":2,
      "sensor_requery_time":20
    }
  }
],
"services":[
  {
    "type":"HM-THKL-GARAGEDOOR",
    "service":"HomeMaticHomeKitGarageDoorService"
}

Log nach Neustart

[12/27/2020, 10:50:01 AM] [HomeMatic CCU] [GDS] garage door inital query ...
[12/27/2020, 10:50:01 AM] [HomeMatic CCU] [Generic] transformDatapoint BidCos-RF.QEQ0013012:1.STATE
[12/27/2020, 10:50:01 AM] [HomeMatic CCU] [Cache] remove :BidCos-RF.QEQ0013012:1.STATE
[12/27/2020, 10:50:01 AM] [HomeMatic CCU] [Core] getValue (BidCos-RF) BidCos-RF.QEQ0013012:1.STATE
[12/27/2020, 10:50:01 AM] [HomeMatic CCU] [Core] check cache BidCos-RF.QEQ0013012:1.STATE
[12/27/2020, 10:50:01 AM] [HomeMatic CCU] [Cache] fail on BidCos-RF.QEQ0013012:1.STATE
[12/27/2020, 10:50:01 AM] [HomeMatic CCU] [Core] cache failed for  BidCos-RF.QEQ0013012:1.STATE will transfer request to rega
[12/27/2020, 10:50:01 AM] [HomeMatic CCU] [Generic] transformDatapoint BidCos-RF.QEQ0013012:2.STATE
[12/27/2020, 10:50:01 AM] [HomeMatic CCU] [Cache] remove :BidCos-RF.QEQ0013012:2.STATE
[12/27/2020, 10:50:01 AM] [HomeMatic CCU] [Core] getValue (BidCos-RF) BidCos-RF.QEQ0013012:2.STATE
[12/27/2020, 10:50:01 AM] [HomeMatic CCU] [Core] check cache BidCos-RF.QEQ0013012:2.STATE
[12/27/2020, 10:50:01 AM] [HomeMatic CCU] [Cache] fail on BidCos-RF.QEQ0013012:2.STATE
[12/27/2020, 10:50:01 AM] [HomeMatic CCU] [Core] cache failed for  BidCos-RF.QEQ0013012:2.STATE will transfer request to rega
[12/27/2020, 10:50:01 AM] [HomeMatic CCU] [Core] rega result for BidCos-RF.QEQ0013012:1.STATE is false
[12/27/2020, 10:50:01 AM] [HomeMatic CCU] [Cache] write false for BidCos-RF.QEQ0013012:1.STATE
[12/27/2020, 10:50:01 AM] [HomeMatic CCU] [GDS] result for close sensor false
[12/27/2020, 10:50:01 AM] [HomeMatic CCU] [Generic] transformDatapoint STATE
[12/27/2020, 10:50:01 AM] [HomeMatic CCU] [Generic] cache .STATE (false)
[12/27/2020, 10:50:01 AM] [HomeMatic CCU] [Generic] datapointEvent STATE with false channel BidCos-RF.QEQ0013012:1
[12/27/2020, 10:50:01 AM] [HomeMatic CCU] [GDS] garage event CH:BidCos-RF.QEQ0013012:1|DP:STATE|NV:false|TCS:false
[12/27/2020, 10:50:01 AM] [HomeMatic CCU] [GDS] Two Sensor Mode
[12/27/2020, 10:50:01 AM] [HomeMatic CCU] [GDS] close sensor is false set CurrentDoorState to close
[12/27/2020, 10:50:01 AM] [HomeMatic CCU] [Core] rega result for BidCos-RF.QEQ0013012:2.STATE is true
[12/27/2020, 10:50:01 AM] [HomeMatic CCU] [Cache] write true for BidCos-RF.QEQ0013012:2.STATE
[12/27/2020, 10:50:01 AM] [HomeMatic CCU] [GDS] result for open sensor true
[12/27/2020, 10:50:01 AM] [HomeMatic CCU] [Generic] transformDatapoint STATE
[12/27/2020, 10:50:01 AM] [HomeMatic CCU] [Generic] cache .STATE (true)
[12/27/2020, 10:50:01 AM] [HomeMatic CCU] [Generic] datapointEvent STATE with true channel BidCos-RF.QEQ0013012:1
[12/27/2020, 10:50:01 AM] [HomeMatic CCU] [GDS] garage event CH:BidCos-RF.QEQ0013012:1|DP:STATE|NV:true|TCS:false
[12/27/2020, 10:50:01 AM] [HomeMatic CCU] [GDS] Two Sensor Mode
[12/27/2020, 10:50:01 AM] [HomeMatic CCU] [GDS] close sensor is true set TargetDoorState to open CurrentDoorState to opening

Die letzte Zeile ist falsch! Der close sensor ist eigentlich false und somit müsste Target und Current den Wert “close” (o.ä.) haben.

Log nach Öffnen und Schließen

[12/27/2020, 12:46:47 PM] [HomeMatic CCU] [GDS] Two sensor mode. Fetching value for Close Sensor BidCos-RF.QEQ0013012:1.STATE
[12/27/2020, 12:46:47 PM] [HomeMatic CCU] [Generic] transformDatapoint BidCos-RF.QEQ0013012:1.STATE
[12/27/2020, 12:46:47 PM] [HomeMatic CCU] [Cache] remove :BidCos-RF.QEQ0013012:1.STATE
[12/27/2020, 12:46:47 PM] [HomeMatic CCU] [Core] getValue (BidCos-RF) BidCos-RF.QEQ0013012:1.STATE
[12/27/2020, 12:46:47 PM] [HomeMatic CCU] [Core] check cache BidCos-RF.QEQ0013012:1.STATE
[12/27/2020, 12:46:47 PM] [HomeMatic CCU] [Cache] hit on BidCos-RF.QEQ0013012:1.STATE false
[12/27/2020, 12:46:47 PM] [HomeMatic CCU] [GDS] get close value result is false
[12/27/2020, 12:46:47 PM] [HomeMatic CCU] [GDS] Fetching value for Open Sensor BidCos-RF.QEQ0013012:1.STATE
[12/27/2020, 12:46:47 PM] [HomeMatic CCU] [Generic] transformDatapoint BidCos-RF.QEQ0013012:2.STATE
[12/27/2020, 12:46:47 PM] [HomeMatic CCU] [Cache] remove :BidCos-RF.QEQ0013012:2.STATE
[12/27/2020, 12:46:47 PM] [HomeMatic CCU] [Core] getValue (BidCos-RF) BidCos-RF.QEQ0013012:2.STATE
[12/27/2020, 12:46:47 PM] [HomeMatic CCU] [Core] check cache BidCos-RF.QEQ0013012:2.STATE
[12/27/2020, 12:46:47 PM] [HomeMatic CCU] [Cache] hit on BidCos-RF.QEQ0013012:2.STATE true
[12/27/2020, 12:46:47 PM] [HomeMatic CCU] [GDS] get open value result is true
[12/27/2020, 12:46:47 PM] [HomeMatic CCU] [GDS] values shows CurrentDoorState is closed

[dinneatgithub]

Habe genau das gleiche Problem. Version 0.1.231. hatte mich schon sehr gewundert, warum in Homebridge es als Closed angezeigt wird und in der iOS Home App als Opening. Jetzt verstehe ich warum. Bin gespannt, ob wir eine Lösung für den TargetState finden. Habe >50 Geräte in Homebridge, das macht das Debug nicht einfach. Zu verbose ;-)

[dinneatgithub]

Ich habe am Wochenende etwas weiter debugged. Mein Fazit: der CurrentState scheint bei mir aktuell richtig erkannt zu werden, sowohl OPEN als auch CLOSED. Das sehe ich über die Debugmeldungen und das Zahnrad auf dem Garagentor in Homebridge. In der Darstellung in der Home App auf dem iPhone wird aber CurrentState und TargetState verglichen. Und wenn die ungleich sind, dann ist man automatisch in einem "opening/closing" modus, was die Darstellung betrifft. Ich steuere nur zu einem geringen Anteil über Siri/Home-App und frage mich: spricht was dagegen, den TargetState auf den aktuellen Zustand nachzuziehen? Also, wenn open=true und closed=false, dann setze TargetStatus=1 (closed), auch wenn es vorher auf 0 (open) war.

Als Workaround helfe ich mir aktuell damit, den Status des Garagentors als Systemvariable in der CCU3 in die Homebrige zu holen und mittels virtuellem Taster dann den Push auf Änderung zu bekommen.

[thkl]

TargetState setze ich auf CurrentState wenn der „Working“ Datapoint von True auf false wechselt. Also wenn das Tor zum stehen kommt.

[dinneatgithub]

`[2/1/2021, 1:28:10 PM] [HomeMatic CCU3] [GDS] Entering: datapointEvent [2/1/2021, 1:28:10 PM] [HomeMatic CCU3] [GDS] garage event CH:HmIP-RF.00145709AEDA0A:1|DP:STATE|NV:true|TCS:false [2/1/2021, 1:28:10 PM] [HomeMatic CCU3] [GDS] Two Sensor Mode [2/1/2021, 1:28:10 PM] [HomeMatic CCU3] [GDS] open sensor is true set CurrentDoorState to open [2/1/2021, 1:28:10 PM] [HomeMatic CCU3] [GDS] Entering: datapointEvent [2/1/2021, 1:28:10 PM] [HomeMatic CCU3] [GDS] garage event CH:HmIP-RF.00145709AEDA0A:2|DP:STATE|NV:false|TCS:false [2/1/2021, 1:28:10 PM] [HomeMatic CCU3] [GDS] Two Sensor Mode [2/1/2021, 1:28:10 PM] [HomeMatic CCU3] [GDS] close sensor is false set CurrentDoorState to opening

[2/1/2021, 1:28:11 PM] [HomeMatic CCU3] [GDS] Entering: datapointEvent [2/1/2021, 1:28:11 PM] [HomeMatic CCU3] [GDS] garage event CH:HmIP-RF.00145709AEDA0A:1|DP:STATE|NV:false|TCS:false [2/1/2021, 1:28:11 PM] [HomeMatic CCU3] [GDS] Two Sensor Mode [2/1/2021, 1:28:11 PM] [HomeMatic CCU3] [GDS] open sensor is false set CurrentDoorState to closing [2/1/2021, 1:28:11 PM] [HomeMatic CCU3] [GDS] Entering: datapointEvent [2/1/2021, 1:28:11 PM] [HomeMatic CCU3] [GDS] garage event CH:HmIP-RF.00145709AEDA0A:2|DP:STATE|NV:false|TCS:false [2/1/2021, 1:28:11 PM] [HomeMatic CCU3] [GDS] Two Sensor Mode [2/1/2021, 1:28:11 PM] [HomeMatic CCU3] [GDS] close sensor is false set CurrentDoorState to opening

[2/1/2021, 1:28:35 PM] [HomeMatic CCU3] [GDS] Entering: datapointEvent [2/1/2021, 1:28:35 PM] [HomeMatic CCU3] [GDS] garage event CH:HmIP-RF.00145709AEDA0A:1|DP:STATE|NV:false|TCS:false [2/1/2021, 1:28:35 PM] [HomeMatic CCU3] [GDS] Two Sensor Mode [2/1/2021, 1:28:35 PM] [HomeMatic CCU3] [GDS] open sensor is false set CurrentDoorState to closing [2/1/2021, 1:28:35 PM] [HomeMatic CCU3] [GDS] Entering: datapointEvent [2/1/2021, 1:28:35 PM] [HomeMatic CCU3] [GDS] garage event CH:HmIP-RF.00145709AEDA0A:2|DP:STATE|NV:true|TCS:false [2/1/2021, 1:28:35 PM] [HomeMatic CCU3] [GDS] Two Sensor Mode [2/1/2021, 1:28:35 PM] [HomeMatic CCU3] [GDS] close sensor is true set CurrentDoorState to close

[2/1/2021, 1:28:35 PM] [HomeMatic CCU3] [GDS] Entering: datapointEvent [2/1/2021, 1:28:35 PM] [HomeMatic CCU3] [GDS] garage event CH:HmIP-RF.00145709AEDA0A:1|DP:STATE|NV:false|TCS:false [2/1/2021, 1:28:35 PM] [HomeMatic CCU3] [GDS] Two Sensor Mode [2/1/2021, 1:28:35 PM] [HomeMatic CCU3] [GDS] open sensor is false set CurrentDoorState to closing [2/1/2021, 1:28:35 PM] [HomeMatic CCU3] [GDS] Entering: datapointEvent [2/1/2021, 1:28:35 PM] [HomeMatic CCU3] [GDS] garage event CH:HmIP-RF.00145709AEDA0A:2|DP:STATE|NV:true|TCS:false [2/1/2021, 1:28:35 PM] [HomeMatic CCU3] [GDS] Two Sensor Mode [2/1/2021, 1:28:35 PM] [HomeMatic CCU3] [GDS] close sensor is true set CurrentDoorState to close

[2/1/2021, 1:36:08 PM] [HomeMatic CCU3] [GDS] Two sensor mode. Fetching value for Close Sensor HmIP-RF.00145709AEDA0A:2.STATE [2/1/2021, 1:36:08 PM] [HomeMatic CCU3] [GDS] get close value result is true [2/1/2021, 1:36:08 PM] [HomeMatic CCU3] [GDS] Fetching value for Open Sensor HmIP-RF.00145709AEDA0A:1.STATE [2/1/2021, 1:36:08 PM] [HomeMatic CCU3] [GDS] get open value result is false [2/1/2021, 1:36:08 PM] [HomeMatic CCU3] [GDS] values show CurrentDoorState is closed

[2/1/2021, 1:36:11 PM] [HomeMatic CCU3] [GDS] Two sensor mode. Fetching value for Close Sensor HmIP-RF.00145709AEDA0A:2.STATE [2/1/2021, 1:36:11 PM] [HomeMatic CCU3] [GDS] get close value result is true [2/1/2021, 1:36:11 PM] [HomeMatic CCU3] [GDS] Fetching value for Open Sensor HmIP-RF.00145709AEDA0A:1.STATE [2/1/2021, 1:36:11 PM] [HomeMatic CCU3] [GDS] get open value result is false [2/1/2021, 1:36:11 PM] [HomeMatic CCU3] [GDS] values show CurrentDoorState is closed `

Ich habe die 0.1.231 am Laufen und das Debug in HomeMaticHomeKitGarageDoorService.js ein bisschen erweitert. Als Sensor ist ein HmIP-MOD-OC8 am Laufen.

Um 01:28:10 habe ich via extern (Taster direkt an Homematic) das Tor von offen auf zu gestellt.

1) 01:28:10 Uhr: Man sieht, es kommt erst (true/false), eine Sekunde später (false/false). 2) Um 01:28:35 ist das Toor dann unten (false/true) 2b) Warum auch immer, das gleiche Event-Pärchen kommt dann nochmal um 01:28:35 (false/true). Ist aber egal. 3) Um 01:36:08 ist dann wohl der 30 Sekunden Requery und er holt sich diesmal andersrum erst CLOSE dann OPEN Sensor, aber wieder richtig als (true/false) 4) 3 Sekunden später um 01:36:11 dann nochmal, wieder mit dem gleichen Ergebnis (true/false)

Es wird erkannt, dass das Tor zu ist. Alle Zustände sind richtig, ABER: targetDoorState wird nicht verändert und steht noch auf 0 (offen). CurrentDoorState steht richtigerweise auf 0.

Warum wird TargetDoorState nicht verändert?

[dinneatgithub]

Randnotiz, ist mir beim Quellcodelesen aufgefallen:

• In Zeile 155 scheint mir open und close vertauscht. Im Single Sensor Mode gibt es ja nur Close, und kein Open und nicht anders herum (betrifft mich nicht, hab zwei Sensoren)
• In Zeile 244 muss ist auch open und close vertauscht: let parts = that.address_sensor_close.split('.') das muss auf OPEN

Habe kein git, vielleicht kann das ja jemand fixen.

[dinneatgithub]

Ich habe auf single sensor umgestellt, also den address_sensor_open auskommentiert. Und siehe da, jetzt klappt alles wie gewünscht. TargetState wird endlich angepasst. Ich sehe jetzt zwar kein Closing/Opening mehr, aber das kann ich gut verschmerzen, denn die Fahrzeit sind 30 Sekunden maximal und danach habe ich dafür richtige Zustände. Wobei CLOSE=True auf CLOSE geht und alles andere auf OPEN. Damit kann ich fürs Erste leben. Ich habe das Gefühl, dass meine Sensor-Meldungen mit dem HmIP-MOD-OC8 einfach nicht zur Algorithmik des Plugins passen.

[stale[bot]]

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions.