145638 - Wrong message showing up on IMAP folder

Status: RESOLVED FIXED

(MailNews Core :: Networking: IMAP, defect)

Description

[Yuting Kuo]

Reproducible: Sometimes

1. Have one message in IMAP INBOX folder.
2. Use some other mail client (e.g. Outlook Express) to retrieve the message via
POP protocol. (Message deleted from server)
3. Second message received in INBOX.

ACTUAL results: Messenger now shows the second message on top pane, but the
contents of the FIRST message in bottom pane.

EXPECTED: The correct message should be shown.

p.s. View message source shows up the wrong message too. So it should be a bug
in the mail database.

Comment 1

[David :Bienvenu]

this would either be an imap problem, or a problem with the thread pane view
code, not a mail database problem.

What build are you running? What IMAP server are you running? If you select
another folder and come back to the INBOX folder, does the correct message show?

Comment 2

[David :Bienvenu]

reporter, do you have any of the info I've asked for? Otherwise, I'll have to
mark this works for me, because I have no idea where to start in trying to
reproduce this.

Comment 3

[Yuting Kuo]

Sorry. Yes the problems persists even if I switch to another folder and switch 
back. Build 2002051006 1.0 RC2. I have yet to identify the IMAP server but I 
have not had this problem problem with other mail clients.

Could you not reproduce it? You need to:

1. Clear your INBOX.
2. Send a message to yourself, subject TEST1, contents THIS IS TEST 1.
3. View the INBOX in Mozilla using IMAP account. You see TEST1, contents THIS 
IS TEST 1.
4. Switch to another mail client (e.g. Outlook). Use POP3 to retrieve the 
INBOX. So the TEST1 is downloaded and removed from server.
5. Send another message to yourself, subject TEST2, contents THIS IS TEST 2.
6. Switch to Mozilla. Refresh the INBOX view.

RESULTS:
TEST 2 appears in the top message list pane (EXPECTED).
TEST 1 appears in the bottom message preview pane (UNEXPECTED).

Switching to another folder and back, or refreshing folders do not solve the 
problem.

Comment 4

[David :Bienvenu]

attaching an imap protocol log would help me a lot:

http://www.mozilla.org/quality/mailnews/mail-troubleshoot.html#imap

thx!

Comment 5

[Maggie Leber]

I have a very similar problem with 1.0 RC1 and 1.0 RC2 on RH Linux 7.1. I use
fetchmail/procmail/SpamAssasin to bring mail from my POP account to my local
machine, and then run an imapd locally and use Moz as my mail client. (This was
the only way I could continue running SpamAssasin while using Moz for mail).  

If fetchmail runs while Moz is still running *after* I've used Moz to look at my
mail and move some/all of it to an archive folder, frequently I'll reopen the
Mail window after getting biffed for the new mail and have the message list show
new messages. 

Selecting one message can cause the preview pane to show the wrong message;
usually one of the previously removed messages. Close/reopen the mail window has
no effect, but restarting Moz cleans up the problem completely untilthe next
time it happens. 

I'll try to get you an IMAP protocol log, but it's hard to predict when it's
going to occurr.     

Comment 6

[Dave Goldblatt]

Attachment: imap log where message in header pane is not the one displayed in view pane

I was able to reproduce this problem by marking two items in my spam folder as
new, deleting them, moving another message into the folder (same behavior
occurs when a new message arrives), and trying to read it.  The message list
pane is correct, but clicking on the message displays the first message
deleted.  A packet capture shows no traffic upon selecting the message, and the
imap log matches that.	Quitting the browser and restarting is the only way to
work around this.

Comment 7

[Dave Goldblatt]

reproducible with 2002081808.

Comment 8

[David :Bienvenu]

