Linage Privacy Guard: Calendars not syncing

fhollerweger

Hi all,

After an upgrade of DAVdroid via FDroid on LineageOS to version 1.11.2-ose (or possibly a version released shortly before that), a previously working account on a Radicale server (version 2.1.9) running on my local laptop has suddenly stopped working.

Specifically, the calendar collections on this server are now listed multiple times in the LineageOS stock calendar (under … > Calendars to display), but neither of these copies seems to be actually synced, ie, the calendar on the LineageOS device does not show any events in any of those calendars.

Every time I attempt such a sync, an additional 2-4 copies of any to-be-synced calendars will be added to the list of calendars on the LineageOS device. For example, I have a ‘work’ and a ‘life’ calendar on my Radicale server. If I add an account on my LineageOS device to connect to that server, all calendars will be recognized. If I now sync those calendars, 2-4 copies of both calendars will be listed in the LineageOS calendar, but none of their events will actually be shown. If I sync again, another 2-4 copies of both calendars will be added (but still no events shown). If I sync again, this time only the ‘work’ calendar, then additional copies of only that calendar will be added to the calendar list.

I should also mention that

Only one instance of each collection is visible in the DAVDroid app and in the web interface for my local Radicale server.
The Radicale server had not been updated in a while, nor has its configuration been changed in any way.
An address book hosted on the same Radicale server synchronizes just fine using the very same DAVdroid account.

Any ideas where to start?

Best wishes,
FH

rfc2822

Hello,

Thanks for your report! Please provide steps to reproduce, Web server and CalDAV/CardDAV server logs taken while the problem occurs, DAVdroid debug info (DAVdroid / Settings / Debug info) and verbose DAVdroid logs etc as described in [READ BEFORE POSTING] What’s required to diagnose a problem.

fhollerweger

--- BEGIN DEBUG INFO ---

SOFTWARE INFORMATION
Package: at.bitfire.davdroid
Version: 1.11.2-ose (218) from May 5, 2018
Installed from: com.android.packageinstaller
JB Workaround installed: no

CONNECTIVITY (at the moment)
Active connection: WiFi, CONNECTED

CONFIGURATION
Power saving disabled: yes
android.permission.READ_CONTACTS permission: granted
android.permission.WRITE_CONTACTS permission: granted
android.permission.READ_CALENDAR permission: granted
android.permission.WRITE_CALENDAR permission: granted
org.dmfs.permission.READ_TASKS permission: granted
org.dmfs.permission.WRITE_TASKS permission: granted
System-wide synchronization: automatically
Account: radicale
  Address book sync. interval: 240 min
  Calendar     sync. interval: 240 min
  OpenTasks    sync. interval: 240 min
  WiFi only: false
  [CardDAV] Contact group method: GROUP_VCARDS
  [CalDAV] Time range (past days): 90
           Manage calendar colors: true
Address book account: contacts (radicale gw)
  Main account: Account {name=radicale, type=bitfire.at.davdroid}
  URL: https://192.168.1.101:5232/flo/3dc6a8e1-4a5a-9e2a-691d-0229ac7afcbc/
  Sync automatically: true

SQLITE DUMP
android_metadata
	|  locale |
	|  en_US |
----------
services
	|  _id | accountName | service | principal |
	|  29 | radicale | carddav | https://192.168.1.101:5232/flo/ |
	|  30 | radicale | caldav | https://192.168.1.101:5232/flo/ |
----------
sqlite_sequence
	|  name | seq |
	|  services | 30 |
	|  homesets | 76 |
	|  collections | 76 |
----------
homesets
	|  _id | serviceID | url |
	|  75 | 29 | https://192.168.1.101:5232/flo/ |
	|  76 | 30 | https://192.168.1.101:5232/flo/ |
----------
collections
	|  _id | serviceID | url | readOnly | displayName | description | color | timezone | supportsVEVENT | supportsVTODO | sync | type | source | forceReadOnly |
	|  70 | 29 | https://192.168.1.101:5232/flo/3dc6a8e1-4a5a-9e2a-691d-0229ac7afcbc/ | 0 | contacts | <null> | <null> | <null> | 0 | 0 | 1 | ADDRESS_BOOK | <null> | 0 |
	|  71 | 30 | https://192.168.1.101:5232/flo/24ef7f36-6269-e258-7ac8-67ab0c68b61a/ | 0 | org | <null> | -8758529 | <null> | 1 | 1 | 1 | CALENDAR | <null> | 0 |
	|  72 | 30 | https://192.168.1.101:5232/flo/a99ed497-74e5-969e-4781-7ec1e7844175/ | 0 | work | <null> | -16766465 | <null> | 1 | 0 | 1 | CALENDAR | <null> | 0 |
	|  73 | 30 | https://192.168.1.101:5232/flo/1eaa1565-1f1a-95b2-a9d4-4b36d626d6a1/ | 0 | manu | <null> | -15482325 | <null> | 1 | 0 | 1 | CALENDAR | <null> | 0 |
	|  74 | 30 | https://192.168.1.101:5232/flo/dc237432-ecb1-2993-e8ec-35b29c7338fa/ | 0 | world | <null> | -2747891 | <null> | 1 | 0 | 1 | CALENDAR | <null> | 0 |
	|  75 | 30 | https://192.168.1.101:5232/flo/f76be379-1fba-edbe-20ae-3ba49cb2c5ee/ | 0 | eltern | <null> | -6421823 | <null> | 1 | 0 | 1 | CALENDAR | <null> | 0 |
	|  76 | 30 | https://192.168.1.101:5232/flo/cacb3f31-bfb4-5d8c-73d7-12c0a474553b/ | 0 | life | <null> | -16732673 | <null> | 1 | 0 | 1 | CALENDAR | <null> | 0 |
