Core: Xiaomi vacuum: errors in log but device working properly

[andriej]

Home Assistant release with the issue: 0.89.1
Last working Home Assistant release (if known): n/a
Operating environment (Hass.io/Docker/Windows/etc.): Debian / venv
Component/platform: vacuum/vacuum.xiaomi_miio

Description of problem: In log there are errors showing up every 15 minutes. Device is despite that working 101% perfect, no connectivity issues (vacuum is less than one meter away from AP) and no unavailability in HA

Problem-relevant configuration.yaml entries and (fill out even if it seems unimortant):

vacuum:
  - platform: xiaomi_miio
    host: !secret xiaomi_vacuum_host [ip]
    token: !secret xiaomi_vacuum_token [token]
    name: 'Mi Robot'

Traceback (if applicable):

Update of vacuum.mi_robot is taking over 10 seconds
Unable to discover a device at address 192.168.x.x
Got exception while fetching the state: Unable to discover the device 192.168.x.x

Additional information: no internet is blocked, vacuum is seen properly in HA and app

[rytilahti]

Unfortunately it is hard to debug this (especially on non-rooted devices); that warning just means that it hasn't been able to do a handshake with the device, which usually happens when the internet is blocked or the token is wrong, both of which do not apply in your case.

[andriej]

What's rather funny is that I didn't see that error when vacuum was more meters away from AP.
I had to move AP to solve problems with Xiaomi gateways and while it got solved, the issue showed up with vacuum. I didn't see it earlier, but don't think better signal strength may be the reason..

[dshokouhi]

I have been seeing the same exact error for my air purifiers. Sometimes it means they went unplugged but other times they just give the error periodically. They usually stay unavailable for a few seconds when this happens. They still work as expected in my case too.

2019-03-10 18:40:34 WARNING (MainThread) [homeassistant.helpers.entity] Update of fan.living_room_air_purifier is taking over 10 seconds
2019-03-10 18:40:34 ERROR (SyncWorker_19) [miio.device] Unable to discover a device at address 192.168.1.x
2019-03-10 18:40:34 ERROR (MainThread) [homeassistant.components.xiaomi_miio.fan] Got exception while fetching the state: Unable to discover the device 192.168.1.x

[andriej]

Mine vacuum doesn't even go unavailable or something. Just works and it's history is all ok

[towerhand]

I get the same on my roborock S5 and the air purifier as stated by @dshokouhi, I have been thinking to submit an issue but kept forgetting about it.

[mawi13]

Same here

[andriej]

Issue is still seen, on regular basis.

[andriej]

Just informational: still present in 0.92 (current latest)

[ajfriesen]

I will have this log entries in home assistant since ever:

Got exception while fetching the state: Unable to discover the device 192.168.178.54
3:09 components/xiaomi_miio/vacuum.py (WARNING) - message first occured at 1. Juli 2019, 3:09 and shows up 7 times

Unable to discover a device at address 192.168.178.54
3:09 components/xiaomi_miio/vacuum.py (ERROR) - message first occured at 1. Juli 2019, 3:09 and shows up 7 times

Update of vacuum.frodolin is taking over 10 seconds
3:09 __main__.py (WARNING) - message first occured at 1. Juli 2019, 3:09 and shows up 3 times

Mostly I do not have a problem, but I have the feeling due to this behavior my automation is not working properly:

automation:
  - alias: 'Start vacuum once a day when nobody is home'
    initial_state: true
    trigger:
      - platform: state
        entity_id: sensor.someone_is_home
        from: 'yes'
        to: 'no'
        for:
          minutes: 5
    condition:
        # At least one of the following is required.
      - condition: state
        entity_id: counter.vacuum_today
        state: '0'
      - condition: time
        after: '09:00:00'
        before: '21:00:00'
    action:
      - service: vacuum.start
        data:
          entity_id: vacuum.frodolin
      - service: notify.chrome_push
        data:
          title: "Frödolin"
          message: "Ich fang an zu saugen!"

You can see everything regarding the vacuum setup on my home assistant instance here:
https://github.com/ajfriesen/home_assistant_configuration/blob/master/packages/components/includes/apps/vacuum.yaml

[postlund]

I see this issue regularly as well.

[andriej]

I confirm, issue is still valid in latest version.

