Kolab 404 errors when syncing with DavDroid 0.8.0



  • Verified both with Kolab Now, as well as our corporate Kolab Server:

    screenshot_2015-05-30-15-30-51

    Issue occurs for calendars only, tasks seem to sync fine.

    Debug log:

    I/davdroid.SyncManager( 7664): Uploading 0 modified resource(s) (if not changed)
    I/davdroid.SyncManager( 7664): Synchronization forced
    I/davdroid.SyncManager( 7664): Fetching remote resource list
    D/HttpClient( 7664): Re-using cached 'basic' auth scheme for https://apps.kolabnow.com:443
    D/HttpClient( 7664): Connection request: [route: HttpRoute[{s}->https://apps.kolabnow.com:443]][total kept alive: 1; route allocated: 1 of 2; total allocated: 1 of 3]
    D/HttpClient( 7664): Connection leased: [id: 5][route: HttpRoute[{s}->https://apps.kolabnow.com:443]][total kept alive: 0; route allocated: 1 of 2; total allocated: 1 of 3]
    D/HttpClient( 7664): Executing request REPORT /calendars/greve@georggreve.net/c81425b202e6-3182008d3351-2712f63c/ HTTP/1.1
    D/HttpClient( 7664): Target auth state: CHALLENGED
    D/HttpClient( 7664): Proxy auth state: UNCHALLENGED
    D/Wire    ( 7664): http-outgoing-5 >> "REPORT /calendars/greve@georggreve.net/c81425b202e6-3182008d3351-2712f63c/ HTTP/1.1[\r][\n]"
    D/Wire    ( 7664): http-outgoing-5 >> "Content-Type: text/xml; charset=UTF-8[\r][\n]"
    D/Wire    ( 7664): http-outgoing-5 >> "Accept: text/xml[\r][\n]"
    D/Wire    ( 7664): http-outgoing-5 >> "Depth: 1[\r][\n]"
    D/Wire    ( 7664): http-outgoing-5 >> "Content-Length: 260[\r][\n]"
    D/Wire    ( 7664): http-outgoing-5 >> "Host: apps.kolabnow.com[\r][\n]"
    D/Wire    ( 7664): http-outgoing-5 >> "Connection: Keep-Alive[\r][\n]"
    D/Wire    ( 7664): http-outgoing-5 >> "User-Agent: DAVdroid/0.8.0[\r][\n]"
    D/Wire    ( 7664): http-outgoing-5 >> "Authorization: <stripped>
    D/Wire    ( 7664): http-outgoing-5 >> "[\r][\n]"
    D/Wire    ( 7664): http-outgoing-5 >> "<C:calendar-query xmlns:C="urn:ietf:params:xml:ns:caldav" xmlns="DAV:">[\n]"
    D/Wire    ( 7664): http-outgoing-5 >> "   <C:filter>[\n]"
    D/Wire    ( 7664): http-outgoing-5 >> "      <C:comp-filter name="VCALENDAR">[\n]"
    D/Wire    ( 7664): http-outgoing-5 >> "         <C:comp-filter name="VEVENT"/>[\n]"
    D/Wire    ( 7664): http-outgoing-5 >> "      </C:comp-filter>[\n]"
    D/Wire    ( 7664): http-outgoing-5 >> "   </C:filter>[\n]"
    D/Wire    ( 7664): http-outgoing-5 >> "   <prop>[\n]"
    D/Wire    ( 7664): http-outgoing-5 >> "      <getetag/>[\n]"
    D/Wire    ( 7664): http-outgoing-5 >> "   </prop>[\n]"
    D/Wire    ( 7664): http-outgoing-5 >> "</C:calendar-query>"
    E/ActivityManager( 1021): checkUser: useridlist=null, currentuser=0
    E/ActivityManager( 1021): checkUser: useridlist=null, currentuser=0
    E/ActivityManager( 1021): checkUser: useridlist=null, currentuser=0
    E/ActivityManager( 1021): checkUser: useridlist=null, currentuser=0
    E/Zygote  ( 9516): MountEmulatedStorage()
    E/Zygote  ( 9516): v2
    E/SELinux ( 9516): [DEBUG] get_category: variable seinfo: release sensitivity: NULL, cateogry: NULL
    E/PhoneWindow(21526): Circular progress bar not located in current window decor
    E/ActivityManager( 1021): checkUser: useridlist=null, currentuser=0
    E/ActivityManager( 1021): checkUser: useridlist=null, currentuser=0
    E/ActivityManager( 1021): checkUser: useridlist=null, currentuser=0
    E/ActivityManager( 1021): checkUser: useridlist=null, currentuser=0
    E/Zygote  ( 9534): MountEmulatedStorage()
    E/Zygote  ( 9534): v2
    E/SELinux ( 9534): [DEBUG] get_category: variable seinfo: platform sensitivity: NULL, cateogry: NULL
    E/DownloadManager( 4736): SB enabled 
    E/DownloadManager( 4736): SB enabled 
    D/Wire    ( 7664): http-outgoing-5 << "HTTP/1.1 404 Not Found[\r][\n]"
    D/Wire    ( 7664): http-outgoing-5 << "Date: Fri, 29 May 2015 14:46:45 GMT[\r][\n]"
    D/Wire    ( 7664): http-outgoing-5 << "Server: Apache[\r][\n]"
    D/Wire    ( 7664): http-outgoing-5 << "X-Frame-Options: SAMEORIGIN[\r][\n]"
    D/Wire    ( 7664): http-outgoing-5 << "Strict-Transport-Security: max-age=63072000; includeSubDomains[\r][\n]"
    D/Wire    ( 7664): http-outgoing-5 << "Transfer-Encoding: chunked[\r][\n]"
    D/Wire    ( 7664): http-outgoing-5 << "Content-Type: application/xml; charset=utf-8[\r][\n]"
    D/Wire    ( 7664): http-outgoing-5 << "[\r][\n]"
    D/HttpClient( 7664): Connection can be kept alive indefinitely
    D/HttpClient( 7664): Authentication succeeded
    D/HttpClient( 7664): http-outgoing-5: Shutdown connection
    D/HttpClient( 7664): Connection discarded
    D/HttpClient( 7664): http-outgoing-5: Close connection
    D/HttpClient( 7664): Connection released: [id: 5][route: HttpRoute[{s}->https://apps.kolabnow.com:443]][total kept alive: 0; route allocated: 0 of 2; total allocated: 0 of 3]
    E/davdroid.DavSyncAdapter( 7664): Hard HTTP error 404
    E/davdroid.DavSyncAdapter( 7664): at.bitfire.davdroid.webdav.NotFoundException: 404 Not Found
    E/davdroid.DavSyncAdapter( 7664): 	at at.bitfire.davdroid.webdav.WebDavResource.checkResponse(WebDavResource.java:427)
    E/davdroid.DavSyncAdapter( 7664): 	at at.bitfire.davdroid.webdav.WebDavResource.checkResponse(WebDavResource.java:405)
    E/davdroid.DavSyncAdapter( 7664): 	at at.bitfire.davdroid.webdav.WebDavResource.report(WebDavResource.java:343)
    E/davdroid.DavSyncAdapter( 7664): 	at at.bitfire.davdroid.resource.RemoteCollection.getMemberETags(RemoteCollection.java:100)
    E/davdroid.DavSyncAdapter( 7664): 	at at.bitfire.davdroid.syncadapter.SyncManager.synchronize(SyncManager.java:78)
    E/davdroid.DavSyncAdapter( 7664): 	at at.bitfire.davdroid.syncadapter.DavSyncAdapter.onPerformSync(DavSyncAdapter.java:146)
    E/davdroid.DavSyncAdapter( 7664): 	at android.content.AbstractThreadedSyncAdapter$SyncThread.run(AbstractThreadedSyncAdapter.java:259)
    I/davdroid.DavSyncAdapter( 7664): Sync complete for com.android.calendar
    D/davdroid.DavSyncAdapter( 7664): Closing httpClient
    D/HttpClient( 7664): Connection manager is shutting down
    D/HttpClient( 7664): Connection manager shut down
    

    Please let me know how to provide more/better information.


  • developer

    The server returns a 404 for REPORT /calendars/greve@georggreve.net/c81425b202e6-3182008d3351-2712f63c/. Is /calendars/greve@georggreve.net/c81425b202e6-3182008d3351-2712f63c/ the correct path?



  • @rfc2822 At least a PROPFIND request on the exact same path succeeds right before:

    "PROPFIND /calendars/greve@georggreve.net/c81425b202e6-3182008d3351-2712f63c/ HTTP/1.1" 207 1018 "-" "DAVdroid/0.8.0"
    "REPORT /calendars/greve@georggreve.net/c81425b202e6-3182008d3351-2712f63c/ HTTP/1.1" 404 739 "-" "DAVdroid/0.8.0"
    

    The interesting thing is that the problem does not happen with all calendars, but only one. The symptoms seem similar to #411, #427 and #443. Since they were only triggered by the 0.8.0 update, maybe there's something on DAVDroid's side that got changed and caused this?


  • admin

    Since they were only triggered by the 0.8.0 update, maybe there's something on DAVDroid's side that got changed and caused this?

    The only relevant change is that DAVdroid uses REPORT since v0.8. However, assuming the path is correct and the request is correct, I think DAVdroid can't be held resposible for getting a 404. Do you have an idea what could be wrong on the server-side?

    Maybe the server returns 404 instead of an empty response when there are not entries?



  • @devvv4ever Not sure whether "404 Not Found" is a valid server response for DAV when there is no report to be found even if the path is valid per se. So filed this as https://git.kolab.org/T474 on our end to have our team look into that as well.

    Since this peeked my curiosity I had a peek into the RFC:

    Looking at https://tools.ietf.org/html/rfc3253#section-3.6, the precondition for a client to be able to expect REPORT to work appears to be that the resource URL must have reported "(DAV:supported-report)" before. I cannot find that in the debug log, however. So unless I misread the RFC, this may be the culprit.

    Is DavDroid checking for having received "(DAV:supported-report)" before issuing REPORT?



  • @devvv4ever Additionally, perhaps it would make sense in any case to add some more resilience to the client even where servers report to support REPORT but then map report Not Found onto a 404? A case where PROPFIND on a given URL succeeds, but REPORT fails maps onto "resource Exists, report Not Found" somewhat sanely. So it is conceivable some servers might indeed take that route.

    So perhaps that is how the client should treat it and continue the sync?


  • developer

    @greve, the REPORT is not a plain WebDAV REPORT, but a CALDAV:calendar-query REPORT which MUST be supported:

    7. Calendaring reports

       This section defines the reports that CalDAV servers MUST support on
       calendar collections and calendar object resources.
    
       CalDAV servers MUST advertise support for these reports on all
       calendar collections and calendar object resources with the DAV:
       supported-report-set property, defined in Section 3.1.5 of [RFC3253].
       CalDAV servers MAY also advertise support for these reports on
       ordinary collections.
    

    So DAVdroid doesn't check for it.

    The REPORT method is essential for task sync because DAVdroid needs a way to filter only files with VEVENT / VTODO. Working around this with a hack that uses PROPFIND and checks the content type of each resource would be possible, but an ugly and error-prone approach. As CalDAV/CardDAV servers must support the REPORT methods, I think this is the way to go – and it seems to work almost everywhere, with a few exceptions. I guess we'll have to track them and find out what's wrong on the server side.

    Is there any way how I can assist you in finding the problem? The first task would be to find a reproducible way to generate those 404 errors.



  • Same problem here, but to add weirdness it affects only 2 out of 4 calendars that are all part of the same account on a Kolab-Server and part of the same DavDroid-Account.



  • Is it your locally installed Kolab Server? Which version? Are you using HA Proxy? We're currently suspecting that to play a role in this.



  • No, it's the server of kolabnow.ch, unfortunately I can't give you the details as I do not know which version the have running :( But I will ask them.



  • Ah yes. That is Kolab Now, which we run. For which it is likely a HA Proxy configuration issue as it turns out. We're looking into that.



  • I can confirm that it's an issue with Davdroid 0.8.0, I downgraded to 0.7.7 and everything works fine again.



  • Since this is also happening with my private Kolab server which does not use HA Proxy and also with other DAV servers, the HA Proxy is most likely not the culprit.


  • developer

    and also with other DAV servers

    Is it possible that all those servers use the same *DAV backend?

    If there's anything wrong with DAVdroid's behaviour, I'll be glad to fix it, but I can't see any wrong.



  • Is it possible that all those servers use the same *DAV backend?

    Yes, I think they are all using SabreDAV.


  • developer

    Yes, I think they are all using SabreDAV.

    It seems like the problem is either in SabreDAV, or it only occurs in combination with DAVdroid 0.8 REPORT requests + SabreDAV.

    Did you manage to reproduce that issue selectively?



  • Yeah, it looks like it. But it is also not consistently happening in all cases against all folders. So perhaps it's a specific set of data that plays a role as well. We're looking into this right now, gave my architect permission to look at my personal data in question.



  • As a result of some troubleshooting, we've found that SabreDAV attempts to examine the object tree for a VEVENT UID property that is (in the form of) a URI. This is very likely the cause, because removing the offending events brings the matter to resolution.

    I propose this issue is closed.


  • developer

    Is there an upstream bug report where we can point users who experience this problem?



  • So how can we detect the events that cause the error? And how can we assure that in the future no such events will be created?

    Am 19. Juni 2015 16:41:01 MESZ, schrieb Jeroen van Meeuwen notifications@github.com:

    As a result of some troubleshooting, we've found that SabreDAV attempts
    to examine the object tree for a VEVENT UID property that is (in the
    form of) a URI. This is very likely the cause, because removing the
    offending events brings the matter to resolution.

    I propose this issue is closed.


    Reply to this email directly or view it on GitHub:
    https://github.com/bitfireAT/davdroid/issues/542#issuecomment-113533797


Log in to reply
 

Looks like your connection to Bitfire App Forums was lost, please wait while we try to reconnect.