OK, the problem here is that we're not clearing out the memory cache when the
uid validity changes on an imap folder. The imap server seems to be rolling uid
validity when you empty the folder (or maybe it does it all the time, or it's
some interaction with spam assasin - I can't tell what server it is from the
log). We do regenerate the database in this case (not hard, since it's empty),
but we have the entry for the old message with uid 1 in that folder in the
system memory cache, and when you try to load the message with uid 1 in that
same folder subsequently, we give you the old message with uid 1 in that folder.
We use the message uri as our key into the memory cache, and the message uri's
for those two messages are the same. In order to fix this, we need to remove
from the memory cache messages in folders which have the uid validity change.

Comment 9

[David :Bienvenu]

since it might be hard or impossible to iterate the memory cache, the other
possibilities for fixing this are

1) encode the uid validity in the memory cache keys, so that if it changes, we
won't get hits against the old uid validity. This would make the keys a bit longer.

2) Don't use the memory cache in a protocol session where the uid validity has
changed. (this isn't perfect, since you could finish the one session after uid
validity changed and then start another session which would not think uid
validity had changed). We could go further and keep track of the folders which
had uid validity changes in the current program run and not use the memory cache
at all for them. This all makes option 1 look the most attractive. 

Comment 10

[Wolfgang Hoessl]

I've sometimes the same problem with 2002091014.

Normally the right message is shown in the preview window.
But when I retrieve a special newsletter (RiskNews, see attached jpg),
the preview windows still shows the RiskNews content even if I've already
deleted the mail (see jpg).

Reproduceability:
This only happens to me, if I retrieve the RiskNews newsletter being followed by
the [idw] newsletter (german), which is not shown in the preview window. Other
e-mails are displayed correctly.

Comment 11

[Wolfgang Hoessl]

Attachment: Picture, showing the wrong mail being displayed (red marks), see comment #10

Comment 12

[Doug Ledford]

> OK, the problem here is that we're not clearing out the memory cache when
> the uid validity changes on an imap folder.

Can you explain what "uid validity" means in this context?  Obviously, if you
are using an IMAP server and the mail client tells the server to move message id
10 to the Trash folder (as mine would for example) and the server responds with
a message of successful completion, then uid #10 in the source folder is no
longer valid whether the uid reappears in another half a second or not.  The
item should be deleted immediately in that case.

> We use the message uri as our key into the memory cache,

That's an invalid programming technique.  The message uri is *not* a unique
message tag across any period of time and it *is* subject to change at *any*
time (think of two IMAP clients accessing the same set of IMAP folders, or think
about IMAP mail folders where the mail delivery subsystem sorts the mail into
folders instead of Mozilla doing that job).  Furthermore, you've already
downloaded the new message headers by the time this particular error happens,
and you've got the old message headers as part of the cached message, so it's
actually easy to tell you have the wrong message in hand because the headers
don't match.  You should be using some item(s) in the message headers as the key
into your memory cache and every delete/move event should immediately remove the
item from memory cache upon completion.  Otherwise this problem will continue
(and it still does as of Mozilla 1.2.1).

Comment 13

[David :Bienvenu]

uid validity is just what it sounds like - uids are valid for as long as the uid
validity doesn't change - valid in the sense that no other message will get the
same uid ever again for that folder, because new messages will get larger uids.
It does not mean that a uid is invalid when a message is deleted.

a message uri would be a perfectly valid cache key as long as the uid validity
didn't change. I'm not sure what your examples are trying to say, but I think
maybe you don't understand what a message uri is, or the way uids work in imap.
I think you're confusing the existence of a message with the validity of a
message uri or a uid - they're not related.

Comment 14

[Doug Ledford]

I switched the OS to All since this report was against Windows while I'm using
Linux and I'm pretty positive that All is in fact correct.  I've also verified
that it still happens on 1.3b.  I would verify the nightly builds but there
haven't been any Red Hat 8x rpm builds in quite a while :-(

Now, to the issue of uid.  I am well aware of uid and uri issues in general (and
yes, a uri is a perfectly fine hash key iff you catch all uid validity changes).
 However, it is painfully obvious that *somewhere* there is a uid validity