----------

SYSTEM INFORMATION
Android version: 7.1.2 (OnePlus5-userdebug 7.1.2 NJH47F 8c480e81d2)
Device: OnePlus ONEPLUS A5000 (OnePlus5)

--- END DEBUG INFO ---

fhollerweger

I’d love to also provide the more detailed DAVdroid logs as described in the section
Your problem doesn’t cause a notification or you need verbose logs?
at [https://forums.bitfire.at/topic/749/read-before-posting-what-s-required-to-diagnose-a-problem](link url)

There it is suggested that if one selects
DAVdroid > Settings (left navigation drawer in the main screen) > Enable “log to external storage.”
“a notification with the log file path appears”.

However, this is not true for my DAVdroid version (1.11.2-ose under LineageOS 14.1), which merely includes the following on/off toggle switch:
DAVdroid > Settings > Debugging > Log to external file
If I enable this switch, there is no indication as to where exactly logs are being saved. A manual search for them in the Android file system has also not yielded any results

Any ideas on where to retrieve those logs?

fhollerweger

Found the logs. For the record, after enabling external file logs, DAVDroid will automatically post a notification message whenever it actually logs something, which includes the path to the logs, which in my case is

/storage/emulated/0/Android/data/at.bitfire.davdroid/files

So it was simply a matter of waiting until the first log event after enabling external file logs. Will post log(s) in a separate post.

fhollerweger

The following DAVdroid log seems representative for what happens upon sync. One thing I noted was a large number of “Adding local calendar” and “Creating local calendar:” events. Considering that all the calendar collections that are being synced here already exist locally on DAVdroid, this might represent the actual moments where these collections are locally duplicated as originally described?

2018-05-23 12:19:59 1976 [PackageChangedReceiver] Package (un)installed; OpenTasks provider now available = true
2018-05-23 12:19:59 1979 [syncadapter.SyncAdapterService] com.android.calendar sync of Account {name=radicale, type=bitfire.at.davdroid} has been initiated
        PARAMETER #0 = ignore_settings, force, expedited, ignore_backoff
2018-05-23 12:19:59 1977 [syncadapter.SyncAdapterService] at.bitfire.davdroid.addressbooks sync of Account {name=radicale, type=bitfire.at.davdroid} has been initiated
        PARAMETER #0 = ignore_settings, force, expedited, ignore_backoff
2018-05-23 12:19:59 1978 [syncadapter.SyncAdapterService] org.dmfs.tasks sync of Account {name=radicale, type=bitfire.at.davdroid} has been initiated
        PARAMETER #0 = ignore_settings, force, expedited, ignore_backoff
2018-05-23 12:19:59 1979 [AccountSettings] Account radicale has version 8, current version: 8
2018-05-23 12:19:59 1978 [AccountSettings] Account radicale has version 8, current version: 8
2018-05-23 12:19:59 1979 [AndroidCalendar] Removing event colors from account Account {name=radicale, type=bitfire.at.davdroid}
2018-05-23 12:19:59 1977 [AccountSettings] Account radicale has version 8, current version: 8
2018-05-23 12:19:59 1977 [syncadapter.AddressBooksSyncAdapterService] Updating local address book https://192.168.1.101:5232/flo/3dc6a8e1-4a5a-9e2a-691d-0229ac7afcbc/
        PARAMETER #0 = CollectionInfo(url=https://192.168.1.101:5232/flo/3dc6a8e1-4a5a-9e2a-691d-0229ac7afcbc/, id=70, serviceID=29, type=ADDRESS_BOOK, readOnly=false, forceReadOnly=false, displayName=contacts, description=null, color=null, timeZone=null, supportsVEVENT=false, supportsVTODO=false, selected=true, source=null, confirmed=false)
2018-05-23 12:19:59 1977 [resource.LocalAddressBook] Address book read-only? = false
2018-05-23 12:19:59 1978 [syncadapter.TasksSyncAdapterService] Task sync complete
2018-05-23 12:19:59 1978 [syncadapter.SyncAdapterService] Sync for org.dmfs.tasks complete
2018-05-23 12:19:59 1979 [syncadapter.CalendarsSyncAdapterService] Adding local calendar
        PARAMETER #0 = CollectionInfo(url=https://192.168.1.101:5232/flo/dc237432-ecb1-2993-e8ec-35b29c7338fa/, id=74, serviceID=30, type=CALENDAR, readOnly=false, forceReadOnly=false, displayName=world, description=null, color=-2747891, timeZone=null, supportsVEVENT=true, supportsVTODO=false, selected=true, source=null, confirmed=false)
2018-05-23 12:19:59 1979 [AndroidCalendar] Creating local calendar: calendar_color=-2747891 sync_events=1 canOrganizerRespond=1 ownerAccount=radicale visible=1 canModifyTimeZone=1 account_type=bitfire.at.davdroid allowedAttendeeTypes=0,2,1,3 allowedAvailability=0,1,2 name=https://192.168.1.101:5232/flo/dc237432-ecb1-2993-e8ec-35b29c7338fa/ allowedReminders=1,2 account_name=radicale calendar_access_level=700 calendar_displayName=world
2018-05-23 12:19:59 1977 [syncadapter.AddressBooksSyncAdapterService] Running sync for address book
        PARAMETER #0 = Account {name=contacts (radicale gw), type=at.bitfire.davdroid.address_book}
2018-05-23 12:19:59 1979 [syncadapter.CalendarsSyncAdapterService] Calendar sync complete
2018-05-23 12:19:59 1979 [syncadapter.SyncAdapterService] Sync for com.android.calendar complete
2018-05-23 12:19:59 1977 [syncadapter.AddressBooksSyncAdapterService] Address book sync complete
2018-05-23 12:19:59 1977 [syncadapter.SyncAdapterService] Sync for at.bitfire.davdroid.addressbooks complete
2018-05-23 12:19:59 1981 [syncadapter.SyncAdapterService] com.android.contacts sync of Account {name=contacts (radicale gw), type=at.bitfire.davdroid.address_book} has been initiated
        PARAMETER #0 = ignore_settings, force, expedited, ignore_backoff
2018-05-23 12:19:59 1981 [AccountSettings] Account radicale has version 8, current version: 8
2018-05-23 12:19:59 1982 [syncadapter.SyncAdapterService] com.android.calendar sync of Account {name=radicale, type=bitfire.at.davdroid} has been initiated
        PARAMETER #0 = 
2018-05-23 12:19:59 1982 [AccountSettings] Account radicale has version 8, current version: 8
2018-05-23 12:19:59 1981 [syncadapter.ContactsSyncAdapterService] Synchronizing address book: https://192.168.1.101:5232/flo/3dc6a8e1-4a5a-9e2a-691d-0229ac7afcbc/
2018-05-23 12:19:59 1981 [syncadapter.ContactsSyncAdapterService] Taking settings from: Account {name=radicale, type=bitfire.at.davdroid}
2018-05-23 12:19:59 1982 [AndroidCalendar] Removing event colors from account Account {name=radicale, type=bitfire.at.davdroid}
2018-05-23 12:19:59 1982 [syncadapter.CalendarsSyncAdapterService] Adding local calendar
        PARAMETER #0 = CollectionInfo(url=https://192.168.1.101:5232/flo/dc237432-ecb1-2993-e8ec-35b29c7338fa/, id=74, serviceID=30, type=CALENDAR, readOnly=false, forceReadOnly=false, displayName=world, description=null, color=-2747891, timeZone=null, supportsVEVENT=true, supportsVTODO=false, selected=true, source=null, confirmed=false)
2018-05-23 12:19:59 1982 [AndroidCalendar] Creating local calendar: calendar_color=-2747891 sync_events=1 canOrganizerRespond=1 ownerAccount=radicale visible=1 canModifyTimeZone=1 account_type=bitfire.at.davdroid allowedAttendeeTypes=0,2,1,3 allowedAvailability=0,1,2 name=https://192.168.1.101:5232/flo/dc237432-ecb1-2993-e8ec-35b29c7338fa/ allowedReminders=1,2 account_name=radicale calendar_access_level=700 calendar_displayName=world
2018-05-23 12:19:59 1981 [CustomTlsSocketFactory] Using device default TLS protocols/ciphers
2018-05-23 12:19:59 1982 [syncadapter.CalendarsSyncAdapterService] Calendar sync complete
2018-05-23 12:19:59 1981 [syncadapter.SyncManager] Preparing synchronization
2018-05-23 12:19:59 1982 [syncadapter.SyncAdapterService] Sync for com.android.calendar complete
2018-05-23 12:19:59 1981 [syncadapter.SyncManager] Querying server capabilities
2018-05-23 12:19:59 1981 [HttpClient] --> PROPFIND https://192.168.1.101:5232/flo/3dc6a8e1-4a5a-9e2a-691d-0229ac7afcbc/
2018-05-23 12:19:59 1981 [HttpClient] Content-Type: application/xml; charset=utf-8
2018-05-23 12:19:59 1981 [HttpClient] Content-Length: 296
2018-05-23 12:19:59 1981 [HttpClient] Depth: 0
2018-05-23 12:19:59 1981 [HttpClient] 
2018-05-23 12:19:59 1981 [HttpClient] <?xml version='1.0' encoding='UTF-8' ?><propfind xmlns="DAV:" xmlns:CAL="urn:ietf:params:xml:ns:caldav" xmlns:CARD="urn:ietf:params:xml:ns:carddav"><prop><CARD:supported-address-data /><supported-report-set /><n0:getctag xmlns:n0="http://calendarserver.org/ns/" /><sync-token /></prop></propfind>
2018-05-23 12:19:59 1981 [HttpClient] --> END PROPFIND (296-byte body)
2018-05-23 12:19:59 1981 [BasicDigestAuthHandler] Trying Basic auth preemptively
2018-05-23 12:19:59 1981 [BasicDigestAuthHandler] Adding Basic authorization header for https://192.168.1.101:5232/flo/3dc6a8e1-4a5a-9e2a-691d-0229ac7afcbc/
2018-05-23 12:19:59 1981 [HttpClient] <-- 207 Multi-Status https://192.168.1.101:5232/flo/3dc6a8e1-4a5a-9e2a-691d-0229ac7afcbc/ (272ms)
2018-05-23 12:19:59 1981 [HttpClient] Date: Wed, 23 May 2018 17:20:07 GMT
2018-05-23 12:19:59 1981 [HttpClient] Server: WSGIServer/0.2 CPython/3.6.5rc1
2018-05-23 12:19:59 1981 [HttpClient] DAV: 1, 2, 3, calendar-access, addressbook, extended-mkcol
2018-05-23 12:19:59 1981 [HttpClient] Content-Type: text/xml; charset=utf-8
2018-05-23 12:19:59 1981 [HttpClient] 
2018-05-23 12:19:59 1981 [HttpClient] <?xml version='1.0' encoding='utf-8'?>
<multistatus xmlns="DAV:" xmlns:CR="urn:ietf:params:xml:ns:carddav" xmlns:CS="http://calendarserver.org/ns/"><response><href>/flo/3dc6a8e1-4a5a-9e2a-691d-0229ac7afcbc/</href><propstat><prop><supported-report-set><supported-report><report><expand-property /></report></supported-report><supported-report><report><principal-search-property-set /></report></supported-report><supported-report><report><principal-property-search /></report></supported-report><supported-report><report><sync-collection /></report></supported-report><supported-report><report><CR:addressbook-multiget /></report></supported-report><supported-report><report><CR:addressbook-query /></report></supported-report></supported-report-set><CS:getctag>"8883aec3e6a1a6f30dd37a6d97f1e5b5"</CS:getctag><sync-token>http://radicale.org/ns/sync/1f94f0d7934b0126e83c0dae25271300</sync-token></prop><status>HTTP/1.1 200 OK</status></propstat><propstat><prop><CR:supported-address-data /></prop><status>HTTP/1.1 404 Not Found</status></propstat></response></multistatus>
2018-05-23 12:19:59 1981 [HttpClient] <-- END HTTP (1070-byte body)
2018-05-23 12:19:59 1981 [PropertyRegistry] Registering DAV property factories
2018-05-23 12:19:59 1981 [PropertyRegistry] Registering at.bitfire.dav4android.property.AddressbookDescription$Factory for urn:ietf:params:xml:ns:carddavaddressbook-description
2018-05-23 12:19:59 1981 [PropertyRegistry] Registering at.bitfire.dav4android.property.AddressbookHomeSet$Factory for urn:ietf:params:xml:ns:carddavaddressbook-home-set
2018-05-23 12:19:59 1981 [PropertyRegistry] Registering at.bitfire.dav4android.property.AddressData$Factory for urn:ietf:params:xml:ns:carddavaddress-data
2018-05-23 12:19:59 1981 [PropertyRegistry] Registering at.bitfire.dav4android.property.CalendarColor$Factory for http://apple.com/ns/ical/calendar-color
2018-05-23 12:19:59 1981 [PropertyRegistry] Registering at.bitfire.dav4android.property.CalendarData$Factory for urn:ietf:params:xml:ns:caldavcalendar-data
2018-05-23 12:19:59 1981 [PropertyRegistry] Registering at.bitfire.dav4android.property.CalendarDescription$Factory for urn:ietf:params:xml:ns:caldavcalendar-description
2018-05-23 12:19:59 1981 [PropertyRegistry] Registering at.bitfire.dav4android.property.CalendarHomeSet$Factory for urn:ietf:params:xml:ns:caldavcalendar-home-set
2018-05-23 12:19:59 1981 [PropertyRegistry] Registering at.bitfire.dav4android.property.CalendarProxyReadFor$Factory for http://calendarserver.org/ns/calendar-proxy-read-for
2018-05-23 12:19:59 1981 [PropertyRegistry] Registering at.bitfire.dav4android.property.CalendarProxyWriteFor$Factory for http://calendarserver.org/ns/calendar-proxy-write-for
2018-05-23 12:19:59 1981 [PropertyRegistry] Registering at.bitfire.dav4android.property.CalendarTimezone$Factory for urn:ietf:params:xml:ns:caldavcalendar-timezone
2018-05-23 12:19:59 1981 [PropertyRegistry] Registering at.bitfire.dav4android.property.CalendarUserAddressSet$Factory for urn:ietf:params:xml:ns:caldavcalendar-user-address-set
2018-05-23 12:19:59 1981 [PropertyRegistry] Registering at.bitfire.dav4android.property.CurrentUserPrincipal$Factory for DAV:current-user-principal
2018-05-23 12:19:59 1981 [PropertyRegistry] Registering at.bitfire.dav4android.property.CurrentUserPrivilegeSet$Factory for DAV:current-user-privilege-set
2018-05-23 12:19:59 1981 [PropertyRegistry] Registering at.bitfire.dav4android.property.DisplayName$Factory for DAV:displayname
2018-05-23 12:19:59 1981 [PropertyRegistry] Registering at.bitfire.dav4android.property.GetContentType$Factory for DAV:getcontenttype
2018-05-23 12:19:59 1981 [PropertyRegistry] Registering at.bitfire.dav4android.property.GetCTag$Factory for http://calendarserver.org/ns/getctag
2018-05-23 12:19:59 1981 [PropertyRegistry] Registering at.bitfire.dav4android.property.GetETag$Factory for DAV:getetag
2018-05-23 12:19:59 1981 [PropertyRegistry] Registering at.bitfire.dav4android.property.GetLastModified$Factory for DAV:getlastmodified
2018-05-23 12:19:59 1981 [PropertyRegistry] Registering at.bitfire.dav4android.property.GroupMembership$Factory for DAV:group-membership
2018-05-23 12:19:59 1981 [PropertyRegistry] Registering at.bitfire.dav4android.property.ResourceType$Factory for DAV:resourcetype
2018-05-23 12:19:59 1981 [PropertyRegistry] Registering at.bitfire.dav4android.property.Source$Factory for http://calendarserver.org/ns/source
2018-05-23 12:19:59 1981 [PropertyRegistry] Registering at.bitfire.dav4android.property.SupportedAddressData$Factory for urn:ietf:params:xml:ns:carddavsupported-address-data
2018-05-23 12:19:59 1981 [PropertyRegistry] Registering at.bitfire.dav4android.property.SupportedCalendarComponentSet$Factory for urn:ietf:params:xml:ns:caldavsupported-calendar-component-set
2018-05-23 12:19:59 1981 [PropertyRegistry] Registering at.bitfire.dav4android.property.SupportedReportSet$Factory for DAV:supported-report-set
2018-05-23 12:19:59 1981 [PropertyRegistry] Registering at.bitfire.dav4android.property.SyncToken$Factory for DAV:sync-token
2018-05-23 12:19:59 1981 [DavResource] Received <response> for https://192.168.1.101:5232/flo/3dc6a8e1-4a5a-9e2a-691d-0229ac7afcbc/
        PARAMETER #0 = [DAV:supported-report-set = [DAV:expand-property, DAV:principal-search-property-set, DAV:principal-property-search, DAV:sync-collection, urn:ietf:params:xml:ns:carddavaddressbook-multiget,
urn:ietf:params:xml:ns:carddavaddressbook-query], http://calendarserver.org/ns/getctag = GetCTag(cTag="8883aec3e6a1a6f30dd37a6d97f1e5b5"), DAV:sync-token = SyncToken(token=http://radicale.org/ns/sync/1f94f0d7934b0126e83c0dae25271300), urn:ietf:params:xml:ns:carddavsupported-address-data = null]
2018-05-23 12:20:00 1981 [syncadapter.ContactsSyncManager] Server supports vCard/4: false
2018-05-23 12:20:00 1981 [syncadapter.ContactsSyncManager] Server supports Collection Sync: true
2018-05-23 12:20:00 1981 [syncadapter.ContactsSyncManager] Contact group method: GROUP_VCARDS
2018-05-23 12:20:00 1981 [syncadapter.SyncManager] Sending local deletes/updates to server
2018-05-23 12:20:00 1981 [syncadapter.BaseDavSyncManager] Removed 0 record(s) from server
2018-05-23 12:20:00 1981 [syncadapter.BaseDavSyncManager] Sent 0 record(s) to server
2018-05-23 12:20:00 1981 [syncadapter.BaseDavSyncManager] Local sync state = {"type":"SYNC_TOKEN","value":"http:\/\/radicale.org\/ns\/sync\/1f94f0d7934b0126e83c0dae25271300","initialSync":false}, remote sync state = {"type":"SYNC_TOKEN","value":"http:\/\/radicale.org\/ns\/sync\/1f94f0d7934b0126e83c0dae25271300"}
2018-05-23 12:20:00 1981 [syncadapter.SyncManager] Remote collection didn't change, no reason to sync
2018-05-23 12:20:00 1981 [syncadapter.ContactsSyncAdapterService] Contacts sync complete
2018-05-23 12:20:00 1981 [syncadapter.SyncAdapterService] Sync for com.android.contacts complete
2018-05-23 12:20:05 1986 [syncadapter.SyncAdapterService] com.android.calendar sync of Account {name=radicale, type=bitfire.at.davdroid} has been initiated
        PARAMETER #0 = ignore_settings, force, expedited, ignore_backoff
