389006 - POP3 mail filters misfiltering incoming emails

Status: RESOLVED DUPLICATE of bug 457168

(MailNews Core :: Filters, defect)

Description

[Nelson Bolyard (seldom reads bugmail)]

Attachment: mismatched email

Gecko/200707100303 SeaMonkey/2.0a1pre

This bug is split off from bug 382051, which has been reduced in scope 
to only IMAP filter errors.

Frequently, incoming POP3 messages are misfiled.  A recent example (today):
A BMO bug mail message from the bugzilla demon to me matched a filter that
looks for messages sent To: a mailing list that I'm on.  

The filter log entry said:

Applied filter "To [e-mail]" to message from [e-mail] - [Bug 306907] Build libsqlite as a standard 
name separate shared library. at 2007-07-19 18:27:05 moved message id = [e-mail] to mailbox://[e-mail]/Professional/nssdev 

That filter contains this:

name="To [e-mail]"
enabled="yes"
type="1"
action="Move to folder"
actionValue="mailbox://[e-mail]/Professional/nssdev"
condition="OR (to or cc,contains,nssdev)"

The message wsa sent To: [e-mail] and there was no CC.
I will attach the message.

This apparently began sometime just before the SM project stopped making 
SM 1.5a and began making SM 2.0a1pre.

I an supply the entire msgFilterRules.dat file but I don't want it publicly
available.

Comment 1

[David :Bienvenu]

yes, I guess privately sending me the msgFilterRules.dat file might be helpful.

I have a fair number of pop3 to or cc contains filters, and I haven't seen a single instance of them mis-firing.

Comment 2

[Nelson Bolyard (seldom reads bugmail)]

happened again today, using 20070810 trunk build

Comment 3

[Nelson Bolyard (seldom reads bugmail)]

Happened again today.  In both of the last two instances, the false match
is always on the filter shown in comment 0.  The misfiltered message did
not contain the string nssdev anywhere in headers or body.

I observe that the message in the filter log, immediately before (above) 
the one that was misfiltered, also matched (albeit correctly) that same 
filter.  This makes me wonder if there is perhaps some problem inthe code
whereby some error in matching a message to any filter can cause it to be filtered as if it matched the filter rule used by the previous message.  

Comment 4

[Nelson Bolyard (seldom reads bugmail)]

I just received the bugzilla email for comment 3 above, and it was 
misfiltered.  It was falsely matched against another rule (not the same
one shown above in comment 0), and it was the same rule as the immediately
preceeding received email, which was correctly filtered.  So, I think I'm 
seeing a pattern here, where misfiltered bugs get treated as if they matched
the same rule as the immediately preceding mail matched.

Again, this is for POP3.

Comment 5

[Nelson Bolyard (seldom reads bugmail)]

More observations about this misfiltering.  

I have two WinXP PCs running SM trunk.  
One is running the last of the SM 1.5a1 builds from 20070527.
The other is running very current SM 2.0a1pre builds, updated ~weekly.

Both systems read incoming mail messages from the same POP3 server 
(leaving messages on the server).  So they both tend to process the same
incoming stream of email messages.

Both systems tend to misfile the same messages!  A message misfiled on one
is likely to also be misfiled on the other.  However, their filter log 
messages tend to be quite different.  

The newer SM 2.0a1pre code tends to log the name of the filter that 
corresponds to the folder into which the message was actually moved, making 
it appear to be a false match on that filter rule, but making it appear 
that the message was filed properly in accordance with that mismatched 
filter rule.

The older SM 1.5a tends to log the expected filter rule name and the 
expected folder name for that filter, making it appear to have correctly 
matched on the right filter, but appearing to have been filed in the 
wrong folder for that filter, filed in a different folder than the one 
named in the logged rule.  

But despite these logging differences, the result is the same.  The message
gets moved to the wrong folder.  

This suggests to me that, perhaps, the code bug that causes the misfiltering 
is actually the same bug in both versions, but that the logging has changed 
somehow.

Comment 6

[WADA:World Anti-bad-Duping Agency]

(In reply to comment #5)
Nelson, do you have rule of "move to Inbox"? In what order related filter rules are defined? 

During test for Bug 232569(problem when mail is already held in move target), I observed funny phenomenon(looks to be false negative) after hit of rule on CC.  See Result-3 of Bug 232569 Comment #8.
If "move to Inbox" is used to keep a mail in Inbox, similar phenomenon to my Result-3 may occur.
And, if "filer not stop firing after move to folder" remains when POP3, same situation as my Case-3/Result-3 can occur.

Comment 7

[WADA:World Anti-bad-Duping Agency]

Please see Bug 393668 for problem of Result-3 of Bug 232569 Comment #8.

Comment 8

[Nelson Bolyard (seldom reads bugmail)]

Wada,  
No, in my SM2.0a1pre profile, my POP3 accounts have no "move to inbox" rules.

Comment 9

[WADA:World Anti-bad-Duping Agency]

Is there filter rule which moves mail from [e-mail] to folder?
Is there something wrong in mail for which "To [e-mail]" correctly fired before mis-firing for mail from bugzilla?
(e.g. No Message-Id: header, Malformed mail header, ...)

Comment 10

[Nelson Bolyard (seldom reads bugmail)]

Wada: I have 105 rules.  
The mozilla-nssdev rule is number 28.
The bugzilla-daemon rule is number 60. 
I am not aware of any defect in the misfiltered rules.  
One example misfiltered email is attached to this bug for your inspection.

Comment 11

[Nelson Bolyard (seldom reads bugmail)]

Any clues?  This continues to happen daily.

Comment 12

[Nelson Bolyard (seldom reads bugmail)]

This happened again today.  Two messages arrived, one was filtered correctly.  
The message immediately after it was misfiltered.  It was falsely found to 
have matched the same filter as the message immediate before it (the first of 
the two, which was correctly filtered).  This begs the question:  Is there
some path through the message filtration code whereby the attempt to find
a matching filter fails (perhaps due to memory allocation failure), and so 
the filter that was found for the previous email is used instead of the 
correct filter?  

Here are two lines from my filter log. It shows both messages having matched
the same filter, even though the second message did NOT match that filter.

Applied filter "To [e-mail]" to message from Bob Lord <[e-mail]> - Using TLS to track Firefox users at 2007-09-17 09:58:54 moved message id = [e-mail] to mailbox://[e-mail]/Professional/mozilla-security

Applied filter "To [e-mail]" to message from [e-mail] - [Bug 327181] Improve error reporting for invalid-certificate errors ( error page for https, or combined dialog) at 2007-09-17 10:27:14 moved message id = [e-mail] to mailbox://[e-mail]/Professional/mozilla-security 

Comment 13

[WADA:World Anti-bad-Duping Agency]

Mis-filtered mail sounds to be always mail from bugzilla-daemon, but not all mail from bugzilla-daemon. When something special in mail from bugzilla-daemon?
 1. Multi-line subject is seen in some mails from bugzilla-daemon
 2. Mail header with no parameter is seen in some mails from bugzilla-daemon
    e.g. X-Bugzilla-Keywords:
Is there any obvious difference between mis-filtered mail from bugzilla and properly filtered mail from bugzilla?
      

Comment 14

[David :Bienvenu]

No, it's unlikely that this has to do with the filter code getting confused about which filter it is executing/applying. It seems more likely that the filter execution code is confused about which *message* it is trying to apply the current set of filters to - if, for example, when evaluating the search criteria, we somehow were looking at the contents of the previous message, or at the previous message's msgHdr, then that would explain why the same filter was firing.

But we seem to have the right msg hdr when we write out the filter log entry, and when moving the message to the filter target. So I really don't know...

Do you have message quarantining turned on (tools | options | privacy | anti-virus) ? Do you have any virus checkers installed? Are you sure that in these cases the two messages arrived and were filtered without any unfiltered messages in between?

Comment 15

[Nelson Bolyard (seldom reads bugmail)]

Over 50% of the email I receive every day is from bugzilla-daemon, so I 
suspect the reason that most misfiled emails are from bugzilla-daemon is 
simply because most emails are from bugzilla-daemon.  

Is anything special about the misfiled emails?  
I don't know of anything special, but I did attach one to this bug.
I could attach others if you wish.

I experience this problem on two systems.  One has antivirus, one does not.
What's the pref name for the quarantining feature you described?
I believe that ALL my incoming messages get filtered, so yes, I'm pretty sure
that no unfiltered messages occur between the one that gets correctly 
filtered and the one immediately following that gets misfiltered.

Comment 16

[David :Bienvenu]

mailnews.downloadToTempFile - it's false by default, so I doubt you've got it set.

Comment 17

[Nelson Bolyard (seldom reads bugmail)]

I guess SM doesn't have that pref.  Doesn't appear in about:config.
Is it very new?

Comment 18

[David :Bienvenu]

it's not in mailnews.js, I guess, but you don't have it set, I'm sure, and the code initializes it to false.

Comment 19

[LYNN ACKERMAN]

I'm not sure it's a filter problem but I am not receiving any emails that are being sent from outside url's

Comment 20

[Nelson Bolyard (seldom reads bugmail)]

This problem persists.  
Two messages come in, from different sources, to different destination 
addresses.  The first one is correctly filtered.  The second one is 
falsely matched to the same filter as the first one, and so is misfiled.  
The particular filter (the correct match for the first of the two messages)
varies (of course).  

Comment 21

[Mike Schroepfer]

Per discussion in m.d.a.seamonkey minusing this for 1.9 - if it is a core bug and seamonkey or tbird need this in the 1.9 timeframe please do re-nominate.

Comment 22

[WADA:World Anti-bad-Duping Agency]

To Nelson Bolyard(bug opener):
Do you define rule with customized "Sender"(rule for Sender: header only)?
If yes, see Bug 404489 Comment #6.

Comment 23

[Nelson Bolyard (seldom reads bugmail)]

No, I have no filters on sender

This bug persists

Comment 24

[Nelson Bolyard (seldom reads bugmail)]

This goes on continually.  Every day I find one or more emails filed in 
the wrong folder, usually bug mails from b.m.o (which are the majority of 
emails I received each day).

Comment 25

[Wayne Mery (:wsmwk)]

perhaps something applicable in http://tinyurl.com/687jua

Comment 26

[Nelson Bolyard (seldom reads bugmail)]

Pretty please, with $200 USD (or some other sugar) on top, can someone fix
this?

Here's the latest example.  Today I received two messages from my POP 
server in the same download.  The filter log shows:

> Applied filter "To [e-mail]" to message from Kai Engert 
> <[e-mail]> - Ubuntu's Alexander Sack's comment on NSS .so names 
> at 2008-08-06 11:51:42 moved message id = [e-mail] to 
> mailbox://[e-mail]/Professional/nssdev

> Applied filter "To [e-mail]" to message from Nelson B 
> Bolyard <[e-mail]> - More pk12util questions at 2008-08-06 
> 12:00:47 moved message id = [e-mail] to 
> mailbox://[e-mail]/Professional/nssdev 

The same filter was applied to both messages.  Trouble is: it was not a 
match for the second message.  The filter catches mail that is sent To 
[e-mail], which the first message was, but the second 
message was NOT.  SO, the message wound up in the wrong folder.  

This happens daily.  I only complain once in a while. :)

