Closed Bug 1231322 Opened 9 years ago Closed 8 years ago

Calendar full resync due to caching issue

Categories

(Calendar :: Provider: GData, defect)

Lightning 4.0.4
defect
Not set
normal

Tracking

(Not tracked)

RESOLVED DUPLICATE of bug 1274728

People

(Reporter: callytic, Unassigned)

Details

User Agent: Mozilla/5.0 (X11; Linux x86_64; rv:38.0) Gecko/20100101 Firefox/38.0 Iceweasel/38.4.0
Build ID: 20151103222033

Steps to reproduce:

Dear maintainer,

We are tyring to push the use of Thunderbird within our company. We are using Google Calendar internally. Usually we configure the user calendar with CalDav and use the Google Data Provider to visualise shared collaborators calendars (as shared calendar do not work in caldav/ics without making them public).

Our main issue is that the plugin slows Thunderbird to a crawl as it keeps syncing full calendars with thousand of events.

I know that you are using a token to prevent this but it seems that sometimes it is not set.

Trying to debug the issue we added some logs and saw that the plugins is behaving correctly except for some calendars that do not get the token.

These calendars returns an error during their caching : 

Timestamp: 09/12/15 12:13:54
Error: [calCachedCalendar] replay action failed: null, uri=googleapi://usermail/?calendar=othercollaboratoremail, result=item.recurrenceInfo is null, op=[xpconnect wrapped calIOperation]
Source File: file:///usr/lib/icedove/extensions/%7Be2fda1a4-762b-4020-b5ad-a41df1933103%7D/calendar-js/calCachedCalendar.js
Line: 322

The log come from Debian Sid system with Icedove/Iceowl/Google Calendar Provider 38.4.0-1 but we reproduce it with all Windows users running the latest version of Thunderbird 38.4.0/Lightning 4.0.4/Google Calendar Provider 1.0.4.

This happens with people with the biggest numbers of events that are here for many years. This lead me to believe that some events have some buggy properties set.

Any idea how to fix this ? I couldn't find a way to return the actual event that fails, but if you provide me with an easyway to do this I can reproduce the issue at will.

Thanks in advance
Cheers


Actual results:

syncToken is not set so all calendars affected are re-downloaded every 60 minutes.


Expected results:

syncToken should be set to prevent to re-download all events.
More information. I saw in my syslog (!) that there was an exception at the time of the sync : 
Feb 17 10:19:42 xxx icedove.desktop[2388]: *************************
Feb 17 10:19:42 xxx icedove.desktop[2388]: A coding exception was thrown and uncaught in a Task.
Feb 17 10:19:42 xxx icedove.desktop[2388]: Full message: TypeError: item.recurrenceInfo is null
Feb 17 10:19:42 xxx icedove.desktop[2388]: Full stack: ItemSaver.prototype.processException@resource://gdata-provider/modules/gdataUtils.jsm:1012:13
Feb 17 10:19:42 xxx icedove.desktop[2388]: ItemSaver.prototype.parseEventStream/<@resource://gdata-provider/modules/gdataUtils.jsm:989:27
Feb 17 10:19:42 xxx icedove.desktop[2388]: TaskImpl_run@resource://gre/modules/Task.jsm:330:41
Feb 17 10:19:42 xxx icedove.desktop[2388]: Handler.prototype.process@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:867:23
Feb 17 10:19:42 xxx icedove.desktop[2388]: this.PromiseWalker.walkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:746:7
Feb 17 10:19:42 xxx icedove.desktop[2388]: this.PromiseWalker.scheduleWalkerLoop/<@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:688:37
Feb 17 10:19:42 xxx icedove.desktop[2388]: *************************

It should help troubleshooting the issue.

Let me know if I can provide you with more info

Cheers
LeTic
Dear maintainer, 

I took some time today to try to troubleshoot the issue.

I enabled the debug log with
 - calendar.debug.log 
 - calendar.debug.log.verbose 

The issue I received is multiple : 

Feb 22 14:15:32 xxx icedove.desktop[24476]: A coding exception was thrown and uncaught in a Task.
Feb 22 14:15:32 xxx icedove.desktop[24476]: Full message: TypeError: item.recurrenceInfo is null
Feb 22 14:15:32 xxx icedove.desktop[24476]: Full stack: ItemSaver.prototype.processException@resource://gdata-provider/modules/gdataUtils.jsm:1110:13
Feb 22 14:15:32 xxx icedove.desktop[24476]: ItemSaver.prototype.parseEventStream/<@resource://gdata-provider/modules/gdataUtils.jsm:1087:27
Feb 22 14:15:32 xxx icedove.desktop[24476]: TaskImpl_run@resource://gre/modules/Task.jsm:330:41
Feb 22 14:15:32 xxx icedove.desktop[24476]: TaskImpl_handleResultValue@resource://gre/modules/Task.jsm:393:7
Feb 22 14:15:32 xxx icedove.desktop[24476]: TaskImpl_run@resource://gre/modules/Task.jsm:332:11
Feb 22 14:15:32 xxx icedove.desktop[24476]: Handler.prototype.process@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:867:23
Feb 22 14:15:32 xxx icedove.desktop[24476]: this.PromiseWalker.walkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:746:7
Feb 22 14:15:32 xxx icedove.desktop[24476]: this.PromiseWalker.scheduleWalkerLoop/<@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:688:37
Feb 22 14:15:32 xxx icedove.desktop[24476]: *************************

Then once per problematic accounts : 

Feb 22 14:15:32 xxx icedove.desktop[24476]: [calGoogleCalendar] Error syncing:
Feb 22 14:15:32 xxx icedove.desktop[24476]: 2147500037: (resource://gdata-provider/modules/gdataUtils.jsm:1110):TypeError: item.recurrenceInfo is null
Feb 22 14:15:32 xxx icedove.desktop[24476]: Error: [calCachedCalendar] replay action failed: null, uri=googleapi://xxx.xxx@virtua.ch/?calendar=yyy.yyy%40virtua.ch, result=item.recurrenceInfo is null, op=[xpconnect wrapped calIOperation]
Feb 22 14:15:32 xxx icedove.desktop[24476]: [calCachedCalendar] replayChangesOn finished.
Feb 22 14:15:32 xxx icedove.desktop[24476]: [calCachedCalendar] sync queue empty.


I thought it was similar to issue : https://bugzilla.mozilla.org/show_bug.cgi?id=1170271 and applied patches from https://hg.mozilla.org/releases/comm-aurora/rev/d0455ccc36ab manually. But the issue still occurs.

Then I upgraded to the latest version of the Google Data Provider with similar results.

I am still investigating but I would appreciate some help.

Thanks in advance
Cheers
LeTic
Status: UNCONFIRMED → RESOLVED
Closed: 8 years ago
Resolution: --- → DUPLICATE
You need to log in before you can comment on or make changes to this bug.