2018-05-23 12:20:05 1985 [syncadapter.SyncAdapterService] at.bitfire.davdroid.addressbooks sync of Account {name=radicale, type=bitfire.at.davdroid} has been initiated
        PARAMETER #0 = ignore_settings, force, expedited, ignore_backoff
2018-05-23 12:20:05 1987 [syncadapter.SyncAdapterService] org.dmfs.tasks sync of Account {name=radicale, type=bitfire.at.davdroid} has been initiated
        PARAMETER #0 = ignore_settings, force, expedited, ignore_backoff
2018-05-23 12:20:05 1986 [AccountSettings] Account radicale has version 8, current version: 8
2018-05-23 12:20:05 1986 [AndroidCalendar] Removing event colors from account Account {name=radicale, type=bitfire.at.davdroid}
2018-05-23 12:20:05 1985 [AccountSettings] Account radicale has version 8, current version: 8
2018-05-23 12:20:05 1987 [AccountSettings] Account radicale has version 8, current version: 8
2018-05-23 12:20:05 1985 [syncadapter.AddressBooksSyncAdapterService] Updating local address book https://192.168.1.101:5232/flo/3dc6a8e1-4a5a-9e2a-691d-0229ac7afcbc/
        PARAMETER #0 = CollectionInfo(url=https://192.168.1.101:5232/flo/3dc6a8e1-4a5a-9e2a-691d-0229ac7afcbc/, id=70, serviceID=29, type=ADDRESS_BOOK, readOnly=false, forceReadOnly=false, displayName=contacts, description=null, color=null, timeZone=null, supportsVEVENT=false, supportsVTODO=false, selected=true, source=null, confirmed=false)
