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

Unresponsive Sonoff Basic switch #22

Closed mariobarisic closed 4 years ago

mariobarisic commented 4 years ago

Sonoff Basic (R1 - FW:3.3.0. - PSF-B01-GL) switch is added to Home Assistant (Hass.io on RPi3 B+ - HA version 0.104.3) with the latest version of this component manually copied to _/customcomponents/ folder.

configuration.yaml file is as follows: _- platform: sonoff_lan_mode_r3 name: "TV_under_LED" device_id: 1000a74e04 api_key: !secret sonoff_api_key1000a74e04 The switch was visible in HA at the begining but after I have toggle it's state through Ewelink app on my phone. Then I was able to control the switch for some time, but I have noticed a lag in sending commands to switch and receiving status from it. Then the switch state in HA goes to Unavailable as you can see in the picture below: image After restarting HA the status is were present for brief time but then once again Unavailable. Also I have noticed when the switch was available when I toggle the switch from HA the action take place several minutes after... The loggs are: Service 1000a74e04 removed 9:30 AM /usr/local/lib/python3.7/site-packages/pysonofflanr3/client.py (WARNING) Connection issue for device 1000a74e04: HTTPConnectionPool(host='192.168.0.32', port=8081): Max retries exceeded with url: /zeroconf/switch (Caused by NewConnectionError('<urllib3.connection.HTTPConnection object at 0x6d72a350>: Failed to establish a new connection: [Errno 111] Connection refused')) 9:29 AM main.py (WARNING)

