sca075 / mqtt_vacuum_camera

Camera Integration for Home Assistant to export and render all Vacuums connected via MQTT( including Valetudo Hypfer and RE(rand256)) Maps.
Apache License 2.0
106 stars 7 forks source link

Detected blocking call to open inside the event loop #176

Closed tomlut closed 4 months ago

tomlut commented 5 months ago

Checklist

The problem

After a home assistant restart I receive the following warning:

Logger: homeassistant.util.loop Source: util/loop.py:84 First occurred: 15:17:43 (652 occurrences) Last logged: 15:18:18

Detected blocking call to open inside the event loop by custom integration 'valetudo_vacuum_camera' at custom_components/valetudo_vacuum_camera/utils/users_data.py, line 107: with open(file_path) as file: (offender: /config/custom_components/valetudo_vacuum_camera/utils/users_data.py, line 107: with open(file_path) as file:), please create a bug report at https://github.com/sca075/valetudo_vacuum_camera/issues Traceback (most recent call last): File "", line 198, in _run_module_as_main File "", line 88, in _run_code File "/usr/src/homeassistant/homeassistant/main.py", line 223, in sys.exit(main()) File "/usr/src/homeassistant/homeassistant/main.py", line 209, in main exit_code = runner.run(runtime_conf) File "/usr/src/homeassistant/homeassistant/runner.py", line 190, in run return loop.run_until_complete(setup_and_run_hass(runtime_config)) File "/usr/local/lib/python3.12/asyncio/base_events.py", line 672, in run_until_complete self.run_forever() File "/usr/local/lib/python3.12/asyncio/base_events.py", line 639, in run_forever self._run_once() File "/usr/local/lib/python3.12/asyncio/base_events.py", line 1988, in _run_once handle._run() File "/usr/local/lib/python3.12/asyncio/events.py", line 88, in _run self._context.run(self._callback, *self._args) File "/usr/src/homeassistant/homeassistant/config_entries.py", line 2055, in async_forward_entry_setup return await self._async_forward_entry_setup(entry, domain, True) File "/usr/src/homeassistant/homeassistant/config_entries.py", line 2081, in _async_forward_entry_setup await entry.async_setup(self.hass, integration=integration) File "/usr/src/homeassistant/homeassistant/config_entries.py", line 594, in async_setup result = await component.async_setup_entry(hass, self) File "/usr/src/homeassistant/homeassistant/components/camera/init.py", line 461, in async_setup_entry return await component.async_setup_entry(entry) File "/usr/src/homeassistant/homeassistant/helpers/entity_component.py", line 196, in async_setup_entry return await self._platforms[key].async_setup_entry(config_entry) File "/usr/src/homeassistant/homeassistant/helpers/entity_platform.py", line 333, in async_setup_entry return await self._async_setup_platform(async_create_setup_awaitable) File "/usr/src/homeassistant/homeassistant/helpers/entity_platform.py", line 363, in _async_setup_platform awaitable = create_eagertask(awaitable, loop=hass.loop) File "/usr/src/homeassistant/homeassistant/util/async.py", line 37, in create_eager_task return Task(coro, loop=loop, name=name, eager_start=True) File "/config/custom_components/valetudo_vacuum_camera/camera.py", line 89, in async_setup_entry async_add_entities(camera, update_before_add=True) File "/usr/src/homeassistant/homeassistant/helpers/entity_platform.py", line 515, in _async_schedule_add_entities_for_entry task = self.config_entry.async_create_task( File "/usr/src/homeassistant/homeassistant/config_entries.py", line 1134, in async_create_task task = hass.async_create_task_internal( File "/usr/src/homeassistant/homeassistant/core.py", line 828, in async_create_task_internal task = create_eagertask(target, name=name, loop=self.loop) File "/usr/src/homeassistant/homeassistant/util/async.py", line 37, in create_eager_task return Task(coro, loop=loop, name=name, eager_start=True) File "/usr/src/homeassistant/homeassistant/helpers/entity_platform.py", line 649, in async_add_entities await add_func(coros, entities, timeout) File "/usr/src/homeassistant/homeassistant/helpers/entity_platform.py", line 555, in _async_add_and_update_entities tasks = [create_eagertask(coro, loop=self.hass.loop) for coro in coros] File "/usr/src/homeassistant/homeassistant/util/async.py", line 37, in create_eager_task return Task(coro, loop=loop, name=name, eager_start=True) File "/usr/src/homeassistant/homeassistant/helpers/entity_platform.py", line 729, in _async_add_entity await entity.async_device_update(warning=False) File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 1289, in async_device_update await self.async_update() File "/config/custom_components/valetudo_vacuum_camera/camera.py", line 345, in async_update self._shared.user_language = await async_get_active_user_language(self.hass) File "/config/custom_components/valetudo_vacuum_camera/utils/users_data.py", line 149, in async_get_active_user_language active_user_id = await async_find_last_logged_in_user(hass) File "/config/custom_components/valetudo_vacuum_camera/utils/users_data.py", line 107, in async_find_last_logged_in_user with open(file_path) as file:

What version of an integration has described problem?

2024.06.2

What was the last working version of an integration?

No response

What vacuum model do you have problems with?

Roborock S50

Please firmware installed on your Vacuum.

2024.02.0

What type of platform you use?

Intel NUC (or generic x86_64)

What version of Home Assistant do you use?

core-2024.6.0

What type of installation are you running?

Home Assistant OS

Camera's settings.

No response

Logs or Errors shown in the HA snapshots (please enable the Debug Mode)

No response

Additional information

No response

sca075 commented 5 months ago

I do not really understand why but again will be checking it.

sca075 commented 5 months ago

@tomlut I think I figured where is the problem I need to go to work as soon I'm back will update you.

tomlut commented 5 months ago

There's no rush. It is only a warning and the camera is still working. Thank you for the prompt response though.

sca075 commented 5 months ago

The issue was closed automatically because of the pull request and release 2024.6.3b1, @tomlut if you could test it and confirm that it work would really nice from use (HACS with the beta release enabled to download it).

tomlut commented 5 months ago

Confirmed. b3 has fixed the issue.

tomlut commented 5 months ago

Actually no it has not fixed it:

Logger: homeassistant.util.loop Source: util/loop.py:84 First occurred: 07:41:19 (12 occurrences) Last logged: 08:45:12

Detected blocking call to open inside the event loop by custom integration 'valetudo_vacuum_camera' at custom_components/valetudo_vacuum_camera/utils/users_data.py, line 155: with open(file_path) as file: (offender: /config/custom_components/valetudo_vacuum_camera/utils/users_data.py, line 155: with open(file_path) as file:), please create a bug report at https://github.com/sca075/valetudo_vacuum_camera/issues Traceback (most recent call last): File "", line 198, in _run_module_as_main File "", line 88, in _run_code File "/usr/src/homeassistant/homeassistant/main.py", line 223, in sys.exit(main()) File "/usr/src/homeassistant/homeassistant/main.py", line 209, in main exit_code = runner.run(runtime_conf) File "/usr/src/homeassistant/homeassistant/runner.py", line 190, in run return loop.run_until_complete(setup_and_run_hass(runtime_config)) File "/usr/local/lib/python3.12/asyncio/base_events.py", line 672, in run_until_complete self.run_forever() File "/usr/local/lib/python3.12/asyncio/base_events.py", line 639, in run_forever self._run_once() File "/usr/local/lib/python3.12/asyncio/base_events.py", line 1988, in _run_once handle._run() File "/usr/local/lib/python3.12/asyncio/events.py", line 88, in _run self._context.run(self._callback, *self._args) File "/usr/src/homeassistant/homeassistant/helpers/entity_platform.py", line 680, in _async_handle_interval_callback self.config_entry.async_create_background_task( File "/usr/src/homeassistant/homeassistant/config_entries.py", line 1164, in async_create_background_task task = hass.async_create_background_task(target, name, eager_start) File "/usr/src/homeassistant/homeassistant/core.py", line 860, in async_create_background_task task = create_eagertask(target, name=name, loop=self.loop) File "/usr/src/homeassistant/homeassistant/util/async.py", line 37, in create_eager_task return Task(coro, loop=loop, name=name, eager_start=True) File "/usr/src/homeassistant/homeassistant/helpers/entity_platform.py", line 1050, in _async_update_entity_states await entity.async_update_ha_state(True) File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 941, in async_update_ha_state await self.async_device_update() File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 1289, in async_device_update await self.async_update() File "/config/custom_components/valetudo_vacuum_camera/camera.py", line 345, in async_update self._shared.user_language = await async_get_active_user_language(self.hass) File "/config/custom_components/valetudo_vacuum_camera/utils/users_data.py", line 155, in async_get_active_user_language with open(file_path) as file:

sca075 commented 5 months ago

Wow I think this is because we accessed the front end file with the user settings.. all of this is just for localization.. the user language is used in the status text translation... interesting I don't get such warnings with the OS for pi4. I'm sure (could not test it yet).. VM os isn't that sensible too.. very sensible HA.. for Intel there's for sure a difference.

Thank you @tomlut I will then try another approach, I think we need to create "our Keys" and store those data in a data class so that we access memory instead of disk this is why HassKey).. will be working on it..

sca075 commented 5 months ago

@tomlut I was able to do some research and I think the problem is the name of the variable (HA is checking the files variables names).

As temporary (the change to data classes will be implemented gradually in the next versions) would release a new beta version tomorrow. As you are actually running the most "sensible" version of the OS could I count on you to test it and let's work together to fix those warnings 😉

tomlut commented 5 months ago

Sure thing. If you need help with event loop blocking issues Nick Koston ( @bdraco ) is usually able to offer some advice.

bdraco commented 5 months ago

Any place you are opening and reading files needs to be run in the executor to avoid blocking the event loop.

Nothing else in Home Assistant can run while the file is being opened and read because it blocks the main thread when you do I/O in the event loop.

Ex https://github.com/sca075/valetudo_vacuum_camera/blob/ab59edb5a24057d8ee1e622c5813c20ebd8fb8d1/custom_components/valetudo_vacuum_camera/utils/users_data.py#L262

There are more places. The above is only the first one I found.

To fix this, make a new function that opens and reads the file and returns the result, than use

data = await loop.run_in_executor(None, your_new_blocking_function)

sca075 commented 5 months ago

( @bdraco ) thanks a lot for the help, to follow the spec I will change this as follow: Create a function that load a file x in the main loop. In the second step Gathered the data will be written in data classes. Basically I couldn't found any core exposed function that return the instance logged in user fronted language and also in discord at that time, the answer was nope. @tomlut thanks really much for this, really appreciated. Then we have a little more work to do on this ;)

bdraco commented 5 months ago

If you are in the Home Assistant code you can use hass.async_add_executor_job instead of loop.run_in_executor

example: https://github.com/home-assistant/core/blob/e4be3d8435c37177ca206232e1c765b97977d2bb/homeassistant/components/logbook/rest_api.py#L120

bdraco commented 5 months ago

More on executor usage in the asyncio dev docs: https://docs.python.org/3/library/asyncio-dev.html#running-blocking-code

sca075 commented 5 months ago

@bdraco conversion is in progress (working on it) as per the camera actually use also different threads I opted for the
loop.run_in_executor solution. I'm currently using this code for loading the files:

async def async_load_file(file_to_load: str) -> Any:
    """Asynchronously load JSON data from a file."""
    loop = asyncio.get_event_loop()
    try:
        with await loop.run_in_executor(None, open, file_to_load, 'r') as data_file:
            data = data_file.read()
            return data
    except Exception as e:
        _LOGGER.warning(f"Exception {e}")
        return None

The warning of course is actually for debug purpose will use a better warning description in the final version. Still need to work on the data classes (but I think the best is to release a new version so that custom component can comply with the requirements and do not block the main thread) as soon I will use a safe way to save the data as temporally Thank you really much for your time and help here.

bdraco commented 5 months ago

The read call above is still happening in the event loop in your code above. Read is a blocking call. Home Assistant can only detect the open call though so when you get a warning on open you need to make sure all the IO that happens after the open call is also run in the executor.

sca075 commented 5 months ago

so it should be something like..

def read_file():
        with open(file_path, 'r') as file:
            return file.read()

    try:
        data = await loop.run_in_executor(None, read_file)
        return data
    except Exception as e:
bdraco commented 5 months ago

so it should be something like..

def read_file():
        with open(file_path, 'r') as file:
            return file.read()

    try:
        data = await loop.run_in_executor(None, read_file)
        return data
    except Exception as e:

Yes that would work.

You don't need data = and could return await loop.run_in_executor(None, read_file)

sca075 commented 5 months ago

@bdraco thank you really much appreciated 🥇 thanks also for the great work you are doing for HA

sca075 commented 5 months ago

@tomlut thank you really much for the help, just published a new beta 2024.06.3b3, would you be so kind to test it? In the final version I count to update also snapshot.py, so the final 2024.06.3 will have this first part remodelling implemented. The second part should arrive with 2024.06.4. @bdraco thanks once again.

tomlut commented 5 months ago

Tested. No more warnings and it is working as expected.

sca075 commented 5 months ago

Thanks a lot for your time and test, we keep this open for the time be. Although I need to tanks especially you this conversation helped me not only technically nut motivationally.

daydy16 commented 5 months ago

Thank you for maintaining this repository and actively addressing issues. It's wonderful to see how the open-source community thrives through efforts like yours. This spirit of collaboration is what makes Home Assistant such a strong and remarkable platform. Your dedication is truly appreciated!

tomlut commented 5 months ago

Not sure if this is Valetudo or the camera generating these warnings:

Logger: homeassistant.components.mqtt.sensor
Source: components/mqtt/sensor.py:241
integration: MQTT (documentation, issues)
First occurred: 11:01:08 (59 occurrences)
Last logged: 12:07:10

Invalid undecoded state message 'b'96'' received from 'valetudo/roborock_downstairs/BatteryStateAttribute/level'
Invalid undecoded state message 'b'89'' received from 'valetudo/roborock_upstairs/BatteryStateAttribute/level'
Invalid undecoded state message 'b'95'' received from 'valetudo/roborock_downstairs/BatteryStateAttribute/level'
Invalid undecoded state message 'b'94'' received from 'valetudo/roborock_downstairs/BatteryStateAttribute/level'
Invalid undecoded state message 'b'93'' received from 'valetudo/roborock_downstairs/BatteryStateAttribute/level'

They appear to be happening while the battery is charging after a clean.

sca075 commented 5 months ago

@tomlut it has something to do with Valetudo I guess, I did face the same error and reported in here #118629. Jan Bouwhuis (@jbouwh) is waiting for some MQTT Explorer log to better understand this phenomena. When we have the data probably we need to open an issue on Valetudo because sometime this value apparently is None and MQTT can't decode it. Anyhow my vacuum didn't generated it probably because battery never went below 95, in this days, it was more evident during the beta of HA. roborock_downstairs is an S5 (my one is and I do not know if it is a model related issue)? if not the firmware 2024.02.0 of the vacuum probably is having issues. We do not publish this value of course we just received it as MQTT did. Will try to reproduce the same and keep MQTT Explorer connected to the instance where the vacuum is.

sca075 commented 5 months ago

Setted the milestone 2024.08.0 to conclude the HASSKey transaction of multiple "un-required" I/O operation. Implementing a data class / model as done recently in the core environment is the goal just fixed.

tomlut commented 4 months ago

Another async issue just popped up in 2024.7.1:

Detected code that calls async_forward_entry_setup for integration mqtt_vacuum_camera with title: robovac-upstairs Camera and entry_id: 09dafb383f5d229eac0dfb8613f6392f, during setup without awaiting async_forward_entry_setup, which can cause the setup lock to be released before the setup is done. This will stop working in Home Assistant 2025.1. Please report this issue.

sca075 commented 4 months ago

@tomlut but the camera works right?

tomlut commented 4 months ago

Sorry, yes. Everything is functioning well still. This is just an extra check for async misuse that was included in 2024.7 so that is why it is showing up now.

sca075 commented 4 months ago

Well it's more than other a deprecation notice, of course it's really appreciated that you reported this. Will add it to the list of things to correct, we will see if we can close this one in the Next versions 😉. Thank you @tomlut

sca075 commented 4 months ago

@tomlut I think I can fix the warning issue with the 2024.07.1 instead of async_forward_entry_setup will use async_forward_entry_setups this should solve the depreciation notice.

sca075 commented 4 months ago

@tomlut 2024.07.1 just released, this should solve also the issue with the startup warning you kindly reported ;)

tomlut commented 4 months ago

Indeed this issue is fixed. Unfortunately I have another to open.