Calendar data lost until reboot since ICS update

[skela]

Since upgrading my Xperia Active to Ice Cream Sandwich, I have noticed that the calendar provider tends to crash. The calendar widget would become empty, and when I try to add an event or list the events, I will get a pop-up saying (my translation from local language) ‘Calendar has stopped’.

Initially, I suspected that this was because I disabled many built-in applications. Today, I finally decided to check with adb logcat for hints. I found this exact message repeated every now and then:

E/CursorWindow(  837): Could not allocate CursorWindow '/data/data/com.android.providers.calendar/databases/calendar.db' of size 2097152 due to error -12.

This was often followed by a stack trace like this:

E/JavaBinder(  837): *** Uncaught remote exception!  (Exceptions are not yet supported across processes.)
E/JavaBinder(  837): android.database.CursorWindowAllocationException: Cursor window allocation of 2048 kb failed. # Open Cursors=536 (# cursors opened by pid 654=536)
E/JavaBinder(  837):      at android.database.CursorWindow.(CursorWindow.java:104)
E/JavaBinder(  837):      at android.database.AbstractWindowedCursor.clearOrCreateWindow(AbstractWindowedCursor.java:198)
E/JavaBinder(  837):      at android.database.sqlite.SQLiteCursor.fillWindow(SQLiteCursor.java:162)
E/JavaBinder(  837):      at android.database.sqlite.SQLiteCursor.getCount(SQLiteCursor.java:156)
E/JavaBinder(  837):      at android.database.AbstractCursor.moveToPosition(AbstractCursor.java:161)
E/JavaBinder(  837):      at android.database.AbstractCursor.moveToNext(AbstractCursor.java:209)
E/JavaBinder(  837):      at com.android.providers.calendar.CalendarCache.readDataLocked(CalendarCache.java:228)
E/JavaBinder(  837):      at com.android.providers.calendar.CalendarCache.readData(CalendarCache.java:202)
E/JavaBinder(  837):      at com.android.providers.calendar.CalendarCache.readTimezoneInstances(CalendarCache.java:114)
E/JavaBinder(  837):      at com.android.providers.calendar.CalendarProvider2.query(CalendarProvider2.java:879)
E/JavaBinder(  837):      at android.content.ContentProvider$Transport.query(ContentProvider.java:178)
E/JavaBinder(  837):      at android.content.ContentProviderNative.onTransact(ContentProviderNative.java:112)
E/JavaBinder(  837):      at android.os.Binder.execTransact(Binder.java:338)
E/JavaBinder(  837):      at dalvik.system.NativeStart.run(Native Method)

Is there a resource leak somewhere? Surely there should not be 536 open cursors to my calendar? I have disabled calendar sync, and there are maybe 5 events in my entire calendar. There are not that many references to pid 654 in the log. These are the first ones (the warning about missing close() was repeated 12 times):

D/dalvikvm(  654): GC_CONCURRENT freed 386K, 9% free 6658K/7239K, paused 2ms+3ms
W/CursorWrapperInner(  654): Cursor finalized without prior close()
E/JavaBinder(  837): android.database.CursorWindowAllocationException: Cursor window allocation of 2048 kb failed. # Open Cursors=536 (# cursors opened by pid 654=536)

Can anyone confirm this problem? Is there a workaround? It is not nice to lose calendar reminders because the backend was suddenly stopped. Not as fatal as the spontaneous shutdowns or reboots with the first firmware, but still not nice.

[skela]

This StackOverflow question about a different brand device seems to be related (but about contacts, not calendar). Is it a bug in core Android 4.0?

[skela]

Let me provide a little more information. My phone contains the firmware 4.1.B.0.431. I updated from Android 2.3.4 with the option that tried to preserve original data. The only application I have installed apart from the built-in software (some of which I have disabled) is OsmAnd. It does not connect to the calendar.

In my initial post, I did not investigate which process is hogging the cursors. Now I got it from adb shell:

shell@android:/ $ ps  675USER     PID   PPID  VSIZE  RSS     WCHAN    PC         NAME
app_118   675   127   281696 29956 ffffffff 00000000 S com.sonyericsson.widget.calendar

You see, this time the log message was:

E/JavaBinder(  841): android.database.CursorWindowAllocationException: Cursor window allocation of 2048 kb failed. # Open Cursors=537 (# cursors opened by pid 675=537)

