Closed Bug 695671 Opened 8 years ago Closed 5 years ago

Filtering stops -- Only 1 filter executes for "Run Filters on Folder" (after execution of action="Delete", further/different actions on other mails is not executed and filter log is not written to filterlog.html).

Categories

(MailNews Core :: Filters, defect, major)

defect
Not set
major

Tracking

(Not tracked)

RESOLVED FIXED
Thunderbird 37.0

People

(Reporter: vng, Assigned: rkent)

References

(Depends on 3 open bugs, Blocks 2 open bugs)

Details

(Keywords: memory-leak, Whiteboard: [filterfails])

Attachments

(3 files, 10 obsolete files)

I have 3 message filters, and only one of them seems to execute when I use the "Run Filters on Folder" selection in the tools menu.

I can reproduce this *only* on new messages coming in.  If I move messages back to my inbox, untag the messages, retag the messages and hit "Run Filters on Folder" - everything works.

Nothing important shows up in the error console.
sorry - missed a detail.  when i click "Run Filters on Folder", my inbox still has the "Archive" tagged emails.  The mails tagged as 'delete' do get processed, but i need to run twice to get my 'archive' emails to get filed away.
Anything in the filter log ?
Component: General → Filters
Product: Thunderbird → MailNews Core
QA Contact: general → filters
The filter log shows up empty when I first go to view it.  If I switch folders from Inbox to my archive folder, then open up the filter log, it looks like just one of the filters (the delete filter) has executed.

Is there a way I can export the filter log to a file so that I can attach it to this bug?
Not that I know of.
The filter log is stored in a file filterlog.html in the filesystem folder where TB stores your emails are stored.

And the 'gloda' error seems important. Does it appear after you run the filters for the first time?

