core icon indicating copy to clipboard operation
core copied to clipboard
Published 4 days ago • verified publisher icon home-assistant

Roborock throws error while setting up

Open luca-angemi opened this issue 2 years ago • 7 comments

The problem

Add the roborock integration (S5E in my case). Logs are filled with these

2023-06-04 22:18:55.057 ERROR (MainThread) [homeassistant.components.switch] roborock: Error on device update!
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/entity_platform.py", line 537, in _async_add_entity
    await entity.async_device_update(warning=False)
  File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 784, in async_device_update
    await self.async_update()
  File "/usr/src/homeassistant/homeassistant/components/roborock/switch.py", line 117, in async_update
    self._attr_is_on = self.entity_description.evaluate_value(
                       ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/components/roborock/switch.py", line 48, in <lambda>
    evaluate_value=lambda data: data["lock_status"] == 1,
                                ~~~~^^^^^^^^^^^^^^^
TypeError: string indices must be integers, not 'str'
2023-06-04 22:18:55.103 ERROR (MainThread) [homeassistant.components.switch] roborock: Error on device update!
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/entity_platform.py", line 537, in _async_add_entity
    await entity.async_device_update(warning=False)
  File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 784, in async_device_update
    await self.async_update()
  File "/usr/src/homeassistant/homeassistant/components/roborock/switch.py", line 117, in async_update
    self._attr_is_on = self.entity_description.evaluate_value(
                       ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/components/roborock/switch.py", line 59, in <lambda>
    evaluate_value=lambda data: data["status"] == 1,
                                ~~~~^^^^^^^^^^
TypeError: string indices must be integers, not 'str'

What version of Home Assistant Core has the issue?

core-2023.6.0b4

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://rc.home-assistant.io/integrations/roborock

Diagnostics information

No response

Example YAML snippet

No response

Anything in the logs that might be useful for us?

No response

Additional information

No response

luca-angemi avatar Jun 04 '23 20:06 luca-angemi

Hey there @humbertogontijo, @lash-l, 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.

(message by CodeOwnersMention)

roborock documentation roborock source (message by IssueLinks)

home-assistant[bot] avatar Jun 04 '23 20:06 home-assistant[bot]

Looks like data is a string and not a dict

balloob avatar Jun 04 '23 20:06 balloob

Ah seems like your device must return these statuses differently

Can you 1) enable debug logging 2) go to developer tools -> services -> vacuum: send command then for the command enter get_child_lock_status

Then look in the logs for the response

Also do you have child lock/ led indicator light as an option in your app? I know it will return "unknown_method" if you don't have it

Lash-L avatar Jun 04 '23 21:06 Lash-L

Thank you! This is the response:

