[horde] ActiveSync syncs single messages countlessly
Michael J Rubinsky
mrubinsk at horde.org
Wed Sep 16 12:16:48 UTC 2015
Quoting Jens Hellermann <hellermann at we-do.com>:
> Am 15.09.2015 um 17:26 schrieb Michael J Rubinsky:
>>
>> Quoting Jens Hellermann <hellermann at we-do.com>:
>>
>>> Dear Horde List members,
>>>
>>> I still have problems syncing a very large email account via
>>> activesync to an Outlook 2013 client. The imap account shows
>>> 54.517 email entries in Horde Webmail.
>>>
>>> To a certain point the sync seems to work normally, but after
>>> hours Outlook starts repeatedly to fetch the same message again
>>> and again. (Approximatly a 100 times)
>>>
>>> Then it goes over to the next message and does the very same thing
>>> again. Something in the communication between Outlook and horde
>>> seems to go wrong.
>>>
>>> Has anyone ever heard of a similar problem? I'm going to do some
>>> extra research tomorrow, but its difficult to go through the log
>>> file as it is extremely large.
>>
>> This *usually* means that there is some issue with that specific
>> email. Try to find the spot in the log where that email is first
>> requested and sent to the client and post the log with some context
>> before and after that request.
>>
> Hello Michael,
>
> here is one example for a mail that has been fetched very often.
> Here come the parts of the log when it turns up the first and the
> second time. As you can see, the next mail in the log is also
> getting fetched a second time.
>
> 2015-09-08T15:15:36+02:00 INFO: [1965] Updating state during change
> 2015-09-08T15:15:36+02:00 INFO: [1965] Peak memory usage after
> message: 68419584
> 2015-09-08T15:15:36+02:00 INFO: [1965]
> Horde_Core_ActiveSync_Driver::getMessage(INBOX, 19429)
> 2015-09-08T15:15:36+02:00 INFO: [1965] Sending MIME Message.
> 2015-09-08T15:15:36+02:00 INFO: [1965] Checking MIMETRUNCATION: ,
> ServerData: 33875
> 2015-09-08T15:15:36+02:00 INFO: [1965] Fetching verb for
> <9E9BE3F2-C32E-4759-96BE-E89CA76E8B9D at we-do.eu>.
> 2015-09-08T15:15:36+02:00 DEBUG: [1965] O <Add>
> 2015-09-08T15:15:36+02:00 DEBUG: [1965] O <ServerEntryId>
> 2015-09-08T15:15:36+02:00 DEBUG: [1965] O 19429
> 2015-09-08T15:15:36+02:00 DEBUG: [1965] O </ServerEntryId>
> 2015-09-08T15:15:36+02:00 DEBUG: [1965] O <Data>
> 2015-09-08T15:15:36+02:00 DEBUG: [1965] O <POOMMAIL:To>
> 2015-09-08T15:15:36+02:00 DEBUG: [1965] O marschall at nexus-netsoft.com
> 2015-09-08T15:15:36+02:00 DEBUG: [1965] O </POOMMAIL:To>
> 2015-09-08T15:15:36+02:00 DEBUG: [1965] O <POOMMAIL:Cc>
> 2015-09-08T15:15:36+02:00 DEBUG: [1965] O [171 bytes of content]
> 2015-09-08T15:15:36+02:00 DEBUG: [1965] O </POOMMAIL:Cc>
> 2015-09-08T15:15:36+02:00 DEBUG: [1965] O <POOMMAIL:From>
> 2015-09-08T15:15:36+02:00 DEBUG: [1965] O Christoph Franz -
> WE DO <franz at we-do.eu>
> 2015-09-08T15:15:36+02:00 DEBUG: [1965] O </POOMMAIL:From>
> 2015-09-08T15:15:36+02:00 DEBUG: [1965] O <POOMMAIL:Subject>
> 2015-09-08T15:15:36+02:00 DEBUG: [1965] O Re: UBSKM:
> Hilfeportal ▒^▒bernahme - offene Fragen
> 2015-09-08T15:15:36+02:00 DEBUG: [1965] O </POOMMAIL:Subject>
> 2015-09-08T15:15:36+02:00 DEBUG: [1965] O <POOMMAIL:Reply-To>
> 2015-09-08T15:15:36+02:00 DEBUG: [1965] O Christoph Franz -
> WE DO <franz at we-do.eu>
> 2015-09-08T15:15:36+02:00 DEBUG: [1965] O </POOMMAIL:Reply-To>
> 2015-09-08T15:15:36+02:00 DEBUG: [1965] O <POOMMAIL:DateReceived>
> 2015-09-08T15:15:36+02:00 DEBUG: [1965] O 2015-01-13T15:46:15.000Z
> 2015-09-08T15:15:36+02:00 DEBUG: [1965] O </POOMMAIL:DateReceived>
> 2015-09-08T15:15:36+02:00 DEBUG: [1965] O <POOMMAIL:DisplayTo>
> 2015-09-08T15:15:36+02:00 DEBUG: [1965] O Ricardo Marschall
> 2015-09-08T15:15:36+02:00 DEBUG: [1965] O </POOMMAIL:DisplayTo>
> 2015-09-08T15:15:36+02:00 DEBUG: [1965] O <POOMMAIL:ThreadTopic>
> 2015-09-08T15:15:36+02:00 DEBUG: [1965] O Re: UBSKM:
> Hilfeportal ▒^▒bernahme - offene Fragen
> 2015-09-08T15:15:36+02:00 DEBUG: [1965] O </POOMMAIL:ThreadTopic>
> 2015-09-08T15:15:36+02:00 DEBUG: [1965] O <POOMMAIL:Importance>
> 2015-09-08T15:15:36+02:00 DEBUG: [1965] O 1
> 2015-09-08T15:15:36+02:00 DEBUG: [1965] O </POOMMAIL:Importance>
> 2015-09-08T15:15:36+02:00 DEBUG: [1965] O <POOMMAIL:Read>
> 2015-09-08T15:15:36+02:00 DEBUG: [1965] O 1
> 2015-09-08T15:15:36+02:00 DEBUG: [1965] O </POOMMAIL:Read>
> 2015-09-08T15:15:36+02:00 DEBUG: [1965] O <POOMMAIL:MessageClass>
> 2015-09-08T15:15:36+02:00 DEBUG: [1965] O IPM.Note
> 2015-09-08T15:15:36+02:00 DEBUG: [1965] O </POOMMAIL:MessageClass>
> 2015-09-08T15:15:36+02:00 DEBUG: [1965] O <POOMMAIL:InternetCPID>
> 2015-09-08T15:15:36+02:00 DEBUG: [1965] O 65001
> 2015-09-08T15:15:36+02:00 DEBUG: [1965] O </POOMMAIL:InternetCPID>
> 2015-09-08T15:15:36+02:00 DEBUG: [1965] O <AirSyncBase:NativeBodyType>
> 2015-09-08T15:15:36+02:00 DEBUG: [1965] O 2
> 2015-09-08T15:15:36+02:00 DEBUG: [1965] O </AirSyncBase:NativeBodyType>
> 2015-09-08T15:15:36+02:00 DEBUG: [1965] O <AirSyncBase:Body>
> 2015-09-08T15:15:36+02:00 DEBUG: [1965] O <AirSyncBase:Type>
> 2015-09-08T15:15:36+02:00 DEBUG: [1965] O 4
> 2015-09-08T15:15:36+02:00 DEBUG: [1965] O </AirSyncBase:Type>
> 2015-09-08T15:15:36+02:00 DEBUG: [1965] O <AirSyncBase:EstimatedDataSize>
> 2015-09-08T15:15:36+02:00 DEBUG: [1965] O 33875
> 2015-09-08T15:15:36+02:00 DEBUG: [1965] O </AirSyncBase:EstimatedDataSize>
> 2015-09-08T15:15:36+02:00 DEBUG: [1965] O <AirSyncBase:Truncated>
> 2015-09-08T15:15:36+02:00 DEBUG: [1965] O 0
> 2015-09-08T15:15:36+02:00 DEBUG: [1965] O </AirSyncBase:Truncated>
> 2015-09-08T15:15:36+02:00 DEBUG: [1965] O <AirSyncBase:Data>
> 2015-09-08T15:15:36+02:00 DEBUG: [1965] O [STREAM]
> 2015-09-08T15:15:36+02:00 DEBUG: [1965] O </AirSyncBase:Data>
> 2015-09-08T15:15:36+02:00 DEBUG: [1965] O </AirSyncBase:Body>
> 2015-09-08T15:15:36+02:00 DEBUG: [1965] O <POOMMAIL:Flag/>
> 2015-09-08T15:15:36+02:00 DEBUG: [1965] O <POOMMAIL:ContentClass>
> 2015-09-08T15:15:36+02:00 DEBUG: [1965] O urn:content-classes:message
> 2015-09-08T15:15:36+02:00 DEBUG: [1965] O </POOMMAIL:ContentClass>
> 2015-09-08T15:15:36+02:00 DEBUG: [1965] O <POOMMAIL:Categories/>
> 2015-09-08T15:15:36+02:00 DEBUG: [1965] O </Data>
> 2015-09-08T15:15:36+02:00 DEBUG: [1965] O </Add>
> 2015-09-08T15:15:36+02:00 INFO: [1965] Updating state during change
> 2015-09-08T15:15:36+02:00 INFO: [1965] Peak memory usage after
> message: 68419584
> 2015-09-08T15:15:36+02:00 INFO: [1965]
> Horde_Core_ActiveSync_Driver::getMessage(INBOX, 19431)
> 2015-09-08T15:15:36+02:00 INFO: [1965] Sending MIME Message.
> 2015-09-08T15:15:36+02:00 INFO: [1965] Checking MIMETRUNCATION: ,
> ServerData: 21084
> 2015-09-08T15:15:36+02:00 INFO: [1965] Fetching verb for
> <8ADBA7D7-3910-401B-B0A7-26E70B5B8761 at we-do.com>.
> 2015-09-08T15:15:36+02:00 DEBUG: [1965] O <Add>
> 2015-09-08T15:15:36+02:00 DEBUG: [1965] O <ServerEntryId>
> 2015-09-08T15:15:36+02:00 DEBUG: [1965] O 19431
> 2015-09-08T15:15:36+02:00 DEBUG: [1965] O </ServerEntryId>
> 2015-09-08T15:15:36+02:00 DEBUG: [1965] O <Data>
> 2015-09-08T15:15:36+02:00 DEBUG: [1965] O <POOMMAIL:To>
> 2015-09-08T15:15:36+02:00 DEBUG: [1965] O [52 bytes of content]
> 2015-09-08T15:15:36+02:00 DEBUG: [1965] O </POOMMAIL:To>
> 2015-09-08T15:15:36+02:00 DEBUG: [1965] O <POOMMAIL:Cc>
> 2015-09-08T15:15:36+02:00 DEBUG: [1965] O [85 bytes of content]
> 2015-09-08T15:15:36+02:00 DEBUG: [1965] O </POOMMAIL:Cc>
> 2015-09-08T15:15:36+02:00 DEBUG: [1965] O <POOMMAIL:From>
> 2015-09-08T15:15:36+02:00 DEBUG: [1965] O Christoph Franz -
> WE DO <franz at we-do.com>
> 2015-09-08T15:15:36+02:00 DEBUG: [1965] O </POOMMAIL:From>
> 2015-09-08T15:15:36+02:00 DEBUG: [1965] O <POOMMAIL:Subject>
> 2015-09-08T15:15:36+02:00 DEBUG: [1965] O Auth-Codes + SSL
> Zertifikat für Domains
>
> 2015-09-08T15:58:17+02:00 INFO: [1968] Updating state during change
> 2015-09-08T15:58:17+02:00 INFO: [1968] Peak memory usage after
> message: 68681728
> 2015-09-08T15:58:17+02:00 INFO: [1968]
> Horde_Core_ActiveSync_Driver::getMessage(INBOX, 19429)
> 2015-09-08T15:58:17+02:00 INFO: [1968] Sending MIME Message.
> 2015-09-08T15:58:17+02:00 INFO: [1968] Checking MIMETRUNCATION: ,
> ServerData: 33875
> 2015-09-08T15:58:17+02:00 INFO: [1968] Fetching verb for
> <9E9BE3F2-C32E-4759-96BE-E89CA76E8B9D at we-do.eu>.
> 2015-09-08T15:58:17+02:00 DEBUG: [1968] O <Add>
> 2015-09-08T15:58:17+02:00 DEBUG: [1968] O <ServerEntryId>
> 2015-09-08T15:58:17+02:00 DEBUG: [1968] O 19429
> 2015-09-08T15:58:17+02:00 DEBUG: [1968] O </ServerEntryId>
> 2015-09-08T15:58:17+02:00 DEBUG: [1968] O <Data>
> 2015-09-08T15:58:17+02:00 DEBUG: [1968] O <POOMMAIL:To>
> 2015-09-08T15:58:17+02:00 DEBUG: [1968] O marschall at nexus-netsoft.com
> 2015-09-08T15:58:17+02:00 DEBUG: [1968] O </POOMMAIL:To>
> 2015-09-08T15:58:17+02:00 DEBUG: [1968] O <POOMMAIL:Cc>
> 2015-09-08T15:58:17+02:00 DEBUG: [1968] O [171 bytes of content]
> 2015-09-08T15:58:17+02:00 DEBUG: [1968] O </POOMMAIL:Cc>
> 2015-09-08T15:58:17+02:00 DEBUG: [1968] O <POOMMAIL:From>
> 2015-09-08T15:58:17+02:00 DEBUG: [1968] O Christoph Franz -
> WE DO <franz at we-do.eu>
> 2015-09-08T15:58:17+02:00 DEBUG: [1968] O </POOMMAIL:From>
> 2015-09-08T15:58:17+02:00 DEBUG: [1968] O <POOMMAIL:Subject>
> 2015-09-08T15:58:17+02:00 DEBUG: [1968] O Re: UBSKM:
> Hilfeportal ▒^▒bernahme - offene Fragen
> 2015-09-08T15:58:17+02:00 DEBUG: [1968] O </POOMMAIL:Subject>
> 2015-09-08T15:58:17+02:00 DEBUG: [1968] O <POOMMAIL:Reply-To>
> 2015-09-08T15:58:17+02:00 DEBUG: [1968] O Christoph Franz -
> WE DO <franz at we-do.eu>
> 2015-09-08T15:58:17+02:00 DEBUG: [1968] O </POOMMAIL:Reply-To>
> 2015-09-08T15:58:17+02:00 DEBUG: [1968] O <POOMMAIL:DateReceived>
> 2015-09-08T15:58:17+02:00 DEBUG: [1968] O 2015-01-13T15:46:15.000Z
> 2015-09-08T15:58:17+02:00 DEBUG: [1968] O </POOMMAIL:DateReceived>
> 2015-09-08T15:58:17+02:00 DEBUG: [1968] O <POOMMAIL:DisplayTo>
> 2015-09-08T15:58:17+02:00 DEBUG: [1968] O Ricardo Marschall
> 2015-09-08T15:58:17+02:00 DEBUG: [1968] O </POOMMAIL:DisplayTo>
> 2015-09-08T15:58:17+02:00 DEBUG: [1968] O <POOMMAIL:ThreadTopic>
> 2015-09-08T15:58:17+02:00 DEBUG: [1968] O Re: UBSKM:
> Hilfeportal ▒^▒bernahme - offene Fragen
> 2015-09-08T15:58:17+02:00 DEBUG: [1968] O </POOMMAIL:ThreadTopic>
> 2015-09-08T15:58:17+02:00 DEBUG: [1968] O <POOMMAIL:Importance>
> 2015-09-08T15:58:17+02:00 DEBUG: [1968] O 1
> 2015-09-08T15:58:17+02:00 DEBUG: [1968] O </POOMMAIL:Importance>
> 2015-09-08T15:58:17+02:00 DEBUG: [1968] O <POOMMAIL:Read>
> 2015-09-08T15:58:17+02:00 DEBUG: [1968] O 1
> 2015-09-08T15:58:17+02:00 DEBUG: [1968] O </POOMMAIL:Read>
> 2015-09-08T15:58:17+02:00 DEBUG: [1968] O <POOMMAIL:MessageClass>
> 2015-09-08T15:58:17+02:00 DEBUG: [1968] O IPM.Note
> 2015-09-08T15:58:17+02:00 DEBUG: [1968] O </POOMMAIL:MessageClass>
> 2015-09-08T15:58:17+02:00 DEBUG: [1968] O <POOMMAIL:InternetCPID>
> 2015-09-08T15:58:17+02:00 DEBUG: [1968] O 65001
> 2015-09-08T15:58:17+02:00 DEBUG: [1968] O </POOMMAIL:InternetCPID>
> 2015-09-08T15:58:17+02:00 DEBUG: [1968] O <AirSyncBase:NativeBodyType>
> 2015-09-08T15:58:17+02:00 DEBUG: [1968] O 2
> 2015-09-08T15:58:17+02:00 DEBUG: [1968] O </AirSyncBase:NativeBodyType>
> 2015-09-08T15:58:17+02:00 DEBUG: [1968] O <AirSyncBase:Body>
> 2015-09-08T15:58:17+02:00 DEBUG: [1968] O <AirSyncBase:Type>
> 2015-09-08T15:58:17+02:00 DEBUG: [1968] O 4
> 2015-09-08T15:58:17+02:00 DEBUG: [1968] O </AirSyncBase:Type>
> 2015-09-08T15:58:17+02:00 DEBUG: [1968] O <AirSyncBase:EstimatedDataSize>
> 2015-09-08T15:58:17+02:00 DEBUG: [1968] O 33875
> 2015-09-08T15:58:17+02:00 DEBUG: [1968] O </AirSyncBase:EstimatedDataSize>
> 2015-09-08T15:58:17+02:00 DEBUG: [1968] O <AirSyncBase:Truncated>
> 2015-09-08T15:58:17+02:00 DEBUG: [1968] O 0
> 2015-09-08T15:58:17+02:00 DEBUG: [1968] O </AirSyncBase:Truncated>
> 2015-09-08T15:58:17+02:00 DEBUG: [1968] O <AirSyncBase:Data>
> 2015-09-08T15:58:17+02:00 DEBUG: [1968] O [STREAM]
> 2015-09-08T15:58:17+02:00 DEBUG: [1968] O </AirSyncBase:Data>
> 2015-09-08T15:58:17+02:00 DEBUG: [1968] O </AirSyncBase:Body>
> 2015-09-08T15:58:17+02:00 DEBUG: [1968] O <POOMMAIL:Flag/>
> 2015-09-08T15:58:17+02:00 DEBUG: [1968] O <POOMMAIL:ContentClass>
> 2015-09-08T15:58:17+02:00 DEBUG: [1968] O urn:content-classes:message
> 2015-09-08T15:58:17+02:00 DEBUG: [1968] O </POOMMAIL:ContentClass>
> 2015-09-08T15:58:17+02:00 DEBUG: [1968] O <POOMMAIL:Categories/>
> 2015-09-08T15:58:17+02:00 DEBUG: [1968] O </Data>
> 2015-09-08T15:58:17+02:00 DEBUG: [1968] O </Add>
> 2015-09-08T15:58:17+02:00 INFO: [1968] Updating state during change
> 2015-09-08T15:58:17+02:00 INFO: [1968] Peak memory usage after
> message: 68681728
> 2015-09-08T15:58:17+02:00 INFO: [1968]
> Horde_Core_ActiveSync_Driver::getMessage(INBOX, 19431)
> 2015-09-08T15:58:17+02:00 INFO: [1968] Sending MIME Message.
> 2015-09-08T15:58:17+02:00 INFO: [1968] Checking MIMETRUNCATION: ,
> ServerData: 21084
> 2015-09-08T15:58:17+02:00 INFO: [1968] Fetching verb for
> <8ADBA7D7-3910-401B-B0A7-26E70B5B8761 at we-do.com>.
> 2015-09-08T15:58:17+02:00 DEBUG: [1968] O <Add>
> 2015-09-08T15:58:17+02:00 DEBUG: [1968] O <ServerEntryId>
> 2015-09-08T15:58:17+02:00 DEBUG: [1968] O 19431
> 2015-09-08T15:58:17+02:00 DEBUG: [1968] O </ServerEntryId>
> 2015-09-08T15:58:17+02:00 DEBUG: [1968] O <Data>
> 2015-09-08T15:58:17+02:00 DEBUG: [1968] O <POOMMAIL:To>
> 2015-09-08T15:58:17+02:00 DEBUG: [1968] O [52 bytes of content]
> 2015-09-08T15:58:17+02:00 DEBUG: [1968] O </POOMMAIL:To>
> 2015-09-08T15:58:17+02:00 DEBUG: [1968] O <POOMMAIL:Cc>
> 2015-09-08T15:58:17+02:00 DEBUG: [1968] O [85 bytes of content]
> 2015-09-08T15:58:17+02:00 DEBUG: [1968] O </POOMMAIL:Cc>
> 2015-09-08T15:58:17+02:00 DEBUG: [1968] O <POOMMAIL:From>
> 2015-09-08T15:58:17+02:00 DEBUG: [1968] O Christoph Franz -
> WE DO <franz at we-do.com>
> 2015-09-08T15:58:17+02:00 DEBUG: [1968] O </POOMMAIL:From>
> 2015-09-08T15:58:17+02:00 DEBUG: [1968] O <POOMMAIL:Subject>
> 2015-09-08T15:58:17+02:00 DEBUG: [1968] O Auth-Codes + SSL
> Zertifikat für Domains
That's not enough of the log to determine anything. I need the entire
request and response. Of at least two instances of this happening.
Preferably the first one, and the second one.
Requests like this rarely contain only a single email message, so it's
not unusual that multiple messages are synchronized each time. If a
single error occurs with any of the messages in a specific request
(identified by a synckey), depending on the error, the client makes
the same request again, which results in the same response, until the
client gives up.
--
mike
The Horde Project
http://www.horde.org
https://www.facebook.com/hordeproject
https://www.twitter.com/hordeproject
-------------- next part --------------
A non-text attachment was scrubbed...
Name: smime.p7s
Type: application/pkcs7-signature
Size: 5751 bytes
Desc: S/MIME Signature
URL: <http://lists.horde.org/archives/horde/attachments/20150916/0aa05856/attachment.bin>
More information about the horde
mailing list