[Tickets #12523] AS: mix of unix timestamp and modseq breaks sync

[noreply at bugs.horde.org]

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

Ticket URL: http://bugs.horde.org/ticket/12523
------------------------------------------------------------------------------
  Ticket             | 12523
  Created By         | Thomas Jarosch <thomas.jarosch at intra2net.com>
  Summary            | AS: mix of unix timestamp and modseq breaks sync
  Queue              | Synchronization
  Version            | Git master
  Type               | Bug
  State              | Unconfirmed
  Priority           | 1. Low
  Milestone          |
  Patch              |
  Owners             |
------------------------------------------------------------------------------


Thomas Jarosch <thomas.jarosch at intra2net.com> (2013-08-01 09:27) wrote:

Hi,

I found a bug mixing unix timestamps and modseq numbers which breaks  
the AS sync:

One ActiveSync client wrote a contact to the server.
I then modified the contact on the server and wanted to sync it back.
This failed with " Ignoring PIM initiated change for XXXXX".

Here's the relevant ActiveSync log:
---------------------------------------
2013-08-01T10:22:51+02:00 INFO: [6611] Initializing state for  
collection: @Contacts@, synckey: {51fa1ab1-ed48-4d7d-a02a-19d3ac100191}3
2013-08-01T10:22:51+02:00 INFO: [6611] Loading state for synckey  
{51fa1ab1-ed48-4d7d-a02a-19d3ac100191}3
2013-08-01T10:22:51+02:00 INFO: [6611] Using MODSEQ 6105 for @Contacts at .
2013-08-01T10:22:51+02:00 INFO: [6611] Initializing message diff  
engine for @Contacts@ (@Contacts@)
2013-08-01T10:22:51+02:00 INFO: [6611]  
Horde_Core_ActiveSync_Driver::getServerChanges(@Contacts@, 6102, 6105,  
0, 0)
2013-08-01T10:22:51+02:00 INFO: [6611] Fetching changes for contacts  
using MODSEQ.
2013-08-01T10:22:51+02:00 INFO: [6611] Found 1 message changes in @Contacts at .
2013-08-01T10:22:51+02:00 INFO: [6611] Checking for PIM initiated changes.
2013-08-01T10:22:51+02:00 INFO: [6611]  
Horde_Core_ActiveSync_Driver::_smartStatMessage(@Contacts@,  
51fa1ab1-17ac-49c8-b2ea-19d3ac100191)
2013-08-01T10:22:51+02:00 INFO: [6611] Ignoring PIM initiated change  
for 51fa1ab1-17ac-49c8-b2ea-19d3ac100191 (PIM TS: 1375345329 Stat TS:  
6105)
---------------------------------------

Corresponding Horde_History database dump:
---------------------------------------
sqlite> select * from horde_histories where history_who='clean';
history_id|object_uid|history_action|history_ts|history_desc|history_who|history_extra|history_modseq
6084|Kolab_History_Sync:0d557a9f952c2c6133f5aedec9a1b911|sync|1375345224||clean||6092
6085|Kolab_History_Sync:1a24c92e4e92615aa1dffe70a9f68b98|sync|1375345221||clean||6090
6086|Kolab_History_Sync:43b14f5d0d455283cffbb1c411de821e|sync|1375347126||clean||6107
6087|Kolab_History_Sync:6dd200ddbb206b50615ff802e58f315e|sync|1375345225||clean||6093
6088|turba:8jZheX0ejM69bpifbWqxRQ1:51fa1ab1-17ac-49c8-b2ea-19d3ac100191|add|1375345329||clean||6099
6089|turba:8jZheX0ejM69bpifbWqxRQ1:51fa1ab1-4010-4193-bca2-19d3ac100191|add|1375345329||clean||6102
6090|turba:8jZheX0ejM69bpifbWqxRQ1:51fa1ab1-17ac-49c8-b2ea-19d3ac100191|modify|1375345361||clean||6105

---------------------------------------

The problem is that the logic for "Ignoring PIM initiated change"  
mixes unix timestamps
and the new modseq numbers: "(PIM TS: 1375345329 Stat TS: 6105)".

This boils down to the "Horde_ActiveSync_State_Sql::_getPIMChangeTS()"  
function
which does not seem to use modseq numbers.

Cheers,
Thomas