2023-06-05 08:46:14.475 DEBUG (MainThread) [roborock.local_api] id=21230 Requesting method get_child_lock_status with None
2023-06-05 08:46:14.488 DEBUG (MainThread) [roborock.local_api] Requesting device with [RoborockMessage(protocol=4, payload=b'{"dps":{"101":"{\\"id\\":21230,\\"method\\":\\"get_child_lock_status\\",\\"params\\":[]}"},"t":1685947574}', seq=167782, version=b'1.0', random=58969, timestamp=1685947574)]
2023-06-05 08:46:14.498 DEBUG (MainThread) [roborock.local_api] id=21230 Response from get_child_lock_status: unknown_method
2023-06-05 08:46:23.192 DEBUG (MainThread) [roborock.local_api] id=30057 Requesting method RoborockCommand.GET_STATUS with None
2023-06-05 08:46:23.197 DEBUG (MainThread) [roborock.local_api] Requesting device with [RoborockMessage(protocol=4, payload=b'{"dps":{"101":"{\\"id\\":30057,\\"method\\":\\"get_status\\",\\"params\\":[]}"},"t":1685947583}', seq=167782, version=b'1.0', random=58969, timestamp=1685947583)]
2023-06-05 08:46:23.200 DEBUG (MainThread) [roborock.local_api] id=74815 Requesting method RoborockCommand.GET_DND_TIMER with None
2023-06-05 08:46:23.209 DEBUG (MainThread) [roborock.local_api] Requesting device with [RoborockMessage(protocol=4, payload=b'{"dps":{"101":"{\\"id\\":74815,\\"method\\":\\"get_dnd_timer\\",\\"params\\":[]}"},"t":1685947583}', seq=167782, version=b'1.0', random=58969, timestamp=1685947583)]
2023-06-05 08:46:23.210 DEBUG (MainThread) [roborock.local_api] id=71486 Requesting method RoborockCommand.GET_CLEAN_SUMMARY with None
2023-06-05 08:46:23.216 DEBUG (MainThread) [roborock.local_api] Requesting device with [RoborockMessage(protocol=4, payload=b'{"dps":{"101":"{\\"id\\":71486,\\"method\\":\\"get_clean_summary\\",\\"params\\":[]}"},"t":1685947583}', seq=167782, version=b'1.0', random=58969, timestamp=1685947583)]
2023-06-05 08:46:23.218 DEBUG (MainThread) [roborock.local_api] id=14600 Requesting method RoborockCommand.GET_CONSUMABLE with None
2023-06-05 08:46:23.223 DEBUG (MainThread) [roborock.local_api] Requesting device with [RoborockMessage(protocol=4, payload=b'{"dps":{"101":"{\\"id\\":14600,\\"method\\":\\"get_consumable\\",\\"params\\":[]}"},"t":1685947583}', seq=167782, version=b'1.0', random=58969, timestamp=1685947583)]
2023-06-05 08:46:23.238 DEBUG (MainThread) [roborock.local_api] id=30057 Response from get_status: {'msg_ver': 2, 'msg_seq': 644, 'state': 8, 'battery': 100, 'clean_time': 3, 'clean_area': 0, 'error_code': 0, 'map_present': 1, 'in_cleaning': 0, 'in_returning': 0, 'in_fresh_state': 1, 'lab_status': 3, 'water_box_status': 0, 'fan_power': 104, 'dnd_enabled': 0, 'map_status': 7, 'is_locating': 0, 'lock_status': 0, 'water_box_mode': 203, 'distance_off': 0, 'water_box_carriage_status': 0, 'mop_forbidden_enable': 0, 'unsave_map_reason': 4, 'unsave_map_flag': 1}
2023-06-05 08:46:23.289 DEBUG (MainThread) [roborock.local_api] id=74815 Response from get_dnd_timer: {'start_hour': 22, 'start_minute': 0, 'end_hour': 8, 'end_minute': 0, 'enabled': 1}
2023-06-05 08:46:23.290 DEBUG (MainThread) [roborock.local_api] id=71486 Response from get_clean_summary: [714571, 10806397500, 566, [1685909099, 1685908149, 1685907961, 1685905743, 1685543579, 1685431834, 1685350650, 1685348549, 1685186572, 1684996470, 1684913667, 1684662593, 1684662177, 1684501863, 1684501825, 1684501763, 1684501672, 1684501583, 1684501466, 1684500922]]
2023-06-05 08:46:23.290 DEBUG (MainThread) [roborock.local_api] id=14600 Response from get_consumable: {'main_brush_work_time': 714604, 'side_brush_work_time': 714604, 'filter_work_time': 167330, 'filter_element_work_time': 3713, 'sensor_dirty_time': 35970}
2023-06-05 08:46:23.294 DEBUG (MainThread) [roborock.local_api] id=79656 Requesting method RoborockCommand.GET_CLEAN_RECORD with [1685909099]
2023-06-05 08:46:23.298 DEBUG (MainThread) [roborock.local_api] Requesting device with [RoborockMessage(protocol=4, payload=b'{"dps":{"101":"{\\"id\\":79656,\\"method\\":\\"get_clean_record\\",\\"params\\":[1685909099]}"},"t":1685947583}', seq=167782, version=b'1.0', random=58969, timestamp=1685947583)]
2023-06-05 08:46:23.362 DEBUG (MainThread) [roborock.local_api] id=79656 Response from get_clean_record: [1685909099, 1685909102, 3, 0, 0, 0, 2, 3, 60]
2023-06-05 08:46:23.365 DEBUG (MainThread) [homeassistant.components.roborock.coordinator] Finished fetching roborock data in 0.173 seconds (success: True)
2023-06-05 08:46:53.193 DEBUG (MainThread) [roborock.local_api] id=39460 Requesting method RoborockCommand.GET_STATUS with None
2023-06-05 08:46:53.200 DEBUG (MainThread) [roborock.local_api] Requesting device with [RoborockMessage(protocol=4, payload=b'{"dps":{"101":"{\\"id\\":39460,\\"method\\":\\"get_status\\",\\"params\\":[]}"},"t":1685947613}', seq=167782, version=b'1.0', random=58969, timestamp=1685947613)]
2023-06-05 08:46:53.202 DEBUG (MainThread) [roborock.local_api] id=74654 Requesting method RoborockCommand.GET_DND_TIMER with None
2023-06-05 08:46:53.206 DEBUG (MainThread) [roborock.local_api] Requesting device with [RoborockMessage(protocol=4, payload=b'{"dps":{"101":"{\\"id\\":74654,\\"method\\":\\"get_dnd_timer\\",\\"params\\":[]}"},"t":1685947613}', seq=167782, version=b'1.0', random=58969, timestamp=1685947613)]
2023-06-05 08:46:53.208 DEBUG (MainThread) [roborock.local_api] id=84848 Requesting method RoborockCommand.GET_CLEAN_SUMMARY with None
2023-06-05 08:46:53.213 DEBUG (MainThread) [roborock.local_api] Requesting device with [RoborockMessage(protocol=4, payload=b'{"dps":{"101":"{\\"id\\":84848,\\"method\\":\\"get_clean_summary\\",\\"params\\":[]}"},"t":1685947613}', seq=167782, version=b'1.0', random=58969, timestamp=1685947613)]
2023-06-05 08:46:53.214 DEBUG (MainThread) [roborock.local_api] id=46382 Requesting method RoborockCommand.GET_CONSUMABLE with None
2023-06-05 08:46:53.217 DEBUG (MainThread) [roborock.local_api] Requesting device with [RoborockMessage(protocol=4, payload=b'{"dps":{"101":"{\\"id\\":46382,\\"method\\":\\"get_consumable\\",\\"params\\":[]}"},"t":1685947613}', seq=167782, version=b'1.0', random=58969, timestamp=1685947613)]
2023-06-05 08:46:53.236 DEBUG (MainThread) [roborock.local_api] id=39460 Response from get_status: {'msg_ver': 2, 'msg_seq': 645, 'state': 8, 'battery': 100, 'clean_time': 3, 'clean_area': 0, 'error_code': 0, 'map_present': 1, 'in_cleaning': 0, 'in_returning': 0, 'in_fresh_state': 1, 'lab_status': 3, 'water_box_status': 0, 'fan_power': 104, 'dnd_enabled': 0, 'map_status': 7, 'is_locating': 0, 'lock_status': 0, 'water_box_mode': 203, 'distance_off': 0, 'water_box_carriage_status': 0, 'mop_forbidden_enable': 0, 'unsave_map_reason': 4, 'unsave_map_flag': 1}
2023-06-05 08:46:53.236 DEBUG (MainThread) [roborock.local_api] id=74654 Response from get_dnd_timer: {'start_hour': 22, 'start_minute': 0, 'end_hour': 8, 'end_minute': 0, 'enabled': 1}
2023-06-05 08:46:53.273 DEBUG (MainThread) [roborock.local_api] id=84848 Response from get_clean_summary: [714571, 10806397500, 566, [1685909099, 1685908149, 1685907961, 1685905743, 1685543579, 1685431834, 1685350650, 1685348549, 1685186572, 1684996470, 1684913667, 1684662593, 1684662177, 1684501863, 1684501825, 1684501763, 1684501672, 1684501583, 1684501466, 1684500922]]
2023-06-05 08:46:53.273 DEBUG (MainThread) [roborock.local_api] id=46382 Response from get_consumable: {'main_brush_work_time': 714604, 'side_brush_work_time': 714604, 'filter_work_time': 167330, 'filter_element_work_time': 3713, 'sensor_dirty_time': 35970}
2023-06-05 08:46:53.275 DEBUG (MainThread) [roborock.local_api] id=19774 Requesting method RoborockCommand.GET_CLEAN_RECORD with [1685909099]
2023-06-05 08:46:53.281 DEBUG (MainThread) [roborock.local_api] Requesting device with [RoborockMessage(protocol=4, payload=b'{"dps":{"101":"{\\"id\\":19774,\\"method\\":\\"get_clean_record\\",\\"params\\":[1685909099]}"},"t":1685947613}', seq=167782, version=b'1.0', random=58969, timestamp=1685947613)]
2023-06-05 08:46:53.339 DEBUG (MainThread) [roborock.local_api] id=19774 Response from get_clean_record: [1685909099, 1685909102, 3, 0, 0, 0, 2, 3, 60]
2023-06-05 08:46:53.340 DEBUG (MainThread) [homeassistant.components.roborock.coordinator] Finished fetching roborock data in 0.148 seconds (success: True)