Comment 27

[Mark Banner (:standard8)]

David, I had a brief look at the code and tried to replicate this using a unit test, but I couldn't.

Is there any place we're likely to be getting something wrong. Comment 26 would likely point to an uninitialised variable but I couldn't see one in the search code. Could it be somewhere in the pop/message copy code?

Comment 28

[David :Bienvenu]

I've looked through the code a lot looking to see what could be going wrong, and I couldn't find anything like that. I also use pop3 filters heavily, and I've never seen a mis-filtered message.

The problem has to be occurring before the pop message copy code, since the filter log is saying that the wrong filter was applied. So it would have to be in the filter evaluation step, I think. Everything is synchronous once we get to applying the filters, so it can't be a race condition or anything like that.

Perhaps we could add an other level or type (NSPR?) of logging to give more detail about the process.

Comment 29

[Dan Mosedale (:dmosedale, :dmose)]

As much as this bug is unpleasant, until someone other than reporter can actually reproduce it, I don't think we can afford to block on it.  :-(

Comment 30

[Dan Mosedale (:dmosedale, :dmose)]

Added the qawanted bug in the hopes that someone can create a reproducible test case.

Comment 31

[Nelson Bolyard (seldom reads bugmail)]

I suggest you create a debug build that does logging of some kind, and let me
run it.  Is the mail/news code in its own shared library?  If so, you might
get away with just doing a special build of that library.  You might even 
throw some logging onto the trunk for a few days. :) I'm running SM trunk.

