Rewrite the way of working with UDP traffic in XiaomiGateway._send_cmd() about pyxiaomigateway

[PaulAnnekov]

I'm gonna fix this bug this week.

[Danielhiversen]

I agree.
I only have one gw and then it works fine.
So the multi gw solution is an old implementation, that I have never tested.

A pull request is welcome :)

[PaulAnnekov]

You will have this issue even with a single gateway. You just need several XiaomiDevices (like XiaomiMotionSensor) to make a request to gateway at the same time. And there will be a big chance of failure and broken state.

[Danielhiversen]

You are right

[heff27]

I have noticed since upgrading to 0.62.1 i am getting a lot of Unavailable status on the window and door sensors, a restart of HA, fixes this for a white while.

[PaulAnnekov]

@heff27 it can indicate that your local network is not very stable and loses packets sent by gateway.

Can you enable debug logging and provide us xiaomi_gateway/homeassistant.components.xiaomi_aqara logs for the last 2 days:

logger:
  logs:
    xiaomi_gateway: debug
    homeassistant.components.xiaomi_aqara: debug

?

Device becomes unavailable when it doesn't send at least one packet of data in 2.5 hours. So if you don't see any report/read_ack/write_ack/heartbeat from your device in 2.5 hours time frame - you get unavailable state. Restarting HA just resets this 2.5 hours timer and countdown begins from start :).

[heff27]

Ok i have enabled logging with the command, I am new to logging how do it get the Xiaomi Logs as the home assistant log file, has a load of stuff in it since added the above commands in to my Config Yaml.

Here is one of the errors since logging as enabled

2018-02-03 02:33:24 DEBUG (SyncWorker_0) [xiaomi_gateway] _send_cmd resp << {'cmd': 'write_ack', 'model': 'gateway', 'sid': '34ce008db90c', 'short_id': 0, 'data': '{"rgb":455343891,"illumination":392,"proto_version":"1.0.9"}'}
2018-02-03 02:33:24 ERROR (SyncWorker_0) [xiaomi_gateway] Non matching response. Expecting read_ack, but got write_ack
2018-02-03 02:33:24 DEBUG (SyncWorker_0) [xiaomi_gateway] read_ack << None
2018-02-03 02:33:24 DEBUG (SyncWorker_5) [xiaomi_gateway] _send_cmd resp << {'cmd': 'read_ack', 'model': 'magnet', 'sid': '158d0001a49988', 'short_id': 43824, 'data': '{"voltage":3045,"status":"open"}'}
2018-02-03 02:33:24 ERROR (SyncWorker_5) [xiaomi_gateway] Non matching response. Expecting write_ack, but got read_ack
2018-02-03 02:33:24 ERROR (SyncWorker_0) [xiaomi_gateway] No data in response from hub None
2018-02-03 02:33:24 DEBUG (SyncWorker_5) [xiaomi_gateway] write_ack << None
2018-02-03 02:33:24 ERROR (SyncWorker_5) [xiaomi_gateway] No data in response from hub None
2018-02-03 02:33:24 INFO (MainThread) [homeassistant.core] Bus:Handling <Event service_executed[L]:

[PaulAnnekov]

@heff27 do it like this:

logger:
  default: error
  logs:
    xiaomi_gateway: debug
    homeassistant.components.xiaomi_aqara: debug

This will log only error logs and all xiaomi-related logs. After 2 days provide us a log file. Read here how you can get all logs as a file: https://home-assistant.io/components/logger/#service-set_level.

[heff27]

HI please attached the log file as requested, if you need anymore information please let me know

Thanks
home-assistant.log.zip

[PaulAnnekov]

I have greped your log and didn't find any problems during this period. I have checked 4 sids: 158d0001a98550, 158d0001a98401, 158d0001d86d4a and 158d0001d5c426 with the command like this: egrep "homeassistant.components.xiaomi_aqara.*158d0001d5c426" home-assistant.log.
I see that you have at least 1 PUSH per hour which means you shouldn't have any unavailabilities. Can you specify at which time did you have unavailability status and for which sids?

[heff27]

158d0001a4c991 7 158d00019e0551 were the sensors that we going into unavailable state but these have seem to have stopped ever since i rebooted after adding the Debug Config.... Sorry probably not what you was looking for..

I am still getting loads of these errors that you can see in the log

No data in response from hub None
23:20 components/binary_sensor/xiaomi_aqara.py (ERROR)
No data in response from hub None
23:20 components/light/xiaomi_aqara.py (ERROR)
Non matching response. Expecting read_ack, but got write_ack
23:20 components/binary_sensor/xiaomi_aqara.py (ERROR)
Non matching response. Expecting write_ack, but got read_ack
23:20 components/light/xiaomi_aqara.py (ERROR)

[PaulAnnekov]

If you want me to debug unavailability state, you need to provide logs, sids and time when state switch happenned.

I am still getting loads of these errors that you can see in the log

Yes, that's what is explained in this issue and will be fixed. But it's not always connected with unavailability.

[heff27]

I had an unavailability status late Friday night around 11pm i looked in the log and nothing. I looked on the MI apps and the sensor was showing unavailable also.... but yesterday I was back available again with no interaction....

[monster1025]

I have same issue with HA component, packet miss/wrong packets(write command other than recieved data)/socket timeouts. It happens often when client (raspberry pi 3 in my case) is connected over wifi network and less often when client is connected over ethernet.

[ReX1983]

So the multi gw solution is an old implementation, that I have never tested.

I can confirm that with 3 gateways each time I restart HA at least one of the gateways is not found.

Have you or PaulAnnekov started any work on the UDP refactoring? I would like to help.

[Danielhiversen]

I have not started on this.

So a pull request would be very welcome

[UmerFraz]

i get the non-matching error too. my gateway seems to have been discovered and responds to the ringtone commands. but no attached devices are discovered.

[Martinvdm]

Having the same issues. errors like:

[xiaomi_gateway] Cannot connect to Gateway
[xiaomi_gateway] No data in response from hub None

Having a about 6 door/window sensors.

With the errors everything seems to working fine, but log is filling

[Barrysv]

I have been getting the "cannot connect to Gateway" and "No data in response from hub None" since setting up the Xiaomi gear back in Dec last year. The Xiaomi gear works really well 99% of the time but have witnessed automations not turn switches on at the scheduled time only to check the HA logs to see that at the same time the above connection errors had occurred.

Hoping I could solve this by brute force, I changed my network setup so my Aqara gateway is on its own access point in close range and on its own vlan with the home assistant. Network traffic is low.
However since this network topology change I still get the cannot connect and no data in response messages in the logs and have seen switches not turn on when they were supposed to.

I wonder if the ultimate solution is to implement point 4 mentioned by Paul? Suggest that HA checks for the acknowledgment within a timeout period and if not it resends the request?

[Barrysv]

Hi Paul/Daniel is this ready to test? I can help

[PaulAnnekov]

@Barrysv yes. It's merged now.

[Barrysv]

@PaulAnnekov been testing it today - no connection errors in the log and the Xiaomi devices working as expected. Great job

[PaulAnnekov]

I think this bug was fixed. Closing the issue.

[cosinguyen]

Hi,
Sorry my code skill very bad. So what i need to do in this case. I using newest version of HassIO with docker.

Thanks.