[charlietomo]

Confirming I still get this issue on 97.2
Vacuum works but log is messy (better than the other way round I guess!).

[timdonovanuk]

Still an issue in 0.99.0.dev20190908.

Was so close to getting my logs silent and then added this platform!

Vacuum controls and service calls work though..

[timdonovanuk]

If you want to quieten the logs, I think change line 404 in homeassistant/components/xiaomi_miio/vacuum.py from

_LOGGER.warning("Got exception while fetching the state: %s", exc)

to

_LOGGER.debug("Got exception while fetching the state: %s", exc)

although I don't think that will solve these logs:

2019-09-08 09:50:20 WARNING (MainThread) [homeassistant.helpers.entity] Update of vacuum.vacuum_bot is taking over 10 seconds
2019-09-08 09:50:30 ERROR (SyncWorker_14) [miio.device] Got error when receiving: timed out

[andriej]

Still present in 0.99.2 (not a surprise, as no commits regarding this platform). Maybe it would be possible to silent it with some switch or change log level to notice?

[stale[bot]]

There hasn't been any activity on this issue recently. Due to the high number of incoming GitHub notifications, we have to clean some of the old issues, as many of them have already been resolved with the latest updates.
Please make sure to update to the latest Home Assistant version and check if that solves the issue. Let us know if that works for you by adding a comment 👍
This issue now has been marked as stale and will be closed if no further activity occurs. Thank you for your contributions.

[djansen1987]

Hi I am on the latest version, being 0.105.3 while writing.

Still Have this issue. Also my Xiaomi Gateway Alarm (custom module) is not working for a couple of versions

EDIT: Gateway is working again. Vacuum is still not.

Error in log:

Feb 13 01:50:31 homeassistant hass[2760]: 2020-02-13 01:50:31 ERROR (SyncWorker_16) [miio.device] Got error when receiving: timed out
Feb 13 01:50:31 homeassistant hass[2760]: 2020-02-13 01:50:31 WARNING (SyncWorker_16) [homeassistant.components.xiaomi_miio.vacuum] Got exception while fetching the state: No response from the device
Feb 13 01:50:42 homeassistant hass[2760]: 2020-02-13 01:50:42 WARNING (MainThread) [homeassistant.helpers.entity] Update of vacuum.stofzuiger is taking over 10 seconds
Feb 13 01:50:53 homeassistant hass[2760]: 2020-02-13 01:50:53 WARNING (MainThread) [homeassistant.components.vacuum] Updating xiaomi_miio vacuum took longer than the scheduled update interval 0:00:20
Feb 13 01:50:53 homeassistant hass[2760]: 2020-02-13 01:50:53 ERROR (SyncWorker_13) [miio.device] Got error when receiving: timed out
Feb 13 01:50:53 homeassistant hass[2760]: 2020-02-13 01:50:53 WARNING (SyncWorker_13) [homeassistant.components.xiaomi_miio.vacuum] Got exception while fetching the state: No response from the device
Feb 13 01:50:31 homeassistant hass[2760]: 2020-02-13 01:50:31 ERROR (SyncWorker_16) [miio.device] Got error when receiving: timed out
Feb 13 01:50:31 homeassistant hass[2760]: 2020-02-13 01:50:31 WARNING (SyncWorker_16) [homeassistant.components.xiaomi_miio.vacuum] Got exception while fetching the state: No response from the device

[ipatalas]

I have just updated 0.103 to 0.105.3 and still the same.
It's like 70-80% of my warnings/errors :(

[me1299]

The same behavior takes place with my Air Purifier 2S. It's clogging up my log files as well.

[rytilahti]

I'm all open for a reasonable solution for this. Maybe the errors/warnings should be first shown after a couple of retries? So if someone wants to do a PR for the upstream lib, I'll be happy to help.

[StWiesi]

I'm having the same issue with my Roborock S5 Max.
At around 3.40 every night, the first error appears and the device is basically not being usable within HA after that. Sometimes it fixes itself, sometimes not. The Mi Home app is working properly all the time.

First occured: 3:48:25 AM (1224 occurences) 
Last logged: 11:06:06 AM

Got exception while fetching the state: Unable to discover the device 192.168.178.61

edit - forgot to mention I am on version 0.106.5 and the vacuum is not restricted access to the internet.

