OwnCloud timeout



  • 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 😕



  • To wrap up my point:

    If servers are reliable, its OK to use an “infinite” timeout – and infinite in computer language could be 5 minutes. If there are tasks, that may take a long time, its in my opinion not ok to say, they should be faster, if the answer is “but they arent”. And that again hopefully currently checked by the owncloud team…

    Best Regards,
    Tobias


  • developer

    The reason why I don’t just increase the timeout is also that I would have to introduce an “interactive” and “non-interactive” mode for HttpClient. Otherwise, the setup process could take (in the worst case) let’s say 10 requests * 5 min = 50 minutes. And nobody wants to wait 50 minutes… even 450 seconds is hard, but it’s somehow acceptable.

    Maybe there should be an interactive mode with 30 seconds timeout and a non-interactive mode with 120 seconds timeout or something like that.



  • Again I understand your point… what is worse? Wait 10 min or no functionality at all? 🙂

    I really dont want to convince you to do something… To solve my personal problem, I will find a solution… I will do a personal build of the app with a higher timeout… so I will be happy…


  • developer

    @Tobias said:

    I really dont want to convince you to do something… To solve my personal problem, I will find a solution… I will do a personal build of the app with a higher timeout… so I will be happy…

    Which should be quite simple 🙂 The timeout is in HttpClient (linked above).

    But I think I’ll raise the timeout – however, it’s also clear that then the servers will never be fixed to work efficiently (because “everything works”).



  • Lets say it will take longer, because only people who are aware of such things will write bug reports… but we already have that situation 🙂



  • @Tobias Can you try it with DAVdroid 0.6.1? This works for me. Perhaps it is the same issue like this.


Log in to reply
 

Similar topics

  • 7
  • 7
  • 3