2018-05-23 12:20:05 1985 [resource.LocalAddressBook] Address book read-only? = false
2018-05-23 12:20:05 1987 [syncadapter.TasksSyncAdapterService] Adding local task list
        PARAMETER #0 = CollectionInfo(url=https://192.168.1.101:5232/flo/24ef7f36-6269-e258-7ac8-67ab0c68b61a/, id=71, serviceID=30, type=CALENDAR, readOnly=false, forceReadOnly=false, displayName=org, description=null, color=-8758529, timeZone=null, supportsVEVENT=true, supportsVTODO=true, selected=true, source=null, confirmed=false)
2018-05-23 12:20:05 1987 [AndroidTaskList] Creating local task list: list_access_level=0 list_name=org _sync_id=https://192.168.1.101:5232/flo/24ef7f36-6269-e258-7ac8-67ab0c68b61a/ visible=1 account_type=bitfire.at.davdroid list_color=-8758529 list_owner=radicale sync_enabled=1 account_name=radicale
2018-05-23 12:20:05 1985 [syncadapter.AddressBooksSyncAdapterService] Running sync for address book
        PARAMETER #0 = Account {name=contacts (radicale gw), type=at.bitfire.davdroid.address_book}
2018-05-23 12:20:05 1985 [syncadapter.AddressBooksSyncAdapterService] Address book sync complete
2018-05-23 12:20:05 1986 [syncadapter.CalendarsSyncAdapterService] Adding local calendar
        PARAMETER #0 = CollectionInfo(url=https://192.168.1.101:5232/flo/1eaa1565-1f1a-95b2-a9d4-4b36d626d6a1/, id=73, serviceID=30, type=CALENDAR, readOnly=false, forceReadOnly=false, displayName=manu, description=null, color=-15482325, timeZone=null, supportsVEVENT=true, supportsVTODO=false, selected=true, source=null, confirmed=false)