Also, what is your account type? POP or IMAP?
(In reply to Victor Ng [:vng] [:crankycoder] from comment #3)
> it looks like just one of the filters (the delete filter) has executed.

Bug 541416?
(In reply to Victor Ng [:vng] [:crankycoder] from comment #0)
> Screenshot of all my filter options and error console output

It was not Bug 541416. Sorry.

msgFilterRules.dat content was re-generated from screen shot.
(because # is used in folder name, "#services-dev" is hashed)
> name="#services-dev"
> enabled="yes"
> type="17"
> action="Move to folder"
> actionValue="mailbox://nobody@Local%20Folders/c0aa4f06"
> condition="AND (to or cc,contains,services-dev@mozilla.org)"
>
> name="Delete Tagged"
> enabled="yes"
> type="17"
> action="Delete"
> condition="AND (tag,contains,delete)"
>
> name="Archive"
> enabled="yes"
> type="17"
> action="Move to folder"
> actionValue="mailbox://nobody@Local%20Folders/archive"
> condition="AND (tag,contains,archive)"

Tag definition in prefs.js.
> user_pref("mailnews.tags.archive.tag", "Archive");
> user_pref("mailnews.tags.delete.tag", "Delete");

(In reply to Victor Ng [:vng] [:crankycoder] from comment #1)
> when i click "Run Filters on Folder", my inbox still has the "Archive" tagged emails.
> The mails tagged as 'delete' do get processed, but i need to run twice to get my 'archive' emails to get filed away.

Confirmed with Tb 9.0.1, with local mail folder(dummy POP3 account).

Workaround, if only one filter rule of action="Delete" is defined:
  Move filter name="Delete Tagged" under filter name="Archive"
  (move filter of action="Delete" to bottom of filter rules)
If multiple rules of action="Delete" are defined, only first one is effective in single run of "Run Filters on Folder".

(In reply to Victor Ng [:vng] [:crankycoder] from comment #3)
> The filter log shows up empty when I first go to view it.

Confirmed too. It looks next.
  If action="Delete" is executed, filter log is not written to log file,
  and it seems kept in memory, and written to log file upon next succsessful run.

Another problem was observed.

When I tested "Run Filters on Folder" just after restart of Tb, this bug was reproduced, and following error was not observed.
However, when I moved a mail from a local mail folder to other local mail folder, following error occurred.
> Error: aFolder is undefined
> Source File: chrome://messenger/content/folderWidgets.xml
> Line: 691
Once this error occurred, two above errors was shown in Error Console upon each move of mail, and three above errors was shown in Error Console upon each delete of mail.
And, this error was observed also upon each "Run Filters on Folder" test for this bug.
Summary: Only 1 message filter seems to execute when I hit "Run Filters on Folder" → Only 1 message filter seems to execute when I hit "Run Filters on Folder" (after execution of action="Delete", further action is not executed and filter log is not written to log file)
"Filter log is not written after action=Delete" seems old problem.
See bug 307540 comment #3.
FYI.
Order of message filter actions. "Delete" and "MoveToFolder" is in same order, because "Delete"=="Move to Trash folder" unless IMAP delete model of "Just mark it as deleted" or "Remove immediately".
> http://mxr.mozilla.org/comm-central/source/mailnews/base/search/src/nsMsgFilter.cpp?force=1#317
> 317 // The order of actions returned by this method:
> 318 //   index    action(s)
> 319 //  -------   ---------
> 320 //     0      FetchBodyFromPop3Server
> 321 //    1..n    all other 'normal' actions, in their original order
> 322 //  n+1..m    CopyToFolder
> 323 //    m+1     MoveToFolder or Delete
> 324 //    m+2     StopExecution
(In reply to WADA from comment #7)
> When I tested "Run Filters on Folder" just after restart of Tb, this bug was
> reproduced, and following error was not observed.
> However, when I moved a mail from a local mail folder to other local mail
> folder, following error occurred.
> > Error: aFolder is undefined
> > Source File: chrome://messenger/content/folderWidgets.xml
> > Line: 691
> Once this error occurred, two above errors was shown in Error Console upon
> each move of mail, and three above errors was shown in Error Console upon
> each delete of mail.
> And, this error was observed also upon each "Run Filters on Folder" test for
> this bug.

This message is bug 670976. It is not yet known if it causes any problems or not.
Whiteboard: [filterfails]
This bug is still observed in Tb 11.0.1.

(1) filterlog.html size and content when filter is executed after clear log.
(filter rule name which executes delete = Delete if Subject ends with: -003)
file size of filterlog.html = 8192 bytes (4KB or 8KB buffer is used?)
bottom part of of filterlog.html
([LF]=0x0A, [EndOfFile]=End of file=Nothing exists here after)  
> <p>[LF]
> Applied filter &quot;Delete if Subject ends with: -003&quot; to message from soarex soarex &lt;soarex@ops.dti.ne.jp&gt; - Y-Test-003 at 2012/04/03 07:14:57[LF]
> deleted[LF]
> </p>[LF]
> <p>[LF]
> Applied filter &quot;Delete if S[EndOfFile]

(2) filterlog.html size and content after termination of Tb.
file size of filterlog.html = 11088 bytes
filterlog.html is fully written.
Needless to say, "log for action like Move to Folder of other messages by other rule after the rule with Delete" doesn't exist in filterlog.html due to this bug.
I can confirm there is a problem with the "Stop filter execution". After a filter containing it is applied on some messages, other filter that could match other messages are not executed.
On the other hand, selecting all the same messages in the folder (Ctrl-A) using "Run filters on message" does work fine. So let's find out what is the difference between these methods.
It looks like nsMsgApplyFiltersToMessages::RunNextFilter() has nice logic how to handle messages that got hit by "stop filter execution".

I can't see anything like that in nsMsgFilterAfterTheFact::RunNextFilter() and 
nsMsgFilterAfterTheFact::OnSearchDone(). I am not sure why Apply to Folder and Apply to Messages use wildly different codepaths. There surely is a reason but the functionality should not diverge.

Well, I said in comment 13 that "Run filters on message" works, but that is not always the case.
It looks like "Run filters on message" does not work OK if the second filter is Mark as read (or unread). It does work with e.g. Add Tag.

David, I think you changed these two actions recently.
(In reply to :aceman from comment #15)
> It looks like "Run filters on message" does not work OK if the second filter
> is Mark as read (or unread). It does work with e.g. Add Tag.
> 
> David, I think you changed these two actions recently.

I doubt I changed them in any way that would affect execution.
(In reply to Victor Ng [:vng] [:crankycoder] from comment #0)
> If I move messages back to my inbox, (snip) and hit "Run Filters on Folder" - everything works.

This part is perhaps bug 393668.
Summary: Only 1 message filter seems to execute when I hit "Run Filters on Folder" (after execution of action="Delete", further action is not executed and filter log is not written to log file) → Only 1 message filter seems to execute when I hit "Run Filters on Folder" (after execution of action="Delete", further/different action on other mails is not executed and filter log is not written to filterlog.html)
OS: Mac OS X → All
(In reply to David :Bienvenu from comment #16)
> (In reply to :aceman from comment #15)
> > It looks like "Run filters on message" does not work OK if the second filter
> > is Mark as read (or unread). It does work with e.g. Add Tag.
> > 
> > David, I think you changed these two actions recently.
> I doubt I changed them in any way that would affect execution.

I think you did something to them when the msgs are downloaded from POP3. Here we use the action on already downloaded msgs (filterAfterTheFact). Maybe this also needs the same fix?
(In reply to :aceman from comment #15)
> It looks like "Run filters on message" does not work OK if the second filter
> is Mark as read (or unread). It does work with e.g. Add Tag.

What phenomeno do you call "not work OK" on "Mark as read (or unread)"?
If you are talking about "Unread" column display and "Status" column display, and it's following phenomenon, it's also observed in Tb 3.0b3pre.
> Mozilla/5.0 (Windows; U; Windows NT 5.1; en-US; rv:1.9.1.1pre) Gecko/20090701 Shredder/3.0b3pre
                                     
Unread/Read bit in X-Mozilla-Status:   Read column  Unread column  Status column
 O (==Unread)                          Unread-mark  blank          blank
                                       (bolded)
 1 (==Read)                            Read-mark    blank          Read

For "correct update of X-Mozilla-Status: and X-Mozilla-Keys: header by filter upon download", fix of bug 746371 is needed. Check with newest builds and check with Read column, please.
I am working with the newest trunk (TB14a1), which should have patch from bug 746371. But as I said this is not "upon download". This is "Run filters on message" so messages are already old (downloaded in the past from POP3.

I have checked solely by seeing messages not changing from bold to normal and back as they should after applying Read/Unread.

I also instrumented the code (debug printfs) so I see what filters/actions are run on how many messages. That log seems correct when using "Run filters on message". Just that it looks like the flags are not applied correctly.
But I will try to look at the X-Mozilla-Status headers too, good idea.
(In reply to :aceman from comment #18)
> (In reply to David :Bienvenu from comment #16)
> > (In reply to :aceman from comment #15)
> > > It looks like "Run filters on message" does not work OK if the second filter
> > > is Mark as read (or unread). It does work with e.g. Add Tag.
> > > 
> > > David, I think you changed these two actions recently.
> > I doubt I changed them in any way that would affect execution.
> 
> I think you did something to them when the msgs are downloaded from POP3.
> Here we use the action on already downloaded msgs (filterAfterTheFact).
> Maybe this also needs the same fix?

That change has nothing to do with whether filters stop or continue execution, and the filter after the fact code was already going through the folder object to do the actions, so it didn't need the same fix.
I have this problem also.
Has there been progress in fixing this?
Current order of action.
> //    m+1     MoveToFolder or Delete
> //    m+2     StopExecution
If definition of "Order of action" is changed to as follows, "interfere of Move actions by first executed Delete" part is easily avoided.
> //    m+1     MoveToFolder
> //    m+2     Delete
> //    m+3     StopExecution
Outstanding issue is; First executed Delete itereferes other Delete's and StopExecution.
aceman, might it be possible to put this near top of heap for fixing. I suspect in many cases it (manual run not working) prevents triagers from testing, so it is a key issue. Unless you think a different filter bug needs targeting to fix manual run failures.
Severity: normal → major
Flags: needinfo?(acelists)
Attached image filtered folder
next - I'm having mental difficulty sorting out which bug(s) I am seeing. It might be this bug, or another - perhaps even multiple

I created a filter with several bug numbers, with actions move message to (a new moz-gmNmaild) folder on same imap account and stop execution, manual run did not work. I removed stop execution and still did not work. I put a single bug# in a filter and it worked.

I also see the following:
- moz-gmNmaild.msf file in the profile but no moz-gmNmaild file. I have no trouble viewing them in the new folder. But wth are the message being stored?
- a one point after several attempts at manual filter run, moz-gmNmaild looks like the attached.
Sorry, I have no clues yet how to debug/fix the problem here. This probably needs rkent to look at the filter internals whether the (imlicit) "Stop filter execution" is used correctly, as there are several bugs reported about it.
Flags: needinfo?(acelists)
rkent, ref comment #24, comment 27
Flags: needinfo?(kent)
From the reports it looks like in some cases the stop filter execution does not only affect the particular message where it matches, but affects all other messages, i.e. filters are stopped globally. But I couldn't find any bug just by reading the code.
After log write to buffer,
> https://mxr.mozilla.org/comm-central/source/mailnews/base/search/src/nsMsgFilterService.cpp#472
472               (void)m_curFilter->LogRuleHit(filterAction, msgHdr);
> 
Filter executes "Delete" action. Following is comment in source.
https://mxr.mozilla.org/comm-central/source/mailnews/base/search/src/nsMsgFilterService.cpp#480
> 480       case nsMsgFilterAction::Delete:
> 481         // we can't pass ourselves in as a copy service listener because the copy service
> 482         // listener won't get called in several situations (e.g., the delete model is imap delete)
> 483         // and we rely on the listener getting called to continue the filter application.
> 484         // This means we're going to end up firing off the delete, and then subsequently
> 485         // issuing a search for the next filter, which will block until the delete finishes.
Set Processing flag is FilterToMove, and is same as "MoveToFolder"/"CopytoFolder".
> m_curFolder->OrProcessingFlags(m_searchHits[i]
,nsMsgProcessingFlags::FilterToMove);
Because even "log buffer flush" is not executed after "Delete" is executed, perhaps nothing is done here after.
It may be;
  Because "copy service listener" is not registered,
  no event which trigers next step happens, then nothing is executed.

Following changes will reduce impact.
(1) Separate "Delete" from "MoveToFolder" by priority change.
    CopyToFolder > Delete==MoveToFolder  > StopExcution.
    CopyToFolder > MoveToFolder > Delete > StopExcution 
    By this change, even if bug occurs, "not executed" is "Delete" and
    "Stop Execution" only, so impact is far smaller than current.
(2) If local message folder, or IMAP folder with "Move to trash" model,
    do "Move to Trash folder" when action==Delete.
    By this change, problem occurs only when "Delete" is executd at
    IMAP folder with "Remove immediately" and "Just mark it as deleted".
By any change, there is no imact for user and other components, because (1) is merely execution order change in filter, and (2) is same as workaround by user.
If similar process to MoveToFilter is hard for Delete(register listner is hard when IMAP), "utilize msgPurge as done by Retension Policy" may be a solution.
See bug 765514 comment #14 for "delete request by Retension Policy", "delete by msgPurge", and "removal of offline-store file data by Compact".
As for "delete from server", this is similar to "delete from POP3 server".
  set "d" for UIDL in popstate.dat, then DELE is issued upon next login
I seem to vaguely recall from the days that I was more heavily involved in filter code, looking at the handling of Stop Execution in after-the-fact filters and saying to myself, "yeah that's not right". Let me look at this some more.
Flags: needinfo?(kent)
Attached patch WIP v1 (obsolete) — Splinter Review
This seems to work, but I want to tweak it some more before I ask for review.

There are a number of issues that I am addressing here:

1) It was not clear how the multiple folder case was handled. I decided to sweep through the filter lists for each folder.

2) The biggest issue was the combination of issues whether to continue to continue to apply filters on a folder, and the related issue of waiting for an async operation to proceed before continuing. I've fixed that by explicitly propagating a flag of whether and async listener will continue the filter actions.
 
3) I also cleaned up the handling of errors a bit, but there are still lots of inconsistencies. This would be so much easier to do if mailnews reviewers would accept my standard do {} while false; construction for breaking on error.

Note to self: you deleted the removal of headers when applyMore is false, try to understand why that was needed in the first place.
Assignee: nobody → kent
Status: NEW → ASSIGNED
Duplicate of this bug: 754635
Attached patch version 2, no white space diff (obsolete) — Splinter Review
Attachment #733706 - Attachment is obsolete: true
Attached patch version 2 (obsolete) — Splinter Review
This is a fairly extensive rewrite of error management for nsMsgFilterAfterTheFact.

That routine is increasing in importance as we start to consider adding additional filter contexts, for example OnArchive or OnSend. I wanted to clean up a number of issues in that method, mostly involving inconsistencies that have crept in over the years.

Main changes:

1) The error management philosophy is changed so that filters try to continue if at all reasonably possible after a failure. This is also important given that a premature exit becomes a memory leak given the manual Release() model.

2) Many errors that were just skipped now call NS_WARNING() so that we can at least see those issues in development. Every reasonable check I could do was added, so hopefully we'll see a few crashers disappear (though any rework like this usually introduces a few new issues as regressions).

3) There is better explicit handling now of cases where the filtering is done in the background, which is signaled by passing a null window.

4) Processing flags are used consistently as a way to communicate between calls that a message should not be further filtering, eliminating the confusing "applyMore" parameter which was at the root of the symptoms of this bug.

5) It was not clear to me that the multiple folder case worked at all in the old method. I believe it should work now in the backend, though needs FE work to actually really work. (Try selecting multiple folders in the folderPane, then do "Run Filters On Folder", it only does one folder.

6) I added unit tests that exercise most of the filter actions.

7) More consistent management of state should help custom filter actions, for example bug 754635
Attachment #735256 - Flags: review?(neil)
Rkent, many thanks for working on this. Let's hope this makes filters much more robust.
Hardware: x86 → All
Blocks: 479823
Comment on attachment 735256 [details] [diff] [review]
version 2

There are a couple of issues I've discovered with this in my work on bug 479823, so I am going to remove the review request for now until I resolve them.
Attachment #735256 - Flags: review?(neil)
Attached patch Fix next action increment bug (obsolete) — Splinter Review
So the change is pretty small, just an error in where I did an increment.
Attachment #735253 - Attachment is obsolete: true
Attachment #735256 - Attachment is obsolete: true
Attachment #739846 - Flags: review?(neil)
Any chance of getting a review on this soon? In addition to the problem of the current bug, I have two new filter features on hold waiting for this review.
Flags: needinfo?(neil)
Sorry, I have been a little busier than usual lately and my review queue has not been seeing as much action as a result...
Flags: needinfo?(neil)
Blocks: 864187
Comment on attachment 739846 [details] [diff] [review]
Fix next action increment bug

Good news, I'm catching up with my review queue! Only almost 4 months late...

>+#define BREAK_IF_FAILURE(_rv, _text) if (NS_FAILED(_rv)) {NS_WARNING(_text); break;}
>+#define CONTINUE_IF_FAILURE(_rv, _text) if (NS_FAILED(_rv)) {NS_WARNING(_text); continue;}
>+#define BREAK_IF_FALSE(_assertTrue, _text) if (!(_assertTrue)) {NS_WARNING(_text); break;}
>+#define CONTINUE_IF_FALSE(_assertTrue, _text) if (!(_assertTrue)) {NS_WARNING(_text); continue;}
(In theory these should make the flow of control easier to understand, but for some reason it's not working for me as well as I feel it should. At least you got rid of that confusing applyMore flag.)

>+  if (NS_FAILED(rv))
>+    NS_WARNING("Search failed");
I would prefer NS_WARN_IF_FALSE(NS_FAILED(rv), "Search failed");
(I think this may occur in other places too.)

>-  bool continueExecution = NS_SUCCEEDED(aExitCode);
>+  bool continueExecution = m_msgWindow ? NS_SUCCEEDED(aExitCode) : true;
>   if (!continueExecution)
>     continueExecution = ContinueExecutionPrompt();
> 
>-  return (continueExecution) ? RunNextFilter() : OnEndExecution(aExitCode);
>+  if (!continueExecution)
>+    // a folder parse failed, and the user asked to quit
>+    return OnEndExecution(aExitCode);
This is becoming unreadable when all you need is something like
if (NS_FAILED(aExitCode) && m_msgWindow && !ContinueExecutionPrompt())
  return OnEndExecution(aExitCode);
(Similarly for the other callers of ContinueExecutionPrompt.)

>     for (uint32_t actionIndex = m_nextAction;
>-         actionIndex < numActions && *aApplyMore;
>+         actionIndex < numActions;
>          actionIndex++)
>     {
...
>       switch (actionType)
>       {
In this block I was confused as to why sometimes you used break and sometimes continue, as they both seem to jump to the same place.

>+              CONTINUE_IF_FALSE(rv, "Could not create partialMsgs array");
This doesn't compile. Did you mean CONTINUE_IF_FALSE(partialMsgs, ...); ?

>-      nsIMsgDBHdr* msgHdr = m_msgHdrList[i];
>+      nsCOMPtr<nsIMsgDBHdr> msgHdr = m_msgHdrList[i];
Why this change?
Attachment #739846 - Flags: review?(neil) → review-
I've addressed the review comments, and updated the test to work after some changes that bitrotted the previous version. Responding to a couple of specific comments:

"In this block I was confused as to why sometimes you used break and sometimes continue, as they both seem to jump to the same place."

I looked it all over, and I feel like the error handling philosophy is consistent. That is, whenever a error occurs, I am continuing on as much as possible. So the differences between continues and breaks are generally my interpretation of whether a failure affects only a single action, or only a single filter. So if you have a specific concern I could address it.

">-      nsIMsgDBHdr* msgHdr = m_msgHdrList[i];
>+      nsCOMPtr<nsIMsgDBHdr> msgHdr = m_msgHdrList[i];
Why this change?"

I generally do not think it is a worthwhile use of thought space to wonder whether a non-smart pointer would work, so I pretty much routinely convert pointers to smart pointers unless there is a reason not to.
Attachment #739846 - Attachment is obsolete: true
Attachment #8335118 - Flags: review?(neil)
Neil, of all the mail bugs in your review list I think this bug and perhaps bug 842632 are most important. I hope you are able  to re-review this shortly, in time for the next branch, which is TB30.
Flags: needinfo?(neil)
Keywords: mlk
Summary: Only 1 message filter seems to execute when I hit "Run Filters on Folder" (after execution of action="Delete", further/different action on other mails is not executed and filter log is not written to filterlog.html) → Filtering stops -- Only 1 filter executes for "Run Filters on Folder" (after execution of action="Delete", further/different actions on other mails is not executed and filter log is not written to filterlog.html).
Neil: ping :)
No changes, just unbitroted in nsMsgFilterService.cpp.
Attachment #8335118 - Attachment is obsolete: true
Attachment #8335118 - Flags: review?(neil)
Attachment #8373515 - Flags: review?(neil)
Aryx, could you make us a try run with this? I think all platforms and tests. Thanks.
Flags: needinfo?(archaeopteryx)
rkent, there is a user in bug 970343 comment 7 that has tried the patch but is reporting some problems with it. Please check it out.
Flags: needinfo?(kent)
Time to refresh this?
Setting dependency to  "Stop Filter Execution" case(bug 537501) for ease of analysis, tracking, search, because essentially same issue.
Depends on: 537501
Depends on: 1025113
I'm going to try to revive this, because there are outstanding issues (On Archive filters, crashes in maildir tests) the should really have this bug landed before we move forward.

I'm removing all review requests, as it is pretty clear that the review is not going to happen in its current form. I've broken out the unit tests, which really are more about testing FilterAfterTheFact than this bug, and put them into bug 1025113 that will land separately.

As to the comments in bug 970343 comment 7, there is no indication in that bug that it concerns FilterAfterTheFact context (manual filters or postplugin filters), specifically mentioning Inbox filters, so it is hard to see how the previous patch on FilterAfterTheFact could have affected it.
Flags: needinfo?(kent)
Attachment #8373515 - Flags: review?(neil)
Duplicate of this bug: 797710
(In reply to Kent James (:rkent) from comment #53)
> I'm going to try to revive this, because there are outstanding issues (On
> Archive filters, 

bug 479823 and bug 661271?

> crashes in maildir tests) the should really have this bug landed before we move forward.

bug  816304 ?
Flags: needinfo?(neil) → needinfo?(kent)
bug 479823 and bug 661271 are correct. For the maildir xpcshell test crashes, I was referring more to some of the recent work that Suyash was doing in GSOC rather than the existing bugs.
Flags: needinfo?(kent)
rkent I'm glad you are going to look at this, given the maildir implications.

unduping bug 797710 to make it clear in crash-stats that it is not fixed. We should revisit 797710 after this is fixed.

We should also revisit bug 555539 after this is fixed.
Blocks: 555539, 661271
Blocks: 797710
See Also: → 797710
Blocks: 11039
Attached patch 695671a.patch (obsolete) — Splinter Review
Attachment #8373515 - Attachment is obsolete: true
Attachment #8532221 - Flags: review?(neil)
Comment on attachment 8532221 [details] [diff] [review]
695671a.patch

If it didn't mess up the diff -w I would have suggested using do_QueryElementAt more. (Also searchScope is only used once.)

>+  for (m_curFilter = nullptr; // we are done with the current filter
>+       m_curFilterIndex < m_numFilters;
>+       m_curFilter = nullptr) // on error, make sure we don't use an invalid filter
This looks odd, especially given that m_curFilter is set really early on in the loop, and won't get cleared if you break out of the loop. I'd just use a while loop here, and clear out m_curFilter after the loop if you think that's necessary (I haven't looked hard enough to be sure). Similarly for your m_curFolder loop.

> NS_IMETHODIMP nsMsgFilterAfterTheFact::OnStopRunningUrl(nsIURI *aUrl, nsresult aExitCode)
> {
>+  if (NS_FAILED(aExitCode) && m_msgWindow && !ContinueExecutionPrompt())
>+    return OnEndExecution(aExitCode);
> 
>+  return NS_SUCCEEDED(aExitCode) ? ApplyFilter() : AdvanceToNextFolder();
This is better than what there was before, but maybe we could go with:
if (NS_SUCCEEDED(aExitCode))
  return RunNextFilter(); // XXX error in patch?
if (m_msgWindow && !ContinueExecutionPrompt())
  return OnEndExecution(aExitCode);
return AdvanceToNextFolder();

>+  if (NS_FAILED(status) && m_msgWindow && !ContinueExecutionPrompt())
>+    return OnEndExecution(status);
>+  return (NS_SUCCEEDED(status) && !m_searchHits.IsEmpty()) ? ApplyFilter() :
>+                                                             RunNextFilter();
[Similar, although ApplyFilter() is correct here.]

>+    if (!m_curFolder)
>+      break; // Maybe not an error, we just need to call AdvanceToNextFolder();
Except you actually call RunNextFilter(). Does that actually work?

>     // We start from m_nextAction to allow us to continue applying actions
>     // after the return from an async copy.
>     for (uint32_t actionIndex = m_nextAction;
>-         actionIndex < numActions && *aApplyMore;
>+         actionIndex < numActions;
>          actionIndex++)
>     {
>+      m_nextAction++;
>       nsCOMPtr<nsIMsgRuleAction> filterAction;
>       rv = actionList->QueryElementAt(actionIndex, NS_GET_IID(nsIMsgRuleAction),
>                                                    getter_AddRefs(filterAction));
At this point, there's very little difference between actionIndex and m_nextAction, so I would go for something like this:
while (m_nextAction < numActions)
{
  nsCOMPtr<nsIMsgRuleAction> filterAction(do_QueryElementAt(actionList, m_nextAction++, &rv));
which is similar to how m_curFilterIndex is used.

>-        if (NS_FAILED(rv) || actionTargetFolderUri.IsEmpty())
>-        {
>-          NS_ASSERTION(false, "actionTargetFolderUri is empty");
>-          continue;
>-        }
>+        CONTINUE_IF_FALSE(NS_SUCCEEDED(rv) && !actionTargetFolderUri.IsEmpty(), "actionTargetFolderUri is empty");
You almost had me confused here!

>       case nsMsgFilterAction::MoveToFolder:
>       case nsMsgFilterAction::CopyToFolder:
>       {
>-        // if moving or copying to a different file, do it.
>+        // Even if move fails we will not run additional actions, as they would not
>+        //  have run if move succeeded.
>+        if (actionType == nsMsgFilterAction::MoveToFolder)
>+          m_nextAction = numActions;
I'd have a slight preference for something like this:
case nsMsgFilterAction::MoveToFolder:
  // Even if move fails we will not run additional actions, as they would not
  // have run if move succeeded.
  m_nextAction = numActions;
  // Fall through to the copy case.
case nsMsgFilterAction::CopyToFolder:

>+      // An async delete may have removed this header, or a filter action may have scheduled it to
>+      //  move. In either case, do not process the header.
What about the filter action to stop filter processing? (Also do the processing flags get cleared?)
(In reply to neil@parkwaycc.co.uk from comment #59)
> Comment on attachment 8532221 [details] [diff] [review]
> 695671a.patch
> 
> >+  for (m_curFilter = nullptr; // we are done with the current filter
> >+       m_curFilterIndex < m_numFilters;
> >+       m_curFilter = nullptr) // on error, make sure we don't use an invalid filter
> This looks odd, especially given that m_curFilter is set really early on in
> the loop, and won't get cleared if you break out of the loop. I'd just use a
> while loop here, and clear out m_curFilter after the loop if you think
> that's necessary (I haven't looked hard enough to be sure). Similarly for
> your m_curFolder loop.

This class has proven to be relatively unreliable and crashy. There are 11 signatures with nsMsgFilterAfterTheFact in the last 4 weeks, for example. What I am trying to do here is to program this very conservatively, because there are async callbacks that can result in unexpected behavior.

In the code that I did, m_curFilter == nullptr means "there is no active current filter", and m_curFolder == null means "there is no current active folder". Yes it is possible to carefully check the code to make sure that all cases are covered, but as you said "I haven't looked hard enough to be sure".

So I will change this to a while loop, but I still null m_curFilter here, since I'm starting a new filter, and this is the point where I know that the old filter is no longer active. (Similarly for m_curFolder)

> 
> > NS_IMETHODIMP nsMsgFilterAfterTheFact::OnStopRunningUrl(nsIURI *aUrl, nsresult aExitCode)
> > {
> >+  if (NS_FAILED(aExitCode) && m_msgWindow && !ContinueExecutionPrompt())
> >+    return OnEndExecution(aExitCode);
> > 
> >+  return NS_SUCCEEDED(aExitCode) ? ApplyFilter() : AdvanceToNextFolder();
> This is better than what there was before, but maybe we could go with:
> if (NS_SUCCEEDED(aExitCode))
>   return RunNextFilter(); // XXX error in patch?
> if (m_msgWindow && !ContinueExecutionPrompt())
>   return OnEndExecution(aExitCode);
> return AdvanceToNextFolder();

OK

> 
> >+  if (NS_FAILED(status) && m_msgWindow && !ContinueExecutionPrompt())
> >+    return OnEndExecution(status);
> >+  return (NS_SUCCEEDED(status) && !m_searchHits.IsEmpty()) ? ApplyFilter() :
> >+                                                             RunNextFilter();
> [Similar, although ApplyFilter() is correct here.]
> 
> >+    if (!m_curFolder)
> >+      break; // Maybe not an error, we just need to call AdvanceToNextFolder();
> Except you actually call RunNextFilter(). Does that actually work?

Yes, because RunNextFilter() checks for null m_curFolder, and breaks to run AdvanceToNextFolder() if it is.

> 
> >     // We start from m_nextAction to allow us to continue applying actions
> >     // after the return from an async copy.
> >     for (uint32_t actionIndex = m_nextAction;
> >-         actionIndex < numActions && *aApplyMore;
> >+         actionIndex < numActions;
> >          actionIndex++)
> >     {
> >+      m_nextAction++;
> >       nsCOMPtr<nsIMsgRuleAction> filterAction;
> >       rv = actionList->QueryElementAt(actionIndex, NS_GET_IID(nsIMsgRuleAction),
> >                                                    getter_AddRefs(filterAction));
> At this point, there's very little difference between actionIndex and
> m_nextAction, so I would go for something like this:
> while (m_nextAction < numActions)
> {
>   nsCOMPtr<nsIMsgRuleAction> filterAction(do_QueryElementAt(actionList,
> m_nextAction++, &rv));
> which is similar to how m_curFilterIndex is used.
> 
> >-        if (NS_FAILED(rv) || actionTargetFolderUri.IsEmpty())
> >-        {
> >-          NS_ASSERTION(false, "actionTargetFolderUri is empty");
> >-          continue;
> >-        }
> >+        CONTINUE_IF_FALSE(NS_SUCCEEDED(rv) && !actionTargetFolderUri.IsEmpty(), "actionTargetFolderUri is empty");
> You almost had me confused here!
> 
> >       case nsMsgFilterAction::MoveToFolder:
> >       case nsMsgFilterAction::CopyToFolder:
> >       {
> >-        // if moving or copying to a different file, do it.
> >+        // Even if move fails we will not run additional actions, as they would not
> >+        //  have run if move succeeded.
> >+        if (actionType == nsMsgFilterAction::MoveToFolder)
> >+          m_nextAction = numActions;
> I'd have a slight preference for something like this:
> case nsMsgFilterAction::MoveToFolder:
>   // Even if move fails we will not run additional actions, as they would not
>   // have run if move succeeded.
>   m_nextAction = numActions;
>   // Fall through to the copy case.
> case nsMsgFilterAction::CopyToFolder:
> 
> >+      // An async delete may have removed this header, or a filter action may have scheduled it to
> >+      //  move. In either case, do not process the header.
> What about the filter action to stop filter processing? (Also do the
> processing flags get cleared?)

There are places where FilterToMove is cleared. The keys themselves though, as I understand it, are not reliably deleted when no longer needed.
Attached patch Add changes from Neil comments (obsolete) — Splinter Review
Revised patch implementing comments.
Attachment #8532221 - Attachment is obsolete: true
Attachment #8532221 - Flags: review?(neil)
Attachment #8534590 - Flags: review?(neil)
Comment on attachment 8534590 [details] [diff] [review]
Add changes from Neil comments

> nsresult nsMsgFilterAfterTheFact::RunNextFilter()
> {
>+  nsresult rv = NS_OK;
>+  while (m_curFilterIndex < m_numFilters)
>+  {
>+    m_curFilter = nullptr;
...
>   }
>+  NS_WARN_IF_FALSE(NS_SUCCEEDED(rv), "Search failed");
>+  return AdvanceToNextFolder();
> }
Did you want to clear m_curFilter once you've run out of filters?

> nsresult nsMsgApplyFiltersToMessages::RunNextFilter()
> {
>+  nsresult rv = NS_OK;
>+  m_curFilter = nullptr;
>   while (m_curFilterIndex < m_numFilters)
>   {
>+    m_curFilter = nullptr; // we are done with the current filter
Clearing m_curFilter before the loop is worse because it makes it look like it's doing something but in the case where you run partially though the loop you don't actually clear the current filter.

>     for (int32_t i = 0; i < m_msgHdrList.Count(); i++)
>     {
>-      nsIMsgDBHdr* msgHdr = m_msgHdrList[i];
>+      nsCOMPtr<nsIMsgDBHdr> msgHdr = m_msgHdrList[i];
>+      CONTINUE_IF_FALSE(msgHdr, "null msgHdr");
>+
>+      // An async delete may have removed this header, or a filter action may
>+      //  have scheduled it to move. In either case, do not process the header.
>+      nsMsgKey key;
>+      msgHdr->GetMessageKey(&key);
>+      uint32_t processingFlags = 0;
>+      m_curFolder->GetProcessingFlags(key, &processingFlags);
>+      if (processingFlags & nsMsgProcessingFlags::FilterToMove)
>+        continue;
>+
>       bool matched;
>-
>       rv = m_curFilter->MatchHdr(msgHdr, m_curFolder, m_curFolderDB, nullptr, 0, &matched);
>-
>       if (NS_SUCCEEDED(rv) && matched)
>       {
>         // In order to work with nsMsgFilterAfterTheFact::ApplyFilter we initialize
>         // nsMsgFilterAfterTheFact's information with a search hit now for the message
>         // that we're filtering.
>         OnSearchHit(msgHdr, m_curFolder);
>       }
>     }
>     m_curFilter->SetScope(nullptr);
> 
>     if (m_searchHits.Length() > 0)
>     {
>-      bool applyMore = true;
>-
>       m_nextAction = 0;
>-      rv = ApplyFilter(&applyMore);
>-      NS_ENSURE_SUCCESS(rv, rv);
>-      if (applyMore)
>-      {
>-        // If there are more filters to apply, then ApplyFilter() would have
>-        // called RunNextFilter() itself, and so we should exit out afterwards
>-        return NS_OK;
>-      }
>-
>-      // If we get here we're done applying filters for those messages that
>-      // matched, so remove them from the message header list
>-      for (uint32_t msgIndex = 0; msgIndex < m_searchHits.Length(); msgIndex++)
>-      {
>-        nsCOMPtr <nsIMsgDBHdr> msgHdr;
>-        m_searchHitHdrs->QueryElementAt(msgIndex, NS_GET_IID(nsIMsgDBHdr), getter_AddRefs(msgHdr));
>-        if (msgHdr)
>-          m_msgHdrList.RemoveObject(msgHdr);
>-      }
Sorry, but it's still not clear to me how this change interacts with the Stop Filter Execution action.
(In reply to neil@parkwaycc.co.uk from comment #62)
> Comment on attachment 8534590 [details] [diff] [review]
> Add changes from Neil comments
> ...
> Sorry, but it's still not clear to me how this change interacts with the
> Stop Filter Execution action.

I'll address the other issues in a new patch. Let me comment though on this issue.

The existing filter service never really handled StopExecution correctly, because it is designed for batching of messages in a folder, but had no real mechanism to stop processing filters on a single message, which is what users of this method expect. In incoming filters this is not an issue, as the filters are applied on a per message basis. When batching of messages is useful (like in a message move), then the imap move coalescer is used.

What did the previous version do on StepExecution? It reset applyMore, which had the effect of stopping further filter execution on all other messages in the batch. So I could have a filter like (IF Subject == skipme THEN stopExecution) followed by a filter (for all messages,tag IMPORTANT). Then if there was any message with the subject skipme, then all messages in the batch would not get the tag.

What I decided to do in the original patch was to interpret StopExecution in a manner that did not cause unexpected skips in unmatched messages, namely to simply stop further execution of actions in the same filter.

In retrospective, the way that we are starting to use this service (in both ExQuilla, and now in PostOutgoing messsages) is to not batch, but use this service on a per-message basis. While inefficient, it has fewer negative consequences. Perhaps I should set the StopExecution method to optimize this case though that would then cause issues in the Archive filter method which does batch IIRC (and in apply messages to folder or selected messages, but that is an existing issue).

I'm still thinking through the correct response. The correct way to solve this is to probably use a processing flag, like we do with the move action. Perhaps I could even use the same processing flag.
Blocks: 537224
Attached patch Deal with StopExecution (obsolete) — Splinter Review
I decided to go ahead and fix the issue with StopExecution using processing flags, as well as explicitly clearing those flags.

On the form of the while loops, the goal is to reset current variables when we know they are invalid. I tried another variant, see what you think of this.
Attachment #8534590 - Attachment is obsolete: true
Attachment #8534590 - Flags: review?(neil)
Attachment #8535300 - Flags: review?(neil)
Comment on attachment 8535300 [details] [diff] [review]
Deal with StopExecution

>+  nsTArray<nsMsgKey>          m_setProcessingFlags;
Aargh, so reading more carefully, we don't want to mess around with the processing flags, because the spam filtering wants to know when a message was moved or deleted by the filter (bug 198100). So, maybe the way to go is to use this array (or maybe it should be a hash set) to determine when to skip a message, instead of changing the processing flags?

>+  while (true)
>+  {
>+    m_curFilter = nullptr;
>+    if (m_curFilterIndex >= m_numFilters)
>+      break;
Fair enough.

>+  while (true)
>   {
>+    m_curFilter = nullptr; // we are done with the current filter
>+    if (!m_curFolder // Not an error, we just need to run AdvanceToNextFolder()
>+        || m_curFilterIndex >= m_numFilters)
>+      break;
Nit: in your do block, you separate the conditions, which IMHO is more readable.
Attached patch 695671d.patch (obsolete) — Splinter Review
Use local array to stop filtering
Attachment #8535300 - Attachment is obsolete: true
Attachment #8535300 - Flags: review?(neil)
Attachment #8535669 - Flags: review?(neil)
Yes Neil you are right. I often complain about conflating of meaning in mailnews code, and I was about to contribute to that my conflating the filterToMove with stopProcessingFilters. The fix is easy though.
Comment on attachment 8535669 [details] [diff] [review]
695671d.patch

>+              nsMsgKey key;
>+              msgHdr->GetMessageKey(&key);
Sorry for not spotting this last time, but just use m_searchHits[i].

>+              m_stopFiltering.AppendElement(key);
Might as well append all the search hits in one go after the loop.
Attachment #8535669 - Flags: review?(neil) → review+
(In reply to neil@parkwaycc.co.uk from comment #68)
> Comment on attachment 8535669 [details] [diff] [review]
> 695671d.patch
> 
> >+              m_stopFiltering.AppendElement(key);
> Might as well append all the search hits in one go after the loop.

That is different behavior. In the original, each message is separately checked to see if it has the ::Partial flag, and if it does it is added to partialMsgs, and will be deleted. Not all m_searchHits may have the flag set, so not all can be added to m_stopFiltering. So I can't do what you suggest.
Attached patch 695671e.patchSplinter Review
Patch to land, carrying forward Neil's review
Attachment #8535669 - Attachment is obsolete: true
Attachment #8537635 - Flags: review+
Landed https://hg.mozilla.org/comm-central/rev/7bc453bb4cdd
Status: ASSIGNED → RESOLVED
Closed: 5 years ago
Resolution: --- → FIXED
Target Milestone: --- → Thunderbird 37.0
(In reply to Kent James from comment #69)
> That is different behavior. In the original, each message is separately
> checked to see if it has the ::Partial flag, and if it does it is added to
> partialMsgs, and will be deleted. Not all m_searchHits may have the flag
> set, so not all can be added to m_stopFiltering.

Good point thanks.
Is this issue fixed in the latest beta (37.0b1) available to download? I am facing a somewhat similar issue and this beta didn't fix it. Thanks.
This patch should be in the latest beta, so if you still have an issue please file a new bug.
Flags: in-testsuite+
Duplicate of this bug: 1147063
Duplicate of this bug: 849629
No longer blocks: 849629
You need to log in before you can comment on or make changes to this bug.