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

0

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! 🙂

0

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?

0

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.