core icon indicating copy to clipboard operation
core copied to clipboard

Roborock: Multiple error messages every night after database cleanup.

Open z-master42 opened this issue 7 months ago • 25 comments

The problem

Every night, from my point of view in connection with the daily database cleanup, i.e. after it is finished, my log starts to fill up with several errors for Roborock integration, sometimes it stops by itself after hours, but sometimes not. Reloading the integration silences the error messages.

What version of Home Assistant Core has the issue?

core-2025.3.4

What was the last working version of Home Assistant Core?

No response

What type of installation are you running?

Home Assistant OS

Integration causing the issue

Roborock

Link to integration documentation on our website

https://www.home-assistant.io/integrations/roborock

Diagnostics information

config_entry-roborock-01J21HDDPDVTNGM5V8EV8NWVAE.json

Example YAML snippet


Anything in the logs that might be useful for us?

Logger: roborock.version_1_apis.roborock_mqtt_client_v1
Quelle: /usr/local/lib/python3.13/site-packages/roborock/cloud_api.py:83
Erstmals aufgetreten: 27. März 2025 um 17:04:42 (731 Vorkommnisse)
Zuletzt protokolliert: 17:20:09

[Roborock S7] Failed to connect (Unknown error.)

Logger: roborock.version_1_apis.roborock_mqtt_client_v1
Quelle: /usr/local/lib/python3.13/site-packages/roborock/api.py:77
Erstmals aufgetreten: 27. März 2025 um 17:04:09 (733 Vorkommnisse)
Zuletzt protokolliert: 17:20:09

[Roborock S7] Client or broker did not communicate in the keepalive interval.
[Roborock S7] A network protocol error occurred when communicating with the broker.

Logger: homeassistant
Quelle: /usr/src/homeassistant/homeassistant/runner.py:112
Erstmals aufgetreten: 27. März 2025 um 17:04:42 (731 Vorkommnisse)
Zuletzt protokolliert: 17:20:09

Error doing job: Exception in callback RoborockFuture._set_exception() (None)
Traceback (most recent call last):
  File "/usr/local/lib/python3.13/asyncio/events.py", line 89, in _run
    self._context.run(self._callback, *self._args)
    ~~~~~~~~~~~~~~~~~^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.13/site-packages/roborock/roborock_future.py", line 26, in _set_exception
    self.fut.set_exception(exc)
    ~~~~~~~~~~~~~~~~~~~~~~^^^^^
asyncio.exceptions.InvalidStateError: invalid state

Additional information

Integration still appears to be working normally.

z-master42 avatar Mar 28 '25 16:03 z-master42

Hey there @lash-l, @allenporter, mind taking a look at this issue as it has been labeled with an integration (roborock) you are listed as a code owner for? Thanks!

Code owner commands

Code owners of roborock can trigger bot actions by commenting:

  • @home-assistant close Closes the issue.
  • @home-assistant rename Awesome new title Renames the issue.
  • @home-assistant reopen Reopen the issue.
  • @home-assistant unassign roborock Removes the current integration label and assignees on the issue, add the integration domain after the command.
  • @home-assistant add-label needs-more-information Add a label (needs-more-information, problem in dependency, problem in custom component) to the issue.
  • @home-assistant remove-label needs-more-information Remove a label (needs-more-information, problem in dependency, problem in custom component) on the issue.

(message by CodeOwnersMention)


roborock documentation roborock source (message by IssueLinks)

home-assistant[bot] avatar Mar 28 '25 16:03 home-assistant[bot]

Thanks for the report. Would you be able to capture this with debug logging turned on? https://www.home-assistant.io/docs/configuration/troubleshooting/#enabling-debug-logging

Thank you

allenporter avatar Mar 29 '25 05:03 allenporter

HI! I'm also getting bombarded with errors.

Logger: roborock.version_1_apis.roborock_mqtt_client_v1
Source: /usr/local/lib/python3.13/site-packages/roborock/api.py:77
First occurred: March 23, 2025 at 16:50:21 (5199 occurrences)
Last logged: 23:24:45

[Roborock S7] A network protocol error occurred when communicating with the broker.
[Roborock S7] The connection was lost.

Integration is working normally.

home-assistant_zha_2025-03-31T02-23-46.244Z.log

Oglaf avatar Mar 31 '25 02:03 Oglaf

Here is the debug log, up to 05:42 this morning. The Home Assistant log says the error first occurred at 04:04:15 ([Roborock S7] The connection was lost.) or 04:04:17 ([Roborock S7] Failed to connect (Unknown error.)).

error_log.log

z-master42 avatar Mar 31 '25 16:03 z-master42

Is that from the custom component or something? The logs have roborock camera entities which don't exist in core.

allenporter avatar Mar 31 '25 16:03 allenporter