Comment 32

[Nelson Bolyard (seldom reads bugmail)]

I've got two systems with SM that read email from the same POP server, and
have approximately the same folders and approximately the same mail filters.
This means that I download all my mail twice, once on each system.  
(Yeah, I know, IMAP is the answer)

I've discovered that when one system experiences this misfiltering error,
it is highly likely that the other system will misfilter the same email 
message in the same way.  In other words, this behavior seems deterministic,
and it is effectively predictable.  That is, after experiencing it on one
system, I can predict pretty accurately that it will happen on the other.

(I could do the same with two profiles on the same system, I suppose.)

Now, I'm thinking that it should be possible to run this email client in
a debugger, and debug the problem when I know it's about to happen.  
I've got a great source code debugger that works on nightly builds, and 
I'm tenacious about debugging.  But I'm not very familiar with the mailnews 
code.  It would help if I knew the names of functions (and/or lines of code) 
that meet any of these criteria:
a) is the place where the filtering starts
b) is the place where the filter action(s) are decided and initiated
c) is the place where the filtering gets logged 
d) is the place where the action of moving the message to a folder occurs.  

(I wish I had noticed this before SM Trunk moved to Hg :(

Comment 33

[Kent James (:rkent)]

(In reply to comment #32)

> It would help if I knew the names of functions (and/or lines of code) 
> that meet any of these criteria:
> a) is the place where the filtering starts

Try
  rv = listener->ApplyFilterHit(filter, msgWindow, &applyMore);

at http://mxr.mozilla.org/mozilla/source/mailnews/base/search/src/nsMsgFilterList.cpp#360

This is after the search has succeeded. That will get you into:

  nsMsgFilterList::ApplyFiltersToHdr

where most of the action takes place.

Comment 34

[David :Bienvenu]

In particular, nsMsgFilterList::ApplyFiltersToHdr, which calls nsMsgFilter::MatchHdr, which calls nsMsgSearchOfflineMail::MatchTermsForFilter, where we evaluate the filter criteria. If the problem is that the filter criteria are getting evaluated incorrectly, then the problem should be in there. If the wrong filter is getting applied, but not because the criteria evaluation is wrong, that would be in nsParseMailbox.cpp, ApplyFilterHit (for pop3)

Comment 35

[Nelson Bolyard (seldom reads bugmail)]

Bug 453385 is a repeatable example of a message that repeatedly fails to 
match a filter that it should match.

Now, I have examples of some emails that repeatedly are found to match a 
filter that they should not.  They match a wrong filter, and get put into 
the wrong folder.  If I move them back to the inbox, and apply filters to 
folder, they go right back to the wrong folder, again.  
Completely repeatable.   I'm going to try restarting SM to see if that 
fixes it.  Maybe it's memory corruption.  

This is driving me mad.  It really upsets me to see little UI tweaks being
made to mailnews, when really important foundational functionality like this
just isn't working right and remains unfixed.

Comment 36

[David :Bienvenu]

You have a reproducible case? Let's debug it sometime. Just ping me.

Comment 37

[David :Bienvenu]

resolving as a dup of bug where patch was attached. Thx for helping diagnose this, Nelson.