Closed Bug 1071628 Opened 10 years ago Closed 5 years ago

filter actions after message move fail

Categories

(MailNews Core :: Filters, defect)

x86
All
defect
Not set
normal

Tracking

(Not tracked)

RESOLVED INCOMPLETE

People

(Reporter: miguelangel.caballerobracero, Unassigned)

References

(Depends on 1 open bug)

Details

(Whiteboard: [dupeme])

Attachments

(1 file)

User Agent: Mozilla/5.0 (X11; Linux i686; rv:24.0) Gecko/20140319 Firefox/24.0 Iceweasel/24.4.0 Build ID: 20140319114152 Steps to reproduce: After creating a filter that does the next operations: Conditions: AAAA message conditions Operations: forward to XXXX@X.X Move to folder ZZZZ and executed manually or at arrival with a message that acomplish AAAA conditions Actual results: When the filter is triggered, the message that acomplish the conditions is moved to the folder ZZZZ, but it's not forwarded to the email XXXX@X.X It's because the message have been moved before have been forwarded. I suposse it happens because the operations in the same filter are done in parallel, not secuencially, so the message it's moved before its forwarded (because forwarding it is slower). And every time it hapens a "blank message" windows appears because the forwarding operation didn't find the message. Expected results: The message have to be forwarded to XXXX@X.X and after moved to folder ZZZZ. ------------------------------------------------- Like a solution i recomend to implement a "delay" function and the possibility of indicating that the operations for mail filtering are done in secuential mode not parallel As a tip, if I divide the filter in two filters: Filter 1: (Priority or position of the filter 1) Conditions: AAAA Forward to XXXX@X.X Filter 2: (Priority o position 100, or lower) Conditions: AAAA Move to folder ZZZZ It works perfectly because thunderbird has to process all the filters between 1 and 99 before moving the mail to folder ZZZZ, so it's like creating a delay.
The operations should not be done in parallel, but sequentially and TB even has a priority list in which to execute the various actions. So Move/Delete is always the last action in the list and Forward should be done sooner, when the message is still there. In TB31 the filter editor even shows you this real order of execution. So theoretically this should not happen. But of course, there may be a bug. What is exact TB version?
Product: Thunderbird → MailNews Core
Whiteboard: [closeme 2014-10-10]
Hi, sorry it's icedove, Package: icedove (10.0.12-1~bpo60+1) and icedove (24.8.0-1~deb7u1 and others) [security], from debian stable and stable-sec. In this 2 versions happens the problem. I'm going to try it in a last versión thunderbird. I'll post then.
(In reply to miguelangel.caballerobracero@gmail.com from comment #0) > Steps to reproduce: > After creating a filter that does the next operations: > Conditions: > AAAA message conditions > Operations: > forward to XXXX@X.X > Move to folder ZZZZ > and executed manually or at arrival with a message that acomplish AAAA conditions > Actual results: > When the filter is triggered, the message that acomplish the conditions is > moved to the folder ZZZZ, but it's not forwarded to the email XXXX@X.X > > It's because the message have been moved before have been forwarded. > I suposse it happens because the operations in the same filter are done in > parallel, not secuencially, so the message it's moved before its forwarded > (because forwarding it is slower). > And every time it hapens a "blank message" windows appears because the forwarding operation didn't find the message. (Q1) POP3? IMAP? Gmail IMAP? If Gmail IMAP, do you enable auto-expunge of Gmail? I could observe the "blank message windows" with following in Tb 31.1.1. IMAP delete model = Mark it as deleted, in order to see deleted mail as "mail with trash can icon & strike-thru line". Gmail IMAP, auto-expunge of Gmail is enabled. FolderX = Offline-Use=Off folder in Tb. Mail data is not held in Offline-Store file. Filter Rule: [x] Manually Run, If subject begins with ..., Forward to ..., Forward to ..., Move to FolderY. Forward option : Inline forward (not forward as attachment). At FolderX of Gmail IMAP, "Run Filters on Folder". In message filter log, all actions(Forward, Move) are normally logged. If "Run Filters on Folder" is executed while "Work Offline" mode, "Forward to ..." is impossible because message body is not available(Offline-Use=Off), "Move to FolderY" is executed in "Work Offline" mode. Because mail is already moved to FolderY in Thunderbird, "Move from FolderX to FolderY" is actually executed after going back to Work Online mode. If "Run Filters on Folder" on Offline-Use=On folder, "Run Filters on Folder while Work Offline mode", did do next. "Forward to ..." is executed because message body is available in Offline-Store file, but "SMTP send fails because of Work Offline mode. "Move to FolderY" is executed in "Work Offline" mode, and .actual move is executed when going back to Work Online mode. (Q2) If Gmail IMAP, do you see your problem on already downloaded mails in Offline-Use=On folder with "Run Filters on Folder"? (Q3) About "newly arrived mails in Inbox" : Do you see your problem with "[ x ] Getting New Mail: Filter after Junk Classification"? (Q4) About "mails in [Gmail]/All Mail" : Do you see your problem with next? "[Gmail]/All Mail" is Offline-Use=Off folder, message body is not held in Offline-Store file. "Run Filters on" on "[Gmail]/All Mail". UID of mail in [Gmail]/All Mail is not removed by "move from [Gmail]/All Mail to other than [Gmail]/Trash(or Spam)". So, UID of mail is accessible at [Gmail]/All Mail even after "move from [Gmail]/All Mail" or ".delete at [Gmail]/All Mail". As known by bug 971401 and bug 1067706, if new mails, entire message data is fetched prior to message filter application. And, because Gmail IMAP supports Move extension, IMAP move command is used by Tb upon filter move. And, if auto-expunge of Gmail is enabled, UID of the moved mail is removed immediately by Gmail IMAP, even when simple "store +Flags(\Deleted)" is used upon filter move. So, once "uid move xx MoveTargetFolder" is executed at Inbox by message filter, "subsequent UID access at Inbox by forward mail composition & SMTP send" is impossible. If Move extension is not supported by IMAP server, "Move mail in Tb" = "uid copy xx MoveTragetFolder" + "uid store xx +Flags(\Deleted)". So, if ordinl IMAP server and Move extension is not used, uid=xx is available even after "Filter Move". (Q5) If IMAP, do you see your problem with ordinal IMAP servers?
NSPR log parameter SET NSPR_LOG_MODULES=SMTP:5,imap:5,ImapAutoSync:5,IMAPOFFLINE:5,MsgCopyService:5 Gmail IMAP, max cached connections = 2, IDLE is enabled Filter Rule : If subject begins ..., Forward to aaa, Forward to bbb, Move to MoveTargetX Mail Folder : MoveTargetX, Offline-Use=Off folder, 1 hit mail Filter Log : 1. Forward to aaa, 2. Forward to bbb, 3. Move to MoveTargetX in this order NSPR log : 0. Connection for MoveTarget is IDLE state 1. DoCopy src MoveTarget dest MoveTargetX, number of mails=1 2. At connection for MoveTarget, DONE 3. queuing url:imap://yatter.king@gmail.com@imap.gmail.com:993/fetch>UID>/MoveTarget>88 4. 17 OK IDLE terminated (Success) 5. :S-MoveTarget:ProcessCurrentURL:imap://yatter%2Eking%40gmail%2Ecom@imap.gmail.com:993/ onlinemove%3EUID%3E/MoveTarget%3E88%3E/MoveTargetX: = currentUrl At connection for MoveTarget, 19 uid move 88 "MoveTargetX 20 OK Success 6. playing queued url:imap://yatter.king@gmail.com@imap.gmail.com:993/fetch>UID>/MoveTarget>88 21 UID fetch 88 (UID RFC822.SIZE BODY[]) nothing is returned, because UID=88 is already moved 21 OK Success It looks : 1. "Forward to aaa" action is executed => mail composition window is internally created with request of "inline forward of UID=88 => end of "Forward action by message filter" 2. "Forward to bbb" action is executed => mail composition window is internally created with request of "inline forward of UID=88 => end of "Forward action by message filter" 3. "Move to MoveTargetX" action is executed => DoCopy is requested and is invoked 4. Before "request for message body to do forward"(= "uid fetch 88 body.peek[]" command) is requested and queued by mail composition job for forward, "request for move by DoCopy"(= "uid move 88 MoveTargetX" command) is requested at cached connection. In this test with NSPR logging enabled, "blank mail composition windows" is not observed. "Forward to ..." step silently fails and nothing is forwarded. It looks that "blank mail composition windows appears or not" is timing dependent. Effect of "Splitting filter rule to 'Rule for Forward' and 'Rule for Move'" is perhaps ; When new mail and "Filter before Junk Classification", "uid fetch xx body.peek[] for forward" is requested by mail composition task before "uid move xx Move-Target-Folder" is requested by DoCopy for filter move. "Filter after Junk Classification" may be a workaround, but it may not be a workaround as seen in bug 1067706. If Move extension is not used, "Move to MoveTargetX" is executed by following IMAP commands : "uid copy 88 MoveTargetX" + "uid store 88 +Flags(\Deleted)" So, subsequent "uid fetch 88 body.peek[]" always returns mail data normally.
OS: Linux → All
FYI. Following is copy of Bug 1071754 Comment #1 posted by Kent James. > "Filter after" uses entirely different code (the FilterAfterTheFact code) than "filter before", > so it is common that bugs in one do not appear in the other. > Although that was added to allow the bayes filter to be used, there are other special cases where works, such as this one. > The bayes filter will not actually occur unless it is selected for the account. Not sure if RSS allows that or not. Because FilterAfterTheFact code is used for "Filter after junk Classification", "Filter after junk Classification" is similar to "Run Filters on Folder".
Problem seems to depend on "Forward option". Test case is same as comment #4. Gmail IMAP, max cached connections = 2, IDLE is enabled Filter Rule : If subject begins ..., Forward to aaa(valid addr), Forward to bbb(non-existent), Move to MoveTargetFolder Mail Folder : TestFolder, Offline-Use=Off folder, 1 hit mail is held, "Run Filters on Folder" is executed on TestFolder Used identity : Mailn identity of this Gmail IMAP account which uses Gmail's SMTP server Test result. (1) Forward option=Inline Forward, No NSPR logging : Two blank composition windows are shown. Forwarded icon is not set. (2) Forward option=Forward as attachment, No NSPR logging : Forward is executed. Forwarded icon is set. Because mail-addr=bbb doesn't exist(non-existent mail domain), delivery failure is notified from Gmail's SMTP server. Forward by messge filter is done via Compose Service->ForwardMessage. > http://mxr.mozilla.org/comm-central/source/mailnews/imap/src/nsImapMailFolder.cpp#3708 > 3696 case nsMsgFilterAction::Forward: > 3708 rv = compService->ForwardMessage(NS_ConvertASCIItoUTF16(forwardTo), > 3709 msgHdr, msgWindow, server, > 3710 nsIMsgComposeService::kForwardAsDefault); ForwardMessage Service is defined at; > http://mxr.mozilla.org/comm-central/source/mailnews/compose/src/nsMsgComposeService.cpp#1166 > 1166 nsMsgComposeService::ForwardMessage(const nsAString &forwardTo, If Inline Forward, ForwardMessage Service returns at here after end of RunMessageThroughMimeDraft. > 1212 if (aForwardType == nsIMsgComposeService::kForwardInline) > 1213 return RunMessageThroughMimeDraft(msgUri, > 1214 nsMimeOutput::nsMimeMessageDraftOrTemplate, > 1215 identity, > 1216 msgUri.get(), aMsgHdr, > 1217 true, forwardTo, > 1218 false, aMsgWindow); If Forward as attachment, ForwardMessage Service returns at here after end of SendMsg service. > 1246 rv = pMsgCompose->Initialize(pMsgComposeParams, parentWindow, nullptr); > 1249 rv = pMsgCompose->SendMsg(nsIMsgSend::nsMsgDeliverNow, identity, nullptr, nullptr, nullptr); > 1257 return folder->AddMessageDispositionState(aMsgHdr, nsIMsgFolder::nsMsgDispositionState_Forwarded); RunMessageThroughMimeDraft(used when Inline Forward) is asynchronous? FYI. Logic for Inline Forward was added by Inline Forward support in message filter. > http://hg.mozilla.org/comm-central/annotate/2b6f0a685995/mailnews/compose/src/nsMsgComposeService.cpp#l1212 > http://hg.mozilla.org/comm-central/diff/b80ba3cbee79/mailnews/compose/src/nsMsgComposeService.cpp#l1.76 > http://hg.mozilla.org/comm-central/diff/b80ba3cbee79/mailnews/compose/src/nsMsgComposeService.cpp#l1.126 > http://hg.mozilla.org/comm-central/rev/b80ba3cbee79 > add forward inline filter action, r=rkent, sr=standard8, bug 312025
Whiteboard: [closeme 2014-10-10] → [Don't closeme 2014-10-10]
FYI. If local mail folder(POP3 account or Local Folders), "forward of filter" is processed here. > http://mxr.mozilla.org/comm-central/search?string=case%2BnsMsgFilterAction%3A%3AForward%3A > http://mxr.mozilla.org/comm-central/source/mailnews/local/src/nsParseMailbox.cpp#2155 > 2155 case nsMsgFilterAction::Forward: > 2156 { > 2157 nsCString forwardTo; > 2158 filterAction->GetStrValue(forwardTo); > 2159 m_forwardTo.AppendElement(forwardTo); > 2160 m_msgToForwardOrReply = msgHdr; > 2161 } > 2162 break; m_forwardTo is referred at here, and Compose Service->ForwardMessage is used too. > http://mxr.mozilla.org/comm-central/ident?i=forwardTo > 2275 if (!m_forwardTo[i].IsEmpty()) > 2276 { > 2281 { > 2282 nsCOMPtr<nsIMsgComposeService> compService = > 2283 do_GetService (NS_MSGCOMPOSESERVICE_CONTRACTID, &rv); > 2284 NS_ENSURE_SUCCESS(rv, rv); > 2285 rv = compService->ForwardMessage(forwardStr, m_msgToForwardOrReply, > 2286 msgWindow, server, > 2287 nsIMsgComposeService::kForwardAsDefault); > 2288 } > 2289 } If local mail folder, "messageKey==messageOffset of filter moved mail(==forwarded mail)" is not changed, unless Compact is executed at Filter Move Source Folder(Inbox when filter on new mail) just after"Filter Move" and just before compService->ForwardMessage call for "Forward Inline by filter". Therefore, "Forward Inline by message filter" can nearly always read mail data of forwarded mail, even if "Filter Move" is executed too quickly before completion of "Forward Inline by filter". So, Problem won't be exposed if local mail folder.
Wooo, a lot of information for my short time now. Thanks a lot for all this WADA. All problems start when I changed my mail "configuration" from a local mail to a IMAP mail (outlook.office365.com; microsoft). With local mail configuration ever have this problem. All mails arrived to local mail and then the same filters than now forward to the same addreses and move to local mail folders (same structure than imap) correctly. But... let's go. Q1? - It's IMAP in (outlook.office365.com; microsoft server), not gmail nor pop. - I always work in online mode, it's rare condition that we have network connectivity problems. Q2? - Not Gmail. Q3? Where it is "Getting New Mail: Filter after Junk Classification"?" Ahhh ok, I see, I always have "Check before Junk Classification", I'LL TEST IT, but I think there isn't to be changes. Q4? - Not Gmail Q5? Yes I see, in (outlook.office365.com; microsoft), but I don't know if it's an ordinal IMAP server. Too much for reading in the "comment 6" for now :-). I'll try.... to understand. Thanks in advance.
Ohh, more information, I forgot, the filters logs of icedove (10.0.12-1~bpo60+1) and icedove (24.8.0-1~deb7u1 and others) [security] indicate the operations have finished OK.... but really don't.
Whiteboard: [Don't closeme 2014-10-10]
(In reply to miguelangel.caballerobracero@gmail.com from comment #9) > I forgot, the filters logs of icedove (10.0.12-1~bpo60+1) and icedove > (24.8.0-1~deb7u1 and others) [security] indicate the operations have finished OK.... but really don't. As known by bug 935934, current purpose of filter logging is to show "which filter did hit on which mail", perhaps except for "filter move from IMAP folder". So, we can't know "filter action was successfully executed or not" by message filter log. This is sadly current design/implementation of message filter logging. "No timestamp of log in message filter log" is also current spec :-)
(In reply to miguelangel.caballerobracero@gmail.com from comment #8) > Q1? - It's IMAP in (outlook.office365.com; microsoft server), not gmail nor pop. Does IMAP server of outlook.office365.com suppot Move extension? Get IMAP log(See bug 402793 comment #28) and check CAPABILITY response and move command use upon move mail/delete mail(move to Trash) by Tb.
See Also: → 935934
:aceman, RunMessageThroughMimeDraft(used when Inline Forward) is asynchronous?
Flags: needinfo?(acelists)
(In reply to WADA from comment #10) > (In reply to miguelangel.caballerobracero@gmail.com from comment #9) > > I forgot, the filters logs of icedove (10.0.12-1~bpo60+1) and icedove > > (24.8.0-1~deb7u1 and others) [security] indicate the operations have finished OK.... but really don't. > > As known by bug 935934, current purpose of filter logging is to show "which > filter did hit on which mail", perhaps except for "filter move from IMAP > folder". So, we can't know "filter action was successfully executed or not" > by message filter log. This is sadly current design/implementation of > message filter logging. "No timestamp of log in message filter log" is also > current spec :-) I proposed some improvements to make the filter log more useful in bug 697522 to allow us better debugging. (In reply to WADA from comment #12) > :aceman, RunMessageThroughMimeDraft(used when Inline Forward) is > asynchronous? I have no idea, just that there is a line "converter->AsyncConvertData(nullptr, nullptr, nullptr, channel);" in that function. I don't know what effect that has. I am not familiar with IMAP either.
Flags: needinfo?(acelists)
miguel, do you still see this issue?
Flags: needinfo?(miguelangel.caballerobracero)
miguel seems to be gone
Depends on: 697522
Summary: Improve or fix operation of filters in thunderbird → filter actions after message move fail
Whiteboard: [dupeme]
(In reply to :aceman from comment #13) > I proposed some improvements to make the filter log more useful in bug > 697522 to allow us better debugging. possible to finish that work? It blocks quite a few items.
Flags: needinfo?(acelists)

Filter hits logging finished, but the bug here may be more dependent on bug 1547508, as it seems the filters hit the right messages here but the actions aren't executed successfully.

Depends on: 1547508
Flags: needinfo?(acelists)
Status: UNCONFIRMED → RESOLVED
Closed: 5 years ago
Flags: needinfo?(miguelangel.caballerobracero)
Resolution: --- → INCOMPLETE
Depends on: 662056

Please try the "move later function" of the FiltaQuilla Addon

You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: