search

yenoiwesa / homebridge-connexoon

A homebridge plugin to integrate Somfy blinds with the Connexoon RTS hub
Apache License 2.0
27 stars 2 forks source link

Homekit polls every hour but it appears to trigger a Set as well as Get? #25

Closed jdebardi closed 3 years ago

jdebardi commented 3 years ago

So every hour my blinds close if they are open, or open then immediately close if they are closed.

See log;

Jan 31 17:40:09 jose-stick homebridge[9481]: [1/31/2021, 5:40:09 PM] [TaHoma Somfy Hub] Get Lounge Left target position success: 100
Jan 31 17:40:09 jose-stick homebridge[9481]: [1/31/2021, 5:40:09 PM] [TaHoma Somfy Hub] Get Lounge Right target position success: 100
Jan 31 17:40:09 jose-stick homebridge[9481]: [1/31/2021, 5:40:09 PM] [TaHoma Somfy Hub] Get Lounge Right target position success: 100
Jan 31 17:40:09 jose-stick homebridge[9481]: [1/31/2021, 5:40:09 PM] [TaHoma Somfy Hub] Get Lounge Left target position success: 100
Jan 31 17:40:10 jose-stick homebridge[9481]: [1/31/2021, 5:40:10 PM] [TaHoma Somfy Hub] Set Lounge Left target position success: 100
Jan 31 17:40:10 jose-stick homebridge[9481]: [1/31/2021, 5:40:10 PM] [TaHoma Somfy Hub] Set Lounge Right target position success: 100
Jan 31 17:40:10 jose-stick homebridge[9481]: [1/31/2021, 5:40:10 PM] [TaHoma Somfy Hub] Set Lounge Left target position success: 0
Jan 31 17:40:10 jose-stick homebridge[9481]: [1/31/2021, 5:40:10 PM] [TaHoma Somfy Hub] Set Lounge Right target position success: 0
Jan 31 18:40:09 jose-stick homebridge[9481]: [1/31/2021, 6:40:09 PM] [TaHoma Somfy Hub] Get Lounge Left target position success: 0
Jan 31 18:40:09 jose-stick homebridge[9481]: [1/31/2021, 6:40:09 PM] [TaHoma Somfy Hub] Get Lounge Right target position success: 0
Jan 31 18:40:09 jose-stick homebridge[9481]: [1/31/2021, 6:40:09 PM] [TaHoma Somfy Hub] Get Lounge Right target position success: 0
Jan 31 18:40:09 jose-stick homebridge[9481]: [1/31/2021, 6:40:09 PM] [TaHoma Somfy Hub] Get Lounge Left target position success: 0
Jan 31 18:40:10 jose-stick homebridge[9481]: [1/31/2021, 6:40:10 PM] [TaHoma Somfy Hub] Set Lounge Left target position success: 100
Jan 31 18:40:10 jose-stick homebridge[9481]: [1/31/2021, 6:40:10 PM] [TaHoma Somfy Hub] Set Lounge Right target position success: 100
Jan 31 18:40:10 jose-stick homebridge[9481]: [1/31/2021, 6:40:10 PM] [TaHoma Somfy Hub] Set Lounge Right target position success: 0
Jan 31 18:40:10 jose-stick homebridge[9481]: [1/31/2021, 6:40:10 PM] [TaHoma Somfy Hub] Set Lounge Left target position success: 0

I don't have any automations set up in Homekit. I have disabled polling with "pollingInterval": 0 but I think this is for it polling Somfy rather than Homekit anyway so not relevant?

It always does 2 Get's per device, and then a Set 100 followed by a Set 0.

Any ideas?

Also - there is virtually no debug logging available. I was hoping to see the requests come from Homekit how they are interpreted and the API calls to Somfy but I don't see anything so it's very hard to track down what's going on.

yenoiwesa commented 3 years ago

Hi @jdebardi,

Also - there is virtually no debug logging available. I was hoping to see the requests come from Homekit how they are interpreted and the API calls to Somfy but I don't see anything so it's very hard to track down what's going on.

Have you tried starting your Homebridge server in debug mode? That's when the debug logs are printed.

The Get and Set target position logs that you see are entirely controlled by Homekit, these are commands that Homekit is sending. I am surprised that you do not see entries about the current position property of your devices in there though. When Homekit refreshes the state of the accessories, it generally asks for both current position and target position.

As to why it continues with setting another position, unfortunately I can't tell. Again that is the first report of this kind I have received.

Could you temporarily change your commands array for all the devices to ["close", "open"] to rule out the stop command messing with the position calculation?

jdebardi commented 3 years ago

Yea I pretty much always run with DEBUG=*

So I removed all config, restarted, re-added with just open/close commands and restarted again.

On startup it shows a far more sensible looking;

Jan 31 21:26:02 jose-stick homebridge[6837]: [1/31/2021, 9:26:02 PM] [Somfy TaHoma Hub] Get Lounge Left target position success: 0
Jan 31 21:26:02 jose-stick homebridge[6837]: [1/31/2021, 9:26:02 PM] [Somfy TaHoma Hub] Get Lounge Left current position success: 0
Jan 31 21:26:02 jose-stick homebridge[6837]: [1/31/2021, 9:26:02 PM] [Somfy TaHoma Hub] Get Lounge Right target position success: 0
Jan 31 21:26:02 jose-stick homebridge[6837]: [1/31/2021, 9:26:02 PM] [Somfy TaHoma Hub] Get Lounge Right current position success: 0

I'll see what happens for the next couple of hours.

The only other thing I had done is assign a touch button to open the blinds, maybe that breaks it! Will let you know.

Thanks for your support!

yenoiwesa commented 3 years ago

I checked the plugin's code and it's true that there are not too many debug entries in general. Feel free to add them directly in the plugin's code in your local node_modules directory for debugging purpose.

But yeah overall the fact that Homekit is sending these commands is not expected.

yenoiwesa commented 3 years ago

Could you add some debugging logs in this method: https://github.com/yenoiwesa/homebridge-connexoon/blob/master/src/api/device.js#L91

And print all the past executions (that I somehow called passedExecs) as well as the found last command before the method returns?

I wonder if using stop marks the last command as failed and thus gets discarded when trying to infer the position of the blind from the command execution history.

Also I would be interested to see what happens if, from the Somfy app on your phone, you request the My position, and compare it afterwards to the command history printed in the logs. That should tell us what command the app is sending for My.

jdebardi commented 3 years ago

Well as a plot twist, I have hung another blind today (I have 5 total, 3 hung so far). The 3rd one I forgot to add the limited open/close commands, so it will be defaulting to open, my, close - and it works! So I have no idea what was happening last night! I'm really hoping something random was going on and now the re-configure has fixed it. Will see what happens, if it misbehaves again I'll try adding some debug as you suggest.

Thanks again!

yenoiwesa commented 3 years ago

Oh well lol, great news then! I will close the issue for now, please reopen it if you encounter the issue again and we can resume the investigation :-)

Cheers!