etesync / etesync-dav

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

EteSync not Syncing on mac OS Mojave – Server Error 500 #109

Open lasscap opened 4 years ago

lasscap commented 4 years ago

Since a few days, before and after the most recent update, EteSync on mac OS does not syncronise anymore. The error message from Calendar is as follows:

Screenshot 2020-01-16

This affects Reminders and Contacts as well.

Trying again with Comand + R just leads to the same result.

tasn commented 4 years ago

Most recent upgrade means going from 0.14.0 to 0.14.1? If so, could you try downgrading, does that fix it?

lasscap commented 4 years ago

I updated from 0.13.0 to 0.14.1 and skipped 0.14.0. Not I downgraded to 0.14.0 but the problem persisted.

tasn commented 4 years ago

So the problem started when upgrading from 0.13.0 to 0.14.1 and it's still there even after downgrading back to 0.13.0? Could you please try that if you haven't?

lasscap commented 4 years ago

I just tried version 0.13.0 and it still does not work. I don't know whether it right worked before the update from 0.13.0 to 0.14.1 that I performed a few days ago. Disabling my firewall does not change anything.

Might that be an authentication problem with the server?

tasn commented 4 years ago

In the pre-compiled binary there are two files, the .app to run etesync-dav from GUI and the other one to run it from the command line. Could you maybe run it from the command line and see if it prints any interesting errors? If not etesync-dav -D should print even more info.

Authentication issue: do other clients work for you? If yes, I don't think it's an authentication issue.

lasscap commented 4 years ago

Sorry it took me so long...

Here you go. That's the logs I got after refreshing my calender.

* Serving Flask app "etesync_dav.webui" (lazy loading)
* Environment: production
  WARNING: This is a development server. Do not use it in a production deployment.
  Use a production WSGI server instead.
