Horde sync fails with error 401 Unauthorized since DAVdroid 0.8.1



  • Since the update, I can no longer sync with my Horde 5.2.1 server. Nothing has changed at the server, and all other programs like e.g. Thunderbird can still sync with it. But DAVdroid just stopped working.

    What can I do to fix this? I tried downgrading to 0.80 but Fdroid won't let me/gives me an installation error.


  • developer

    Thanks for your report. Please read Reporting issues and provide all information mentioned there, including detailled steps to reproduce the issue, client and server software details, and verbose logs.

    As far as I know, Android won't let you downgrade apps. You can remove DAVdroid from your device and re-install 0.8.0 at any time, but of course it would be better to see what's the cause.



  • I have the same problem, uninstall and reinstalling 0.8.0 works. I don't have time at the moment to fetch verbose logs (I need a working phone), but I can give you some more info from server-side logs.

    Client is DAVdroid 0.8.1 from F-Droid on LG p880 with CyanogenMod 10.1.3. Server is Horde 5.2.2, user authentication via IMAP. The Horde logs look like the following:

    Jul 10 19:09:38 horde HORDE: [imp] Login success for tobias (xxxx) to {imap://xxxx/} [pid 23123 on line 157 of "/usr/share/horde/imp/lib/Auth.php"]
    Jul 10 19:09:38 horde HORDE: [imp] [login] No password provided. [pid 23123 on line 726 of "/usr/share/horde/imp/lib/Imap.php"]
    Jul 10 19:09:38 horde HORDE: [imp] [login] No password provided. [pid 23123 on line 726 of "/usr/share/horde/imp/lib/Imap.php"]
    Jul 10 19:09:39 horde HORDE: [imp] [login] No password provided. [pid 23126 on line 726 of "/usr/share/horde/imp/lib/Imap.php"]
    Jul 10 19:09:39 horde HORDE: [imp] [login] No password provided. [pid 23126 on line 726 of "/usr/share/horde/imp/lib/Imap.php"]
    

    The problem is due to the "No password provided" line. Seems like DAVdroid sometimes does not provide a password when logging in? Strangely enough sometimes synchronizations go through but the next try will fail. Hope that helps at least a bit.



  • All I need to do to reproduce the bug is trying to sync, it happens every time. On my phone this here happens when I try to manually sync the calendar via DAVdroid 0.81 from FDroid on my OnePlus One running up-to-date Cyanogenmod 12S. Horde 5.2.1 server, as I wrote in the post above. I can't obtain any server-side logs for my server, but thankfully t-brink was able to reproduce this error as well so I suppose we now are able see both sides of the problem.

    For me, no synchronizations go through, not a single one. However, the error only appears when I sync calendars and contacts; for tasks, nothing happens (but then again I am not using tasks, so perhaps it just notices that and doesn't sync any.

    I/davdroid.DavSyncAdapter( 3517): Performing sync for authority com.android.calendar
    D/davdroid.DavSyncAdapter( 3517): Creating new DavHttpClient
    I/davdroid.DavHttpClient( 3517): Wire logging active, disabling HTTP compression
    V/davdroid.URIUtils( 3517): Normalized URI https://my.hordeserver.com/rpc.php/calendars/myusername%40hordeserver.com/calendar%3aknT1fW4vA3amrxUf5R3yjg2/ -> https://my.hordeserver.com/rpc.php/calendars/myusername@hordeserver.com/calendar:knT1fW4vA3amrxUf5R3yjg2/ assuming that it was an URI or path name
    D/davdroid.WebDavResource( 3517): Using preemptive authentication (not compatible with Digest auth)
    V/davdroid.URIUtils( 3517): Normalized URI https://my.hordeserver.com/rpc.php/calendars/myusername%40hordeserver.com/calendar%3a20NMEuSMkLWUwn4Zw0F60Q1/ -> https://my.hordeserver.com/rpc.php/calendars/myusername@hordeserver.com/calendar:20NMEuSMkLWUwn4Zw0F60Q1/ assuming that it was an URI or path name
    D/davdroid.WebDavResource( 3517): Using preemptive authentication (not compatible with Digest auth)
    V/davdroid.URIUtils( 3517): Normalized URI https://my.hordeserver.com/rpc.php/calendars/myusername%40hordeserver.com/calendar%7ejZBOe0ToeUhHTJDGd4KhFQ4/ -> https://my.hordeserver.com/rpc.php/calendars/myusername@hordeserver.com/calendar~jZBOe0ToeUhHTJDGd4KhFQ4/ assuming that it was an URI or path name
    D/davdroid.WebDavResource( 3517): Using preemptive authentication (not compatible with Digest auth)
    I/davdroid.SyncManager( 3517): Remotely removing 0 deleted resource(s) (if not changed)
    I/davdroid.SyncManager( 3517): Uploading 0 new resource(s) (if not existing)
    I/davdroid.SyncManager( 3517): Uploading 0 modified resource(s) (if not changed)
    D/HttpClient( 3517): CookieSpec selected: best-match
    D/HttpClient( 3517): Re-using cached 'basic' auth scheme for https://my.hordeserver.com:443
    D/HttpClient( 3517): Connection request: [route: HttpRoute[{s}->https://my.hordeserver.com:443]][total kept alive: 0; route allocated: 0 of 2; total allocated: 0 of 3]
    D/HttpClient( 3517): Connection leased: [id: 5][route: HttpRoute[{s}->https://my.hordeserver.com:443]][total kept alive: 0; route allocated: 1 of 2; total allocated: 1 of 3]
    D/HttpClient( 3517): Opening connection HttpRoute[{s}->https://my.hordeserver.com:443]
    D/HttpClient( 3517): Connecting to my.hordeserver.com/31.15.66.41:443
    D/HttpClient( 3517): Connecting socket to my.hordeserver.com/31.15.66.41:443 with timeout 20000
    D/HttpClient( 3517): Enabled protocols: [TLSv1, TLSv1.1, TLSv1.2]
    D/HttpClient( 3517): Enabled cipher suites:[TLS_ECDHE_ECDSA_WITH_AES_128_GCM_SHA256, TLS_ECDHE_ECDSA_WITH_AES_256_GCM_SHA384, TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256, TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384, TLS_DHE_RSA_WITH_AES_128_GCM_SHA256, TLS_DHE_RSA_WITH_AES_256_GCM_SHA384, TLS_ECDHE_ECDSA_WITH_AES_128_CBC_SHA, TLS_ECDHE_ECDSA_WITH_AES_256_CBC_SHA, TLS_ECDHE_RSA_WITH_AES_128_CBC_SHA, TLS_ECDHE_RSA_WITH_AES_256_CBC_SHA, TLS_DHE_RSA_WITH_AES_128_CBC_SHA, TLS_DHE_RSA_WITH_AES_256_CBC_SHA, TLS_DHE_DSS_WITH_AES_128_CBC_SHA, TLS_DHE_DSS_WITH_AES_256_CBC_SHA, TLS_ECDHE_ECDSA_WITH_RC4_128_SHA, TLS_ECDHE_RSA_WITH_RC4_128_SHA, TLS_RSA_WITH_AES_128_GCM_SHA256, TLS_RSA_WITH_AES_256_GCM_SHA384, TLS_RSA_WITH_AES_128_CBC_SHA, TLS_RSA_WITH_AES_256_CBC_SHA, SSL_RSA_WITH_RC4_128_SHA, TLS_EMPTY_RENEGOTIATION_INFO_SCSV]
    D/HttpClient( 3517): Enabling SNI for my.hordeserver.com
    D/HttpClient( 3517): Starting handshake
    D/HttpClient( 3517): Secure session established
    D/HttpClient( 3517):  negotiated protocol: TLSv1.2
    D/HttpClient( 3517):  negotiated cipher suite: TLS_DHE_RSA_WITH_AES_128_GCM_SHA256
    D/HttpClient( 3517):  peer principal: CN=cn.hordeserver.com
    D/HttpClient( 3517): Connection established 192.168.178.111:58698<->31.15.66.41:443
    D/HttpClient( 3517): Executing request PROPFIND /rpc.php/calendars/myusername@hordeserver.com/calendar~jZBOe0ToeUhHTJDGd4KhFQ4/ HTTP/1.1
    D/HttpClient( 3517): Target auth state: CHALLENGED
    D/HttpClient( 3517): Proxy auth state: UNCHALLENGED
    D/Wire    ( 3517): http-outgoing-5 >> "PROPFIND /rpc.php/calendars/myusername@hordeserver.com/calendar~jZBOe0ToeUhHTJDGd4KhFQ4/ HTTP/1.1[\r][\n]"
    D/Wire    ( 3517): http-outgoing-5 >> "Content-Type: text/xml; charset=UTF-8[\r][\n]"
    D/Wire    ( 3517): http-outgoing-5 >> "Accept: text/xml[\r][\n]"
    D/Wire    ( 3517): http-outgoing-5 >> "Depth: 0[\r][\n]"
    D/Wire    ( 3517): http-outgoing-5 >> "Content-Length: 117[\r][\n]"
    D/Wire    ( 3517): http-outgoing-5 >> "Host: my.hordeserver.com[\r][\n]"
    D/Wire    ( 3517): http-outgoing-5 >> "Connection: Keep-Alive[\r][\n]"
    D/Wire    ( 3517): http-outgoing-5 >> "User-Agent: DAVdroid/0.8.1[\r][\n]"
    D/Wire    ( 3517): http-outgoing-5 >> "Authorization: Basic <censored>[\r][\n]"
    D/Wire    ( 3517): http-outgoing-5 >> "[\r][\n]"
    D/Wire    ( 3517): http-outgoing-5 >> "<propfind xmlns="DAV:">[\n]"
    D/Wire    ( 3517): http-outgoing-5 >> "   <prop>[\n]"
    D/Wire    ( 3517): http-outgoing-5 >> "      <CS:getctag xmlns:CS="http://calendarserver.org/ns/"/>[\n]"
    D/Wire    ( 3517): http-outgoing-5 >> "   </prop>[\n]"
    D/Wire    ( 3517): http-outgoing-5 >> "</propfind>"
    D/Wire    ( 3517): http-outgoing-5 << "HTTP/1.1 207 Multi-Status[\r][\n]"
    D/Wire    ( 3517): http-outgoing-5 << "Date: Fri, 10 Jul 2015 18:25:44 GMT[\r][\n]"
    D/Wire    ( 3517): http-outgoing-5 << "Server: Apache/2.2.22 (Debian)[\r][\n]"
    D/Wire    ( 3517): http-outgoing-5 << "X-Powered-By: PHP/5.4.4-14+deb7u8[\r][\n]"
    D/Wire    ( 3517): http-outgoing-5 << "Set-Cookie: Horde=jgf9u188lp72gvqgia9at510p7; path=/; domain=my.hordeserver.com; secure; HttpOnly[\r][\n]"
    D/Wire    ( 3517): http-outgoing-5 << "Expires: Thu, 19 Nov 1981 08:52:00 GMT[\r][\n]"
    D/Wire    ( 3517): http-outgoing-5 << "Cache-Control: no-store, no-cache, must-revalidate, post-check=0, pre-check=0[\r][\n]"
    D/Wire    ( 3517): http-outgoing-5 << "Pragma: no-cache[\r][\n]"
    D/Wire    ( 3517): http-outgoing-5 << "Set-Cookie: Horde=f5cmfd0vlvr4mlevk26076jo47; path=/; domain=my.hordeserver.com; secure; HttpOnly[\r][\n]"
    D/Wire    ( 3517): http-outgoing-5 << "Set-Cookie: default_horde_view=deleted; expires=Thu, 01-Jan-1970 00:00:01 GMT; path=/; domain=my.hordeserver.com[\r][\n]"
    D/Wire    ( 3517): http-outgoing-5 << "Vary: Accept-Encoding[\r][\n]"
    D/Wire    ( 3517): http-outgoing-5 << "DAV: 1, 3, extended-mkcol, calendar-access, calendar-proxy, addressbook, 2, access-control, calendarserver-principal-property-search[\r][\n]"
    D/Wire    ( 3517): http-outgoing-5 << "Content-Length: 455[\r][\n]"
    D/Wire    ( 3517): http-outgoing-5 << "Keep-Alive: timeout=5, max=100[\r][\n]"
    D/Wire    ( 3517): http-outgoing-5 << "Connection: Keep-Alive[\r][\n]"
    D/Wire    ( 3517): http-outgoing-5 << "Content-Type: application/xml; charset=utf-8[\r][\n]"
    D/Wire    ( 3517): http-outgoing-5 << "[\r][\n]"
    D/HttpClient( 3517): Connection can be kept alive for 5000 MILLISECONDS
    D/HttpClient( 3517): Authentication succeeded
    D/HttpClient( 3517): Cookie accepted [Horde="jgf9u188lp72gvqgia9at510p7", version:0, domain:my.hordeserver.com, path:/, expiry:null]
    D/HttpClient( 3517): Cookie accepted [Horde="f5cmfd0vlvr4mlevk26076jo47", version:0, domain:my.hordeserver.com, path:/, expiry:null]
    D/HttpClient( 3517): Cookie accepted [default_horde_view="deleted", version:0, domain:my.hordeserver.com, path:/, expiry:Thu Jan 01 01:00:01 MEZ 1970]
    D/Wire    ( 3517): http-outgoing-5 << "<?xml version="1.0" encoding="utf-8"?>[\n]"
    D/Wire    ( 3517): http-outgoing-5 << "<d:multistatus xmlns:d="DAV:" xmlns:s="http://sabredav.org/ns" xmlns:cal="urn:ietf:params:xml:ns:caldav" xmlns:cs="http://calendarserver.org/ns/" xmlns:card="urn:ietf:params:xml:ns:carddav"><d:response><d:href>/rpc.php/calendars/myusername@hordeserver.com/calendar~jZBOe0ToeUhHTJDGd4KhFQ4/</d:href><d:propstat><d:prop><cs:getctag/></d:prop><d:status>HTTP/1.1 404 Not Found</d:status></d:propstat></d:response></d:multistatus>[\n]"
    V/davdroid.URIUtils( 3517): Normalized URI /rpc.php/calendars/myusername@hordeserver.com/calendar~jZBOe0ToeUhHTJDGd4KhFQ4/ -> /rpc.php/calendars/myusername@hordeserver.com/calendar~jZBOe0ToeUhHTJDGd4KhFQ4/ assuming that it was an URI or path name
    D/davdroid.WebDavResource( 3517): Processing multi-status element: https://my.hordeserver.com/rpc.php/calendars/myusername@hordeserver.com/calendar~jZBOe0ToeUhHTJDGd4KhFQ4/
    D/HttpClient( 3517): Connection [id: 5][route: HttpRoute[{s}->https://my.hordeserver.com:443]] can be kept alive for 5.0 seconds
    D/HttpClient( 3517): Connection released: [id: 5][route: HttpRoute[{s}->https://my.hordeserver.com:443]][total kept alive: 1; route allocated: 1 of 2; total allocated: 1 of 3]
    D/davdroid.SyncManager( 3517): Last local CTag = null; current remote CTag = null
    I/davdroid.SyncManager( 3517): Fetching remote resource list
    D/HttpClient( 3517): CookieSpec selected: best-match
    D/HttpClient( 3517): Cookie [version: 0][name: Horde][value: f5cmfd0vlvr4mlevk26076jo47][domain: my.hordeserver.com][path: /][expiry: null] match [(secure)my.hordeserver.com:443/rpc.php/calendars/myusername@hordeserver.com/calendar~jZBOe0ToeUhHTJDGd4KhFQ4/]
    D/HttpClient( 3517): Connection request: [route: HttpRoute[{s}->https://my.hordeserver.com:443]][total kept alive: 1; route allocated: 1 of 2; total allocated: 1 of 3]
    D/HttpClient( 3517): Connection leased: [id: 5][route: HttpRoute[{s}->https://my.hordeserver.com:443]][total kept alive: 0; route allocated: 1 of 2; total allocated: 1 of 3]
    D/HttpClient( 3517): Executing request REPORT /rpc.php/calendars/myusername@hordeserver.com/calendar~jZBOe0ToeUhHTJDGd4KhFQ4/ HTTP/1.1
    D/HttpClient( 3517): Target auth state: SUCCESS
    D/HttpClient( 3517): Proxy auth state: UNCHALLENGED
    D/Wire    ( 3517): http-outgoing-5 >> "REPORT /rpc.php/calendars/myusername@hordeserver.com/calendar~jZBOe0ToeUhHTJDGd4KhFQ4/ HTTP/1.1[\r][\n]"
    D/Wire    ( 3517): http-outgoing-5 >> "Content-Type: text/xml; charset=UTF-8[\r][\n]"
    D/Wire    ( 3517): http-outgoing-5 >> "Accept: text/xml[\r][\n]"
    D/Wire    ( 3517): http-outgoing-5 >> "Depth: 1[\r][\n]"
    D/Wire    ( 3517): http-outgoing-5 >> "Content-Length: 260[\r][\n]"
    D/Wire    ( 3517): http-outgoing-5 >> "Host: my.hordeserver.com[\r][\n]"
    D/Wire    ( 3517): http-outgoing-5 >> "Connection: Keep-Alive[\r][\n]"
    D/Wire    ( 3517): http-outgoing-5 >> "User-Agent: DAVdroid/0.8.1[\r][\n]"
    D/Wire    ( 3517): http-outgoing-5 >> "Cookie: Horde=f5cmfd0vlvr4mlevk26076jo47[\r][\n]"
    D/Wire    ( 3517): http-outgoing-5 >> "Cookie2: $Version=1[\r][\n]"
    D/Wire    ( 3517): http-outgoing-5 >> "Authorization: Basic <censored>[\r][\n]"
    D/Wire    ( 3517): http-outgoing-5 >> "[\r][\n]"
    D/Wire    ( 3517): http-outgoing-5 >> "<C:calendar-query xmlns:C="urn:ietf:params:xml:ns:caldav" xmlns="DAV:">[\n]"
    D/Wire    ( 3517): http-outgoing-5 >> "   <C:filter>[\n]"
    D/Wire    ( 3517): http-outgoing-5 >> "      <C:comp-filter name="VCALENDAR">[\n]"
    D/Wire    ( 3517): http-outgoing-5 >> "         <C:comp-filter name="VEVENT"/>[\n]"
    D/Wire    ( 3517): http-outgoing-5 >> "      </C:comp-filter>[\n]"
    D/Wire    ( 3517): http-outgoing-5 >> "   </C:filter>[\n]"
    D/Wire    ( 3517): http-outgoing-5 >> "   <prop>[\n]"
    D/Wire    ( 3517): http-outgoing-5 >> "      <getetag/>[\n]"
    D/Wire    ( 3517): http-outgoing-5 >> "   </prop>[\n]"
    D/Wire    ( 3517): http-outgoing-5 >> "</C:calendar-query>"
    D/Wire    ( 3517): http-outgoing-5 << "HTTP/1.1 401 Unauthorized[\r][\n]"
    D/Wire    ( 3517): http-outgoing-5 << "Date: Fri, 10 Jul 2015 18:25:44 GMT[\r][\n]"
    D/Wire    ( 3517): http-outgoing-5 << "Server: Apache/2.2.22 (Debian)[\r][\n]"
    D/Wire    ( 3517): http-outgoing-5 << "X-Powered-By: PHP/5.4.4-14+deb7u8[\r][\n]"
    D/Wire    ( 3517): http-outgoing-5 << "Expires: Thu, 19 Nov 1981 08:52:00 GMT[\r][\n]"
    D/Wire    ( 3517): http-outgoing-5 << "Cache-Control: no-store, no-cache, must-revalidate, post-check=0, pre-check=0[\r][\n]"
    D/Wire    ( 3517): http-outgoing-5 << "Pragma: no-cache[\r][\n]"
    D/Wire    ( 3517): http-outgoing-5 << "Set-Cookie: horde_secret_key=f5cmfd0vlvr4mlevk26076jo47; path=/; domain=my.hordeserver.com; secure; httponly[\r][\n]"
    D/Wire    ( 3517): http-outgoing-5 << "WWW-Authenticate: Basic realm="Horde DAV Server"[\r][\n]"
    D/Wire    ( 3517): http-outgoing-5 << "Vary: Accept-Encoding[\r][\n]"
    D/Wire    ( 3517): http-outgoing-5 << "Content-Length: 285[\r][\n]"
    D/Wire    ( 3517): http-outgoing-5 << "Keep-Alive: timeout=5, max=99[\r][\n]"
    D/Wire    ( 3517): http-outgoing-5 << "Connection: Keep-Alive[\r][\n]"
    D/Wire    ( 3517): http-outgoing-5 << "Content-Type: application/xml; charset=utf-8[\r][\n]"
    D/Wire    ( 3517): http-outgoing-5 << "[\r][\n]"
    D/HttpClient( 3517): Connection can be kept alive for 5000 MILLISECONDS
    D/HttpClient( 3517): Authentication required
    D/HttpClient( 3517): Clearing cached auth scheme for https://my.hordeserver.com:443
    D/HttpClient( 3517): my.hordeserver.com:443 requested authentication
    D/HttpClient( 3517): Authentication schemes in the order of preference: [negotiate, Kerberos, NTLM, Digest, Basic]
    D/HttpClient( 3517): Challenge for negotiate authentication scheme not available
    D/HttpClient( 3517): Challenge for Kerberos authentication scheme not available
    D/HttpClient( 3517): Challenge for NTLM authentication scheme not available
    D/HttpClient( 3517): Challenge for Digest authentication scheme not available
    D/HttpClient( 3517): Selected authentication options: [BASIC]
    D/Wire    ( 3517): http-outgoing-5 << "<?xml version="1.0" encoding="utf-8"?>[\n]"
    D/Wire    ( 3517): http-outgoing-5 << "<d:error xmlns:d="DAV:" xmlns:s="http://sabredav.org/ns">[\n]"
    D/Wire    ( 3517): http-outgoing-5 << "  <s:exception>Sabre\DAV\Exception\NotAuthenticated</s:exception>[\n]"
    D/Wire    ( 3517): http-outgoing-5 << "  <s:message>Username or password does not match</s:message>[\n]"
    D/Wire    ( 3517): http-outgoing-5 << "  <s:sabredav-version>1.8.10</s:sabredav-version>[\n]"
    D/Wire    ( 3517): http-outgoing-5 << "</d:error>[\n]"
    D/HttpClient( 3517): Executing request REPORT /rpc.php/calendars/myusername@hordeserver.com/calendar~jZBOe0ToeUhHTJDGd4KhFQ4/ HTTP/1.1
    D/HttpClient( 3517): Target auth state: CHALLENGED
    D/HttpClient( 3517): Generating response to an authentication challenge using basic scheme
    D/HttpClient( 3517): Proxy auth state: UNCHALLENGED
    D/Wire    ( 3517): http-outgoing-5 >> "REPORT /rpc.php/calendars/myusername@hordeserver.com/calendar~jZBOe0ToeUhHTJDGd4KhFQ4/ HTTP/1.1[\r][\n]"
    D/Wire    ( 3517): http-outgoing-5 >> "Content-Type: text/xml; charset=UTF-8[\r][\n]"
    D/Wire    ( 3517): http-outgoing-5 >> "Accept: text/xml[\r][\n]"
    D/Wire    ( 3517): http-outgoing-5 >> "Depth: 1[\r][\n]"
    D/Wire    ( 3517): http-outgoing-5 >> "Content-Length: 260[\r][\n]"
    D/Wire    ( 3517): http-outgoing-5 >> "Host: my.hordeserver.com[\r][\n]"
    D/Wire    ( 3517): http-outgoing-5 >> "Connection: Keep-Alive[\r][\n]"
    D/Wire    ( 3517): http-outgoing-5 >> "User-Agent: DAVdroid/0.8.1[\r][\n]"
    D/Wire    ( 3517): http-outgoing-5 >> "Cookie: Horde=f5cmfd0vlvr4mlevk26076jo47[\r][\n]"
    D/Wire    ( 3517): http-outgoing-5 >> "Cookie2: $Version=1[\r][\n]"
    D/Wire    ( 3517): http-outgoing-5 >> "Authorization: Basic <censored>[\r][\n]"
    D/Wire    ( 3517): http-outgoing-5 >> "[\r][\n]"
    D/Wire    ( 3517): http-outgoing-5 >> "<C:calendar-query xmlns:C="urn:ietf:params:xml:ns:caldav" xmlns="DAV:">[\n]"
    D/Wire    ( 3517): http-outgoing-5 >> "   <C:filter>[\n]"
    D/Wire    ( 3517): http-outgoing-5 >> "      <C:comp-filter name="VCALENDAR">[\n]"
    D/Wire    ( 3517): http-outgoing-5 >> "         <C:comp-filter name="VEVENT"/>[\n]"
    D/Wire    ( 3517): http-outgoing-5 >> "      </C:comp-filter>[\n]"
    D/Wire    ( 3517): http-outgoing-5 >> "   </C:filter>[\n]"
    D/Wire    ( 3517): http-outgoing-5 >> "   <prop>[\n]"
    D/Wire    ( 3517): http-outgoing-5 >> "      <getetag/>[\n]"
    D/Wire    ( 3517): http-outgoing-5 >> "   </prop>[\n]"
    D/Wire    ( 3517): http-outgoing-5 >> "</C:calendar-query>"
    D/Wire    ( 3517): http-outgoing-5 << "HTTP/1.1 401 Unauthorized[\r][\n]"
    D/Wire    ( 3517): http-outgoing-5 << "Date: Fri, 10 Jul 2015 18:25:45 GMT[\r][\n]"
    D/Wire    ( 3517): http-outgoing-5 << "Server: Apache/2.2.22 (Debian)[\r][\n]"
    D/Wire    ( 3517): http-outgoing-5 << "X-Powered-By: PHP/5.4.4-14+deb7u8[\r][\n]"
    D/Wire    ( 3517): http-outgoing-5 << "Expires: Thu, 19 Nov 1981 08:52:00 GMT[\r][\n]"
    D/Wire    ( 3517): http-outgoing-5 << "Cache-Control: no-store, no-cache, must-revalidate, post-check=0, pre-check=0[\r][\n]"
    D/Wire    ( 3517): http-outgoing-5 << "Pragma: no-cache[\r][\n]"
    D/Wire    ( 3517): http-outgoing-5 << "Set-Cookie: horde_secret_key=f5cmfd0vlvr4mlevk26076jo47; path=/; domain=my.hordeserver.com; secure; httponly[\r][\n]"
    D/Wire    ( 3517): http-outgoing-5 << "WWW-Authenticate: Basic realm="Horde DAV Server"[\r][\n]"
    D/Wire    ( 3517): http-outgoing-5 << "Vary: Accept-Encoding[\r][\n]"
    D/Wire    ( 3517): http-outgoing-5 << "Content-Length: 285[\r][\n]"
    D/Wire    ( 3517): http-outgoing-5 << "Keep-Alive: timeout=5, max=98[\r][\n]"
    D/Wire    ( 3517): http-outgoing-5 << "Connection: Keep-Alive[\r][\n]"
    D/Wire    ( 3517): http-outgoing-5 << "Content-Type: application/xml; charset=utf-8[\r][\n]"
    D/Wire    ( 3517): http-outgoing-5 << "[\r][\n]"
    D/HttpClient( 3517): Connection can be kept alive for 5000 MILLISECONDS
    D/HttpClient( 3517): Authentication required
    D/HttpClient( 3517): my.hordeserver.com:443 requested authentication
    D/HttpClient( 3517): Authorization challenge processed
    D/HttpClient( 3517): Authentication failed
    D/HttpClient( 3517): Clearing cached auth scheme for https://my.hordeserver.com:443
    D/HttpClient( 3517): Cookie accepted [horde_secret_key="f5cmfd0vlvr4mlevk26076jo47", version:0, domain:my.hordeserver.com, path:/, expiry:null]
    D/HttpClient( 3517): http-outgoing-5: Shutdown connection
    D/HttpClient( 3517): Connection discarded
    D/HttpClient( 3517): http-outgoing-5: Close connection
    D/HttpClient( 3517): Connection released: [id: 5][route: HttpRoute[{s}->https://my.hordeserver.com:443]][total kept alive: 0; route allocated: 0 of 2; total allocated: 0 of 3]
    E/davdroid.DavSyncAdapter( 3517): HTTP Unauthorized 401
    E/davdroid.DavSyncAdapter( 3517): at.bitfire.davdroid.webdav.NotAuthorizedException: 401 Unauthorized
    E/davdroid.DavSyncAdapter( 3517): 	at at.bitfire.davdroid.webdav.WebDavResource.checkResponse(WebDavResource.java:426)
    E/davdroid.DavSyncAdapter( 3517): 	at at.bitfire.davdroid.webdav.WebDavResource.checkResponse(WebDavResource.java:406)
    E/davdroid.DavSyncAdapter( 3517): 	at at.bitfire.davdroid.webdav.WebDavResource.report(WebDavResource.java:344)
    E/davdroid.DavSyncAdapter( 3517): 	at at.bitfire.davdroid.resource.RemoteCollection.getMemberETags(RemoteCollection.java:90)
    E/davdroid.DavSyncAdapter( 3517): 	at at.bitfire.davdroid.syncadapter.SyncManager.synchronize(SyncManager.java:75)
    E/davdroid.DavSyncAdapter( 3517): 	at at.bitfire.davdroid.syncadapter.DavSyncAdapter.onPerformSync(DavSyncAdapter.java:137)
    E/davdroid.DavSyncAdapter( 3517): 	at android.content.AbstractThreadedSyncAdapter$SyncThread.run(AbstractThreadedSyncAdapter.java:259)
    I/davdroid.DavSyncAdapter( 3517): Sync complete for com.android.calendar
    D/davdroid.DavSyncAdapter( 3517): Closing httpClient
    D/HttpClient( 3517): Connection manager is shutting down
    D/HttpClient( 3517): Connection manager shut down
    

    EDIT: Sorry, forgot to enable verbose logging before, now it's a verbose log that shows that the Horde server is saying "welp, you are not using the correct username/password".


  • developer

    And is the Basic Auth correct? You can just base64-decode the string, it's in the form username:password (the one from:)

    D/Wire    ( 3517): http-outgoing-5 >> "Authorization: Basic <censored>[\r][\n]"
    


  • My base64-encoded username and password are 100% correct. I can log into the web interface of the Horde server with no problem at all using the data obtained from the decoded string. The [\r][\n] part is correct, I take it?


  • developer

    So, if the credentials are sent correctly and Horde returns 401, it must be a problem with Horde?



  • But nothing changed with Horde, so that seems strange ad well. Maybe I will install the previous version and see if the authentication works differently there (e. g. different encoding of the @ sign or something of the sort)
    Am 13.07.2015 12:29 schrieb rfc2822 notifications@github.com:So, if the credentials are sent correctly and Horde returns 401, it must be a problem with Horde?

    —Reply to this email directly or view it on GitHub.


  • developer

    The @ sign is in the ASCII range, so it shouldn't be encoded.

    May it's somehow related to the Cookie support introduced with DAVdroid/0.8.1? Cookies are now stored for the sync process so that Horde can detect it's one "session".



  • If you could give me a build with cookies disabled/optional (signed via
    Fdroid), I could test that out; but not sure if that is possible. Any other
    ideas to check this?

    rfc2822 notifications@github.com schrieb am Mo., 13. Juli 2015 14:37:

    The @ sign is in the ASCII range, so it shouldn't be encoded.

    May it's somehow related to the Cookie support introduced with
    DAVdroid/0.8.1? Cookies are now stored for the sync process so that Horde
    can detect it's one "session".


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



  • DavDroid would have to release a new version to get a build signed by Fdroid.

    On 13 July 2015 15:28:32 CEST, Natanji notifications@github.com wrote:

    If you could give me a build with cookies disabled/optional (signed via
    Fdroid), I could test that out; but not sure if that is possible. Any
    other
    ideas to check this?

    rfc2822 notifications@github.com schrieb am Mo., 13. Juli 2015 14:37:

    The @ sign is in the ASCII range, so it shouldn't be encoded.

    May it's somehow related to the Cookie support introduced with
    DAVdroid/0.8.1? Cookies are now stored for the sync process so that
    Horde
    can detect it's one "session".


    Reply to this email directly or view it on GitHub

    https://github.com/bitfireAT/davdroid/issues/577#issuecomment-120913289.


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

    --
    Sent from my phone. Please excuse my brevity.



  • Well, I'm in a bit of a bad situation right now. The problem is that I have no access to the Horde server, can't provide logs there, and therefore can't file a bug report in Horde. Besides, convincing the Horde developers that the bug is at their side will be hard when essentially I will tell them "DAVdroid changed something and now it doesn't work with Horde anymore".

    Firstly, I would like someone who runs their own Horde server, like @t-brink, to file that bug report with as much info as possible so this gets fixed.

    In the meantime, users of DAVdroid should have a better option than just not using DAVdroid anymore, correct? Therefore I propose that either the DAVdroid developers try to reproduce this problem with Horde and find a workaround, or that the new auth method which seems the likely cause is given an advanced "disable" option.

    Because really, the only alternative to any user of Horde at the moment is uninstalling DAVdroid completely (losing any changed calendar/contact info in the meantime on the phone) and then installing 0.8, and staying at 0.8 indefinitely until Horde fixes this bug. Which is probably going to take a while.

    I know this situation sucks, but I believe DAVdroid should not introduce changes that completely break compatibility with one of the huge server softwares typically used with it. This is a critical bug.

    I also politely ask to remove the "need info" label, since all the info that I can provide was already provided. I will try to be of any help I can, but I don't know what to do at this point except switching to 0.8 and never updating DAVdroid again.


  • developer

    Besides, convincing the Horde developers that the bug is at their side will be hard when essentially I will tell them "DAVdroid changed something and now it doesn't work with Horde anymore".

    I don't say that the bug is on the Horde side. I just can't see any misbehaviour on DAVdroid's side when the URL and credentials are correct and Horde says 401.

    The "need info" tag is there because I don't know what to do. There's no bug identified yet. Do you have any suggestions on how to detect the possible bug in DAVdroid?


  • developer

    Just installed Horde 5.3.0 from Debian 8.0 and everything works fine…

    http-outgoing-15 >> "REPORT /horde/rpc.php/calendars/test/calendar~uw2x0m8A3cFSh9k-zctX-A1/ HTTP/1.1[\r][\n]"
    http-outgoing-15 >> "Content-Type: text/xml; charset=UTF-8[\r][\n]"
    http-outgoing-15 >> "Accept: text/xml[\r][\n]"
    http-outgoing-15 >> "Depth: 1[\r][\n]"
    http-outgoing-15 >> "Content-Length: 260[\r][\n]"
    http-outgoing-15 >> "Host: debian-test[\r][\n]"
    http-outgoing-15 >> "Connection: Keep-Alive[\r][\n]"
    http-outgoing-15 >> "User-Agent: DAVdroid/0.8.1[\r][\n]"
    http-outgoing-15 >> "Cookie: Horde=7lubh9svrqfokhnqfeh4iprem0[\r][\n]"
    http-outgoing-15 >> "Cookie2: $Version=1[\r][\n]"
    http-outgoing-15 >> "Authorization: Basic dGVzdDp0ZXN0[\r][\n]"
    http-outgoing-15 >> "[\r][\n]"
    http-outgoing-15 >> "<C:calendar-query xmlns:C="urn:ietf:params:xml:ns:caldav" xmlns="DAV:">[\n]"
    http-outgoing-15 >> "   <C:filter>[\n]"
    http-outgoing-15 >> "      <C:comp-filter name="VCALENDAR">[\n]"
    http-outgoing-15 >> "         <C:comp-filter name="VEVENT"/>[\n]"
    http-outgoing-15 >> "      </C:comp-filter>[\n]"
    http-outgoing-15 >> "   </C:filter>[\n]"
    http-outgoing-15 >> "   <prop>[\n]"
    http-outgoing-15 >> "      <getetag/>[\n]"
    http-outgoing-15 >> "   </prop>[\n]"
    http-outgoing-15 >> "</C:calendar-query>"
    http-outgoing-15 << "HTTP/1.1 207 Multi-Status[\r][\n]"
    http-outgoing-15 << "Date: Fri, 17 Jul 2015 22:13:28 GMT[\r][\n]"
    http-outgoing-15 << "Server: Apache/2.4.10 (Debian)[\r][\n]"
    http-outgoing-15 << "Expires: Thu, 19 Nov 1981 08:52:00 GMT[\r][\n]"
    http-outgoing-15 << "Cache-Control: no-store, no-cache, must-revalidate, post-check=0, pre-check=0[\r][\n]"
    http-outgoing-15 << "Pragma: no-cache[\r][\n]"
    http-outgoing-15 << "Set-Cookie: horde_secret_key=7lubh9svrqfokhnqfeh4iprem0; path=/; domain=debian-test; httponly[\r][\n]"
    http-outgoing-15 << "Vary: Brief,Prefer,Accept-Encoding[\r][\n]"
    http-outgoing-15 << "Content-Length: 529[\r][\n]"
    http-outgoing-15 << "Keep-Alive: timeout=5, max=100[\r][\n]"
    http-outgoing-15 << "Connection: Keep-Alive[\r][\n]"
    http-outgoing-15 << "Content-Type: application/xml; charset=utf-8[\r][\n]"
    http-outgoing-15 << "[\r][\n]"
    

    I need more information.

    • Which authentication type do you use?
    • Does it happen when you add only address books/calendars without entries, too?
    • If no, can you provide a contact/event that reproduces the issue?
    • Any other ideas how this can be reproduced and/or diagnosed?

  • developer

    Any news on this?


  • developer

    Closing this for now as repeated Horde testing doesn't show any problems here.

    If you have any news on this, please post here and I'll re-open.



  • I had this problem, too. For those interested: As far as I understand, it had something to do with multiple connections when synchronizing multiple calendars. This seems to be a Horde bug, actually. Maybe a change in the sync strategy caused the Horde bug to become apparent?
    Here is the ticket: http://bugs.horde.org/ticket/13449
    The Horde "No password provided" log entry is misleading and completely unrelated to the 401, by the way.

    tl;dr: Update Horde to at least 5.2.3


  • developer

    Ok, so this seems to be a third-party issue. Closing it now.


Log in to reply
 

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