change being missed.  Do you rely upon the server to tell you when there is a
uid validity change or do you track that in mozilla directly?  Also, a possible
important bit to this may be the IMAP delete behaviour.  In my case, it's set to
Move to Trash Folder.  I also routinely tell Mozilla to compact folders 3 or 4
times a day after cleaning out the emails I don't need to do anything with. 
That might play a role as well.  As to the comment about deleting an email not
being a validity change, are you certain that's true if the option Move to Trash
Folder is set and the imap server is in fact moving the message immediately?

OK, so it just happened again.  I took a screenshot of the window to show what
it is doing.  I've also copied the exact contents of my imap mail folder to a
tmp file for future reference.  In between the two different emails I deleted
all the emails from the mail folder and I compacted the mail folder.  Then, when
new email was delivered and I tried to view it, I got an email from cache instead.

After some experimentation with my IMAP files, it seems pretty obvious what the
WashU IMAP server does.  The WashU IMAP server evidently tracks the highest
known UID in a mail folder, and upon receipt of a new message allocates the next
higher number to that mail item.  So, if you have messages numbered 1, 2, and 5
in a folder, the next message gets UID 6.  If you then delete 5 and compact the
folder, you will now have 1, 2, and 6 in the folder (aka, it does *not* renumber
messages on compaction).  However, if you get 3 emails and have 1, 2, 6, 7, 8,
and 9, and you then delete 8 and 9 and compact the folder, the top of folder UID
is reset back to 7 and the next new message will get UID 8.  This is where the
corruption comes in because Mozilla is mistakenly pulling UID 8 from cache
instead of downloading it.  So, the question becomes "where are we missing a uid
validity change"?  If the server is immediately moving the items to trash and
actually writing the changes to the imap files, then every time you delete the
highest numbered UID in an imap folder you have a uid validity change event. 
Otherwise, you have a UID validity change every time you have both A) deleted
the highest numbered UID message in a folder and B) compacted that folder.

Comment 15

[David :Bienvenu]

We're "missing" the uid validity change in the sense that we're not clearing out
the memory cache when the uid validity changes. I believe that's understood. The
alternative, as I said before, is to encode the uid validity into the memory
cache lookup key (basically, tack it onto the end of the uri). Thus, if the uid
validity changes, we'll no longer get hits on uri's which no longer correspond
to the message they used to correspond to.

If you attach an imap protocol log, it's easy enough to see where the uid
validity changes. I'm a little surprised that UW does what you describe, but not
shocked.

Comment 16

[Doug Ledford]

I'm attaching an edited imap log (the full log is huge and I see no reason to
include the contents of my emails in the attached file).  I have comments inline
in the log file, but for the benefit of people watching this thread I'll include
the final conclusion here:

Then we mark the message as seen without ever downloading it...

This is *VERY* obviously a mozilla bug.  The WashU IMAP server is changing the
uid validity *twice* and mozilla is still ignoring it and failing to clean
out cache and download the new messages.

Comment 17

[Doug Ledford]

Attachment: Imap log from failing connection

Comment 18

[David :Bienvenu]

Just to be clear, it's definitely a mozilla bug - I thought we were only
disagreeing about the cause and the potential fix.

Comment 19

[Doug Ledford]

/me still suggests that the proper fix is to remove the message from cache the
moment that you get an "Expunge Complete" message back from the IMAP server on
the message in question, this not only makes it impossible for this cache lookup
to succeed in the future, it also has the very nice benefit of reducing cache
bloat in mozilla

Comment 20

[Doug Ledford]

Hmmm...in the light of possibly two different imap clients effecting the same
imap mailbox, you actually would need to invalidate cache on a uid validity
change regardless of anything else, so invalidating it preemptively on an
expunge would just be a perk for reducing cache bloat and not a sufficient
invalidation method.

Comment 21

[David :Bienvenu]

in general, it's not certain that a uid validity change would go hand in hand
with an expunge. In other words, uid validity could change without a
corresponding expunge, so your suggestion wouldn't handle that case.

Comment 22

[Doug Ledford]

