DB write errors with recent paperless version

[Meuschke]

Since 08.09.2024, my Logs get spammed with Errors:

2024-09-08T21:53:13.000Z 527:C 08 Sep 2024 21:53:13.508 * Fork CoW for RDB: current 0 MB, peak 0 MB, average 0 MB
2024-09-08T22:00:02.000Z 2024-09-08 22:00:02,760 INFO spawned: 'paperless-scheduler.service' with pid 2819464
2024-09-08T22:00:03.000Z 2024-09-08 22:00:03,761 INFO success: paperless-scheduler.service entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2024-09-08T22:00:04.000Z 
2024-09-08T22:00:04.000Z 
2024-09-08T22:00:04.000Z 
2024-09-08T22:00:04.000Z 
2024-09-08T22:00:04.000Z During handling of the above exception, another exception occurred:
2024-09-08T22:00:04.000Z During handling of the above exception, another exception occurred:
2024-09-08T22:00:04.000Z During handling of the above exception, another exception occurred:
2024-09-08T22:00:04.000Z During handling of the above exception, another exception occurred:
2024-09-08T22:00:04.000Z File "/usr/lib/python3.10/functools.py", line 981, in __get__
2024-09-08T22:00:04.000Z File "/usr/lib/python3.10/shelve.py", line 111, in __getitem__
2024-09-08T22:00:04.000Z File "/usr/lib/python3.10/shelve.py", line 113, in __getitem__
2024-09-08T22:00:04.000Z File "/usr/lib/python3.10/shelve.py", line 125, in __setitem__
2024-09-08T22:00:04.000Z File "/usr/local/lib/python3.10/dist-packages/celery/apps/beat.py", line 113, in start_scheduler
2024-09-08T22:00:04.000Z File "/usr/local/lib/python3.10/dist-packages/celery/beat.py", line 264, in __init__
2024-09-08T22:00:04.000Z File "/usr/local/lib/python3.10/dist-packages/celery/beat.py", line 513, in __init__
2024-09-08T22:00:04.000Z File "/usr/local/lib/python3.10/dist-packages/celery/beat.py", line 541, in setup_schedule
2024-09-08T22:00:04.000Z File "/usr/local/lib/python3.10/dist-packages/celery/beat.py", line 570, in _create_schedule
2024-09-08T22:00:04.000Z File "/usr/local/lib/python3.10/dist-packages/celery/beat.py", line 574, in _create_schedule
2024-09-08T22:00:04.000Z File "/usr/local/lib/python3.10/dist-packages/celery/beat.py", line 634, in start
2024-09-08T22:00:04.000Z File "/usr/local/lib/python3.10/dist-packages/celery/beat.py", line 668, in get_scheduler
2024-09-08T22:00:04.000Z File "/usr/local/lib/python3.10/dist-packages/celery/beat.py", line 677, in scheduler
2024-09-08T22:00:04.000Z File "/usr/local/lib/python3.10/dist-packages/kombu/utils/objects.py", line 40, in __get__
2024-09-08T22:00:04.000Z KeyError: 'entries'
2024-09-08T22:00:04.000Z KeyError: b'entries'
2024-09-08T22:00:04.000Z Traceback (most recent call last):
2024-09-08T22:00:04.000Z Traceback (most recent call last):
2024-09-08T22:00:04.000Z Traceback (most recent call last):
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,954] [INFO] [celery.beat] beat: Starting...
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,964] [CRITICAL] [celery.beat] beat raised exception <class '_dbm.error'>: error('cannot add item to database')
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,965] [WARNING] [celery.redirected]   File "/usr/lib/python3.10/shelve.py", line 111, in __getitem__
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,965] [WARNING] [celery.redirected] Traceback (most recent call last):
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,966] [WARNING] [celery.redirected]
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,966] [WARNING] [celery.redirected]
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,966] [WARNING] [celery.redirected] 'entries'
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,966] [WARNING] [celery.redirected] :
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,966] [WARNING] [celery.redirected] KeyError
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,966] [WARNING] [celery.redirected] value = self.cache[key]
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,967] [WARNING] [celery.redirected]
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,967] [WARNING] [celery.redirected]
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,967] [WARNING] [celery.redirected]   File "/usr/lib/python3.10/shelve.py", line 113, in __getitem__
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,967] [WARNING] [celery.redirected]   File "/usr/local/lib/python3.10/dist-packages/celery/beat.py", line 570, in _create_schedule
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,967] [WARNING] [celery.redirected] Traceback (most recent call last):
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,967] [WARNING] [celery.redirected] self._store['entries']
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,968] [WARNING] [celery.redirected]
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,968] [WARNING] [celery.redirected]   File "/usr/local/bin/celery", line 8, in <module>
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,968] [WARNING] [celery.redirected] :
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,968] [WARNING] [celery.redirected] KeyError
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,968] [WARNING] [celery.redirected] Traceback (most recent call last):
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,968] [WARNING] [celery.redirected] b'entries'
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,968] [WARNING] [celery.redirected] f = BytesIO(self.dict[key.encode(self.keyencoding)])
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,969] [WARNING] [celery.redirected]
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,969] [WARNING] [celery.redirected]
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,969] [WARNING] [celery.redirected]   File "/usr/local/lib/python3.10/dist-packages/celery/__main__.py", line 15, in main
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,969] [WARNING] [celery.redirected]   File "/usr/local/lib/python3.10/dist-packages/celery/bin/celery.py", line 236, in main
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,969] [WARNING] [celery.redirected] sys.exit(_main())
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,969] [WARNING] [celery.redirected] sys.exit(main())
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,970] [WARNING] [celery.redirected]
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,970] [WARNING] [celery.redirected]
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,970] [WARNING] [celery.redirected]   File "/usr/local/lib/python3.10/dist-packages/click/core.py", line 1078, in main
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,970] [WARNING] [celery.redirected]   File "/usr/local/lib/python3.10/dist-packages/click/core.py", line 1157, in __call__
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,970] [WARNING] [celery.redirected] return celery(auto_envvar_prefix="CELERY")
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,970] [WARNING] [celery.redirected] return self.main(*args, **kwargs)
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,971] [WARNING] [celery.redirected]
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,971] [WARNING] [celery.redirected]   File "/usr/local/lib/python3.10/dist-packages/click/core.py", line 1688, in invoke
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,971] [WARNING] [celery.redirected] rv = self.invoke(ctx)
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,972] [WARNING] [celery.redirected]
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,972] [WARNING] [celery.redirected]
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,972] [WARNING] [celery.redirected]   File "/usr/local/lib/python3.10/dist-packages/click/core.py", line 1434, in invoke
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,972] [WARNING] [celery.redirected]   File "/usr/local/lib/python3.10/dist-packages/click/core.py", line 783, in invoke
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,972] [WARNING] [celery.redirected] return _process_result(sub_ctx.command.invoke(sub_ctx))
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,972] [WARNING] [celery.redirected] return ctx.invoke(self.callback, **ctx.params)
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,973] [WARNING] [celery.redirected]
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,973] [WARNING] [celery.redirected]
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,973] [WARNING] [celery.redirected]   File "/usr/local/lib/python3.10/dist-packages/celery/bin/base.py", line 135, in caller
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,973] [WARNING] [celery.redirected]   File "/usr/local/lib/python3.10/dist-packages/click/decorators.py", line 33, in new_func
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,973] [WARNING] [celery.redirected] return __callback(*args, **kwargs)
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,973] [WARNING] [celery.redirected] return f(get_current_context(), *args, **kwargs)
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,974] [WARNING] [celery.redirected]
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,974] [WARNING] [celery.redirected]
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,974] [WARNING] [celery.redirected]   File "/usr/local/lib/python3.10/dist-packages/celery/apps/beat.py", line 84, in run
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,974] [WARNING] [celery.redirected]   File "/usr/local/lib/python3.10/dist-packages/celery/bin/beat.py", line 72, in beat
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,974] [WARNING] [celery.redirected] return beat().run()
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,974] [WARNING] [celery.redirected] return f(ctx, *args, **kwargs)
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,975] [WARNING] [celery.redirected]
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,975] [WARNING] [celery.redirected]
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,975] [WARNING] [celery.redirected]   File "/usr/local/lib/python3.10/dist-packages/celery/apps/beat.py", line 113, in start_scheduler
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,975] [WARNING] [celery.redirected]   File "/usr/local/lib/python3.10/dist-packages/celery/beat.py", line 634, in start
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,975] [WARNING] [celery.redirected] self.start_scheduler()
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,975] [WARNING] [celery.redirected] service.start()
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,976] [WARNING] [celery.redirected]
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,976] [WARNING] [celery.redirected]
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,976] [WARNING] [celery.redirected]   File "/usr/lib/python3.10/functools.py", line 981, in __get__
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,976] [WARNING] [celery.redirected]   File "/usr/local/lib/python3.10/dist-packages/kombu/utils/objects.py", line 40, in __get__
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,976] [WARNING] [celery.redirected] humanize_seconds(self.scheduler.max_interval))
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,976] [WARNING] [celery.redirected] return super().__get__(instance, owner)
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,977] [WARNING] [celery.redirected]
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,977] [WARNING] [celery.redirected]
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,977] [WARNING] [celery.redirected]   File "/usr/local/lib/python3.10/dist-packages/celery/beat.py", line 677, in scheduler
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,977] [WARNING] [celery.redirected] val = self.func(instance)
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,978] [WARNING] [celery.redirected]
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,978] [WARNING] [celery.redirected]
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,978] [WARNING] [celery.redirected]   File "/usr/local/lib/python3.10/dist-packages/celery/beat.py", line 513, in __init__
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,978] [WARNING] [celery.redirected]   File "/usr/local/lib/python3.10/dist-packages/celery/beat.py", line 668, in get_scheduler
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,978] [WARNING] [celery.redirected] return self.get_scheduler()
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,978] [WARNING] [celery.redirected] return symbol_by_name(self.scheduler_cls, aliases=aliases)(
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,979] [WARNING] [celery.redirected]
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,979] [WARNING] [celery.redirected]   File "/usr/local/lib/python3.10/dist-packages/celery/beat.py", line 264, in __init__
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,979] [WARNING] [celery.redirected]   File "/usr/local/lib/python3.10/dist-packages/celery/beat.py", line 541, in setup_schedule
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,979] [WARNING] [celery.redirected] self.setup_schedule()
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,979] [WARNING] [celery.redirected] super().__init__(*args, **kwargs)
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,980] [WARNING] [celery.redirected]
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,980] [WARNING] [celery.redirected]
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,980] [WARNING] [celery.redirected]   File "/usr/local/lib/python3.10/dist-packages/celery/beat.py", line 574, in _create_schedule
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,980] [WARNING] [celery.redirected] self._create_schedule()
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,980] [WARNING] [celery.redirected] self._store['entries'] = {}
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,981] [WARNING] [celery.redirected]
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,981] [WARNING] [celery.redirected]   File "/usr/lib/python3.10/shelve.py", line 125, in __setitem__
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,981] [WARNING] [celery.redirected] .
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,981] [WARNING] [celery.redirected] _dbm
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,981] [WARNING] [celery.redirected] error
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,981] [WARNING] [celery.redirected] self.dict[key.encode(self.keyencoding)] = f.getvalue()
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,982] [WARNING] [celery.redirected] :
2024-09-08T22:00:04.000Z [2024-09-09 00:00:04,982] [WARNING] [celery.redirected] cannot add item to database
2024-09-08T22:00:04.000Z _dbm.error: cannot add item to database
2024-09-08T22:00:04.000Z f = BytesIO(self.dict[key.encode(self.keyencoding)])
2024-09-08T22:00:04.000Z humanize_seconds(self.scheduler.max_interval))
2024-09-08T22:00:04.000Z return self.get_scheduler()
2024-09-08T22:00:04.000Z return super().__get__(instance, owner)
2024-09-08T22:00:04.000Z return symbol_by_name(self.scheduler_cls, aliases=aliases)(
2024-09-08T22:00:04.000Z self._create_schedule()
2024-09-08T22:00:04.000Z self._store['entries']
2024-09-08T22:00:04.000Z self._store['entries'] = {}
2024-09-08T22:00:04.000Z self.dict[key.encode(self.keyencoding)] = f.getvalue()
2024-09-08T22:00:04.000Z self.setup_schedule()
2024-09-08T22:00:04.000Z service.start()
2024-09-08T22:00:04.000Z super().__init__(*args, **kwargs)
2024-09-08T22:00:04.000Z val = self.func(instance)
2024-09-08T22:00:04.000Z value = self.cache[key]
2024-09-08T22:00:05.000Z . broker -> redis://redis-4e44cb59-f283-4ea3-83be-781fa795cfe5:6379//
2024-09-08T22:00:05.000Z . db -> /app/data/data/celerybeat-schedule.db
2024-09-08T22:00:05.000Z . loader -> celery.loaders.app.AppLoader
2024-09-08T22:00:05.000Z . logfile -> [stderr]@%INFO
2024-09-08T22:00:05.000Z . maxinterval -> 5.00 minutes (300s)
2024-09-08T22:00:05.000Z . scheduler -> celery.beat.PersistentScheduler
2024-09-08T22:00:05.000Z 2024-09-08 22:00:05,426 INFO exited: paperless-scheduler.service (exit status 1; not expected)
2024-09-08T22:00:05.000Z Configuration ->
2024-09-08T22:00:05.000Z LocalTime -> 2024-09-09 00:00:04
2024-09-08T22:00:05.000Z [2024-09-09 00:00:05,074] [WARNING] [celery.redirected]   File "/usr/lib/python3.10/shelve.py", line 162, in __del__
2024-09-08T22:00:05.000Z [2024-09-09 00:00:05,074] [WARNING] [celery.redirected] <function Shelf.__del__ at 0x7ff6952b0f70>
2024-09-08T22:00:05.000Z [2024-09-09 00:00:05,074] [WARNING] [celery.redirected] Exception ignored in:
2024-09-08T22:00:05.000Z [2024-09-09 00:00:05,074] [WARNING] [celery.redirected] Traceback (most recent call last):
2024-09-08T22:00:05.000Z [2024-09-09 00:00:05,075] [WARNING] [celery.redirected]
2024-09-08T22:00:05.000Z [2024-09-09 00:00:05,075] [WARNING] [celery.redirected]   File "/usr/lib/python3.10/shelve.py", line 144, in close
2024-09-08T22:00:05.000Z [2024-09-09 00:00:05,075] [WARNING] [celery.redirected] self.close()
2024-09-08T22:00:05.000Z [2024-09-09 00:00:05,076] [WARNING] [celery.redirected]
2024-09-08T22:00:05.000Z [2024-09-09 00:00:05,076] [WARNING] [celery.redirected]
2024-09-08T22:00:05.000Z [2024-09-09 00:00:05,076] [WARNING] [celery.redirected]   File "/usr/lib/python3.10/shelve.py", line 125, in __setitem__
2024-09-08T22:00:05.000Z [2024-09-09 00:00:05,076] [WARNING] [celery.redirected]   File "/usr/lib/python3.10/shelve.py", line 168, in sync
2024-09-08T22:00:05.000Z [2024-09-09 00:00:05,076] [WARNING] [celery.redirected] self.sync()
2024-09-08T22:00:05.000Z [2024-09-09 00:00:05,076] [WARNING] [celery.redirected] self[key] = entry
2024-09-08T22:00:05.000Z [2024-09-09 00:00:05,077] [WARNING] [celery.redirected]
2024-09-08T22:00:05.000Z [2024-09-09 00:00:05,077] [WARNING] [celery.redirected] .
2024-09-08T22:00:05.000Z [2024-09-09 00:00:05,077] [WARNING] [celery.redirected] :
2024-09-08T22:00:05.000Z [2024-09-09 00:00:05,077] [WARNING] [celery.redirected] _dbm
2024-09-08T22:00:05.000Z [2024-09-09 00:00:05,077] [WARNING] [celery.redirected] cannot add item to database
2024-09-08T22:00:05.000Z [2024-09-09 00:00:05,077] [WARNING] [celery.redirected] error
2024-09-08T22:00:05.000Z [2024-09-09 00:00:05,077] [WARNING] [celery.redirected] self.dict[key.encode(self.keyencoding)] = f.getvalue()
2024-09-08T22:00:05.000Z __    -    ... __   -        _
2024-09-08T22:00:05.000Z celery beat v5.4.0 (opalescent) is starting.
2024-09-08T22:00:06.000Z 2024-09-08 22:00:06,430 INFO spawned: 'paperless-scheduler.service' with pid 2819511
2024-09-08T22:00:07.000Z 2024-09-08 22:00:07,432 INFO success: paperless-scheduler.service entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2024-09-08T22:00:08.000Z 
2024-09-08T22:00:08.000Z 
2024-09-08T22:00:08.000Z 
2024-09-08T22:00:08.000Z 
2024-09-08T22:00:08.000Z . broker -> redis://redis-4e44cb59-f283-4ea3-83be-781fa795cfe5:6379//
2024-09-08T22:00:08.000Z . db -> /app/data/data/celerybeat-schedule.db
2024-09-08T22:00:08.000Z . loader -> celery.loaders.app.AppLoader
2024-09-08T22:00:08.000Z . logfile -> [stderr]@%INFO
2024-09-08T22:00:08.000Z . maxinterval -> 5.00 minutes (300s)
2024-09-08T22:00:08.000Z . scheduler -> celery.beat.PersistentScheduler
2024-09-08T22:00:08.000Z Configuration ->
2024-09-08T22:00:08.000Z During handling of the above exception, another exception occurred:
2024-09-08T22:00:08.000Z During handling of the above exception, another exception occurred:
2024-09-08T22:00:08.000Z During handling of the above exception, another exception occurred:
2024-09-08T22:00:08.000Z During handling of the above exception, another exception occurred:

Has anyone similar problems? Tool seems to work stable, but my logs exploding.

Performance stats seems normal:

Best Regards
Meuschke

[nebulon]

This seems to be the same as https://forum.cloudron.io/topic/12412/celery-stuck-in-restarting-loop/2 and https://forum.cloudron.io/topic/12195/high-cpu-utilization-since-update-1-25-1/18

I will lock this in favor of the others.