Tickets :: [#13010] Activesync on WP7.8 deleted messages reappear

6.0.0-beta1

7/5/25

Summary	Activesync on WP7.8 deleted messages reappear
Queue	Synchronization
Queue Version	Git master
Type	Bug
State	Resolved
Priority	1. Low
Owners	mrubinsk (at) horde (dot) org
Requester	spamstop2 (at) terriertech (dot) com
Created	03/05/2014 (4140 days ago)
Due
Updated	03/06/2014 (4139 days ago)
Assigned	03/05/2014 (4140 days ago)
Resolved	03/06/2014 (4139 days ago)
Github Issue Link
Github Pull Request
Milestone
Patch	Yes

03/06/2014 05:20:24 AM	Michael Rubinsky	Comment #11 State ⇒ Resolved	Reply to this comment
Horde_Imap_Client-2.19.0 and Horde_ActiveSync-2.13.0

03/06/2014 05:18:56 AM	Git Commit	Comment #10	Reply to this comment
Changes have been made in Git (master): commit ceb9df1d0b402abd8299f3a9493cdbcc99734486 Author: Michael J Rubinsky <mrubinsk@horde.org> Date: Thu Mar 6 00:13:05 2014 -0500 ~~Bug: 13010~~ Return accurate message uids after move regardless of UIDPLUS status. .../lib/Horde/ActiveSync/Imap/Adapter.php \| 26 ++----------------- 1 files changed, 3 insertions(+), 23 deletions(-) http://git.horde.org/horde-git/-/commit/ceb9df1d0b402abd8299f3a9493cdbcc99734486

03/05/2014 07:39:48 PM	Git Commit	Comment #9	Reply to this comment
Changes have been made in Git (master): commit 0d66d4551dd946fb1068698b949e41fc8c85150d Author: Michael M Slusarz <slusarz@horde.org> Date: Wed Mar 5 12:22:03 2014 -0700 [mms] Add 'force_map' option to Horde_Imap_Client_Base#copy() to guarantee that the mapping array is always returned. See ~~Bug #13010~~ .../Imap_Client/doc/Horde/Imap/Client/UPGRADING \| 10 +++++++ .../Imap_Client/lib/Horde/Imap/Client/Base.php \| 27 +++++++++++++++++-- framework/Imap_Client/package.xml \| 10 ++++--- .../Horde/Imap/Client/RemoteImapServerTest.php \| 22 ++++++++++------ 4 files changed, 54 insertions(+), 15 deletions(-) http://git.horde.org/horde-git/-/commit/0d66d4551dd946fb1068698b949e41fc8c85150d

03/05/2014 06:30:28 PM	Michael Rubinsky	Comment #8	Reply to this comment
The code to do this already exists in append() (where we automatically workaround the lack of UIDPLUS), so this should not be difficult. Ok. I'll take a look at it then, thanks.

03/05/2014 06:27:48 PM	Michael Slusarz	Comment #7	Reply to this comment
The best solution will be to remove all UIDPLUS code from ActiveSync and instead add an option to Horde_Imap_Client_Base#copy() that guarantees a return of old -> new UIDs list even if the server does not automatically provide that information. I leave that one up to you and will adjust the code in the ActiveSync library when it's available. The code to do this already exists in append() (where we automatically workaround the lack of UIDPLUS), so this should not be difficult.

03/05/2014 02:19:35 PM	Michael Rubinsky	Comment #6 Assigned to Michael Rubinsky State ⇒ Assigned	Reply to this comment
The best solution will be to remove all UIDPLUS code from ActiveSync and instead add an option to Horde_Imap_Client_Base#copy() that guarantees a return of old -> new UIDs list even if the server does not automatically provide that information. I leave that one up to you and will adjust the code in the ActiveSync library when it's available. The correct way to workaround this via IMAP is to search for the message ID header in the new mailbox. You absolutely can't use the UIDNEXT value since servers don't necessarily use the next sequential UID (i.e. Gmail). The only IMAP requirement for UIDs is that they must be ascending; there is no requirement they must be contiguous. In the meantime, I'll refactor for this.

03/05/2014 02:13:42 PM	spamstop2 (at) terriertech (dot) com	Comment #5 New Attachment: Activesync-delete-2.patch	Reply to this comment
The correct way to workaround this via IMAP is to search for the message ID header in the new mailbox. You absolutely can't use the UIDNEXT value since servers don't necessarily use the next sequential UID (i.e. Gmail). The only IMAP requirement for UIDs is that they must be ascending; there is no requirement they must be contiguous. Thank you for the hints. I've attached a new patch for /usr/share/pear/Horde/ActiveSync/Imap/Adapter.php which does the above, and seems to fix the problem (limited testing so far). A few notes/questions: - The submitted patch fetches the message-id from BOTH the 'from' and 'to' folders. If it is already known to Horde, I couldn't see where. - If moving multiple UID's, the patch looks up each message-id in the 'to' folder as a separate IMAP query. Maybe it would be better to OR them? I left this as an optimization to see if the solution is on the right track first. - I haven't patched the base IMAP client, just ActiveSync. I suppose it is an open question whether looking up the message-id's in the 'to' folder should be done within the copy() function. Here is a new log with the patch: 2014-03-05T08:12:08-06:00 INFO: [30698] Handling MoveItems command. 2014-03-05T08:12:08-06:00 DEBUG: [30698] I <Move:Moves> 2014-03-05T08:12:08-06:00 DEBUG: [30698] I <Move:Move> 2014-03-05T08:12:08-06:00 DEBUG: [30698] I <Move:SrcMsgId> 2014-03-05T08:12:08-06:00 DEBUG: [30698] I 95473 2014-03-05T08:12:08-06:00 DEBUG: [30698] I </Move:SrcMsgId> 2014-03-05T08:12:08-06:00 DEBUG: [30698] I <Move:SrcFldId> 2014-03-05T08:12:08-06:00 DEBUG: [30698] I Fdf2bae0c 2014-03-05T08:12:08-06:00 DEBUG: [30698] I </Move:SrcFldId> 2014-03-05T08:12:08-06:00 DEBUG: [30698] I <Move:DstFldId> 2014-03-05T08:12:08-06:00 DEBUG: [30698] I F861db7b0 2014-03-05T08:12:08-06:00 DEBUG: [30698] I </Move:DstFldId> 2014-03-05T08:12:08-06:00 DEBUG: [30698] I </Move:Move> 2014-03-05T08:12:08-06:00 DEBUG: [30698] I </Move:Moves> 2014-03-05T08:12:08-06:00 DEBUG: [30698] O <Move:Moves> 2014-03-05T08:12:08-06:00 DEBUG: [30698] O <Move:Response> 2014-03-05T08:12:08-06:00 DEBUG: [30698] O <Move:SrcMsgId> 2014-03-05T08:12:08-06:00 DEBUG: [30698] O 95473 2014-03-05T08:12:08-06:00 DEBUG: [30698] O </Move:SrcMsgId> 2014-03-05T08:12:08-06:00 INFO: [30698] Horde_Core_ActiveSync_Driver::moveMessage(INBOX, [95473], Deleted Items) 2014-03-05T08:12:08-06:00 INFO: [30698] Updating state during delete 2014-03-05T08:12:08-06:00 DEBUG: [30698] O <Move:Status> 2014-03-05T08:12:08-06:00 DEBUG: [30698] O 3 2014-03-05T08:12:08-06:00 DEBUG: [30698] O </Move:Status> 2014-03-05T08:12:08-06:00 DEBUG: [30698] O <Move:DstMsgId> 2014-03-05T08:12:08-06:00 DEBUG: [30698] O 63 2014-03-05T08:12:08-06:00 DEBUG: [30698] O </Move:DstMsgId> 2014-03-05T08:12:08-06:00 DEBUG: [30698] O </Move:Response> 2014-03-05T08:12:08-06:00 DEBUG: [30698] O </Move:Moves> 2014-03-05T08:12:08-06:00 INFO: [30698] Maximum memory usage for ActiveSync request: 8908912 bytes.

03/05/2014 08:16:13 AM	Michael Slusarz	Comment #4	Reply to this comment
I've done some more investigating: this may be related to UIDPLUS and moveMessage() in Imap/Adapter.php. Client code really should not need to have to deal with capability sniffing. The best solution will be to remove all UIDPLUS code from ActiveSync and instead add an option to Horde_Imap_Client_Base#copy() that guarantees a return of old -> new UIDs list even if the server does not automatically provide that information. The correct way to workaround this via IMAP is to search for the message ID header in the new mailbox. You absolutely can't use the UIDNEXT value since servers don't necessarily use the next sequential UID (i.e. Gmail). The only IMAP requirement for UIDs is that they must be ascending; there is no requirement they must be contiguous.

03/05/2014 07:27:50 AM	spamstop2 (at) terriertech (dot) com	Comment #3	Reply to this comment
To answer the question: Yes, the message exists in deleted items. I've done some more investigating: this may be related to UIDPLUS and moveMessage() in Imap/Adapter.php. The IMAP backend (dovecot) is sending UIDPLUS. This means $uidplus is not set. But the value of $copy_res is 1 (i.e. not an array), so execution goes to the section labelled "No UIDPLUS". As a consequence, Horde is sending Move:Status=5 even though the move was successful at the backend: 2014-03-05T00:02:41-06:00 DEBUG: [24718] I <Move:Moves> 2014-03-05T00:02:41-06:00 DEBUG: [24718] I <Move:Move> 2014-03-05T00:02:41-06:00 DEBUG: [24718] I <Move:SrcMsgId> 2014-03-05T00:02:41-06:00 DEBUG: [24718] I 95335 2014-03-05T00:02:41-06:00 DEBUG: [24718] I </Move:SrcMsgId> 2014-03-05T00:02:41-06:00 DEBUG: [24718] I <Move:SrcFldId> 2014-03-05T00:02:41-06:00 DEBUG: [24718] I F1f4debc6 2014-03-05T00:02:41-06:00 DEBUG: [24718] I </Move:SrcFldId> 2014-03-05T00:02:41-06:00 DEBUG: [24718] I <Move:DstFldId> 2014-03-05T00:02:41-06:00 DEBUG: [24718] I F7be09d0e 2014-03-05T00:02:41-06:00 DEBUG: [24718] I </Move:DstFldId> 2014-03-05T00:02:41-06:00 DEBUG: [24718] I </Move:Move> 2014-03-05T00:02:41-06:00 DEBUG: [24718] I </Move:Moves> 2014-03-05T00:02:41-06:00 DEBUG: [24718] O <Move:Moves> 2014-03-05T00:02:41-06:00 DEBUG: [24718] O <Move:Response> 2014-03-05T00:02:41-06:00 DEBUG: [24718] O <Move:SrcMsgId> 2014-03-05T00:02:41-06:00 DEBUG: [24718] O 95335 2014-03-05T00:02:41-06:00 DEBUG: [24718] O </Move:SrcMsgId> 2014-03-05T00:02:41-06:00 INFO: [24718] Horde_Core_ActiveSync_Driver::moveMessage(INBOX, [9 5335], Deleted Items) 2014-03-05T00:02:42-06:00 INFO: [24718] Updating state during delete 2014-03-05T00:02:42-06:00 DEBUG: [24718] O <Move:Status> 2014-03-05T00:02:42-06:00 DEBUG: [24718] O 5 2014-03-05T00:02:42-06:00 DEBUG: [24718] O </Move:Status> 2014-03-05T00:02:42-06:00 DEBUG: [24718] O </Move:Response> 2014-03-05T00:02:42-06:00 DEBUG: [24718] O </Move:Moves> Because it is told the move was unsuccessful, WP7.8 is returning the message to the Inbox. Next I'll try to disable UIDPLUS on dovecot and see if that fixes it.

03/05/2014 05:10:18 AM	Michael Rubinsky	State ⇒ Feedback Priority ⇒ 1. Low

03/05/2014 05:10:05 AM	Michael Rubinsky	Comment #2	Reply to this comment
I'm not seeing this behavior on my WP7.8 device. Removing that code is absolutely not the correct thing to do. That prevents a delete command SENT FROM THE CLIENT from being sent BACK to the client when it is detected as a change on the server. If the client is not removing, or putting back a message that it has told the server it has deleted, that is absolutely broken behavior. Does the message exist in the Trash folder (on the client) when this occurs?

03/05/2014 04:00:54 AM	spamstop2 (at) terriertech (dot) com	Comment #1 New Attachment: Activesync-delete.patch State ⇒ Unconfirmed Patch ⇒ Yes Milestone ⇒ Queue ⇒ Synchronization Summary ⇒ Activesync on WP7.8 deleted messages reappear Type ⇒ Bug Priority ⇒ 2. Medium	Reply to this comment
Configuration: Using Horde 5.1.5, IMP 6.1.6, Horde_ActiveSync 2.12.4. IMP is configured to "move to trash" when deleting; "Trash" folder is flagged as wastebasket in IMAP backend. EAS version seems not to matter (e.g. use 12.1). Problem: On WP7.8 (newer WP versions not tested), configure the sync interval to be manual. Delete message on phone. Initiate sync. The item reappears in the WP's Inbox, but is successfully deleted on the backend IMAP server. Solution: Don't ignore the message when it is CHANGE_TYPE_DELETE. See attached patch. The message briefly reappears in the Inbox during sync, then is correctly removed. Comments: Applying the patch did not appear to break other ActiveSync clients (tested MeeGo, WebOS, but not iOS). Having the message reappear briefly in the Inbox is cosmetically annoying (does not happen with Z-Push), but I did not get a chance to look into that more.