[#11115] delete action does not update mailbox in traditional view
Summary delete action does not update mailbox in traditional view
Queue IMP
Queue Version Git master
Type Bug
State Not A Bug
Priority 1. Low
Owners slusarz@horde.org
Requester leena.heino@uta.fi
Created 2012-03-29 (2704 days ago)
Due
Updated 2012-04-19 (2683 days ago)
Assigned 2012-04-03 (2699 days ago)
Resolved 2012-04-19 (2683 days ago)
Milestone
Patch No

Comments
leena.heino@uta.fi 2012-03-29 11:49:36
When user marks message as deleted in traditional mode, the folder 
view or message status is not updated and the message is still shown 
as not deleted. If user does folder refresh or does the same mark as 
delete operation again, then the message status is updated as deleted.

This does not happen when the delete status is removed from the 
message. Then the folder view or message status is updated immediately.

How to reproduce situation:
1. log in to imp in traditional mode
2. mark message as deleted
3. message status in the folder view is not updated

leena.heino@uta.fi 2012-04-03 08:56:27
This also happens with dynamic view.

IMAP Server: Cyrus IMAPD 2.4.14

Jan Schneider <jan@horde.org> 2012-04-03 09:11:52
Duplicate of bug #11118?

leena.heino@uta.fi 2012-04-03 09:39:03
> Duplicate of bug #11118?

I don't think so.

This seems to be related to the way cache works. As this happens 
rarely when cache => false in backends.php, but it happens really 
often when cache => true.

Michael Slusarz <slusarz@horde.org> 2012-04-04 23:15:58
>> Duplicate of bug #11118?
>
> I don't think so.

Are you truly using Git master (as opposed to the latest release versions)?

Michael Slusarz <slusarz@horde.org> 2012-04-04 23:18:17
>>> Duplicate of bug #11118?
>>
>> I don't think so.
>
> Are you truly using Git master (as opposed to the latest release versions)?

And at a minimum, we need the IMAP log of the page access where the 
unseen count is not being updated correctly.



To further debug this issue, we need details of the IMP -> IMAP/POP 
communication.

To enable debugging, see instructions contained in 
imp/config/backends.php (the 'debug' config parameter).

Debugging should not be enabled on a production server,   Attach/post 
only the portion of the log that directly deals with the problem 
reported (it may be simplest to clear the log file and then perform 
the event that causes the error).

leena.heino@uta.fi 2012-04-05 12:49:58
>> Are you truly using Git master (as opposed to the latest release versions)?

Yes, I am using the latest from Git Master.

> To further debug this issue, we need details of the IMP -> IMAP/POP 
> communication.

I have available protocol logs from Cyrus IMAPD server when cache is 
enabled in IMP and when cache is disabled.

I can include the logs here with this bug. But I would prefer that 
these logs are only available to developers.

leena.heino@uta.fi 2012-04-05 13:20:49
I have also discussed this bug with Cyrus IMAPD developers. In their 
opinion this might not a problem with Cyrus, but if you use 
FLAGS.SILENT and don't get an error, you need to update your local 
cache.

Included is imap-cache.txt: Cache is enabled in IMP and example user 
does this:
1. Open mailbox
2. Mark message as deleted -> flag change is not shown on the screen
3. Mark message again as deleted -> now message is shown as deleted
4. Mark message as undeleted -> deleted flag is still shown on the screen
5. Mark message as undeleted -> now deleted flag is no longer seen on 
the screen
6. Logout

Michael Slusarz <slusarz@horde.org> 2012-04-05 17:11:15
You have cleared all your cache files, correct? (See Bug #11118)

leena.heino@uta.fi 2012-04-05 18:58:59
> You have cleared all your cache files, correct? (See Bug #11118)

Yes the cache was cleared before testing.

Michael Slusarz <slusarz@horde.org> 2012-04-05 19:10:27
> I have also discussed this bug with Cyrus IMAPD developers. In their 
> opinion this might not a problem with Cyrus, but if you use 
> FLAGS.SILENT and don't get an error, you need to update your local 
> cache.

This is already what we do. From Horde_Imap_Client_Socket:

             $this->_sendLine($cmd);
             $this->_storeUpdateCache('replace', $options['replace']);
[...]
                     $this->_sendLine($cmdtmp);
                     $this->_storeUpdateCache($k, $options[$k]);

If the command executes correctly on the IMAP server ($this->_sendLine 
will throw an Exception on a BAD/NO response from the server), the 
cache is updated with the changes.

It goes without saying that this works fine for me, whether IMAP 
debugging is turned on or off (this toggles whether FLAGS or 
FLAGS.SILENT is sent).

> Included is imap-cache.txt:

There is no imap-cache.txt attached.

leena.heino@uta.fi 2012-04-05 19:28:27
>> Included is imap-cache.txt:
>
> There is no imap-cache.txt attached.

There must have been some problem with browser not attaching the file.


Michael Slusarz <slusarz@horde.org> 2012-04-06 20:37:23
>>> Included is imap-cache.txt:
>>
>> There is no imap-cache.txt attached.
>
> There must have been some problem with browser not attaching the file.

Please use IMP's IMAP debugging isntead, as it provides information on 
caching done by Horde_Imap_Cache.

leena.heino@uta.fi 2012-04-06 21:04:56
> Please use IMP's IMAP debugging isntead, as it provides information 
> on caching done by Horde_Imap_Cache.

Here is a summary of testing:
- if I enable debug mode in backends.local.php then the problems 
disappear and flags are updated correctly
- If I disable debug mode in backends.local.php then the problems 
reappear and every flag changing operation has to be done twice.

Are the any other differences between these modes in IMAP protocol 
level other than one uses FLAGS and the other uses FLAGS.SILENT?

leena.heino@uta.fi 2012-04-06 21:15:33
Attached is a log from imap session with cache enabled and IMP uses 
debug mode.

Michael Slusarz <slusarz@horde.org> 2012-04-09 16:13:14
I can verify that if I modify the code to only use FLAGS.SILENT 
(regardless of the debug setting), the flag changes are still 
correctly saved in the cache.

So this behavior is only being seen on your server, which means you 
will need to track down the issue further.

leena.heino@uta.fi 2012-04-09 18:10:18
> I can verify that if I modify the code to only use FLAGS.SILENT 
> (regardless of the debug setting), the flag changes are still 
> correctly saved in the cache.
>
> So this behavior is only being seen on your server, which means you 
> will need to track down the issue further.

That is really strange. Do you have a imap trace log so that I would 
be able to compare the logs.

Which server are you testing against?



Michael Slusarz <slusarz@horde.org> 2012-04-09 18:19:39
> That is really strange. Do you have a imap trace log so that I would 
> be able to compare the logs.

Here's a delete action.

>> Timestamp: Mon, 09 Apr 2012 12:16:18 -0600
S: * OK [CAPABILITY IMAP4rev1 LITERAL+ LOGIN-REFERRALS ID ENABLE 
AUTH=LOGIN XIMAPPROXY] Dovecot ready.
C: [LOGIN Command - username: slusarz]
S: * OK [XPROXYREUSE] IMAP connection reused by squirrelmail-imap_proxy
S: 1 OK User logged in
C: 2 SELECT Testing.AAC (QRESYNC (1255685589 148 50:76,78:103,106))
S: * FLAGS (\Answered \Flagged \Deleted \Seen \Draft impflag0 
$Forwarded impflag1)
S: * OK [PERMANENTFLAGS (\Answered \Flagged \Deleted \Seen \Draft 
impflag0 $Forwarded impflag1 \*)] Flags permitted.
S: * 54 EXISTS
S: * 0 RECENT
S: * OK [UNSEEN 2] First unseen.
S: * OK [UIDVALIDITY 1255685589] UIDs valid
S: * OK [UIDNEXT 107] Predicted next UID
S: * OK [HIGHESTMODSEQ 148] Highest
S: 2 OK [READ-WRITE] Select completed.
>> CACHE: Retrieved messages (mailbox: Testing.AAC; UIDs: 55)
C: 3 UID STORE 55 (UNCHANGEDSINCE 148) +FLAGS.SILENT \deleted
S: * 6 FETCH (UID 55 MODSEQ (149))
S: 3 OK Store completed.
>> CACHE: Retrieved messages (mailbox: Testing.AAC; UIDs: 55)
[NOTE: The below command is the log entry indicating that the flag was 
successfully updated]
>> CACHE: Stored messages (mailbox: Testing.AAC; UIDs: 55)
[NOTE: And since flags are updated in mailbox, we know that cached 
search queries are no longer valid so we need to remove those also]
>> Expired search results from cache (mailbox: Testing.AAC)
C: 4 UID SORT RETURN (ALL COUNT) (DATE) US-ASCII ALL
S: * ESEARCH (TAG "4") UID ALL 
50,79,51,80,52,81,53,82,54,83,55,84,56,85,57,86,58,87,59,88,60,89,61,90,62,91,63,92,64,93,65,94,66,95,67,96,68,97,69,98,70,99,71,100,72,101,73,102,74,103,75,78,106,76 COUNT 
54
S: 4 OK Sort completed (0.000 secs).
>> Saved search results to cache (mailbox: Testing.AAC; id: 
>> 98367107759a917e62e60584c8d69c2f)
C: 5 UID FETCH 50:76,78:103,106 UID (CHANGEDSINCE 147)
S: * 6 FETCH (UID 55 MODSEQ (149))
S: 5 OK Fetch completed.
>> CACHE: Retrieved messages (mailbox: Testing.AAC; UIDs: 55)
C: 6 LOGOUT
S: * OK [CLOSED] Previous mailbox closed.
S: * BYE LOGOUT received
S: 6 OK Completed

Here's the undelete action immediately after:

>> Timestamp: Mon, 09 Apr 2012 12:16:20 -0600
S: * OK [CAPABILITY IMAP4rev1 LITERAL+ LOGIN-REFERRALS ID ENABLE 
AUTH=LOGIN XIMAPPROXY] Dovecot ready.
C: [LOGIN Command - username: slusarz]
S: * OK [XPROXYREUSE] IMAP connection reused by squirrelmail-imap_proxy
S: 1 OK User logged in
C: 2 SELECT Testing.AAC (QRESYNC (1255685589 149 50:76,78:103,106))
S: * FLAGS (\Answered \Flagged \Deleted \Seen \Draft impflag0 
$Forwarded impflag1)
S: * OK [PERMANENTFLAGS (\Answered \Flagged \Deleted \Seen \Draft 
impflag0 $Forwarded impflag1 \*)] Flags permitted.
S: * 54 EXISTS
S: * 0 RECENT
S: * OK [UNSEEN 2] First unseen.
S: * OK [UIDVALIDITY 1255685589] UIDs valid
S: * OK [UIDNEXT 107] Predicted next UID
S: * OK [HIGHESTMODSEQ 149] Highest
S: 2 OK [READ-WRITE] Select completed.
C: 3 UID STORE 55 (UNCHANGEDSINCE 149) -FLAGS.SILENT \deleted
S: * 6 FETCH (UID 55 MODSEQ (150))
S: 3 OK Store completed.
>> CACHE: Retrieved messages (mailbox: Testing.AAC; UIDs: 55)
[NOTE: Again, this is the updating of the deleted flag in the cache]
>> CACHE: Stored messages (mailbox: Testing.AAC; UIDs: 55)
C: 4 LOGOUT
S: * OK [CLOSED] Previous mailbox closed.
S: * BYE LOGOUT received
S: 4 OK Completed

> Which server are you testing against?

Dovecot (2.1.3), but that should be irrelevant.

leena.heino@uta.fi 2012-04-18 12:36:06
The bug was in Cyrus IMAPD and it was fixed in the version 2.4.15.

As a workaround I used these settings in backends.local.php:
'cache' => true,
'debug' => '/dev/null',