Roller shutter status getting out of sync about homebridge-shelly HOT 12 CLOSED

Hi Matej, that seems strange. You can try running homebridge with the -D option to see debug messages. Maybe that can give you some hints?

from homebridge-shelly.

Sorry for the long delay here. I finally managed to find some time to start looking into this a bit more closely. Here's what I found out so far.

Reseting Homebridge seems to sync everything up (in my case that's a sudo service homebridge restart). Even if HomeKit apps showed incorrect state that appears to update after a reset.

Using the various ways to set the offset quickly leads to a bad value reported by HomeKit. Using only physically switches wired to the Shelly appears to be the most reliable way (although I observed issues there as well).

Here's a sample of using only the Home app to adjust the value: HomeKit.mp4.zip

Focusing on the very first change I mede in that video, you can see that when the roller reaches the final position it just jumps back to 0 in the Home app, despite the physical roller being moved correctly. The web interface reflects the position correctly, but it can take a bit to update (you see it update for the change at the very end, before I was just too quick to modify values before). Looking at the log, it's apparent that a current state of 0 comes in at the time of that jump. Could this be an issue with the Shells then? Is that an incorrect position being pushed from the device (via CoAP)? My guess would be that querying the API at that point or slightly delayed would then result in the correct value (explaining the correct state on the device website and after a restart).

Side note: when interacting with the slides on the Home app UI it looks like the updates are continuously pushed to the Shelly and the relay can start triggering pretty intently for a small update (as move and stop commands are issued all the time). Debouncing those updates a bit would definitely result in a smoother experience here. But that's a separate issue.

Here's another example where I mix the web UI and HomeKit: WebAndHomeKit.mp4.zip

In some cases it looks like the updates lag behind one change at at time, but that also doesn't seem to be always the case.

Node is a bit out of my comfort zone, but I'm happy to try and help out if I can get some additional pointers on what I could try?

from homebridge-shelly.

This plugin actually uses the REST API to get the current roller shutter position. I think the Shellies will start reporting their positions over CoAP in the next firmware update, but so far what is transmitted is just the states of the relays. I’ve used this to determine if the roller shutter is stopped (no relay is active) or if it is moving (one of the relays is active). Whenever the states of the relays change the API is queried to get the current position, which means that the API is queried once when the shutter starts moving and once when it stops moving. So if the position in the Home app is incorrect I suppose that it is reported incorrectly by the API.

I have several Shelly 2s and 2.5s but no roller shutter to control so I can’t really test their actual behavior. But if you can query the /status endpoint repeatedly while your roller shutter is moving and look at the current_pos property perhaps you can tell if it is correct at all times?

from homebridge-shelly.

Thanks for the suggestion. After testing I can confirm that there appears to be a delay between a stop being registered and the API reporting the correct offset.

I restarted Homebridge while the blinds were set to 5%. Both the API and Home app reflected the correct value. Then I initiated a move to 46% via the Home app.

Here's the output of polling the API every second during the move with some added comments.

...

{"state":"open","power":108.78,"is_valid":true,"safety_switch":false,"overtemperature":false,"stop_reason":"normal","last_direction":"open","current_pos":5,"calibrating":false,"positioning":true}

{"state":"open","power":108.72,"is_valid":true,"safety_switch":false,"overtemperature":false,"stop_reason":"normal","last_direction":"open","current_pos":5,"calibrating":false,"positioning":true}

{"state":"open","power":108.80,"is_valid":true,"safety_switch":false,"overtemperature":false,"stop_reason":"normal","last_direction":"open","current_pos":5,"calibrating":false,"positioning":true}

{"state":"open","power":108.76,"is_valid":true,"safety_switch":false,"overtemperature":false,"stop_reason":"normal","last_direction":"open","current_pos":5,"calibrating":false,"positioning":true}

{"state":"open","power":108.85,"is_valid":true,"safety_switch":false,"overtemperature":false,"stop_reason":"normal","last_direction":"open","current_pos":5,"calibrating":false,"positioning":true}

{"state":"open","power":109.29,"is_valid":true,"safety_switch":false,"overtemperature":false,"stop_reason":"normal","last_direction":"open","current_pos":5,"calibrating":false,"positioning":true}

// Movement stops, power goes to 0, position is still 5%!

{"state":"stop","power":0.00,"is_valid":true,"safety_switch":false,"overtemperature":false,"stop_reason":"normal","last_direction":"open","current_pos":5,"calibrating":false,"positioning":true}

// Now the position updates to 46% and stays stable.

{"state":"stop","power":0.00,"is_valid":true,"safety_switch":false,"overtemperature":false,"stop_reason":"normal","last_direction":"open","current_pos":46,"calibrating":false,"positioning":true}

{"state":"stop","power":0.00,"is_valid":true,"safety_switch":false,"overtemperature":false,"stop_reason":"normal","last_direction":"open","current_pos":46,"calibrating":false,"positioning":true}

{"state":"stop","power":0.00,"is_valid":true,"safety_switch":false,"overtemperature":false,"stop_reason":"normal","last_direction":"open","current_pos":46,"calibrating":false,"positioning":true}

...

So there is a delay between the state moving to "stop" and the offset being reported correctly on the API side. That could definitely explain the inconsistencies I'm seeing.

Here's the plugin log corresponding to this move.

May 02 11:37:29 RaspberryPi homebridge[24354]: [2019-5-2 11:37:29] [Shelly] Setting target roller shutter position of device SHSW-25 5DB8EA to 44
May 02 11:37:29 RaspberryPi homebridge[24354]: [2019-5-2 11:37:29] [Shelly] Roller shutter state of device SHSW-25 5DB8EA changed to open
May 02 11:37:29 RaspberryPi homebridge[24354]: [2019-5-2 11:37:29] [Shelly] Setting current roller shutter position of device - modified -  SHSW-25 5DB8EA to 5
May 02 11:37:47 RaspberryPi homebridge[24354]: [2019-5-2 11:37:47] [Shelly] Roller shutter state of device SHSW-25 5DB8EA changed to stop
May 02 11:37:47 RaspberryPi homebridge[24354]: [2019-5-2 11:37:47] [Shelly] Setting current roller shutter position of device - modified -  SHSW-25 5DB8EA to 5

The position at the end remained at 5% instead of 46%. The 5% was also reflected in the UI. At that point HomeKit was no longer in sync with the device.

I tried making this little modification in getCurrentPosition():

async getCurrentPosition() {
  await this.sleep(1000)
  const status = await this.device.getStatus()
  return status.rollers[0].current_pos
}

sleep(ms){
    return new Promise(resolve=>{
        setTimeout(resolve,ms)
    })
}

Sure enough, that lead to the correct values being reported in HomeKit. I'm sure this could be implemented nicer. The 1s delay is just a guess. It seemed reliable, but I didn't really test all that much. 0.5s was already too quick and occasionally produced issues. Perhaps doing a few delayed repeated calls when stopping instead would be a nicer solution. The workaround could probably be limited to only delay calls from rollerStateChangeHandler only for the "stop" state.

With the new firmware, this could hopefully be handled via CoAP (if a message is sent on every position update). Until that's available, it would be nice to have some sort of temporary workaround.

from homebridge-shelly.

Ok that makes sense. I agree that doing some delayed calls is the best way to work around it right now.

I noticed that Shelly 2s already send a new property over CoAP now in 'roller' mode. I suspect it might be the roller shutter position. Could you install the roller-position branch of my shellies library ($ npm install -g alexryd/node-shellies#roller-position), run $ shellies listen and see if the rollerPosition0 property of your Shelly 2 is updated when you move your roller shutter?

Btw, thank you so much for your donation! 🙇 I really appreciate it!

from homebridge-shelly.

run $ shellies listen and see if the rollerPosition0 property of your Shelly 2 is updated when you move your roller shutter?

Yes, that seems to work. Here's some output when moving the shutters using the physical switches:

[Property changed] 2019-05-02T18:43:40.011Z
Property: relay1 Value: true Device ID: 5DB8EA
[Property changed] 2019-05-02T18:43:40.012Z
Property: rollerState Value: open Device ID: 5DB8EA
[Property changed] 2019-05-02T18:43:42.348Z
Property: relay1 Value: false Device ID: 5DB8EA
[Property changed] 2019-05-02T18:43:42.349Z
Property: rollerPosition0 Value: 5 Device ID: 5DB8EA
[Property changed] 2019-05-02T18:43:42.351Z
Property: powerMeter1 Value: 103.400093 Device ID: 5DB8EA
[Property changed] 2019-05-02T18:43:42.352Z
Property: rollerState Value: stop Device ID: 5DB8EA
[Property changed] 2019-05-02T18:43:44.209Z
Property: relay0 Value: true Device ID: 5DB8EA
[Property changed] 2019-05-02T18:43:44.210Z
Property: powerMeter1 Value: 0 Device ID: 5DB8EA
[Property changed] 2019-05-02T18:43:44.212Z
Property: rollerState Value: close Device ID: 5DB8EA
[Property changed] 2019-05-02T18:43:44.703Z
Property: powerMeter0 Value: 100.168007 Device ID: 5DB8EA
[Property changed] 2019-05-02T18:43:46.707Z
Property: powerMeter0 Value: 6.000765 Device ID: 5DB8EA
[Property changed] 2019-05-02T18:43:46.919Z
Property: relay0 Value: false Device ID: 5DB8EA
[Property changed] 2019-05-02T18:43:46.920Z
Property: rollerPosition0 Value: 0 Device ID: 5DB8EA
[Property changed] 2019-05-02T18:43:46.922Z
Property: rollerState Value: stop Device ID: 5DB8EA
[Property changed] 2019-05-02T18:43:47.716Z
Property: powerMeter0 Value: 0 Device ID: 5DB8EA

When using HomeKit or the web interface it sometimes took a bit (1-3 seconds) for rollerPosition0 to show up after the movement, but eventually I always got a result reported. When using physical switches (the above output) the reports were pretty much instant. That potential explains why the values did not get out of sync so often when just using switches - the value seems to be updated quicker in that case and that seems to extend to the API queries.

Looks like adopting this could be a good clean option.

Btw, thank you so much for your donation! 🙇 I really appreciate it!

Oh, don't mention it. I'm more than happy to support this project. Great work so far! 👏

from homebridge-shelly.

I see, that's nice!
I've created a new branch that uses this property instead of loading the position from the API. You can try it out by running $ npm install -g alexryd/homebridge-shelly#roller-position. Does it work?

from homebridge-shelly.

Nice. Looks like it does work. The values are now synced up much more reliable. At least eventually. There tends to be quite a bit of lag.

Here's an example when using HomeKit alone:

(see how it jumps back to the value it was set originally and then after several seconds it goes back to the value I set it to be +/- a few % error)

Here's when using the Web UI:

Notice that even the Web UI doesn't update immediately to reflect the new value. But HomeKit still takes quite a bit longer.

When using physical switches it's pretty much instant and always show the right value as soon as I release the switch. I guess this is more or less a Shelly problem, where the value just takes time to show up and appear via CoAP. Perhaps this gets better in future updates. If you're in touch with anybody there it might be good to loop them in on this?

For HomeKit it might be feasible to just assume that the set value is the destination value until an updated CoAP message gets in? I guess that also means ignoring values that come in that still have the old value set. But perhaps too finicky to get right?

In any case - thanks for looking into this. For my use case this is already much better than it was before. 👏

from homebridge-shelly.

Ok, good to see that is works. As for the lagging, I'll talk to Allterco about it. I think it would be much better if they could fix that on their end rather than me having to add quirks and fixes to get around it.

from homebridge-shelly.

Ok, sounds good. Do you intend to merge those changes back into master and make them part of future releases?

from homebridge-shelly.

Yes, definitely. They're in master now, will be released when I've finished implementing support for the Shelly RGBW2 and the Shelly Bulb that I'm currently working on.

from homebridge-shelly.

Closed? Shelly fixed some Bugs and updated s new Firmware

from homebridge-shelly.