alexryd / homebridge-shelly

Homebridge plugin for Shelly devices
MIT License
297 stars 44 forks source link

Shelly Firmware 1.8.3. wrong status indications in HomeKit #177

Open jchristianj opened 3 years ago

jchristianj commented 3 years ago

Describe the bug Not sure if this happened on Shelly FW 1.8.0 as well, but for sure it has been working perfect in 1.7.x. For the Shelly 2.5 in roller shutter mode the indications for opening and closing status in HomeKit are either lagging behind or they are too quick and therefore wrong. Example: A fully opened shutter is shown as "open" on the Homekit tile which is ok. But open pushing that tile, the roller shutter starts to move downwards, and the indication changes to "closed" immediately. This is not correct, as the shutter is still moving. In former FW versions (or plugin versions?) there has been a spinning wheel on that tile and there was a "closing..." indication during movement which changed to "closed" after the shutter stopped in closed position. This is gone now, and the same applies for the opening procedure.

Sometimes when the shutter is operated with the wall switch, the movement is not indicated at all on the Homekit tile, and the status is updated after a few minutes only or only after a force quit and restart of the home.app.

Log output None.

Environment:

lacsap88 commented 3 years ago

I have a Problem that all Shelly 2.5 FW 1.8.3 (Plugin Version 0.14) are not shown as shutter. They are just 2 Switches

alexryd commented 3 years ago

@jchristianj If you can run homebridge in debug mode, you will see a lot more info about what is happening in the log. This sounds like an issue with CoAP multicast messages, but I don't know why it would only occur with firmware 1.8.3. You can also try one of the commands listed here and see if you get CoAP messages for when your shutter starts, stops, is operated from the wall switch etc.

@lacsap88 Try running homebridge-shelly describe <ip-address> with the IP address of one of your 2.5s and then post the output here.

jchristianj commented 3 years ago

@alexryd Thanks for reply. Went back to FW 1.7.7. for testing on one of the Shellys. All is fine with 1.7.7., I have the spinning wheel as long as the shutter is moving which is correct, and correctly timed open / closed indication. So the issue seems to be related to FW1.8.0. One more odd thing I noticed in context with this issue: In the detailed device sheet (home.app, long press the tile) where the position of the shutter can be set with the vertical slider, the slider moves directly to fully opened / closed position, regardless of the selected opening degree; after a while, when the shutter stopped moving and reached the selected position, the slider indicates the correct position. This is very confusing.

FW 1.7.7. https://share.icloud.com/photos/0DRhFZ-U59B1UvVRVdW1rEqYg FW 1.8.0. https://share.icloud.com/photos/00uRAXIFCVkQSZgn4fcLQLVXA

jchristianj commented 3 years ago

Just gathered the Shelly's extended logs. Both logs show the action of the same command (set roller to certain position, starting position is app. 80%):

Log from Shelly with FW 1.7.7.: [Shelly] Setting rollerPosition of device SHSW-25 68C63AFA2BB1 to 53 [Shelly] rollerState of device SHSW-25 68C63AFA2BB1 changed to close [Shelly] rollerPosition of device SHSW-25 68C63AFA2BB1 changed to 53 [Shelly] rollerState of device SHSW-25 68C63AFA2BB1 changed to stop

Log from Shelly with FW 1.8.0.: [Shelly] Setting rollerPosition of device SHSW-25 68C63AFA3527 to 57 [Shelly] rollerState of device SHSW-25 68C63AFA3527 changed to close [Shelly] rollerPosition of device SHSW-25 68C63AFA3527 changed to 57 [Shelly] Setting target position of device SHSW-25 68C63AFA3527 to 0 [Shelly] rollerState of device SHSW-25 68C63AFA3527 changed to stop [Shelly] Setting target position of device SHSW-25 68C63AFA3527 to 57

There is one line in the 1.8.0. log which explains the false signaling, I think: "Setting target position of device SHSW-25 68C63AFA3527 to 0". Position is not set to zero in the home.app, but that might be the reason for the that strange display behavior.

alexryd commented 3 years ago

I'm guessing that rollerPosition and rollerState is not updated at the same time in firmware 1.8. So when rollerPosition is changed to 57 but rollerState is still close (eg. closing), to this plugin it appears that the shutter is still closing, and so it sets the target position to 0 just so that HomeKit will display it as closing.

