SOGo | BTS

View Issue Details Jump to Notes ] Issue History ] Print ]
IDProjectCategoryView StatusDate SubmittedLast Update
0004448SOGoActiveSyncpublic2018-04-15 04:562018-04-16 11:45
Reportereina 
Assigned To 
PrioritynormalSeverityminorReproducibilityalways
StatusnewResolutionopen 
PlatformOSOS Version
Product Version 
Target VersionFixed in Version 
Summary0004448: ActiveSync stops sync at some stage
DescriptionHi, we have one user with large mailbox - ~40k e-mails and about 30GB. We tried to sync its mailbox to MS Outlook 2013 several times, and we encounter same error everytime, this is debug log of EAS on which the sync stops:

Apr 15 10:41:20 sogod [7083]: <0x0x55c19de165c0[SOGoActiveSyncDispatcher]> Cache cleanup needed for device F052DB623C104868926617915E9B6393 - user: 6959 syncKey: 34174-34272 cache: 34174-34273
Apr 15 10:41:20 sogod [7083]: <0x0x55c19e11b4d0[NGImap4Client]> Note: no key found for sorting, using 'DATE': (null)
Apr 15 10:41:20 sogod [7083]: <0x0x55c19de165c0[SOGoActiveSyncDispatcher]> EAS - sortedBySequence (34172) - lastObject: 34174-34273
Apr 15 10:41:20 sogod [7083]: <0x0x55c19de165c0[SOGoActiveSyncDispatcher]> EAS - allCacheObjects (2) - lastObject: 34174-34273
Apr 15 10:41:21 sogod [7083]: <0x0x55c19de165c0[SOGoActiveSyncDispatcher]> EAS - Cache cleanup: from uid: 34174 to uid: 34174
Apr 15 10:41:21 sogod [7083]: <0x0x55c19de165c0[SOGoActiveSyncDispatcher]> EAS - Cache cleanup: ADD 34174
Apr 15 10:41:21 sogod [7083]: <0x0x55c19de165c0[SOGoActiveSyncDispatcher]> EAS - Cache cleanup: CHANGE 34171
Apr 15 10:41:21 sogod [7083]: <0x0x55c19de165c0[SOGoActiveSyncDispatcher]> EAS - found in cache: 0 k = 0
Apr 15 10:41:21 sogod [7083]: <0x0x55c19de165c0[SOGoActiveSyncDispatcher]> EAS - Dealing with cacheObject: 34171-34272
Apr 15 10:41:21 sogod [7083]: <0x0x55c19de165c0[SOGoActiveSyncDispatcher]> EAS - CHANGE!
Apr 15 10:41:21 sogod [7083]: <0x0x55c19de165c0[SOGoActiveSyncDispatcher]> EAS - Dealing with cacheObject: 34174-34273
Apr 15 10:41:21 sogod [7083]: <0x0x55c19de165c0[SOGoActiveSyncDispatcher]> EAS - ADD!
Apr 15 10:41:21 sogod [7083]: <0x0x55c19de165c0[SOGoActiveSyncDispatcher]> EAS - first uid added 34174

And from this moment no more items are synced to Outlook.
I think server has problem with item which number is somewhere from 34174-34273. What does those SyncKey means? And how can I rely on them when searching items in inbox?
TagsNo tags attached.
Attached Files

- Relationships Relation Graph ] Dependency Graph ]

-  Notes
(0012840)
tfu (reporter)
2018-04-15 09:09

34174-34273 >> 34174 = imap-uid of the email-message / 34273 = imap-modseq of the email message

To identify the message with uid 34174 you could search sogo.log for "<ServerId>34174</ServerId>".

To fetch the message with uid 34174 from you imap-server:
telnet <your imap-server> 143
1 login <user> <password>
1 select inbox
1 uid fetch 34174 (BODY.PEEK[])
(0012841)
eina (reporter)
2018-04-15 13:16

Where can i enable logging to sogo.log? In my server sogo.log file is empty... Only sogo-eas.log is growing.
(0012842)
eina (reporter)
2018-04-15 14:03

And what does that mean that cache cleanup needed for device? That means that I have to resync that device?
(0012843)
tfu (reporter)
2018-04-15 14:25

Sogo.log is just the default name. If it's sogo-eas.log in your case, check this file.

The "... cleanup..." message is a debug message. Usually user can ignore this message, but in your case there seems to a sync issue we need to analyze.
(0012844)
eina (reporter)
2018-04-15 14:30
edited on: 2018-04-15 14:41

Hmm, if its just a debug message so it's very strange, because none of other users has that message, only that problematic:

Apr 15 20:24:42 sogod [8705]: <0x0x56401d62c870[SOGoActiveSyncDispatcher]> Cache cleanup needed for device F052DB623C104868926617915E9B6393 - user: 6959 syncKey: 34174-34272 cache: 34174-34273
Apr 15 20:30:20 sogod [8708]: <0x0x56401d995130[SOGoActiveSyncDispatcher]> Cache cleanup needed for device F052DB623C104868926617915E9B6393 - user: 6959 syncKey: 34174-34272 cache: 34174-34273
Apr 15 20:35:40 sogod [8637]: <0x0x56401d660160[SOGoActiveSyncDispatcher]> Cache cleanup needed for device F052DB623C104868926617915E9B6393 - user: 6959 syncKey: 34174-34272 cache: 34174-34273
Apr 15 20:41:20 sogod [8711]: <0x0x56401d651bb0[SOGoActiveSyncDispatcher]> Cache cleanup needed for device F052DB623C104868926617915E9B6393 - user: 6959 syncKey: 34174-34272 cache: 34174-34273
Apr 15 20:46:45 sogod [8759]: <0x0x56401d6156e0[SOGoActiveSyncDispatcher]> Cache cleanup needed for device F052DB623C104868926617915E9B6393 - user: 6959 syncKey: 34174-34272 cache: 34174-34273


I have copied inbox to test mailbox and trying to sync it from other user and see if it will be the same. And if it will be the same - then I will try to figure out item which has a problems.

(0012845)
eina (reporter)
2018-04-15 23:56
edited on: 2018-04-15 23:56

I have tried to sync Inbox from Maildir to my test account, and what do you think - it has synced all items and everything is fine.
I have also tried to resync the original Inbox and it is failing again. But now it is failing with:

Apr 16 06:48:20 sogod [10680]: <0x0x56401de6caf0[SOGoActiveSyncDispatcher]> Cache cleanup needed for device F052DB623C104868926617915E9B6393 - user: 6959 syncKey: 34175-34274 cache: 34177-34277

at night, when sync was in progress, there were two new items which got to inbox, so sync key is higher. I have checked - sync key in appearing in log message is one of two new item. So my guess is that sync has been completed successfully, but when new items poped in it started to fail syncing.
Maybe someone has any thoughts on this issue? My test inbox is fine, it can get new messages and does not show that cache cleanup needed...

(0012846)
tfu (reporter)
2018-04-16 01:16

If you want to provide your sogo.log including a few sync request of the problem client I can have a look.
(0012848)
tfu (reporter)
2018-04-16 11:45

Setting SOGoEASDebugEnabled = YES will enable debug logging which might help to analyze the problem.

- Issue History
Date Modified Username Field Change
2018-04-15 04:56 eina New Issue
2018-04-15 09:09 tfu Note Added: 0012840
2018-04-15 13:16 eina Note Added: 0012841
2018-04-15 14:03 eina Note Added: 0012842
2018-04-15 14:25 tfu Note Added: 0012843
2018-04-15 14:30 eina Note Added: 0012844
2018-04-15 14:41 eina Note Edited: 0012844 View Revisions
2018-04-15 23:56 eina Note Added: 0012845
2018-04-15 23:56 eina Note Edited: 0012845 View Revisions
2018-04-16 01:16 tfu Note Added: 0012846
2018-04-16 11:45 tfu Note Added: 0012848


Copyright © 2000 - 2018 MantisBT Team
Powered by Mantis Bugtracker