Yes, that's what my comment in entry #20 was all about.  You have to invalidate
on uid validity change, you *could* invalidate on expunge as well, but it would
just be an optimization to avoid a uid validity check (if you wanted to really
optimize it you could make it invalidate on expunge only when expunging the last
message in the folder and you could make it only invalidate the uids from the
new top uid number to the old top uid number, but that's a bit much considering
I don't know if other imap servers besides the washu server happen to treats
uids the same as the washu server).

In retrospect, I'm pretty positive that this exact bug is why I could never use
the "Remove it immediately" option for how to handle item deletion on imap
servers because it made this bug show up much, much faster.

Comment 23

[David :Bienvenu]

most imap servers almost never roll uid validity.

Comment 24

[Doug Ledford]

It is interesting to note that rfc2683 says:
   We do not know of, nor do we anticipate the future existance of, a
   server that changes UIDVALIDITY while there are existing messages,
   but clients must be prepared to handle this eventuality.

It is more interesting to note that rfc2060 says:
   The unique identifier of a message MUST NOT change during the
   session, and SHOULD NOT change between sessions.  However, if it is
   not possible to preserve the unique identifier of a message in a
   subsequent session, each subsequent session MUST have a new unique
   identifier validity value that is larger than any that was used
   previously.

When you combine the note from rfc2060 with the imap log I posted, the washu
imap server *did* violate rfc2060 by giving 3 different uidvalidity numbers for
the same mailbox that were not sequentially increasing.  In general, the washu
imap server's handling of uid values is *very* bad for performance because it
requires the client blow away *all* message caches after every expunge event
that deletes the top message in the file and after every close/open cycle (it
assigns a new uidvalidity value based upon current time each time you open a
mailbox).  So, while mozilla should handle this properly, I'm also going to be
filing a couple reports with the washu imap team about this poor behaviour.  It
might be acceptable if the washu imap server didn't maintain a status entry in
the imap file where it could store the next uid value between sessions, but
since the server already *does* store such a fake status message at the
beginning of the inbox, there is absolutely *no* reason they can't make uid
numbers monotonically increasing regardless of expunges and make the uidvalidity
constant between mailbox creations.

Comment 25

[Doug Ledford]

Red Hat Linux (as of 8.0) shipped with version 2001a of the WashU imap server. 
There is a bug in that version of the server that causes excessive UIDVALIDITY
changes.  I've built version 2002b of the WashU imap server and tested it on my
personal mail server and it greatly reduces the number of validity changes.  I
will try to push that on through the normal update process, but that may take a
while since there isn't a security issue involved.  If that goes through, then
it will reduce the severity of the mozilla bug, but I do still think it needs
fixed ;-)

Comment 26

[David :Bienvenu]

*** Bug 204590 has been marked as a duplicate of this bug. ***

Comment 27

[Jason Rumney]

Doug,

You are reading RFC2060 wrong. UW-IMAP is not violating it, as the uid's of 
individual messages ARE being maintained between sessions, so the following 
clause does not hold.

Why is this taking so long to fix BTW? It is a serious bug which makes Mozilla 
unusable with UW-IMAP, which has a significant installed base. The fix 
(clearing the message cache on uidvalidity change) was identified 9 months ago.

Comment 28

[David :Bienvenu]

Attachment: preparation for the fix

this code makes it so we can get the uid validity from the folder sink, which
we will eventually use for the cache key (everything's done except that last
part). I moved the uid validity code from the miscellaneous sink to the imap
mail folder sink.

Comment 29

[David :Bienvenu]

Attachment: proposed fix

stick the uid validity in front of the url spec, so instead of imap://..., it
will be something like 303038383imap://...

Comment 30

[(not reading, please use [e-mail] instead)]

Comment on attachment 126656 [details] [diff] [review]
proposed fix

r/sr=sspitzer, david tells me, over aim, that he is using base 16 for less
bytes.

Comment 31

[David :Bienvenu]

fix checked in to 1.5 trunk.

Comment 32

[David :Bienvenu]

*** Bug 199382 has been marked as a duplicate of this bug. ***

Comment 33

[Henrik Gemal]

*** Bug 151680 has been marked as a duplicate of this bug. ***