[johntdyer]

yea, same problem here ...

[rytilahti]

@StWiesi if it happens every time approximately at the same time, it may have something to do with the watchdog of the device. Maybe the device thinks it has stalled (are you dropping outgoing network connections? are you blocking dns requests?) which causes the device to reboot itself.

If anyone having the problem want to give it a try, https://github.com/rytilahti/python-miio/pull/686 changes the handshake behavior to send several requests instead of just a single one, which can improve the situation if datagrams are getting lost / the device is not responsive for some other reason.

[StWiesi]

Hey @rytilahti,

thanks for your input!

I am not blocking any outgoing connections or dns requests.

I actually would like to try this, but it seems I don't have a miioprotocol.py file, but only a protocol.py - this looks totally different though :(

[rytilahti]

That got changed in python-miio 0.5+ to accommodate support for new devices (which will ship with the 0.109). If you want to try it out now, the old location for the handshake is here in device.py: https://github.com/rytilahti/python-miio/blob/0.4.8/miio/device.py#L199

Anyway, not receiving responses for the discovery indicates some problem with the device, or network. That PR tries to send multiple discovery requests in hopes that one of them gets through and gets answered, so it may or may not help.

[StWiesi]

Thanks - I adjusted it - will report back how the impact was.

Network connectivity shouldn't actually be an issue. The vacuum's charging station is barely 5 meters away from my Fritzbox.

[rytilahti]

Any news on this? I'm preparing a new release, and if that is helpful I'll merge it also in.

[StWiesi]

Didn't work. I unfortunately still get the same error message. Maybe it really is network related after all, but nothing else has any problems ...

[rytilahti]

If you are comfortable with network analysis, you could use wireshark or tcpdump to record a PCAP to verify if the packets are flowing as expected. Anyway, for a reason or another it is not receiving a response for the initial handshake, but as the device itself is a blackbox it's hard to figure out what's the exact cause...

[andriej]

0.109.1 - problem still persists

[cho0p]

I doubt that it is related to the AP/network connectivity. I am also facing this issue and it appears once per day in my log - always at night at around 3 am (+/- 2 hours). The robot stands next to a UniFi access point (4 meters without a wall in between).

@rytilahti - I have modified my miioprotocol.py now following the changes stated here https://github.com/rytilahti/python-miio/pull/686/files

[rytilahti]