[11c83c5c0] INFO: Starting Radicale
[11c83c5c0] INFO: Authentication type is 'htpasswd'
[11c83c5c0] INFO: Storage type is 'etesync_dav.radicale.storage'
[11c83c5c0] INFO: Rights type is 'etesync_dav.radicale.rights'
[11c83c5c0] INFO: Web type is 'etesync_dav.radicale.web'
* Debug mode: off
* Running on http://127.0.0.1:37359/ (Press CTRL+C to quit)
[11c83c5c0] INFO: Listening to '1.0.0.127.in-addr.arpa' on port 37358 using SSL
[11c83c5c0] INFO: Radicale server ready
[70000d7b1000] INFO: PROPFIND request for '/my-email/' with depth '0' received from 127.0.0.1 using 'Mac+OS+X/10.14.6 (18G3020) CalendarAgent/416.5.1'
[70000d7b1000] DEBUG: Request headers:
{'CONTENT_LENGTH': '743',
'CONTENT_TYPE': 'text/xml',
'GATEWAY_INTERFACE': 'CGI/1.1',
'HTTP_ACCEPT': '*/*',
'HTTP_ACCEPT_ENCODING': 'br, gzip, deflate',
'HTTP_ACCEPT_LANGUAGE': 'en-gb',
'HTTP_BRIEF': 't',
'HTTP_CONNECTION': 'keep-alive',
'HTTP_DEPTH': '0',
'HTTP_HOST': 'localhost:37358',
'HTTP_PREFER': 'return=minimal',
'HTTP_USER_AGENT': 'Mac+OS+X/10.14.6 (18G3020) CalendarAgent/416.5.1',
'PATH_INFO': '/my-email/',
'QUERY_STRING': '',
'REMOTE_ADDR': '127.0.0.1',
'REMOTE_CERTIFICATE': None,
'REMOTE_HOST': '',
'REQUEST_METHOD': 'PROPFIND',
'SCRIPT_NAME': '',
'SERVER_NAME': '1.0.0.127.in-addr.arpa',
'SERVER_PORT': '37358',
'SERVER_PROTOCOL': 'HTTP/1.1',
'SERVER_SOFTWARE': 'WSGIServer/0.2',
'wsgi.errors': <_io.StringIO object at 0x10f3bd730>,
'wsgi.file_wrapper': <class 'wsgiref.util.FileWrapper'>,
'wsgi.input': <_io.BufferedReader name=9>,
'wsgi.multiprocess': False,
'wsgi.multithread': True,
'wsgi.run_once': False,
'wsgi.url_scheme': 'http',
'wsgi.version': (1, 0)}
[70000d7b1000] DEBUG: Sanitized script name: ''
[70000d7b1000] DEBUG: Sanitized path: '/my-email/'
[70000d7b1000] INFO: Access to '/my-email/' denied for anonymous user
[70000d7b1000] DEBUG: Asking client for authentication
[70000d7b1000] DEBUG: Response content:
Access to the requested resource forbidden.
[70000d7b1000] INFO: PROPFIND response status for '/my-email/' with depth '0' in 0.001 seconds: 401 Unauthorized
[70000d7b1000] INFO: PROPFIND request for '/my-email/' with depth '0' received from 127.0.0.1 using 'Mac+OS+X/10.14.6 (18G3020) CalendarAgent/416.5.1'
[70000d7b1000] DEBUG: Request headers:
{'CONTENT_LENGTH': '743',
'CONTENT_TYPE': 'text/xml',
'GATEWAY_INTERFACE': 'CGI/1.1',
'HTTP_ACCEPT': '*/*',
'HTTP_ACCEPT_ENCODING': 'br, gzip, deflate',
'HTTP_ACCEPT_LANGUAGE': 'en-gb',
'HTTP_AUTHORIZATION': 'Basic **masked**',
'HTTP_BRIEF': 't',
'HTTP_CONNECTION': 'keep-alive',
'HTTP_DEPTH': '0',
'HTTP_HOST': 'localhost:37358',
'HTTP_PREFER': 'return=minimal',
'HTTP_USER_AGENT': 'Mac+OS+X/10.14.6 (18G3020) CalendarAgent/416.5.1',
'PATH_INFO': '/my-email/',
'QUERY_STRING': '',
'REMOTE_ADDR': '127.0.0.1',
'REMOTE_CERTIFICATE': None,
'REMOTE_HOST': '',
'REQUEST_METHOD': 'PROPFIND',
'SCRIPT_NAME': '',
'SERVER_NAME': '1.0.0.127.in-addr.arpa',
'SERVER_PORT': '37358',
'SERVER_PROTOCOL': 'HTTP/1.1',
'SERVER_SOFTWARE': 'WSGIServer/0.2',
'wsgi.errors': <_io.StringIO object at 0x10f3bd730>,
'wsgi.file_wrapper': <class 'wsgiref.util.FileWrapper'>,
'wsgi.input': <_io.BufferedReader name=9>,
'wsgi.multiprocess': False,
'wsgi.multithread': True,
'wsgi.run_once': False,
'wsgi.url_scheme': 'http',
'wsgi.version': (1, 0)}
[70000d7b1000] DEBUG: Sanitized script name: ''
[70000d7b1000] DEBUG: Sanitized path: '/my-email/'
[70000d7b1000] INFO: Successful login: 'my-email'
[70000d7b1000] ERROR: An exception occurred during PROPFIND request on '/my-email/': database disk image is malformed
Traceback (most recent call last):
 File "peewee.py", line 2949, in execute_sql
sqlite3.DatabaseError: database disk image is malformed

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
 File "radicale/__init__.py", line 332, in __call__
 File "radicale/__init__.py", line 477, in _handle_request
 File "contextlib.py", line 112, in __enter__
 File "etesync_dav/radicale/storage.py", line 601, in acquire_lock
 File "contextlib.py", line 112, in __enter__
 File "etesync_dav/radicale/etesync_cache.py", line 141, in etesync_for_user
 File "etesync_dav/radicale/etesync_cache.py", line 123, in etesync_for_user
 File "etesync/api.py", line 23, in __init__
 File "etesync/api.py", line 50, in _init_db
 File "etesync/api.py", line 33, in _set_db
 File "etesync_dav/radicale/etesync_cache.py", line 18, in _init_db_tables
 File "etesync/api.py", line 54, in _init_db_tables
 File "peewee.py", line 3132, in create_tables
 File "peewee.py", line 6296, in create_table
 File "peewee.py", line 5456, in create_all
 File "peewee.py", line 5311, in create_table
 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.DatabaseError: database disk image is malformed
