[horde] AS email not current

Michael J Rubinsky mrubinsk at horde.org
Wed Mar 6 16:54:32 UTC 2013


Quoting simon at simonandkate.net:

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

Possibly, though since I have no idea where this is being cleared, I  
don't know where to tell you to put it yet.


-- 
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/20130306/77e98bcd/attachment-0001.bin>


More information about the horde mailing list