| Summary | Error saving state for synckey { <somekey>: SQLSTATE[23000]: Integrity constraint violation: 1062 Duplicate entry |
| Queue | Synchronization |
| Queue Version | Git master |
| Type | Bug |
| State | Not A Bug |
| Priority | 1. Low |
| Owners | |
| Requester | jmozdzen (at) nde (dot) ag |
| Created | 11/23/2012 (4608 days ago) |
| Due | |
| Updated | 11/23/2012 (4608 days ago) |
| Assigned | |
| Resolved | 11/23/2012 (4608 days ago) |
| Github Issue Link | |
| Github Pull Request | |
| Milestone | |
| Patch | No |
once I manually deleted the preference folder in the IMAP store (might
even date back to Horde V1) and started over, sync works like a charm.
Case closed.
State ⇒ Unconfirmed
Priority ⇒ 1. Low
Type ⇒ Bug
Summary ⇒ Error saving state for synckey { <somekey>: SQLSTATE[23000]: Integrity constraint violation: 1062 Duplicate entry
Queue ⇒ Synchronization
Milestone ⇒
Patch ⇒ No
number of tries during the last few days.
I'm trying to add my WebOS phone to Horde5. The first attempt seemed
to go well, a calendar change on the phone found its way to Horde5's
calendar. But not the other way around.
I've tried a few things and found out how to debug ActiveSync, where I
detected an error message that seems to explain why no updates can be
seen nomore.
Test setup:
- I remove the ActiveSync account from the mobile device
- I shutdown the mobile device
- I remove all traces of the device via Horde5 web UI ("ActiveSync devices")
- I checked via MySQL that all activesync_* tables are empty (except
for _schema ;) )
- I restart the web server running Horde5
- I remove the old ActiveSync debug log file
- settings in conf.php:
$conf['activesync']['emailsync'] = true;
$conf['activesync']['version'] = '2.5'; // WIKI page has a report of a
WebOS device working
$conf['activesync']['autodiscovery'] = 'full';
$conf['activesync']['logging']['path'] = '/tmp/horde5/activesync';
$conf['activesync']['logging']['type'] = 'custom';
$conf['activesync']['ping']['heartbeatmin'] = 60;
$conf['activesync']['ping']['heartbeatmax'] = 2700;
$conf['activesync']['ping']['heartbeatdefault'] = 480;
$conf['activesync']['ping']['deviceping'] = true;
$conf['activesync']['ping']['waitinterval'] = 5;
$conf['activesync']['enabled'] = true;
- I power up the mobile device and create a "Microsoft Exchange"
account, selecting all elements to be synced (mail, calendar,...)
- sync starts automatically on the mobile device
- a trace file for the device is created
- some (but not all) emails appear on the device
- no calendar entries appear on the device
Scanning through the device trace file shows proper log in and sync
progress, including transfer of emails. It seems some sort of "sync
points" are maintained ({sync_key}n, with n = 1, 2, ...), I see the
following messages:
webserver:/tmp/horde5/activesync # egrep -ie "old SYNCKEY|SQLSTATE"
PALM71e4c550ad065147ed43363abfd7.txt |more
2012-11-23T15:24:10+00:00 DEBUG: Old SYNCKEY: 0, New SYNCKEY:
{50af951a-7688-43b7-bc3a-121ac0a86742}1
2012-11-23T15:24:10+00:00 DEBUG: Old SYNCKEY: 0, New SYNCKEY:
{50af951a-96c4-4c40-a7ab-120bc0a86742}1
2012-11-23T15:24:10+00:00 DEBUG: Old SYNCKEY: 0, New SYNCKEY:
{50af951a-6a7c-431a-a54a-1209c0a86742}1
2012-11-23T15:24:10+00:00 DEBUG: Old SYNCKEY: 0, New SYNCKEY:
{50af951a-901c-48df-8a1f-120cc0a86742}1
2012-11-23T15:24:10+00:00 DEBUG: Old SYNCKEY: 0, New SYNCKEY:
{50af951a-5dd0-4a0c-8e3d-121bc0a86742}1
2012-11-23T16:24:15+01:00 DEBUG: Old SYNCKEY:
{50af951a-901c-48df-8a1f-120cc0a86742}1, New SYNCKEY:
{50af951a-901c-48df-8a1f-120cc0a86742}2
2012-11-23T15:24:15+00:00 DEBUG: Old SYNCKEY:
{50af951a-7688-43b7-bc3a-121ac0a86742}1, New SYNCKEY:
{50af951a-7688-43b7-bc3a-121ac0a86742}2
2012-11-23T15:24:16+00:00 DEBUG: Old SYNCKEY:
{50af951a-5dd0-4a0c-8e3d-121bc0a86742}1, New SYNCKEY:
{50af951a-5dd0-4a0c-8e3d-121bc0a86742}2
2012-11-23T16:24:18+01:00 DEBUG: Old SYNCKEY:
{50af951a-96c4-4c40-a7ab-120bc0a86742}1, New SYNCKEY:
{50af951a-96c4-4c40-a7ab-120bc0a86742}2
2012-11-23T15:24:27+00:00 DEBUG: Old SYNCKEY:
{50af951a-5dd0-4a0c-8e3d-121bc0a86742}2, New SYNCKEY:
{50af951a-5dd0-4a0c-8e3d-121bc0a86742}3
2012-11-23T15:24:27+00:00 DEBUG: Old SYNCKEY:
{50af951a-5dd0-4a0c-8e3d-121bc0a86742}2, New SYNCKEY:
{50af951a-5dd0-4a0c-8e3d-121bc0a86742}3
2012-11-23T15:24:27+00:00 NOTICE: [4618] Error saving state for
synckey {50af951a-5dd0-4a0c-8e3d-121bc0a86742}3: SQLSTATE[23000]:
Integrity constraint violation: 1062 Duplicate entry
'{50af951a-5dd0-4a0c-8e3d-121bc0a86742}3' for key 1 - removing
previous sync state and t
rying again.
2012-11-23T15:24:27+00:00 DEBUG: Old SYNCKEY:
{50af951a-5dd0-4a0c-8e3d-121bc0a86742}2, New SYNCKEY:
{50af951a-5dd0-4a0c-8e3d-121bc0a86742}3
2012-11-23T15:24:27+00:00 DEBUG: Old SYNCKEY:
{50af951a-5dd0-4a0c-8e3d-121bc0a86742}2, New SYNCKEY:
{50af951a-5dd0-4a0c-8e3d-121bc0a86742}3
2012-11-23T15:24:27+00:00 DEBUG: Old SYNCKEY:
{50af951a-5dd0-4a0c-8e3d-121bc0a86742}2, New SYNCKEY:
{50af951a-5dd0-4a0c-8e3d-121bc0a86742}3
2012-11-23T15:24:27+00:00 DEBUG: Old SYNCKEY:
{50af951a-5dd0-4a0c-8e3d-121bc0a86742}2, New SYNCKEY:
{50af951a-5dd0-4a0c-8e3d-121bc0a86742}3
2012-11-23T15:24:27+00:00 DEBUG: Old SYNCKEY:
{50af951a-5dd0-4a0c-8e3d-121bc0a86742}2, New SYNCKEY:
{50af951a-5dd0-4a0c-8e3d-121bc0a86742}3
2012-11-23T15:24:27+00:00 NOTICE: [4634] Error saving state for
synckey {50af951a-5dd0-4a0c-8e3d-121bc0a86742}3: SQLSTATE[23000]:
Integrity constraint violation: 1062 Duplicate entry
'{50af951a-5dd0-4a0c-8e3d-121bc0a86742}3' for key 1 - removing
previous sync state and t
rying again.
2012-11-23T15:24:27+00:00 NOTICE: [4631] Error saving state for
synckey {50af951a-5dd0-4a0c-8e3d-121bc0a86742}3: SQLSTATE[23000]:
Integrity constraint violation: 1062 Duplicate entry
'{50af951a-5dd0-4a0c-8e3d-121bc0a86742}3' for key 1 - removing
previous sync state and t
rying again.
2012-11-23T15:24:27+00:00 NOTICE: [4620] Error saving state for
synckey {50af951a-5dd0-4a0c-8e3d-121bc0a86742}3: SQLSTATE[23000]:
Integrity constraint violation: 1062 Duplicate entry
'{50af951a-5dd0-4a0c-8e3d-121bc0a86742}3' for key 1 - removing
previous sync state and t
rying again.
2012-11-23T15:24:27+00:00 DEBUG: Old SYNCKEY:
{50af951a-5dd0-4a0c-8e3d-121bc0a86742}2, New SYNCKEY:
{50af951a-5dd0-4a0c-8e3d-121bc0a86742}3
2012-11-23T15:24:27+00:00 NOTICE: [4633] Error saving state for
synckey {50af951a-5dd0-4a0c-8e3d-121bc0a86742}3: SQLSTATE[23000]:
Integrity constraint violation: 1062 Duplicate entry
'{50af951a-5dd0-4a0c-8e3d-121bc0a86742}3' for key 1 - removing
previous sync state and t
rying again.
2012-11-23T15:24:28+00:00 ERR: SQLSTATE[23000]: Integrity constraint
violation: 1062 Duplicate entry
'{50af951a-5dd0-4a0c-8e3d-121bc0a86742}3' for key 1
2012-11-23T15:24:28+00:00 NOTICE: [4617] Error saving state for
synckey {50af951a-5dd0-4a0c-8e3d-121bc0a86742}3: SQLSTATE[23000]:
Integrity constraint violation: 1062 Duplicate entry
'{50af951a-5dd0-4a0c-8e3d-121bc0a86742}3' for key 1 - removing
previous sync state and t
rying again.
2012-11-23T15:24:28+00:00 DEBUG: Old SYNCKEY:
{50af951a-5dd0-4a0c-8e3d-121bc0a86742}2, New SYNCKEY:
{50af951a-5dd0-4a0c-8e3d-121bc0a86742}3
2012-11-23T15:24:28+00:00 DEBUG: Old SYNCKEY:
{50af951a-5dd0-4a0c-8e3d-121bc0a86742}2, New SYNCKEY:
{50af951a-5dd0-4a0c-8e3d-121bc0a86742}3
(and more of this)
First of all, the time stamps are mixed (some logged with offset, some
with not). Secondly, at "2012-11-23T15:24:27+00:00" there are
*multiple synchronous" requests to update from {}2 to {}3, which fails
with an SQL error (primary index constraint violation, AFAICT). From
then on, it's always tried to go from 2 to 3, which fails, roll-back
to 2, and that's probably why no more updates get through to the device.
As I'm new to all this - is it really a concurrent update problem,
probably caused by the device (requesting syncs in parallel from
multiple applications or alike), or am I barking up the wrong tree and
should look for some other traces in the debug file?
Regards,
Jens