Gigabytes of logs, and a memory leak.

[shadow7412]

The problem

I've had this issue since updating to home assistant 2024.8. Originally I dealt with the issue by downgrading back to 2024.7.4 and hoping that somebody else would fix it, but there are features I want in newer versions so it's time to raise a ticket.

The following tests were done in safe mode (although the issue was first observed when running normally).

The logs start getting spammed the logs after being up for around 5 minutes, and continue until the computed crashes due to lack of system memory (though I've mitigated this by setting a memory limit on the docker container)

024-09-21 13:46:38.129 ERROR (MainThread) [homeassistant] Error doing job: Exception in callback _SelectorSocketTransport._read_ready() (None)
Traceback (most recent call last):
  File "/usr/local/lib/python3.12/asyncio/events.py", line 88, in _run
    self._context.run(self._callback, *self._args)
  File "/usr/local/lib/python3.12/asyncio/selector_events.py", line 960, in _read_ready
    self._read_ready_cb()
TypeError: 'NoneType' object is not callable
2024-09-21 13:46:38.130 ERROR (MainThread) [homeassistant] Error doing job: Exception in callback _SelectorSocketTransport._read_ready() (None)
Traceback (most recent call last):
  File "/usr/local/lib/python3.12/asyncio/events.py", line 88, in _run
    self._context.run(self._callback, *self._args)
  File "/usr/local/lib/python3.12/asyncio/selector_events.py", line 960, in _read_ready
    self._read_ready_cb()
TypeError: 'NoneType' object is not callable
2024-09-21 13:46:38.130 ERROR (MainThread) [homeassistant] Error doing job: Exception in callback _SelectorSocketTransport._read_ready() (None)
Traceback (most recent call last):
  File "/usr/local/lib/python3.12/asyncio/events.py", line 88, in _run
    self._context.run(self._callback, *self._args)
  File "/usr/local/lib/python3.12/asyncio/selector_events.py", line 960, in _read_ready
    self._read_ready_cb()
TypeError: 'NoneType' object is not callable
2024-09-21 13:46:38.131 ERROR (MainThread) [homeassistant] Error doing job: Exception in callback _SelectorSocketTransport._read_ready() (None)
Traceback (most recent call last):
  File "/usr/local/lib/python3.12/asyncio/events.py", line 88, in _run
    self._context.run(self._callback, *self._args)
  File "/usr/local/lib/python3.12/asyncio/selector_events.py", line 960, in _read_ready
    self._read_ready_cb()
TypeError: 'NoneType' object is not callable
2024-09-21 13:46:38.131 ERROR (MainThread) [homeassistant] Error doing job: Exception in callback _SelectorSocketTransport._read_ready() (None)
Traceback (most recent call last):
  File "/usr/local/lib/python3.12/asyncio/events.py", line 88, in _run
    self._context.run(self._callback, *self._args)
  File "/usr/local/lib/python3.12/asyncio/selector_events.py", line 960, in _read_ready
    self._read_ready_cb()
TypeError: 'NoneType' object is not callable
2024-09-21 13:46:38.131 ERROR (MainThread) [homeassistant] Error doing job: Exception in callback _SelectorSocketTransport._read_ready() (None)
Traceback (most recent call last):
  File "/usr/local/lib/python3.12/asyncio/events.py", line 88, in _run
    self._context.run(self._callback, *self._args)
  File "/usr/local/lib/python3.12/asyncio/selector_events.py", line 960, in _read_ready
    self._read_ready_cb()
TypeError: 'NoneType' object is not callable

I've included this many mostly to draw attention to the timestamps - I'm getting a couple of these every millisecond!

The logs on my local system blew out past a few gigabytes fairly quickly. The symptom that actually made me notice something was wrong however, was a memory leak seems to manifest that exhausted my ram in a few hours.

What version of Home Assistant Core has the issue?

core-2024.8.3

What was the last working version of Home Assistant Core?

core-2024.7.4

What type of installation are you running?

Home Assistant Container

Integration causing the issue

Unknown

Link to integration documentation on our website

Unknown

Diagnostics information

Turning on debug mode via homeassistant.debug in the configuration file did not add any extra information to the logs posted above.

Example YAML snippet

No response

Anything in the logs that might be useful for us?

I feel like this is going to be one of those annoying cases where finding the root cause is tricky, unless someone happens to recognise what's happening in that log. :(

I've written core-2024.8.3 above as that's the version I tested with again today, but the issue has been present since core-2024.8.0.

Additional information

No response

[shadow7412]

profile.1726890736795121.cprof.zip

Here's a 60 second profile from when these errors are churning out into the logs. Hopefully that might help diagnose where this is coming from...

The profile was run while home assistant was in safe mode.

[home-assistant[bot]]

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

Code owner commands

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

---

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

[bdraco]

Its almost certainly a thread safety problem. Given its happening in safe mode its likely a bug in a core integration.

Can you try enabling debugpy see Enabling asyncio debug mode before startup (fallback plan) in https://community.home-assistant.io/t/2024-5-tracking-down-instability-issues-caused-by-integrations/724441

[hipitihop]

I'm piggybacking on to this issue as the symptoms around the memory exhaustion sound familiar. I have not witnessed the logs issue, but I have not looked. Just raising my hand that I also have a setup where the presumed memory leak is occurring. I cannot pin it as well as the OP has to a specific version, but it seems somewhere around the same time I noticed too i.e. 2024.8

In my case, to mitigate running out of ram, I have doubled the amount of ram allocated to the VM from 3GiB to 6GiB and I monitor it and restart it every few days.

I run HA & container & z-wave-js (via docker compose) in a Ubuntu VM on Proxmox.

• HA 2024.9.3
• zwave-js 9.20.0
• Ubuntu: 22.04.5 LTS
• Docker: 27.3.1, build ce12230
• Proxmox 7.4-19
• Numerous integrations including HACS

I'm happy to help diagnose if provided with specific commands/log locations. It is currently not practical to uninstall and remove integrations because it is a live running system, as identifying a culprit will take days at a time for each

[shadow7412]

This took a little longer than expected.

I had created a new home assistant instance (I can't really afford mine to be down, as it's pretty essential to my household) and had been disabling things in the broken one as I ported things across to the new one.

So naturally, when I received your message I realised that the old one had stablised :/

I restored a backup from a while ago, and upgraded it to the version mentioned in the message and ... ugh. Software.

I'm hoping that @hipitihop above is in a position to add debugpy to their configuration (taking the performance hit) so something can be found, because I don't doubt this will swing around and hit me again some day. At least when that day comes I'll have a better idea of how to get you more useful information.

[shadow7412]

Actually, when shutting down the container I did get the following. It possibly benign (the container was in the middle of shutting down), but just in case...

2024-10-01 13:30:59.408 ERROR (MainThread) [homeassistant.config_entries] Error setting up entry AC:ED:5C:68:69:5F for bluetooth
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/config_entries.py", line 604, in async_setup
    result = await component.async_setup_entry(hass, self)
             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/components/bluetooth/__init__.py", line 328, in async_setup_entry
    await scanner.async_start()
  File "src/habluetooth/scanner.py", line 261, in async_start
  File "src/habluetooth/scanner.py", line 262, in habluetooth.scanner.HaScanner.async_start
  File "src/habluetooth/scanner.py", line 267, in _async_start
  File "src/habluetooth/scanner.py", line 360, in _async_start_attempt
  File "src/habluetooth/scanner.py", line 310, in habluetooth.scanner.HaScanner._async_start_attempt
  File "src/habluetooth/scanner.py", line 310, in habluetooth.scanner.HaScanner._async_start_attempt
  File "src/habluetooth/scanner.py", line 313, in habluetooth.scanner.HaScanner._async_start_attempt
  File "/usr/local/lib/python3.12/site-packages/bleak/__init__.py", line 203, in start
    await self._backend.start()
  File "/usr/local/lib/python3.12/site-packages/bleak/backends/bluezdbus/scanner.py", line 168, in start
    manager = await get_global_bluez_manager()
              ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/bleak/backends/bluezdbus/manager.py", line 1072, in get_global_bluez_manager
    await instance.async_init()
  File "/usr/local/lib/python3.12/site-packages/bleak/backends/bluezdbus/manager.py", line 258, in async_init
    await bus.connect()
  File "/usr/local/lib/python3.12/site-packages/dbus_fast/aio/message_bus.py", line 226, in connect
    await self._authenticate()
  File "/usr/local/lib/python3.12/site-packages/dbus_fast/aio/message_bus.py", line 493, in _authenticate
    response = self._auth._receive_line(await self._auth_readline())
                                        ^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/dbus_fast/aio/message_bus.py", line 475, in _auth_readline
    buf += await self._loop.sock_recv(self._sock, 1024)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/asyncio/selector_events.py", line 384, in sock_recv
    return await fut
           ^^^^^^^^^
asyncio.exceptions.CancelledError: Home Assistant is stopping
2024-10-01 13:30:59.448 WARNING (MainThread) [homeassistant.components.modbus.modbus] modbus mb_fronius communication closed
2024-10-01 13:30:59.727 ERROR (MainThread) [homeassistant] Error doing job: Future exception was never retrieved (None):   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 674, in run_until_complete
    self.run_forever()
  File "/usr/local/lib/python3.12/asyncio/base_events.py", line 641, in run_forever
    self._run_once()
  File "/usr/local/lib/python3.12/asyncio/base_events.py", line 1982, 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/core.py", line 1148, in async_stop
    self.bus.async_fire_internal(EVENT_HOMEASSISTANT_STOP)
  File "/usr/src/homeassistant/homeassistant/core.py", line 1564, in async_fire_internal
    self._hass.async_run_hass_job(job, event)
  File "/usr/src/homeassistant/homeassistant/core.py", line 938, in async_run_hass_job
    hassjob.target(*args)
  File "/usr/src/homeassistant/homeassistant/core.py", line 1425, in __call__
    self.hass.async_run_hass_job(self.listener_job, event)
  File "/usr/src/homeassistant/homeassistant/core.py", line 941, in async_run_hass_job
    return self._async_add_hass_job(hassjob, *args, background=background)
  File "/usr/src/homeassistant/homeassistant/core.py", line 769, in _async_add_hass_job
    task = self.loop.run_in_executor(None, hassjob.target, *args)
  File "/usr/local/lib/python3.12/asyncio/base_events.py", line 862, in run_in_executor
    return futures.wrap_future(
  File "/usr/local/lib/python3.12/asyncio/futures.py", line 417, in wrap_future
    new_future = loop.create_future()
  File "/usr/local/lib/python3.12/asyncio/base_events.py", line 449, in create_future
    return futures.Future(loop=self)
Traceback (most recent call last):
  File "/usr/local/lib/python3.12/concurrent/futures/thread.py", line 58, in run
    result = self.fn(*self.args, **self.kwargs)
             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/config/custom_components/localtuya/__init__.py", line 155, in _shutdown
    discovery.close()
  File "/config/custom_components/localtuya/discovery.py", line 59, in close
    transport.close()
  File "/usr/local/lib/python3.12/asyncio/selector_events.py", line 865, in close
    self._loop.call_soon(self._call_connection_lost, None)
  File "/usr/local/lib/python3.12/asyncio/base_events.py", line 797, in call_soon
    self._check_thread()
  File "/usr/local/lib/python3.12/asyncio/base_events.py", line 834, in _check_thread
    raise RuntimeError(
RuntimeError: Non-thread-safe operation invoked on an event loop other than the current one

[bdraco]

, when shutting down the container I did get the following. It possibly benign (the container was in the middle of shutting down), but just in case...

definitely not benign. That’s a potential crash every time that code is called in localtuya

[shadow7412]

In that case, I'm glad I posted it 😅 The "non-thread-safe operation" part was the reason I decided it might be worth it.

[hipitihop]

debugpy

Can someone please point me at specific steps to set this up. And how much of a performance hit is this ? As I said this is a live system including many automations via node-red calling HA services over websocket. Does this mean response time are significantly affected ? or just a bigger load on the HA host/vm

[shadow7412]

@hipitihop, check out this link which has answers to those questions.

try enabling debugpy see Enabling asyncio debug mode before startup (fallback plan) in https://community.home-assistant.io/t/2024-5-tracking-down-instability-issues-caused-by-integrations/724441

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