Also I noticed that during the night the log was filled with these errors (probably unrelated to this issue):

2023-06-05 05:06:36.231 ERROR (MainThread) [roborock.api] Timeout after 4 seconds waiting for response
2023-06-05 05:06:36.242 ERROR (MainThread) [roborock.api] Timeout after 4 seconds waiting for response
2023-06-05 05:07:10.230 ERROR (MainThread) [roborock.api] Timeout after 4 seconds waiting for response
2023-06-05 05:07:10.236 ERROR (MainThread) [roborock.api] Timeout after 4 seconds waiting for response
2023-06-05 05:07:10.241 ERROR (MainThread) [roborock.api] Timeout after 4 seconds waiting for response
2023-06-05 05:07:44.222 ERROR (MainThread) [roborock.api] Timeout after 4 seconds waiting for response
2023-06-05 05:07:44.227 ERROR (MainThread) [roborock.api] Timeout after 4 seconds waiting for response
2023-06-05 05:07:44.232 ERROR (MainThread) [roborock.api] Timeout after 4 seconds waiting for response
2023-06-05 05:09:48.211 ERROR (MainThread) [roborock.api] Timeout after 4 seconds waiting for response
2023-06-05 05:09:48.216 ERROR (MainThread) [roborock.api] Timeout after 4 seconds waiting for response

