OutlookGoogleCalendarSync icon indicating copy to clipboard operation
OutlookGoogleCalendarSync copied to clipboard

Sync doesn't finish - seems to be going back forever

Open ajkessel opened this issue 3 years ago • 9 comments

I'm using 2.8.7.0 to do a one-way sync from Google to Outlook. I have it configured to go back only 14 days but it seems to take forever to finish. Looking at the detailed logs, I see messages like:

2021-06-28 20:40:33,342 DEBUG  7 OutlookGoogleCalendarSync.GoogleOgcs.Calendar [261] -  Retrieving all events from Google: 5/26/2019 -> 5/27/2019
2021-06-28 20:40:33,342 DEBUG  7 OutlookGoogleCalendarSync.GoogleOgcs.Calendar [261] -  Retrieving all events from Google: 5/26/2019 -> 5/27/2019

Even going back now to 2007. Is this normal behavior? If I'm asking it to only sync 14 days back, shouldn't it only be looking back to 6/14/2021, not back to May 2019? Or am I misunderstanding the logic?

My settings are below.

CheckShortcut: directory=Startup; subdir=
Logging level configured to 'All'
OUTLOOK SETTINGS:-
  Service: DefaultMailbox
  Mailbox/FolderStore Name: 
  Calendar: Default Calendar 
  Category Filter: Exclude
  Categories: 
  Only Responded Invites: False
  Filter String: g
  GAL Blocked: False
  Disconnect Between Sync: False
GOOGLE SETTINGS:-
  Calendar: Adam Kessel (ID: ...)
  Exclude Declined Invites: True
  Exclude Goals: True
  Personal API Keys: False
    Client Identifier: 
    Client Secret: 
  API attendee limit in effect: False
  API attendee limit last reached: 1/1/2000 12:00:00 AM
  Cloak Email: True
SYNC OPTIONS:-
 How
  SyncDirection: Outlook ← Google
  MergeItems: True
  DisableDelete: False
  ConfirmOnDelete: True
  SetEntriesPrivate: True
  SetEntriesAvailable: True; olBusy
  SetEntriesColour: True; olCategoryColorTeal; "Personal"
  SingleCategoryOnly: False
  Obfuscate Words: False
 When
  DaysInThePast: 14
  DaysInTheFuture:365
  SyncInterval: 15
  SyncIntervalUnit: Minutes
  Push Changes: False
 What
  AddLocation: True
  AddDescription: True; OnlyToGoogle: True
  AddAttendees: True <200
  AddColours: False
  AddReminders: False
    UseGoogleDefaultReminder: False
    UseOutlookDefaultReminder: True
    ReminderDND: False (22:00-06:00)
PROXY:-
  Type: None
APPLICATION BEHAVIOUR:-
  ShowBubbleTooltipWhenSyncing: True
  StartOnStartup: True; DelayedStartup: 0
  HideSplashScreen: N/A
  SuppressSocialPopup: N/A
  StartInTray: True
  MinimiseToTray: True
  MinimiseNotClose: True
  ShowBubbleWhenMinimising: True
  Portable: False
  CreateCSVFiles: False
  VerboseOutput: True
  MuteClickSounds: False
  Logging Level: ALL
  Error Reporting: 
ABOUT:-
  Alpha Releases: True
  Skip Version: 
  Subscribed: 01-Jan-2000
  Timezone Database: 2021a
ENVIRONMENT:-
  Current Locale: en-US
  Short Date Format: M/d/yyyy
  Short Time Format: h:mm tt
  System Time Zone: Eastern Standard Time; DST=True
  Completed Syncs: 14

(Update - it does seem to finish eventually -- but it takes a very long time!)

ajkessel avatar Jun 29 '21 00:06 ajkessel

Yes, that seems likely behaviour - it sounds like you have some very long running recurring series (that span the sync window) and this is what is causing the "Retrieving all events from Google". This happens when the master event for the Outlook recurring series occurs before the sync window you have defined, so OGCS has to go to Google to try and retrieve the Google equivalent for that master event date (eg May 2019).

However, I think it should only do this once - are you seeing those lines in the log for the same events on subsequent syncs? How many items does it say it's having to sync and how long is a very long time?