And more detailed (debug) one: 2020-01-29 09:25:26 DEBUG (zeroconf-ServiceBrowserewelink._tcp.local.) [homeassistant.components.switch.sonoff_lan_mode_r3] Service eWeLink_10005677b8._ewelink._tcp.local. updated (not our switch) 2020-01-29 09:25:26 DEBUG (zeroconf-ServiceBrowser__ewelink._tcp.local.) [homeassistant.components.switch.sonoff_lan_mode_r3] Service eWeLink_100063a1ff._ewelink._tcp.local. updated (not our switch) 2020-01-29 09:25:26 DEBUG (zeroconf-ServiceBrowserewelink._tcp.local.) [homeassistant.components.switch.sonoff_lan_mode_r3] Service eWeLink_1000636c23._ewelink._tcp.local. updated (not our switch) 2020-01-29 09:25:26 INFO (zeroconf-ServiceBrowserewelink._tcp.local.) [homeassistant.components.switch.sonoff_lan_mode_r3] Service type _ewelink._tcp.local. of name eWeLink_1000a74e04._ewelink._tcp.local. added 2020-01-29 09:25:26 DEBUG (zeroconf-ServiceBrowserewelink._tcp.local.) [homeassistant.components.switch.sonoff_lan_mode_r3] service is at 192.168.0.32:8081 2020-01-29 09:25:26 DEBUG (zeroconf-ServiceBrowserewelink._tcp.local.) [homeassistant.components.switch.sonoff_lan_mode_r3] properties: {b'txtvers': b'1', b'id': b'1000a74e04', b'type': b'plug', b'apivers': b'1', b'seq': b'95', b'encrypt': True, b'iv': b'NDc0MzA4MzcwNzc1NzYzNg==', b'data1': b'2BkN3fiFx8YxjkWWEe7HMztOxABIWrCA0oCCQt/rdmL1wVJRZ3UtfR2HE6/tVBE9ZGXirpOAScsGwwD3chsxkH/KUtQsgCkhu5cc7Jq8P+uyhRpc+cWqGIXnyMz6m8NA'} 2020-01-29 09:25:26 DEBUG (zeroconf-ServiceBrowserewelink._tcp.local.) [homeassistant.components.switch.sonoff_lan_mode_r3] type: b'plug' 2020-01-29 09:25:26 DEBUG (zeroconf-ServiceBrowserewelink._tcp.local.) [homeassistant.components.switch.sonoff_lan_mode_r3] decrypted data: b'{"switch":"off","startup":"off","pulse":"off","sledOnline":"on","pulseWidth":500,"rssi":-42}' 2020-01-29 09:25:26 DEBUG (MainThread) [homeassistant.components.switch.sonoff_lan_mode_r3] enter handle_message() b'{"switch":"off","startup":"off","pulse":"off","sledOnline":"on","pulseWidth":500,"rssi":-42}' 2020-01-29 09:25:26 DEBUG (zeroconf-ServiceBrowser__ewelink._tcp.local.) [homeassistant.components.switch.sonoff_lan_mode_r3] properties: {b'txtvers': b'1', b'id': b'1000a74e04', b'type': b'plug', b'apivers': b'1', b'seq': b'95', b'encrypt': True, b'iv': b'NDc0MzA4MzcwNzc1NzYzNg==', b'data1': b'2BkN3fiFx8YxjkWWEe7HMztOxABIWrCA0oCCQt/rdmL1wVJRZ3UtfR2HE6/tVBE9ZGXirpOAScsGwwD3chsxkH/KUtQsgCkhu5cc7Jq8P+uyhRpc+cWqGIXnyMz6m8NA'} 2020-01-29 09:25:26 DEBUG (MainThread) [homeassistant.components.switch.sonoff_lan_mode_r3] Message: Received status from device, storing in instance 2020-01-29 09:25:26 DEBUG (zeroconf-ServiceBrowserewelink._tcp.local.) [homeassistant.components.switch.sonoff_lan_mode_r3] type: b'plug' 2020-01-29 09:25:26 INFO (MainThread) [homeassistant.components.switch.sonoff_lan_mode_r3] unsolicited update received from switch: off 2020-01-29 09:25:26 DEBUG (zeroconf-ServiceBrowser__ewelink._tcp.local.) [homeassistant.components.switch.sonoff_lan_mode_r3] decrypted data: b'{"switch":"off","startup":"off","pulse":"off","sledOnline":"on","pulseWidth":500,"rssi":-42}' 2020-01-29 09:25:26 DEBUG (MainThread) [homeassistant.components.switch.sonoff_lan_mode_r3] Switch update pre-callback filter running 2020-01-29 09:25:26 DEBUG (zeroconf-ServiceBrowserewelink._tcp.local.) [homeassistant.components.switch.sonoff_lan_mode_r3] Service eWeLink_1000568b68._ewelink._tcp.local. updated (not our switch) 2020-01-29 09:25:26 DEBUG (MainThread) [homeassistant.components.switch.sonoff_lan_mode_r3] Not inching switch, calling parent callback 2020-01-29 09:25:26 DEBUG (zeroconf-ServiceBrowserewelink._tcp.local.) [homeassistant.components.switch.sonoff_lan_mode_r3] Service eWeLink_10004f5b71._ewelink._tcp.local. updated (not our switch) 2020-01-29 09:25:26 INFO (MainThread) [homeassistant.components.switch.sonoff_lan_mode_r3] Sonoff LAN Mode switch TV_under_LED received updated state from the device: OFF, available: True 2020-01-29 09:25:26 DEBUG (MainThread) [homeassistant.components.switch.sonoff_lan_mode_r3] HassSonoffSwitch async_update called 2020-01-29 09:25:26 DEBUG (MainThread) [homeassistant.components.switch.sonoff_lan_mode_r3] connected event, sending update 2020-01-29 09:25:26 DEBUG (MainThread) [homeassistant.components.switch.sonoff_lan_mode_r3] waiting for disconnection 2020-01-29 09:25:26 DEBUG (MainThread) [homeassistant.components.switch.sonoff_lan_mode_r3] HassSonoffSwitch returning _available: True 2020-01-29 09:25:26 DEBUG (MainThread) [homeassistant.components.switch.sonoff_lan_mode_r3] HassSonoffSwitch returning _state: False 2020-01-29 09:25:26 DEBUG (MainThread) [homeassistant.components.switch.sonoff_lan_mode_r3] HassSonoffSwitch returning _name: TV_under_LED 2020-01-29 09:25:26 DEBUG (MainThread) [homeassistant.components.switch.sonoff_lan_mode_r3] enter handle_message() b'{"switch":"off","startup":"off","pulse":"off","sledOnline":"on","pulseWidth":500,"rssi":-42}' 2020-01-29 09:25:26 DEBUG (MainThread) [homeassistant.components.switch.sonoff_lan_mode_r3] Message: Received status from device, storing in instance 2020-01-29 09:25:26 INFO (MainThread) [homeassistant.components.switch.sonoff_lan_mode_r3] unsolicited update received from switch: off

If you need anything else please let me know. Best regards, Mario

mattsaxon commented 4 years ago

The errors messages are clearly showing network issues to connect to the device.

My experiences with this are complex, but basically when I experience these sort of issues in HA, I have similar issues in eWeLink.

They do however show differently, eWeLink shows the device available more often, but I get issues with operation.

There are some residual errors as a result of this, which I am trying to fix in Zeroconf, but this is a dependant component, so it’s taking a while to get these reviewed and accepted.

Sorry I can’t be of more help, but at least I have a similar situation for one of my devices in a poor connectors area so will be trying to fix it.

That said only one of my 20 or so devices has this issue, and I might just get another wifi Access point. It’s certainly cheaper in effort!

mariobarisic commented 4 years ago

It's very strange that it has something to do with connection problems hence the Sonoff device is less then 0.5m away of the Wifi router?! Yesterday I have added second Sonoff device, It's also Basic R1 version but with FW: 3.0.1. - ITA-GZ1-GL. The situation is a little bit better but still I'm experience some lag in communication from HA in both sending commands and receiving switch states. The situation in native eWeLink app is better in the same time and I can control the device within the app and see the current status. I don't know if it has something to do with sonoff switch version - Basic R1, because this device isn't mentioned directly as supported.

mattsaxon commented 4 years ago

I’m afraid I only have r2 and r3 devices, but I doubt this would be the problem.

