fmbiete / Z-Push-contrib

Z-Push fork with changes that I will try to contrib
GNU Affero General Public License v3.0
134 stars 62 forks source link

Loop detected on IMAP and impossible to get rid of it #157

Closed MykeulGit closed 9 years ago

MykeulGit commented 9 years ago

Hello,

First of all, thank you for this fork, which is perfectly what I needed. Good work.

Tech env :

I have 3 mailboxes on my current test system, and on 2 of them, I get an infinite loop (that never ends obviously). It is the same message than https://github.com/fmbiete/Z-Push-contrib/issues/71 but I do not get ANY error in apache error log, and XMLElement is OK.

Here is the DEBUG log I get : http://pastebin.com/raw.php?i=tfUZhuyh (see at the end mainly)

Sometimes the lines following the error messages changes :

Message id 2930 :

17/03/2015 14:24:21 [ 9363] [DEBUG] [test@example.com] Combined->GetExporter('i/30cca50c')
17/03/2015 14:24:21 [ 9363] [DEBUG] [test@example.com] ExportChangesDiff->InitializeExporter(): Initializing message diff engine. '1155' messages in state
17/03/2015 14:24:21 [ 9363] [DEBUG] [test@example.com] BackendIMAP->GetMessageList('30cca50c','0')
17/03/2015 14:24:21 [ 9363] [DEBUG] [test@example.com] BackendIMAP->getImapIdFromFolderId('30cca50c') = Sent
17/03/2015 14:24:21 [ 9363] [DEBUG] [test@example.com] BackendIMAP->GetMessageList(): searching with sequence '1:*'
17/03/2015 14:24:26 [ 9363] [ INFO] [test@example.com] ExportChangesDiff->InitializeExporter(): Found '1696' changes
17/03/2015 14:24:26 [ 9363] [DEBUG] [test@example.com] Folder type: Email
17/03/2015 14:24:26 [ 9363] [DEBUG] [test@example.com] DeviceManager->GetWindowSize() overwriting max itmes requested of 512 by 100 forced in configuration.
17/03/2015 14:24:26 [ 9363] [DEBUG] [test@example.com] LoopDetection->Detect(): case 3.3 detected - in loop mode, increase loop counter
17/03/2015 14:24:26 [ 9363] [DEBUG] [test@example.com] LoopDetection->Detect(): case 3.3.1 detected - broken item should be next, attempt to ignore it - id '1773'
17/03/2015 14:24:26 [ 9363] [DEBUG] [test@example.com] LoopDetection->Detect(): loop data: loopcount(34), maxCount(1763), queued(1695), ignored(false)
17/03/2015 14:24:26 [ 9363] [ WARN] [test@example.com] Mobile loop detected! Messages sent to the mobile will be restricted to 2 items in order to identify the conflict
17/03/2015 14:24:26 [ 9363] [DEBUG] [test@example.com] BackendIMAP->StatMessage('30cca50c','2930')
17/03/2015 14:24:26 [ 9363] [DEBUG] [test@example.com] BackendIMAP->getImapIdFromFolderId('30cca50c') = Sent
17/03/2015 14:24:26 [ 9363] [DEBUG] [test@example.com] BackendIMAP->GetMessage('30cca50c','2930')
17/03/2015 14:24:26 [ 9363] [DEBUG] [test@example.com] BackendIMAP->getImapIdFromFolderId('30cca50c') = Sent
17/03/2015 14:24:26 [ 9363] [DEBUG] [test@example.com] BackendIMAP->StatMessage('30cca50c','2930')
17/03/2015 14:24:26 [ 9363] [DEBUG] [test@example.com] BackendIMAP->getImapIdFromFolderId('30cca50c') = Sent
17/03/2015 14:24:26 [ 9363] [DEBUG] [test@example.com] BackendIMAP->GetMessage - getBodyPreferenceBestMatch: 4
17/03/2015 14:24:26 [ 9363] [DEBUG] [test@example.com] LoopDetection->IgnoreNextMessage(): this should be the broken one, but is not! Resetting loop count.
17/03/2015 14:24:26 [ 9363] [DEBUG] [test@example.com] LoopDetection->IgnoreNextMessage(): Loop mode, potential broken message id '2930'
17/03/2015 14:24:26 [ 9363] [DEBUG] [test@example.com] BackendIMAP->StatMessage('30cca50c','1772')
17/03/2015 14:24:26 [ 9363] [DEBUG] [test@example.com] BackendIMAP->getImapIdFromFolderId('30cca50c') = Sent
17/03/2015 14:24:26 [ 9363] [DEBUG] [test@example.com] BackendIMAP->GetMessage('30cca50c','1772')
17/03/2015 14:24:26 [ 9363] [DEBUG] [test@example.com] BackendIMAP->getImapIdFromFolderId('30cca50c') = Sent
17/03/2015 14:24:26 [ 9363] [DEBUG] [test@example.com] BackendIMAP->StatMessage('30cca50c','1772')
17/03/2015 14:24:26 [ 9363] [DEBUG] [test@example.com] BackendIMAP->getImapIdFromFolderId('30cca50c') = Sent

Message id 2930 too :

