Sync fails because of "Couldn't unbind CustomCertService"



  • Hi there.

    I have run into a problem with 2.0.5-ose installed from F-Droid.

    I have done the following steps:

    1. Ran DAVdroid < 2.0.5-ose (don't remember the version) for years with a self-hosted Baikal instance.
    2. Turned off the Baikal instance.
    3. Exported all calendars to .ics-files using the app "Calendar Import Export"
    4. Removed DAVdroid from phone
    5. Created an account at posteo.de
    6. Installed DAVdroid 2.0.5-ose on phone
    7. Created calendars on posteo.de
    8. Logged into posteo.de account in DAVdroid 2.0.5-ose
    9. Set all sync intervalls to 60 minutes and set to sync all past events
    10. Enabled logging to external file
    11. Imported .ics-File with about 1300 entries to a posteo.de calendar using the app "Calendar Import Export".
    12. Start a sync in DAVdroid settings
    13. Wait
    14. No events appear in posteo.de web interface
    15. Look inside external log file.
    16. Find the following entries in the log file (see end of post). (I have anonymized the log and removed a lot of info. I am happy to submit the full anonymized file via a private message or the likes):
    17. Remove DAVdroid 2.0.5-ose and install DAVdroid 2.0.3-ose
    18. Remove all calendars in posteo.de
    19. Redo steps 7-13 with DAVdroid 2.0.3-ose
    20. Events appear in posteo.de and are synced properly.

    Unfortunately I won't be able to test further, because 2.0.3-ose is working and I don't want to mess with the now working setup.

    I'm curious to hear your thoughts.

    Thanks for the great work, btw, I appreciate it!

    Log file of DAVdroid 2.0.5-ose:

    2018-11-14 22:52:18 4747 [AndroidEvent] Read event entity from calender provider
    	PARAMETER #0 = availability=0 dtstart=1498867200000 lastSynced=0 duration=P1D rrule=FREQ=MONTHLY accessLevel=0 eventTimezone=UTC allDay=1 hasAttendeeData=0 _id=9273 guestsCanModify=1 uid2445=87ac2b81-7389-493a-9746-e5db77a685aa dirty=1 guestsCanInviteOthers=1 cal_sync1={"type":"CTAG","value":"0"} guestsCanSeeGuests=1 selfAttendeeStatus=0 mutators=org.sufficientlysecure.ical hasExtendedProperties=0 organizer=<anonymized> title=<anynomized> calendar_id=3 deleted=0 hasAlarm=0 isOrganizer=0
    
    
    
    <removed tons of entries "Read event entity from calender provider">
    
    
    2018-11-14 22:53:20 4747 [AndroidEvent] Read event entity from calender provider
    	PARAMETER #0 = availability=0 dtstart=1479378600000 lastSynced=0 accessLevel=0 eventTimezone=Europe/Paris allDay=0 dtend=1479384000000 hasAttendeeData=0 _id=9869 guestsCanModify=1 uid2445=8d8ef415-a999-4595-a2df-1c1cfe1b9cfe dirty=1 guestsCanInviteOthers=1 lastDate=1479384000000 cal_sync1={"type":"CTAG","value":"0"} guestsCanSeeGuests=1 eventEndTimezone=Europe/Paris selfAttendeeStatus=0 mutators=org.sufficientlysecure.ical hasExtendedProperties=0 organizer=<anonymized> title=<anonymized> calendar_id=3 deleted=0 hasAlarm=0 isOrganizer=0
    2018-11-14 22:53:20 4747 [CustomCertManager] Couldn't unbind CustomCertService
    EXCEPTION java.lang.IllegalArgumentException: Service not registered: at.bitfire.cert4android.CustomCertManager$1@4effc3c
    	at android.app.LoadedApk.forgetServiceDispatcher(LoadedApk.java:1289)
    	at android.app.ContextImpl.unbindService(ContextImpl.java:1483)
    	at android.content.ContextWrapper.unbindService(ContextWrapper.java:648)
    	at at.bitfire.cert4android.CustomCertManager.close(CustomCertManager.kt:115)
    	at at.bitfire.davdroid.HttpClient.close(HttpClient.kt:65)
    	at at.bitfire.davdroid.syncadapter.SyncManager.close(SyncManager.kt:101)
    	at kotlin.jdk7.AutoCloseableKt.closeFinally(AutoCloseable.kt:59)
    	at at.bitfire.davdroid.syncadapter.CalendarsSyncAdapterService$CalendarsSyncAdapter.sync(CalendarsSyncAdapterService.kt:55)
    	at at.bitfire.davdroid.syncadapter.SyncAdapterService$SyncAdapter.onPerformSync(SyncAdapterService.kt:84)
    	at android.content.AbstractThreadedSyncAdapter$SyncThread.run(AbstractThreadedSyncAdapter.java:272)
    
    2018-11-14 22:53:20 4747 [syncadapter.CalendarsSyncAdapterService] Couldn't sync calendars
    EXCEPTION java.lang.InterruptedException: Sync was cancelled
    	at at.bitfire.davdroid.syncadapter.SyncManager.abortIfCancelled(SyncManager.kt:588)
    	at at.bitfire.davdroid.syncadapter.SyncManager$uploadDirty$1.invoke(SyncManager.kt:302)
    	at at.bitfire.davdroid.syncadapter.SyncManager$uploadDirty$1.invoke(SyncManager.kt:55)
    	at at.bitfire.davdroid.syncadapter.SyncManager.useLocal(SyncManager.kt:760)
    	at at.bitfire.davdroid.syncadapter.SyncManager.uploadDirty(SyncManager.kt:301)
    	at at.bitfire.davdroid.syncadapter.SyncManager$performSync$1.invoke(SyncManager.kt:123)
    	at at.bitfire.davdroid.syncadapter.SyncManager$performSync$1.invoke(SyncManager.kt:55)
    	at at.bitfire.davdroid.syncadapter.SyncManager.unwrapExceptions(SyncManager.kt:800)
    	at at.bitfire.davdroid.syncadapter.SyncManager.performSync(SyncManager.kt:109)
    	at at.bitfire.davdroid.syncadapter.CalendarsSyncAdapterService$CalendarsSyncAdapter.sync(CalendarsSyncAdapterService.kt:56)
    	at at.bitfire.davdroid.syncadapter.SyncAdapterService$SyncAdapter.onPerformSync(SyncAdapterService.kt:84)
    	at android.content.AbstractThreadedSyncAdapter$SyncThread.run(AbstractThreadedSyncAdapter.java:272)
    
    2018-11-14 22:53:20 4747 [syncadapter.CalendarsSyncAdapterService] Calendar sync complete
    2018-11-14 22:53:20 4747 [settings.Settings] Couldn't unbind Settings service
    EXCEPTION java.lang.IllegalArgumentException: Service not registered: at.bitfire.davdroid.settings.Settings$Companion$getInstance$serviceConn$1@af48b6a
    	at android.app.LoadedApk.forgetServiceDispatcher(LoadedApk.java:1289)
    	at android.app.ContextImpl.unbindService(ContextImpl.java:1483)
    	at android.content.ContextWrapper.unbindService(ContextWrapper.java:648)
    	at at.bitfire.davdroid.settings.Settings$Stub.close(Settings.kt:223)
    	at kotlin.jdk7.AutoCloseableKt.closeFinally(AutoCloseable.kt:56)
    	at at.bitfire.davdroid.syncadapter.SyncAdapterService$SyncAdapter.onPerformSync(SyncAdapterService.kt:75)
    	at android.content.AbstractThreadedSyncAdapter$SyncThread.run(AbstractThreadedSyncAdapter.java:272)
    
    2018-11-14 22:53:20 4747 [syncadapter.SyncAdapterService] Sync for (com.android.calendar, Account {name=<anonymized>@posteo.de, type=bitfire.at.davdroid}) finished```


  • Update:
    I have now run into the same issue on 2.0.3-ose!
    The sync ends with the message " Couldn't unbind CustomCertService"

    Does not seem to be a bug that was introduced between 2.0.3-ose and 2.0.5-ose.



  • Debug log for 2.0.3-ose is:

    --- BEGIN DEBUG INFO ---
    
    SOFTWARE INFORMATION
    Package: at.bitfire.davdroid
    Version: 2.0.3-ose (244) from Aug 30, 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: denied
    android.permission.WRITE_CONTACTS permission: denied
    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: <anonymized>@<anonymized>
      Address book sync. interval: 60 min
      Calendar     sync. interval: 60 min
      OpenTasks    sync. interval: 60 min
      WiFi only: false
      [CardDAV] Contact group method: CATEGORIES
      [CalDAV] Time range (past days): null
               Manage calendar colors: true
    
    SQLITE DUMP
    android_metadata
    	|  locale |
    	|  en_US |
    ----------
    services
    	|  _id | accountName | service | principal |
    	|  1 | <anonymized>@<anonymized> | carddav | https://posteo.de:8443/principals/<anonymized><anonymized>/ |
    	|  2 | <anonymized>@<anonymized> | caldav | https://posteo.de:8443/principals/<anonymized><anonymized>/ |
    ----------
    sqlite_sequence
    	|  name | seq |
    	|  services | 2 |
    	|  homesets | 2 |
    	|  collections | 3 |
    ----------
    homesets
    	|  _id | serviceID | url |
    	|  1 | 1 | https://posteo.de:8443/addressbooks/<anonymized><anonymized>/ |
    	|  2 | 2 | https://posteo.de:8443/calendars/<anonymized><anonymized>/ |
    ----------
    collections
    	|  _id | serviceID | type | url | privWriteContent | privUnbind | forceReadOnly | displayName | description | color | timezone | supportsVEVENT | supportsVTODO | source | sync |
    	|  1 | 1 | ADDRESS_BOOK | https://posteo.de:8443/addressbooks/<anonymized><anonymized>/default/ | 1 | 1 | 0 | default addressbook | <null> | <null> | <null> | 0 | 0 | <null> | 0 |
    	|  2 | 2 | CALENDAR | https://posteo.de:8443/calendars/<anonymized><anonymized>/default/ | 1 | 1 | 0 | nicht benutzt | <null> | -5717279 | <null> | 1 | 1 | <null> | 0 |
    	|  3 | 2 | CALENDAR | https://posteo.de:8443/calendars/<anonymized><anonymized>/htszvo/ | 1 | 1 | 0 | Persönlich | <null> | -5717279 | <null> | 1 | 1 | <null> | 1 |
    ----------
    
    SYSTEM INFORMATION
    Android version: 7.1.2 (lineage_athene-userdebug 7.1.2 NJH47F 3fbfe6998a)
    Device: Motorola Moto G4 (athene)
    
    --- END DEBUG INFO ---
    


  • I can import the .ics-file to a local Thunderbird calendar without problems.

    If I create a posteo.de CalDav calendar in Thunderbird and then import the .ics-file, the import fails for 51 entries.
    So it seems like the problem is not related to DAVdroid but to posteo.de or my .ics-file.

    However the error message DAVdroid produces is not very helpful 🙂



  • I've been able to figure out why the import in Thunderbird failed for the 51 entries:

    If the UID of a VEVENT contains "@domainname.tld" or "@machine-name", the Posteo.de CalDAV server returns HTTP statuscode 404 for the REPORT HTTP method.

    I have now removed all occurences of "@followedbyastring" and successfully imported my .ics-file with Thunderbird.

    I have not tested the import on my phone using DAVdroid and Calendar Import Export.

    Should Posteo.de support occurences of "@followedbyastring" in a UID?

    If I have time to do so, I will report this issue to Posteo.de
    But please: Feel free to test and report the issue to Posteo.de

    Sorry for the noise, I initially thought this was a DAVdroid problem.