search

gawindx / homebridge-risco-platform

RiscoAlarm Platform for Homebridge - Originally based on the 'szlaskidaniel / homebridge-risco-alarm' project
5 stars 1 forks source link

disarm / arm / disarm #42

Closed andyblac closed 3 years ago

andyblac commented 3 years ago

i keep getting this in the mornings

[28/02/2021, 10:18:42] [RiscoAlarm] Partition "Castle Int Alarm" => New state detected: (3) -> DISARM. Notify!
[28/02/2021, 10:18:42] [RiscoAlarm] Partition "Castle Int Alarm" is not Occupied. Notify!
[28/02/2021, 10:18:43] [RiscoAlarm] Partition "Castle Int Alarm" => New state detected: (1) -> AWAY_ARM. Notify!
[28/02/2021, 10:18:43] [RiscoAlarm] Partition "Castle Int Alarm" is not Occupied. Notify!
[28/02/2021, 10:18:46] [RiscoAlarm] Partition "Castle Int Alarm" => New state detected: (3) -> DISARM. Notify!
[28/02/2021, 10:18:46] [RiscoAlarm] Partition "Castle Int Alarm" is not Occupied. Notify!

any ideas ? Andy

andyblac commented 3 years ago

still happening

[03/03/2021, 18:02:15] [RiscoAlarm] Partition "Garage" => New state detected: (1) -> AWAY_ARM. Notify!
[03/03/2021, 18:02:15] [RiscoAlarm] Partition "Garage" is not Occupied. Notify!
[03/03/2021, 18:02:16] [RiscoAlarm] Partition "Garage" => New state detected: (3) -> DISARM. Notify!
[03/03/2021, 18:02:16] [RiscoAlarm] Partition "Garage" is not Occupied. Notify!
[03/03/2021, 18:02:19] [RiscoAlarm] Partition "Garage" => New state detected: (1) -> AWAY_ARM. Notify!
[03/03/2021, 18:02:19] [RiscoAlarm] Partition "Garage" is not Occupied. Notify!
andyblac commented 3 years ago

any ideas ?

gawindx commented 3 years ago

no, I am not seeing this behavior on my side, so I cannot try to reproduce it and understand it.

The only thing I see is the timing in the events: t0 = event 1 t0 + 1s = event 2 t0 + 4s = event 1

I don't know if you have other examples like that, but it might be interesting to have the full logs (Debug mode in HomeBridge)

andyblac commented 3 years ago

no, I am not seeing this behavior on my side, so I cannot try to reproduce it and understand it.

The only thing I see is the timing in the events: t0 = event 1 t0 + 1s = event 2 t0 + 4s = event 1

I don't know if you have other examples like that, but it might be interesting to have the full logs (Debug mode in HomeBridge)

it does not happen all the time, i'll enable debug logs, and try to catch it.

andyblac commented 3 years ago

got a log where should i send it ?

gawindx commented 3 years ago

by mail or by creating a gist.

I will try to study this this weekend but I do not know if it will help me to understand the phenomenon encountered.

andyblac commented 3 years ago

done

andyblac commented 3 years ago

another log sent.

gawindx commented 3 years ago

Okay, I think I've figured out what's going on and why I'm not experiencing this behavior.

Tell me if I'm wrong, have you configured the refresh at 3 seconds?

On your second log (for the first, I did not find the problem): 9:27:13 => Panel Status Update Loop

9:27:15 => Disarming from HomeKit (Request 1)

9:27:16 => Panel Status Update Loop

9:27:18 => Response to request 1 and update of the partition state with request's response 9:27:18 => Notification of partition status (DISARM)

9:27:19 => Panel Status Update Loop Partition seen as actualstate = armed !!!! 9:27:19 => Notification of partition status (AWAY)

9:27:22 => Panel Status Update Loop Partition seen as actualstate = disarmed 9:27:22 => Notification of partition status (DISARM)

9:27:25 => Panel Status Update Loop

9:27:28 => Panel Status Update Loop

So, if I analyze what is happening:

Either the RiscoCloud does not use the response obtained by the control unit to update the state of the system in the RiscoCloud (unlike this plugin because it seemed obvious to me to implement it in this way for faster state changes), or the information has not yet propagated in the RiscoCloud and you get a response that is not yet up to date.

Personally, I work with a 5 second polling delay, which will explain why I don't have this problem because I allow more time between each polling and each response to a command for the information to propagate.

Another hypothesis could be slowdown problems in the RiscoCloud network infrastructure (temporary slowdown or resulting from a change in their back-office), which would explain that you have not noticed this problem before with the same settings of polling delay.

In conclusion, I don't see a lot of possibilities:

For my part, I do not consider this to be a bug because the plugin behaves as it should. On the other hand, I will add a warning to warn about the use of a too short delay for the polling.

andyblac commented 3 years ago

thx i'll try 5 seconds, it does not happen all the time, even at 3 seconds, why is it seen ARM after 1 seconds ?

gawindx commented 3 years ago

I think that when the plugin queries the RiscoCLoud again, the new status of the control panel has not propagated to RiscoCloud, or that the control panel has not yet sent an update of its status.

In a way, it's a bit as if the state of your control unit was a little undetermined on the RiscoCloud side or still in the process of changing and that only its final state was taken into account (whereas when you pilot a action, the API returns us a result which can suggest that the action is already executed and taken into account).

To be sure, you would need to have access to their code, but that ....