17/03/2015 14:24:51 [ 9365] [DEBUG] [test@example.com] Combined->GetExporter('i/30cca50c')
17/03/2015 14:24:51 [ 9365] [DEBUG] [test@example.com] ExportChangesDiff->InitializeExporter(): Initializing message diff engine. '1155' messages in state
17/03/2015 14:24:51 [ 9365] [DEBUG] [test@example.com] BackendIMAP->GetMessageList('30cca50c','0')
17/03/2015 14:24:51 [ 9365] [DEBUG] [test@example.com] BackendIMAP->getImapIdFromFolderId('30cca50c') = Sent
17/03/2015 14:24:51 [ 9365] [DEBUG] [test@example.com] BackendIMAP->GetMessageList(): searching with sequence '1:*'
17/03/2015 14:24:56 [ 9365] [ INFO] [test@example.com] ExportChangesDiff->InitializeExporter(): Found '1696' changes
17/03/2015 14:24:56 [ 9365] [DEBUG] [test@example.com] Folder type: Email
17/03/2015 14:24:56 [ 9365] [DEBUG] [test@example.com] DeviceManager->GetWindowSize() overwriting max itmes requested of 512 by 100 forced in configuration.
17/03/2015 14:24:56 [ 9365] [DEBUG] [test@example.com] LoopDetection->Detect(): case 3.3 detected - in loop mode, increase loop counter
17/03/2015 14:24:56 [ 9365] [DEBUG] [test@example.com] LoopDetection->Detect(): loop data: loopcount(2), maxCount(1763), queued(1695), ignored(false)
17/03/2015 14:24:56 [ 9365] [ WARN] [test@example.com] Mobile loop detected! Messages sent to the mobile will be restricted to 1 items in order to identify the conflict
17/03/2015 14:24:56 [ 9365] [DEBUG] [test@example.com] BackendIMAP->StatMessage('30cca50c','2930')
17/03/2015 14:24:56 [ 9365] [DEBUG] [test@example.com] BackendIMAP->getImapIdFromFolderId('30cca50c') = Sent
17/03/2015 14:24:56 [ 9365] [DEBUG] [test@example.com] BackendIMAP->GetMessage('30cca50c','2930')
17/03/2015 14:24:56 [ 9365] [DEBUG] [test@example.com] BackendIMAP->getImapIdFromFolderId('30cca50c') = Sent
17/03/2015 14:24:56 [ 9365] [DEBUG] [test@example.com] BackendIMAP->StatMessage('30cca50c','2930')
17/03/2015 14:24:56 [ 9365] [DEBUG] [test@example.com] BackendIMAP->getImapIdFromFolderId('30cca50c') = Sent
17/03/2015 14:24:56 [ 9365] [DEBUG] [test@example.com] BackendIMAP->GetMessage - getBodyPreferenceBestMatch: 4
17/03/2015 14:24:56 [ 9365] [DEBUG] [test@example.com] LoopDetection->IgnoreNextMessage(): Loop mode, potential broken message id '2930'
17/03/2015 14:24:56 [ 9365] [DEBUG] [test@example.com] HandleSync(): Exported maxItems of messages: 1 / 1696
17/03/2015 14:24:56 [ 9365] [DEBUG] [test@example.com] FileStateMachine->SetState() written 94847 bytes on file: '/var/lib/z-push/1/d/4141b05e932d4bf4aa2de0e1857801d1-80234346-48df-4995-be05-eca080e2f5f3-68'
17/03/2015 14:24:56 [ 9365] [DEBUG] [test@example.com] SyncCollections->SaveCollection(): Data of folder 'i/30cca50c' changed
17/03/2015 14:24:56 [ 9365] [DEBUG] [test@example.com] FileStateMachine->SetState() written 897 bytes on file: '/var/lib/z-push/1/d/4141b05e932d4bf4aa2de0e1857801d1-80234346-48df-4995-be05-eca080e2f5f3-fd'
17/03/2015 14:24:56 [ 9365] [DEBUG] [test@example.com] Sync->loadStates(): loading states for folder 'c/Tpersonal'

Can you please help me or tell me what I did wrong ?

FYI : CalDav & CardDAV are syncing perfectly to Owncloud

Regards

fmbiete commented 9 years ago

Hi @MykeulGit

Put your log in WBXML level and check for errors processing the message with id: 1773 Maybe you will find the reason why it's stopping in that message.

MykeulGit commented 9 years ago

Hello,

Thanks for your answer. Very surprisingly, it solved my problem but I do not know why. When activating WEBXML debug, I maxed out the 128M memory_limit of php. I pushed it to 1024M and I have no problem anymore ... which is bizarre as I never had the memory_limit error before.

Now I have another problem, all folders are synced EXCEPT the INBOX which is empty (whereas in the logs it syncs and at the end finds 0 changes for it).

I use dovecot 2.2.13, and have set :

define('IMAP_FOLDER_ROOT', '');
define('IMAP_FOLDER_SENT', '');
define('IMAP_FOLDER_DRAFT', '');
define('IMAP_FOLDER_TRASH', '');

My mailbox is like this :

user@force:/backup/www/z-push-contrib$ perl list_imap_folders.pl -S localhost:993/user@example.com/testpass
Annonces
Divers
Drafts
INBOX
Junk
Junk E-mail
Sent
Trash
VPS

Any ideas ?

Regards

fmbiete commented 9 years ago

Hi @MykeulGit

IMAP_FOLDER_ROOT is the name of your inbox folder, so in your case, it should be INBOX (the default value) IMAP_FOLDER_SENT; "Sent" IMAP_FOLDER_DRAFT; "Drafts" IMAP_FOLDER_TRASH; "Trash"

I think that part needs some rework, so stay tuned.

fmbiete commented 9 years ago

I also have found a problem with the imap_getsubscribed function and dovecot, INBOX won't be listed. So I reverted back to the imap_getmailboxes.

Note the new required config options.

MykeulGit commented 9 years ago

Hello,

I would like to thank you really. It works perfectly. Very good software, keep up the good work.

Regards