High cpu utilization since update 1.25.1
-
Hello,
First time publishing hereThe app is waiting for production, for now there is 0 user.
Since update 1.25.1 the CPU utilization is constantly at 62% (caused by the errors i got every 2 seconds i guess).
Here's the logs i have :
2024-07-31T07:12:30.000Z Traceback (most recent call last): 2024-07-31T07:12:30.000Z [2024-07-31 07:12:30,565] [INFO] [celery.beat] beat: Starting... 2024-07-31T07:12:30.000Z [2024-07-31 07:12:30,574] [CRITICAL] [celery.beat] beat raised exception <class '_dbm.error'>: error('cannot add item to database') 2024-07-31T07:12:30.000Z [2024-07-31 07:12:30,576] [WARNING] [celery.redirected] 2024-07-31T07:12:30.000Z [2024-07-31 07:12:30,576] [WARNING] [celery.redirected] File "/usr/lib/python3.10/shelve.py", line 111, in __getitem__ 2024-07-31T07:12:30.000Z [2024-07-31 07:12:30,576] [WARNING] [celery.redirected] KeyError 2024-07-31T07:12:30.000Z [2024-07-31 07:12:30,576] [WARNING] [celery.redirected] Traceback (most recent call last): 2024-07-31T07:12:30.000Z [2024-07-31 07:12:30,576] [WARNING] [celery.redirected] value = self.cache[key] ---- ... ---- 2024-07-31T07:12:30.000Z [2024-07-31 07:12:30,686] [WARNING] [celery.redirected] self[key] = entry 2024-07-31T07:12:30.000Z [2024-07-31 07:12:30,687] [WARNING] [celery.redirected] . 2024-07-31T07:12:30.000Z [2024-07-31 07:12:30,687] [WARNING] [celery.redirected] : 2024-07-31T07:12:30.000Z [2024-07-31 07:12:30,687] [WARNING] [celery.redirected] _dbm 2024-07-31T07:12:30.000Z [2024-07-31 07:12:30,687] [WARNING] [celery.redirected] cannot add item to database 2024-07-31T07:12:30.000Z [2024-07-31 07:12:30,687] [WARNING] [celery.redirected] error 2024-07-31T07:12:30.000Z [2024-07-31 07:12:30,687] [WARNING] [celery.redirected] self.dict[key.encode(self.keyencoding)] = f.getvalue() 2024-07-31T07:12:30.000Z __ - ... __ - _ 2024-07-31T07:12:30.000Z _dbm.error: cannot add item to database 2024-07-31T07:12:30.000Z celery beat v5.4.0 (opalescent) is starting. 2024-07-31T07:12:30.000Z f = BytesIO(self.dict[key.encode(self.keyencoding)]) 2024-07-31T07:12:30.000Z humanize_seconds(self.scheduler.max_interval)) 2024-07-31T07:12:30.000Z return self.get_scheduler() 2024-07-31T07:12:30.000Z return super().__get__(instance, owner) 2024-07-31T07:12:30.000Z return symbol_by_name(self.scheduler_cls, aliases=aliases)( 2024-07-31T07:12:30.000Z self._create_schedule() 2024-07-31T07:12:30.000Z self._store['entries'] 2024-07-31T07:12:30.000Z self._store['entries'] = {} 2024-07-31T07:12:30.000Z self.dict[key.encode(self.keyencoding)] = f.getvalue() 2024-07-31T07:12:30.000Z self.setup_schedule() 2024-07-31T07:12:30.000Z service.start() 2024-07-31T07:12:30.000Z super().__init__(*args, **kwargs) 2024-07-31T07:12:30.000Z val = self.func(instance) 2024-07-31T07:12:30.000Z value = self.cache[key]
Tell me if the whole log file is necessary.
I tried to restart the app, but didn't resolved my problem
If someone experienced the same problem can help me !Thanks
-
I'm running into the same high cpu usage too. @Purple8 did you report this upstream? If so, please share the ticket number/link.
-
Indeed, same issue here!
-
@joseph said in High cpu utilization since update 1.25.1:
@humptydumpty @imc67 is it constantly crashing with
KeyError
for you as well?No it never crashed but it has 4GB for its own
-
I kept the app running last night and the RAM has high"er" usage too. App has 2GB allocated and is using 600-700mb and 80-100% CPU when idle.
-
@humptydumpty Hi, no i did not beacause i couldn't reproduce the error after a reinstall.
-
-
@girish docker stats result in screenshot, it's high alright.
-
@humptydumpty next step would be to
docker exec -it 73c74bd70aef /bin/bash
(hopefully, I got the container name correct from the screenshot) and then run top and see which process is consuming so much CPU. Usually, > 100% means some process is taking one core completely. -
I tried to inspect the cloudron pid further, but the pid keeps changing.
-
@girish more info..
docker logs 73c74bd70aef | grep "celery beat"
full page w/ single repeating line
celery beat v5.4.0 (opalescent) is starting.
I also ran
docker logs 73c74bd70aef | grep celery
and saved it to a log file. I can't paste it anywhere as it's too long. Here's a sliver of the bottom portion.[2024-08-10 12:09:46,892] [WARNING] [celery.redirected] cannot add item to database [2024-08-10 12:09:46,953] [WARNING] [celery.redirected] Exception ignored in: [2024-08-10 12:09:46,954] [WARNING] [celery.redirected] <function Shelf.__del__ at 0x7ee070a90f70> [2024-08-10 12:09:46,954] [WARNING] [celery.redirected] Traceback (most recent call last): [2024-08-10 12:09:46,955] [WARNING] [celery.redirected] File "/usr/lib/python3.10/shelve.py", line 162, in __del__ [2024-08-10 12:09:46,955] [WARNING] [celery.redirected] [2024-08-10 12:09:46,955] [WARNING] [celery.redirected] self.close() [2024-08-10 12:09:46,955] [WARNING] [celery.redirected] File "/usr/lib/python3.10/shelve.py", line 144, in close [2024-08-10 12:09:46,955] [WARNING] [celery.redirected] [2024-08-10 12:09:46,956] [WARNING] [celery.redirected] self.sync() [2024-08-10 12:09:46,956] [WARNING] [celery.redirected] File "/usr/lib/python3.10/shelve.py", line 168, in sync [2024-08-10 12:09:46,956] [WARNING] [celery.redirected] [2024-08-10 12:09:46,956] [WARNING] [celery.redirected] self[key] = entry [2024-08-10 12:09:46,956] [WARNING] [celery.redirected] File "/usr/lib/python3.10/shelve.py", line 125, in __setitem__ [2024-08-10 12:09:46,957] [WARNING] [celery.redirected] [2024-08-10 12:09:46,957] [WARNING] [celery.redirected] self.dict[key.encode(self.keyencoding)] = f.getvalue() [2024-08-10 12:09:46,957] [WARNING] [celery.redirected] _dbm [2024-08-10 12:09:46,957] [WARNING] [celery.redirected] . [2024-08-10 12:09:46,957] [WARNING] [celery.redirected] error [2024-08-10 12:09:46,958] [WARNING] [celery.redirected] : [2024-08-10 12:09:46,958] [WARNING] [celery.redirected] cannot add item to database [2024-08-10 12:09:49,950] [DEBUG] [celery.utils.functional] def empty_trash(doc_ids=0): return 1 [2024-08-10 12:09:49,951] [DEBUG] [celery.utils.functional] def chunks(task, it, n): return 1 [2024-08-10 12:09:49,951] [DEBUG] [celery.utils.functional] def bulk_update_documents(document_ids): return 1 [2024-08-10 12:09:49,951] [DEBUG] [celery.utils.functional] def consume_file(self, input_doc, overrides=0): return 1 [2024-08-10 12:09:49,952] [DEBUG] [celery.utils.functional] def group(self, tasks, result, group_id, partial_args, add_to_parent=0): return 1 [2024-08-10 12:09:49,952] [DEBUG] [celery.utils.functional] def delete(doc_ids): return 1 [2024-08-10 12:09:49,953] [DEBUG] [celery.utils.functional] def index_optimize(): return 1 [2024-08-10 12:09:49,953] [DEBUG] [celery.utils.functional] def error_callback(request, exc, tb, rule_id, message_uid, message_subject, message_date): return 1 [2024-08-10 12:09:49,953] [DEBUG] [celery.utils.functional] def chain(*args, **kwargs): return 1 [2024-08-10 12:09:49,954] [DEBUG] [celery.utils.functional] def process_mail_accounts(): return 1 [2024-08-10 12:09:49,954] [DEBUG] [celery.utils.functional] def chord(self, header, body, partial_args=0, interval=1, countdown=2, max_retries=3, eager=4, **kwargs): return 1 [2024-08-10 12:09:49,955] [DEBUG] [celery.utils.functional] def accumulate(self, *args, **kwargs): return 1 [2024-08-10 12:09:49,955] [DEBUG] [celery.utils.functional] def update_document_archive_file(document_id): return 1 [2024-08-10 12:09:49,956] [DEBUG] [celery.utils.functional] def unlock_chord(self, group_id, callback, interval=0, max_retries=1, result=2, Result=3, GroupResult=4, result_from_tuple=5, **kwargs): return 1 [2024-08-10 12:09:49,956] [DEBUG] [celery.utils.functional] def backend_cleanup(): return 1 [2024-08-10 12:09:49,956] [DEBUG] [celery.utils.functional] def sanity_check(): return 1 [2024-08-10 12:09:49,957] [DEBUG] [celery.utils.functional] def xmap(task, it): return 1 [2024-08-10 12:09:49,957] [DEBUG] [celery.utils.functional] def train_classifier(): return 1 [2024-08-10 12:09:49,958] [DEBUG] [celery.utils.functional] def apply_mail_action(result, rule_id, message_uid, message_subject, message_date): return 1 [2024-08-10 12:09:49,958] [DEBUG] [celery.utils.functional] def xstarmap(task, it): return 1 [2024-08-10 12:09:49,972] [DEBUG] [celery.beat] Setting default socket timeout to 30 [2024-08-10 12:09:49,972] [INFO] [celery.beat] beat: Starting... [2024-08-10 12:09:49,982] [CRITICAL] [celery.beat] beat raised exception <class '_dbm.error'>: error('cannot add item to database') Traceback (most recent call last): File "/usr/lib/python3.10/shelve.py", line 111, in __getitem__ value = self.cache[key] KeyError: 'entries' During handling of the above exception, another exception occurred: Traceback (most recent call last): File "/usr/local/lib/python3.10/dist-packages/celery/beat.py", line 570, in _create_schedule self._store['entries'] File "/usr/lib/python3.10/shelve.py", line 113, in __getitem__ f = BytesIO(self.dict[key.encode(self.keyencoding)]) KeyError: b'entries' During handling of the above exception, another exception occurred: Traceback (most recent call last): File "/usr/local/lib/python3.10/dist-packages/celery/apps/beat.py", line 113, in start_scheduler service.start() File "/usr/local/lib/python3.10/dist-packages/celery/beat.py", line 634, in start humanize_seconds(self.scheduler.max_interval)) File "/usr/local/lib/python3.10/dist-packages/kombu/utils/objects.py", line 40, in __get__ return super().__get__(instance, owner) File "/usr/lib/python3.10/functools.py", line 981, in __get__ val = self.func(instance) File "/usr/local/lib/python3.10/dist-packages/celery/beat.py", line 677, in scheduler return self.get_scheduler() File "/usr/local/lib/python3.10/dist-packages/celery/beat.py", line 668, in get_scheduler return symbol_by_name(self.scheduler_cls, aliases=aliases)( File "/usr/local/lib/python3.10/dist-packages/celery/beat.py", line 513, in __init__ super().__init__(*args, **kwargs) File "/usr/local/lib/python3.10/dist-packages/celery/beat.py", line 264, in __init__ self.setup_schedule() File "/usr/local/lib/python3.10/dist-packages/celery/beat.py", line 541, in setup_schedule self._create_schedule() File "/usr/local/lib/python3.10/dist-packages/celery/beat.py", line 574, in _create_schedule self._store['entries'] = {} File "/usr/lib/python3.10/shelve.py", line 125, in __setitem__ self.dict[key.encode(self.keyencoding)] = f.getvalue() _dbm.error: cannot add item to database [2024-08-10 12:09:49,983] [WARNING] [celery.redirected] Traceback (most recent call last): [2024-08-10 12:09:49,983] [WARNING] [celery.redirected] File "/usr/lib/python3.10/shelve.py", line 111, in __getitem__ [2024-08-10 12:09:49,984] [WARNING] [celery.redirected] [2024-08-10 12:09:49,984] [WARNING] [celery.redirected] value = self.cache[key] [2024-08-10 12:09:49,984] [WARNING] [celery.redirected] KeyError [2024-08-10 12:09:49,984] [WARNING] [celery.redirected] : [2024-08-10 12:09:49,984] [WARNING] [celery.redirected] 'entries' [2024-08-10 12:09:49,984] [WARNING] [celery.redirected] During handling of the above exception, another exception occurred: [2024-08-10 12:09:49,985] [WARNING] [celery.redirected] Traceback (most recent call last): [2024-08-10 12:09:49,985] [WARNING] [celery.redirected] File "/usr/local/lib/python3.10/dist-packages/celery/beat.py", line 570, in _create_schedule [2024-08-10 12:09:49,985] [WARNING] [celery.redirected] [2024-08-10 12:09:49,985] [WARNING] [celery.redirected] self._store['entries'] [2024-08-10 12:09:49,985] [WARNING] [celery.redirected] File "/usr/lib/python3.10/shelve.py", line 113, in __getitem__ [2024-08-10 12:09:49,986] [WARNING] [celery.redirected] [2024-08-10 12:09:49,986] [WARNING] [celery.redirected] f = BytesIO(self.dict[key.encode(self.keyencoding)]) [2024-08-10 12:09:49,986] [WARNING] [celery.redirected] KeyError [2024-08-10 12:09:49,986] [WARNING] [celery.redirected] : [2024-08-10 12:09:49,986] [WARNING] [celery.redirected] b'entries' [2024-08-10 12:09:49,986] [WARNING] [celery.redirected] During handling of the above exception, another exception occurred: [2024-08-10 12:09:49,987] [WARNING] [celery.redirected] Traceback (most recent call last): [2024-08-10 12:09:49,987] [WARNING] [celery.redirected] File "/usr/local/bin/celery", line 8, in <module> [2024-08-10 12:09:49,987] [WARNING] [celery.redirected] [2024-08-10 12:09:49,987] [WARNING] [celery.redirected] sys.exit(main()) [2024-08-10 12:09:49,987] [WARNING] [celery.redirected] File "/usr/local/lib/python3.10/dist-packages/celery/__main__.py", line 15, in main [2024-08-10 12:09:49,988] [WARNING] [celery.redirected] [2024-08-10 12:09:49,988] [WARNING] [celery.redirected] sys.exit(_main()) [2024-08-10 12:09:49,988] [WARNING] [celery.redirected] File "/usr/local/lib/python3.10/dist-packages/celery/bin/celery.py", line 236, in main [2024-08-10 12:09:49,988] [WARNING] [celery.redirected] [2024-08-10 12:09:49,988] [WARNING] [celery.redirected] return celery(auto_envvar_prefix="CELERY") [2024-08-10 12:09:49,988] [WARNING] [celery.redirected] File "/usr/local/lib/python3.10/dist-packages/click/core.py", line 1157, in __call__ [2024-08-10 12:09:49,989] [WARNING] [celery.redirected] [2024-08-10 12:09:49,989] [WARNING] [celery.redirected] return self.main(*args, **kwargs) [2024-08-10 12:09:49,989] [WARNING] [celery.redirected] File "/usr/local/lib/python3.10/dist-packages/click/core.py", line 1078, in main [2024-08-10 12:09:49,990] [WARNING] [celery.redirected] [2024-08-10 12:09:49,990] [WARNING] [celery.redirected] rv = self.invoke(ctx) [2024-08-10 12:09:49,990] [WARNING] [celery.redirected] File "/usr/local/lib/python3.10/dist-packages/click/core.py", line 1688, in invoke [2024-08-10 12:09:49,990] [WARNING] [celery.redirected] [2024-08-10 12:09:49,990] [WARNING] [celery.redirected] return _process_result(sub_ctx.command.invoke(sub_ctx)) [2024-08-10 12:09:49,991] [WARNING] [celery.redirected] File "/usr/local/lib/python3.10/dist-packages/click/core.py", line 1434, in invoke [2024-08-10 12:09:49,991] [WARNING] [celery.redirected] [2024-08-10 12:09:49,991] [WARNING] [celery.redirected] return ctx.invoke(self.callback, **ctx.params) [2024-08-10 12:09:49,991] [WARNING] [celery.redirected] File "/usr/local/lib/python3.10/dist-packages/click/core.py", line 783, in invoke [2024-08-10 12:09:49,992] [WARNING] [celery.redirected] [2024-08-10 12:09:49,992] [WARNING] [celery.redirected] return __callback(*args, **kwargs) [2024-08-10 12:09:49,992] [WARNING] [celery.redirected] File "/usr/local/lib/python3.10/dist-packages/click/decorators.py", line 33, in new_func [2024-08-10 12:09:49,992] [WARNING] [celery.redirected] [2024-08-10 12:09:49,993] [WARNING] [celery.redirected] return f(get_current_context(), *args, **kwargs) [2024-08-10 12:09:49,993] [WARNING] [celery.redirected] File "/usr/local/lib/python3.10/dist-packages/celery/bin/base.py", line 135, in caller [2024-08-10 12:09:49,993] [WARNING] [celery.redirected] [2024-08-10 12:09:49,993] [WARNING] [celery.redirected] return f(ctx, *args, **kwargs) [2024-08-10 12:09:49,993] [WARNING] [celery.redirected] File "/usr/local/lib/python3.10/dist-packages/celery/bin/beat.py", line 72, in beat [2024-08-10 12:09:49,993] [WARNING] [celery.redirected] [2024-08-10 12:09:49,994] [WARNING] [celery.redirected] return beat().run() [2024-08-10 12:09:49,994] [WARNING] [celery.redirected] File "/usr/local/lib/python3.10/dist-packages/celery/apps/beat.py", line 84, in run [2024-08-10 12:09:49,994] [WARNING] [celery.redirected] [2024-08-10 12:09:49,994] [WARNING] [celery.redirected] self.start_scheduler() [2024-08-10 12:09:49,994] [WARNING] [celery.redirected] File "/usr/local/lib/python3.10/dist-packages/celery/apps/beat.py", line 113, in start_scheduler [2024-08-10 12:09:49,995] [WARNING] [celery.redirected] [2024-08-10 12:09:49,995] [WARNING] [celery.redirected] service.start() [2024-08-10 12:09:49,995] [WARNING] [celery.redirected] File "/usr/local/lib/python3.10/dist-packages/celery/beat.py", line 634, in start [2024-08-10 12:09:49,995] [WARNING] [celery.redirected] [2024-08-10 12:09:49,995] [WARNING] [celery.redirected] humanize_seconds(self.scheduler.max_interval)) [2024-08-10 12:09:49,996] [WARNING] [celery.redirected] File "/usr/local/lib/python3.10/dist-packages/kombu/utils/objects.py", line 40, in __get__ [2024-08-10 12:09:49,996] [WARNING] [celery.redirected] [2024-08-10 12:09:49,996] [WARNING] [celery.redirected] return super().__get__(instance, owner) [2024-08-10 12:09:49,996] [WARNING] [celery.redirected] File "/usr/lib/python3.10/functools.py", line 981, in __get__ [2024-08-10 12:09:49,997] [WARNING] [celery.redirected] [2024-08-10 12:09:49,997] [WARNING] [celery.redirected] val = self.func(instance) [2024-08-10 12:09:49,997] [WARNING] [celery.redirected] File "/usr/local/lib/python3.10/dist-packages/celery/beat.py", line 677, in scheduler [2024-08-10 12:09:49,997] [WARNING] [celery.redirected] [2024-08-10 12:09:49,997] [WARNING] [celery.redirected] return self.get_scheduler() [2024-08-10 12:09:49,997] [WARNING] [celery.redirected] File "/usr/local/lib/python3.10/dist-packages/celery/beat.py", line 668, in get_scheduler [2024-08-10 12:09:49,998] [WARNING] [celery.redirected] [2024-08-10 12:09:49,998] [WARNING] [celery.redirected] return symbol_by_name(self.scheduler_cls, aliases=aliases)( [2024-08-10 12:09:49,998] [WARNING] [celery.redirected] File "/usr/local/lib/python3.10/dist-packages/celery/beat.py", line 513, in __init__ [2024-08-10 12:09:49,998] [WARNING] [celery.redirected] [2024-08-10 12:09:49,999] [WARNING] [celery.redirected] super().__init__(*args, **kwargs) [2024-08-10 12:09:49,999] [WARNING] [celery.redirected] File "/usr/local/lib/python3.10/dist-packages/celery/beat.py", line 264, in __init__ [2024-08-10 12:09:49,999] [WARNING] [celery.redirected] [2024-08-10 12:09:49,999] [WARNING] [celery.redirected] self.setup_schedule() [2024-08-10 12:09:49,999] [WARNING] [celery.redirected] File "/usr/local/lib/python3.10/dist-packages/celery/beat.py", line 541, in setup_schedule [2024-08-10 12:09:50,000] [WARNING] [celery.redirected] [2024-08-10 12:09:50,000] [WARNING] [celery.redirected] self._create_schedule() [2024-08-10 12:09:50,000] [WARNING] [celery.redirected] File "/usr/local/lib/python3.10/dist-packages/celery/beat.py", line 574, in _create_schedule [2024-08-10 12:09:50,000] [WARNING] [celery.redirected] [2024-08-10 12:09:50,000] [WARNING] [celery.redirected] self._store['entries'] = {} [2024-08-10 12:09:50,001] [WARNING] [celery.redirected] File "/usr/lib/python3.10/shelve.py", line 125, in __setitem__ [2024-08-10 12:09:50,001] [WARNING] [celery.redirected] [2024-08-10 12:09:50,001] [WARNING] [celery.redirected] self.dict[key.encode(self.keyencoding)] = f.getvalue() [2024-08-10 12:09:50,001] [WARNING] [celery.redirected] _dbm [2024-08-10 12:09:50,001] [WARNING] [celery.redirected] . [2024-08-10 12:09:50,002] [WARNING] [celery.redirected] error [2024-08-10 12:09:50,002] [WARNING] [celery.redirected] : [2024-08-10 12:09:50,002] [WARNING] [celery.redirected] cannot add item to database [2024-08-10 12:09:50,059] [WARNING] [celery.redirected] Exception ignored in: [2024-08-10 12:09:50,059] [WARNING] [celery.redirected] <function Shelf.__del__ at 0x7bef67d94f70> [2024-08-10 12:09:50,059] [WARNING] [celery.redirected] Traceback (most recent call last): [2024-08-10 12:09:50,059] [WARNING] [celery.redirected] File "/usr/lib/python3.10/shelve.py", line 162, in __del__ [2024-08-10 12:09:50,060] [WARNING] [celery.redirected] [2024-08-10 12:09:50,060] [WARNING] [celery.redirected] self.close() [2024-08-10 12:09:50,060] [WARNING] [celery.redirected] File "/usr/lib/python3.10/shelve.py", line 144, in close [2024-08-10 12:09:50,060] [WARNING] [celery.redirected] [2024-08-10 12:09:50,061] [WARNING] [celery.redirected] self.sync() [2024-08-10 12:09:50,061] [WARNING] [celery.redirected] File "/usr/lib/python3.10/shelve.py", line 168, in sync [2024-08-10 12:09:50,061] [WARNING] [celery.redirected] [2024-08-10 12:09:50,061] [WARNING] [celery.redirected] self[key] = entry [2024-08-10 12:09:50,061] [WARNING] [celery.redirected] File "/usr/lib/python3.10/shelve.py", line 125, in __setitem__ [2024-08-10 12:09:50,062] [WARNING] [celery.redirected] [2024-08-10 12:09:50,062] [WARNING] [celery.redirected] self.dict[key.encode(self.keyencoding)] = f.getvalue() [2024-08-10 12:09:50,062] [WARNING] [celery.redirected] _dbm [2024-08-10 12:09:50,062] [WARNING] [celery.redirected] . [2024-08-10 12:09:50,062] [WARNING] [celery.redirected] error [2024-08-10 12:09:50,062] [WARNING] [celery.redirected] : [2024-08-10 12:09:50,063] [WARNING] [celery.redirected] cannot add item to database
-
This very much reads like task tries to work a job which then fails due to a database conflict. Since that job never finishes it just retries in a loop. I think it is worth if you report this upstream as it kinda seems like a regression in the app itself.
-
Upstream ticket opened here: https://github.com/paperless-ngx/paperless-ngx/issues/7439