2018-05-23 12:20:05 1986 [AndroidCalendar] Creating local calendar: calendar_color=-15482325 sync_events=1 canOrganizerRespond=1 ownerAccount=radicale visible=1 canModifyTimeZone=1 account_type=bitfire.at.davdroid allowedAttendeeTypes=0,2,1,3 allowedAvailability=0,1,2 name=https://192.168.1.101:5232/flo/1eaa1565-1f1a-95b2-a9d4-4b36d626d6a1/ allowedReminders=1,2 account_name=radicale calendar_access_level=700 calendar_displayName=manu
2018-05-23 12:20:05 1985 [syncadapter.SyncAdapterService] Sync for at.bitfire.davdroid.addressbooks complete
2018-05-23 12:20:05 1987 [syncadapter.TasksSyncAdapterService] Synchronizing task list #16 [https://192.168.1.101:5232/flo/24ef7f36-6269-e258-7ac8-67ab0c68b61a/]
2018-05-23 12:20:05 1989 [syncadapter.SyncAdapterService] com.android.contacts sync of Account {name=contacts (radicale gw), type=at.bitfire.davdroid.address_book} has been initiated
        PARAMETER #0 = ignore_settings, force, expedited, ignore_backoff
2018-05-23 12:20:05 1986 [syncadapter.CalendarsSyncAdapterService] Adding local calendar
        PARAMETER #0 = CollectionInfo(url=https://192.168.1.101:5232/flo/24ef7f36-6269-e258-7ac8-67ab0c68b61a/, id=71, serviceID=30, type=CALENDAR, readOnly=false, forceReadOnly=false, displayName=org, description=null, color=-8758529, timeZone=null, supportsVEVENT=true, supportsVTODO=true, selected=true, source=null, confirmed=false)
