search

kewisch / gdata-provider

Provider for Google Calendar
https://addons.thunderbird.net/thunderbird/addon/provider-for-google-calendar/
Other
239 stars 31 forks source link

[needs testing latest version] Issues with idle time and lost synchronization #498

Closed multiprod closed 2 months ago

multiprod commented 1 year ago

Hello, To synchronize my agenda with google agenda I need to reboot Thunderbird 102.1.2 (64 bits) under windows Is it normal?

LOG ERRORS

Successfully loaded OpenPGP library rnp.dll version 0.16+git20220124.f06439f7.MZLA from C:\Program Files (x86)\Mozilla Thunderbird\rnp.dll [RNPLib.jsm:100:15](chrome://openpgp/content/modules/RNPLib.jsm)
Found 0 public keys and 0 secret keys (0 protected, 0 unprotected) [RNPLib.jsm:301:15](chrome://openpgp/content/modules/RNPLib.jsm)
Trying to load C:\Program Files (x86)\Mozilla Thunderbird\libotr.dll [OTRLib.jsm:64:11](resource:///modules/OTRLib.jsm)
Successfully loaded OTR library C:\Program Files (x86)\Mozilla Thunderbird\libotr.dll [OTRLib.jsm:72:13](resource:///modules/OTRLib.jsm)
services.settings: Failed to load last_modified.json: TypeError: NetworkError when attempting to fetch resource. [Utils.jsm:330](resource://services-settings/Utils.jsm)
Cette page est en mode de compatibilité (quirks). La mise en page peut en être affectée. Pour le mode standard, utilisez « <!DOCTYPE html> ».
181 [calItemBase.js:431:30](resource:///components/calItemBase.js)
Cette page est en mode de compatibilité (quirks). La mise en page peut en être affectée. Pour le mode standard, utilisez « <!DOCTYPE html> ».
5 [calViewUtils.jsm:416:35](resource:///modules/calendar/utils/calViewUtils.jsm)
Cette page est en mode de compatibilité (quirks). La mise en page peut en être affectée. Pour le mode standard, utilisez « <!DOCTYPE html> ».
37 [calItemBase.js:431:30](resource:///components/calItemBase.js)
tb.account.size_on_disk - Trying to set an unsigned scalar to a negative number. 2
tb.account.size_on_disk - Truncating float/double number. 4
tb.account.size_on_disk - Trying to set an unsigned scalar to a negative number. 12
Une tentative visant à définir un en-tête interdit à été bloquée : Content-Length 2 [cardbookWebDAV.js:386:17](chrome://cardbook/content/cardbookWebDAV.js)
Cette page est en mode de compatibilité (quirks). La mise en page peut en être affectée. Pour le mode standard, utilisez « <!DOCTYPE html> ».
[blank](about:blank)
Cette page est en mode de compatibilité (quirks). La mise en page peut en être affectée. Pour le mode standard, utilisez « <!DOCTYPE html> ».
[background.js:59:41](moz-extension://background.js)
Cette page est en mode presque standard. La mise en page peut en être affectée. Pour le mode standard, utilisez « <!DOCTYPE html> ».
[](moz-nullprincipal:)
Cette page est en mode presque standard. La mise en page peut en être affectée. Pour le mode standard, utilisez « <!DOCTYPE html> ».
[blank](about:blank)
Cette page est en mode de compatibilité (quirks). La mise en page peut en être affectée. Pour le mode standard, utilisez « <!DOCTYPE html> ».
[fetch>UID>.INBOX>153770]
Cette page est en mode presque standard. La mise en page peut en être affectée. Pour le mode standard, utilisez « <!DOCTYPE html> ».
[cardbookMain.css:161:7](chrome://cardbook/content/skin/cardbookMain.css)
Erreur d’analyse de la valeur pour « align-items ».  Déclaration abandonnée. [cardbookMain.css:201:15](chrome://cardbook/content/skin/cardbookMain.css)
kewisch commented 1 year ago

Is this still an issue with the latest version? I don't see anything suggesting a need for restart in the logs.

hakanyi commented 1 year ago

I can confirm that at least clicking "Synchronize" in the calendar tab (at the top left) does not seem to have an effect. I have to restart Thunderbird (102.5.0-1) to see changes. I'm on Manjaro Linux -- please let me know if/how I can help.

multiprod commented 1 year ago

No synchro problem since updating last versions Thunderbird 102.5.0 64bits and addon 102.0.0

hakanyi commented 1 year ago

Just checked, still an issue for me, unfortunately :/

jachoo commented 1 year ago

Still have sync problems. It's been a few months since some of my Google Calendars don't synchronize correctly. I cannot trust Thunderbird calendar anymore :/

Especially, events created by other people in shared google calendars don't appear in TB without the application restart. My own private calendars and my own events in shared calendars seem to synchronize. But I'm not sure if it's always the case.

I'm on Windows 11, TB 102.5.0, Google provider 102.0.3

kewisch commented 1 year ago

Can you try re-subscribing to the calendar? If that doesn't work, I will need a few more logs, e.g. these steps logged

  1. re-subscribe the calendar and make sure it is synchronized (I don't need the full logs here, just maybe the sync token)
  2. create event in google calendar
  3. click synchronize
n00mad commented 1 year ago

Hello @kewisch , I can try to help. This thread seems similar to #529 that I started. But I don't know much about Thunderbird. For logs, do you want the error console output?
Or a log created ala https://wiki.mozilla.org/MailNews:Logging#Mac_OS_X ? or some other log source?

Will a Macos Thunderbird client even be helpful? I don't have the resources to try this on Windows or some variety *nix.

I also don't know much about git / github. Should I merge 529 into 498 and if so, what is an education references on how to do that.

fwiw, n00mad

jachoo commented 1 year ago

Can you try re-subscribing to the calendar? If that doesn't work, I will need a few more logs, e.g. these steps logged

  1. re-subscribe the calendar and make sure it is synchronized (I don't need the full logs here, just maybe the sync token)
  2. create event in google calendar
  3. click synchronize

I cannot reproduce the problem this way. After re-subscribing (or restarting TB) synchronization mostly works (as far as I can see). But after some time (hours, days?) calendars stop synchronizing from Google to TB.

Probably it's important to say that I subscribe to 16 google calendars (some are my private, some are shared, and some are public).

It's difficult for me to reproduce the issue, as it seems to happen after a few days. The first thing that seems to break is when an event is deleted on Google's side (then it still exists in TB). But after some time the synchronization stops entirely, or almost entirely. When I click "synchronize", in the status bar I see synchronization messages, but in reality, the calendars are not synced from Google to TB. The other way (from TB to Google) sync is still OK.

There are no messages in the developer console, so I cannot tell you more. Is there an option to enable better logging or something that can help us diagnose the issue? I had to stop using TB as my primary calendar because it's completely unreliable now :(

UPDATE:

I see two strange things in the logs, but they seem to be NOT correlated to sync problems (they happen just after re-subscribing, when the sync still works correctly, I think):

  1. Sometimes the status bar message doesn't disappear after the sync ('synchronizing calendar XXX`)
  2. There are a few error messages in the console: 
    Assert failed: Calendar manager initialised calendars before loadCalendarComponent ran on the first 3pane window. This should not happen. [calUtils.jsm:109](resource:///modules/calendar/calUtils.jsm)
Calendar: [calICSService] Error in parser worker: [object Object] [calICSService.js:588](resource:///components/calICSService.js)
Calendar: Error Parsing ICS: 2147500037 [CalIcsParser.jsm:146](resource:///modules/CalIcsParser.jsm)
jachoo commented 1 year ago

@kewisch, any updates on the issue? Can I help you somehow?

multiprod commented 1 year ago

Hello,

For the moment, I have another problem.

Could you please explain me how to delete the rigth column (Général vCard) on my CardBook ?

Michel Schatz

MosAiles 51 rue de la gare 57330 Zoufftgen

Tél : 00 33 (0)6 61 202 203 @.***

visitez notre sitehttps://www.mosailes.com visitez notre sitehttps://shop.mosailes.com

Je pense environnement: ai-je vraiment besoin d’imprimer ce message ? Save the Planet: Do I really need to print this email ?

Le 02/01/2023 à 14:42, jachoo a écrit :

Can you try re-subscribing to the calendar? If that doesn't work,
I will need a few more logs, e.g. these steps logged
1. re-subscribe the calendar and make sure it is synchronized (I
don't need the full logs here, just maybe the sync token)
2. create event in google calendar
3. click synchronize

@kewisch https://github.com/kewisch, any updates on the issue? Can I help you somehow?

— Reply to this email directly, view it on GitHub https://github.com/kewisch/gdata-provider/issues/498#issuecomment-1368957954, or unsubscribe https://github.com/notifications/unsubscribe-auth/AGITWWKNMSVVP3Z4XTL3Y6DWQLLOBANCNFSM6AAAAAAQTVJURA. You are receiving this because you authored the thread.Message ID: @.***>

carlosabalde commented 1 year ago

Same problem here: hours/days after restarting TB or disabling-enabling the add-on sync stops.

peci1 commented 1 year ago

This also happens to me on current stable release (both Windows and Linux). Are the debug steps from https://github.com/kewisch/gdata-provider/issues/498#issuecomment-1331857281 still up-to-date? I'll try to collect them when it happens again.

carlosabalde commented 1 year ago

I've trying to understand the issue and I found a tiny modification of the add-on that -so far- has fixed the issue for me. Details in https://github.com/kewisch/gdata-provider/discussions/497#discussioncomment-5188907 just in case somebody here wants to help testing it.

jachoo commented 1 year ago

I've managed to workaround the bug without rebuilding or reinstalling. Just run in the console (Tools -> Developer Tools -> Debug Addons -> Provide for Google Calendar -> Console) following line:

> await messenger.storage.local.set({"settings.idleTime": 0})

After executing this line, one must restart Thunderbird. From now, the calendar sync should work correctly.

carlosabalde commented 1 year ago

The side effect is the same, because that way maxIdleTime != 0 && idleTime > maxIdleTime will never be true. In any case, one way or another, it seems obvious that a bugfix release will be needed to avoid hacky workarounds.

peci1 commented 1 year ago

await messenger.storage.local.set({"settings.idleTime": 0})

This doesn't sound like a good idea. It might have severe performance implications.

jachoo commented 1 year ago

await messenger.storage.local.set({"settings.idleTime": 0}) This doesn't sound like a good idea. It might have severe performance implications.

I don't agree. According to documentation (quoted below), idle time is a time when there is no keyboard/mouse activity. So if I'm using actively the computer, this command doesn't change anything in TB. But correctly workarounds the issue.

This interface lets you monitor how long the user has been 'idle', i.e. not used their mouse or keyboard. You can get the idle time directly, but in most cases you will want to register an observer for a predefined interval. The observer will get an 'idle' notification when the user is idle for that interval (or longer), and receive an 'active' notification when the user starts using their computer again.

kewisch commented 1 year ago

You'll be able to get more logs by setting calendar.debug.log and calendar.debug.log.verbose in the advanced config editor in Thunderbird. This will also let you see if you get the message [calGoogleCalendar] Skipping refresh since user is idle while not actually idle. Can someone provide logs on that?

The logic is simply there to reduce API calls and avoid hitting the API limit. Setting idleTime to 0 has no other negative effects.

I'm curious if the idle time is a red herring though. In theory if you are using Thunderbird you should notice no difference. It should only start skipping syncs if you haven't used Thunderbird for 5 minutes. As soon as you hit sync, it should be up to date again.

peci1 commented 1 year ago

It happened again today. A colleague sent added me to an event. I clicked "Synchronize" in TB, but the event was not there (it was normally present in online GCal webpage). There's nothing interesting in the log. Not even Skipping refresh since user is idle.

When I restarted TB, the event appeared in the startup log:

14:33:02.322 Calendar: [calGoogleCalendar] Request GET [https://www.googleapis.com/calendar/v3/calendars/***%40…eleted=true&syncToken=***](https://www.googleapis.com/calendar/v3/calendars/***/events?maxResults=1000&showDeleted=true&syncToken=***) responded with HTTP 200 [gdataRequest.jsm:390](resource://gdata-provider/legacy/modules/gdataRequest.jsm)
14:33:02.322 Calendar: [calGoogleCalendar] Timezone for *** is Europe/Prague [gdataUtils.jsm:1099](resource://gdata-provider/legacy/modules/gdataUtils.jsm)
14:33:02.322 Calendar: [calGoogleCalendar] Parsing 1 received events [gdataUtils.jsm:1107](resource://gdata-provider/legacy/modules/gdataUtils.jsm)
14:33:02.322 Calendar: [calGoogleCalendar] Parsing entry:
{
 "kind": "calendar#event",
 "etag": "\"3377984525032000\"",
 "id": "05kgvj3po8le0hcsjn86fv4onr",
 "status": "confirmed",
 "htmlLink": "https://www.google.com/calendar/event?eid=MDVrZ3ZqM3BvOGxlMGhjc2puODZmdjRvbnIgcGVja2FtYTJAZmVsLmN2dXQuY3o",
 "created": "2023-07-10T12:26:36.000Z",
 "updated": "2023-07-10T12:31:02.516Z",
 "summary": "***",
 "creator": {
  "email": "***"
 },
 "organizer": {
  "email": "***"
 },
 "start": {
  "dateTime": "2023-07-11T15:00:00+02:00",
  "timeZone": "Europe/Berlin"
 },
 "end": {
  "dateTime": "2023-07-11T16:00:00+02:00",
  "timeZone": "Europe/Berlin"
 },
 "iCalUID": "***",
 "sequence": 0,
 "attendees": [
  {
   "email": "***",
   "displayName": "***",
   "self": true,
   "responseStatus": "accepted"
  },
  {
   "email": "***",
   "responseStatus": "needsAction"
  },
  {
   "email": "***",
   "organizer": true,
   "responseStatus": "accepted"
  }
 ],
 "hangoutLink": "***",
 "conferenceData": {
  "entryPoints": [
   {
    "entryPointType": "video",
    "uri": "***",
    "label": "[***](chrome://devtools/content/webconsole/meet.google.com/***)"
   }
  ],
  "conferenceSolution": {
   "key": {
    "type": "hangoutsMeet"
   },
   "name": "Google Meet",
   "iconUri": "https://fonts.gstatic.com/s/i/productlogos/meet_2020q4/v6/web-512dp/logo_meet_2020q4_color_2x_web_512dp.png"
  },
  "conferenceId": "***"
 },
 "reminders": {
  "useDefault": true
 },
 "eventType": "default"
}
[gdataLogging.jsm:17](resource://gdata-provider/legacy/modules/gdataLogging.jsm)
14:33:02.328 Calendar: [calGoogleCalendar] Logging calIEvent:
    id:05kgvj3po8le0hcsjn86fv4onr@google.com
    created:2023-07-10T12:26:36Z
    updated:2023-07-10T12:31:02Z
    title:***
    description:null
    transparency:null
    status:CONFIRMED
    startTime:2023-07-11T15:00:00
    endTime:2023-07-11T16:00:00
    location:null
    privacy:null
    sequence:0
    alarmLastAck:null
    snoozeTime:null
    isOccurrence: false
    Organizer: 
        ID: mailto:***
            Name: undefined
            Rsvp: null
            Is Organizer: yes
            Role: null
            Status: NEEDS-ACTION
    Attendees: 

        ID: mailto:***
            Name: ***
            Rsvp: null
            Is Organizer: no
            Role: REQ-PARTICIPANT
            Status: ACCEPTED

        ID: mailto:***
            Name: undefined
            Rsvp: null
            Is Organizer: no
            Role: REQ-PARTICIPANT
            Status: NEEDS-ACTION

        ID: mailto:***
            Name: undefined
            Rsvp: null
            Is Organizer: no
            Role: REQ-PARTICIPANT
            Status: ACCEPTED
    recurrence: no
    alarms: yes: 

        Action: DISPLAY
        Offset: -PT10M
        alarmDate: null
        related: 1
        repeat: 0
        repeatOffset: null
        repeatDate: null
        description: null
        summary: null
        properties: yes:
            X-DEFAULT-ALARM:TRUE
jachoo commented 1 year ago

I'm curious if the idle time is a red herring though. In theory if you are using Thunderbird you should notice no difference. It should only start skipping syncs if you haven't used Thunderbird for 5 minutes. As soon as you hit sync, it should be up to date again.

The implementation is (or was) buggy. More info here: https://github.com/kewisch/gdata-provider/discussions/497#discussioncomment-5194513

carlosabalde commented 1 year ago

After updating to 115.0.1 (and dropping the fix described in https://github.com/kewisch/gdata-provider/discussions/497#discussioncomment-5164776: i.e. removing this branch), the issue is back. Some time after I stopped using the computer, these are the last logged messages:

19:48:39.539 Calendar: [calGoogleCalendar] Skipping refresh since user is idle gdataCalendar.jsm:758
19:48:39.554 Calendar: [calGoogleCalendar] Skipping refresh since user is idle gdataCalendar.jsm:758
19:48:39.572 Calendar: [calGoogleCalendar] Skipping refresh since user is idle gdataCalendar.jsm:758
19:48:39.636 Calendar: [calGoogleCalendar] Skipping refresh since user is idle gdataCalendar.jsm:758
19:48:40.163 Calendar: [calGoogleCalendar] Skipping refresh since user is idle gdataCalendar.jsm:758
19:48:40.208 Calendar: [calGoogleCalendar] Skipping refresh since user is idle gdataCalendar.jsm:758
19:48:40.218 Calendar: [calGoogleCalendar] Skipping refresh since user is idle gdataCalendar.jsm:758

After that, clicks on 'Calendars > Synchronize' are silently ignored and events are not synchronized.

ThatGeoGuy commented 1 year ago

There's a couple things I noticed that might be worthwhile. First off:

Anyways, that aside, I don't have enough context to understand what the correct fix would be, but there seems to be a suggested workaround of pasting the following into the terminal:

await messenger.storage.local.set({"settings.idleTime": 0})

I just wanted to point out that this is unnecessarily complicated. Instead, go to Settings, search for "config editor" and you should see the following:

image

This is the same thing as about:config in Firefox. Anyways, you can set the idle time to zero there directly:

image

No console or restart of thunderbird required. In any case I hope that someone (maybe @kewisch or @nneul?) can look into providing a patch soon. This issue seems like it'd be straightforward enough given that the discussion around it suggests that it is only one branch condition causing the problem, but maybe I'm completely mistaken on that front.

kewisch commented 1 year ago

Note that the config editor and the add-on's local storage are two separate storages. I do have some migration code between the two somewhere, so by coincidence it might work. If you want a GUI editor, debug add-ons to open the add-on devtools, go to the storage tab, and change/add settings.

I won't have time in the near future to reproduce and work on this issue, but I'll try to squeeze it in. If others are able to debug further what causes the sync to return without action when returning I'd much appreciate!

kewisch commented 11 months ago

After updating to 115.0.1 (and dropping the fix described in #497 (comment): i.e. removing this branch), the issue is back. Some time after I stopped using the computer, these are the last logged messages:

19:48:39.539 Calendar: [calGoogleCalendar] Skipping refresh since user is idle gdataCalendar.jsm:758
19:48:39.554 Calendar: [calGoogleCalendar] Skipping refresh since user is idle gdataCalendar.jsm:758
19:48:39.572 Calendar: [calGoogleCalendar] Skipping refresh since user is idle gdataCalendar.jsm:758
19:48:39.636 Calendar: [calGoogleCalendar] Skipping refresh since user is idle gdataCalendar.jsm:758
19:48:40.163 Calendar: [calGoogleCalendar] Skipping refresh since user is idle gdataCalendar.jsm:758
19:48:40.208 Calendar: [calGoogleCalendar] Skipping refresh since user is idle gdataCalendar.jsm:758
19:48:40.218 Calendar: [calGoogleCalendar] Skipping refresh since user is idle gdataCalendar.jsm:758

After that, clicks on 'Calendars > Synchronize' are silently ignored and events are not synchronized.

@carlosabalde When you click synchronize, does it say [calGoogleCalendar] Skipping refresh since user is idle as well? Or are these all log messages from while you were indeed idle?

carlosabalde commented 11 months ago

@kewisch the 'Skipping refresh' events are the last messages in the log, probably logged because I went idle. problem is once they are logged, clicks on 'Calendars > Synchronize' are silently ignored and nothing is logged (and events are not synchronized anymore).

kewisch commented 11 months ago

Would you be up for some debugging? The idle time check is the very first thing that is done, so if that doesn't provide a message then the idle time is probably a red herring.

If you set the debugger to break here: https://github.com/kewisch/gdata-provider/blob/1b494e010928b5a61401b27e7ec866b8e37c4a54/src/legacy/modules/gdataCalendar.jsm#L750

then you should be able to find out at what point it bails out. You can access the debugger with Tools> Developer Tools > Developer Toolbox

carlosabalde commented 11 months ago

For the last months I've using the await messenger.storage.local.set({"settings.idleTime": 0}) workaround. Yesterday I executed await messenger.storage.local.set({"settings.idleTime": 60}) and the issue reappeared after some idle time (Thunderbird 115.3.1 + Provider for Google Calendar 115.0.2). However, I'd need some help to add the breakpoint. Using the debugger and inspectingthe add-on, the only file I can see to add breakpoints is background.js.

screenshot-2023 10 16-08 45 16

kewisch commented 11 months ago

There is a more elaborate debugger if you follow the menu structure I posted above, that should allow you to debug all of Thunderbird (including legacy add-ons like this one). Can you try that?

carlosabalde commented 11 months ago

@kewisch finally I managed to add the breakpoint you suggested, but all I can see is replayChangesOn(aListener) is never called once the issue appears. If I restart Thunderbird to 'fix' the issue, then the breakpoint works as expected.

jachoo commented 10 months ago

The issue is already diagnosed in the following threads: https://github.com/kewisch/gdata-provider/discussions/497#discussioncomment-5194513 and https://github.com/kewisch/gdata-provider/discussions/497#discussioncomment-5164776

Probably there's no need to investigate this problem further. You can try to fix this if you have enough knowledge. I don't :(

kewisch commented 10 months ago

Disabling idle time is not a fix, and I'm not yet seeing how the listener isn't triggered in that flow. I'm open to hearing ideas on how to do a proper fix. In the meanwhile, we'll need to do some more debugging. I'm super busy at work at the moment, but hope to get back to this in November.

The interesting piece from that first comment link is that if the listener is never called, then it won't actually replayChangesOn again. So indeed somewhere, there is a listener that isn't being called at the right time.

@carlosabalde you might want to add some debug print statements with cal.LOG() and log when replayChangesOn is called, and maybe a wrapper around the listener to see when the listener is called. This might help narrow down where the missing listener call is.

kewisch commented 7 months ago

@carlosabalde wondering if you could take a look? The listener not being called is very promising, if we find out why and make sure it is called, we can finally fix this issue.

carlosabalde commented 7 months ago

I attempted it a few months ago, but I wasn't successful. Maybe it's not that challenging, but my total lack of JavaScript skills is hindering me here :/

rmhansense commented 5 months ago

Jachoo added this comment: The issue is already diagnosed in the following threads: https://github.com/kewisch/gdata-provider/discussions/497#discussioncomment-5194513 and https://github.com/kewisch/gdata-provider/discussions/497#discussioncomment-5164776" I checked it, from the comments it seems to be working. How can you implement this into Tbird 115.9 This seems to be the same problem I have struggled with for 6 months. Fix is to Turn Provider OFF and ON, and then the calendars refresh properly. Also, I am on GitHub, how do I subscribe to this thread?

kewisch commented 5 months ago

I need to find the root cause of the issue, not simply disable a feature that happens to work around the issue. There is apparently a listener call that doesn't complete, which I thought was impossible, since I catch most of the calls and take action one way or another.

If anyone else experiencing this could add a few log calls as noted in the prior comment I'd appreciate.

peci1 commented 5 months ago

TB 115.8.1 on Linux, provider 115.0.2, I now see this error right after starting TB:

TypeError: messenger is undefined
    replayChangesOn resource://gdata-provider/legacy/modules/gdataCalendar.jsm:755
    _doSynchronize resource:///components/calCachedCalendar.js:328
    _doSynchronize resource:///components/calCachedCalendar.js:302
    synchronize resource:///components/calCachedCalendar.js:282
    onLoad resource:///components/calCachedCalendar.js:75
    notify resource:///modules/calendar/utils/calDataUtils.jsm:39
    notify resource:///modules/calendar/utils/calDataUtils.jsm:66
    refresh resource://gdata-provider/legacy/modules/gdataCalendar.jsm:664
    downstreamRefresh resource:///components/calCachedCalendar.js:629
    refresh resource:///components/calCachedCalendar.js:622

The line mentioned in the stack trace is this one:

https://github.com/kewisch/gdata-provider/blob/e8061fd536400e0fa964919113ef8f0b08655252/src/legacy/modules/gdataCalendar.jsm#L764

benjunmun commented 4 months ago

I believe that I have found the underlying cause of this issue, but I don't know the best way to fix it.

The root cause is that the current calendar code does not like the listener onResult to be called "right away". Normally replayChangesOn will call onResult at some point in the future when promises resolve. However, in the idle timeout case, replayChangesOn calls onResult synchronously.

The conflict is with the thunderbird codebase calCachedCalendar.synchronize. The calendar code assigns this.mPendingSync here, and expects it to be cleared by clearPending in a future onResult call.

However, if the doSynchronize/replayChangesOn resolves instantly, it clears mPendingSync before assigning it during the synchronize call. This leads to an mPendingSync that will stick around forever in the finished state and prevent future refreshes from happening.

Honestly the core thunderbird code looks fragile and might be the better place to fix this, but as a proof of concept I added an extra delay in the replayChangesOn idle code and it appears to fix the problem. I am very unfamiliar with the plugin ecosystem so I assume there is a much better way to defer the onResult here. But I hope this analysis helps!

(also willing to put together a pull request if someone can suggest a proper way to defer the result)

diff --git a/src/legacy/modules/gdataCalendar.jsm b/src/legacy/modules/gdataCalendar.jsm
index b986f77..0224722 100644
--- a/src/legacy/modules/gdataCalendar.jsm
+++ b/src/legacy/modules/gdataCalendar.jsm
@@ -765,8 +765,14 @@ class calGoogleCalendar extends cal.provider.BaseClass {

     if (maxIdleTime != 0 && idleTime > maxIdleTime) {
       cal.LOG("[calGoogleCalendar] Skipping refresh since user is idle");
-      aListener.onResult({ status: Cr.NS_OK }, null);
-      return Promise.resolve();
+      var { setTimeout } = ChromeUtils.import("resource://gre/modules/Timer.jsm");
+      return new Promise(resolve => {
+        cal.LOG("[calGoogleCalendar] Sleeping for 1s");
+        setTimeout(resolve, 1000);
+      }
+      ).then((val) => {
+        aListener.onResult({ status: Cr.NS_OK }, null);
+      });
     }
binki commented 4 months ago

If it is really that type of “zalgo” issue, then it should be sufficient to just move the call into a continuation of Promise.resolve() because that will let the caller’s synchronous code finish executing before running the callback:

      aListener.onResult({ status: Cr.NS_OK }, null);
      return Promise.resolve();

becomes

      // Do not call onResult() until nextTick()!
      return Promise.resolve().then(() => {
        aListener.onResult({ status: Cr.NS_OK }, null);
      });

As you said, the Mozilla code should itself be doing this for you so that it doesn’t matter if your own code runs synchronously or not.

kewisch commented 3 months ago

Let's give this a try. Version 115.3.0 is pending review on addons.thunderbird.net with @benjunmun 's fix. I'm going to leave this open for comments for a bit. You'll have to make sure you restart Thunderbird, not just update the add-on. Hoping very much this was it!

kewisch commented 2 months ago

I'm going to assume it works now, thank you again!

stevepiercy commented 2 months ago

@kewisch there appears to still be an issue reported on https://addons.thunderbird.net/en-US/thunderbird/addon/provider-for-google-calendar/reviews/. Do reviewers know about this repo, or do you check the reviews?

I still cannot dismiss some events to which I have been invited and accepted or "maybe"ed the invitation. I can dismiss all events that I create.

NickNackGus commented 2 months ago

I'm not sure this issue is fixed; I'm still seeing calendar events in Thunderbird that were deleted from my Google Calendar over a year ago, even after manually asking Thunderbird to sync.

olifre commented 2 months ago

On my end, I can confirm that the issue this report is about has been fixed for me — to reiterate, this issue was about the following:

This issue fixed the problem for me, i.e. restarting Thunderbird is not needed anymore to make it sync again.

@stevepiercy and @NickNackGus , I think you are describing different issues which relate to sync problems which were not even fixed by a Thunderbird restart, i.e. these would warrant a new issue to my understanding.

kewisch commented 1 month ago

I'd agree the issues noted are separate issues. I don't regularly look at the reviews, but I do get email for new reviews so if something comes up many times and I have an idea what the issue might be I take a closer look.

vaubaehn commented 1 month ago

Hi @kewisch , thanks for all your great work!

I was also affected from the synchronization issue, updated the provider to 115.3.0, and since then after starting Thunderbird and some days have passed, Thunderbird enters a non-responding state (my workstation is up 24/7). Thunderbird was working fine before, updating gdata-provider was the only thing I changed, that's why I'm assuming it to be correlated. I will update to the latest provider and give feedback if the issue should persist.

stevepiercy commented 1 month ago

New issue created in https://github.com/kewisch/gdata-provider/issues/781