It's unfortunate, but probably not what's causing your issue?

jchristianj commented 3 years ago

Just re-checked: There doesn't seem to be an issue with status indication after operating by wall switch, that works fine now (re-started all shellys and waited a few hours) and open/close/% status is represented after a few seconds correctly in home.app after manual operation; so what remains is an issue with displaying the actual status in home.app. after controlling it in home.app.

What I can say is that there is definitely a difference in logics (open/moving/closed) between Shelly FW 1.7.7. and 1.8.0. 1.7.7. is way better and more accurate (shows the spinning wheel during movement) compared to 1.8.0 which shows "closed" or "open" although the roller is in the middle of movement and shows the "jumping" position slider.

For me I decided to go back to FW 1.7.7. on all my Shellys which are configured as roller shutter, as long as the plugin and FW 1.8.x are not fine-tuned. Thanks anyway for your support!

jchristianj commented 3 years ago

Just for information: Shelly for HomeAssistant has same problems with position in roller shutter mode. https://github.com/StyraHem/ShellyForHASS/issues/399

alexryd commented 3 years ago

Thanks @jchristianj. It's hard for me to debug this as I don't have any roller shutters, but I'll have a look at ShellyForHASS and see what adjustments they've made.

nejcklinc commented 3 years ago

@alexryd do you have an estimate when can we expect fix for this issue?

Kroellie commented 3 years ago

I have similar, though somewhat different issues with v1.8.3 firmware for shelly 1. I can enable the device fine through Homekit/Homebridge. Disabling the switch fails.

command shellies listen shows: [Device discovered] 2020-09-22T09:43:07.964Z Model: Shelly 1 ID: E098068D90B5 Host: 192.168.1.43 Property: relay0 Value: false Property: input0 Value: 0 Property: inputEvent0 Value: Property: inputEventCounter0 Value: 0 Property: externalTemperature0 Value: null Property: externalTemperature1 Value: null Property: externalTemperature2 Value: null Property: externalHumidity Value: null Property: externalInput0 Value: null [Device discovered] 2020-09-22T09:43:07.979Z Model: Shelly 1 ID: B97354 Host: 192.168.1.20 Property: relay0 Value: false Property: input0 Value: 0 Property: inputEvent0 Value: Property: inputEventCounter0 Value: 0 Property: externalTemperature0 Value: null Property: externalTemperature1 Value: null Property: externalTemperature2 Value: null Property: externalHumidity Value: null Property: externalInput0 Value: null [Request failed] 2020-09-22T09:43:08.001Z Failed to load settings for device with ID E098068D90B5 Error: 401 Unauthorized [Request failed] 2020-09-22T09:43:08.005Z Failed to load settings for device with ID B97354 Error: 401 Unauthorized

borez commented 3 years ago

Hi all,

Adding my problems with the Shelly 1s, on 1.8.3. As some of these relays are powered off, Homebridge 1.2.3 does not accurately detect the status of these switches upon initialization. They are shown as "Off" rather than "No Response".

The relays sometimes don't respond to commands either. There are no issues activating these relays via the cloud (either from Shelly App or Google Home).