luca-angemi avatar Jun 05 '23 06:06 luca-angemi

Fixed in #94069 - now if the function is not supported, the entity wont be added.

As far as the disconnects go, that should also improve with the version bump PR that got merged in yesterday.

Lash-L avatar Jun 05 '23 13:06 Lash-L

I've other errors that came up in the logs. Let me please know if I have to open an other issue.

2023-06-05 18:27:54.131 ERROR (MainThread) [homeassistant] Error doing job: Exception in callback Future.set_result(([717648, 10858022500, 570, [1685975265, 1685973118, 1685958641, 1685958550, 1685909099, 1685908149, ...]], None))
Traceback (most recent call last):
  File "/usr/local/lib/python3.11/asyncio/events.py", line 80, in _run
    self._context.run(self._callback, *self._args)
asyncio.exceptions.InvalidStateError: invalid state
2023-06-05 18:27:58.117 ERROR (MainThread) [homeassistant.components.roborock.coordinator] Unexpected error fetching roborock data: 65241
Traceback (most recent call last):
  File "/usr/local/lib/python3.11/site-packages/roborock/api.py", line 192, in _async_response
    raise RoborockTimeout(f"Timeout after {QUEUE_TIMEOUT} seconds waiting for response") from None
roborock.exceptions.RoborockTimeout: Timeout after 4 seconds waiting for response
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 283, in _async_refresh
    self.data = await self._async_update_data()
                ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/components/roborock/coordinator.py", line 68, in _async_update_data
    await self._update_device_prop()
  File "/usr/src/homeassistant/homeassistant/components/roborock/coordinator.py", line 58, in _update_device_prop
    device_prop = await self.api.get_prop()
                  ^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/roborock/api.py", line 338, in get_prop
    [status, dnd_timer, clean_summary, consumable] = await asyncio.gather(
                                                     ^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/roborock/api.py", line 229, in get_status
    status = await self.send_command(RoborockCommand.GET_STATUS)
             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/roborock/local_api.py", line 93, in send_command
    return (await self.send_message(roborock_message))[0]
            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/roborock/local_api.py", line 137, in send_message
    raise exception
  File "/usr/local/lib/python3.11/site-packages/roborock/local_api.py", line 106, in async_local_response
    (response, err) = await self._async_response(request_id, response_protocol)
                      ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/roborock/api.py", line 194, in _async_response
    del self._waiting_queue[request_id]
        ~~~~~~~~~~~~~~~~~~~^^^^^^^^^^^^
KeyError: 65241

luca-angemi avatar Jun 05 '23 16:06 luca-angemi

I'd hold off on making a new issue. That may be fixed with the api version bump

Lash-L avatar Jun 05 '23 17:06 Lash-L