[70000d7b1000] INFO: PROPFIND request for '/my-email/' with depth '0' received from 127.0.0.1 using 'Mac+OS+X/10.14.6 (18G3020) CalendarAgent/416.5.1'
[70000d7b1000] DEBUG: Request headers:
{'CONTENT_LENGTH': '170',
'CONTENT_TYPE': 'text/xml',
'GATEWAY_INTERFACE': 'CGI/1.1',
'HTTP_ACCEPT': '*/*',
'HTTP_ACCEPT_ENCODING': 'br, gzip, deflate',
'HTTP_ACCEPT_LANGUAGE': 'en-gb',
'HTTP_AUTHORIZATION': 'Basic **masked**',
'HTTP_BRIEF': 't',
'HTTP_CONNECTION': 'keep-alive',
'HTTP_DEPTH': '0',
'HTTP_HOST': 'localhost:37358',
'HTTP_PREFER': 'return=minimal',
'HTTP_USER_AGENT': 'Mac+OS+X/10.14.6 (18G3020) CalendarAgent/416.5.1',
'PATH_INFO': '/my-email/',
'QUERY_STRING': '',
'REMOTE_ADDR': '127.0.0.1',
'REMOTE_CERTIFICATE': None,
'REMOTE_HOST': '',
'REQUEST_METHOD': 'PROPFIND',
'SCRIPT_NAME': '',
'SERVER_NAME': '1.0.0.127.in-addr.arpa',
'SERVER_PORT': '37358',
'SERVER_PROTOCOL': 'HTTP/1.1',
'SERVER_SOFTWARE': 'WSGIServer/0.2',
'wsgi.errors': <_io.StringIO object at 0x10f3bdaf0>,
'wsgi.file_wrapper': <class 'wsgiref.util.FileWrapper'>,
'wsgi.input': <_io.BufferedReader name=9>,
'wsgi.multiprocess': False,
'wsgi.multithread': True,
'wsgi.run_once': False,
'wsgi.url_scheme': 'http',
'wsgi.version': (1, 0)}
[70000d7b1000] DEBUG: Sanitized script name: ''
[70000d7b1000] DEBUG: Sanitized path: '/my-email/'
[70000d7b1000] INFO: Successful login: 'my-email'
[70000d7b1000] ERROR: An exception occurred during PROPFIND request on '/my-email/': database disk image is malformed
Traceback (most recent call last):
 File "peewee.py", line 2949, in execute_sql
sqlite3.DatabaseError: database disk image is malformed

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
 File "radicale/__init__.py", line 332, in __call__
 File "radicale/__init__.py", line 477, in _handle_request
 File "contextlib.py", line 112, in __enter__
 File "etesync_dav/radicale/storage.py", line 601, in acquire_lock
 File "contextlib.py", line 112, in __enter__
 File "etesync_dav/radicale/etesync_cache.py", line 141, in etesync_for_user
 File "etesync_dav/radicale/etesync_cache.py", line 123, in etesync_for_user
 File "etesync/api.py", line 23, in __init__
 File "etesync/api.py", line 50, in _init_db
 File "etesync/api.py", line 33, in _set_db
 File "etesync_dav/radicale/etesync_cache.py", line 18, in _init_db_tables
 File "etesync/api.py", line 54, in _init_db_tables
 File "peewee.py", line 3132, in create_tables
 File "peewee.py", line 6296, in create_table
 File "peewee.py", line 5456, in create_all
 File "peewee.py", line 5311, in create_table
 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.DatabaseError: database disk image is malformed