NB: The sync would run faster if you reduce the logging level to something like DEBUG instead of ALL.

phw198 avatar Jul 08 '21 23:07 phw198

It takes about 22 minutes to sync. I just noticed, however, that if I disconnect from my work VPN, sync completes in about 20 seconds. This can't possibly be a throughput issue -- although the work VPN is slower than my home LAN, I still get about 200Mbps throughput on the VPN.

It looks like the problem is when I'm on VPN, there is a 30 second delay between "retrieving all events" and "page 1 received" for each item, e.g.:

2021-07-09 09:36:15,817 DEBUG  7 OutlookGoogleCalendarSync.GoogleOgcs.Calendar [261] -  Retrieving all events from Google: 4/29/2021 -> 4/30/2021
2021-07-09 09:36:46,489 DEBUG  7 OutlookGoogleCalendarSync.GoogleOgcs.Calendar [275] -  Page 1 received.

Whereas off the VPN, it is nearly instant:

2021-07-09 11:27:54,706 DEBUG  18 OutlookGoogleCalendarSync.GoogleOgcs.Calendar [261] -  Retrieving all events from Google: 8/23/1962 -> 8/24/1962
2021-07-09 11:27:54,798 DEBUG  18 OutlookGoogleCalendarSync.GoogleOgcs.Calendar [275] -  Page 1 received.

So there may be some sort of security thing causing a delay here that isn't OGCS's fault, but if OGCS did not try to rescan all the past events, it wouldn't be such a problem. For example, that 1962 item (just someone's birthday) seems to be re-scanned every time OGCS is run.

ajkessel avatar Jul 09 '21 15:07 ajkessel

Hi

Since 4 days I am also having issues with syncing. It never finishes. I am running the latest alpha version - it stopped working on Jul 15. I also tried with and without VPN. Below the latest log (direct connection , no VPN, no proxy)

I am syncing 1 day before, and 1 day after, Outlook -> Google only

Outlook hangs at the same time the sync starts. I already clear all outlook data files and started from scratch

2021-07-20 13:49:26,923 DEBUG  16 OutlookGoogleCalendarSync.Recurrence [583] -  This is a recurring appointment with 7 exceptions that will now be iteratively compared.
2021-07-20 13:50:10,424 DEBUG  1 OutlookGoogleCalendarSync.Sync.SyncTimer [37] -  Scheduled sync triggered.
2021-07-20 13:50:10,429 DEBUG  1 OutlookGoogleCalendarSync.Sync.SyncTimer [43] -  Busy syncing already. Rescheduled for 5 mins time.
2021-07-20 13:50:10,430 INFO  1 OutlookGoogleCalendarSync.Sync.SyncTimer [18] -  Next sync scheduled for 20 de julho de 2021 @ 13:55:10

cinzas avatar Jul 20 '21 12:07 cinzas

@phw198 .... today I got this error

2021-07-22 10:27:31,876 DEBUG  1 OutlookGoogleCalendarSync.Sync.SyncTimer [37] -  Scheduled sync triggered.
2021-07-22 10:27:31,877 DEBUG  1 OutlookGoogleCalendarSync.Sync.SyncTimer [43] -  Busy syncing already. Rescheduled for 5 mins time.
2021-07-22 10:27:31,878 INFO  1 OutlookGoogleCalendarSync.Sync.SyncTimer [18] -  Next sync scheduled for 22 de julho de 2021 @ 10:32:31
2021-07-22 10:29:56,965 ERROR  8 OutlookGoogleCalendarSync.Console [278] -  Unable to update existing entries in the Google calendar.
2021-07-22 10:29:56,968 ERROR  8 OutlookGoogleCalendarSync.Console [278] -  System call failed. (Exception from HRESULT: 0x80010100 (RPC_E_SYS_CALL_FAILED))
2021-07-22 10:29:57,747 ERROR  8 OutlookGoogleCalendarSync.OGCSexception [28] -  System.Runtime.InteropServices.COMException: System call failed. (Exception from HRESULT: 0x80010100 (RPC_E_SYS_CALL_FAILED))
2021-07-22 10:29:57,748 ERROR  8 OutlookGoogleCalendarSync.OGCSexception [21] -  Code: 0x80010100,-2147417856; Location: get_AppointmentItem() in <Unknown File>
2021-07-22 10:29:57,749 ERROR  8 OutlookGoogleCalendarSync.OGCSexception [65] -     at Microsoft.Office.Interop.Outlook.Exception.get_AppointmentItem()
   at OutlookGoogleCalendarSync.Recurrence.UpdateGoogleExceptions(AppointmentItem ai, Event ev, Boolean dirtyCache) in C:\Users\Paul\Git\OutlookGoogleCalendarSync\src\OutlookGoogleCalendarSync\Recurrence.cs:line 597
   at OutlookGoogleCalendarSync.GoogleOgcs.Calendar.UpdateCalendarEntries(Dictionary`2 entriesToBeCompared, Int32& entriesUpdated) in C:\Users\Paul\Git\OutlookGoogleCalendarSync\src\OutlookGoogleCalendarSync\GoogleOgcs\GoogleCalendar.cs:line 560
   at OutlookGoogleCalendarSync.Sync.Engine.outlookToGoogle(List`1 outlookEntries, List`1 googleEntries, String& bubbleText) in C:\Users\Paul\Git\OutlookGoogleCalendarSync\src\OutlookGoogleCalendarSync\Sync\Engine.cs:line 649
   at OutlookGoogleCalendarSync.Sync.Engine.synchronize() in C:\Users\Paul\Git\OutlookGoogleCalendarSync\src\OutlookGoogleCalendarSync\Sync\Engine.cs:line 537
   at OutlookGoogleCalendarSync.Sync.Engine.<>c__DisplayClass24_0.<Start>b__0(Object o, DoWorkEventArgs args) in C:\Users\Paul\Git\OutlookGoogleCalendarSync\src\OutlookGoogleCalendarSync\Sync\Engine.cs:line 216
2021-07-22 10:29:57,750 ERROR  8 OutlookGoogleCalendarSync.Console [278] -  System call failed. (Exception from HRESULT: 0x80010100 (RPC_E_SYS_CALL_FAILED))

cinzas avatar Jul 22 '21 09:07 cinzas

Hi @phw198 .

I think I solved it. I had 2 or 3 recurrent meetings, from 2 years ago and with end date to 2023, with some exceptions. These meetings were causing issues. I removed them and Synch went great and fast. I asked the owner to invite me again to those meetings (removed the exceptions cases), and it is syncing fast again.

Thanks

cinzas avatar Jul 23 '21 10:07 cinzas

@ajkessel When you are on the VPN, what's the DNS lookup time? Try running the following in a PowerShell console window: measure-command { nslookup www.googleapis.com }

Annual recurring series, such as birthdays, will only be synced if the month they fall on is within the date range being synced. However, given you're syncing 365 days into the future, this will always sync every annual series.

phw198 avatar Jul 24 '21 21:07 phw198

DNS lookup time on VPN for that example is about 900ms, versus about 270ms off VPN on my current network. Shouldn't DNS lookup for any given domain name only occur once and then be cached, though?

ajkessel avatar Aug 02 '21 12:08 ajkessel

It was a bit of a long shot, but just wondered if there was something wacky going on with your VPN DNS lookups. It doesn't seem to be that, but as you've identified, the problem is specific to your VPN somehow so I'm not sure there's much more I can do.

Once an annual appointment is synced to Google, you could try putting it out of scope of future syncs by assigning it a category you exclude for OGCS. If you're in luck, OGCS won't try and remove it from Google either - but of course an changes to the annual event also won't get synced.

phw198 avatar Aug 07 '21 14:08 phw198

Once an annual appointment is synced to Google, you could try putting it out of scope of future syncs by assigning it a category you exclude for OGCS. If you're in luck, OGCS won't try and remove it from Google either - but of course an changes to the annual event also won't get synced.

If I'm only syncing one way -- Google to Outlook -- and I have no recurring items in my Google Calendar, then this shouldn't be happening, right? Or do I also need to exclude my Outlook recurring items to avoid this behavior, even when it's just a one-way sync to Outlook?

ajkessel avatar Aug 07 '21 22:08 ajkessel