Can you confirm the problem? If the calendar application were user-replaceable and open source, I could try to fix this myself.

I guess the next step is to remove the Calendar widget from the home screen, and to see if this makes the leak go away.

[Johan]

Please keep me updated if the "remove calendar widget" worked.

[skela]

At least the calendar did not hang today. But, I only launched the calendar application twice from the menu. Tomorrow I will try to check it more often (maybe set up a number of alarms to remind me :smileyhappy:).

On a somewhat related note, it would be nice if the number of home screen panels were configurable, like the number of menu screens is. Currently (with the calendar widget removed), I have use for 3 home screen panels, and 2 are empty. Also, sometimes the home screen does react to screen rotation events, while most of the time it does not. I have not figured out what enables this behaviour.

[skela]

The calendar worked all day, even after entering several events and after having reminders go off several times. The only errors in the log look related to camera, and I did not attempt to access the camera since the reboot this morning. These messages are repeated several times:

D/PhoneStatusBar(  353): disable: < expand icons alerts ticker system_info back* home* recent clock* >I/CameraService(  143): Opening camera 0
W/ServiceManager(  143): Permission failure: com.sonyericsson.permission.CAMERA_EXTENDED from uid=10003 pid=2220
I/caladbolg(  143): 4206651040 cald_camctrl.c                    (6713)  3232 P [SVR]  -88316286 + Cald_CamCtrl_PowerUp
I/caladbolg(  143): 4206651101 cald_camctrl.c                    (7484)  3232 P [SVR]  -88316195 + Cald_CamCtrl_FSM_Func_PowerUp
I/caladbolg(  143): 4206653726 cald_hal_qct.c                    (2789)  3232 P [HAL]  -88313570 + Cald_Hal_Qct_If_PowerUp
I/caladbolg(  143): 4206653878 cald_hal_qct.c                    (2847)  3232 P [HAL]  -88313448 - Cald_Hal_Qct_If_PowerUp (0)
I/caladbolg(  143): 4206654702 cald_camctrl.c                    (7563)  3232 P [SVR]  -88312594 - Cald_CamCtrl_FSM_Func_PowerUp (0)
I/caladbolg(  143): 4206654763 cald_camctrl.c                    (6720)  3232 P [SVR]  -88312533 - Cald_CamCtrl_PowerUp (0)
I/AwesomePlayer(  143): setDataSource_l('/system/media/audio/ui/camera_click.ogg')
E/CMarlinMediator(  128): Error : MarlinMediator Failed to get TrustedTime
I/AwesomePlayer(  143): setDataSource_l('/system/media/audio/ui/VideoRecord.ogg')
E/CMarlinMediator(  128): Error : MarlinMediator Failed to get TrustedTime
D/CameraService(  143): getParameter
W/ServiceManager(  143): Permission failure: com.sonyericsson.permission.CAMERA_EXTENDED from uid=10003 pid=2220

In other words, the Calendar widget is responsible for the cursor leak and the calendar hang. Is there any hope of getting it fixed in the next firmware update?

[skela]

Coincidentally, I got the over-the-air update to the 4.1.B.0.587 firmware today morning. After installing it, I re-enabled the calendar widget (the non-resizable one, with the InfiniteView looks).

The calendar did not hang completely, but there was one ANR (Application Not Responding) notification, and I did see some errors in the log, such as (cutting some parts of it):