[70000d7b1000] INFO: PROPFIND request for '/' with depth '0' received from 127.0.0.1 using 'Mac+OS+X/10.14.6 (18G3020) CalendarAgent/416.5.1'
[70000d7b1000] DEBUG: Request headers:
{'CONTENT_LENGTH': '170',
'CONTENT_TYPE': 'text/xml',
'GATEWAY_INTERFACE': 'CGI/1.1',
'HTTP_ACCEPT': '*/*',
'HTTP_ACCEPT_ENCODING': 'br, gzip, deflate',
'HTTP_ACCEPT_LANGUAGE': 'en-gb',
'HTTP_BRIEF': 't',
'HTTP_CONNECTION': 'keep-alive',
'HTTP_DEPTH': '0',
'HTTP_HOST': 'localhost:37358',
'HTTP_PREFER': 'return=minimal',
'HTTP_USER_AGENT': 'Mac+OS+X/10.14.6 (18G3020) CalendarAgent/416.5.1',
'PATH_INFO': '/',
'QUERY_STRING': '',
'REMOTE_ADDR': '127.0.0.1',
'REMOTE_CERTIFICATE': None,
'REMOTE_HOST': '',
'REQUEST_METHOD': 'PROPFIND',
'SCRIPT_NAME': '',
'SERVER_NAME': '1.0.0.127.in-addr.arpa',
'SERVER_PORT': '37358',
'SERVER_PROTOCOL': 'HTTP/1.1',
'SERVER_SOFTWARE': 'WSGIServer/0.2',
'wsgi.errors': <_io.StringIO object at 0x10f3bd870>,
'wsgi.file_wrapper': <class 'wsgiref.util.FileWrapper'>,
'wsgi.input': <_io.BufferedReader name=9>,
'wsgi.multiprocess': False,
'wsgi.multithread': True,
'wsgi.run_once': False,
'wsgi.url_scheme': 'http',
'wsgi.version': (1, 0)}
[70000d7b1000] DEBUG: Sanitized script name: ''
[70000d7b1000] DEBUG: Sanitized path: '/'
[70000d7b1000] INFO: Access to '/' denied for anonymous user
[70000d7b1000] DEBUG: Asking client for authentication
[70000d7b1000] DEBUG: Response content:
Access to the requested resource forbidden.
[70000d7b1000] INFO: PROPFIND response status for '/' with depth '0' in 0.001 seconds: 401 Unauthorized
[70000d7b1000] INFO: PROPFIND request for '/' with depth '0' received from 127.0.0.1 using 'Mac+OS+X/10.14.6 (18G3020) CalendarAgent/416.5.1'
[70000d7b1000] DEBUG: Request headers:
{'CONTENT_LENGTH': '170',
'CONTENT_TYPE': 'text/xml',
'GATEWAY_INTERFACE': 'CGI/1.1',
'HTTP_ACCEPT': '*/*',
'HTTP_ACCEPT_ENCODING': 'br, gzip, deflate',
'HTTP_ACCEPT_LANGUAGE': 'en-gb',
'HTTP_AUTHORIZATION': 'Basic **masked**',
'HTTP_BRIEF': 't',
'HTTP_CONNECTION': 'keep-alive',
'HTTP_DEPTH': '0',
'HTTP_HOST': 'localhost:37358',
'HTTP_PREFER': 'return=minimal',
'HTTP_USER_AGENT': 'Mac+OS+X/10.14.6 (18G3020) CalendarAgent/416.5.1',
'PATH_INFO': '/',
'QUERY_STRING': '',
'REMOTE_ADDR': '127.0.0.1',
'REMOTE_CERTIFICATE': None,
'REMOTE_HOST': '',
'REQUEST_METHOD': 'PROPFIND',
'SCRIPT_NAME': '',
'SERVER_NAME': '1.0.0.127.in-addr.arpa',
'SERVER_PORT': '37358',
'SERVER_PROTOCOL': 'HTTP/1.1',
'SERVER_SOFTWARE': 'WSGIServer/0.2',
'wsgi.errors': <_io.StringIO object at 0x10f3bd870>,
'wsgi.file_wrapper': <class 'wsgiref.util.FileWrapper'>,
'wsgi.input': <_io.BufferedReader name=9>,
'wsgi.multiprocess': False,
'wsgi.multithread': True,
'wsgi.run_once': False,
'wsgi.url_scheme': 'http',
'wsgi.version': (1, 0)}
[70000d7b1000] DEBUG: Sanitized script name: ''
[70000d7b1000] DEBUG: Sanitized path: '/'
[70000d7b1000] INFO: Successful login: 'my-email'
[70000d7b1000] ERROR: An exception occurred during PROPFIND request on '/': database disk image is malformed
Traceback (most recent call last):
 File "peewee.py", line 2949, in execute_sql
sqlite3.DatabaseError: database disk image is malformed

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
 File "radicale/__init__.py", line 332, in __call__
 File "radicale/__init__.py", line 477, in _handle_request
 File "contextlib.py", line 112, in __enter__
 File "etesync_dav/radicale/storage.py", line 601, in acquire_lock
 File "contextlib.py", line 112, in __enter__
 File "etesync_dav/radicale/etesync_cache.py", line 141, in etesync_for_user
 File "etesync_dav/radicale/etesync_cache.py", line 123, in etesync_for_user
 File "etesync/api.py", line 23, in __init__
 File "etesync/api.py", line 50, in _init_db
 File "etesync/api.py", line 33, in _set_db
 File "etesync_dav/radicale/etesync_cache.py", line 18, in _init_db_tables
 File "etesync/api.py", line 54, in _init_db_tables
 File "peewee.py", line 3132, in create_tables
 File "peewee.py", line 6296, in create_table
 File "peewee.py", line 5456, in create_all
 File "peewee.py", line 5311, in create_table
 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.DatabaseError: database disk image is malformed
