[Tickets #12075] PING-SYNC storm in ActiveSync

[noreply at bugs.horde.org]

DO NOT REPLY TO THIS MESSAGE. THIS EMAIL ADDRESS IS NOT MONITORED.

Ticket URL: http://bugs.horde.org/ticket/12075
------------------------------------------------------------------------------
  Ticket             | 12075
  Created By         | arjen+horde at de-korte.org
  Summary            | PING-SYNC storm in ActiveSync
  Queue              | Synchronization
  Version            | Git master
  Type               | Bug
  State              | Unconfirmed
  Priority           | 1. Low
  Milestone          |
  Patch              |
  Owners             |
------------------------------------------------------------------------------


arjen+horde at de-korte.org (2013-02-27 09:04) wrote:

Occasionally I see a significant battery drain on my mobile phone that  
syncs through ActiveSync. I enabled debugging and found that during  
such an event it continuously repeats the same PING-SYNC sycle.

When it PINGs the server, it will get a reply status of 2 and in the  
logs it mentions

2013-02-22T14:36:53+01:00 DEBUG: [29575] Initializing state for  
collection: Commercieel, synckey:  
{512745e0-365c-4a01-9e3f-4202c0a8010a}2
2013-02-22T14:36:53+01:00 DEBUG: [29575] Loading state for synckey  
{512745e0-365c-4a01-9e3f-4202c0a8010a}2
2013-02-22T14:36:53+01:00 DEBUG: [29575] Initializing message diff  
engine for Commercieel
2013-02-22T14:36:53+01:00 DEBUG: [29575]  
Horde_Core_ActiveSync_Driver::getServerChanges(Commercieel,  
1361528289, 1361540213, 0, 1)
2013-02-22T14:36:54+01:00 DEBUG: [29575] Found 1 message changes in  
Commercieel.
2013-02-22T14:36:54+01:00 DEBUG: [29575] No PIM changes present,  
returning all messages.

But when it subsequently attempts to SYNC that folder, no changes are found:

2013-02-22T14:36:56+01:00 DEBUG: [29598] Initializing state for  
collection: Commercieel, synckey:  
{512745e0-365c-4a01-9e3f-4202c0a8010a}2
2013-02-22T14:36:56+01:00 DEBUG: [29598] Loading state for synckey  
{512745e0-365c-4a01-9e3f-4202c0a8010a}2
2013-02-22T14:36:56+01:00 DEBUG: [29598] Initializing message diff  
engine for Commercieel
2013-02-22T14:36:56+01:00 DEBUG: [29598]  
Horde_Core_ActiveSync_Driver::getServerChanges(Commercieel,  
1361528289, 1361540216, 1359121016, 0)
2013-02-22T14:36:57+01:00 DEBUG: IMAP status: Array
(
     [uidnext] => 1349
     [uidvalidity] => 1108813680
     [highestmodseq] => 1506
)

2013-02-22T14:36:57+01:00 DEBUG: CONDSTORE and CHANGES
2013-02-22T14:36:57+01:00 DEBUG: [29598] Found 0 message changes in  
Commercieel.

This cycle repeats every few seconds until a new message arrives in  
that folder or flags of a message in said folder are changed, after  
which the situation is back to normal. It looks like at times the  
cached state is out of sync with the IMAP server.

The problem seems to be triggered by moving or deleting messages from  
folders that are synchronized through ActiveSync with a non-ActiveSync  
client (I used Horde Webmail). So far it has only occurred minutes  
after the phone went from the direct-push to manual sync mode, but I'm  
not entirely sure if this is related (the problem in this case  
surfaces when the phone goes back to direct-push). But this may also  
have to do with when the phone is in direct-push mode, a human won't  
be fast enough to beat ActiveSync from keeping up with the changes on  
the server.