W/CursorWrapperInner( 4311): Cursor finalized without prior close()
…
E/ActivityThread( 1957): Failed to find provider info for calendar
E/ActivityThread( 1957): Failed to find provider info for calendar
E/ActivityThread( 1957): Failed to find provider info for calendar
I/ActivityManager(  285): Start proc com.android.calendar for broadcast com.android.calendar/.widget.CalendarAppWidgetService$CalendarFactory: pid=4257 uid=10084 gids={3003, 1015}
E/ActivityThread( 1957): Failed to find provider info for calendar
E/AndroidRuntime( 1769): FATAL EXCEPTION: main
E/AndroidRuntime( 1769): java.lang.OutOfMemoryError: thread creation failed
E/AndroidRuntime( 1769):      at java.lang.VMThread.create(Native Method)
E/AndroidRuntime( 1769):      at java.lang.Thread.start(Thread.java:1050)
E/AndroidRuntime( 1769):      at android.app.IntentService.onCreate(IntentService.java:108)
E/AndroidRuntime( 1769):      at android.app.ActivityThread.handleCreateService(ActivityThread.java:2273)
E/AndroidRuntime( 1769):      at android.app.ActivityThread.access$1600(ActivityThread.java:127)
E/AndroidRuntime( 1769):      at android.app.ActivityThread$H.handleMessage(ActivityThread.java:1212)
E/AndroidRuntime( 1769):      at android.os.Handler.dispatchMessage(Handler.java:99)
E/AndroidRuntime( 1769):      at android.os.Looper.loop(Looper.java:137)
E/AndroidRuntime( 1769):      at android.app.ActivityThread.main(ActivityThread.java:4441)
E/AndroidRuntime( 1769):      at java.lang.reflect.Method.invokeNative(Native Method)
E/AndroidRuntime( 1769):      at java.lang.reflect.Method.invoke(Method.java:511)
E/AndroidRuntime( 1769):      at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:784)
E/AndroidRuntime( 1769):      at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:551)
E/AndroidRuntime( 1769):      at dalvik.system.NativeStart.main(Native Method)
I/ActivityThread( 1957): Removing dead content provider: com.android.calendar
I/ActivityManager(  285): Process com.android.providers.calendar (pid 1769) has d
ied.
W/ActivityManager(  285): Scheduling restart of crashed service com.android.providers.calendar/.CalendarProviderIntentService in 5000ms
I/ActivityManager(  285): Kill com.sonyericsson.widget.calendar (pid 1957): provider com.android.providers.calendar.CalendarProvider2 in dying process com.android.providers.calendar
I/ActivityManager(  285): Process com.sonyericsson.widget.calendar (pid 1957) has died.
W/ActivityManager(  285): Scheduling restart of crashed service com.sonyericsson.widget.calendar/.CalendarService in 14970ms
I/ActivityManager(  285): Start proc com.android.providers.calendar for service com.android.providers.calendar/.CalendarProviderIntentService: pid=4277 uid=10056 gids={3003, 1015}
E/AndroidRuntime( 4277): FATAL EXCEPTION: IntentService[CalendarProviderIntentService]
E/AndroidRuntime( 4277): java.lang.RuntimeException: WakeLock under-locked ScheduleNextAlarmWakeLock
E/AndroidRuntime( 4277):      at android.os.PowerManager$WakeLock.release(PowerManager.java:325)
E/AndroidRuntime( 4277):      at android.os.PowerManager$WakeLock.release(PowerManager.java:300)
E/AndroidRuntime( 4277):      at com.android.providers.calendar.CalendarAlarmManager.releaseScheduleNextAlarmWakeLock(CalendarAlarmManager.java:182)
E/AndroidRuntime( 4277):      at com.android.providers.calendar.CalendarProviderIntentService.onHandleIntent(CalendarProviderIntentService.java:48)
E/AndroidRuntime( 4277):      at android.app.IntentService$ServiceHandler.handleMessage(IntentService.java:65)
E/AndroidRuntime( 4277):      at android.os.Handler.dispatchMessage(Handler.java:99)
E/AndroidRuntime( 4277):      at android.os.Looper.loop(Looper.java:137)
E/AndroidRuntime( 4277):      at android.os.HandlerThread.run(HandlerThread.java:60)
I/ActivityManager(  285): Process com.android.providers.calendar (pid 4277) has died.
W/ActivityManager(  285): Service crashed 2 times, stopping: ServiceRecord{2c4cac80 com.android.providers.calendar/.CalendarProviderIntentService}
I/ActivityManager(  285): Start proc com.android.providers.calendar for broadcast com.android.providers.calendar/.CalendarProviderBroadcastReceiver: pid=4294 uid=10056 gids={3003, 1015}

Process 4311 (the one that forgets to close in the above log) is com.sonyericsson.widget.calendar.

Next, I will try the other (resizable) calendar widget and see if it leaks cursors.

[skela]

Next, I will try the other (resizable) calendar widget and see if it leaks cursors.

I did not observe any cursor leak yet, but I did not use the calendar much either. There are 2 calendar-related processes in the system according to ps -x in adb shell:

app_84    3796  132   288696 24128 ffffffff 00000000 S com.android.calendar (u:159, s:23)
app_56    3811  132   281268 18320 ffffffff 00000000 S com.android.providers.calendar (u:45, s:10)

I have now disabled the non-resizable calendar widget altogether.