[70000d7b1000] INFO: PROPFIND request for '/principals/' with depth '0' received from 127.0.0.1 using 'Mac+OS+X/10.14.6 (18G3020) CalendarAgent/416.5.1'
[70000d7b1000] DEBUG: Request headers:
{'CONTENT_LENGTH': '170',
'CONTENT_TYPE': 'text/xml',
'GATEWAY_INTERFACE': 'CGI/1.1',
'HTTP_ACCEPT': '*/*',
'HTTP_ACCEPT_ENCODING': 'br, gzip, deflate',
'HTTP_ACCEPT_LANGUAGE': 'en-gb',
'HTTP_AUTHORIZATION': 'Basic **masked**',
'HTTP_BRIEF': 't',
'HTTP_CONNECTION': 'keep-alive',
'HTTP_DEPTH': '0',
'HTTP_HOST': 'localhost:37358',
'HTTP_PREFER': 'return=minimal',
'HTTP_USER_AGENT': 'Mac+OS+X/10.14.6 (18G3020) CalendarAgent/416.5.1',
'PATH_INFO': '/principals/',
'QUERY_STRING': '',
'REMOTE_ADDR': '127.0.0.1',
'REMOTE_CERTIFICATE': None,
'REMOTE_HOST': '',
'REQUEST_METHOD': 'PROPFIND',
'SCRIPT_NAME': '',
'SERVER_NAME': '1.0.0.127.in-addr.arpa',
'SERVER_PORT': '37358',
'SERVER_PROTOCOL': 'HTTP/1.1',
'SERVER_SOFTWARE': 'WSGIServer/0.2',
'wsgi.errors': <_io.StringIO object at 0x10f3bdeb0>,
'wsgi.file_wrapper': <class 'wsgiref.util.FileWrapper'>,
'wsgi.input': <_io.BufferedReader name=9>,
'wsgi.multiprocess': False,
'wsgi.multithread': True,
'wsgi.run_once': False,
'wsgi.url_scheme': 'http',
'wsgi.version': (1, 0)}
[70000d7b1000] DEBUG: Sanitized script name: ''
[70000d7b1000] DEBUG: Sanitized path: '/principals/'
[70000d7b1000] INFO: Successful login: 'my-email'
[70000d7b1000] ERROR: An exception occurred during PROPFIND request on '/principals/': database disk image is malformed
Traceback (most recent call last):
 File "peewee.py", line 2949, in execute_sql
sqlite3.DatabaseError: database disk image is malformed

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
 File "radicale/__init__.py", line 332, in __call__
 File "radicale/__init__.py", line 477, in _handle_request
 File "contextlib.py", line 112, in __enter__
 File "etesync_dav/radicale/storage.py", line 601, in acquire_lock
 File "contextlib.py", line 112, in __enter__
 File "etesync_dav/radicale/etesync_cache.py", line 141, in etesync_for_user
 File "etesync_dav/radicale/etesync_cache.py", line 123, in etesync_for_user
 File "etesync/api.py", line 23, in __init__
 File "etesync/api.py", line 50, in _init_db
 File "etesync/api.py", line 33, in _set_db
 File "etesync_dav/radicale/etesync_cache.py", line 18, in _init_db_tables
 File "etesync/api.py", line 54, in _init_db_tables
 File "peewee.py", line 3132, in create_tables
 File "peewee.py", line 6296, in create_table
 File "peewee.py", line 5456, in create_all
 File "peewee.py", line 5311, in create_table
 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.DatabaseError: database disk image is malformed

I hope that helps!

tasn commented 4 years ago

For a reason I can't even start to imagine, as I've never seen it before, your local cache seems to be malformed (sqlite3.DatabaseError: database disk image is malformed). Really no idea how it can happen.

Though luckily, since it's just a cache, it's very easy to fix. You just need to remove the malformed database and etesync-dav will recreate it. Just make sure you don't have any unsynced events. To do it:

  1. Stop etesync-dav.
  2. Run mv .config/etesync-dav/etesync_data.db{,.back}
  3. Start etesync-dav again.

Does that fix it for you?

lasscap commented 4 years ago

After running mv .config/etesync-dav/etesync_data.db{,.back} I get the error that there is no such file or directory.

tasn commented 4 years ago

Grr, right, that's the path here, though I guess it's different on macs...

Try ~/Library/Application Support/etesync-dav is there an etesync_data.db file there? If so, rename it to etesync_data.db.back

lasscap commented 4 years ago

In the Appication Support folder under Library there is no etesync-dav and I can't find a etesync_data.db file on my computer.

tasn commented 4 years ago

How about etesync_creds, can you find that one?

lasscap commented 4 years ago

In the Appication Support folder under Library there is no etesync_creds or anything called like etesync. I have lots of other programs there but no etesync. I'll update to the new version and let you knwo if anythng changes.

tasn commented 4 years ago

Is it working?