OwnCloud timeout



  • Hi rfc2822,

    Yes, before posting here the first time, I did check everything.

    Something strange, is that this calendar was working with an old version of DAVDroid on an older version of android.

    Our Owncloud server has a least 6 different calender, with all use of davdroid and working. Only the one of my girlfriend who has about 4 meeting a day 7 days a week is not synchronising.

    My device is rooted, I can write a file in the directory pointed by DAVDroid for the log file, but DAVDroid do hang when I do enable the log option.

    I did reinstall davdroid different time allready, nothing change.

    I will try tonight (GMT+1) to test the log with adb (never did that).

    Bye,
    Brisferr


  • developer

    @Brisferr Can you please send a copy of /data/data/com.android.providers.calendar/databases/calendar.db to play@bitfire.at (OpenPGP 🔑)?

    Allow root for apps in Developer/Debug Settings, then open your file manager, navigate to /data/data/com.android.providers.calendar/databases (will require root), then copy calendar.db to the SD card. Then you can send it via email. Or just fetch it via adb pull, or any other way – but the file could be helpful 😉



  • My phone is not rooted… I’ll try to get it by adb…


  • developer

    @Tobias said:

    My phone is not rooted… I’ll try to get it by adb…

    If your device is not rooted, you won’t get access to this file. Then you can just get the DAVdroid logs via adb logcat.



  • I’ll do that!



  • I just checked: I have a mail-account with the same name as my Caldav-Account… could that be a problem?

    BTW: With the Android Studio I got logs… here is an excerpt with the big calendar:

    11-26 19:26:49.320 14371-15392/? I/davdroid: Synchronizing calendar #11, URL: http://...
    11-26 19:26:49.320 14371-15392/? I/davdroid: AccountSettings version: v2, should be: 2
    11-26 19:26:49.340 14371-15392/? I/MemorizingTrustManager: getAppKeyStore(/data/data/at.bitfire.davdroid/app_KeyStore/KeyStore.bks) - exception loading file key store
                                                               java.io.FileNotFoundException: /data/data/at.bitfire.davdroid/app_KeyStore/KeyStore.bks: open failed: ENOENT (No such file or directory)
                                                                   at libcore.io.IoBridge.open(IoBridge.java:416)
                                                                   at java.io.FileInputStream.<init>(FileInputStream.java:78)
                                                                   at de.duenndns.ssl.MemorizingTrustManager.loadAppKeyStore(MemorizingTrustManager.java:327)
                                                                   at de.duenndns.ssl.MemorizingTrustManager.init(MemorizingTrustManager.java:152)
                                                                   at de.duenndns.ssl.MemorizingTrustManager.<init>(MemorizingTrustManager.java:130)
                                                                   at at.bitfire.davdroid.HttpClient.<init>(HttpClient.java:59)
                                                                   at at.bitfire.davdroid.HttpClient.<init>(HttpClient.java:104)
                                                                   at at.bitfire.davdroid.syncadapter.SyncManager.<init>(SyncManager.java:125)
                                                                   at at.bitfire.davdroid.syncadapter.CalendarSyncManager.<init>(CalendarSyncManager.java:63)
                                                                   at at.bitfire.davdroid.syncadapter.CalendarsSyncAdapterService$SyncAdapter.onPerformSync(CalendarsSyncAdapterService.java:57)
                                                                   at android.content.AbstractThreadedSyncAdapter$SyncThread.run(AbstractThreadedSyncAdapter.java:254)
                                                                Caused by: libcore.io.ErrnoException: open failed: ENOENT (No such file or directory)
                                                                   at libcore.io.Posix.open(Native Method)
                                                                   at libcore.io.BlockGuardOs.open(BlockGuardOs.java:110)
                                                                   at libcore.io.IoBridge.open(IoBridge.java:400)
                                                                   at java.io.FileInputStream.<init>(FileInputStream.java:78) 
                                                                   at de.duenndns.ssl.MemorizingTrustManager.loadAppKeyStore(MemorizingTrustManager.java:327) 
                                                                   at de.duenndns.ssl.MemorizingTrustManager.init(MemorizingTrustManager.java:152) 
                                                                   at de.duenndns.ssl.MemorizingTrustManager.<init>(MemorizingTrustManager.java:130) 
                                                                   at at.bitfire.davdroid.HttpClient.<init>(HttpClient.java:59) 
                                                                   at at.bitfire.davdroid.HttpClient.<init>(HttpClient.java:104) 
                                                                   at at.bitfire.davdroid.syncadapter.SyncManager.<init>(SyncManager.java:125) 
                                                                   at at.bitfire.davdroid.syncadapter.CalendarSyncManager.<init>(CalendarSyncManager.java:63) 
                                                                   at at.bitfire.davdroid.syncadapter.CalendarsSyncAdapterService$SyncAdapter.onPerformSync(CalendarsSyncAdapterService.java:57) 
                                                                   at android.content.AbstractThreadedSyncAdapter$SyncThread.run(AbstractThreadedSyncAdapter.java:254) 
    11-26 19:26:49.350 14371-15392/? I/davdroid: Preparing synchronization
    11-26 19:26:49.350 14371-15392/? I/davdroid: Querying capabilities
    11-26 19:26:49.860 14371-15392/? I/davdroid: Setting calendar name and color (if available)
    11-26 19:26:49.870 14371-15392/? I/davdroid: Processing locally deleted entries
    11-26 19:26:49.880 14371-15392/? I/davdroid: Locally preparing dirty entries
    11-26 19:26:49.890 14371-15392/? I/davdroid: Processing deleted exceptions
    11-26 19:26:49.900 14371-15392/? I/davdroid: Processing dirty exceptions
    11-26 19:26:49.910 14371-15392/? I/davdroid: Uploading dirty entries
    11-26 19:26:49.930 14371-15392/? I/davdroid: Checking sync state
    11-26 19:26:49.940 14371-15392/? I/davdroid: Listing local entries
    11-26 19:26:49.950 14371-15392/? I/davdroid: Listing remote entries
    11-26 19:27:34.960 14371-15392/? E/davdroid: I/O exception during sync, trying again later
                                                 java.net.SocketTimeoutException
                                                     at java.net.PlainSocketImpl.read(PlainSocketImpl.java:491)
                                                     at java.net.PlainSocketImpl.access$000(PlainSocketImpl.java:46)
                                                     at java.net.PlainSocketImpl$PlainSocketInputStream.read(PlainSocketImpl.java:240)
                                                     at okio.Okio$2.read(Okio.java:139)
                                                     at okio.AsyncTimeout$2.read(AsyncTimeout.java:211)
                                                     at okio.RealBufferedSource.indexOf(RealBufferedSource.java:306)
                                                     at okio.RealBufferedSource.indexOf(RealBufferedSource.java:300)
                                                     at okio.RealBufferedSource.readUtf8LineStrict(RealBufferedSource.java:196)
                                                     at com.squareup.okhttp.internal.http.HttpConnection.readResponse(HttpConnection.java:191)
                                                     at com.squareup.okhttp.internal.http.HttpTransport.readResponseHeaders(HttpTransport.java:80)
                                                     at com.squareup.okhttp.internal.http.HttpEngine.readNetworkResponse(HttpEngine.java:910)
                                                     at com.squareup.okhttp.internal.http.HttpEngine.access$300(HttpEngine.java:93)
                                                     at com.squareup.okhttp.internal.http.HttpEngine$NetworkInterceptorChain.proceed(HttpEngine.java:895)
                                                     at at.bitfire.davdroid.HttpClient$PreemptiveAuthenticationInterceptor.intercept(HttpClient.java:155)
                                                     at com.squareup.okhttp.internal.http.HttpEngine$NetworkInterceptorChain.proceed(HttpEngine.java:868)
                                                     at at.bitfire.davdroid.HttpClient$UserAgentInterceptor.intercept(HttpClient.java:142)
                                                     at com.squareup.okhttp.internal.http.HttpEngine$NetworkInterceptorChain.proceed(HttpEngine.java:868)
                                                     at com.squareup.okhttp.internal.http.HttpEngine.readResponse(HttpEngine.java:749)
                                                     at com.squareup.okhttp.Call.getResponse(Call.java:277)
                                                     at com.squareup.okhttp.Call$ApplicationInterceptorChain.proceed(Call.java:234)
                                                     at com.squareup.okhttp.Call.getResponseWithInterceptorChain(Call.java:196)
                                                     at com.squareup.okhttp.Call.execute(Call.java:79)
                                                     at at.bitfire.dav4android.DavCalendar.calendarQuery(DavCalendar.java:73)
                                                     at at.bitfire.davdroid.syncadapter.CalendarSyncManager.listRemote(CalendarSyncManager.java:117)
                                                     at at.bitfire.davdroid.syncadapter.SyncManager.performSync(SyncManager.java:172)
                                                     at at.bitfire.davdroid.syncadapter.CalendarsSyncAdapterService$SyncAdapter.onPerformSync(CalendarsSyncAdapterService.java:58)
                                                     at android.content.AbstractThreadedSyncAdapter$SyncThread.run(AbstractThreadedSyncAdapter.java:254)
    11-26 19:27:34.960 14371-15392/? I/davdroid: Synchronizing calendar #12, URL: http://...
    

    edit: made logs readable by surrounding them with ```



  • Another try:

    11-26 19:33:39.340 14371-15605/? I/davdroid: Synchronizing calendar #11, URL: http://...
    11-26 19:33:39.340 14371-15605/? I/davdroid: AccountSettings version: v2, should be: 2
    11-26 19:33:39.370 14371-15605/? I/MemorizingTrustManager: getAppKeyStore(/data/data/at.bitfire.davdroid/app_KeyStore/KeyStore.bks) - exception loading file key store
                                                               java.io.FileNotFoundException: /data/data/at.bitfire.davdroid/app_KeyStore/KeyStore.bks: open failed: ENOENT (No such file or directory)
                                                                   at libcore.io.IoBridge.open(IoBridge.java:416)
                                                                   at java.io.FileInputStream.<init>(FileInputStream.java:78)
                                                                   at de.duenndns.ssl.MemorizingTrustManager.loadAppKeyStore(MemorizingTrustManager.java:327)
                                                                   at de.duenndns.ssl.MemorizingTrustManager.init(MemorizingTrustManager.java:152)
                                                                   at de.duenndns.ssl.MemorizingTrustManager.<init>(MemorizingTrustManager.java:130)
                                                                   at at.bitfire.davdroid.HttpClient.<init>(HttpClient.java:59)
                                                                   at at.bitfire.davdroid.HttpClient.<init>(HttpClient.java:104)
                                                                   at at.bitfire.davdroid.syncadapter.SyncManager.<init>(SyncManager.java:125)
                                                                   at at.bitfire.davdroid.syncadapter.CalendarSyncManager.<init>(CalendarSyncManager.java:63)
                                                                   at at.bitfire.davdroid.syncadapter.CalendarsSyncAdapterService$SyncAdapter.onPerformSync(CalendarsSyncAdapterService.java:57)
                                                                   at android.content.AbstractThreadedSyncAdapter$SyncThread.run(AbstractThreadedSyncAdapter.java:254)
                                                                Caused by: libcore.io.ErrnoException: open failed: ENOENT (No such file or directory)
                                                                   at libcore.io.Posix.open(Native Method)
                                                                   at libcore.io.BlockGuardOs.open(BlockGuardOs.java:110)
                                                                   at libcore.io.IoBridge.open(IoBridge.java:400)
                                                                   at java.io.FileInputStream.<init>(FileInputStream.java:78) 
                                                                   at de.duenndns.ssl.MemorizingTrustManager.loadAppKeyStore(MemorizingTrustManager.java:327) 
                                                                   at de.duenndns.ssl.MemorizingTrustManager.init(MemorizingTrustManager.java:152) 
                                                                   at de.duenndns.ssl.MemorizingTrustManager.<init>(MemorizingTrustManager.java:130) 
                                                                   at at.bitfire.davdroid.HttpClient.<init>(HttpClient.java:59) 
                                                                   at at.bitfire.davdroid.HttpClient.<init>(HttpClient.java:104) 
                                                                   at at.bitfire.davdroid.syncadapter.SyncManager.<init>(SyncManager.java:125) 
                                                                   at at.bitfire.davdroid.syncadapter.CalendarSyncManager.<init>(CalendarSyncManager.java:63) 
                                                                   at at.bitfire.davdroid.syncadapter.CalendarsSyncAdapterService$SyncAdapter.onPerformSync(CalendarsSyncAdapterService.java:57) 
                                                                   at android.content.AbstractThreadedSyncAdapter$SyncThread.run(AbstractThreadedSyncAdapter.java:254) 
    11-26 19:33:39.370 14371-15605/? I/davdroid: Preparing synchronization
    11-26 19:33:39.370 14371-15605/? I/davdroid: Querying capabilities
    11-26 19:33:39.880 14371-15605/? I/davdroid: Setting calendar name and color (if available)
    11-26 19:33:39.890 14371-15605/? I/davdroid: Processing locally deleted entries
    11-26 19:33:39.900 14371-15605/? I/davdroid: Locally preparing dirty entries
    11-26 19:33:39.900 14371-15605/? I/davdroid: Processing deleted exceptions
    11-26 19:33:39.920 14371-15605/? I/davdroid: Processing dirty exceptions
    11-26 19:33:39.940 14371-15605/? I/davdroid: Uploading dirty entries
    11-26 19:33:39.950 14371-15605/? I/davdroid: Checking sync state
    11-26 19:33:39.960 14371-15605/? I/davdroid: Listing local entries
    11-26 19:33:39.970 14371-15605/? I/davdroid: Listing remote entries
    11-26 19:34:24.980 14371-15605/? E/davdroid: I/O exception during sync, trying again later
                                                 java.net.SocketTimeoutException
                                                     at java.net.PlainSocketImpl.read(PlainSocketImpl.java:491)
                                                     at java.net.PlainSocketImpl.access$000(PlainSocketImpl.java:46)
                                                     at java.net.PlainSocketImpl$PlainSocketInputStream.read(PlainSocketImpl.java:240)
                                                     at okio.Okio$2.read(Okio.java:139)
                                                     at okio.AsyncTimeout$2.read(AsyncTimeout.java:211)
                                                     at okio.RealBufferedSource.indexOf(RealBufferedSource.java:306)
                                                     at okio.RealBufferedSource.indexOf(RealBufferedSource.java:300)
                                                     at okio.RealBufferedSource.readUtf8LineStrict(RealBufferedSource.java:196)
                                                     at com.squareup.okhttp.internal.http.HttpConnection.readResponse(HttpConnection.java:191)
                                                     at com.squareup.okhttp.internal.http.HttpTransport.readResponseHeaders(HttpTransport.java:80)
                                                     at com.squareup.okhttp.internal.http.HttpEngine.readNetworkResponse(HttpEngine.java:910)
                                                     at com.squareup.okhttp.internal.http.HttpEngine.access$300(HttpEngine.java:93)
                                                     at com.squareup.okhttp.internal.http.HttpEngine$NetworkInterceptorChain.proceed(HttpEngine.java:895)
                                                     at at.bitfire.davdroid.HttpClient$PreemptiveAuthenticationInterceptor.intercept(HttpClient.java:155)
                                                     at com.squareup.okhttp.internal.http.HttpEngine$NetworkInterceptorChain.proceed(HttpEngine.java:868)
                                                     at at.bitfire.davdroid.HttpClient$UserAgentInterceptor.intercept(HttpClient.java:142)
                                                     at com.squareup.okhttp.internal.http.HttpEngine$NetworkInterceptorChain.proceed(HttpEngine.java:868)
                                                     at com.squareup.okhttp.internal.http.HttpEngine.readResponse(HttpEngine.java:749)
                                                     at com.squareup.okhttp.Call.getResponse(Call.java:277)
                                                     at com.squareup.okhttp.Call$ApplicationInterceptorChain.proceed(Call.java:234)
                                                     at com.squareup.okhttp.Call.getResponseWithInterceptorChain(Call.java:196)
                                                     at com.squareup.okhttp.Call.execute(Call.java:79)
                                                     at at.bitfire.dav4android.DavCalendar.calendarQuery(DavCalendar.java:73)
                                                     at at.bitfire.davdroid.syncadapter.CalendarSyncManager.listRemote(CalendarSyncManager.java:117)
                                                     at at.bitfire.davdroid.syncadapter.SyncManager.performSync(SyncManager.java:172)
                                                     at at.bitfire.davdroid.syncadapter.CalendarsSyncAdapterService$SyncAdapter.onPerformSync(CalendarsSyncAdapterService.java:58)
                                                     at android.content.AbstractThreadedSyncAdapter$SyncThread.run(AbstractThreadedSyncAdapter.java:254)
    

    edit: made logs readable by surrounding them with ```



  • The last trace seems to repeat with some minutes delay…


  • developer

    java.net.SocketTimeoutException

    Well the case seems pretty clear… your server doesn’t respond in time for the “big” calendar, so DAVdroid can’t synchronize.

    That also explains why only big calendars are a problem – the server is fast enough for the small ones.

    So I think this is clearly a server issue? Listing elements should never take longer than 45 seconds before the first byte is sent.



  • That is kind of strange… Thunderbird and EasyDav are working without problem. And without delay.

    Does DavDroid use some special query to the server? Could you tell me, which query it could be? Then I can go find out, why it takes so long?

    EasyDav is based on an older Version of DavDroid – so the special query must have been added to a newer version of DavDroid?

    Thanks,
    Tobias


  • developer

    @Tobias As far as I know, CalDAV doesn’t make a difference between “special” and “non-special” commands. DAVdroid sends a REPORT calendar-query request.

    You can try it with curl:

    curl -vX REPORT -H 'Depth: 1' -H 'Content-Type: application/xml; charset=utf-8' --data @cq.xml -u username:password https://calendar-url/as/seen/in/logs
    
    # cq.xml:
    <CAL:calendar-query xmlns="DAV:" xmlns:CAL="urn:ietf:params:xml:ns:caldav">
    <prop>
      <getetag/>
    </prop>
    <CAL:filter>
      <CAL:comp-filter name="VCALENDAR">
        <CAL:comp-filter name="VEVENT"/>
      </CAL:comp-filter>
    </CAL:filter>
    </CAL:calendar-query>
    


  • Answer from owncloud to that:

    <?xml version="1.0" encoding="utf-8"?>
    <d:error xmlns:d="DAV:" xmlns:s="http://sabredav.org/ns">
      <s:sabredav-version>2.1.7</s:sabredav-version>
      <s:exception>Sabre\DAV\Exception\ReportNotSupported</s:exception>
      <s:message></s:message>
      <d:supported-report/>
    </d:error>
    

    I dont have a clue, what that means… Maybe you could add logs in DavDroid to show, which request failed?

    😕

    BTW: You are really doing a good job here!!


  • developer

    @Tobias I have edited cq.xml above, can you try with the updated one?



  • I got a very big answer to that request, but it took about 60 seconds. The answer started with:

    <?xml version="1.0" encoding="utf-8"?>
    <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/"><d:response><d:href>/remote.php/caldav/calendar .....
    

    That seems to be better? Maybe you could extend the timeout a little (much)? What has changed since an older version of DavDroid: the timeout or the request?

    Again – doing a great job here…


  • developer

    @Tobias said:

    I got a very big answer to that request, but it took about 60 seconds.

    This is the problem. 60 seconds is far too long, and the current DAVdroid read timeout is 45 seconds.

    In my opinion, a server shouldn’t need 60 seconds to process some indexed items.

    Maybe you could extend the timeout a little (much)?

    What would you consider a good value? 60 seconds? As far as I know, there have already been requests to set it to 120 seconds. And of course, when I set it to 120 seconds, there will be people who want 600 seconds.

    I suggest asking in the OwnCloud community why the request takes so long and whether this is an error.



  • OK. But why does EasyDav work? It is based on an older version of DavDroid? What is that request doing? What is the change since an older version of DavDroid? Is the request new or the timeout?


  • developer

    @Tobias said:

    OK. But why does EasyDav work? It is based on an older version of DavDroid? What is that request doing? What is the change since an older version of DavDroid? Is the request new or the timeout?

    As far as I remember, both (timeout and request) have changed over time. Earlier DAVdroid versions (without tasks support) used PROPFIND instead of REPORT calendar-query. Seems that EasyDAV is based on such an early DAVdroid version.

    However – why does it matter? The problem has been identified.



  • OK sorry… I dont want to upset you. I am a fan of “defensive programming”. When there is a way with less error potential, I go for it… if that report takes potentially a long time, then I would try to ship around… But I really am not a specialist in Dav-Servers…


  • developer

    @Tobias said:

    OK sorry… I dont want to upset you. I am a fan of “defensive programming”. When there is a way with less error potential, I go for it…

    … and get no tasks synchronization; also, there are other reasons why we have chosen REPORT calendar-query. It’s the right request for what we want to receive. 🙂

    if that report takes potentially a long time, then I would try to ship around…

    Maybe it actually makes sense to increase the timeout. I would just like to know what a good value would be (based on arguments, not feelings). Which values are used by other clients? As far as I know, the standards don’t suggest any value.

    However, at first I would like to know why OwnCloud takes that long. How many entries does the calendar have? Is there no index and does OwnCloud have to scan every single entry? Even then, how can that take 60 seconds? Do you have a powerful server or a rather weak embedded PC (Raspberry etc.)?



  • Cool – talking to a technician, who can discuss things without taking them personally… like that! In my job I dont have that often 🙂

    I have just posted that issue to owncloud: https://forum.owncloud.org/viewtopic.php?f=36&t=31760

    Lets see, if they answer to it.

    I see the problem about the timeout and you are right… just increasing it wont help… when the calendar gets bigger, we have to increase it again.

    I think this is a matter of believe :-): First we need to answer your question, if owncloud is lazy with the request or if the request is tricky. If the request is tricky, then DavDroid needs a solution for the problem. If or if not, maybe here is an argument:

    The current behaviour is little bit suspicious about the server, if it will or will not answer. We give him an amount of time which in general is OK, but not in special cases. And when he cant succeed in time, we expect him to be crashed and go into a timeout.

    Lets say, we increase timeout to 5 minutes… But: Increasing the timeout so much would imply the confidence, that the server will answer at all… whenever… (yeah… believe in servers :-)!!) If servers are more or less reliable, then a high timeout will help with that problem, because we are sure (and believe in), that the answer will come at all (whenever)…

    If servers are more or less unreliable, then we need suspicion… and a timeout at 45s is OK. (Depending on first question: is it a tricky request?!?).

    BTW: I am running my owncloud on webspace with MySQL-DB… Dont know, what hardware they have 😕


Log in to reply
 

Similar topics