I have integrated a Roborock S7 via the Core integration and another Roborock S5 via the Xiaomi Miio integration, as the S5 cannot be used via the Roborock Core integration as far as I know. For this I also have the Xiaomi Cloud Map Extractor from HACS running.

I made the debug log via the core integration.

z-master42 avatar Mar 31 '25 16:03 z-master42

That last log file looks like the issue where it disconnects/drops the connection at 3:04 (but it's 4:04) and it is able to reconnect after a few minutes when the device comes back online. This seems a bit different than the symptoma above where it can't reconnect.

allenporter avatar Mar 31 '25 16:03 allenporter

I think it's the same, they keep repeating until I reload the integration. I did that today around 11:04.

Logger: roborock.version_1_apis.roborock_mqtt_client_v1
Quelle: /usr/local/lib/python3.13/site-packages/roborock/cloud_api.py:83
Erstmals aufgetreten: 04:04:17 (216 Vorkommnisse)
Zuletzt protokolliert: 11:04:47

[Roborock S7] Failed to connect (Unknown error.)
Logger: roborock.version_1_apis.roborock_mqtt_client_v1
Quelle: /usr/local/lib/python3.13/site-packages/roborock/api.py:77
Erstmals aufgetreten: 04:04:15 (217 Vorkommnisse)
Zuletzt protokolliert: 11:04:47

[Roborock S7] The connection was lost.
[Roborock S7] A network protocol error occurred when communicating with the broker.

z-master42 avatar Mar 31 '25 16:03 z-master42

From https://github.com/home-assistant/core/issues/139909 seems like there may be an mqtt version compatibility issue. Investigating further...

allenporter avatar Apr 01 '25 04:04 allenporter

Ok. Is there an easy way to find out if a custom integration forces a certain paho_mqtt version? The funny thing is that it always starts to occur at the same time and can initially be fixed by reloading the integration.

z-master42 avatar Apr 01 '25 05:04 z-master42

The device goes bad at the same time each day. Normally just reconnecting fixes it.

Diagnostics should give info on custom packages

allenporter avatar Apr 01 '25 06:04 allenporter

What exactly is meant by diagnostics?

Unfortunately, most custom integrations do not allow any diagnostic data to be downloaded.

z-master42 avatar Apr 01 '25 07:04 z-master42

I don't know if this is related, but today I also have this warning and the error in the log. These also survive a reload of the integration.

Logger: roborock.version_1_apis.roborock_local_client_v1
Quelle: runner.py:154
Erstmals aufgetreten: 10:34:36 (1391 Vorkommnisse)
Zuletzt protokolliert: 18:36:10

[Roborock S7] Attempting to create a future with an existing id 2 (3)... New id is 40282. Code may not function properly.
[Roborock S7] Attempting to create a future with an existing id 2 (3)... New id is 40283. Code may not function properly.
[Roborock S7] Attempting to create a future with an existing id 2 (3)... New id is 40284. Code may not function properly.
[Roborock S7] Attempting to create a future with an existing id 2 (3)... New id is 40285. Code may not function properly.
[Roborock S7] Attempting to create a future with an existing id 2 (3)... New id is 40286. Code may not function properly.
Logger: homeassistant
Quelle: /usr/src/homeassistant/homeassistant/runner.py:112
Erstmals aufgetreten: 10:34:37 (897 Vorkommnisse)
Zuletzt protokolliert: 18:36:10

Error doing job: Exception in callback RoborockFuture._set_result() (None)
Traceback (most recent call last):
  File "/usr/local/lib/python3.13/asyncio/events.py", line 89, in _run
    self._context.run(self._callback, *self._args)
    ~~~~~~~~~~~~~~~~~^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.13/site-packages/roborock/roborock_future.py", line 19, in _set_result
    self.fut.set_result(item)
    ~~~~~~~~~~~~~~~~~~~^^^^^^
asyncio.exceptions.InvalidStateError: invalid state

z-master42 avatar Apr 02 '25 16:04 z-master42

Is that from the custom component or something? The logs have roborock camera entities which don't exist in core.

The only custom integration I have is Adaptive Lightning.

Oglaf avatar Apr 04 '25 00:04 Oglaf

I'm seeing similar errors repeating at random times, multiple times per day, often at a 1 hour distance like in the following example. I think since HA 2025.4.0. The only device the integration is handling is a Roborock Flexi.

2025-04-07 14:06:09.014 WARNING (MainThread) [roborock.version_a01_apis.roborock_mqtt_client_a01] [Roborock Flexi] Attempting to create a future with an existing id 1 (0)... New id is 20004. Code may not function properly.
2025-04-07 14:06:09.018 ERROR (MainThread) [homeassistant] Error doing job: Exception in callback RoborockFuture._set_result() (None)
Traceback (most recent call last):
  File "/usr/local/lib/python3.13/asyncio/events.py", line 89, in _run
    self._context.run(self._callback, *self._args)
    ~~~~~~~~~~~~~~~~~^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.13/site-packages/roborock/roborock_future.py", line 19, in _set_result
    self.fut.set_result(item)
    ~~~~~~~~~~~~~~~~~~~^^^^^^
asyncio.exceptions.InvalidStateError: invalid state
2025-04-07 14:06:19.017 ERROR (MainThread) [homeassistant.components.roborock.coordinator] Unexpected error fetching roborock data
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 380, in _async_refresh
    self.data = await self._async_update_data()
                ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/components/roborock/coordinator.py", line 494, in _async_update_data
    return await self.api.update_values(self.request_protocols)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.13/site-packages/roborock/version_a01_apis/roborock_mqtt_client_a01.py", line 71, in update_values
    return await self.send_message(
           ^^^^^^^^^^^^^^^^^^^^^^^^
    ...<5 lines>...
    )
    ^
  File "/usr/local/lib/python3.13/site-packages/roborock/version_a01_apis/roborock_mqtt_client_a01.py", line 43, in send_message
    await self.validate_connection()
  File "/usr/local/lib/python3.13/site-packages/roborock/api.py", line 89, in validate_connection
    await self.async_disconnect()
  File "/usr/local/lib/python3.13/site-packages/roborock/cloud_api.py", line 161, in async_disconnect
    await disconnected_future
  File "/usr/local/lib/python3.13/site-packages/roborock/api.py", line 99, in _wait_response
    raise RoborockTimeout(f"id={request_id} Timeout after {self.queue_timeout} seconds") from None
roborock.exceptions.RoborockTimeout: id=20004 Timeout after 10 seconds

...

2025-04-07 15:06:32.013 WARNING (MainThread) [roborock.version_a01_apis.roborock_mqtt_client_a01] [Roborock Flexi] Attempting to create a future with an existing id 1 (0)... New id is 20005. Code may not function properly.
2025-04-07 15:06:32.018 ERROR (MainThread) [homeassistant] Error doing job: Exception in callback RoborockFuture._set_result() (None)
Traceback (most recent call last):
  File "/usr/local/lib/python3.13/asyncio/events.py", line 89, in _run
    self._context.run(self._callback, *self._args)
    ~~~~~~~~~~~~~~~~~^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.13/site-packages/roborock/roborock_future.py", line 19, in _set_result
    self.fut.set_result(item)
    ~~~~~~~~~~~~~~~~~~~^^^^^^
asyncio.exceptions.InvalidStateError: invalid state
2025-04-07 15:06:42.017 ERROR (MainThread) [homeassistant.components.roborock.coordinator] Unexpected error fetching roborock data
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 380, in _async_refresh
    self.data = await self._async_update_data()
                ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/components/roborock/coordinator.py", line 494, in _async_update_data
    return await self.api.update_values(self.request_protocols)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.13/site-packages/roborock/version_a01_apis/roborock_mqtt_client_a01.py", line 71, in update_values
    return await self.send_message(
           ^^^^^^^^^^^^^^^^^^^^^^^^
    ...<5 lines>...
    )
    ^
  File "/usr/local/lib/python3.13/site-packages/roborock/version_a01_apis/roborock_mqtt_client_a01.py", line 43, in send_message
    await self.validate_connection()
  File "/usr/local/lib/python3.13/site-packages/roborock/api.py", line 89, in validate_connection
    await self.async_disconnect()
  File "/usr/local/lib/python3.13/site-packages/roborock/cloud_api.py", line 161, in async_disconnect
    await disconnected_future
  File "/usr/local/lib/python3.13/site-packages/roborock/api.py", line 99, in _wait_response
    raise RoborockTimeout(f"id={request_id} Timeout after {self.queue_timeout} seconds") from None
roborock.exceptions.RoborockTimeout: id=20005 Timeout after 10 seconds

MacrosorcH avatar Apr 07 '25 13:04 MacrosorcH

Thank you for the details. If anyone can capture this with debug logging enabled that could also be useful so we have a hint as to the request path being triggered.

allenporter avatar Apr 07 '25 13:04 allenporter

@allenporter Here is another occurrence of the same error, this time with debug logging enabled:

2025-04-07 17:07:11.014 INFO (MainThread) [roborock.version_a01_apis.roborock_mqtt_client_a01] [Roborock Flexi] Resetting Roborock connection due to kepalive timeout
2025-04-07 17:07:11.014 INFO (MainThread) [roborock.version_a01_apis.roborock_mqtt_client_a01] [Roborock Flexi] Disconnecting from mqtt
2025-04-07 17:07:11.014 WARNING (MainThread) [roborock.version_a01_apis.roborock_mqtt_client_a01] [Roborock Flexi] Attempting to create a future with an existing id 1 (0)... New id is 20007. Code may not function properly.
2025-04-07 17:07:11.016 INFO (paho-mqtt-client-) [roborock.version_a01_apis.roborock_mqtt_client_a01] [Roborock Flexi] Roborock client disconnected
2025-04-07 17:07:11.018 ERROR (MainThread) [homeassistant] Error doing job: Exception in callback RoborockFuture._set_result() (None)
Traceback (most recent call last):
  File "/usr/local/lib/python3.13/asyncio/events.py", line 89, in _run
    self._context.run(self._callback, *self._args)
    ~~~~~~~~~~~~~~~~~^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.13/site-packages/roborock/roborock_future.py", line 19, in _set_result
    self.fut.set_result(item)
    ~~~~~~~~~~~~~~~~~~~^^^^^^
asyncio.exceptions.InvalidStateError: invalid state
2025-04-07 17:07:21.018 ERROR (MainThread) [homeassistant.components.roborock.coordinator] Unexpected error fetching roborock data
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 380, in _async_refresh
    self.data = await self._async_update_data()
                ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/components/roborock/coordinator.py", line 494, in _async_update_data
    return await self.api.update_values(self.request_protocols)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.13/site-packages/roborock/version_a01_apis/roborock_mqtt_client_a01.py", line 71, in update_values
    return await self.send_message(
           ^^^^^^^^^^^^^^^^^^^^^^^^
    ...<5 lines>...
    )
    ^
  File "/usr/local/lib/python3.13/site-packages/roborock/version_a01_apis/roborock_mqtt_client_a01.py", line 43, in send_message
    await self.validate_connection()
  File "/usr/local/lib/python3.13/site-packages/roborock/api.py", line 89, in validate_connection
    await self.async_disconnect()
  File "/usr/local/lib/python3.13/site-packages/roborock/cloud_api.py", line 161, in async_disconnect
    await disconnected_future
  File "/usr/local/lib/python3.13/site-packages/roborock/api.py", line 99, in _wait_response
    raise RoborockTimeout(f"id={request_id} Timeout after {self.queue_timeout} seconds") from None
roborock.exceptions.RoborockTimeout: id=20007 Timeout after 10 seconds
2025-04-07 17:07:21.025 DEBUG (MainThread) [homeassistant.components.roborock.coordinator] Finished fetching roborock data in 10.012 seconds (success: False)

MacrosorcH avatar Apr 07 '25 15:04 MacrosorcH

Hmm, maybe we are at least getting closer to the cause of my problem. The last time these error messages came up now

2025-04-11 04:10:37.622 WARNING (paho-mqtt-client-) [roborock.version_1_apis.roborock_mqtt_client_v1] [Roborock S7] The connection was lost.
2025-04-11 04:10:38.703 ERROR (paho-mqtt-client-) [roborock.version_1_apis.roborock_mqtt_client_v1] [Roborock S7] Failed to connect (Unknown error.)
2025-04-11 04:10:38.705 WARNING (paho-mqtt-client-) [roborock.version_1_apis.roborock_mqtt_client_v1] [Roborock S7] A network protocol error occurred when communicating with the broker.

was around the time when my FritzBox router performed its next forced disconnection. This always takes place at 04:10. However, the Roborock integration only manages to re-establish a clean connection after a reload. I had the same problem today when I had to restart my router unplanned and the same errors appeared in the log.

z-master42 avatar Apr 11 '25 15:04 z-master42

Could this be related? https://github.com/home-assistant/core/issues/98013

tzagim avatar Apr 24 '25 14:04 tzagim

Yes

allenporter avatar Apr 24 '25 14:04 allenporter

Rather, people may be discussing two issues here.

allenporter avatar Apr 24 '25 14:04 allenporter

My interim solution is to reload the configuration entry as soon as the error appears in the log.

alias: Reload Roborock integration
description: ""
triggers:
  - event_type: system_log_event
    event_data:
      level: ERROR
    trigger: event
conditions:
  - condition: template
    value_template: "{{ \"Roborock S7\" in trigger.event.data.message[0] }}"
actions:
  - action: homeassistant.reload_config_entry
    data:
      entry_id: 01J21HDDPDVTNGM5V8EV8NWVAE
    target:
      device_id: 1bb57c9c670f8857d42391425952c5bd
mode: single

But other than in the referenced issue, the integration can still be used with the errors.

z-master42 avatar Apr 24 '25 15:04 z-master42

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 has now been marked as stale and will be closed if no further activity occurs. Thank you for your contributions.

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 has now been marked as stale and will be closed if no further activity occurs. Thank you for your contributions.

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 has now been marked as stale and will be closed if no further activity occurs. Thank you for your contributions.

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 has now been marked as stale and will be closed if no further activity occurs. Thank you for your contributions.

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 has now been marked as stale and will be closed if no further activity occurs. Thank you for your contributions.