2018-05-23 12:20:05 1989 [AccountSettings] Account radicale has version 8, current version: 8
2018-05-23 12:20:05 1986 [AndroidCalendar] Creating local calendar: calendar_color=-8758529 sync_events=1 canOrganizerRespond=1 ownerAccount=radicale visible=1 canModifyTimeZone=1 account_type=bitfire.at.davdroid allowedAttendeeTypes=0,2,1,3 allowedAvailability=0,1,2 name=https://192.168.1.101:5232/flo/24ef7f36-6269-e258-7ac8-67ab0c68b61a/ allowedReminders=1,2 account_name=radicale calendar_access_level=700 calendar_displayName=org
2018-05-23 12:20:05 1986 [syncadapter.CalendarsSyncAdapterService] Adding local calendar
        PARAMETER #0 = CollectionInfo(url=https://192.168.1.101:5232/flo/a99ed497-74e5-969e-4781-7ec1e7844175/, id=72, serviceID=30, type=CALENDAR, readOnly=false, forceReadOnly=false, displayName=work, description=null, color=-16766465, timeZone=null, supportsVEVENT=true, supportsVTODO=false, selected=true, source=null, confirmed=false)
2018-05-23 12:20:05 1986 [AndroidCalendar] Creating local calendar: calendar_color=-16766465 sync_events=1 canOrganizerRespond=1 ownerAccount=radicale visible=1 canModifyTimeZone=1 account_type=bitfire.at.davdroid allowedAttendeeTypes=0,2,1,3 allowedAvailability=0,1,2 name=https://192.168.1.101:5232/flo/a99ed497-74e5-969e-4781-7ec1e7844175/ allowedReminders=1,2 account_name=radicale calendar_access_level=700 
[... SOME LINES REMOVED HERE IN ORDER NOT TO EXCEED MAXIMUM POST LENGTH...]
2018-05-23 12:20:05 1990 [AndroidCalendar] Creating local calendar: calendar_color=-6421823 sync_events=1 canOrganizerRespond=1 ownerAccount=radicale visible=1 canModifyTimeZone=1 account_type=bitfire.at.davdroid allowedAttendeeTypes=0,2,1,3 allowedAvailability=0,1,2 name=https://192.168.1.101:5232/flo/f76be379-1fba-edbe-20ae-3ba49cb2c5ee/ allowedReminders=1,2 account_name=radicale calendar_access_level=700 calendar_displayName=eltern
2018-05-23 12:20:05 1987 [HttpClient] <-- 200 OK https://192.168.1.101:5232/flo/24ef7f36-6269-e258-7ac8-67ab0c68b61a/c401351f40cac2aeaf32edb091ff70f8822e899b1731a6d2b53449eaae266e63.ics (60ms)
2018-05-23 12:20:05 1987 [HttpClient] Date: Wed, 23 May 2018 17:20:13 GMT
2018-05-23 12:20:05 1987 [HttpClient] Server: WSGIServer/0.2 CPython/3.6.5rc1
2018-05-23 12:20:05 1987 [HttpClient] Content-Type: text/calendar; charset=utf-8
2018-05-23 12:20:05 1987 [HttpClient] Last-Modified: Mon, 09 Oct 2017 21:22:28 GMT
2018-05-23 12:20:05 1987 [HttpClient] ETag: "e2a7fc44132227e78a7fd4eccc36729e"
2018-05-23 12:20:05 1987 [HttpClient] Content-Length: 326
2018-05-23 12:20:05 1987 [HttpClient] 
2018-05-23 12:20:05 1987 [HttpClient] BEGIN:VCALENDAR
VERSION:2.0
CALSCALE:GREGORIAN
PRODID:-//Inf-IT//InfCloud 0.13.2rc1//EN
BEGIN:VTODO
CLASS:PUBLIC
CREATED:20171009T212228Z
DTSTAMP:20171009T212228Z
LAST-MODIFIED:20171009T212228Z
PERCENT-COMPLETE:0
STATUS:NEEDS-ACTION
SUMMARY:test
UID:icuesmg7-x7nn-1o16-et7a-0lwjm1pwgrru
END:VTODO
END:VCALENDAR

