MATRIX integration blocking Home Assistant from wrapping up the start up phase / task pending

[jsapede]

The problem

Since days got warning message at HA restart issued from matrix integration, despite integration seems to work Made update of matrix server yesterday but no effect except generating new warnings (see https://github.com/home-assistant/core/issues/111921)

`Enregistreur: homeassistant.core Source: core.py:533 S'est produit pour la première fois: 09:29:13 (1 occurrences) Dernier enregistrement: 09:29:13

Something is blocking Home Assistant from wrapping up the start up phase. We're going to continue anyway. Please report the following info at https://github.com/home-assistant/core/issues: tapo_control.button, adguard.sensor, esphome.binary_sensor, energy, mqtt.device_tracker, sun, shelly.binary_sensor, versatile_thermostat.climate, mobile_app, template, zeroconf, bluetooth, tapo_control.switch, mqtt.sensor, meteo_france.sensor, spook.event, esphome.button, select, presence_simulation.switch, mqtt, logger, versatile_thermostat, frigate.image, threshold.binary_sensor, http, hassio.binary_sensor, pirateweather, input_text, xiaomi_miot, awtrix, esphome, awtrix.notify, proxmoxve.binary_sensor, xiaomi_miio.alarm_control_panel, xiaomi_miot.climate, xiaomi_miio.switch, zwave_js.binary_sensor, mobile_app.notify, remote, zone, usb, local_calendar, binary_sensor, system_log, mqtt.number, co2signal, tapo_control.camera, logbook, esphome.sensor, xiaomi_miot.cover, energy.sensor, zwave_js.number, telegram_bot, versatile_thermostat.select, dhcp, ipp.sensor, template.cover, diagnostics, scheduler, tapo_control.select, moon.sensor, forecast_solar, homeassistant.scene, scheduler.switch, frigate, mobile_app.binary_sensor, xiaomi_miot.text, spook, api, group, command_line.switch, alarmo.alarm_control_panel, stt, my, shelly.climate, search, spook.select, mqtt.switch, websocket_api, threshold, wyoming.stt, shelly, spook.switch, zwave_js.switch, shelly.event, media_player, cover, input_button, proxmoxve, frigate.switch, device_tracker, ssdp, mqtt.text, config, mqtt.binary_sensor, sun.sensor, tts, zwave_js.cover, blueprint, calendar, homeassistant, meross_lan.update, utility_meter, shelly.valve, auth, backup, ffmpeg, frigate.binary_sensor, time, hacs.sensor, versatile_thermostat.number, xiaomi_miot.vacuum, xiaomi_miot.camera, cast, command_line, xiaomi_miot.fan, forecast_solar.sensor, switch_as_x.light, proxmoxve.sensor, zwave_js.button, lock, group.cover, notify, homeassistant_alerts, xiaomi_miot.button, frigate.update, xiaomi_miot.device_tracker, fan, zwave_js.sensor, number, shelly.light, wyoming.tts, workday, input_datetime, versatile_thermostat.sensor, hacs, input_number, sensor, xiaomi_miio.sensor, light, device_automation, shelly.sensor, co2signal.sensor, panel_custom, trace, counter, filter.sensor, cast.media_player, shelly.button, humidifier, synology_dsm.sensor, synology_dsm.button, conversation, scene, frontend, webhook, xiaomi_miot.switch, frigate.camera, xiaomi_miot.number, mobile_app.sensor, adguard.switch, spook.number, tapo_control.number, xiaomi_miot.water_heater, xiaomi_miot.remote, google_assistant, hacs.update, google_translate, zwave_js, mqtt.lock, timer, frigate.sensor, cloud, tapo_control, meross_lan, weather, workday.binary_sensor, climate, mqtt.select, mqtt.button, media_source, tapo_control.update, hardware, spook.button, wyoming, xiaomi_miot.media_player, spook.sensor, moon, mqtt.light, hassio, wake_word, xiaomi_miot.sensor, zwave_js.light, matrix.notify, onvif, google_translate.tts, script, picotts.tts, input_select, xiaomi_miio, tapo_control.light, meross_lan.light, switch, alarmo, synology_dsm.update, network, adguard, update, schedule, xiaomi_miot.light, person, season, mobile_app.device_tracker, synology_dsm.switch, meteo_france.weather, map, synology_dsm.camera, mqtt.update, synology_dsm, vacuum, valve, google_assistant.button, camera, frigate.number, file_upload, xiaomi_miot.alarm_control_panel, zwave_js.update, utility_meter.sensor, spook.time, xiaomi_miot.select, spook.binary_sensor, matrix, meross_lan.sensor, analytics, shelly.cover, local_calendar.calendar, tapo_control.sensor, automation, synology_dsm.binary_sensor, onboarding, intent, text, system_health, webrtc, python_script, derivative.sensor, repairs, application_credentials, hassio.update, pirateweather.sensor, telegram.notify, zwave_js.select, assist_pipeline, event, derivative, persistent_notification, presence_simulation, shelly.switch, siren, tapo_control.siren, switch_as_x, versatile_thermostat.binary_sensor, statistics.sensor, tag, xiaomi_miot.humidifier, hassio.sensor, history, button, meteo_france, default_config, meross_lan.switch, alarm_control_panel, lovelace, water_heater, shelly.update, xiaomi_miio.light, image_upload, template.sensor, season.sensor, image, tapo_control.binary_sensor, group.switch, ipp, input_boolean, cloud.tts, xiaomi_miot.binary_sensor, proxmoxve.button, recorder, stream The system is waiting for tasks: {<Task pending name='Task-2473' coro=<MatrixBot.init..handle_startup() running at /usr/src/homeassistant/homeassistant/components/matrix/init.py:217> wait_for= cb=[set.remove()]>}`

What version of Home Assistant Core has the issue?

core-2024.5.5

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

Matrix

Link to integration documentation on our website

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

Diagnostics information

No response

Example YAML snippet

##########
# Matrix #
##########
matrix:
  homeserver: https://synapse.xxxxx
  username: "@xxxx:synapse.xxxxx"
  password: xxxxxx
  rooms:
    - "#notifications:synapse.xxxxx"

notify:
    # Matrix
  - name: synapse
    platform: matrix
    default_room: "#notifications:synapse.xxxxx"

Anything in the logs that might be useful for us?

No response

Additional information

No response

[home-assistant[bot]]

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

Code owner commands

Code owners of `matrix` 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 matrix` 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)}}

---

matrix documentation matrix source _{^{(message by IssueLinks)}}

[PaarthShah]

When you say that it seems to work, can you confirm that events are fired based off of word commands/regex commands?

Or that you're able to send messages as the bot user using the notify service?

[jsapede]

hello

i'm able to use the notify service, will have a try tonight or tomorrow to fire events

[jsapede]

OK tried the following commands :

'matrix: homeserver: https://synapse.xxxx username: "@soucieu:synapse.xxxx" password: xxxxx rooms:

• "#notifications:synapse.xxxx" commands:
• word: lightson name: lights_on rooms:
  • "#notifications:synapse.xxxx"`

and automation :

`alias: Nouvelle automatisation description: "" trigger:

• platform: event event_type: matrix_command event_data: command: lightson condition: [] action:
• type: toggle device_id: 8e6801bf05a0e0a278a2660cdc08b461 entity_id: 48439bf8a6389777216b2ad13e4a83a6 domain: light mode: single`

but nothing happens. No execution traces, and no system journal specific message

[EDIT] it started to work after 2 reboots and a wait time, say 5 minutes or so ... but still got the message at HA start

[rwjack]

I'm also getting this. Everything seems to be working, although I'm thinking this might be related to another warning:

Detected blocking call to open inside the event loop by integration 'matrix' at homeassistant/components/matrix/__init__.py, line 345: return load_json_object(self._session_filepath) (offender: /usr/src/homeassistant/homeassistant/util/json.py, line 78: with open(filename, mode="rb") as fdesc:), please create a bug report at https://github.com/home-assistant/core/issues?q=is%3Aopen+is%3Aissue+label%3A%22integration%3A+matrix%22 Traceback (most recent call last): File "<frozen runpy>", line 198, in _run_module_as_main File "<frozen runpy>", line 88, in _run_code File "/usr/src/homeassistant/homeassistant/__main__.py", line 223, in <module> 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/runner.py", line 166, in setup_and_run_hass return await hass.async_run() File "/usr/src/homeassistant/homeassistant/core.py", line 515, in async_run await self.async_start() File "/usr/src/homeassistant/homeassistant/core.py", line 534, in async_start self.bus.async_fire_internal(EVENT_HOMEASSISTANT_START) File "/usr/src/homeassistant/homeassistant/core.py", line 1554, in async_fire_internal self._hass.async_run_hass_job(job, event) File "/usr/src/homeassistant/homeassistant/core.py", line 936, in async_run_hass_job hassjob.target(*args) File "/usr/src/homeassistant/homeassistant/core.py", line 1418, in __call__ self.hass.async_run_hass_job(self.listener_job, event) File "/usr/src/homeassistant/homeassistant/core.py", line 939, in async_run_hass_job return self._async_add_hass_job(hassjob, *args, background=background) File "/usr/src/homeassistant/homeassistant/core.py", line 748, in _async_add_hass_job task = create_eager_task( 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/components/matrix/__init__.py", line 207, in handle_startup self._access_tokens = await self._get_auth_tokens() File "/usr/src/homeassistant/homeassistant/components/matrix/__init__.py", line 345, in _get_auth_tokens return load_json_object(self._session_filepath) 

@PaarthShah I use another custom extension that seems to have fixed this warning, more info here: https://github.com/Athozs/hass-additional-ca/issues/7

[PaarthShah]

Ooh interesting; this should hopefully be an easy fix, I'll check it out

[rwjack]

hey @PaarthShah, any updates on this?

[jsapede]

Still having the startup message

[TheOneValen]

I have the same message and the integration is not working. I do not get the entities. I use version 2024.7.3.

[PaarthShah]

Still looking into all of this. Fundamental issue is a failure to replicate on my end. I'm trying not to just throw my hands up and say "you might be having network/homeserver issues", but... I'd like to see that matrix-nio is connecting well to your homeservers in the first place too 😅

Haven't forgotten this though, I promise!

[rwjack]

I'd like to see that matrix-nio is connecting well to your homeservers in the first place too 😅

Is there any way we can fetch this data for you?

I'm not seeing anything unusual on my proxy. The integration seems to be making around 2 requests per minute:

I get the same message as OP:

Something is blocking Home Assistant from wrapping up the start up phase.
We're going to continue anyway. 
Please report the following info at https://github.com/home-assistant/core/issues:
<60+ of my integrations and core ones listed between these brackets> 
The system is waiting for tasks: {<Task pending name='Task-2177' coro=<MatrixBot.__init__.<locals>.handle_startup() 
running at /usr/src/homeassistant/homeassistant/components/matrix/__init__.py:217> wait_for=<Future pending cb=[Task.task_wakeup()]> cb=[set.remove()]>}

And check the timestamps below. The two warnings seem to be 15 seconds apart:

[PaarthShah]

@rwjack Apologies, I completely mistook this for another issue as I was looking at it. I just went ahead and made a PR to resolve this issue outright: https://github.com/home-assistant/core/pull/122730

[rwjack]

Awesome, hopefully both of the warnings go away now. Thanks @PaarthShah!

[rwjack]

@PaarthShah yeah, just to confirm, I modified the Matrix __init__.py file in my homeassistant HAOS contaier, and after restarting, we managed to get rid of the Detected blocking call to open... warning for sure, but I'm still seeing the other warning (The one this issue was originally about, so it seems they are not related):

Logger: homeassistant.core
Source: core.py:552
First occurred: 1:17:29 PM (1 occurrences)
Last logged: 1:17:29 PM

Something is blocking Home Assistant from wrapping up the start up phase.
We're going to continue anyway.
Please report the following info at https://github.com/home-assistant/core/issues:
unifi.image, mqtt_room.sensor, history, api, xiaomi_ble.binary_sensor, < ... SNIP ... >
The system is waiting for tasks: {<Task pending name='Task-1909' coro=<MatrixBot.__init__.<locals>.handle_startup() running at /usr/src/homeassistant/homeassistant/components/matrix/__init__.py:217> wait_for=<Future pending cb=[Task.task_wakeup()]> cb=[set.remove()]>}

And it seems to be related to this line: https://github.com/home-assistant/core/blob/ac0d0b21e20534e89590868284f690f6990c9011/homeassistant/components/matrix/__init__.py#L217

Here's a custom built timeline correlated to what I see in my logs:

PROXY:
13:16:50 PM - HTTP 200 - GET /_matrix/client/r0/sync?<SNIP>

RESTART:

CORE:
2024-07-28 13:17:06.437 INFO (MainThread) [supervisor.homeassistant.core] Home Assistant Core state changed to NOT_RUNNING
2024-07-28 13:17:16.450 INFO (MainThread) [supervisor.homeassistant.core] Home Assistant Core state changed to STARTING

PROXY:
13:17:21 PM - HTTP 200 - GET /_matrix/client/r0/sync?<SNIP>

SUPERVISOR:
First occurred: 1:17:29 PM (1 occurrences) 
Last logged: 1:17:29 PM
Something is blocking Home Assistant from wrapping up the start up phase.
We're going to continue anyway. 
< ... SNIP ... >

CORE:
2024-07-28 13:17:31.472 INFO (MainThread) [supervisor.homeassistant.core] Home Assistant Core state changed to RUNNING
2024-07-28 13:17:31.472 INFO (MainThread) [supervisor.homeassistant.core] Detect a running Home Assistant instance

PROXY:
13:17:42 PM - HTTP 499 - GET /_matrix/client/r0/sync?<SNIP>
13:17:45 PM - HTTP 499 - GET /_matrix/client/r0/sync?<SNIP>
13:18:05 PM - HTTP 200 - GET /_matrix/client/r0/account/whoami?<SNIP>
13:18:05 PM - HTTP 200 - POST /_matrix/client/r0/join/!<SNIP> # room 1
13:18:05 PM - HTTP 200 - POST /_matrix/client/r0/join/!<SNIP> # room 2 (2 total)
13:18:05 PM - HTTP 200 - GET /_matrix/client/r0/sync/!<SNIP>
13:18:05 PM - HTTP 200 - GET /_matrix/client/r0/sync/!<SNIP>
13:18:17 PM - HTTP 200 - GET /_matrix/client/r0/sync?<SNIP>
13:18:20 PM - HTTP 200 - GET /_matrix/client/r0/sync?<SNIP>

[PaarthShah]

Aha, gotcha, looks like I only fixed one error then; should be another one-liner for the other. Will get to it in a few minutes

[bdraco]

cd /config
curl -o- -sSL https://gist.githubusercontent.com/bdraco/43f8043cb04b9838383fd71353e99b18/raw/core_integration_pr | bash /dev/stdin -d matrix -p 122730

PR can be tested as a custom component as well

[PaarthShah]

Okay latest push to the PR branch fixes both warnings in my tests!

[rwjack]

Wohoo, no more warning! 🥳 🎉

[PaarthShah]

@rwjack all fixes are merged to dev! Thanks for your help