[horde] AS email not current

Michael J Rubinsky mrubinsk at horde.org
Wed Mar 6 01:42:51 UTC 2013


Quoting simon at simonandkate.net:

>> Quoting Simon Wilson <simon at simonandkate.net>:
>>
>>>>>> Quoting Simon Wilson <simon at simonandkate.net>:
>>>>>>
>>>>>>>> Quoting Simon Wilson <simon at simonandkate.net>:
>>>>>>>>
>>>>>>>>>>> On 02/03/2013 4:22 AM, Simon Wilson wrote:
>>>>>>>>>>>> But if I delete emails in Imp, the deleted messages are not
>>>>>>>>>>>> sync'ed, and those emails continue to show in the iOS devices
>>>>>>>>>>>
>>>>>>>>>>> http://wiki.horde.org/ActiveSync
>>>>>>>>>>>
>>>>>>>>>>> "Deleting from a MUA: If the MUA is not configured to move
>>>>>>>>>>> messages to the trash, and instead just flags them as
>>>>>>>>>>> deleted, these message deletions will NOT be synched to the
>>>>>>>>>>> ActiveSync client, as there is no equivalent command in the
>>>>>>>>>>> protocol. These messages will only be removed from the
>>>>>>>>>>> ActiveSync client once expunged from the mailbox. This is in
>>>>>>>>>>> accordance with the ActiveSync protocol specs.
>>>>>>>>>>>
>>>>>>>>>>> *If you wish to ensure all message deletions are synched
>>>>>>>>>>> quickly to the device, you should configure the use of a
>>>>>>>>>>> Trash folder.*"
>>>>>>>>>>>
>>>>>>>>>>> --
>>>>>>>>>>> Horde mailing list
>>>>>>>>>>> Frequently Asked Questions: http://horde.org/faq/
>>>>>>>>>>> To unsubscribe, mail: horde-unsubscribe at lists.horde.org
>>>>>>>>>>
>>>>>>>>>> As per my other reply, Imp is configured to move to trash
>>>>>>>>>> folder, and purge from Inbox.
>>>>>>>>>>
>>>>>>>>>> It does not just flag as deleted.
>>>>>>>>>>
>>>>>>>>>> Simon
>>>>>>>>>> --
>>>>>>>>>
>>>>>>>>> OK - did an experiment... deleting an email on the same iOS
>>>>>>>>> device in Apple Mail (via a direct IMAP connection), and the
>>>>>>>>> resultant sync back to the AS email connection removes the
>>>>>>>>> deleted email correctly.
>>>>>>>>>
>>>>>>>>> Delete an email in Imp and it does not.
>>>>>>>>>
>>>>>>>>> My Imp's mail deletion prefs are set as per following screen shot:
>>>>>>>>>
>>>>>>>>> http://www.simonandkate.net/impprefs.png
>>>>>>>>>
>>>>>>>>> So what is happening in Imp that it is not flagging those
>>>>>>>>> deletions back through AS?
>>>>>>>>
>>>>>>>> Not sure. Those settings are correct.
>>>>>>>> --
>>>>>>>> mike
>>>>>>>
>>>>>>> :( troubleshooting suggestions?
>>>>>>>
>>>>>>> If I empty the AS log, delete an email in Imp, and post the sync
>>>>>>> log will that help?
>>>>>>
>>>>>> I doubt it, though I'll look at it if you send it me. The device
>>>>>> is not being told to remove the email, so it won't be in the log.
>>>>>>
>>>>>>> What about Imap log for the delete transaction?
>>>>>>
>>>>>> Not really. The email is obviously being removed from your INBOX
>>>>>> since you no longer see it in IMP (or other MUA).
>>>>>>
>>>>>>> What is the process that a delete triggers?
>>>>>>
>>>>>> This happens in one of two ways depending on the features of your
>>>>>> IMAP server. If you don't support CONDSTORE or per-mailbox MODSEQ
>>>>>> values (which, if I remember right from looking at your log, is
>>>>>> your case) - we basically compare the UID list that we have
>>>>>> cached in the ActiveSync state with what the IMAP server returns
>>>>>> as being present in the mailbox. Anything not listed in the IMAP
>>>>>> server's list of UIDs, but present in the ActiveSync list is
>>>>>> removed from the device.
>>>>>>
>>>>>>
>>>>>>
>>>>>>> Does AS care WHERE the email is deleted to? I have Cyrus IMAP
>>>>>>> with a "Deleted Items" folder that Imp calls Trash, seems to
>>>>>>> function fine. Should I be using virtual trash in Imp?
>>>>>>
>>>>>> It doesn't matter. From the point of view of ActiveSync, the
>>>>>> message is just vanished from the INBOX (or whatever folder we
>>>>>> are talking about). Adding it to the Deleted Items/Trash/Whatever
>>>>>> folder is a separate operation.
>>>>>>
>>>>>>
>>>>>>
>>>>>> --
>>>>>> mike
>>>>>
>>>>> Thanks Mike. You know how much I hate it when things start working
>>>>> by themselves with no change????? Lots.
>>>>>
>>>>> I tried today in Outlook with an IMAP connection to my mailbox.
>>>>> Deleted some emails. When my iOS devices next connected, the
>>>>> mailbox changes (deletions) were correctly sent through. So that
>>>>> is with both Apple Mail and MS Outlook 2010 that deletions in
>>>>> other MUAs are correctly sync'ed through AS.
>>>>>
>>>>> Then tried in Imp again. And it updated. :-O
>>>>>
>>>>> Man I hate that.
>>>>>
>>>>> I haven't changed ANYTHING.
>>>>>
>>>>> Anyway, apologies for the noise, I'll monitor and see if it reoccurs.
>>>>>
>>>>> Simon.
>>>>
>>>> I spoke too soon. It was updating automatically for a while, then
>>>> stopped again.
>>>>
>>>> At this stage I have one email that ActiveSync thinks is there but
>>>> that isn't.
>>>>
>>>> I have confirmed that the email does NOT exist in the Cyrus
>>>> partition, so the IMAP delete has successfully completed.
>>>>
>>>> Is there any way to see what UIDs ActiveSync has cached, and what
>>>> it is getting from IMAP to compare?
>>>>
>>>> I then deleted a second email from Imp, and it also hung up...
>>>> deleted OK on the Cyrus partition, but AS still thinks it's there.
>>>>
>>>> Third email deleted then from Outlook - and it also hung up... as
>>>> per last one, gone in Cyrus, AS still thinks it's there.
>>>>
>>>> Sounding to me like AS caching something incorrectly reading the
>>>> Cyrus list. Could it be related to bug 11115?
>>>>
>>>> Simon
>>>
>>> I have the following set in backends.local.php. Cache was set to
>>> true, but setting to false hasn't changed anything. :
>>>
>>> <?php
>>>
>>> $servers['imap'] = array(
>>>    'disabled' => false,
>>>    'name' => 'Cyrus IMAP Server',
>>>    'hostspec' => 'server04.simonandkate.lan',
>>>    'hordeauth' => true,
>>>    'protocol' => 'imap',
>>>    'secure' => 'tls',
>>>    'port' => 143,
>>>    'quota' => array(
>>>        'driver' => 'imap',
>>>        'params' => array(
>>>                'hide_quota_when_unlimited' => true,
>>>                'unit' => 'MB'
>>>         )
>>>    ),
>>>    'maildomain' => 'simonandkate.net',
>>>    'acl' => true,
>>>    'cache' => false,
>>> //    'debug' => ($GLOBALS['registry']->getAuth() == 'simon') ?
>>> '/var/log/hordeas/impdebug' : false,
>>>    'debug' => '/var/log/hordeas/impdebug',
>>>    'debug_raw' => false,
>>> );
>>>
>>> Setting Impdebug gives some info...
>>>
>>> Initial connection:
>
>>> Snip
>
>>> Doing an update on the iPhone's AS Inbox generates this IMAP debug log:
>>>
>>> http://www.simonandkate.net/imaplog.txt
>>>
>>> That UID list returned from Cyrus is correct - 46072 is the last
>>> (newest) email that is actually in the mailbox. It appears that
>>> Cyrus is sending the correct info. Imp shows this correctly. Yet AS
>>> into iOS is not showing this, with four emails showing that are newer.
>>>
>>> The AS log for this is as follows:
>>>
>>> http://www.simonandkate.net/asimap.txt
>>>
>>> That also shows the correct UID sequence. Yet iPhone continues to
>>> show the old list of emails - not being told to update?
>>
>> Actually, this log was very helpful. It doesn't contain *any* UID
>> Sequences at all. I'm not talking about just the UIDNEXT value, but
>> the entire sequence of message UIDs that ActiveSync thinks is on the
>> device. This should be visible in the 'm' parameter of the state that
>> is saved (and would basically look like a large array of integers).
>> Yours is showing an empty array. This would definitely cause deleted
>> emails from not being detected since we perform an array_diff on the
>> list we have and the list the IMAP server has. The question is, *why*
>> you don't have a valid list of UIDs. Something must be wiping in the
>> code somewhere, I'll have to dig further on that during my next coding
>> sprint later this week.
>>
> Yay!! I was starting to get a bit disheartened, but that's great  
> news that the log gives you something useful.

I've spent about an hour trying to reproduce this and can't. I've  
disabled features on my IMAP server to emulate not having per-mailbox  
MODSEQ values like your IMAP server, tried IMAP caching on/off,  
performed dozens of mailbox operations from various MUAs and  
activesync clients. I'm not able to lose ActiveSync's internal message  
cache nor am I able to see any code path where the message state would  
be reset.

You are going to need to start from a fresh account, synchronize it,  
and find the point where your log goes from having the proper state to  
an empty state.

2013-03-05T20:39:14-05:00 DEBUG: [8689] Saving state: Array
(
     [0] => {51369e16-4154-423a-bcf7-21f2c0a8015f}25
     [1] => Horde_Db_Value_Binary Object
         (
             [_value:protected] =>  
C:28:"Horde_ActiveSync_Folder_Imap":1184:{a:5:{s:1:"s";a:3:{s:7:"uidnext";s:6:"168028";s:11:"uidvalidity";s:10:"1292457115";s:13:"highestmodseq";i:0;}s:1:"m";a:21:{i:167587;a:2:{s:4:"read";i:1;s:7:"flagged";i:0;}i:167604;a:2:{s:4:"read";i:1;s:7:"flagged";i:0;}i:167612;a:2:{s:4:"read";i:1;s:7:"flagged";i:0;}i:167638;a:2:{s:4:"read";i:1;s:7:"flagged";i:0;}i:167642;a:2:{s:4:"read";i:1;s:7:"flagged";i:0;}i:167643;a:2:{s:4:"read";i:1;s:7:"flagged";i:0;}i:167648;a:2:{s:4:"read";i:1;s:7:"flagged";i:0;}i:167665;a:2:{s:4:"read";i:1;s:7:"flagged";i:0;}i:167666;a:2:{s:4:"read";i:1;s:7:"flagged";i:0;}i:167672;a:2:{s:4:"read";i:1;s:7:"flagged";i:0;}i:167679;a:2:{s:4:"read";i:1;s:7:"flagged";i:0;}i:167712;a:2:{s:4:"read";i:1;s:7:"flagged";i:0;}i:167721;a:2:{s:4:"read";i:1;s:7:"flagged";i:0;}i:167753;a:2:{s:4:"read";i:1;s:7:"flagged";i:0;}i:167758;a:2:{s:4:"read";i:1;s:7:"flagged";i:0;}i:168018;a:2:{s:4:"read";i:0;s:7:"flagged";i:0;}i:168019;a:2:{s:4:"read";i:1;s:7:"flagged";i:0;}i:168024;a:2:{s:4:
"read";i:1;s:7:"flagged";i:0;}i:168025;a:2:{s:4:"read";i:0;s:7:"flagged";i:0;}i:168026;a:2:{s:4:"read";i:0;s:7:"flagged";i:0;}i:168027;a:2:{s:4:"read";i:0;s:7:"flagged";i:0;}}s:1:"f";s:5:"INBOX";s:1:"c";s:5:"Email";s:1:"v";i:1;}}
         )

     [2] => ApplGB024LGPZ3A
     [3] => 1362533954
     [4] => INBOX
     [5] => mike
     [6] => 0
)
Note the entries after the "m" value. This is the message state for  
this folder. Now, YOUR log looks like this:

2013-03-04T11:30:07+00:00 DEBUG: [14497] Saving state: Array
(
     [0] => {51347830-a744-4382-b47a-214dc0a801e6}110
     [1] => Horde_Db_Value_Binary Object
         (
             [_value:protected] =>  
C:28:"Horde_ActiveSync_Folder_Imap":174:{a:5:{s:1:"s";a:3:{s:13:"highestmodseq";i:0;s:7:"uidnext";s:5:"46217";s:11:"uidvalidity";s:10:"1238677126";}s:1:"m";a:0:{}s:1:"f";s:5:"INBOX";s:1:"c";s:5:"Email";s:1:"v";i:1;}}
         )

     [2] => Appl79030T3BA4S
     [3] => 1362396607
     [4] => INBOX
     [5] => simon
     [6] => 0
)

Note the "m";a:0: value. This means your internal message state is  
empty. I.e., the ActiveSync state cache thinks the INBOX on your  
device is empty - so we have no context to pass to Horde_Imap_Client  
when asking for the list of vanished messages. (This will always  
return an empty list).


-- 
mike

The Horde Project (www.horde.org)
mrubinsk at horde.org
-------------- next part --------------
A non-text attachment was scrubbed...
Name: smime.p7s
Type: application/pkcs7-signature
Size: 6062 bytes
Desc: S/MIME Cryptographic Signature
URL: <http://lists.horde.org/archives/horde/attachments/20130305/c2aedf6a/attachment-0001.bin>


More information about the horde mailing list