search

etesync / etesync-dav

This is a CalDAV and CardDAV adapter for EteSync
https://www.etesync.com
GNU General Public License v3.0
298 stars 51 forks source link

sqlite3.OperationalError: database is locked #240

Open stuart12 opened 2 years ago

stuart12 commented 2 years ago

hello, I am trying to debug https://github.com/etesync/etesync-dav/issues/206 and am being distracted by database is locked error messages. I am just importing, modifying and deleting calendar entries from a single Thunderbird instance.

[2021-12-18 15:17:29 +1100] [48911/Thread-3] [ERROR] An exception occurred during PUT request on '/stuart/J_NqYUidGenForSVT@vtlhl5.sabre.com.ics': database is locked
Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/peewee.py", line 3144, in execute_sql
    cursor.execute(sql, params or ())
sqlite3.OperationalError: database is locked

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/home/ete/.local/lib/python3.9/site-packages/radicale/app/__init__.py", line 105, in __call__
    status, headers, answers = self._handle_request(environ)
  File "/home/ete/.local/lib/python3.9/site-packages/radicale/app/__init__.py", line 276, in _handle_request
    status, headers, answer = function(
  File "/home/ete/.local/lib/python3.9/site-packages/radicale/app/put.py", line 210, in do_PUT
    etag = parent_item.upload(href, prepared_item).etag
  File "/home/ete/.local/lib/python3.9/site-packages/etesync_dav/radicale/storage_etebase_collection.py", line 283, in upload
    etesync_item.save()
  File "/home/ete/.local/lib/python3.9/site-packages/etesync_dav/local_cache/__init__.py", line 362, in save
    self.cache_item.save()
  File "/usr/lib/python3/dist-packages/peewee.py", line 6556, in save
    pk = self.insert(**field_dict).execute()
  File "/usr/lib/python3/dist-packages/peewee.py", line 1907, in inner
    return method(self, database, *args, **kwargs)
  File "/usr/lib/python3/dist-packages/peewee.py", line 1978, in execute
    return self._execute(database)
  File "/usr/lib/python3/dist-packages/peewee.py", line 2745, in _execute
    return super(Insert, self)._execute(database)
  File "/usr/lib/python3/dist-packages/peewee.py", line 2474, in _execute
    cursor = database.execute(self)
  File "/usr/lib/python3/dist-packages/peewee.py", line 3157, in execute
    return self.execute_sql(sql, params, commit=commit)
  File "/usr/lib/python3/dist-packages/peewee.py", line 3151, in execute_sql
    self.commit()
  File "/usr/lib/python3/dist-packages/peewee.py", line 2917, in __exit__
    reraise(new_type, new_type(exc_value, *exc_args), traceback)
  File "/usr/lib/python3/dist-packages/peewee.py", line 190, in reraise
    raise value.with_traceback(tb)
  File "/usr/lib/python3/dist-packages/peewee.py", line 3144, in execute_sql
    cursor.execute(sql, params or ())
peewee.OperationalError: database is locked
stuart12 commented 2 years ago

This problem is on Linux running the last version of etesync-dav.

stuart12 commented 2 years ago

Using Radicale-3.0.6 appdirs-1.4.4 etebase-0.31.2 etesync-0.12.1 etesync-dav-0.30.8

CodingCellist commented 2 years ago
I'm having a similar issue. Logs below: ``` [2022-06-20 09:24:51 +0200] [3436/Thread-5] [ERROR] error sending request for url (https://api.etebase.com/partner/etesync/api/v1/collection/list_multi/?stoken=[...]): operation timed out Traceback (most recent call last): File "etesync_dav/radicale/storage.py", line 84, in run File "etesync_dav/local_cache/__init__.py", line 90, in sync File "etesync_dav/local_cache/__init__.py", line 104, in sync_collection_list File "etebase/__init__.py", line 247, in list etebase_python.Error: error sending request for url (https://api.etebase.com/partner/etesync/api/v1/collection/list_multi/?stoken=[...]): operation timed out [2022-06-20 09:25:08 +0200] [3436/Thread-4] [ERROR] An exception occurred during PROPFIND request on '/CodingCellist/[...]/': error sending request for url (https://api.etebase.com/partner/etesync/api/v1/collection/list_multi/?stoken=[...]): operation timed out [2022-06-20 09:25:08 +0200] [3436/Thread-5] [ERROR] database is locked Traceback (most recent call last): File "peewee.py", line 2949, in execute_sql sqlite3.OperationalError: database is locked During handling of the above exception, another exception occurred: Traceback (most recent call last): File "etesync_dav/radicale/storage.py", line 84, in run File "etesync_dav/local_cache/__init__.py", line 92, in sync File "etesync_dav/local_cache/__init__.py", line 158, in sync_collection File "etesync_dav/local_cache/__init__.py", line 190, in pull_collection File "peewee.py", line 6199, in save File "peewee.py", line 1785, in inner File "peewee.py", line 1856, in execute File "peewee.py", line 2320, in _execute File "peewee.py", line 2962, in execute File "peewee.py", line 2956, in execute_sql File "peewee.py", line 2732, in __exit__ File "peewee.py", line 183, in reraise File "peewee.py", line 2949, in execute_sql peewee.OperationalError: database is locked [2022-06-20 09:25:08 +0200] [3436/Thread-7] [ERROR] An exception occurred during PROPFIND request on '/CodingCellist/': database is locked [2022-06-20 09:31:52 +0200] [3436/Thread-16] [ERROR] error sending request for url (https://api.etebase.com/partner/etesync/api/v1/collection/list_multi/?stoken=[...]): operation timed out Traceback (most recent call last): File "etesync_dav/radicale/storage.py", line 84, in run File "etesync_dav/local_cache/__init__.py", line 90, in sync File "etesync_dav/local_cache/__init__.py", line 104, in sync_collection_list File "etebase/__init__.py", line 247, in list etebase_python.Error: error sending request for url (https://api.etebase.com/partner/etesync/api/v1/collection/list_multi/?stoken=[...]): operation timed out [2022-06-20 09:31:52 +0200] [3436/Thread-15] [ERROR] An exception occurred during PUT request on '/CodingCellist/[...]/[...].ics': error sending request for url (https://api.etebase.com/partner/etesync/api/v1/collection/list_multi/?stoken=[...]): operation timed out ```
arichiardi commented 1 year ago

Same error here, is there a way to "unlock" the database, I think it got into a weird state while upgrading versions.

EDIT: deleting the database files (the three of them, quite arbitrarily) in the etesync data dir solved it for me.

devurandom commented 10 months ago

I encounter the same error:

  1. I stopped etesync-dav (sudo systemctl stop etesync-dav)
  2. I deleted any existing database in /var/lib/private/etesync-dav/*
  3. I started etesync-dav (sudo systemctl start etesync-dav)
  4. I added my account on http://localhost:37358/.web/add/
  5. I try to add a CalDAV in KDE PIM (http://localhost:37358/$USERNAME/) and get a 500 Internal Server Error
  6. I try to open the "collections list" (http://localhost:37358/.web/user/$USERNAME) and get a 500 Internal Server Error and a stacktrace in journald
Traceback (most recent call last):
  File "/nix/store/z8s2bq19jglfywagpcya0mk9ksrnd4df-python3.11-peewee-3.17.0/lib/python3.11/site-packages/peewee.py", line 3252, in execute_sql
    cursor.execute(sql, params or ())
sqlite3.OperationalError: database is locked
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
  File "/nix/store/3h4rw6gj7l5p49d7q2c10hapnwchmi9d-python3.11-flask-2.3.3/lib/python3.11/site-packages/flask/app.py", line 2190, in wsgi_app
    response = self.full_dispatch_request()
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/nix/store/3h4rw6gj7l5p49d7q2c10hapnwchmi9d-python3.11-flask-2.3.3/lib/python3.11/site-packages/flask/app.py", line 1486, in full_dispatch_request
    rv = self.handle_user_exception(e)
         ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/nix/store/3h4rw6gj7l5p49d7q2c10hapnwchmi9d-python3.11-flask-2.3.3/lib/python3.11/site-packages/flask/app.py", line 1484, in full_dispatch_request
    rv = self.dispatch_request()
         ^^^^^^^^^^^^^^^^^^^^^^^
  File "/nix/store/3h4rw6gj7l5p49d7q2c10hapnwchmi9d-python3.11-flask-2.3.3/lib/python3.11/site-packages/flask/app.py", line 1469, in dispatch_request
    return self.ensure_sync(self.view_functions[rule.endpoint])(**view_args)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/nix/store/ii85x0dvabnlmscqppgv4s07hzl8nr04-etesync-dav-0.32.1/lib/python3.11/site-packages/etesync_dav/webui.py", line 93, in decorated_view
    return func(*args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^
  File "/nix/store/ii85x0dvabnlmscqppgv4s07hzl8nr04-etesync-dav-0.32.1/lib/python3.11/site-packages/etesync_dav/webui.py", line 121, in user_index
    etesync.sync_collection_list()
  File "/nix/store/ii85x0dvabnlmscqppgv4s07hzl8nr04-etesync-dav-0.32.1/lib/python3.11/site-packages/etesync_dav/local_cache/__init__.py", line 130, in sync_collection_list
    self.user.save()
  File "/nix/store/z8s2bq19jglfywagpcya0mk9ksrnd4df-python3.11-peewee-3.17.0/lib/python3.11/site-packages/peewee.py", line 6828, in save
    rows = self.update(**field_dict).where(self._pk_expr()).execute()
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/nix/store/z8s2bq19jglfywagpcya0mk9ksrnd4df-python3.11-peewee-3.17.0/lib/python3.11/site-packages/peewee.py", line 1972, in inner
    return method(self, database, *args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/nix/store/z8s2bq19jglfywagpcya0mk9ksrnd4df-python3.11-peewee-3.17.0/lib/python3.11/site-packages/peewee.py", line 2043, in execute
    return self._execute(database)
           ^^^^^^^^^^^^^^^^^^^^^^^
  File "/nix/store/z8s2bq19jglfywagpcya0mk9ksrnd4df-python3.11-peewee-3.17.0/lib/python3.11/site-packages/peewee.py", line 2561, in _execute
    cursor = database.execute(self)
             ^^^^^^^^^^^^^^^^^^^^^^
  File "/nix/store/z8s2bq19jglfywagpcya0mk9ksrnd4df-python3.11-peewee-3.17.0/lib/python3.11/site-packages/peewee.py", line 3260, in execute
    return self.execute_sql(sql, params)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/nix/store/z8s2bq19jglfywagpcya0mk9ksrnd4df-python3.11-peewee-3.17.0/lib/python3.11/site-packages/peewee.py", line 3250, in execute_sql
    with __exception_wrapper__:
  File "/nix/store/z8s2bq19jglfywagpcya0mk9ksrnd4df-python3.11-peewee-3.17.0/lib/python3.11/site-packages/peewee.py", line 3020, in __exit__
    reraise(new_type, new_type(exc_value, *exc_args), traceback)
  File "/nix/store/z8s2bq19jglfywagpcya0mk9ksrnd4df-python3.11-peewee-3.17.0/lib/python3.11/site-packages/peewee.py", line 192, in reraise
    raise value.with_traceback(tb)
  File "/nix/store/z8s2bq19jglfywagpcya0mk9ksrnd4df-python3.11-peewee-3.17.0/lib/python3.11/site-packages/peewee.py", line 3252, in execute_sql
    cursor.execute(sql, params or ())
peewee.OperationalError: database is locked

Further observations:

  1. After listing the collections from the etesync-dav web UI, a file etebase_data.db exists and is few kilobytes in size.
  2. When trying to discover the CalDAV collections with KDE PIM, two additional files etebase_data.db-shm and etebase_data.db-wal appear.
  3. The DB grows by a few kilobytes and stops.
  4. The WAL file grows to a few hundred kilobytes and stops.
  5. KDE PIM reports etesync-dav responding with 500 Internal Server Error.
  6. The WAL file grows for a while by about 100 kilobyte per second and then stops at a size of few megabytes.
  7. The DB file jumps to a size slightly smaller than the WAL file.
  8. In KDE PIM I try to fetch the collections again and this time it succeeds and lists all collections.
  9. The WAL file still exists at (about) the same size as in step 6, even if I wait several minutes.
  10. I set the CalDAV and CardDAV URL in KDE PIM and finalize creating the Akonadi / KDE PIM resource.
  11. At the time the contacts appear in KAddressbook, the WAL file has vanished.

Running NixOS 23.11.20231231.32f6357.