[horde] AS email not current

simon at simonandkate.net simon at simonandkate.net
Wed Mar 6 08:34:02 UTC 2013



Simon Wilson
M: 0400 12 11 16

On 06/03/2013, at 11:42 AM, Michael J Rubinsky <mrubinsk at horde.org> wrote:

> 
> 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

Ok. I'll remove the device from AS in horde, remove its log file, and connect as my test account, that only has about 3 emails in it and 2 appts. Will the horde inline debug function that can be thrown into the php help me anywhere? 

Simon



More information about the horde mailing list