OwnCloud times out since DAVdroid/0.8.0

DAVx⁵
Log in to reply
  • A

    DAVdroid 0.7.x was syncing fine with my home run Debian/wheezy ownCloud 7.0.2+dfsg-1~bpo70+2 server. I upgraded to DAVdroid 0.8.0 and syncing the calendar stopped working. My contacts are still syncing fine. When I force a calendar sync the wheel turns for ~ 49 seconds (on the server apache2 is using 98% of the CPU during this time) and then the sync stops and the time of the last successful sync (“1/06/2015 21:05”) is shown again.

    The logs show:

    D/davdroid.SyncManager( 8840): Last local CTag = 10474; current remote CTag = 10477
I/davdroid.SyncManager( 8840): Fetching remote resource list
D/HttpClient( 8840): Connection request: [route: HttpRoute[{s}->https://owncloud.?????:443]][total kept alive: 1; route allocated: 1 of 2; total allocated: 1 of 3]
D/HttpClient( 8840): Connection leased: [id: 40][route: HttpRoute[{s}->https://owncloud.?????:443]][total kept alive: 0; route allocated: 1 of 2; total allocated: 1 of 3]
D/HttpClient( 8840): Executing request REPORT /remote.php/caldav/calendars/stuart/personal/ HTTP/1.1
D/HttpClient( 8840): Target auth state: SUCCESS
D/HttpClient( 8840): Proxy auth state: UNCHALLENGED
D/Wire    ( 8840): http-outgoing-40 >> "REPORT /remote.php/caldav/calendars/stuart/personal/ HTTP/1.1[\r][\n]"
D/Wire    ( 8840): http-outgoing-40 >> "Content-Type: text/xml; charset=UTF-8[\r][\n]"
D/Wire    ( 8840): http-outgoing-40 >> "Accept: text/xml[\r][\n]"
D/Wire    ( 8840): http-outgoing-40 >> "Depth: 1[\r][\n]"
D/Wire    ( 8840): http-outgoing-40 >> "Content-Length: 260[\r][\n]"
D/Wire    ( 8840): http-outgoing-40 >> "Host: owncloud.?????[\r][\n]"
D/Wire    ( 8840): http-outgoing-40 >> "Connection: Keep-Alive[\r][\n]"
D/Wire    ( 8840): http-outgoing-40 >> "User-Agent: DAVdroid/0.8.0[\r][\n]"
D/Wire    ( 8840): http-outgoing-40 >> "Authorization: Basic c3R1YXJ0OW15NjcxSuaw==[\r][\n]"
D/Wire    ( 8840): http-outgoing-40 >> "[\r][\n]"
D/Wire    ( 8840): http-outgoing-40 >> "<C:calendar-query xmlns:C="urn:ietf:params:xml:ns:caldav" xmlns="DAV:">[\n]"
D/Wire    ( 8840): http-outgoing-40 >> "   <C:filter>[\n]"
D/Wire    ( 8840): http-outgoing-40 >> "      <C:comp-filter name="VCALENDAR">[\n]"
D/Wire    ( 8840): http-outgoing-40 >> "         <C:comp-filter name="VEVENT"/>[\n]"
D/Wire    ( 8840): http-outgoing-40 >> "      </C:comp-filter>[\n]"
D/Wire    ( 8840): http-outgoing-40 >> "   </C:filter>[\n]"
D/Wire    ( 8840): http-outgoing-40 >> "   <prop>[\n]"
D/Wire    ( 8840): http-outgoing-40 >> "      <getetag/>[\n]"
D/Wire    ( 8840): http-outgoing-40 >> "   </prop>[\n]"
D/Wire    ( 8840): http-outgoing-40 >> "</C:calendar-query>"
D/davdroid.DavSyncAdapter( 8840): Closing httpClient
D/Wire    ( 8840): http-outgoing-40 << "[read] I/O error: Read timed out"
D/HttpClient( 8840): http-outgoing-40: Close connection
D/HttpClient( 8840): http-outgoing-40: Shutdown connection
D/HttpClient( 8840): Connection discarded
D/HttpClient( 8840): http-outgoing-40: Close connection
D/HttpClient( 8840): Connection released: [id: 40][route: HttpRoute[{s}->https://owncloud.?????:443]][total kept alive: 0; route allocated: 0 of 2; total allocated: 0 of 3]
E/davdroid.DavSyncAdapter( 8840): I/O error (Android will try again later)
E/davdroid.DavSyncAdapter( 8840): java.net.SocketTimeoutException: Read timed out
E/davdroid.DavSyncAdapter( 8840): 	at com.android.org.conscrypt.NativeCrypto.SSL_read(Native Method)
E/davdroid.DavSyncAdapter( 8840): 	at com.android.org.conscrypt.OpenSSLSocketImpl$SSLInputStream.read(OpenSSLSocketImpl.java:690)
E/davdroid.DavSyncAdapter( 8840): 	at org.apache.http.impl.conn.LoggingInputStream.read(LoggingInputStream.java:87)
E/davdroid.DavSyncAdapter( 8840): 	at org.apache.http.impl.io.SessionInputBufferImpl.streamRead(SessionInputBufferImpl.java:136)
E/davdroid.DavSyncAdapter( 8840): 	at org.apache.http.impl.io.SessionInputBufferImpl.fillBuffer(SessionInputBufferImpl.java:152)
E/davdroid.DavSyncAdapter( 8840): 	at org.apache.http.impl.io.SessionInputBufferImpl.readLine(SessionInputBufferImpl.java:270)
E/davdroid.DavSyncAdapter( 8840): 	at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:140)
E/davdroid.DavSyncAdapter( 8840): 	at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:57)
E/davdroid.DavSyncAdapter( 8840): 	at org.apache.http.impl.io.AbstractMessageParserHC4.parse(AbstractMessageParserHC4.java:260)
E/davdroid.DavSyncAdapter( 8840): 	at org.apache.http.impl.DefaultBHttpClientConnection.receiveResponseHeader(DefaultBHttpClientConnection.java:161)
E/davdroid.DavSyncAdapter( 8840): 	at org.apache.http.impl.conn.CPoolProxy.receiveResponseHeader(CPoolProxy.java:153)
E/davdroid.DavSyncAdapter( 8840): 	at org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:279)
E/davdroid.DavSyncAdapter( 8840): 	at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:121)
E/davdroid.DavSyncAdapter( 8840): 	at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:260)
E/davdroid.DavSyncAdapter( 8840): 	at org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:195)
E/davdroid.DavSyncAdapter( 8840): 	at org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:86)
E/davdroid.DavSyncAdapter( 8840): 	at org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:108)
E/davdroid.DavSyncAdapter( 8840): 	at org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:178)
E/davdroid.DavSyncAdapter( 8840): 	at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:82)
E/davdroid.DavSyncAdapter( 8840): 	at at.bitfire.davdroid.webdav.WebDavResource.report(WebDavResource.java:339)
E/davdroid.DavSyncAdapter( 8840): 	at at.bitfire.davdroid.resource.RemoteCollection.getMemberETags(RemoteCollection.java:100)
E/davdroid.DavSyncAdapter( 8840): 	at at.bitfire.davdroid.syncadapter.SyncManager.synchronize(SyncManager.java:78)
E/davdroid.DavSyncAdapter( 8840): 	at at.bitfire.davdroid.syncadapter.DavSyncAdapter.onPerformSync(DavSyncAdapter.java:146)
E/davdroid.DavSyncAdapter( 8840): 	at android.content.AbstractThreadedSyncAdapter$SyncThread.run(AbstractThreadedSyncAdapter.java:259)
I/davdroid.DavSyncAdapter( 8840): Sync complete for com.android.calendar
D/HttpClient( 8840): Connection manager is shutting down
D/HttpClient( 8840): Connection manager shut down

    I tried to simulate the above request using curl to get an idea of how long ownCloud needs to complete the request. Is this the right way to do a REPORT request using curl?

    :; time curl  -o /tmp/report -v -X REPORT  --user "$user:$pw" -d @/tmp/filename.dat https://$host/remote.php/caldav/calendars/$user/personal/
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
  0     0    0     0    0     0      0      0 --:--:-- --:--:-- --:--:--     0*   Trying 88.171.134.228...
