6.0.0-git
2019-03-20

[#13010] Activesync on WP7.8 deleted messages reappear
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 2014-03-05 (1841 days ago)
Due
Updated 2014-03-06 (1840 days ago)
Assigned 2014-03-05 (1841 days ago)
Resolved 2014-03-06 (1840 days ago)
Milestone
Patch Yes

History
2014-03-06 05:20:24 Michael Rubinsky Comment #11
State ⇒ Resolved
Reply to this comment
Horde_Imap_Client-2.19.0 and Horde_ActiveSync-2.13.0
2014-03-06 05:18:56 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
2014-03-05 19:39:48 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
2014-03-05 18:30:28 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.
2014-03-05 18:27:48 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.
2014-03-05 14:19:35 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.
2014-03-05 14:13:42 spamstop2 (at) terriertech (dot) com Comment #5
New Attachment: Activesync-delete-2.patch Download
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.

2014-03-05 08:16:13 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.
2014-03-05 07:27:50 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.
2014-03-05 05:10:18 Michael Rubinsky State ⇒ Feedback
Priority ⇒ 1. Low
 
2014-03-05 05:10:05 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?
2014-03-05 04:00:54 spamstop2 (at) terriertech (dot) com Comment #1
Type ⇒ Bug
State ⇒ Unconfirmed
Priority ⇒ 2. Medium
Summary ⇒ Activesync on WP7.8 deleted messages reappear
Queue ⇒ Synchronization
Milestone ⇒
Patch ⇒ Yes
New Attachment: Activesync-delete.patch Download
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.

Saved Queries