Okay, then it sounds like the system gets locked up (or it think it does), and the watchdog reboots it. It is probably firmware/device specific, I have only personally encountered the problems when the firewall drops the cloud-going packets (instead of blocking them with REJECT, https://python-miio.readthedocs.io/en/latest/troubleshooting.html#intermittent-connection-issues-timeouts-xiaomi-vacuum).

[cho0p]

It's still the same. I got the same errors again this night:

Logger: miio.miioprotocol
Source: components/xiaomi_miio/vacuum.py:456
Last logged: 03:44:33
Unable to discover a device at address 192.168.1.40

Logger: homeassistant.components.xiaomi_miio.vacuum
Source: components/xiaomi_miio/vacuum.py:471
Last logged: 03:44:33
Got exception while fetching the state: Unable to discover the device 192.168.1.40

It would be great if somebody could solve that as it is really spamming the log.

[artkrz]

I doubt that it is related to the AP/network connectivity. I am also facing this issue and it appears once per day in my log - always at night at around 3 am (+/- 2 hours). The robot stands next to a UniFi access point (4 meters without a wall in between).

@rytilahti - I have modified my miioprotocol.py now following the changes stated here https://github.com/rytilahti/python-miio/pull/686/files

Is your ha running on pi via wlan and you have wifi ai enabled in unifi controller?

[StWiesi]

My Pi is running via LAN, WLAN is completely disabled.

[andriej]

On my side I can also confirm using only LAN connection and UniFi without any experimental/roaming. moved to unifi month ago, previously it was openwrt AP and same issues with vacuum.

[fufar]

same issue
i think that solution shoul look like this ( like icinga or other monitoring)

  - platform: xiaomi_miio
    host: xxx:xxx:xxx:xxx
    token: xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
    name: something
    max_check_attempts: 3
    retry_interval: 1m

if message appears, it doesnt go to log untill the some number of checks from max_check_attempts was done, and between check was time from retry_interval

[Draluak]

Same Issue for me for years now. I tried to silence or at least reduce the spam by setting the log level for homeassistant.components.xiaomi_miio and miio.miioprotocol to critical, but that seemed to have no effect at all for me.
In addition to that, this seems not only to be related to vacuum cleaner. I am using the custom component for a Xiaomi Mi Smart Standing Fan (xiaomi_miio_fan), which produces similar errors/warnings in the Logfile, while the fan itself works and can be controlled from HA without any problems.

[rytilahti]

The changelog of the newest homeassistant release seems to indicate that some issue related to loggers has been fixed, maybe that is helpful in this case?

[Draluak]

The changelog of the newest homeassistant release seems to indicate that some issue related to loggers has been fixed, maybe that is helpful in this case?

I hoped so, but unfortunatelly not for me, i'm already on 0.111 and still getting all those messages in my log.

[cho0p]

The changelog of the newest homeassistant release seems to indicate that some issue related to loggers has been fixed, maybe that is helpful in this case?

There are fixes for the logger but this is not the system log. In my case I'm trying to get rid of the spam in the system log (Developer Tools -> Logs).

[d3m3trius]

I have this issue with an error every 21 seconds when the vacuum wifi is unreachable.
It flood the logs that grow-up to a huge size.

2020-07-05 20:21:47 ERROR (SyncWorker_4) [miio.miioprotocol] Unable to discover a device at address 192.168.1.7
2020-07-05 20:21:47 WARNING (SyncWorker_4) [homeassistant.components.xiaomi_miio.vacuum] Got exception while fetching the state: Unable to discover the device 192.168.x.x

[cichytom]

I have HA version 0.111.6 and Xiaomi MiJia Mi Robot Vacuum Cleaner. Also for a long time I have error messages "Unable to discover a device at address ...".
Logger: miio.miioprotocol
Source: components / xiaomi_miio / vacuum.py: 464

[rytilahti]

So I just stumbled upon this issue again and wondered if the situation could be improved. I created a PR that converts the
error into a debug message and does some retries before raising an exception: https://github.com/rytilahti/python-miio/pull/754

Feel free to test and report back if it's helpful or not.

[cho0p]

Hi rytilahti,

thank you for your help. I'd like to test it but I am unsure how to properly do that. I read in another thread that you shouldn't change the original code but create a file in the customer_component folder instead. I have created a folder named "xiaomi_miio" and copied the modified "miioprotocol.py" into it. Am I heading in the right direction?

Thanks

[rytilahti]

That's wrong direction actually, as that PR modifies the backend library. You need to locate the existing miioprotocol.py and replace it with the one in the PR to test.

[cho0p]

I have modified the file in the docker container. It's a Warning instead of an Error message now. That works but it still pops up every night at around 3 am. I guess the daily update/reboot(?) routine needs more time than the newly added 3 retries. Could you add a timer/delay of x seconds to the retry routine in the code?

[rytilahti]

I just created a PR to adjust the behavior when update fails. When that gets merged, the entity will be correctly marked as unavailable when an error happens, and the error/warning will get only logged if the device was earlier available (e.g., if it's rebooting, or temporarily unavailable otherwise for a longer time period, like in the case @d3m3trius described).

I hope that this change will also help with the issue you described, @cho0p. Adding a more complicated backoff inside the python-miio is something I want to avoid. To be consistent, my personal opinion is that if such backoff for updates is wanted, that should be done in the homeassistant core (which I don't see happening any time soon).

tl;dr: the upstream PR (when it gets released and included to homeassistant) will fix the unwanted logging of intermittent connection issues, the linked homeassistant PR will fix the issue of flooding the logs when the vacuum is offline for a longer period of time.

[stale[bot]]

There hasn't been any activity on this issue recently. Due to the high number of incoming GitHub notifications, we have to clean some of the old issues, as many of them have already been resolved with the latest updates.
Please make sure to update to the latest Home Assistant version and check if that solves the issue. Let us know if that works for you by adding a comment 👍
This issue now has been marked as stale and will be closed if no further activity occurs. Thank you for your contributions.

[d3m3trius]

no update with PR?

[rytilahti]

There is a PR just above that stops the log spam, but the tests are failing and I'm not sure how to fix that.