CalDAV syncing crashes: Could not allocate CursorWindow due to error -12



  • I noticed that davdroid stopped syncing my calender, so made sure I run the latest version and I investigated. Triggering a manual sync did not get me my events, it produced the following messages:

    D/SyncManager(  397): setSyncAutomatically:  provider com.android.calendar, user 0 -> false
    D/dalvikvm(24046): GC_CONCURRENT freed 1390K, 30% free 5789K/8195K, paused 8ms+10ms, total 107ms
    D/SyncManager(  397): setSyncAutomatically:  provider com.android.calendar, user 0 -> true
    I/davdroid.DavSyncAdapter(24444): Performing sync for authority com.android.calendar
    I/davdroid.WebDavResource(24444): Using preemptive authentication (not compatible with Digest auth)
    I/davdroid.SyncManager(24444): Remotely removing 0 deleted resource(s) (if not changed)
    I/davdroid.SyncManager(24444): Uploading 0 new resource(s) (if not existing)
    I/davdroid.SyncManager(24444): Uploading 0 modified resource(s) (if not changed)
    D/davdroid.HttpPropfind(24444): Prepared PROPFIND request: <propfind xmlns="DAV:">
    D/davdroid.HttpPropfind(24444):    <prop>
    D/davdroid.HttpPropfind(24444):       <CS:getctag xmlns:CS="http://calendarserver.org/ns/"/>
    D/davdroid.HttpPropfind(24444):    </prop>
    D/davdroid.HttpPropfind(24444): </propfind>
    I/davdroid.SNISocketFactory(24444): No SNI support below Android 4.2!
    I/davdroid.SNISocketFactory(24444): Established TLSv1 connection with dav.myserver.de using TLS_DHE_RSA_WITH_AES_256_CBC_SHA
    D/davdroid.WebDavResource(24444): Received HTTP/1.1 207 Multi-Status
    D/davdroid.WebDavResource(24444): Processing multi-status element: https://dav.myserver.de/calendars/me%40myserver.de/f75745c2e1ff-43ce65bf664b-61b19136/
    D/davdroid.WebDavResource(24444): Content: <?xml version="1.0" encoding="utf-8"?>
    D/davdroid.WebDavResource(24444): <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>/calendars/me%40myserver.de/f75745c2e1ff-43ce65bf664b-61b19136/</d:href><d:propstat><d:prop><cs:getctag>1297553617-52-519</cs:getctag></d:prop><d:status>HTTP/1.1 200 OK</d:status></d:propstat></d:response></d:multistatus>
    

    So I created a new event in my Android calendar and triggered a sync again, this time lots and lots of debug messages came, but still no events in my calender. I share some of the logcat output below to help you finding the problem:

    I/davdroid.DavSyncAdapter(24444): Performing sync for authority com.android.calendar
    I/davdroid.WebDavResource(24444): Using preemptive authentication (not compatible with Digest auth)
    I/davdroid.SyncManager(24444): Remotely removing 0 deleted resource(s) (if not changed)
    D/dalvikvm(24444): GC_CONCURRENT freed 3535K, 56% free 3619K/8195K, paused 3ms+5ms, total 76ms
    I/davdroid.SyncManager(24444): Uploading 1 new resource(s) (if not existing)
    D/davdroid.WebDavResource(24444): Sending PUT request: BEGIN:VCALENDAR
    D/davdroid.WebDavResource(24444): VERSION:2.0                                                                                                                                       
    D/davdroid.WebDavResource(24444): PRODID:-//bitfire web engineering//DAVdroid 0.5.2-alpha//EN                                                                                       
    D/davdroid.WebDavResource(24444): BEGIN:VEVENT                                                                                                                                      
    [...]                                                                                                                                                                               
    D/davdroid.WebDavResource(24444): END:VCALENDAR                                                                                                                                     
    I/davdroid.SNISocketFactory(24444): No SNI support below Android 4.2!                                                                                                               
    I/davdroid.SNISocketFactory(24444): Established TLSv1 connection with dav.myserver.de using TLS_DHE_RSA_WITH_AES_256_CBC_SHA                                                        
    D/davdroid.WebDavResource(24444): Received HTTP/1.1 201 Created                                                                                                                     
    I/davdroid.LocalCollection(24444): Committing 2 operations                                                                                                                          
    I/davdroid.SyncManager(24444): Uploading 0 modified resource(s) (if not changed)                                                                                                    
    I/davdroid.SyncManager(24444): Fetching remote resource list                                                                                                                        
    D/davdroid.HttpPropfind(24444): Prepared PROPFIND request: <propfind xmlns="DAV:">                                                                                                  
    D/davdroid.HttpPropfind(24444):    <prop>                                                                                                                                           
    D/davdroid.HttpPropfind(24444):       <CS:getctag xmlns:CS="http://calendarserver.org/ns/"/>                                                                                        
    D/davdroid.HttpPropfind(24444):       <getetag/>                                                                                                                                    
    D/davdroid.HttpPropfind(24444):    </prop>                                                                                                                                          
    D/davdroid.HttpPropfind(24444): </propfind>                                                                                                                                         
    W/SingleClientConnManager(24444): Invalid use of SingleClientConnManager: connection still allocated.                                                                               
    W/SingleClientConnManager(24444): Make sure to release the connection before allocating another one.                                                                                
    I/davdroid.SNISocketFactory(24444): No SNI support below Android 4.2!                                                                                                               
    I/davdroid.SNISocketFactory(24444): Established TLSv1 connection with dav.myserver.de using TLS_DHE_RSA_WITH_AES_256_CBC_SHA                                                        
    D/davdroid.WebDavResource(24444): Processing multi-status element: https://dav.myserver.de/calendars/me%40myserver.de/f75745c2e1ff-43ce65bf664b-61b19136/                           
    

    and many more of these multi-status elements, then suddenly this:

    D/davdroid.WebDavResource(24444): Content: <?xml version="1.0" encoding="utf-8"?>
    D/davdroid.WebDavResource(24444): <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>/calendars/me%40myserver.de/f75745c2e1ff-43ce65bf664b-61b19136/</d:href><d:propstat><d:prop><cs:getctag>1297553617-53-520</cs:getctag></d:prop><d:status>HTTP/1.1 200 OK</d:status></d:propstat><d:propstat><d:prop><d:getetag/></d:prop><d:status>HTTP/1.1 404 Not Found</d:status></d:propstat></d:response><d:response><d:href>/calendars/me%40myserver.de/f75745c2e1ff-43ce65bf664b-61b19136/KOrganizer-63059839.988.ics</d:href><d:propstat><d:prop><d:getetag>"23ecc39ae88f7904-7"</d:getetag></d:prop><d:status>HTTP/1.1 200 OK</d:status></d:propstat><d:propstat><d:prop><cs:getctag/></d:prop><d:status>HTTP/1.1 404 Not Found</d:status></d:propstat></d:response><d:response><d:href>/calendars/me%40myserver.de/f75745c2e1ff-43ce65bf664b-61b19136/KOrganizer-2006058353.906.ics</d:href><d:propstat><d:prop><d:getetag>"1daaa65aa8aa70e7-8"</d:getetag></d:prop><d:status>HTTP/1.1 200 OK</d:status></d:propstat><d:propstat><d:prop><cs:getctag/></d:prop><d:status>HTTP/1.1 404 Not Found</d:status></d:propstat></d:response><d:response><d:href>/calendars/me%40myserver.de/f75745c2e1ff-43ce65bf664b-61b19136/KOrganizer-1488543495.812.ics</d:href><d:propstat><d:prop><d:getetag>"2557581738d408f9-9"</d:getetag></d:prop><d:status>HTTP/1.1 200 OK</d:status></d:propstat><d:propstat><d:prop><cs:getctag/></d:prop><d:status>HTTP/1.1 404 Not Found</d:status></d:propstat></d:response><d:response><d:href>/calendars/me%40myserver.de/f75745c2e1ff-43ce65bf664b-61b19136/KOrganizer-336135994.761.ics</d:href><d:propstat><d:prop><d:getetag>"abbb821b67e7b310-10"</d:getetag></d:prop><d:status>HTTP/1.1 200 OK</d:status></d:propstat><d:propstat><d:prop><cs:getctag/></d:prop><d:status>HTTP/1.1 404 Not Found</d:status></d:propstat></d:response><d:response><d:href>/calendars/me%40myserver.de/f75745c2e1ff-43ce65bf664b-61b19136/KOrganizer-1858651979.70.ics</d:href><d:propstat><d:prop><d:getetag>"ab302a42e24563ad-11"</d:getetag></d:prop><d:status>HTTP/1.1 200 OK</d:status></d:propstat><d:propstat><d:prop><cs:getctag/></d:prop><d:status>HTTP/1.1 404 Not Found</d:status></d:propstat></d:response><d:response><d:href>/calendars/me%40myserver.de/f75745c2e1ff-43ce65bf664b-61b19136/KOrganizer-414760586.664.ics</d:href><d:propstat><d:prop><d:getetag>"10cca3e54e847109-12"</d:getetag></d:prop><d:status>HTTP/1.1 200 OK</d:status></d:propstat><d:propstat><d:prop><cs:getctag/></d:prop><d:status>HTTP/1.1 404 Not Found</d:status></d:propstat></d:response><d:response><d:href>/calendars/me%40myserver.de/f75745c2e1ff-43ce65bf664b-61b19136/KOrganizer-609449351.726.ics</d:href><d:propstat><d:prop><d:getetag>"324ffd435fb18883-13"</d:getetag></d:prop><d:status>HTTP/1.1 200 OK</d:status></d:propstat><d:propstat><d:prop><cs:getctag/></d:prop><d:status>HTTP/1.1 404 Not Found</d:status></d:propstat></d:response><d:response><d:href>/calendars/me%40myserver.de/f75745c2e1ff-43ce65bf664b-61b19136/KOrganizer-1451297853.976.ics</d:href><d:propstat><d:prop><d:getetag>"6ac921ef8c04170f-14"</d:getetag></d:prop><d:status>HTTP/1.1 200 OK</d:status></d:propstat><d:propstat><d:prop><cs:getctag/></d:prop><d:status>HTTP/1.1 404 Not Found</d:status></d:propstat></d:response><d:response><d:href>/calendars/me%40myserver.de/f75745c2e1ff-43ce65bf664b-61b19136/KOrganizer-1806805806.281.ics</d:href><d:propstat><d:prop><d:getetag>"55941ae59c5c4e25-15"</d:getetag></d:prop><d:status>HTTP/1.1 200 OK</d:status></d:propstat><d:propstat><d:prop><cs:getctag/></d:prop><d:status>HTTP/1.1 404 Not Found</d:status></d:propstat></d:response><d:response><d:href>/calendars/me%40myserver.de/f75745c2e1ff-43ce65bf664b-61b19136/KOrganizer-339518024.459.ics</d:href><d:propstat><d:prop><d:getetag>"9a589a6aa0a36399-19"</d:getetag></d:prop><d:status>HTTP/1.1 200 OK</d:status></d:propstat><d:propstat><d:prop><cs:getctag/></d:prop><d:status>HTTP/1.1 404 Not Fo
    

    and it really stops at 'Fo'. Then there's loooooots of these exceptions:

    E/CursorWindow(24348): Could not allocate CursorWindow '/data/user/0/com.android.providers.calendar/databases/calendar.db' of size 2097152 due to error -12.
    E/JavaBinder(24348): *** Uncaught remote exception!  (Exceptions are not yet supported across processes.)
    E/JavaBinder(24348): android.database.CursorWindowAllocationException: Cursor window allocation of 2048 kb failed. # Open Cursors=534 (# cursors opened by pid 24362=1) (# cursors opened by pid 24444=533)
    E/JavaBinder(24348):    at android.database.CursorWindow.<init>(CursorWindow.java:104)
    E/JavaBinder(24348):    at android.database.AbstractWindowedCursor.clearOrCreateWindow(AbstractWindowedCursor.java:198)
    E/JavaBinder(24348):    at android.database.sqlite.SQLiteCursor.fillWindow(SQLiteCursor.java:139)
    E/JavaBinder(24348):    at android.database.sqlite.SQLiteCursor.getCount(SQLiteCursor.java:133)
    E/JavaBinder(24348):    at android.database.CursorToBulkCursorAdaptor.getBulkCursorDescriptor(CursorToBulkCursorAdaptor.java:143)
    E/JavaBinder(24348):    at android.content.ContentProviderNative.onTransact(ContentProviderNative.java:118)
    E/JavaBinder(24348):    at android.os.Binder.execTransact(Binder.java:367)
    E/JavaBinder(24348):    at dalvik.system.NativeStart.run(Native Method)
    

    Then it still does a

    D/DavHttpReport(24444): Prepared REPORT request: <C:calendar-multiget xmlns:C="urn:ietf:params:xml:ns:caldav" xmlns="DAV:">
    

    and it seems to repeat the whole process all over again, except there's now some of these:

    D/davdroid.Event(24444): Assuming time zone Europe/Berlin for Europe/Berlin
    

    Eventually it even crashed the entire calendar:

    E/AndroidRuntime(24362): FATAL EXCEPTION: main
    E/AndroidRuntime(24362): java.lang.RuntimeException: Unable to start activity ComponentInfo{com.android.calendar/com.android.calendar.selectcalendars.SelectSyncedCalendarsMultiAccountActivity}: java.lang.NullPointerException
    E/AndroidRuntime(24362):        at android.app.ActivityThread.performLaunchActivity(ActivityThread.java:2185)
    E/AndroidRuntime(24362):        at android.app.ActivityThread.handleLaunchActivity(ActivityThread.java:2210)
    E/AndroidRuntime(24362):        at android.app.ActivityThread.access$600(ActivityThread.java:142)
    E/AndroidRuntime(24362):        at android.app.ActivityThread$H.handleMessage(ActivityThread.java:1208)
    E/AndroidRuntime(24362):        at android.os.Handler.dispatchMessage(Handler.java:99)
    E/AndroidRuntime(24362):        at android.os.Looper.loop(Looper.java:137)
    E/AndroidRuntime(24362):        at android.app.ActivityThread.main(ActivityThread.java:4931)
    E/AndroidRuntime(24362):        at java.lang.reflect.Method.invokeNative(Native Method)
    E/AndroidRuntime(24362):        at java.lang.reflect.Method.invoke(Method.java:511)
    E/AndroidRuntime(24362):        at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:791)
    E/AndroidRuntime(24362):        at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:558)
    E/AndroidRuntime(24362):        at dalvik.system.NativeStart.main(Native Method)
    E/AndroidRuntime(24362): Caused by: java.lang.NullPointerException
    E/AndroidRuntime(24362):        at com.android.calendar.Utils.matrixCursorFromCursor(Utils.java:314)
    E/AndroidRuntime(24362):        at com.android.calendar.selectcalendars.SelectSyncedCalendarsMultiAccountActivity.onCreate(SelectSyncedCalendarsMultiAccountActivity.java:62)
    E/AndroidRuntime(24362):        at android.app.Activity.performCreate(Activity.java:5008)
    E/AndroidRuntime(24362):        at android.app.Instrumentation.callActivityOnCreate(Instrumentation.java:1079)
    E/AndroidRuntime(24362):        at android.app.ActivityThread.performLaunchActivity(ActivityThread.java:2139)
    E/AndroidRuntime(24362):        ... 11 more
    

    I hope that helps to fix the issue. I'd like to get my calender back to my phone. Thanks for all your awesome work so far! :)



  • Ok after digging a little further, this looks like a memory problem, because too many cursors are opened. So I restarted my phone, started the calender and got no cursor errors, then I triggered a sync which now looked good at first. I got many "Processing multi-status element" messages and a <d:multistatus..> request again after which there was quite some wait with the dalvik VM showing

    D/dalvikvm( 1928): GC_CONCURRENT freed 1709K, 64% free 3002K/8195K, paused 3ms+4ms, total 60ms
    D/dalvikvm( 1928): GC_FOR_ALLOC freed 261K, 62% free 3179K/8195K, paused 33ms, total 104ms
    D/dalvikvm( 1928): GC_FOR_ALLOC freed 85K, 61% free 3199K/8195K, paused 21ms, total 21ms
    [...]
    D/dalvikvm(  542): GC_EXPLICIT freed 730K, 68% free 2646K/8195K, paused 2ms+8ms, total 44ms
    D/dalvikvm(  401): GC_EXPLICIT freed 86K, 41% free 9363K/15751K, paused 4ms+8ms, total 92ms
    D/dalvikvm(  401): GC_EXPLICIT freed 89K, 41% free 9365K/15751K, paused 4ms+8ms, total 89ms
    

    and then all the Cursor window allocation of 2048 kb failed. # Open Cursors=533 errors came again.

    Is there a way to maybe finish these database transactions, make a break, free some cursors and then continue?



  • Could you try to put a "commit();" after the Line "addDataRows(resource, -1, idx);"
    https://github.com/rfc2822/davdroid/blob/master/src/at/bitfire/davdroid/resource/LocalCollection.java#L169
    I think this could circumvent this problem.
    A real solution should work like the "MAX_UPDATES_BEFORE_COMMIT"
    https://github.com/rfc2822/davdroid/blob/master/src/at/bitfire/davdroid/syncadapter/SyncManager.java#L32


Log in to reply
 

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