Could it be related to your HA device? Is everything else that that controls working well?

mattsaxon commented 4 years ago

How bad is the lag? I expect you are seeing retries in the log when this lag is occurring, can you confirm?

mattsaxon commented 4 years ago

This error message is very clear Connection issue for device 1000a74e04: HTTPConnectionPool(host='192.168.0.32', port=8081): Max retries exceeded with url: /zeroconf/switch (Caused by NewConnectionError('<urllib3.connection.HTTPConnection object at 0x6d72a350>: Failed to establish a new connection: [Errno 111] Connection refused'))

This means that an HTTP connection could not be established between the HA device and the switch.

mattsaxon commented 4 years ago

You could ask back on the home assistant community thread if anyone is having success with R1 devices.

mariobarisic commented 4 years ago

How bad is the lag? I expect you are seeing retries in the log when this lag is occurring, can you confirm?

It's very bad sometimes more then 10-15 seconds. For example I'm changing the switch in HA, and then after 10-20s the sonoff turns on or off the light... also with the status of the light. In HA i can see like is turned on and the actual status is off. Then again after several seconds (10-20-30s) i can see the right status in HA. Meanwhile in eWeLink app the status and control is almost instant!

mariobarisic commented 4 years ago

I’m afraid I only have r2 and r3 devices, but I doubt this would be the problem.

Could it be related to your HA device? Is everything else that that controls working well?

I have also R2 devices (both Basic and RF) so I will try them in HA and see will it work better. Also for R1 devices I can put Tasmota FW (i will backup original FW just in case) I'm waiting for USB/TTL card to arrive.

mattsaxon commented 4 years ago

The 10-15 second lag shows the component is retrying, you should see evidence of this in the logs.

There is nothing I can do in the component to resolve this, if the component can’t get to the device, all I can do is retry.

The network route is going to be different between Ewelink vs HA, so I suggest you look at if that is the problem. How does HA connect to your WiFi?

mariobarisic commented 4 years ago

HA which is on RPi3 B+ is connected with ethernet cable to the first router (ISPs). Then second router ASUS 1200G+ is connected with Gigabit LAN with first router and I'm using it just for wifi coverage of entire apartment. (on the first router WIFI is disabled, and all of my equipment is connected to 2nd router) I can see that your component is trying to communicate but after some time it stops which is normal and timeout is declared or something like this.

mattsaxon commented 4 years ago

I use the same Rpi by the way.

Nothing seems wrong in your setup from your description.

I’m not sure there is anything I can assist with unfortunately. It will be good to know if your R2s work though so we can tell others if it is an R1 issue

mariobarisic commented 4 years ago

I will definitely get back with feedback for R2 devices... One more time thanks for your help and excellent custom component ;)

mariobarisic commented 4 years ago

Is there a limit of connected devices with this component. Yesterday I've added 3rd one (this time Sonoff Basic R2 - FW: 3.3.0. - PSF-B01-GL) and after HA server restart all 3 devices were unavailable. I have restarted HA several times, double check configuration. In loggs only some attempts and delays were present. Then I've removed all except this last added device (Basic R2) and after server restart it shows up immediately in HA and the status were correct. I didn't manage to test the behavior of this switch because it was very late, and this device turns on LED above bed in our master bedroom (and my wife was sleeping already ;)

mattsaxon commented 4 years ago

No limit that I’m aware of.

I have around 20 sonoff devices Integrated in my system.

mariobarisic commented 4 years ago

Then it must be something with my setup in HA and this custom component and sonoff devices. They are rather old ones compared to new R3 devices... I will try also the same device with custom firmware (Tasmota) and see the behavior over MQTT in my network.

mattsaxon commented 4 years ago

For further info, I’ve only had a single R3, most are R2. I think Tasmota feedback will be interesting as it will tell you of it is something to do with your hardware. Although obviously you will loose eWeLink fallback capability, which was one of my main reasons for sticking with factory firmware.

mariobarisic commented 4 years ago

For starters I will flash only one Sonoff switch with Tasmota (I will backup original FW, just in case) and see how it performs in my test enviroment... Very strange thing is that under eWeLink app on my mobile phone in the same WiFi network at home, sonoff switches act like it should. Very fast on action and updating it's states. I'm using them with app and Alexa for more than a year and no problem what so ever...

mattsaxon commented 4 years ago

The evidence here points to the connection between the HA box and your router. I’m not saying it is that, but given what you’ve said it where I’d look first

mariobarisic commented 4 years ago

Yes you are right. I will try connect RPI HA host to 2nd router (wired) where all the WIFI traffic is made... Maybe this helps.

mariobarisic commented 4 years ago

Just to inform @mattsaxon after moving RPi3 with HA to 2nd router LAN port everything is working as expected. All switches are very fast in both ways - activacting and sending the actual states. So at the end the problem was related to 2 routers... Thank once again for all your help.

mattsaxon commented 4 years ago

Glad you got it sorted!