2018-05-23 12:20:05 1987 [HttpClient] <-- END HTTP (326-byte body)
2018-05-23 12:20:05 1989 [syncadapter.BaseDavSyncManager] Removed 0 record(s) from server
2018-05-23 12:20:06 1989 [syncadapter.BaseDavSyncManager] Sent 0 record(s) to server
2018-05-23 12:20:06 1987 Error loading custom timezone aliases: Attempt to invoke virtual method 'int java.io.Reader.read(char[])' on a null object reference
2018-05-23 12:20:06 1990 [syncadapter.CalendarsSyncAdapterService] Calendar sync complete
2018-05-23 12:20:06 1990 [syncadapter.SyncAdapterService] Sync for com.android.calendar complete
2018-05-23 12:20:06 1989 [syncadapter.BaseDavSyncManager] Local sync state = {"type":"SYNC_TOKEN","value":"http:\/\/radicale.org\/ns\/sync\/1f94f0d7934b0126e83c0dae25271300","initialSync":false}, remote sync state = {"type":"SYNC_TOKEN","value":"http:\/\/radicale.org\/ns\/sync\/1f94f0d7934b0126e83c0dae25271300"}
2018-05-23 12:20:06 1989 [syncadapter.SyncManager] Remote collection didn't change, no reason to sync
2018-05-23 12:20:06 1989 [syncadapter.ContactsSyncAdapterService] Contacts sync complete
2018-05-23 12:20:06 1989 [syncadapter.SyncAdapterService] Sync for com.android.contacts complete
2018-05-23 12:20:06 1987 [syncadapter.TasksSyncManager] Adding c401351f40cac2aeaf32edb091ff70f8822e899b1731a6d2b53449eaae266e63.ics to local task list
2018-05-23 12:20:06 1987 [AndroidTask] Built task object
        PARAMETER #0 = mType: 1, mUri: content://org.dmfs.tasks/tasks?account_name=radicale&account_type=bitfire.at.davdroid&caller_is_syncadapter=true, mSelection: null, mExpectedCount: null, mYieldAllowed: false, mValues: percent_complete=0 is_allday=0 last_modified=1507584148000 tz=America/Chicago geo=null task_color=null dtstart=null url=null rdate=null _dirty=0 duration=null rrule=null exdate=null completed_is_allday=0 completed=null organizer=null due=null class=0 title=test description=null status=0 location=null sync_version=0 _uid=icuesmg7-x7nn-1o16-et7a-0lwjm1pwgrru list_id=16 priority=0 created=1507584148000, mValuesBackReferences: null, mSelectionArgsBackReferences: null
