search

mattsaxon / sonoff-lan-mode-homeassistant

Home Assistant platform to control Sonoff switches running the latest Itead firmware, locally (LAN mode).
MIT License
51 stars 23 forks source link

Devices Unavailable after each HA restart #31

Closed mariobarisic closed 4 years ago

mariobarisic commented 4 years ago

I'm running HA (Hass.io on RPi3B+, current version is 0.108.8) and I have noticed now every time when HA restarts all of my Sonoff devices are Unavailable. I need to go to Ewelink app on my phone and just open the app and then all the devices are immediately visible in HA. I don't know if it has something with HA or even with newest version of Ewelink Android app now is version 4.0.2.

mattsaxon commented 4 years ago

This looks similar to this issue here (which is fixed) https://github.com/mattsaxon/sonoff-lan-mode-homeassistant/issues/24

Can you confirm if this worked prior to 0.108.8?

What devices do you have and what mode are you using them in? Please post the relevant part of your config file.

mariobarisic commented 4 years ago

I can confirm it was working before. I don't know exactly with which HA version is stopped. For several weeks it doesn't work. I have different devices in my setup, Sonoff Basic, Sonof -Basic2, and Sonoff RF_R2 switch. All of them are on latest FW - 3.4.0 My config yaml: `# ## SONOFF VIA custom component ##

mattsaxon commented 4 years ago

Ok. I’m on 108.2 and it works fine. I’ll upgrade and see what issues are, but 108.9 is available now. There a fix that I’ve just coded for a dependant library, zeroconf, that I expect will improve stability, so we will need to wait for that to be included in the HA code add to see how things pan out. They usually include them pretty quickly, so hopefully only a couple of weeks away.

mariobarisic commented 4 years ago

One question, when I want to update your custom component it is enough just to replace files under /custom component folder on hass.io with new ones from your repo and restart HA?

mattsaxon commented 4 years ago

Yes that’s right. I’ve recently heard there is a component called HACS that automates updates often custom components. You could give that a try.

mariobarisic commented 4 years ago

OK, I have tried to add your repo as custom to HACS: https://github.com/mattsaxon/sonoff-lan-mode-homeassistant.git but I'm getting this error in HA: image

mattsaxon commented 4 years ago

I’ve never used it, but see this issue https://github.com/mattsaxon/sonoff-lan-mode-homeassistant/issues/30 perhaps if you ask that user who raised the issue and says it is now resolved can assist.

mattsaxon commented 4 years ago

OK, thanks for the info on your Python version, that may well be it. I note that HomeAssistant requires 3.7 now looking at https://pypi.org/project/homeassistant/

mariobarisic commented 4 years ago

The last few days I'm experiencing that all of my Sonoff devices are completely Unavailable from HA, and at the same time I can control all devices within Ewelink app on my mobile? I have tried to restart HA several times, even to reinstall this custom component, but without any success. Now my HA is 0.109.0 and I can update to 0.109.2...

mattsaxon commented 4 years ago

Apparently 109 doesn’t work at all. I’m on 108.2, will take a look today what has broken things

mariobarisic commented 4 years ago

I hope you will find what is the cause that your superb custom component doesn't work any more... I don't want to flash all of my Sonoff devices with Tasmota....

mattsaxon commented 4 years ago

@mariobarisic fixed in 1.1.4.1

mariobarisic commented 4 years ago

@mattsaxon I have updated your component through HACS and after restart only one SONOFF device were Available, all other still Unavailable... This one in Master Bedroom is connected to the 2nd wifi router (with the same WIFI SSID name like 1st from ISP).All other devices which are connected to the main router (Ubee) and also Rpi3B+ with HA are not working via HA (they are Unavailable). In the same time all of my devices are Available through Ewelink app on my phone and the are in LAN mode... I hope that my HA isn't updated one more time to 0.109.2... or this strange behaviour is somehow connected both with HA version and my WIFI router topology at home... Maybe debugg logg can show as something??

mariobarisic commented 4 years ago

Here is my debug logg:

2020-05-02 15:35:27 DEBUG (SyncWorker_2) [custom_components.sonoff_lan_mode_r3.switch] encrypted: {'sequence': '1588426527306', 'deviceid': '10005cec8e', 'selfApikey': '123', 'iv': 'j+9woEAQc1KN8jVatkxxyw==', 'encrypt': True, 'data': 'MThasg8R+hYXx000sdsmkw=='} 2020-05-02 15:35:27 DEBUG (SyncWorker_2) [custom_components.sonoff_lan_mode_r3.switch] Sending http message to http://192.168.0.33:8081/zeroconf/signal_strength: {"sequence":"1588426527306","deviceid":"10005cec8e","selfApikey":"123","iv":"j+9woEAQc1KN8jVatkxxyw==","encrypt":true,"data":"MThasg8R+hYXx000sdsmkw=="} 2020-05-02 15:35:27 DEBUG (SyncWorker_2) [custom_components.sonoff_lan_mode_r3.switch] response received: <Response [200]> b'{"seq":315,"sequence":"1588426527306","error":422}' 2020-05-02 15:35:27 INFO (SyncWorker_2) [custom_components.sonoff_lan_mode_r3.switch] Service 10005cec8e flagged for removal, but is still active! 2020-05-02 15:37:17 INFO (zeroconf-ServiceBrowser__ewelink._tcp.local.) [custom_components.sonoff_lan_mode_r3.switch] Service eWeLink_10005cec8e._ewelink._tcp.local. added again (1 times) 2020-05-02 15:37:17 DEBUG (MainThread) [custom_components.sonoff_lan_mode_r3.switch] enter handle_message() {} 2020-05-02 15:37:17 INFO (zeroconf-ServiceBrowser__ewelink._tcp.local.) [custom_components.sonoff_lan_mode_r3.switch] Service type _ewelink._tcp.local. of name eWeLink_10005cec8e._ewelink._tcp.local. added 2020-05-02 15:37:17 DEBUG (MainThread) [custom_components.sonoff_lan_mode_r3.switch] Switch update pre-callback filter running 2020-05-02 15:37:17 DEBUG (zeroconf-ServiceBrowser__ewelink._tcp.local.) [custom_components.sonoff_lan_mode_r3.switch] service is at http://192.168.0.33:8081 2020-05-02 15:37:17 DEBUG (MainThread) [custom_components.sonoff_lan_mode_r3.switch] Not inching switch, calling parent callback 2020-05-02 15:37:17 DEBUG (zeroconf-ServiceBrowser__ewelink._tcp.local.) [custom_components.sonoff_lan_mode_r3.switch] properties: {b'txtvers': b'1', b'id': b'10005cec8e', b'type': b'plug', b'apivers': b'1', b'seq': b'314', b'encrypt': b'true', b'iv': b'ODYxMDczMjM3NDY2NjI0NA==', b'data1': b'SQ2yivvpbAXP9wZFkD3oRlSb7vZtKTvPJO8UufSPlFUVj3bXbpncQ9wxt/JyCSukyooUfLo7brcETfiaOhLzzb/JkGuZqNf6xR42G2QmiRJ1ROeJVFGY1ECtQDkidvKF'} 2020-05-02 15:37:17 INFO (MainThread) [custom_components.sonoff_lan_mode_r3.switch] Sonoff LAN Mode switch Bedroom_LED received updated state from the device: OFF, available: True 2020-05-02 15:37:17 DEBUG (zeroconf-ServiceBrowser__ewelink._tcp.local.) [custom_components.sonoff_lan_mode_r3.switch] type: b'plug' 2020-05-02 15:37:17 DEBUG (MainThread) [custom_components.sonoff_lan_mode_r3.switch] HassSonoffSwitch async_update called 2020-05-02 15:37:17 DEBUG (MainThread) [custom_components.sonoff_lan_mode_r3.switch] HassSonoffSwitch returning _available: True 2020-05-02 15:37:17 DEBUG (zeroconf-ServiceBrowser__ewelink._tcp.local.) [custom_components.sonoff_lan_mode_r3.switch] decrypted data: b'{"switch":"off","startup":"off","pulse":"off","sledOnline":"on","pulseWidth":500,"rssi":-83}' 2020-05-02 15:37:17 DEBUG (MainThread) [custom_components.sonoff_lan_mode_r3.switch] HassSonoffSwitch returning _state: False 2020-05-02 15:37:18 DEBUG (zeroconf-ServiceBrowser__ewelink._tcp.local.) [custom_components.sonoff_lan_mode_r3.switch] service is at http://192.168.0.33:8081 2020-05-02 15:37:18 DEBUG (MainThread) [custom_components.sonoff_lan_mode_r3.switch] HassSonoffSwitch returning _name: Bedroom_LED 2020-05-02 15:37:18 INFO (zeroconf-ServiceBrowser__ewelink._tcp.local.) [custom_components.sonoff_lan_mode_r3.switch] same update received for device: eWeLink_10005cec8e._ewelink._tcp.local. 2020-05-02 15:37:18 DEBUG (MainThread) [custom_components.sonoff_lan_mode_r3.switch] enter handle_message() b'{"switch":"off","startup":"off","pulse":"off","sledOnline":"on","pulseWidth":500,"rssi":-83}' 2020-05-02 15:37:18 DEBUG (MainThread) [custom_components.sonoff_lan_mode_r3.switch] Message: Received status from device, storing in instance 2020-05-02 15:37:18 INFO (MainThread) [custom_components.sonoff_lan_mode_r3.switch] 10005cec8e: Connected event, sending 'available' update 2020-05-02 15:37:18 INFO (MainThread) [custom_components.sonoff_lan_mode_r3.switch] unsolicited update received from switch: off 2020-05-02 15:42:23 DEBUG (zeroconf-ServiceBrowser__ewelink._tcp.local.) [custom_components.sonoff_lan_mode_r3.switch] Service eWeLink_10005cec8e._ewelink._tcp.local. flagged for removal 2020-05-02 15:42:23 DEBUG (SyncWorker_8) [custom_components.sonoff_lan_mode_r3.switch] Sending retry message for 10005cec8e 2020-05-02 15:42:23 DEBUG (SyncWorker_8) [custom_components.sonoff_lan_mode_r3.switch] params: {} 2020-05-02 15:42:23 DEBUG (SyncWorker_8) [custom_components.sonoff_lan_mode_r3.switch] encrypted: {'sequence': '1588426943362', 'deviceid': '10005cec8e', 'selfApikey': '123', 'iv': 'cX1+WzVvdqsICXBCtwZOng==', 'encrypt': True, 'data': 'z42yguJ9D08P2Li4B5ZVDw=='} 2020-05-02 15:42:23 DEBUG (SyncWorker_8) [custom_components.sonoff_lan_mode_r3.switch] Sending http message to http://192.168.0.33:8081/zeroconf/signal_strength: {"sequence":"1588426943362","deviceid":"10005cec8e","selfApikey":"123","iv":"cX1+WzVvdqsICXBCtwZOng==","encrypt":true,"data":"z42yguJ9D08P2Li4B5ZVDw=="} 2020-05-02 15:42:23 DEBUG (SyncWorker_8) [custom_components.sonoff_lan_mode_r3.switch] response received: <Response [200]> b'{"seq":315,"sequence":"1588426943362","error":422}' 2020-05-02 15:42:23 INFO (SyncWorker_8) [custom_components.sonoff_lan_mode_r3.switch] Service 10005cec8e flagged for removal, but is still active!

mariobarisic commented 4 years ago

And this part is where I can toggle state on my Bedroom LED light:

2020-05-02 16:13:09 DEBUG (MainThread) [custom_components.sonoff_lan_mode_r3.switch] HassSonoffSwitch returning _available: True 2020-05-02 16:13:09 INFO (MainThread) [custom_components.sonoff_lan_mode_r3.switch] Sonoff LAN Mode switch Bedroom_LED switching on 2020-05-02 16:13:09 DEBUG (MainThread) [custom_components.sonoff_lan_mode_r3.switch] Switch turn_on called. 2020-05-02 16:13:09 DEBUG (MainThread) [custom_components.sonoff_lan_mode_r3.switch] Scheduling params update message to device: {'switch': 'on'} 2020-05-02 16:13:09 DEBUG (MainThread) [custom_components.sonoff_lan_mode_r3.switch] Connected! 2020-05-02 16:13:09 DEBUG (MainThread) [custom_components.sonoff_lan_mode_r3.switch] params: {'switch': 'on'} 2020-05-02 16:13:09 DEBUG (MainThread) [custom_components.sonoff_lan_mode_r3.switch] encrypted: {'sequence': '1588428789280', 'deviceid': '10005cec8e', 'selfApikey': '123', 'iv': 'O/7FTDrdSMC61cLO3oCBjg==', 'encrypt': True, 'data': 'zHm0Dxx4OlRXsruhBeoA7Q=='} 2020-05-02 16:13:09 DEBUG (SyncWorker_10) [custom_components.sonoff_lan_mode_r3.switch] Sending http message to http://192.168.0.33:8081/zeroconf/switch: {"sequence":"1588428789280","deviceid":"10005cec8e","selfApikey":"123","iv":"O/7FTDrdSMC61cLO3oCBjg==","encrypt":true,"data":"zHm0Dxx4OlRXsruhBeoA7Q=="} 2020-05-02 16:13:09 DEBUG (SyncWorker_10) [custom_components.sonoff_lan_mode_r3.switch] response received: <Response [200]> b'{"seq":315,"sequence":"1588428789280","error":0}' 2020-05-02 16:13:09 DEBUG (SyncWorker_10) [custom_components.sonoff_lan_mode_r3.switch] message sent to switch successfully 2020-05-02 16:13:11 WARNING (MainThread) [custom_components.sonoff_lan_mode_r3.switch] Device: 10005cec8e. Update message not received in timeout period, retry 2020-05-02 16:13:11 DEBUG (MainThread) [custom_components.sonoff_lan_mode_r3.switch] send_updated_params_loop now awaiting event 2020-05-02 16:13:11 DEBUG (MainThread) [custom_components.sonoff_lan_mode_r3.switch] Connected! 2020-05-02 16:13:11 DEBUG (MainThread) [custom_components.sonoff_lan_mode_r3.switch] params: {'switch': 'on'} 2020-05-02 16:13:11 DEBUG (MainThread) [custom_components.sonoff_lan_mode_r3.switch] encrypted: {'sequence': '1588428791341', 'deviceid': '10005cec8e', 'selfApikey': '123', 'iv': 'QoODMfeYagHDyibPnddlnQ==', 'encrypt': True, 'data': 'Ns3eYZoHgk2+DccGbjh6dw=='} 2020-05-02 16:13:11 DEBUG (SyncWorker_12) [custom_components.sonoff_lan_mode_r3.switch] Sending http message to http://192.168.0.33:8081/zeroconf/switch: {"sequence":"1588428791341","deviceid":"10005cec8e","selfApikey":"123","iv":"QoODMfeYagHDyibPnddlnQ==","encrypt":true,"data":"Ns3eYZoHgk2+DccGbjh6dw=="} 2020-05-02 16:13:11 DEBUG (SyncWorker_12) [custom_components.sonoff_lan_mode_r3.switch] response received: <Response [200]> b'{"seq":316,"sequence":"1588428791341","error":0}' 2020-05-02 16:13:11 DEBUG (SyncWorker_12) [custom_components.sonoff_lan_mode_r3.switch] message sent to switch successfully 2020-05-02 16:13:13 DEBUG (MainThread) [custom_components.sonoff_lan_mode_r3.switch] HassSonoffSwitch returning _available: True 2020-05-02 16:13:13 INFO (MainThread) [custom_components.sonoff_lan_mode_r3.switch] Sonoff LAN Mode switch Bedroom_LED switching on 2020-05-02 16:13:13 DEBUG (MainThread) [custom_components.sonoff_lan_mode_r3.switch] Switch turn_on called. 2020-05-02 16:13:13 DEBUG (MainThread) [custom_components.sonoff_lan_mode_r3.switch] unnecessary update received, ignoring 2020-05-02 16:13:16 WARNING (MainThread) [custom_components.sonoff_lan_mode_r3.switch] Device: 10005cec8e. Update message not received in timeout period, retry 2020-05-02 16:13:16 DEBUG (MainThread) [custom_components.sonoff_lan_mode_r3.switch] send_updated_params_loop now awaiting event 2020-05-02 16:13:16 DEBUG (MainThread) [custom_components.sonoff_lan_mode_r3.switch] Connected! 2020-05-02 16:13:16 DEBUG (MainThread) [custom_components.sonoff_lan_mode_r3.switch] params: {'switch': 'on'} 2020-05-02 16:13:16 DEBUG (MainThread) [custom_components.sonoff_lan_mode_r3.switch] encrypted: {'sequence': '1588428796389', 'deviceid': '10005cec8e', 'selfApikey': '123', 'iv': 'rdeHbpmx6NpRkcQnJs5b4g==', 'encrypt': True, 'data': 'VOrZucVvd6/e1Ms1vnRexQ=='}

mattsaxon commented 4 years ago

Can we track back on this... when did this stop working? At that time what version on HA were you on? I appreciate the 109 caused an issue, but I've fixed that today. And for me its all working fine. I have 0.109.2 now with my component at 1.1.4.1

We first need to track down if you only had issues since 0.109. If so, then ensure you are on my latest version and 109.2. If however problem was before you upgrades to 0.109, and it stopped working, then you likely have something wrong in your local network.

I haven't looked at the debug logs in detail yet, but it does seem that there is a network issue there from a cursory look.

mariobarisic commented 4 years ago

OK, the issues starts to occur when I move my 2nd router in the different place in my apartment and when I enabled wifi on both routers.. In the same time HA was updated to version 0.108 and Ewelink app to version 4, I think... In the beginning after entering Ewelink app on my phone all the devices were Available in HA. Now I have latest HA version - 0.109.2, latest version of your component 1.1.4.1 and still nothing... Now I have just disabled WIFI from my first ISPs router, restarts HA and all of my devices are once again Available and Controllable 😄 It seems like my Sonoff devices don't like ISPs router when they need to work with HA.... I would like to know why, but for now I will leave as it is...

mariobarisic commented 4 years ago

OK there is a lag with controll and feedback from devices... When I press buttons on HA interface nothing is changed and then several seconds (10-20) the lights switch on or off.. Mostly on, and I can't turn them off via HA?! Definitely strange behavior on my side...

mattsaxon commented 4 years ago

Not sure. I suggest waiting for the fixes zeroconf 0.26.0 to be integrated with home Assistant. I’m hopefully that this will help with network issues. It specifically deals with changes of IP address that likely occur in situations like this.

I’d check that you don’t have dhcp configured on multiple routers, as this will likely cause issues