Please see also http://bugzilla.zimbra.com/show_bug.cgi?id=84857
Waiting for feedback from Zimbra
Sync fails with "The target server failed to respond"
-
With version 0.5.10.2 (installed via F-Droid) under Android 4.1, I now get this error:
I/davdroid.SyncManager(23379): Fetching 460 new remote resource(s) I/davdroid.RemoteCollection(23379): Multi-getting 35 remote resource(s) D/ch.boye.httpclientandroidlib.wire(23379): http-outgoing-7 >> "REPORT /calendars/__uids__/2faeac7a-0279-583d-8282-ce4c6cd37a6e/calendar/ HTTP/1.1[\r][\n]" D/ch.boye.httpclientandroidlib.wire(23379): http-outgoing-7 >> "Content-Type: text/xml; charset=UTF-8[\r][\n]" D/ch.boye.httpclientandroidlib.wire(23379): http-outgoing-7 >> "Depth: 0[\r][\n]" D/ch.boye.httpclientandroidlib.wire(23379): http-outgoing-7 >> "Content-Length: 4465[\r][\n]" D/ch.boye.httpclientandroidlib.wire(23379): http-outgoing-7 >> "Host: servername:8008[\r][\n]" D/ch.boye.httpclientandroidlib.wire(23379): http-outgoing-7 >> "Connection: Keep-Alive[\r][\n]" D/ch.boye.httpclientandroidlib.wire(23379): http-outgoing-7 >> "User-Agent: DAVdroid/0.5.10.2-alpha[\r][\n]" D/ch.boye.httpclientandroidlib.wire(23379): http-outgoing-7 >> "Accept-Encoding: gzip,deflate[\r][\n]" D/ch.boye.httpclientandroidlib.wire(23379): http-outgoing-7 >> "Authorization: Basic b2xpdmVyOnBhc3M=[\r][\n]" D/ch.boye.httpclientandroidlib.wire(23379): http-outgoing-7 >> "[\r][\n]" D/ch.boye.httpclientandroidlib.wire(23379): http-outgoing-7 >> "<C:calendar-multiget xmlns:C="urn:ietf:params:xml:ns:caldav" xmlns="DAV:">[\n]" D/ch.boye.httpclientandroidlib.wire(23379): http-outgoing-7 >> " <prop>[\n]" D/ch.boye.httpclientandroidlib.wire(23379): http-outgoing-7 >> " <C:calendar-data/>[\n]" D/ch.boye.httpclientandroidlib.wire(23379): http-outgoing-7 >> " <getetag/>[\n]" D/ch.boye.httpclientandroidlib.wire(23379): http-outgoing-7 >> " </prop>[\n]" D/ch.boye.httpclientandroidlib.wire(23379): http-outgoing-7 >> " <href>/calendars/__uids__/2faeac7a-0279-583d-8282-ce4c6cd37a6e/calendar/03081c1c-060b-41e6-848e-8552eec6a86b.ics</href>[\n]"
…
D/ch.boye.httpclientandroidlib.wire(23379): http-outgoing-7 >> " <href>/calendars/__uids__/2faeac7a-0279-583d-8282-ce4c6cd37a6e/calendar/cc08285a-2b75-47c0-9c9d-8010d7e404b3.ics</href>[\n]" D/ch.boye.httpclientandroidlib.wire(23379): http-outgoing-7 >> "</C:calendar-multiget>" D/class ch.boye.httpclientandroidlib.impl.conn.DefaultManagedHttpClientConnection(23379): http-outgoing-7: Close connection D/class ch.boye.httpclientandroidlib.impl.conn.DefaultManagedHttpClientConnection(23379): http-outgoing-7: Shutdown connection D/class ch.boye.httpclientandroidlib.impl.conn.DefaultManagedHttpClientConnection(23379): http-outgoing-7: Close connection E/davdroid.DavSyncAdapter(23379): I/O error E/davdroid.DavSyncAdapter(23379): ch.boye.httpclientandroidlib.NoHttpResponseException: The target server failed to respond E/davdroid.DavSyncAdapter(23379): at ch.boye.httpclientandroidlib.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:143) E/davdroid.DavSyncAdapter(23379): at ch.boye.httpclientandroidlib.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:57) E/davdroid.DavSyncAdapter(23379): at ch.boye.httpclientandroidlib.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:260) E/davdroid.DavSyncAdapter(23379): at ch.boye.httpclientandroidlib.impl.DefaultBHttpClientConnection.receiveResponseHeader(DefaultBHttpClientConnection.java:161) E/davdroid.DavSyncAdapter(23379): at java.lang.reflect.Method.invokeNative(Native Method) E/davdroid.DavSyncAdapter(23379): at java.lang.reflect.Method.invoke(Method.java:511) E/davdroid.DavSyncAdapter(23379): at ch.boye.httpclientandroidlib.impl.conn.CPoolProxy.invoke(CPoolProxy.java:138) E/davdroid.DavSyncAdapter(23379): at $Proxy5.receiveResponseHeader(Native Method) E/davdroid.DavSyncAdapter(23379): at ch.boye.httpclientandroidlib.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:271) E/davdroid.DavSyncAdapter(23379): at ch.boye.httpclientandroidlib.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:123) E/davdroid.DavSyncAdapter(23379): at ch.boye.httpclientandroidlib.impl.execchain.MainClientExec.execute(MainClientExec.java:254) E/davdroid.DavSyncAdapter(23379): at ch.boye.httpclientandroidlib.impl.execchain.ProtocolExec.execute(ProtocolExec.java:195) E/davdroid.DavSyncAdapter(23379): at ch.boye.httpclientandroidlib.impl.execchain.RetryExec.execute(RetryExec.java:85) E/davdroid.DavSyncAdapter(23379): at ch.boye.httpclientandroidlib.impl.execchain.RedirectExec.execute(RedirectExec.java:108) E/davdroid.DavSyncAdapter(23379): at ch.boye.httpclientandroidlib.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:186) E/davdroid.DavSyncAdapter(23379): at ch.boye.httpclientandroidlib.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:82) E/davdroid.DavSyncAdapter(23379): at at.bitfire.davdroid.webdav.WebDavResource.multiGet(WebDavResource.java:298) E/davdroid.DavSyncAdapter(23379): at at.bitfire.davdroid.resource.RemoteCollection.multiGet(RemoteCollection.java:88) E/davdroid.DavSyncAdapter(23379): at at.bitfire.davdroid.syncadapter.SyncManager.pullNew(SyncManager.java:187) E/davdroid.DavSyncAdapter(23379): at at.bitfire.davdroid.syncadapter.SyncManager.synchronize(SyncManager.java:87) E/davdroid.DavSyncAdapter(23379): at at.bitfire.davdroid.syncadapter.DavSyncAdapter.onPerformSync(DavSyncAdapter.java:93) E/davdroid.DavSyncAdapter(23379): at android.content.AbstractThreadedSyncAdapter$SyncThread.run(AbstractThreadedSyncAdapter.java:254) D/SyncManager( 572): failed sync operation rb2 (bitfire.at.davdroid), com.android.calendar, USER, earliestRunTime 158299076, SyncResult: stats [ numIoExceptions: 1]
This is for a big calendar (460 items apparently); with a smaller calendar (~10-20 items) it works fine. With older versions (0.5.6 maybe?) this error didn’t occur.
The calendar is served by Darwin CalendarServer 2.4 running on Debian. It can be used fine with Thunderbird+Lightning.
Not sure yet whether the problem is on server or client side… Does the backtrace ring any bells?
-
Not sure yet whether the problem is on server or client side… Does the backtrace ring any bells?
Looks like a server problem. DAVdroid as sent a REPORT multi-get request, but the server didn’t send anything back (apparently not even headers).
-
So I think this is caused by the server closing the (HTTP keep-alive) connection, but the client doesn’t notice this (or notices too late). IIUC this is what happens:
- client opens HTTP connection (HTTP 1.1, so keep-alive is implicitly enabled)
- client sends PROPFIND request
- server sends huge HTTP 1.1 response (Content-Length: 224076)
- client has to a) receive and b) parse response, and c) create the REPORT request for first 35 items
- a+b+c takes maybe 20-40 seconds; but the server closes the HTTP connection 15 seconds after it has finished sending its response (server calls shutdown() and close() on the socket) - this is due to the default “idle timeout” in Calendarserver being set to 15 seconds
- client doesn’t notice that server has closed connection, tries to send REPORT request over socket that is already closed on server side
- server replies with TCP Reset packets, and client finally closes connection on his side, and raises error because it didn’t get a response
I have now worked around this problem by increasing the HTTP Keep-Alive timeout on server to 120 seconds, by adding these lines to
/etc/caldavd/caldavd.plist
:<key>IdleConnectionTimeOut</key> <integer>120</integer>
(this is probably a good idea anyway, performance-wise).
So the problem is aggravated by a large calendar, low-end phone (600 MHz) and low Keep-Alive timeout on server side.
It would be nice if there was a way to make the client notice that the Keep-Alive connection is closed before it sends the next request. No idea at the moment how to do that.
-
Sounds reasonable, thanks for the debugging work. I will have a look at the Keep-Alive settings.
-
I have tried this out by setting the Keep-Alive time on our server to 2 secs and adding a
Thread.sleep(5000)
between two operations so that the stale connection problem can be reproduced: In DAVroid/0.5.11, theNoHttpResponseException
(which is a soft I/O error) occurs because the HttpClient stale connection check is disabled AND there’s not appropriate retry strategy.With the new DavHttpRequestRetryHandler, the request is retried on a new connection when the old connection has got stale (closed). The stale connection check is not required because at the moment, all used HTTP verbs are idempotent.