Closed Gfkappa closed 1 year ago
from Host log:
[ 2356.869301] oom-kill:constraint=CONSTRAINT_NONE,nodemask=(null),cpuset=21c98732bf7e7d6ba3d73347542c4017f87b7a38f2a1cb7135eaf1e80637077f,mems_allowed=0,global_oom,task_memcg=/docker/ac6d7591b994b55cd6db2d658aadcdd778374e8b3ea0892e4e9bf188dccc1186,task=python3,pid=15748,uid=0 [ 2356.869357] Out of memory: Killed process 15748 (python3) total-vm:17142140kB, anon-rss:6962752kB, file-rss:0kB, shmem-rss:0kB, UID:0 pgtables:22756kB oom_score_adj:0
Something is eating away at your memory.
Could you check on your host using e.g. htop
if the memory usage of Home Assistant keeps on increasing?
Or if something else is consuming large amounts of memory?
Hello,
Only HA run on this pc, here the outcome:
Da: RoboMagus @.> Inviato: giovedì 7 luglio 2022 15:03 A: home-assistant/core @.> Cc: Gfkappa @.>; Author @.> Oggetto: Re: [home-assistant/core] Loop restarting (Issue #74606)
Something is eating away at your memory. Could you check on your host using e.g. htop if the memory usage of Home Assistant keeps on increasing? Or if something else is consuming large amounts of memory?
— Reply to this email directly, view it on GitHub https://github.com/home-assistant/core/issues/74606#issuecomment-1177578558 , or unsubscribe https://github.com/notifications/unsubscribe-auth/ATCIV4M2FAGVOVDTN7ZWMK3VS3IOVANCNFSM5245PPVA . You are receiving this because you authored the thread. https://github.com/notifications/beacon/ATCIV4J2G4X7CO7EKZ7PRQTVS3IOVA5CNFSM5245PPVKYY3PNVWWK3TUL52HS4DFVREXG43VMVBW63LNMVXHJKTDN5WW2ZLOORPWSZGOIYYGYPQ.gif Message ID: @. @.> >
Hello, anybody can help here? Thanks in advance
There's hardly any info to go on here, which makes providing assistance quite hard. Could you try again sharing the details that are missing from your previous message?
Only HA run on this pc, here the outcome:
Additional logging is required on what is actually causing the issue.
I think I am seeing this problem also. Since upgrading to 2022.7.0 my memory usage has been bananas. Normally my server sits around 15% memory but it is spiking way up high and then home assistant gets OOMed and it restarts. My sever has 32gb of RAM, so the usage is high :)
I am running an unsupported setup (because thats how I installed things before the supervised support was defined). However, I don't think that is the cause of the problem here. I'm running Ubuntu 18.04 LTS with a supervised home assistant container.
The uptime sensor tells me this is roughly happening every 20-30 minutes or so. Somewhat slower than OP reported, but I likely have more RAM to fill.
An example OOM kill log from my sys logs.
Jul 11 15:08:21 hoose kernel: [28672.766498] Out of memory: Kill process 32063 (python3) score 808 or sacrifice child
Jul 11 15:08:21 hoose kernel: [28672.766642] Killed process 32063 (python3) total-vm:41035648kB, anon-rss:20403540kB, file-rss:0kB, shmem-rss:0kB
Jul 11 15:08:21 hoose kernel: [28673.444216] oom_reaper: reaped process 32063 (python3), now anon-rss:0kB, file-rss:0kB, shmem-rss:8kB
I don't see any new errors in the home assistant log and I looked through the errors I have in sentry for this release. They all appear to be the normal timeouts etc. The fault log is a segmentation fault, as you might expect from a killed process, so not very useful but I'm happy to share it. Here is a sample as its 600+ lines long.
Fatal Python error: Segmentation fault
Thread 0x00007f2992f3ab30 (most recent call first):
File "/usr/local/lib/python3.9/concurrent/futures/thread.py", line 75 in _worker
File "/usr/local/lib/python3.9/threading.py", line 910 in run
File "/usr/local/lib/python3.9/site-packages/sentry_sdk/integrations/threading.py", line 67 in run
File "/usr/local/lib/python3.9/threading.py", line 973 in _bootstrap_inner
File "/usr/local/lib/python3.9/threading.py", line 930 in _bootstrap
Thread 0x00007f29c3b19b30 (most recent call first):
File "/usr/local/lib/python3.9/concurrent/futures/thread.py", line 75 in _worker
File "/usr/local/lib/python3.9/threading.py", line 910 in run
File "/usr/local/lib/python3.9/site-packages/sentry_sdk/integrations/threading.py", line 67 in run
File "/usr/local/lib/python3.9/threading.py", line 973 in _bootstrap_inner
File "/usr/local/lib/python3.9/threading.py", line 930 in _bootstrap
Thread 0x00007f29d1e9eb30 (most recent call first):
File "/usr/local/lib/python3.9/concurrent/futures/thread.py", line 75 in _worker
File "/usr/local/lib/python3.9/threading.py", line 910 in run
File "/usr/local/lib/python3.9/site-packages/sentry_sdk/integrations/threading.py", line 67 in run
File "/usr/local/lib/python3.9/threading.py", line 973 in _bootstrap_inner
File "/usr/local/lib/python3.9/threading.py", line 930 in _bootstrap
Thread 0x00007f29effa3b30 (most recent call first):
File "/usr/local/lib/python3.9/concurrent/futures/thread.py", line 75 in _worker
File "/usr/local/lib/python3.9/threading.py", line 910 in run
File "/usr/local/lib/python3.9/site-packages/sentry_sdk/integrations/threading.py", line 67 in run
File "/usr/local/lib/python3.9/threading.py", line 973 in _bootstrap_inner
File "/usr/local/lib/python3.9/threading.py", line 930 in _bootstrap
Thread 0x00007f2a1eb9eb30 (most recent call first):
File "/usr/local/lib/python3.9/ssl.py", line 1099 in read
File "/usr/local/lib/python3.9/ssl.py", line 1241 in recv_into
File "/usr/local/lib/python3.9/socket.py", line 704 in readinto
File "/usr/local/lib/python3.9/http/client.py", line 506 in readinto
File "/usr/local/lib/python3.9/http/client.py", line 462 in read
File "/usr/local/lib/python3.9/site-packages/urllib3/response.py", line 519 in read
File "/usr/local/lib/python3.9/site-packages/urllib3/response.py", line 576 in stream
File "/usr/local/lib/python3.9/site-packages/requests/models.py", line 758 in generate
File "/usr/local/lib/python3.9/site-packages/sseclient/__init__.py", line 48 in _read
File "/usr/local/lib/python3.9/site-packages/sseclient/__init__.py", line 58 in events
File "/usr/local/lib/python3.9/site-packages/nest/nest.py", line 1792 in _start_event_loop
File "/usr/local/lib/python3.9/threading.py", line 910 in run
File "/usr/local/lib/python3.9/site-packages/sentry_sdk/integrations/threading.py", line 67 in run
File "/usr/local/lib/python3.9/threading.py", line 973 in _bootstrap_inner
File "/usr/local/lib/python3.9/threading.py", line 930 in _bootstrap
...... lots of similar and repetition .....
Thread 0x00007f2a42d9f8b0 (most recent call first):
File "/usr/local/lib/python3.9/selectors.py", line 469 in select
File "/usr/local/lib/python3.9/asyncio/base_events.py", line 1854 in _run_once
File "/usr/local/lib/python3.9/asyncio/base_events.py", line 596 in run_forever
File "/usr/local/lib/python3.9/asyncio/base_events.py", line 629 in run_until_complete
File "/usr/src/homeassistant/homeassistant/runner.py", line 121 in run
File "/usr/src/homeassistant/homeassistant/__main__.py", line 318 in main
File "/usr/src/homeassistant/homeassistant/__main__.py", line 331 in <module>
File "/usr/local/lib/python3.9/runpy.py", line 87 in _run_code
File "/usr/local/lib/python3.9/runpy.py", line 197 in _run_module_as_main
With this flux query I can see the home assisstant container memory usage. Data gathered by Telegraf.
from(bucket: "telegraf")
|> range(start: v.timeRangeStart, stop: v.timeRangeStop)
|> filter(fn: (r) => r["_measurement"] == "docker_container_mem")
|> filter(fn: (r) => r["_field"] == "usage")
|> filter(fn: (r) => r["container_name"] == "homeassistant")
|> aggregateWindow(every: 5s, fn: mean, createEmpty: false)
|> yield(name: "mean")
The colours show the HA releases - so the flat blue being 2022.6, the spikes start in purple 2202.7, then 2202.7.1, .2, and orange is 2202.7.3
It is hard to know what other information to give. Do we have any tools for analysing memory usage? Maybe there is a misbehaving integration that both I and @Gfkappa are using?
I think the next best step is to use https://www.home-assistant.io/integrations/profiler/#service-profilermemory to get a memory profile
I plan on creating an automation that triggers the profile service every minute. Then when there is a crash I can just take the last one. I have downgraded my version at the moment as the constant restarts were problematic but I'll try and do this over the weekend.
I tried to debug this further last night and wrote the following automation to help me get some data. Turn the input boolean on and it will profile every two minutes until HA restarts (or you turn it off).
input_boolean:
debug_profile:
name: Debug Profile
initial: false
automation:
- alias: Debug Profile
id: debug_profile
trigger:
- platform: time_pattern
minutes: "/2"
condition:
- >
{{ is_state("input_boolean.debug_profile", "on") }}
action:
- parallel:
- service: profiler.memory
- service: profiler.start
However, Interestingly I am not seeing this issue on 2022.7.4. I'll keep the code around incase it does come up but its been running file for 12 hours now. That may be useful for somebody else if they hit this.
It just happened on 2022.7.4
for me - so turned my automation on. Hopefully it happens again fairly soon and I get some data.
Hello, here the output from home-assistant.log.fault:
Fatal Python error: Aborted
Thread 0x00007f0516f67b30 (most recent call first): File "/usr/local/lib/python3.9/concurrent/futures/thread.py", line 75 in _worker File "/usr/local/lib/python3.9/threading.py", line 910 in run File "/usr/local/lib/python3.9/threading.py", line 973 in _bootstrap_inner File "/usr/local/lib/python3.9/threading.py", line 930 in _bootstrap
Current thread 0x00007f0519cacb30 (most recent call first): File "/usr/src/homeassistant/homeassistant/components/stream/worker.py", line 225 in mux_packet File "/usr/src/homeassistant/homeassistant/components/stream/worker.py", line 539 in stream_worker File "/usr/src/homeassistant/homeassistant/components/stream/init.py", line 332 in _run_worker File "/usr/local/lib/python3.9/threading.py", line 910 in run File "/usr/local/lib/python3.9/threading.py", line 973 in _bootstrap_inner File "/usr/local/lib/python3.9/threading.py", line 930 in _bootstrap
Thread 0x00007f0519db1b30 (most recent call first): File "/usr/src/homeassistant/homeassistant/components/stream/worker.py", line 349 in next File "/usr/src/homeassistant/homeassistant/components/stream/worker.py", line 531 in stream_worker File "/usr/src/homeassistant/homeassistant/components/stream/init.py", line 332 in _run_worker File "/usr/local/lib/python3.9/threading.py", line 910 in run File "/usr/local/lib/python3.9/threading.py", line 973 in _bootstrap_inner File "/usr/local/lib/python3.9/threading.py", line 930 in _bootstrap
Thread 0x00007f0519f43b30 (most recent call first): File "/usr/local/lib/python3.9/threading.py", line 312 in wait File "/usr/local/lib/python3.9/queue.py", line 171 in get File "/usr/local/lib/python3.9/site-packages/telegram/ext/dispatcher.py", line 249 in _pooled File "/usr/local/lib/python3.9/threading.py", line 910 in run File "/usr/local/lib/python3.9/threading.py", line 973 in _bootstrap_inner File "/usr/local/lib/python3.9/threading.py", line 930 in _bootstrap
Thread 0x00007f051a048b30 (most recent call first): File "/usr/local/lib/python3.9/threading.py", line 312 in wait File "/usr/local/lib/python3.9/queue.py", line 171 in get File "/usr/local/lib/python3.9/site-packages/telegram/ext/dispatcher.py", line 249 in _pooled File "/usr/local/lib/python3.9/threading.py", line 910 in run File "/usr/local/lib/python3.9/threading.py", line 973 in _bootstrap_inner File "/usr/local/lib/python3.9/threading.py", line 930 in _bootstrap
Thread 0x00007f051a14db30 (most recent call first): File "/usr/local/lib/python3.9/threading.py", line 312 in wait File "/usr/local/lib/python3.9/queue.py", line 171 in get File "/usr/local/lib/python3.9/site-packages/telegram/ext/dispatcher.py", line 249 in _pooled File "/usr/local/lib/python3.9/threading.py", line 910 in run File "/usr/local/lib/python3.9/threading.py", line 973 in _bootstrap_inner File "/usr/local/lib/python3.9/threading.py", line 930 in _bootstrap
Thread 0x00007f051a252b30 (most recent call first): File "/usr/src/homeassistant/homeassistant/util/async_.py", line 167 in protected_loop_func File "/usr/local/lib/python3.9/site-packages/telegram/ext/updater.py", line 485 in _network_loop_retry File "/usr/local/lib/python3.9/site-packages/telegram/ext/updater.py", line 441 in _start_polling File "/usr/local/lib/python3.9/site-packages/telegram/ext/updater.py", line 236 in _thread_wrapper File "/usr/local/lib/python3.9/threading.py", line 910 in run File "/usr/local/lib/python3.9/threading.py", line 973 in _bootstrap_inner File "/usr/local/lib/python3.9/threading.py", line 930 in _bootstrap
Thread 0x00007f051a357b30 (most recent call first): File "/usr/local/lib/python3.9/threading.py", line 312 in wait File "/usr/local/lib/python3.9/queue.py", line 171 in get File "/usr/local/lib/python3.9/site-packages/telegram/ext/dispatcher.py", line 249 in _pooled File "/usr/local/lib/python3.9/threading.py", line 910 in run File "/usr/local/lib/python3.9/threading.py", line 973 in _bootstrap_inner File "/usr/local/lib/python3.9/threading.py", line 930 in _bootstrap
Thread 0x00007f051a45cb30 (most recent call first): File "/usr/local/lib/python3.9/threading.py", line 316 in wait File "/usr/local/lib/python3.9/queue.py", line 180 in get File "/usr/local/lib/python3.9/site-packages/telegram/ext/dispatcher.py", line 362 in start File "/usr/local/lib/python3.9/site-packages/telegram/ext/updater.py", line 236 in _thread_wrapper File "/usr/local/lib/python3.9/threading.py", line 910 in run File "/usr/local/lib/python3.9/threading.py", line 973 in _bootstrap_inner File "/usr/local/lib/python3.9/threading.py", line 930 in _bootstrap
Thread 0x00007f051a5a1b30 (most recent call first): File "/usr/local/lib/python3.9/threading.py", line 312 in wait File "/usr/local/lib/python3.9/threading.py", line 574 in wait File "/usr/local/lib/python3.9/site-packages/apscheduler/schedulers/blocking.py", line 28 in _main_loop File "/usr/local/lib/python3.9/threading.py", line 910 in run File "/usr/local/lib/python3.9/threading.py", line 973 in _bootstrap_inner File "/usr/local/lib/python3.9/threading.py", line 930 in _bootstrap
Thread 0x00007f051b6a6b30 (most recent call first): File "/usr/local/lib/python3.9/site-packages/paho/mqtt/client.py", line 1150 in _loop File "/usr/local/lib/python3.9/site-packages/paho/mqtt/client.py", line 1756 in loop_forever File "/usr/local/lib/python3.9/site-packages/paho/mqtt/client.py", line 3591 in _thread_main File "/usr/local/lib/python3.9/threading.py", line 910 in run File "/usr/local/lib/python3.9/threading.py", line 973 in _bootstrap_inner File "/usr/local/lib/python3.9/threading.py", line 930 in _bootstrap
Thread 0x00007f051ba2bb30 (most recent call first): File "/usr/local/lib/python3.9/concurrent/futures/thread.py", line 75 in _worker File "/usr/local/lib/python3.9/threading.py", line 910 in run File "/usr/local/lib/python3.9/threading.py", line 973 in _bootstrap_inner File "/usr/local/lib/python3.9/threading.py", line 930 in _bootstrap
Thread 0x00007f051bcf0b30 (most recent call first): File "/usr/local/lib/python3.9/site-packages/paho/mqtt/client.py", line 1150 in _loop File "/usr/local/lib/python3.9/site-packages/paho/mqtt/client.py", line 1756 in loop_forever File "/usr/local/lib/python3.9/site-packages/paho/mqtt/client.py", line 3591 in _thread_main File "/usr/local/lib/python3.9/threading.py", line 910 in run File "/usr/local/lib/python3.9/threading.py", line 973 in _bootstrap_inner File "/usr/local/lib/python3.9/threading.py", line 930 in _bootstrap
Thread 0x00007f051bdf5b30 (most recent call first): File "/usr/local/lib/python3.9/concurrent/futures/thread.py", line 75 in _worker File "/usr/local/lib/python3.9/threading.py", line 910 in run File "/usr/local/lib/python3.9/threading.py", line 973 in _bootstrap_inner File "/usr/local/lib/python3.9/threading.py", line 930 in _bootstrap
Hi @Gfkappa, could you take a look at https://github.com/home-assistant/core/issues/74606#issuecomment-1185305804 and also report back your memory trace? The errors you've shown in your log do not reflect the actual cause of the issue.
Hello, this is the HPY file content:
.loader: _load_stat
.format: SetFormat
.timemade: 1658137392.782600
.count: 4677
.size: 558947
.kindname:
.kindheader: Referrers by Kind (class / dict of class)
.numrows: 116
.r: 839 88494 dict (no owner)
.r: 516 70176 functools._lru_cache_wrapper
.r: 110 49320 types.CellType
.r: 211 46845
@Gfkappa weird question, do you use emojis in your automations at all? I was tracing an error last night that seemed to only be related to emojis and I am wondering if it could be related to this as the home assistant log gets crazy. I send emojis to my telegram bot.
@d0ugal hello, no I do not use emojis with telegram but I use JPG files via the following icon variable:
- service: notify.telegram_gfk
data:
title: '{{ states("sensor.assistente") }}'
message: "{{icon}} - {{title}} {{ now().strftime('%Y-%m-%d %H:%M:%S') }} - {{message}}"
Hello, I'm tring different things now and one seems working:
Installed last version: -Home Assistant 2022.7.5 -Supervisor 2022.07.0 -Frontend 20220707.1 - latest
Stopped the MariaDB component (v 2.5.0)
No restart anymore since more then 20 minutes.
Hello, system stable since I stopped MariaDB, I've tried to restart the component and the system reboot every 3 minutes.
Thanks in advance for your support.
I think this matches my investigation too. I was seeing errors related to the database. Sorry I’ve been very busy lately and not able to add my details. I’ll try and do that soon.
I also use mariadb and I’ve been stable since removing the emojis. I was seeing errors related to mixed encodings and there were some strange trace backs that got bigger and bigger each time.
I have managed to create a reproducer for this. This could probably be reduced and made smaller again - it is just based on a small part of my automations.
script:
debug_cause_problems:
alias: Debug Cause Problems
sequence:
- service: script.debug_telegram_send_message
data:
message: |-
🥶 it is cold!
debug_telegram_send_message:
alias: Debug Telegram send
mode: queued
variables:
enable_notification: False
sequence:
- service: telegram_bot.send_message
data:
message: "{{ message or 'Message missing' }}"
parse_mode: html
disable_notification: "{{ not enable_notification }}"
if I manually trigger the service script.debug_casue_problems
my home assistant will jump to 100% CPU and a few minutes later it will run out of memory.
This error seems to be the root casue.
2022-07-26 21:17:52 ERROR (Recorder) [homeassistant.components.recorder.core] Unhandled database error while processing task EventTask(event=<Event call_service[L]: domain=script, service=debug_telegram_send_message, service_data=message=🥶 it is cold!>): (MySQLdb.OperationalError) (1267, "Illegal mix of collations (utf8mb4_unicode_ci,IMPLICIT) and (utf8mb3_general_ci,COERCIBLE) for operation '='")
[SQL: SELECT event_data.data_id
FROM event_data
WHERE event_data.hash = %s AND event_data.shared_data = %s]
[parameters: (3257230980, '{"domain":"script","service":"debug_telegram_send_message","service_data":{"message":"🥶 it is cold!"}}')]
(Background on this error at: https://sqlalche.me/e/14/e3q8)
Traceback (most recent call last):
File "/usr/local/lib/python3.10/site-packages/sqlalchemy/engine/base.py", line 1819, in _execute_context
self.dialect.do_execute(
File "/usr/local/lib/python3.10/site-packages/sqlalchemy/engine/default.py", line 732, in do_execute
cursor.execute(statement, parameters)
File "/usr/local/lib/python3.10/site-packages/MySQLdb/cursors.py", line 206, in execute
res = self._query(query)
File "/usr/local/lib/python3.10/site-packages/MySQLdb/cursors.py", line 319, in _query
db.query(q)
File "/usr/local/lib/python3.10/site-packages/MySQLdb/connections.py", line 254, in query
_mysql.connection.query(self, query)
MySQLdb.OperationalError: (1267, "Illegal mix of collations (utf8mb4_unicode_ci,IMPLICIT) and (utf8mb3_general_ci,COERCIBLE) for operation '='")
The above exception was the direct cause of the following exception:
Traceback (most recent call last):
File "/usr/src/homeassistant/homeassistant/components/recorder/core.py", line 610, in _process_one_task_or_recover
return task.run(self)
File "/usr/src/homeassistant/homeassistant/components/recorder/tasks.py", line 211, in run
instance._process_one_event(self.event)
File "/usr/src/homeassistant/homeassistant/components/recorder/core.py", line 708, in _process_one_event
self._process_non_state_changed_event_into_session(event)
File "/usr/src/homeassistant/homeassistant/components/recorder/core.py", line 773, in _process_non_state_changed_event_into_session
if data_id := self._find_shared_data_in_db(data_hash, shared_data):
File "/usr/src/homeassistant/homeassistant/components/recorder/core.py", line 743, in _find_shared_data_in_db
if data_id := self.event_session.execute(
File "/usr/local/lib/python3.10/site-packages/sqlalchemy/orm/session.py", line 1712, in execute
result = conn._execute_20(statement, params or {}, execution_options)
File "/usr/local/lib/python3.10/site-packages/sqlalchemy/engine/base.py", line 1631, in _execute_20
return meth(self, args_10style, kwargs_10style, execution_options)
File "/usr/local/lib/python3.10/site-packages/sqlalchemy/sql/lambdas.py", line 516, in _execute_on_connection
return connection._execute_clauseelement(
File "/usr/local/lib/python3.10/site-packages/sqlalchemy/engine/base.py", line 1498, in _execute_clauseelement
ret = self._execute_context(
File "/usr/local/lib/python3.10/site-packages/sqlalchemy/engine/base.py", line 1862, in _execute_context
self._handle_dbapi_exception(
File "/usr/local/lib/python3.10/site-packages/sqlalchemy/engine/base.py", line 2043, in _handle_dbapi_exception
util.raise_(
File "/usr/local/lib/python3.10/site-packages/sqlalchemy/util/compat.py", line 208, in raise_
raise exception
File "/usr/local/lib/python3.10/site-packages/sqlalchemy/engine/base.py", line 1819, in _execute_context
self.dialect.do_execute(
File "/usr/local/lib/python3.10/site-packages/sqlalchemy/engine/default.py", line 732, in do_execute
cursor.execute(statement, parameters)
File "/usr/local/lib/python3.10/site-packages/MySQLdb/cursors.py", line 206, in execute
res = self._query(query)
File "/usr/local/lib/python3.10/site-packages/MySQLdb/cursors.py", line 319, in _query
db.query(q)
File "/usr/local/lib/python3.10/site-packages/MySQLdb/connections.py", line 254, in query
_mysql.connection.query(self, query)
sqlalchemy.exc.OperationalError: (MySQLdb.OperationalError) (1267, "Illegal mix of collations (utf8mb4_unicode_ci,IMPLICIT) and (utf8mb3_general_ci,COERCIBLE) for operation '='")
[SQL: SELECT event_data.data_id
FROM event_data
WHERE event_data.hash = %s AND event_data.shared_data = %s]
[parameters: (3257230980, '{"domain":"script","service":"debug_telegram_send_message","service_data":{"message":"🥶 it is cold!"}}')]
(Background on this error at: https://sqlalche.me/e/14/e3q8)
It doesn't seem to be that bad at first glace, but the error seems to constantly repeat with the traceback getting larger each time.
2022-07-26 21:17:52 ERROR (Recorder) [homeassistant.components.recorder.core] Unhandled database error while processing task EventTask(event=<Event system_log_event[L]: name=homeassistant.components.recorder.core, message=['Unhandled database error while processing task EventTask(event=<Event system_log_event[L]: name=homeassistant.components.recorder.core, message=[\'Unhandled database error while processing task EventTask(event=<Event system_log_event[L]: name=homeassistant.components.recorder.core, message=[\\\'Unhandled database error while processing task EventTask(event=<Event call_service[L]: domain=script, service=debug_telegram_send_message, service_data=message=🥶 it is cold!>): (MySQLdb.OperationalError) (1267, "Illegal mix of collations (utf8mb4_unicode_ci,IMPLICIT) and (utf8mb3_general_ci,COERCIBLE) for operation \\\\\\'=\\\\\\\'")\\\\n[SQL: SELECT event_data.data_id \\\\nFROM event_data \\\\nWHERE event_data.hash = %s AND event_data.shared_data = %s]\\\\n[parameters: (3257230980, \\\\\\\'{"domain":"script","service":"debug_telegram_send_message","service_data":{"message":"🥶 it is cold!"}}\\\\\\\')]\\\\n(Background on this error at: https://sqlalche.me/e/14/e3q8)\\\'], level=ERROR, source=[\\\'components/recorder/core.py\\\', 743], imestamp=1658911052.3394768, exception=Traceback (most recent call last):\\n File "/usr/local/lib/python3.10/site-packages/sqlalchemy/engine/base.py", line 1819, in _execute_context\\n self.dialect.do_execute(\\n File "/usr/local/lib/python3.10/site-packages/sqlalchemy/engine/default.py", line 732, in do_execute\\n cursor.execute(statement, parameters)\\n File "/usr/local/lib/python3.10/site-packages/MySQLdb/cursors.py", line 206, in execute\\n res = self._query(query)\\n File "/usr/local/lib/python3.10/site-packages/MySQLdb/cursors.py", line 319, in _query\\n db.query(q)\\n File "/usr/local/lib/python3.10/site-packages/MySQLdb/connections.py", line 254, in query\\n _mysql.connection.query(self, query)\\nMySQLdb.OperationalError: (1267, "Illegal mix of collations (utf8mb4_unicode_ci,IMPLICIT) and (utf8mb3_general_ci,COERCIBLE) for operation \\\'=\\\'")\\n\\nThe above exception was the direct cause of the following exception:\\n\\nTraceback (most recent call last):\\n File "/usr/src/homeassistant/homeassistant/components/recorder/core.py", line 610, in _process_one_task_or_recover\\n return task.run(self)\\n File "/usr/src/homeassistant/homeassistant/components/recorder/tasks.py", line 211, in run\\n instance._process_one_event(self.event)\\n File "/usr/src/homeassistant/homeassistant/components/recorder/core.py", line 708, in _process_one_event\\n self._process_non_state_changed_event_into_session(event)\\n File "/usr/src/homeassistant/homeassistant/components/recorder/core.py", line 773, in _process_non_state_changed_event_into_session\\n if data_id := self._find_shared_data_in_db(data_hash, shared_data):\\n File "/usr/src/homeassistant/homeassistant/components/recorder/core.py", line 743, in _find_shared_data_in_db\\n if data_id := self.event_session.execute(\\n File "/usr/local/lib/python3.10/site-packages/sqlalchemy/orm/session.py", line 1712, in execute\\n result = conn._execute_20(statement, params or {}, execution_options)\\n File "/usr/local/lib/python3.10/site-packages/sqlalchemy/engine/base.py", line 1631, in _execute_20\\n return meth(self, args_10style, kwargs_10style, execution_options)\\n File "/usr/local/lib/python3.10/site-packages/sqlalchemy/sql/lambdas.py", line 516, in _execute_on_connection\\n return connection._execute_clauseelement(\\n File "/usr/local/lib/python3.10/site-packages/sqlalchemy/engine/base.py", line 1498, in _execute_clauseelement\\n ret = self._execute_context(\\n File "/usr/local/lib/python3.10/site-packages/sqlalchemy/engine/base.py", line 1862, in _execute_context\\n self._handle_dbapi_exception(\\n File "/usr/local/lib/python3.10/site-packages/sqlalchemy/engine/base.py", line 2043, in _handle_dbapi_exception\\n util.raise_(\\n File "/usr/local/lib/python3.10/site-packages/sqlalchemy/util/compat.py", line 208, in raise_\\n raise exception\\n File "/usr/local/lib/python3.10/site-packages/sqlalchemy/engine/base.py", line 1819, in _execute_context\\n self.dialect.do_execute(\\n File "/usr/local/lib/python3.10/site-packages/sqlalchemy/engine/default.py", line 732, in do_execute\\n cursor.execute(statement, parameters)\\n File "/usr/local/lib/python3.10/site-packages/MySQLdb/cursors.py", line 206, in execute\\n res = self._query(query)\\n File "/usr/local/lib/python3.10/site-packages/MySQLdb/cursors.py", line 319, in _query\\n db.query(q)\\n File "/usr/local/lib/python3.10/site-packages/MySQLdb/connections.py", line 254, in query\\n _mysql.connection.query(self, query)\\nsqlalchemy.exc.OperationalError: (MySQLdb.OperationalError) (1267, "Illegal mix of collations (utf8mb4_unicode_ci,IMPLICIT) and (utf8mb3_general_ci,COERCIBLE) for operation \\\'=\\\'")\\n[SQL: SELECT event_data.data_id \\nFROM event_data \\nWHERE event_data.hash = %s AND event_data.shared_data = %s]\\n[parameters: (3257230980, \\\'{"domain":"script","service":"debug_telegram_send_message","service_data":{"message":"🥶 it is cold!"}}\\\')]\\n(Backgrund on this error at: https://sqlalche.me/e/14/e3q8)\\n, count=1, first_occurred=1658911052.3394768>): (MySQLdb.OperationalError) (1267, "Illegal mix of collations (utf8mb4_unicode_ci,IMPLICIT) and (utf8mb3_general_ci,COERCIBLE) for operation \\\'=\\\'")\\n[SQL: SELECT event_data.data_id \\nFROM event_data \\nWHERE event_data.hash = %s AND event_data.shared_data = %s]\\n[parameters: (3179095351, \\\'{"name":"homeassistant.components.recorder.core","message":["Unhandled database error while processing task EventTask(event=<Event call_service[L]: d ... (4728 characters truncated) ... essage\\\\\\\\":\\\\\\\\"🥶 it is cold!\\\\\\\"}}\\\\\\\')]\\\\\\\\n(Background on this error at: https://sqlalche.me/e/14/e3q8)\\\\\\\\n","count":1,"first_occurred":1658911052.3394768}\\\')]\\n(Background on this error at: https://sqlalche.me/e/14/e3q8)\'], level=ERROR, source=[\'components/recorder/core.py\', 743], timestamp=1658911052.3901663, exception=Traceback (most recent call last):\n File "/usr/local/lib/python3.10/site-packages/sqlalchemy/engine/base.py", line 1819, in _execute_context\n self.dialect.do_execute(\n File "/usr/local/lib/python3.10/site-packages/sqlalchemy/engine/default.py", line 732, in do_execute\n cursor.execute(statement, parameters)\n File "/usr/local/lib/python3.10/site-packages/MySQLdb/cursors.py", line 206, in execute\n res = self._query(query)\n File "/usr/local/lib/python3.10/site-packages/MySQLdb/cursors.py", line 319, in _query\n db.query(q)\n File "/usr/local/lib/python3.10/site-packages/MySQLdb/connections.py", line 254, in query\n _mysql.connection.query(self, query)\nMySQLdb.OperationalError: (1267, "Illegal mix of collations (utf8mb4_unicode_ci,IMPLICIT) and (utf8mb3_general_ci,COERCIBLE) for operation \'=\'")\n\nThe above exception was the direct cause of the following exception:\n\nTraceback (most recent call last):\n File "/usr/src/homeassistant/homeassistant/components/recorder/core.py", line 610, in _process_one_task_or_recover\n return task.run(self)\n File "/usr/src/homeassistant/homeassistant/components/recorder/tasks.py", line 211, in run\n instance._process_one_event(self.event)\n File "/usr/src/homeassistant/homeassistant/components/recorder/core.py", line 708, in _process_one_event\n self._process_non_state_changed_event_into_session(event)\n File "/usr/src/homeassistant/homeassistant/components/recorder/core.py", line 773, in _process_non_state_changed_event_into_session\n if data_id := self._find_shared_data_in_db(data_hash, shared_data):\n File "/usr/src/homeassistant/homeassistant/components/recorder/core.py", line 743, in _find_shared_data_in_db\n if data_id := self.event_session.execute(\n File "/usr/local/lib/python3.10/site-packages/sqlalchemy/orm/session.py", line 1712, in execute\n result = conn._execute_20(statement, params or {}, execution_options)\n File "/usr/local/lib/python3.10/site-packages/sqlalchemy/engine/base.py", line 1631, in _execute_20\n return meth(self, args_10style, kwargs_10style, execution_options)\n File "/usr/local/lib/python3.10/site-packages/sqlalchemy/sql/lambdas.py", line 516, in _execute_on_connection\n return connection._execute_clauseelement(\n File "/usr/local/lib/python3.10/site-packages/sqlalchemy/engine/base.py", line 1498, in _execute_clauseelement\n ret = self._execute_context(\n File "/usr/local/lib/python3.10/site-packages/sqlalchemy/engine/base.py", line 1862, in _execute_context\n self._handle_dbapi_exception(\n File "/usr/local/lib/python3.10/site-packages/sqlalchemy/engine/base.py", line 2043, in _handle_dbapi_exception\n util.raise_(\n File "/usr/local/lib/python3.10/site-packages/sqlalchemy/util/compat.py", line 208, in raise_\n raise exception\n File "/usr/local/lib/python3.10/site-packages/sqlalchemy/engine/base.py", line 1819, in _execute_context\n self.dialect.do_execute(\n File "/usr/local/lib/python3.10/site-packages/sqlalchemy/engine/default.py", line 732, in do_execute\n cursor.execute(statement, parameters)\n File "/usr/local/lib/python3.10/site-packages/MySQLdb/cursors.py", line 206, in execute\n res = self._query(query)\n File "/usr/local/lib/python3.10/site-packages/MySQLdb/cursors.py", line 319, in _query\n db.query(q)\n File "/usr/local/lib/python3.10/site-packages/MySQLdb/connections.py", line 254, in query\n _mysql.connection.query(self, query)\nsqlalchemy.exc.OperationalError: (MySQLdb.OperationalError) (1267, "Illegal mix of collations (utf8mb4_unicode_ci,IMPLICIT) and (utf8mb3_general_ci,COERCIBLE) for operation \'=\'")\n[SQL: SELECT event_data.data_id \nFROM event_data \nWHERE event_data.hash = %s AND event_data.shared_data = %s]\n[parameters: (3179095351, \'{"name":"homeassistant.components.recorder.core","message":["Unhandled database error while processing task EventTask(event=<Event call_service[L]: d ... (4728 characters truncated) ... essage\\\\":\\\\"🥶 it is cold!\\\\"}}\\\')]\\\\n(Background on this error at: https://sqlalche.me/e/14/e3q8)\\\\n","count":1,"first_occurred":658911052.3394768}\')]\n(Background on this error at: https://sqlalche.me/e/14/e3q8)\n, count=1, first_occurred=1658911052.3901663>): (MySQLdb.OperationalError) (1267, "Illegal mix of collations (utf8mb4_unicode_ci,IMPLICIT) and (utf8mb3_general_ci,COERCIBLE) for operation \'=\'")\n[SQL: SELECT event_data.data_id \nFROM event_data \nWHERE event_data.hash = %s AND event_data.shared_data = %s]\n[parameters: (1954235075, \'{"name":"homeassistant.components.recorder.core","message":["Unhandled database error while processing task EventTask(event=<Event system_log_event[L ... (10224 characters truncated) ... occurred\\\\":1658911052.3394768}\\\')]\\\\n(Background on this error at: https://sqlalche.me/e/14/e3q8)\\\\n","count":1,"first_occurred":1658911052.3901663}\')]\n(Background on this error at: https://sqlalche.me/e/14/e3q8)'], level=ERROR, source=['components/recorder/core.py', 743], timestamp=1658911052.4294298, exception=Traceback (most recent call last):
File "/usr/local/lib/python3.10/site-packages/sqlalchemy/engine/base.py", line 1819, in _execute_context
self.dialect.do_execute(
File "/usr/local/lib/python3.10/site-packages/sqlalchemy/engine/default.py", line 732, in do_execute
cursor.execute(statement, parameters)
File "/usr/local/lib/python3.10/site-packages/MySQLdb/cursors.py", line 206, in execute
res = self._query(query)
File "/usr/local/lib/python3.10/site-packages/MySQLdb/cursors.py", line 319, in _query
db.query(q)
File "/usr/local/lib/python3.10/site-packages/MySQLdb/connections.py", line 254, in query
_mysql.connection.query(self, query)
MySQLdb.OperationalError: (1267, "Illegal mix of collations (utf8mb4_unicode_ci,IMPLICIT) and (utf8mb3_general_ci,COERCIBLE) for operation '='")
Notice all the extra backslashes in that second traceback? Kinda hard to see because github doesn't wrap the code but seeing how far it scrolls left gives you a clue. Soon the log looks like this and it is kinda hard to get a reasonable paste...
I only triggered the service once in this test, but if it it is triggered a couple of times then memory is exhausted quickly. I tracked this down due to the recent heat wave causing an automation with a :hot_face: emoji to run more often and coincide with the OOMs. I thought it was due to my server getting hot at first! I used the cold face in my example here out of wishful thinking.
So, anyway, it seems like a MySQLdb.OperationalError is constantly retried in a loop somewhere and the select query shared_data
gets bigger each time until things eventually die.
My work around for now has been to remove emojis, which makes things stable but less fun. :broken_heart: :cry:
Nice work on digging through this @d0ugal!
There seems to be another issue relating to the MariaDB errors: #75126. Looks like they are onto something there.
Thanks @RoboMagus. I'll try their fix - it looks like it will do the job. I think there may still be a valid bug here though as home assistant shouldn't fail so badly for an exception like this. Maybe we can close this and move discussion to that bug.
I can confirm their fix solved it for me.
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.
The problem
After upgrade to 2022.7.0 the system restart every 3 minutes
What version of Home Assistant Core has the issue?
2022.7.0
What was the last working version of Home Assistant Core?
2022.6.7
What type of installation are you running?
Home Assistant OS
Integration causing the issue
No response
Link to integration documentation on our website
No response
Diagnostics information
No response
Example YAML snippet
No response
Anything in the logs that might be useful for us?
Additional information
No response