Summary | Contacts sync with ActiveSync get duplicates and not sync |
Queue | Synchronization |
Queue Version | Git master |
Type | Bug |
State | Resolved |
Priority | 1. Low |
Owners | mrubinsk (at) horde (dot) org |
Requester | carlos.velasco (at) nimastelecom (dot) com |
Created | 07/28/2013 (4314 days ago) |
Due | |
Updated | 08/12/2013 (4299 days ago) |
Assigned | 08/09/2013 (4302 days ago) |
Resolved | 08/12/2013 (4299 days ago) |
Milestone | |
Patch | Yes |
imported, and the fields are not present, the hash does not contain
those fields and the default for those fields in the DB is null. The
duplicate detection still works in this case. So, unless you see some
unwanted behavior because of this, I'll still consider this ticket
resolved.
When imported from VCard file:
turba_objects where object_firstname='TEST';
| object_anniversary | object_workemail | object_homeemail |
+--------------------+------------------+------------------+
| NULL | NULL | NULL |
+--------------------+------------------+------------------+
1 row in set (0.00 sec)
When added manually through Turba web:
turba_objects where object_firstname='TESTMANUAL';
| object_anniversary | object_workemail | object_homeemail |
+--------------------+------------------+------------------+
| NULL | | |
+--------------------+------------------+------------------+
1 row in set (0.00 sec)
commit 07436f188b4e5f7727b176a3192346a943958514
Author: Thomas Jarosch <thomas.jarosch@intra2net.com>
Date: Fri Aug 9 18:39:02 2013 +0200
Remove empty 'birthday' or 'anniversary' fields during Kolab
_store(), otherwise Kolab_Format will try to generate date fields and
crashes.
Second part of the fix for
bug #12506.Signed-off-by: Thomas Jarosch <thomas.jarosch@intra2net.com>
Signed-off-by: Michael J Rubinsky <mrubinsk@horde.org>
turba/lib/Driver/Kolab.php | 8 ++++++++
1 files changed, 8 insertions(+), 0 deletions(-)
http://git.horde.org/horde-git/-/commit/07436f188b4e5f7727b176a3192346a943958514
your example:
array(3) { 'homePhone' => string(10) "+555555555" 'firstname' =>
string(4) "TEST" 'name' => string(4) "TEST" }
State ⇒ Assigned
Patch ⇒ Yes
New Attachment: 0001-Remove-empty-birthday-or-anniversary-fields-during-K.patch
'birthday' or 'anniversary' are '' instead of null.
Please apply the attached patch to fix EAS imports.
BEGIN:VCARD
VERSION:3.0
TEL;TYPE=HOME,VOICE:+555555555
N:;TEST;;;
FN:TEST
END:VCARD
When imported homeEmail, workEmail and so are set to NULL not to ''
http://git.horde.org/horde-git/-/commit/963d725f32fbbe4fb4c5f1b9ff6a9c4a1ab5c235 applied, I still see homeemail and others with NULL after importing a vcard file through turba
web.
commit e766cc017e7f1d5e80487760e189f9529f354cf0
Author: Thomas Jarosch <thomas.jarosch@intra2net.com>
Date: Thu Aug 8 21:47:30 2013 +0200
Prevent setting the current date as birthday/anniversary if the
corresponding field was not given during EAS import
The bug was "uncovered" by a recent fix for
#12506Signed-off-by: Thomas Jarosch <thomas.jarosch@intra2net.com>
Signed-off-by: Michael J Rubinsky <mrubinsk@horde.org>
turba/lib/Driver/Kolab.php | 4 ++--
1 files changed, 2 insertions(+), 2 deletions(-)
http://git.horde.org/horde-git/-/commit/e766cc017e7f1d5e80487760e189f9529f354cf0
State ⇒ Assigned
New Attachment: 0001-Prevent-setting-the-current-date-as-birthday-anniver.patch
State ⇒ Resolved
separate issues.
commit 963d725f32fbbe4fb4c5f1b9ff6a9c4a1ab5c235
Author: Michael J Rubinsky <mrubinsk@horde.org>
Date: Thu Aug 8 14:49:49 2013 -0400
Ensure the email fields are not set to null
Bug: 12506.turba/lib/Driver.php | 18 ++++++++++++------
1 files changed, 12 insertions(+), 6 deletions(-)
http://git.horde.org/horde-git/-/commit/963d725f32fbbe4fb4c5f1b9ff6a9c4a1ab5c235
the duplicate detection fix has a nasty side effect:
When you create a new contact on the PIM and don't set a birthday field,
it will set the birthday and anniversary to the current date in turba.
from the client does not set any birthday value for me.
ActiveSync, but if you import a VCard file (vcf) through Turba wen
interface, these fields are NULL too.
It seems that import functions let fields at NULL too.
the duplicate detection fix has a nasty side effect:
When you create a new contact on the PIM and don't set a birthday field,
it will set the birthday and anniversary to the current date in turba.
This is what the client sent on adding a contact:
-----------------------------------
2013-08-08T17:08:01+02:00 DEBUG: [1809] I <Add>
2013-08-08T17:08:01+02:00 DEBUG: [1809] I <ClientEntryId>
2013-08-08T17:08:01+02:00 DEBUG: [1809] I new_39_1375974483846
2013-08-08T17:08:01+02:00 DEBUG: [1809] I </ClientEntryId>
2013-08-08T17:08:01+02:00 DEBUG: [1809] I <Data>
2013-08-08T17:08:01+02:00 DEBUG: [1809] I
<POOMCONTACTS:MobilePhoneNumber>
2013-08-08T17:08:01+02:00 DEBUG: [1809] I 9876/54321
2013-08-08T17:08:01+02:00 DEBUG: [1809] I
</POOMCONTACTS:MobilePhoneNumber>
2013-08-08T17:08:01+02:00 DEBUG: [1809] I <POOMCONTACTS:LastName>
2013-08-08T17:08:01+02:00 DEBUG: [1809] I Koreo
2013-08-08T17:08:01+02:00 DEBUG: [1809] I </POOMCONTACTS:LastName>
2013-08-08T17:08:01+02:00 DEBUG: [1809] I <POOMCONTACTS:FirstName>
2013-08-08T17:08:01+02:00 DEBUG: [1809] I Samsungo
2013-08-08T17:08:01+02:00 DEBUG: [1809] I </POOMCONTACTS:FirstName>
2013-08-08T17:08:01+02:00 DEBUG: [1809] I <POOMCONTACTS:FileAs>
2013-08-08T17:08:01+02:00 DEBUG: [1809] I Samsungo Koreo
2013-08-08T17:08:01+02:00 DEBUG: [1809] I </POOMCONTACTS:FileAs>
2013-08-08T17:08:01+02:00 DEBUG: [1809] I <AirSyncBase:Body>
2013-08-08T17:08:01+02:00 DEBUG: [1809] I <AirSyncBase:Type>
2013-08-08T17:08:01+02:00 DEBUG: [1809] I 1
2013-08-08T17:08:01+02:00 DEBUG: [1809] I </AirSyncBase:Type>
2013-08-08T17:08:01+02:00 DEBUG: [1809] I <AirSyncBase:Data>
2013-08-08T17:08:01+02:00 DEBUG: [1809] I
2013-08-08T17:08:01+02:00 DEBUG: [1809] I </AirSyncBase:Data>
2013-08-08T17:08:01+02:00 DEBUG: [1809] I </AirSyncBase:Body>
2013-08-08T17:08:01+02:00 DEBUG: [1809] I <POOMCONTACTS:Email1Address>
2013-08-08T17:08:01+02:00 DEBUG: [1809] I "Samsungo Koreo"
<kim@korea.com>
2013-08-08T17:08:01+02:00 DEBUG: [1809] I </POOMCONTACTS:Email1Address>
2013-08-08T17:08:01+02:00 DEBUG: [1809] I <POOMCONTACTS:Categories>
2013-08-08T17:08:01+02:00 DEBUG: [1809] I <POOMCONTACTS:Category>
2013-08-08T17:08:01+02:00 DEBUG: [1809] I Friends
2013-08-08T17:08:01+02:00 DEBUG: [1809] I </POOMCONTACTS:Category>
2013-08-08T17:08:01+02:00 DEBUG: [1809] I </POOMCONTACTS:Categories>
2013-08-08T17:08:01+02:00 DEBUG: [1809] I </Data>
2013-08-08T17:08:01+02:00 INFO: [1809]
Horde_Core_ActiveSync_Driver::changeMessage(@Contacts@, ...)
2013-08-08T17:08:01+02:00 INFO: [1809] Using MODSEQ 2708 for @Contacts@.
2013-08-08T17:08:01+02:00 INFO: [1809] Updating state during change
2013-08-08T17:08:01+02:00 DEBUG: [1809] I </Add>
-----------------------------------
ActiveSync, but if you import a VCard file (vcf) through Turba wen
interface, these fields are NULL too.
It seems that import functions let fields at NULL too.
State ⇒ Assigned
changes until they are all parsed looks like we will still need to
refactor the client ADD code to not perform the additions until after
all the data is received instead of the current way of importing them
as we receive them to save on memory.
New Attachment: load200.pcapng
New Attachment: load250.pcapng
It "solves" the issue just discarding the Sync returning a Status 4
for the global sync if the number of contacts is more than 200
(aprox.) No contacts are added to the account, just a Status 4 is
returned and the whole sync is discarded.
I am uploading sniffer traces for a load of 200 contacts (success,
status 1), and a load of 250 contacts (fails, status 4).
ActiveSync, but if you import a VCard file (vcf) through Turba wen
interface, these fields are NULL too.
New Attachment: android42timeout.pcap
It is still worse. The timeout is now as low as 30 seconds.
Uploading pcap sniffer traces with Android 4.2.2
I would like to test this issue with a Exchange Server to see what
happens and how a Exchange Server handles this, indeed I have access
to one, but it only uses SSL and I haven't the private RSA key to
decrypt, it would be really difficult to me.
time later. I have always assumed this is right because you need the
status for the whole Sync and you can not know this until all
additions are processed.
request is handled before we send any responses and the ADD command
may not be the only or last command processed. We process the incoming
data as we receive it so that we don't need to keep all the incoming
message data in memory before we start processing it.
first 50 ADDs in the packet, this sortens the GAP to less than 1
minute and workarounds the timeout. With this patch (hack) Android
seems to work fine and sync all contacts with time.
that actually follows the specs. It ignores incoming changes and sends
no status response on those skipped messages. According to the specs
the client MUST assume the addition worked and should NOT send the
change(s) again.
we should return the existing item's UID as if the addition was
successful. Of course, I have no idea what your client will do with
this, since it is demonstrating broken behavior anyway, not to
mention if the connection continues to timeout, this won't help your
original problem anyway.
work, there are not additions so the GAP should be low.
either. When these sync with the server if we send back the same UID
for each one of these (an action which is undefined in the EAS spec),
there could now be multiple copies in the client's datastore that
connect with the same UID on the backend. What happens when a user
deletes one of these? Yup, the (only) copy of it on the server is
deleted. Less worrisome is that there would still be copies of it on
the client not attached to any server side copy. The state is now
corrupt. Even if the client doesn't exhibit the broken behavior yours
does of sending different clientids, it would still be possible for
the user to add the same contact data accidentally.
If anything is to be done here to mitigate this, I think we need to
totally rewrite the way incoming changes are handled so that we don't
actually process them until they are all read. We will use more memory
on the incoming request but we will be able to start sending packets
back to the client more quickly. I'm not sure I like this, as one of
the things that differentiates Horde's activesync implementation is
relatively low memory consumption per request and I have not been able
to find any protocol related documentation as to any incoming change
time limits. I think the use case of importing hundreds and hundreds
of new contacts FROM THE CLIENT is relatively rare.
New Attachment: horde-eas-synchack-1.patch
*any* response from the server before it closes the connection. It
doesn't matter what response we send if the client never sees it.
device and output from horde.
This is:
Device: Begin sending contacts
Device : Finish ADD contacts, waiting reply
GAP: Horde Begin adding contacts.
GAP: Horde Finish adding cotacts.
Horde: Begins sending replies (status).
...
If the GAP time is above 80 seconds (aprox.) Android timeouts and
close the connection *before* Horde begins sending replies. I have
tested other Android devices and this seems the behaviour in all
Android 4.1 versions. I need to test with 4.2 to see how this behave.
The issue is that Horde "buffers" the replies and send them all at a
time later. I have always assumed this is right because you need the
status for the whole Sync and you can not know this until all
additions are processed. So I think in this process time the timeout
occurs because device does not receive any packet from Horde.
If we reduce the process time, we reduce the "GAP" so this problem
does not arise.
By examplle If I use the uploaded patch (hack) it only process the
first 50 ADDs in the packet, this sortens the GAP to less than 1
minute and workarounds the timeout. With this patch (hack) Android
seems to work fine and sync all contacts with time.
we should return the existing item's UID as if the addition was
successful. Of course, I have no idea what your client will do with
this, since it is demonstrating broken behavior anyway, not to
mention if the connection continues to timeout, this won't help your
original problem anyway.
work, there are not additions so the GAP should be low.
it tries to upload them again and again and again... dups detected,
of course, but this is bad.
*any* response from the server before it closes the connection. It
doesn't matter what response we send if the client never sees it.
http://msdn.microsoft.com/en-us/library/gg675457%28v=exchg.80%29.aspx
===
7
synced by the client (the client knows the item's server-side UID)
that has changed on both the client and server.
What probably should happen is when a duplicate addition is detected
we should return the existing item's UID as if the addition was
successful. Of course, I have no idea what your client will do with
this, since it is demonstrating broken behavior anyway, not to mention
if the connection continues to timeout, this won't help your original
problem anyway. As I said before uploading hundreds of new messages
from the client to the server is NOT something the protocol was
originally designed to handle.
doesn't see any status reply for some items it behaves like if they
were not accepted by the server and try again.
make much sense here). From MS-ASCMD 2.2.3.7:
==
The server is not required to send an individual response for every
operation that is sent by the client. The client only receives
responses for successful additions and fetches, and failed changes and
deletions. When the client does not receive a response, the client
MUST assume that the operation succeeded unless informed otherwise.
==
So, no, the client should NOT resend an item if it does not receive
ANY status response. Of course, for client -> server additions the
behavior of any further actions would be undetermined since the client
would not know the server's UID. Rather, from what you told me
earlier, your client is resending the messages because it did not
receive ANY response before the connection was closed.
EAS protocol. Attempting to abuse some status code that should have
another meaning is nothing more that a hack to get around broken
client behavior.
2013-08-03T13:07:54+02:00 INFO: [15950]
Horde_Core_ActiveSync_Driver::changeMessage(@Contacts@, ...)
2013-08-03T13:07:54+02:00 ERR: Already Exists
However, when this happens the server doesn't reply anything for these
entries, no status is replied for them to client (Android).
Later, as the client device does not see any reply for these entries
it tries to upload them again and again and again... dups detected, of
course, but this is bad.
Looking at EAS docs maybe a Status 7 should be replied?
http://msdn.microsoft.com/en-us/library/gg675457%28v=exchg.80%29.aspx
===
7
Conflict matching the client and server object.
The client has changed an item for which the conflict policy indicates
that the server's changes take precedence.
Item
If it is necessary, inform the user that the change they made to the
item has been overwritten by a server change.
===
On the other hand, it seems interesting that if the Android device
doesn't see any status reply for some items it behaves like if they
were not accepted by the server and try again. Maybe this could be
used for pacing the client uploads.
Assigned to Michael Rubinsky
State ⇒ Resolved
prevent the duplicates from being added.
Still won't solve the timeout issue on the device, but there is
nothing Horde can do about that.
If matching is done with wildcards, two contacts like "Carlo" and
"Carlota" would match and could be considerated dups, when they are
not.
have entries in all the fields that would match in the same way, they
will not be detected as dups.
commit f52676bd1cc63ab80423038970628aa9f8321508
Author: Michael J Rubinsky <mrubinsk@horde.org>
Date: Fri Aug 2 13:49:41 2013 -0400
Add test for
Bug: 12506turba/test/Turba/Unit/Driver/Base.php | 13 +++++++++++++
1 files changed, 13 insertions(+), 0 deletions(-)
http://git.horde.org/horde-git/-/commit/f52676bd1cc63ab80423038970628aa9f8321508
commit 96886eea55280554292e2dcddf19cee288e314bd
Author: Michael J Rubinsky <mrubinsk@horde.org>
Date: Fri Aug 2 13:48:49 2013 -0400
Bug: 12506Fix detecting duplicate additions from EAS contactswith no email addresses.
turba/lib/Driver.php | 20 ++++++++++++--------
1 files changed, 12 insertions(+), 8 deletions(-)
http://git.horde.org/horde-git/-/commit/96886eea55280554292e2dcddf19cee288e314bd
If matching is done with wildcards, two contacts like "Carlo" and
"Carlota" would match and could be considerated dups, when they are not.
Why the wildcards there?
responses before timing out, but if it decides the sync is
unsuccessful, it should not regenerate those ids.
anything from Horde.
duplicates be added. There is code in Turba_Api::import() that is
supposed to reject entries that contain the exact same data (current
Git - Turba/lib/Api.php line 745. You can add some debug logging
there and compare the value of $content for each attempt.
The $content is something like this:
array(61) {
["name"]=>
string(6) "foo496"
["lastname"]=>
string(0) ""
["firstname"]=>
string(6) "foo496"
["middlenames"]=>
string(0) ""
["alias"]=>
string(0) ""
["nickname"]=>
string(0) ""
["namePrefix"]=>
string(0) ""
["nameSuffix"]=>
string(0) ""
["homeStreet"]=>
string(0) ""
["homeCity"]=>
string(0) ""
["homeProvince"]=>
string(0) ""
["homePostalCode"]=>
string(0) ""
["homeCountryFree"]=>
string(0) ""
["otherStreet"]=>
string(0) ""
["otherCity"]=>
string(0) ""
["otherProvince"]=>
string(0) ""
["otherPostalCode"]=>
string(0) ""
["otherCountryFree"]=>
string(0) ""
["workStreet"]=>
string(0) ""
["workCity"]=>
string(0) ""
["workProvince"]=>
string(0) ""
["workPostalCode"]=>
string(0) ""
["workCountryFree"]=>
string(0) ""
["title"]=>
string(0) ""
["company"]=>
string(0) ""
["department"]=>
string(0) ""
["office"]=>
string(0) ""
["spouse"]=>
string(0) ""
["website"]=>
string(0) ""
["assistant"]=>
string(0) ""
["manager"]=>
string(0) ""
["yomifirstname"]=>
string(0) ""
["yomilastname"]=>
string(0) ""
["imaddress"]=>
string(0) ""
["imaddress2"]=>
string(0) ""
["imaddress3"]=>
string(0) ""
["homePhone"]=>
string(11) "+3466666496"
["homePhone2"]=>
string(0) ""
["workPhone"]=>
string(0) ""
["workPhone2"]=>
string(0) ""
["fax"]=>
string(0) ""
["homeFax"]=>
string(0) ""
["pager"]=>
string(0) ""
["cellPhone"]=>
string(0) ""
["carPhone"]=>
string(0) ""
["assistPhone"]=>
string(0) ""
["companyPhone"]=>
string(0) ""
["radioPhone"]=>
string(0) ""
["notes"]=>
string(0) ""
["photo"]=>
string(0) ""
["emails"]=>
string(2) ",,"
["email"]=>
NULL
["homeEmail"]=>
NULL
["workEmail"]=>
NULL
["category"]=>
string(0) ""
["children"]=>
string(0) ""
["birthday"]=>
NULL
["anniversary"]=>
NULL
["homeCountry"]=>
NULL
["workCountry"]=>
NULL
["otherCountry"]=>
NULL
}
But the search returns 0. Why?
The complete SQL is:
SELECT object_id, owner_id, object_type, object_members, object_uid,
object_firstname, object_lastname, object_middlenames,
object_nameprefix, object_namesuffix, object_alias,
object_yomifirstname, object_yomilastname, object_bday,
object_anniversary, object_spouse, object_photo, object_phototype,
object_homestreet, object_homepob, object_homecity,
object_homeprovince, object_homepostalcode, object_homecountry,
object_workstreet, object_workpob, object_workcity,
object_workprovince, object_workpostalcode, object_workcountry,
object_otherstreet, object_otherpob, object_othercity,
object_otherprovince, object_otherpostalcode, object_othercountry,
object_department, object_manager, object_assistant, object_tz,
object_homeemail, object_homephone, object_homephone2,
object_homefax,
object_workphone, object_workphone2, object_cellphone,
object_carphone, object_radiophone, object_companyphone,
object_assistantphone, object_fax, object_pager, object_title,
object_role, object_company, object_logo, object_logotype,
object_category, object_notes, object_url, object_freebusyurl,
object_pgppublickey, object_smimepublickey, object_imaddress,
object_imaddress2, object_imaddress3, object_workemail FROM
turba_objects WHERE (owner_id = 'testas@nimastelecom.com' AND
((LOWER(object_nameprefix) LIKE LOWER('%foo73%') OR
LOWER(object_firstname) LIKE LOWER('%foo73%') OR
LOWER(object_middlenames) LIKE LOWER('%foo73%') OR
LOWER(object_lastname) LIKE LOWER('%foo73%') OR
LOWER(object_namesuffix) LIKE LOWER('%foo73%')) AND
LOWER(object_lastname) LIKE LOWER('%%') AND LOWER(object_firstname)
LIKE LOWER('%foo73%') AND LOWER(object_middlenames) LIKE LOWER('%%')
AND LOWER(object_alias) LIKE LOWER('%%') AND
LOWER(object_nameprefix)
LIKE LOWER('%%') AND LOWER(object_namesuffix) LIKE LOWER('%%') AND
LOWER(object_homestreet) LIKE LOWER('%%') AND LOWER(object_homecity)
LIKE LOWER('%%') AND LOWER(object_homeprovince) LIKE LOWER('%%') AND
LOWER(object_homepostalcode) LIKE LOWER('%%') AND
LOWER(object_otherstreet) LIKE LOWER('%%') AND
LOWER(object_othercity)
LIKE LOWER('%%') AND LOWER(object_otherprovince) LIKE
LOWER('%%') AND
LOWER(object_otherpostalcode) LIKE LOWER('%%') AND
LOWER(object_workstreet) LIKE LOWER('%%') AND LOWER(object_workcity)
LIKE LOWER('%%') AND LOWER(object_workprovince) LIKE LOWER('%%') AND
LOWER(object_workpostalcode) LIKE LOWER('%%') AND
LOWER(object_title)
LIKE LOWER('%%') AND LOWER(object_company) LIKE LOWER('%%') AND
LOWER(object_department) LIKE LOWER('%%') AND LOWER(object_spouse)
LIKE LOWER('%%') AND LOWER(object_url) LIKE LOWER('%%') AND
LOWER(object_assistant) LIKE LOWER('%%') AND LOWER(object_manager)
LIKE LOWER('%%') AND LOWER(object_yomifirstname) LIKE
LOWER('%%') AND
LOWER(object_yomilastname) LIKE LOWER('%%') AND
LOWER(object_imaddress) LIKE LOWER('%%') AND
LOWER(object_imaddress2)
LIKE LOWER('%%') AND LOWER(object_imaddress3) LIKE LOWER('%%') AND
LOWER(object_homephone) LIKE LOWER('%+346666673%') AND
LOWER(object_homephone2) LIKE LOWER('%%') AND
LOWER(object_workphone)
LIKE LOWER('%%') AND LOWER(object_workphone2) LIKE LOWER('%%') AND
LOWER(object_fax) LIKE LOWER('%%') AND LOWER(object_homefax) LIKE
LOWER('%%') AND LOWER(object_pager) LIKE LOWER('%%') AND
LOWER(object_cellphone) LIKE LOWER('%%') AND LOWER(object_carphone)
LIKE LOWER('%%') AND LOWER(object_assistantphone) LIKE
LOWER('%%') AND
LOWER(object_companyphone) LIKE LOWER('%%') AND
LOWER(object_radiophone) LIKE LOWER('%%') AND
LOWER(object_notes) LIKE
LOWER('%%') AND LOWER(object_homeemail) LIKE LOWER('%%') AND
LOWER(object_homeemail) LIKE LOWER('%%') AND LOWER(object_workemail)
LIKE LOWER('%%') AND LOWER(object_category) LIKE LOWER('%%') AND
LOWER(object_bday) LIKE LOWER('%%') AND
LOWER(object_anniversary) LIKE
LOWER('%%') AND LOWER(object_homecountry) LIKE LOWER('%%') AND
LOWER(object_workcountry) LIKE LOWER('%%') AND
LOWER(object_othercountry) LIKE LOWER('%%')));
Returns 0 because in the "LOWER(object_homeemail) LIKE LOWER('%%')",
this field is NULL in these contacts and NULL does not match in LIKE
wildcards.
Same for object_workemail.
These fields are mapped in my backend local.
$cfgSources['localsql']['map']['email'] = 'object_homeemail';
$cfgSources['localsql']['map']['homeEmail'] = 'object_homeemail';
$cfgSources['localsql']['map']['workEmail'] = 'object_workemail';
And are as type email in attributes.
blocking android device if we detect this problem or something.
Don't know how.
using the only bit of uniquely identifying data the client provides
with new entries - the ClientEntryId value. The client is supposed to
save this value until it receives a response from the server mapping a
server UID with the ClientEntryId. The problem in your case is that
your client is sending a *different* value for this field with each
attempt. This could be because the client is receiving *some* of the
responses before timing out, but if it decides the sync is
unsuccessful, it should not regenerate those ids.
What I don't understand yet though is why Turba is letting the
duplicates be added. There is code in Turba_Api::import() that is
supposed to reject entries that contain the exact same data (current
Git - Turba/lib/Api.php line 745. You can add some debug logging there
and compare the value of $content for each attempt.
accepting just 20 entries from the phone at a time.
I am not an ActiveSync expert, should this work or you must accept
the full sync?
to page incoming changes. All incoming requests must be handled, or an
explicit error code for the failure must be sent...and there is no
error code for "Too many messages sent". Simply ignoring the other
entries will cause the device to believe that they have been
successfully added when in fact they have not. This is per the EAS
specs. The reverse is not true - the client will only request a subset
of all server changes at a time.
1. With this timeout issue Android device thinks that contacts are
not uploaded and then tries to upload contacts again and again.
Just 1 android device managed to turn down my mysql in some hours with
hundreds of dups...
It is a real problem if we think that admins (we) can't control what
users do with their devices and this issue is rather trivial.
I think that something should be used to limit this problem somehow,
blocking android device if we detect this problem or something. Don't
know how.
2. About the real timeout issue, I was thinking about limiting and
accepting just 20 entries from the phone at a time.
I am not an ActiveSync expert, should this work or you must accept the
full sync?
I was looking into Horde Activesync code to do this but I am a total
newbie here.
State ⇒ Not A Bug
Priority ⇒ 1. Low
I have taken sniffer traces of the 500 contacts upload.
After waiting 80 seconds for answer from server (Horde), it sends a
FIN packet, connection is closed in Android side.
any control over when Android is going to decide it's taking too long.
As mentioned below, you should import this many contacts on the Turba
side first.
of the 500 contacts from Android to Turba, the Android SyncKey is
not updated from {51f5844b-ef0c-4b3a-937b-784b5570088c}2 to
{51f5844b-ef0c-4b3a-937b-784b5570088c}3.
The protocol is not really optimized/designed for importing that many
new items from the device to the server. It was originally designed to
be a mirror of an already existing Exchange account. As such, there is
no mechanism in place in the protocol to "page" changes from client ->
server as there is in the other direction.
E.g., if you were to import the 500 new contacts into Turba the
changes would be sent to the client in multiple requests, each
containing a small chunk of the changes (the exact number is client
dependent but usually ranges from 5 - 20).
2013-07-28T23:01:52+02:00 NOTICE: [30665] Error saving state for
synckey {51f5844b-ef0c-4b3a-937b-784b5570088c}3: QUERY FAILED:
Duplicate entry '{51f5844b-ef0c-4b3a-937b-784b5570088c}3' for key
'PRIMARY'
to Horde multiple times. It's an indicator that the device either did
not receive the entire response to the most recent request or it did
not accept the response for some reason.
in Horde 5.1.2 Turba 4.1.1
Client Device: Samsung Galaxy S2 i9100 Android ICS 4.1.2
In my tests I have generated a test.vcf file with 500 contacts
("foo1"-"foo500").
Attaching the ActiveSync debug log.
Horde sending contacts to the device. Then there are a whole bunch of
<REMOVE> commands sent to the device from horde. You should clear
your device completely, i.e., delete and recreate the activesync
account before testing this again.
New Attachment: capttimeout.pcap
I have taken sniffer traces of the 500 contacts upload.
After waiting 80 seconds for answer from server (Horde), it sends a
FIN packet, connection is closed in Android side.
Uploading sniffer traces of these packets.
New Attachment: new2.txt
seems related to volume contacts. Attaching new debug logs with 5
contacts.
Looking into both logs I see this:
In the 500 contacts log:
2013-07-28T22:54:05+02:00 DEBUG: [30637] I <SyncKey>
2013-07-28T22:54:05+02:00 DEBUG: [30637] I
{51f5844b-ef0c-4b3a-937b-784b5570088c}2
2013-07-28T22:54:05+02:00 DEBUG: [30637] I </SyncKey>
...
2013-07-28T22:59:01+02:00 DEBUG: [30637] I </Synchronize>
...
2013-07-28T22:59:10+02:00 DEBUG: [30637] O <SyncKey>
2013-07-28T22:59:10+02:00 DEBUG: [30637] O
{51f5844b-ef0c-4b3a-937b-784b5570088c}3
2013-07-28T22:59:10+02:00 DEBUG: [30637] O </SyncKey>
...
2013-07-28T23:01:36+02:00 DEBUG: [30665] SYNC request received for
user testas@nimastelecom.com
...
2013-07-28T23:01:37+02:00 DEBUG: [30665] I <Folder>
2013-07-28T23:01:37+02:00 DEBUG: [30665] I <SyncKey>
2013-07-28T23:01:37+02:00 DEBUG: [30665] I
{51f5844b-ef0c-4b3a-937b-784b5570088c}2
2013-07-28T23:01:37+02:00 DEBUG: [30665] I </SyncKey>
2013-07-28T23:01:37+02:00 DEBUG: [30665] I <FolderId>
2013-07-28T23:01:37+02:00 DEBUG: [30665] I @Contacts@
2013-07-28T23:01:37+02:00 DEBUG: [30665] I </FolderId>
2013-07-28T23:01:37+02:00 DEBUG: [30665] I <DeletesAsMoves />
2013-07-28T23:01:37+02:00 DEBUG: [30665] I <GetChanges />
2013-07-28T23:01:37+02:00 DEBUG: [30665] I <WindowSize>
2013-07-28T23:01:37+02:00 DEBUG: [30665] I 5
2013-07-28T23:01:37+02:00 DEBUG: [30665] I </WindowSize>
2013-07-28T23:01:37+02:00 DEBUG: [30665] I <Options>
2013-07-28T23:01:37+02:00 DEBUG: [30665] I <AirSyncBase:BodyPreference>
2013-07-28T23:01:37+02:00 DEBUG: [30665] I <AirSyncBase:Type>
2013-07-28T23:01:37+02:00 DEBUG: [30665] I 1
2013-07-28T23:01:37+02:00 DEBUG: [30665] I </AirSyncBase:Type>
2013-07-28T23:01:37+02:00 DEBUG: [30665] I <AirSyncBase:TruncationSize>
2013-07-28T23:01:37+02:00 DEBUG: [30665] I 400000
2013-07-28T23:01:37+02:00 DEBUG: [30665] I </AirSyncBase:TruncationSize>
2013-07-28T23:01:37+02:00 DEBUG: [30665] I </AirSyncBase:BodyPreference>
2013-07-28T23:01:37+02:00 DEBUG: [30665] I </Options>
2013-07-28T23:01:37+02:00 DEBUG: [30665] I </Folder>
In the 5 contacts log:
2013-07-29T12:20:07+02:00 DEBUG: [8841] I <SyncKey>
2013-07-29T12:20:07+02:00 DEBUG: [8841] I
{51f64171-3fc0-4f87-ba3b-22a55570088c}2
2013-07-29T12:20:07+02:00 DEBUG: [8841] I </SyncKey>
...
2013-07-29T12:20:11+02:00 DEBUG: [8841] I </Synchronize>
...
2013-07-29T12:20:12+02:00 DEBUG: [8841] O <SyncKey>
2013-07-29T12:20:12+02:00 DEBUG: [8841] O
{51f64171-3fc0-4f87-ba3b-22a55570088c}3
2013-07-29T12:20:12+02:00 DEBUG: [8841] O </SyncKey>
...
2013-07-29T12:20:13+02:00 DEBUG: [8841] SYNC request received for user
testas@nimastelecom.com
...
2013-07-29T12:20:13+02:00 DEBUG: [8841] I <Folder>
2013-07-29T12:20:13+02:00 DEBUG: [8841] I <SyncKey>
2013-07-29T12:20:13+02:00 DEBUG: [8841] I
{51f64171-3fc0-4f87-ba3b-22a55570088c}3
2013-07-29T12:20:13+02:00 DEBUG: [8841] I </SyncKey>
2013-07-29T12:20:13+02:00 DEBUG: [8841] I <FolderId>
2013-07-29T12:20:13+02:00 DEBUG: [8841] I @Contacts@
2013-07-29T12:20:13+02:00 DEBUG: [8841] I </FolderId>
2013-07-29T12:20:13+02:00 DEBUG: [8841] I <DeletesAsMoves />
2013-07-29T12:20:13+02:00 DEBUG: [8841] I <GetChanges />
2013-07-29T12:20:13+02:00 DEBUG: [8841] I <WindowSize>
2013-07-29T12:20:13+02:00 DEBUG: [8841] I 5
2013-07-29T12:20:13+02:00 DEBUG: [8841] I </WindowSize>
2013-07-29T12:20:13+02:00 DEBUG: [8841] I <Options>
2013-07-29T12:20:13+02:00 DEBUG: [8841] I <AirSyncBase:BodyPreference>
2013-07-29T12:20:13+02:00 DEBUG: [8841] I <AirSyncBase:Type>
2013-07-29T12:20:13+02:00 DEBUG: [8841] I 1
2013-07-29T12:20:13+02:00 DEBUG: [8841] I </AirSyncBase:Type>
2013-07-29T12:20:13+02:00 DEBUG: [8841] I <AirSyncBase:TruncationSize>
2013-07-29T12:20:13+02:00 DEBUG: [8841] I 400000
2013-07-29T12:20:13+02:00 DEBUG: [8841] I </AirSyncBase:TruncationSize>
2013-07-29T12:20:13+02:00 DEBUG: [8841] I </AirSyncBase:BodyPreference>
2013-07-29T12:20:13+02:00 DEBUG: [8841] I </Options>
2013-07-29T12:20:13+02:00 DEBUG: [8841] I </Folder>
So, it seems that in the 500 contacts log, after the initial upload of
the 500 contacts from Android to Turba, the Android SyncKey is not
updated from {51f5844b-ef0c-4b3a-937b-784b5570088c}2 to
{51f5844b-ef0c-4b3a-937b-784b5570088c}3.
However in the 5 contacts log, the synckey in Android gets updated
without problem.
Maybe some timeout issue??
In the 500 contacts case it gets more than 5 minutes to upload for 5
seconds in the 5 contacts case.
I am trying to activate debug logs in Android client, but not sure how
to do it.
In the other hand, Horde/Turba should handle this problem somehow.
Right now it generates an error because backend is mysql and little
more. It seems that Android device tries to upload and upload and
upload the contacts again and again after some time leading to
thousand of duplicated contacts in Turba.
2013-07-28T23:01:52+02:00 NOTICE: [30665] Error saving state for
synckey {51f5844b-ef0c-4b3a-937b-784b5570088c}3: QUERY FAILED:
Duplicate entry '{51f5844b-ef0c-4b3a-937b-784b5570088c}3' for key
'PRIMARY'
New Attachment: test.vcf
State ⇒ Unconfirmed
Priority ⇒ 2. Medium
Type ⇒ Bug
Summary ⇒ Contacts sync with ActiveSync get duplicates and not sync
Queue ⇒ Synchronization
Milestone ⇒
Patch ⇒ No
New Attachment: SAMSUNG1359090042570562.zip
Horde 5.1.2 Turba 4.1.1
Client Device: Samsung Galaxy S2 i9100 Android ICS 4.1.2
In my tests I have generated a test.vcf file with 500 contacts
("foo1"-"foo500").
Attaching the ActiveSync debug log.
Steps:
1. Sync the device with empty contacts with Horde.
2. Import vcf file in device in ActiveSync account. -> Around
2013-07-28T22:53:33+02:00 in the debug log.
3. Device is synced (upload contact to Horde is ok).
4. Through Turba (web) I deleted contacts "foo102"-"foo105". ->
Around 2013-07-28T23:01:17+02:00 in the debug log.
5. Device is not synced, contacs still appears in the device.
6. Device start "sync now". -> Around 2013-07-28T23:04:47+02:00 in the
debug log.
7. All contacts get duplicated in Turba. All contacts appears twice
but the deleted ones that only have 1 entry each.
Contacts in device are NOT duplicated, all contacts appears in
the device, including the deleted ones.