Type: SHSW-1 CoAP description: {"blk":[{"I":1,"D":"relay_0"},{"I":2,"D":"sensor_0"},{"I":3,"D":"sensor_1"},{"I":4,"D":"sensor_2"},{"I":5,"D":"device"}],"sen":[{"I":9103,"T":"EVC","D":"cfgChanged","R":"U16","L":5},{"I":1101,"T":"S","D":"output","R":"0/1","L":1},{"I":2101,"T":"S","D":"input","R":"0/1","L":1},{"I":2102,"T":"EV","D":"inputEvent","R":["S/L",""],"L":1},{"I":2103,"T":"EVC","D":"inputEventCnt","R":"U16","L":1},{"I":3101,"T":"T","D":"extTemp","U":"C","R":["-55/125","999"],"L":2},{"I":3102,"T":"T","D":"extTemp","U":"F","R":["-67/257","999"],"L":2},{"I":3201,"T":"T","D":"extTemp","U":"C","R":["-55/125","999"],"L":3},{"I":3202,"T":"T","D":"extTemp","U":"F","R":["-67/257","999"],"L":3},{"I":3301,"T":"T","D":"extTemp","U":"C","R":["-55/125","999"],"L":4},{"I":3302,"T":"T","D":"extTemp","U":"F","R":["-67/257","999"],"L":4},{"I":3103,"T":"H","D":"humidity","R":["0/100","999"],"L":2}]} CoAP status: {"G":[[0,9103,2],[0,1101,1],[0,2101,0],[0,2102,""],[0,2103,0]]} HTTP Settings:: {"device":{"type":"SHSW-1","mac":"xxxx","hostname":"shelly1-xxxx","num_outputs":1},"wifi_ap":{"enabled":false,"ssid":"shelly1-xxxx","key":""},"wifi_sta":{"enabled":true,"ssid":"-xxx-","ipv4_method":"dhcp","ip":null,"gw":null,"mask":null,"dns":null},"wifi_sta1":{"enabled":false,"ssid":null,"ipv4_method":"dhcp","ip":null,"gw":null,"mask":null,"dns":null},"mqtt":{"enable":false,"server":"192.168.33.3:1883","user":"","id":"shelly1-xxxx","reconnect_timeout_max":60,"reconnect_timeout_min":2,"clean_session":true,"keep_alive":60,"max_qos":0,"retain":false,"update_period":30},"coiot":{"update_period":15},"sntp":{"server":"time.google.com","enabled":true},"login":{"enabled":false,"unprotected":false,"username":"admin"},"pin_code":"^Ls!r6","name":"Shelly-xx","fw":"20200827-065344/v1.8.3@4a8bc427","factory_reset_from_switch":true,"discoverable":false,"build_info":{"build_id":"20200827-065344/v1.8.3@4a8bc427","build_timestamp":"2020-08-27T06:53:44Z","build_version":"1.0"},"cloud":{"enabled":true,"connected":true},"timezone":"Asia/Singapore","lat":1.29546,"lng":103.790001,"tzautodetect":true,"tz_utc_offset":28800,"tz_dst":false,"tz_dst_auto":true,"time":"20:48","unixtime":1601758121,"actions":{"active":false,"names":["btn_on_url","btn_off_url","longpush_url","shortpush_url","out_on_url","out_off_url"]},"hwinfo":{"hw_revision":"prod-191217","batch_id":1},"mode":"relay","longpush_time":800,"relays":[{"name":null,"ison":true,"has_timer":false,"default_state":"on","btn_type":"toggle","btn_reverse":0,"auto_on":0,"auto_off":0,"power":0,"btn_on_url":"","btn_off_url":"","out_on_url":"","out_off_url":"","longpush_url":"","shortpush_url":"","schedule":false,"schedule_rules":[]}],"ext_sensors":{},"ext_temperature":{},"ext_humidity":{}} HTTP Status:: {"wifi_sta":{"connected":true,"ssid":"-networkIoT-","ip":"xxx","rssi":-75},"cloud":{"enabled":true,"connected":true},"mqtt":{"connected":false},"time":"20:48","unixtime":1601758121,"serial":11,"has_update":false,"mac":"xxxx","cfg_changed_cnt":2,"actions_stats":{"skipped":0},"relays":[{"ison":true,"has_timer":false,"timer_started":0,"timer_duration":0,"timer_remaining":0,"source":"http"}],"meters":[{"power":0,"is_valid":true}],"inputs":[{"input":0,"event":"","event_cnt":0}],"ext_sensors":{},"ext_temperature":{},"ext_humidity":{},"update":{"status":"idle","has_update":false,"new_version":"20200827-065344/v1.8.3@4a8bc427","old_version":"20200827-065344/v1.8.3@4a8bc427"},"ram_total":51112,"ram_free":39288,"fs_size":233681,"fs_free":150349,"uptime":1650}

To add more debugging info:

[10/3/2020, 20:56:00] [Shelly] Failed to set relay0 [10/3/2020, 20:56:00] [Shelly] Request timeout (device SHSW-1 xxxx, at 192.x.x.x) [10/3/2020, 20:56:22] [Shelly] Failed to set relay0 [10/3/2020, 20:56:22] [Shelly] Error: connect EHOSTUNREACH 192.x.x.x:80 (device SHSW-1 xxxx, at 192.x.x.x)

However on the homebridge-shelly server (:8181), the device is still shown as Online. This is 3 mins since the relay was powered off. Shelly Cloud app already shows the device as offline.