High cpu utilization since update 1.25.1

[humptydumpty]

@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

[nebulon]

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.

[humptydumpty]

Upstream ticket opened here: https://github.com/paperless-ngx/paperless-ngx/issues/7439

[humptydumpty]

@nebulon upstream closed the ticket and said the following:

Perhaps a better question for cloudron not a bug report here. Memory yes, 100% CPU, no.

I appreciate that cloud hosting companies tend to push users to the project itself but since the only people having this problem are those hosting on cloudron (there have been no similar reports lately and I think there would be since it sounds like the app is effectively broken) I think the more logical conclusion is that this is a cloudron issue not a paperless one.

Could you please get in touch with them and sort this out?

[niquon]

Googling this suggests trying to remove a corrupted file eg data/celerybeat.db

https://stackoverflow.com/questions/12362045/django-celery-error-when-starting-celerybeat-cannot-add-item-to-database

[humptydumpty]

Shoutout to stumpylog (paperless maintainer) for the fix. Using the file manager, browse to /app/data/data and delete celerybeat-schedule.db.db and restart the server app. CPU usage went down for me. Hopefully, it stays that way.

[imc67]

@humptydumpty said in High cpu utilization since update 1.25.1:

Shoutout to stumpylog (paperless maintainer) for the fix. Using the file manager, browse to /app/data/data and delete celerybeat-schedule.db.db and restart the server app. CPU usage went down for me. Hopefully, it stays that way.

This solution solved the issue for me! Thanks!!

[necrevistonnezr]

@humptydumpty said in High cpu utilization since update 1.25.1:

Shoutout to stumpylog (paperless maintainer) for the fix. Using the file manager, browse to /app/data/data and delete celerybeat-schedule.db.db and restart the server app. CPU usage went down for me. Hopefully, it stays that way.

So it was not a Cloudron issue in the end?

[humptydumpty]

@necrevistonnezr we still don’t know the root cause of the file corruption. It could happen again anytime. Upstream closed the discussion and moved on. It looks like only Cloudron users are affected on existing installs and not on a fresh app. App update snafu?

Btw, upstream said the +500mb ram on idle is normal. I don’t get why it should be that high.

[humptydumpty]

@nebulon I uploaded the corrupted db file upstream as requested.. edit: just realized I can copy the github link https://github.com/user-attachments/files/16591433/celerybeat-schedule.db.zip

I'll keep the cloned app for the time being. Please let me know if you need more info.

[humptydumpty]

CPU is high again on Paperless-ngx 2.11.6. Deleting the celery file and restarting still works as a temp fix. I did turn off the server today and updated the BIOS. Idk if that has anything to do with it.

[wheez]

Do we know by now what is causing this problem? I have had it for the second time today. Last time about a Month ago. The fix worked in both cases but I guess it would still be interesting to know why this is happening.

[humptydumpty]

It's going nuts again after it updated to 1.27 then 1.28 today.

edit: This time I had to delete the celery file and restart the app twice for the fix to work.

[humptydumpty]

Just an FYI, it's still recurring on v.1.3.2.

[flwd]

Same issue for me. I ran cloudron as a VM on unraid and on proxmox, on 2 different hosts and with and without a CIFS mount as consume folder. The issue recurred in every constellation.

[joseph]

@flwd said in High cpu utilization since update 1.25.1:

The issue recurred in every constellation

What does this mean?

[jdaviescoates]

@joseph installation typo would be my guess

[flwd]

@joseph it occured in every installation variant i tried, independant of the CIFS mount and config.

[joseph]

@flwd thanks for the clarification. I think the original issue atleast was narrowed down to celery database going corrupt and it's not related to volume type. Have you tried deleting that database pointed out earlier in the thread?

[flwd]

@joseph yes, deleting the database fixes the problem temporarily.