6.0.0-git
2019-03-23

[#13038] Error saving state for synckey - no Inbox synchronization
Summary Error saving state for synckey - no Inbox synchronization
Queue Synchronization
Queue Version Git master
Type Bug
State Resolved
Priority 1. Low
Owners mrubinsk (at) horde (dot) org
Requester samuel.wolf (at) wolf-maschinenbau (dot) de
Created 2014-03-12 (1837 days ago)
Due
Updated 2014-03-24 (1825 days ago)
Assigned 2014-03-13 (1836 days ago)
Resolved 2014-03-24 (1825 days ago)
Milestone
Patch No

History
2014-03-24 22:16:25 Michael Rubinsky Comment #27
State ⇒ Resolved
Reply to this comment
Horde_ActiveSync-2.13.3 is out.

Sorry for the recent issues all....
2014-03-24 22:08:43 arjen+horde (at) de-korte (dot) org Comment #26 Reply to this comment
OK, I see now what you are saying.  Is there a fix being contemplated/needed?
See http://bugs.horde.org/ticket/13052#c6
2014-03-24 22:08:03 Michael Rubinsky Comment #25 Reply to this comment
Running a last "the new release doesn't blow up my computer" test as we speak.
2014-03-24 21:59:38 skaman (dot) tx (at) gmail (dot) com Comment #24 Reply to this comment

[Show Quoted Text - 38 lines]
OK, I see now what you are saying.  Is there a fix being contemplated/needed?

2014-03-24 21:55:28 Michael Rubinsky Comment #23 Reply to this comment
Hmmm, then why is the same device using EAS 14.1 and now syncing 
just fine under ActiveSync v2.13.2?  Recall from my previous post 
that once I downgraded to 2.12.4, then manuall sync'd the device, 
then upgraded to 2.13.2, the device works just fine.  Doesn't seem 
right somehow.
If the device was paired while running 2.12.4 (and therefore 
negotiated EAS version 12.x), it will continue to work under that 
version until it is told otherwise.
2014-03-24 21:54:57 arjen+horde (at) de-korte (dot) org Comment #22 Reply to this comment

[Show Quoted Text - 29 lines]
The device isn't using EAS 12.1, Horde is using EAS 14.1. This will 
work as long as Horde is not using something that wasn't available in 
EAS 12.1. But as soon as it does, synchronization will break again.
  Recall from my previous post that once I downgraded to 2.12.4, then 
manuall sync'd the device, then upgraded to 2.13.2, the device works 
just fine.  Doesn't seem right somehow.
2014-03-24 21:49:09 skaman (dot) tx (at) gmail (dot) com Comment #21 Reply to this comment

[Show Quoted Text - 26 lines]
Hmmm, then why is the same device using EAS 14.1 and now syncing just 
fine under ActiveSync v2.13.2?  Recall from my previous post that once 
I downgraded to 2.12.4, then manuall sync'd the device, then upgraded 
to 2.13.2, the device works just fine.  Doesn't seem right somehow.

2014-03-24 21:37:06 arjen+horde (at) de-korte (dot) org Comment #20 Reply to this comment

[Show Quoted Text - 17 lines]
The device uses EAS 12.1 and therefor will not work with the 
Horde_ActiveSync-2.13.2. So yes, if you revert this commit, it will 
most likely work if it worked with Horde_ActiveSync-2.12.4.
The 2.13.2 entry shows the following:

Request being handled for device: ANDROIDC135954261, Supporting 
protocol version: 14.1, Using Horde_ActiveSync v2.13.2
2014-03-24 21:32:59 skaman (dot) tx (at) gmail (dot) com Comment #19 Reply to this comment

[Show Quoted Text - 11 lines]
The log file I posted contains entries while running under 2.13.2 and 
2.12.4.  The 2.12.4 entry shows the following:

equest being handled for device: ANDROIDC135954261, Supporting 
protocol version: 12.1, Using Horde_ActiveSync v2.12.4

The 2.13.2 entry shows the following:

Request being handled for device: ANDROIDC135954261, Supporting 
protocol version: 14.1, Using Horde_ActiveSync v2.13.2

2014-03-24 21:27:08 Michael Rubinsky Comment #18 Reply to this comment
See attached log.  Includes error when running 2.13.2 and proper 
sync once downgraded to 2.12.4.  Note that once I downgraded to 
2.12.4 and synced the email accounts on the device manually, then 
upgraded to 2.13.2, the device sync'd just fine.  However, since I 
don't have control over my email users devices, I'm downgrading back 
to 2.12.4 since I know it "just works."
I'm not familiar with the Moto X, but since it's a fairly recent 
device I would imagine it uses EAS 14.1? Can you look at your logs 
when using 2.12.4 and see what the initial log entry says about the 
EAS version in  use?
2014-03-24 21:24:41 Michael Rubinsky Comment #17 Reply to this comment
Hard to say, as your log doesn't really show any thing to indicate an 
error. If this is an older device that can only talk a version less 
than 14.1, then it will likely help.
2014-03-24 13:10:11 samuel (dot) wolf (at) wolf-maschinenbau (dot) de Comment #16 Reply to this comment
http://article.gmane.org/gmane.comp.horde.user/34712

Maybe this fix my issue as well?
2014-03-15 08:23:26 samuel (dot) wolf (at) wolf-maschinenbau (dot) de Comment #15 Reply to this comment
This line number only contains a [] operator in version 2.12.4. Do 
you see any errors when running it under the current version?
You're right, this errors happens only with 2.12.4, not with 2.13.2.
Send you today my debug log by mail.
2014-03-13 17:02:29 skaman (dot) tx (at) gmail (dot) com Comment #14 Reply to this comment
See attached log.  Includes error when running 2.13.2 and proper 
sync once downgraded to 2.12.4.  Note that once I downgraded to 
2.12.4 and synced the email accounts on the device manually, then 
upgraded to 2.13.2, the device sync'd just fine.  However, since I 
don't have control over my email users devices, I'm downgrading back 
to 2.12.4 since I know it "just works."
Perhaps you can delete the attachment from the ticket once you've 
grabbed it as well.
2014-03-13 16:46:30 skaman (dot) tx (at) gmail (dot) com Comment #13
New Attachment: ANDROIDC135954261.zip Download
Reply to this comment
See attached log.  Includes error when running 2.13.2 and proper sync 
once downgraded to 2.12.4.  Note that once I downgraded to 2.12.4 and 
synced the email accounts on the device manually, then upgraded to 
2.13.2, the device sync'd just fine.  However, since I don't have 
control over my email users devices, I'm downgrading back to 2.12.4 
since I know it "just works."
2014-03-13 16:27:45 Michael Rubinsky Comment #12 Reply to this comment
I'm going to need a full synclog to see where this is failing.
2014-03-13 15:52:55 skaman (dot) tx (at) gmail (dot) com Comment #11 Reply to this comment
I can confirm that ActiveSync-2.13.1 and ActiveSync-2.13.2 do break 
sync on Android MOTO1080X.  Still works on Nexus 7 gen. 2.  Downgrade 
to ActiveSync-2.12.4 and all is working again on MOTO1080X.

2014-03-13 14:45:33 samuel (dot) wolf (at) wolf-maschinenbau (dot) de Comment #10 Reply to this comment
Work for some mails now and stop again:
2014-03-13T14:41:03+00:00 NOTICE: [4077] Error saving state for 
synckey {5320712f-xxxx-xxxx-xxxx-xxxxxxxxxxxx}42: QUERY FAILED: 
Duplicate entry '{5320712f-xxxx-xxxx-xxxx-xxxxxxxxxxxx}42' for key 
'PRIMARY' INSERT INTO horde_activesync_state (sync_key, sync_data, 
sync_devid, sync_mod, sync_folderid, sync_user, sync_pending, 
sync_timestamp) VALUES [...]
Is it a way to delete all AS database entries for my user, if yes which?
2014-03-13 13:50:44 Michael Rubinsky Comment #9 Reply to this comment
You mean this error was from 2.12.4?
Yes.
Watch it now for some hours and give you a feedback.
Maybe this fix my issue as well?
https://github.com/horde/horde/commit/1288a7436ba2d95159814f04e3c69264d5fa319e
Possible. It would have caused a bunch of old processes to hang around 
for a while, possibly corrupting some state.
2014-03-13 05:24:54 samuel (dot) wolf (at) wolf-maschinenbau (dot) de Comment #8 Reply to this comment
This line number only contains a [] operator in version 2.12.4. Do 
you see any errors when running it under the current version?
You mean this error was from 2.12.4? Possible and I do not noticed 
when i am testing between 2.12.4 and 2.13.1. Anyway, at the moment I 
do not see any errors after update to Horde_ActiveSync-2.13.2.
Watch it now for some hours and give you a feedback.

Maybe this fix my issue as well?
https://github.com/horde/horde/commit/1288a7436ba2d95159814f04e3c69264d5fa319e
2014-03-13 04:47:03 Michael Rubinsky State ⇒ Feedback
 
2014-03-13 04:46:52 Michael Rubinsky Comment #7 Reply to this comment
[Wed Mar 12 05:29:28 2014] [error] [client 93.201.xx.xx] PHP Fatal
error:  [] operator not supported for strings in
/usr/share/php/Horde/ActiveSync/Folder/Imap.php on line 222

This line number only contains a [] operator in version 2.12.4. Do you 
see any errors when running it under the current version?
2014-03-12 14:52:31 Michael Rubinsky Comment #6
Assigned to Michael Rubinsky
State ⇒ Assigned
Reply to this comment
Probably related to adding sequence string storage:

https://github.com/horde/horde/commit/8bc8f6433f808c5761bee3d609d230daf4281f23

Will take a look as soon as I'm able.
2014-03-12 11:47:49 samuel (dot) wolf (at) wolf-maschinenbau (dot) de Comment #5 Reply to this comment
Did you try to resynchronize devices? That's when the problems 
started for me. When a device is already synchronized, upgrading to 
Horde_ActiveSync-2.13.1 doesn't seem to break existing 
(synchronized) accounts. But as soon as a device is resynchronized, 
problems start.
I have tried:
* reset the device in horde
* delete the device in horde
* remove the as account on the smartphone and delete it in horde
* downgrade to Horde_ActiveSync-2.12.4, restore database (2.12.4), 
sync device and upgrade direct to Horde_ActiveSync-2.13.1 same problem

2014-03-12 11:38:05 arjen+horde (at) de-korte (dot) org Comment #4 Reply to this comment
Did you try to resynchronize devices? That's when the problems started 
for me. When a device is already synchronized, upgrading to 
Horde_ActiveSync-2.13.1 doesn't seem to break existing (synchronized) 
accounts. But as soon as a device is resynchronized, problems start.


2014-03-12 11:23:19 samuel (dot) wolf (at) wolf-maschinenbau (dot) de Comment #3 Reply to this comment
I see the same behavior here, but with a different mailbox. My guess 
is that you have a fair number of message in you Inbox, since here 
the mailbox that loses synchronization is the one with the most 
messages in it (over 500 messages).
I move all messages into a other folder, only one message is in the 
inbox, same problem.
At the moment only on device is affected, the other work as expected.

2014-03-12 10:57:51 arjen+horde (at) de-korte (dot) org Comment #2 Reply to this comment
My Android 4.1.2 device stop synchronize my mail Inbox with 
Horde_ActiveSync-2.13.1, other Mailfolders work fine. Reset the 
device does not help.
I see the same behavior here, but with a different mailbox. My guess 
is that you have a fair number of message in you Inbox, since here the 
mailbox that loses synchronization is the one with the most messages 
in it (over 500 messages).

It may or may not have something to do with this, but synchronization 
of the calendar also failed when resynchronizing the device. 
Downgrading to Horde_ActiveSync-2.12.4 resolved both the mailbox and 
calendar synchronization issues.
2014-03-12 08:59:50 samuel (dot) wolf (at) wolf-maschinenbau (dot) de Comment #1
Type ⇒ Bug
State ⇒ Unconfirmed
Priority ⇒ 1. Low
Summary ⇒ Error saving state for synckey - no Inbox synchronization
Queue ⇒ Synchronization
Milestone ⇒
Patch ⇒ No
Reply to this comment
My Android 4.1.2 device stop synchronize my mail Inbox with 
Horde_ActiveSync-2.13.1, other Mailfolders work fine. Reset the device 
does not help.

Horde Log:
2014-03-12T04:14:53+00:00 INFO: [25603] Updating state during change
2014-03-12T04:14:53+00:00 DEBUG: [25603] O     </Commands>
2014-03-12T04:14:53+00:00 INFO: [25603] Saving state: 
a:8:{i:0;s:39:"{531fddad-xxxx-xxxx-xxxx-xxxxxxxxxxxx}5";i:1;O:21:"Horde_Db_Value_Binary":1:{s:5:"value";s:206:"C:28:"Horde_ActiveSync_Folder_Imap":164:{{"s":{"messages":"1","uidnext":"5378","uidvalidity":"1342278888","highestmodseq":"12679"},"m":"5377","f":"INBOX","c":"Email","lsd":1393992593,"sd":1394597393,"v":2}}";}i:2;s:17:"ANDROID1xxxx";i:3;i:1394597693;i:4;s:9:"F3ef80eea";i:5;s:6:"samuel";i:6;i:0;i:7;i:1394597693;}
2014-03-12T04:14:53+00:00 NOTICE: [25603] Error saving state for 
synckey {531fddad-xxxx-xxxx-xxxx-xxxxxxxxxxxx}5: QUERY FAILED: 
Duplicate entry '{531fddad-xxxx-xxxx-xxxx-xxxxxxxxxxxx}5' for key 
'PRIMARY'

INSERT INTO horde_activesync_state (sync_key, sync_data, sync_devid, 
sync_mod, sync_folderid, sync_user, sync_pending, sync_timestamp) 
VALUES ('{531fddad-xxxx-xxxx-xxxx-xxxxxxxxxxxx}5', 
'C:28:"Horde_ActiveSync_Folder_Imap":164:{{"s":{"messages":"1","uidnext":"5378","uidvalidity":"1342278888","highestmodseq":"12679"},"m":"5377","f":"INBOX","c":"Email","lsd":1393992593,"sd":1394597393,"v":2}}', 'ANDROID1xxxx', 1394597693, 'F3ef80eea', 'samuel', 'a:0:{}', 1394597693) - removing previous sync state and trying 
again.
2014-03-12T04:14:53+00:00 DEBUG: [25603] O    </Folder>
2014-03-12T04:14:53+00:00 DEBUG: [25603] O   </Folders>
2014-03-12T04:14:53+00:00 DEBUG: [25603] O  </Synchronize>

Found some errors in the apache log:
[Wed Mar 12 05:29:28 2014] [error] [client 93.201.xx.xx] PHP Fatal 
error:  [] operator not supported for strings in 
/usr/share/php/Horde/ActiveSync/Folder/Imap.php on line 222
[Wed Mar 12 05:29:28 2014] [error] [client 93.201.xx.xx] PHP Stack trace:
[Wed Mar 12 05:29:28 2014] [error] [client 93.201.xx.xx] PHP   1. 
{main}() /var/www/https/horde/rpc.php:0
[Wed Mar 12 05:29:28 2014] [error] [client 93.201.xx.xx] PHP   2. 
Horde_Rpc_ActiveSync->getResponse() /var/www/https/horde/rpc.php:156
[Wed Mar 12 05:29:28 2014] [error] [client 93.201.xx.xx] PHP   3. 
Horde_ActiveSync->handleRequest() 
/usr/share/php/Horde/Rpc/ActiveSync.php:143
[Wed Mar 12 05:29:28 2014] [error] [client 93.201.xx.xx] PHP   4. 
Horde_ActiveSync_Request_Base->handle() 
/usr/share/php/Horde/ActiveSync.php:897
[Wed Mar 12 05:29:28 2014] [error] [client 93.201.xx.xx] PHP   5. 
Horde_ActiveSync_Request_Sync->_handle() 
/usr/share/php/Horde/ActiveSync/Request/Base.php:249
[Wed Mar 12 05:29:28 2014] [error] [client 93.201.xx.xx] PHP   6. 
Horde_ActiveSync_Collections->getCollectionChangeCount() 
/usr/share/php/Horde/ActiveSync/Request/Sync.php:399
[Wed Mar 12 05:29:28 2014] [error] [client 93.201.xx.xx] PHP   7. 
Horde_ActiveSync_Collections->getCollectionChanges() 
/usr/share/php/Horde/ActiveSync/Collections.php:1216
[Wed Mar 12 05:29:28 2014] [error] [client 93.201.xx.xx] PHP   8. 
Horde_ActiveSync_State_Base->getChanges() 
/usr/share/php/Horde/ActiveSync/Collections.php:1180
[Wed Mar 12 05:29:28 2014] [error] [client 93.201.xx.xx] PHP   9. 
Horde_ActiveSync_Folder_Imap->updateState() 
/usr/share/php/Horde/ActiveSync/State/Base.php:445

Downgrade to Horde_ActiveSync-2.12.4 help.
php5 5.4.4-14+deb7u8
Horde_Mime                2.3.0   stable
Horde_Imap_Client         2.19.0  stable


Saved Queries