* Connected to owncloud.????? (88.171.134.228) port 443 (#0)
* found 174 certificates in /etc/ssl/certs/ca-certificates.crt
* ALPN, offering http/1.1
  0     0    0     0    0     0      0      0 --:--:-- --:--:-- --:--:--     0* SSL connection using TLS1.2 / RSA_AES_128_CBC_SHA1
* 	 server certificate verification OK
* 	 server certificate status verification SKIPPED
* 	 common name: owncloud.????? (matched)
* 	 server certificate expiration date OK
* 	 server certificate activation date OK
* 	 certificate public key: RSA
* 	 certificate version: #3
* 	 subject: C=IT,L=Sydney,O=Pook IT,CN=owncloud.?????
* 	 start date: Tue, 11 Nov 2014 23:02:37 GMT
* 	 expire date: Fri, 29 Oct 2066 23:02:37 GMT
* 	 issuer: C=IT,L=Sydney,O=Pook IT,CN=owncloud.?????
* 	 compression: NULL
* ALPN, server did not agree to a protocol
* Server auth using Basic with user 'stuart'
> REPORT /remote.php/caldav/calendars/stuart/personal/ HTTP/1.1
> Host: owncloud.?????
> Authorization: Basic c3rR1YXJ0jw+oSnVuaw==
> User-Agent: curl/7.42.1
> Accept: */*
> Content-Length: 251
> Content-Type: application/x-www-form-urlencoded
> 
} [251 bytes data]
* upload completely sent off: 251 out of 251 bytes
100   251    0     0  100   251      0      2  0:02:05  0:01:45  0:00:20     0< HTTP/1.1 207 Multi-Status
< Date: Sat, 06 Jun 2015 22:51:01 GMT
< Server: Apache
< X-Powered-By: PHP/5.4.39-0+deb7u2
< Set-Cookie: oce327bbe=tr9omm7; path=/; HttpOnly
< Expires: Thu, 19 Nov 1981 08:52:00 GMT
< Cache-Control: no-store, no-cache, must-revalidate, post-check=0, pre-check=0
< Pragma: no-cache
< Strict-Transport-Security: max-age=31536000
< X-XSS-Protection: 1; mode=block
< X-Content-Type-Options: nosniff
< X-Frame-Options: Sameorigin
< Content-Security-Policy: default-src 'self'; script-src 'self' 'unsafe-eval'; style-src 'self' 'unsafe-inline'; frame-src *; img-src *; font-src 'self' data:; media-src *
< X-Robots-Tag: none
< Set-Cookie: oce3247b7abe=29m1l64ha5; path=/; secure; HttpOnly
< Vary: Brief,Prefer
< Transfer-Encoding: chunked
< Content-Type: application/xml; charset=utf-8
< 
{ [7 bytes data]
100  997k    0  997k  100   251   9591      2  0:02:05  0:01:46  0:00:19  227k
* Connection #0 to host owncloud.????? left intact

real	1m46.480s
user	0m0.020s
sys	0m0.012s
:; cat /tmp/filename.dat 
<C:calendar-query xmlns:C="urn:ietf:params:xml:ns:caldav" xmlns="DAV:">
   <C:filter>
      <C:comp-filter name="VCALENDAR">
         <C:comp-filter name="VEVENT"/>
      </C:comp-filter>
   </C:filter>
   <prop>
      <getetag/>
   </prop>
</C:calendar-query>

    My ownCloud server is a SheevaPlug and I’m the only user.

    0
  • A

    I have 3827 calendar entries (I think).

    :; tr '<' '\n' <  /tmp/report | grep /remote.php/caldav/calendars | wc -l
3827

    mysql> select count(*) from oc_clndr_objects;
+----------+
| count(*) |
+----------+
|     3827 |
+----------+
1 row in set (0.02 sec)
    0
  • A

    My Android phone running Davdroid and my ownCloud server are on the same LAN.

    0
  • A

    Given that 5f3c6045d819057d1e71fb920291b04b16693bd3 “Implement remote filters to fetch only CalDAV resources with useful components (VEVENT for now)” (added in 0.8.0) mentions “REPORT” the next step is to downgrade. Why does f-droid say “(De-)Installation Error” when I try to downgrade to 0.7.7? I have > 2 GB of free space in internal storage.

    0
  • rfc2822
    developer

    Querying a few thousands records should be done in <1 second, except you have a very slow 8 MHz embedded server or something like that.

    Could you please look up / report this to the OwnCloud tracker, so that I can reference it when closing here?

    Why does f-droid say “(De-)Installation Error” when I try to downgrade to 0.7.7? I have > 2 GB of free space in internal storage.

    I don’t know. Maybe another Android bug. Try deinstalling and installing it again.

    0
  • A

    I added the time in seconds of each request to my apache2 log messages. You can see that this “REPORT” took 629 seconds.

    192.168.0.254 - stuart [07/Jun/2015:12:31:05 +0200] "PROPFIND /remote.php/caldav/calendars/stuart/personal/ HTTP/1.1" 207 397 "-" "DAVdroid/0.8.0" 1
192.168.0.254 - stuart [07/Jun/2015:12:39:31 +0200] "PROPFIND /remote.php/carddav/addressbooks/stuart/contacts/ HTTP/1.1" 207 408 "-" "DAVdroid/0.8.0" 0
192.168.0.254 - stuart [07/Jun/2015:12:31:07 +0200] "REPORT /remote.php/caldav/calendars/stuart/personal/ HTTP/1.1" 207 1021285 "-" "DAVdroid/0.8.0" 629

    I asked mysql to log all requests that take more than 2 seconds and there aren’t any. When the REPORT is running sometimes it is apache2 that is using all the CPU time. Sometimes it is mysqld and apache2 together.

    0
  • A

    @stuart12 Fdroid hides useful error messages from Android’s package installer. I’d take a look into the logcat.

    0
  • A

    My server is a SheevaPlug with a 1.2 GHz ARM Marvell Kirkwood 88F6281 CPU and 512 Mb of RAM.

    I’ll look at the Fdroid logs for the downgrade problem.

    0
  • A

    Well this is what android.packageinstaller says when I try to downgrade to DADdroid 0.7.7.

    D/ApkDownloader( 2153): Download finished: /data/data/org.fdroid.fdroid/cache/temp/at.bitfire.davdroid_63.apk
I/ActivityManager(  847): START u0 {act=android.intent.action.INSTALL_PACKAGE dat=file:///data/data/org.fdroid.fdroid/cache/temp/at.bitfire.davdroid_63.apk cmp=com.android.packageinstaller/.PackageInstallerActivity (has extras)} from pid 2153
I/ActivityManager(  847): Displayed com.android.packageinstaller/.PackageInstallerActivity: +335ms
I/Timeline( 2479): Timeline: Activity_idle id: android.os.BinderProxy@42232460 time:1558298
I/Timeline(  847): Timeline: Activity_windows_visible id: ActivityRecord{421a8880 u0 com.android.packageinstaller/.PackageInstallerActivity t3} time:1558578
I/Timeline( 2479): Timeline: Activity_launch_request id:com.android.packageinstaller time:1562168
I/ActivityManager(  847): START u0 {dat=file:///data/data/org.fdroid.fdroid/cache/temp/at.bitfire.davdroid_63.apk flg=0x2000000 cmp=com.android.packageinstaller/.InstallAppProgress (has extras)} from pid 2479
W/InstallAppProgress( 2479): Replacing package:at.bitfire.davdroid
W/ActivityManager(  847): No content provider found for permission revoke: file:///data/data/org.fdroid.fdroid/cache/temp/at.bitfire.davdroid_63.apk
W/PackageManager(  847): Can't install update of at.bitfire.davdroid update version 63 is older than installed version 66
I/ActivityManager(  847): Displayed com.android.packageinstaller/.InstallAppProgress: +115ms
D/AppDetails( 2153): Getting application details for at.bitfire.davdroid
E/AppDetails( 2153): Installer aborted with errorCode: 2
    0
  • A

    W/PackageManager( 847): Can’t install update of at.bitfire.davdroid update version 63 is older than installed version 66

    I think you’ll have to uninstall and install the old version then. “oandbackup” can help you with preserving your app data

    0
  • A

    I managed to downgrade!

    :; adb push /tmp/at.bitfire.davdroid_63.apk //storage/emulated/legacy/at.bitfire.davdroid_63.apk
5208 KB/s (1314324 bytes in 0.246s)
:; adb shell pm install  -r -d /storage/emulated/legacy/at.bitfire.davdroid_63.apk
	pkg: /storage/emulated/legacy/at.bitfire.davdroid_63.apk
Success

    and now I can sync my calendar again. The requests are very long and too close to the timeout for comfort as they go up to 26 seconds:

    192.168.0.254 - stuart [07/Jun/2015:13:37:46 +0200] "PROPFIND /remote.php/caldav/calendars/stuart/contact_birthdays/ HTTP/1.1" 207 22716 "-" "DAVdroid/0.7.7" 4
192.168.0.254 - stuart [07/Jun/2015:13:37:53 +0200] "PROPFIND /remote.php/caldav/calendars/stuart/personal/ HTTP/1.1" 207 1396623 "-" "DAVdroid/0.7.7" 26
192.168.0.254 - stuart [07/Jun/2015:13:39:35 +0200] "REPORT /remote.php/caldav/calendars/stuart/personal/ HTTP/1.1" 207 7110 "-" "DAVdroid/0.7.7" 0
192.168.0.254 - stuart [07/Jun/2015:13:39:38 +0200] "PROPFIND /remote.php/caldav/calendars/stuart/personal/ HTTP/1.1" 207 397 "-" "DAVdroid/0.7.7" 0
192.168.0.254 - stuart [07/Jun/2015:13:39:39 +0200] "PROPFIND /remote.php/caldav/calendars/stuart/contact_birthdays/ HTTP/1.1" 207 411 "-" "DAVdroid/0.7.7" 0
    0
  • A

    I hope that OwnCloud fixes the REPORT performance problem as I’d like to be able to sync my tasks (feature introduced in DAVdroid v0.8.0 at the same time as the use of REPORT).

    0
  • A

    I too use a small device to serve owncloud calendar and contact data. I wonder if it would be possible to do one of the following:

    1. Make the connection timeout configurable by the user:
      (HttpUrlConnection) conn.setConnectTimeout(sec * 1000);

    2. Just set a longer timeout:
      (HttpUrlConnection) conn.setConnectTimeout(300 * 1000);

    3. Do an exponential- or linear-style backoff if the connection gets java.net.SocketTimeoutException; start with 60sec (remember, this is a maximum timeout), and go up by there.

    0
  • rfc2822
    developer

    Do you really think this should be work-arounded on client side? A server shouldn’t take 300 seconds to answer such a request.

    Maybe increasing would be a good idea nevertheless, but to which value? Do you know reasonable values and references/explanations why these values are reasonable?

    0
  • A

    Well, like the original poster, I too have a very slow server, which has worked well until now. I don’t want to keep a fast and/or powerful server running all the time just to coordinate calendars on my devices. I am annoyed that ownCloud takes a long time to serve this request, and I wish they would fix that. At the same time, if there is a small fix on the client side that would help in the short term, and would not break things in the long term, I’d like to explore that.

    The first option would be to let the user configure the timeout; most users would not change it at all.

    The third option could just start with the default timeout, and then an exponential backoff with an algorithm of choice; that’s not different from typical collision detection algorithms for, e.g., layer 2.

    I can’t really justify the hard coded 300 seconds in the second option other than it would work for me, and it should not affect the typical user who has a fast server and connection.

    0
  • A

    I suggest that the third option, an exponential backup, is not worth the time spent on it. You could screw up implementing it, and all to work around a server side bug. If one were to use a client side fix to fix a server side problem, a simple fix such as the second one – extending the time to 300 seconds – is the simplest and therefore safest choice. Whether that is worthwhile on the whole I do not know. After all, what do you do, add it and then remove it a year from now when most (but not all!) servers have upgraded to a less buggy OwnCloud? That’s no good, so maybe it stays around for a very long time.

    0
  • rfc2822
    developer

    Just think of the auto-detection and that a server doesn’t respond at all because of mis-configuration. This would mean that when adding an account, you would have to wait 300 seconds (=5 min) in the “Please wait” fragment until the “No CalDAV/CardDAV service found” message appears. I think that would be quite annoying… just as an example what can happen. Also people, might report “My sync process has started and the green wheel is spinning for 4 minutes, but nothing happens” in such a case. I don’t like a timeout of 300 seconds.

    Would be interesting to know what timeouts other clients like Thunderbird or Evolution use.

    0
  • A

    Well, socket timeouts could continue to happen for any reasons: slow server, slow connection, giant reply message (does anyone ever delete old calendar entries?), etc. I think in general having /some/ reasonable way to handle timeouts is not a bad idea, even if the general case is DAVdroid connecting to fast servers over fast connections.

    0
  • A

    Don’t set the long timeout when adding an account, just on the sync calls. In most cases, for most people, their sync won’t take the whole 5 minutes, so they should never see a problem. And for people like stuart and me, we can start using DAVdroid again without downgrading to < 0.8.

    If you don’t like a timeout of 300sec, then would you consider letting the user configure it? Most people won’t, so they won’t have any more issues than they do now, and DAVdroid will start working for me again.

    I can confirm that Thunderbird/Icedove works like DAVdroid < 0.8 - it doesn’t use the REPORT query. I can still see my calendars on my desktop.

    0
  • rfc2822
    developer

    Well, socket timeouts could continue to happen for any reasons: slow server, slow connection, giant reply message (does anyone ever delete old calendar entries?), etc. I think in general having /some/ reasonable way to handle timeouts is not a bad idea, even if the general case is DAVdroid connecting to fast servers over fast connections.

    The timeouts you mention are handled in different ways:

    • ConnectTimeout is the timeout value for connecting to the socket (regardless of the reply), i.e. if the timeout is 40, a server may take 39 seconds to reply with SYN+ACK, while
    • SocketTimeout defines how long a read() call may block until a SocketTimeoutException is thrown.

    The first timeout is usually not a problem and a Web server thing, while the second one is given by the actual CalDAV/CardDAV application.

    • Slow connection: the connection timeout applies. Please note that in case of a connection timeout (for instance, because mobile network is connected, but not able to transfer data [e.g. train tunnel] for 45 seconds) the sync process will fail softly and Android will retry again in a short time.
    • Slow server: the socket timeout applies.
    • Giant reply message: no timeout will occur, except when the server takes too long to calculate the reply (in this case: see “slow server”).

    Don’t set the long timeout when adding an account, just on the sync calls.

    Do you really think DavHttpClient should have different timeouts for different actions? This would mean implementing a “mode”, for instance interactive mode and sync mode.

    Most people won’t, so they won’t have any more issues than they do now, and DAVdroid will start working for me again.

    I recommend to stay with DAVdroid 0.7.7 until the OwnCloud problem is fixed. Would that be a solution for you?

    0

Similar topics

  • T


    DAVx⁵ •

    45
  • A


    DAVx⁵ •

    6
  • R


    DAVx⁵ •

    2