2018-05-23 12:20:06 1987 [BatchOperation] Committing 1 operations
2018-05-23 12:20:06 1987 [BatchOperation] Running 1 operations (0 .. 0)
2018-05-23 12:20:06 1987 [BatchOperation] … 1 record(s) affected
2018-05-23 12:20:06 1987 [syncadapter.SyncManager] Deleting entries which are not present remotely anymore
2018-05-23 12:20:06 1987 [syncadapter.BaseDavSyncManager] Removed 0 local resources which are not present on the server anymore
2018-05-23 12:20:06 1987 [syncadapter.SyncManager] Post-processing
2018-05-23 12:20:06 1987 [syncadapter.SyncManager] Saving sync state
        PARAMETER #0 = {"type":"SYNC_TOKEN","value":"http:\/\/radicale.org\/ns\/sync\/51c33ea7fcb428131844a5e855c60abd"}
2018-05-23 12:20:06 1987 [syncadapter.TasksSyncAdapterService] Task sync complete
2018-05-23 12:20:06 1987 [syncadapter.SyncAdapterService] Sync for org.dmfs.tasks complete

devvv4ever

Are the LinageOS “privacy guard” or similar features disabled for DAVdroid?

fhollerweger

@devvv4ever, this did indeed solve the problem - thanks!

For the record, in LineageOS, I went into
Settings > Personal > Privacy > Privacy Guard
and disabled the PrivacyGuard for DAVdroid there. After this, the next sync in DAVdroid removed all duplicate collections as described above, and I ended up with a single copy of all collections, and all events in those calendars successfully synced.

@devvv4ever, is there a specific reason why this would have started to become a problem only a few weeks/months ago? I do believe I ran DAVdroid under Privacy Guard just fine until recently. Also, should the disabling of Privacy Guard be considered a mere workaround or the definite solution for this kind of situation?

rfc2822

@fhollerweger As far as I know, the whole aim of the Privacy Guard is to block access to contacts and events. What should be the actual advantage of using Privacy Guard for DAVdroid?

fhollerweger

@rfc2822: I am not debating the usefulness of disabling the PrivacyGuard for DAVdroid. Rather, I am looking for an explanation why /not/ disabling it didn’t seem to cause any issue until a few weeks ago, but then suddenly became a problem.

rfc2822

@fhollerweger I only know that Privacy Guard has to be disabled for DAVdroid since I know about Privacy Guard (we even had a FAQ article about that in the beginning).

So I assume that if DAVdroid with enabled Pricacy Guard has worked some time, this was by chance and maybe even a Privacy Guard bug. After all, Privacy Guard’s task is block access to contacts and events and thus DAVdroid.

If you find anything about why its behaviour has suddenly changed, please let us know