Open Bug 971401 Opened 11 years ago Updated 8 months ago

Severe delay with body matching rule exists(Body condition, with Apply filter on/Getting New Mail/Filter before Junk Classification) and autosync enabled, processing only 1 message at a time, ~50% CPU

Categories

(MailNews Core :: Filters, defect)

Product:
MailNews Core
Component:
Filters
Type:
defect

Tracking

(Not tracked)

People

(Reporter: k.joe, Unassigned)

References

(Depends on 1 open bug)

Details

(Keywords: perf, Whiteboard: [see comment 35,41,43][needs performance profile])

Attachments

(6 files, 2 obsolete files)

Automatic filtering
84.64 KB, image/png
Details
Manual filtering
75.39 KB, image/png
Details
Thunderbird informations
11.42 KB, text/plain
Details
IMAP Log for Filter Move, with Body Filter, with Filter before Classicfiction
191.71 KB, text/plain
Details
Full IMAP Log for Filter Move : Add tag & move without Body filter at "Before Classicfiction", Add tag & move with Body Filter at "After Classicfiction"
140.21 KB, text/plain
Details
Reduced IMAP Log for Filter Move : Add tag & move without Body filter at "Before Classicfiction", Add tag & move with Body Filter at "After Classicfiction"
57.84 KB, text/plain
Details
User Agent: Mozilla/5.0 (X11; Ubuntu; Linux i686; rv:26.0) Gecko/20100101 Firefox/26.0 (Beta/Release) Build ID: 20131206152524 Steps to reproduce: I've daily hundreds of emails and ten automatic filters (about 15-20 rules), which moves mails to several subfolders. Automatic filtering of incoming IMAP messages is extremely slow, but if I intentionally close Thunderbird while filtering and start it again (the result is many unreaded/unfiltered mail left in incoming folder), and manually select run filters on folder from the menu, then all messages are filtered in seconds magically, and moved to corresponding folders. Trying in safe mode the results are same, screenshots attached. Actual results: Thunderbird automatically filtering incoming new messages one by one (see activity manager), applying all rules, then actualizing and indexing the target folder, and starts next round. The manual folder filter takes all messages, and filtering whole thing in one round, thus mass move all messages to its corresponding subfolders. Expected results: Automatic incoming message filtering should not start while messages/headers downloading is in progress, or must index/filter all downloaded new messages in one round (like manual run, which is significantly faster), not just one by one.
Attached image Automatic filtering —
Attached image Manual filtering —
Hardware: x86 → x86_64
See Also: → 277042
What happens if you disable "sync" in tools | accounts | sync and storage ??
Flags: needinfo?(k.joe)
Keywords: perf
Whiteboard: [closeme 2014-09-05]
If I turn off the sync of incoming folder in the advanced dialog, then the problem disappears, thanks! However, the automatic filtering could not be wait for sync, before start?
Flags: needinfo?(k.joe)
If you turn sync back on, what is your CPU usage when things are slow? And, is the progress bar moving in the status bar at bottom of window?
Flags: needinfo?(k.joe)
Whiteboard: [closeme 2014-09-05]
I think it is not a CPU related problem. I have daily 200-2000 incoming emails at the morning, and when I start Thunderbird for first time, then THB starts downloading body of all new messages (due to sync incoming folder), but it takes time (1-10 minutes), and during this sync starts message filtering too. When sync is off for incoming folder, then only message headers are downloaded, which is significantly faster, and then filtering similar messages in one step (the whole process takes only 1-2 minutes), rather than try to move individual messages to target folders one by one.
Flags: needinfo?(k.joe)
Ok. But I am still seek the specific information to both of my questions
Flags: needinfo?(k.joe)
Today I turned sync back, so downloading/syncing and filtering 513 messages takes 37 minutes, CPU usage was between 30% and 80%, system load was about 1.3 on Intel Core2 Duo E7500 @ 2.93 GHz CPU (2 core), the statusbar shows moving progressbar and infos about the process (downloading, moving messages, etc.). The imap server load is 1.0-2.5 on Intel Xeon E5520 @ 2.27GHz CPU (4 core), but it has 200-250 simultaneous imap connections, so server is not an issue (nor significant I/O wait on either side).
Flags: needinfo?(k.joe)
(In reply to k.joe from comment #9) > Today I turned sync back, so downloading/syncing and filtering 513 messages > takes 37 minutes, CPU usage was between 30% and 80%, system load was about > 1.3 on Intel Core2 Duo E7500 @ 2.93 GHz CPU (2 core), the statusbar shows > moving progressbar and infos about the process (downloading, moving > messages, etc.). This is exactly the info I needed. The relatively high but not 100% CPU usage suggests some level of IO or server-bound activity. We can probably rule out the later, given your testing that shows fast download with no filtering and sync enabled, correct? This leaves us with IO, which suggests bug 589310. n.b. bug 589310 comment 21. How big is the snmp folder in Thunderbird - number of messages AND file size? Is that the biggest folder being filtered to? And can you attach a log file per https://wiki.mozilla.org/MailNews:Logging for msgdblog:5 > The imap server load is 1.0-2.5 on Intel Xeon E5520 @ > 2.27GHz CPU (4 core), but it has 200-250 simultaneous imap connections, so > server is not an issue (nor significant I/O wait on either side). Unlikely, yes. But we will see. When you say "200-250 simultaneous imap connections" do you mean that it can potentially handle that many? Or do you mean that it has that many open and *active*?
Flags: needinfo?(k.joe)
Summary: Incoming message filter processing is very slow → Bulk message incoming message filter processing is very slow. High CPU usage.
p.s. when did you first noticing this slowness - in version 24?
(In reply to Wayne Mery (:wsmwk) from comment #10) > This is exactly the info I needed. The relatively high but not 100% CPU > usage suggests some level of IO or server-bound activity. We can probably > rule out the later, given your testing that shows fast download with no > filtering and sync enabled, correct? Sync enabled, continuous downloading messages' bodies, but filtering only one msg at a time (status bar says moving 1/1 to target folder, then syncing target folder too), so this is slow. It seems clearly, that while body download is in progress, then (a paralel thread?) filtering only individual messages at a time. If no body download (sync off or close thunderbird then start and run same filters on inbox manually from tools menu), then filtering similar matching messages together (see original activity attachments), relatively fast. > How big is the snmp folder in Thunderbird - number of messages AND file size? > Is that the biggest folder being filtered to? The snmp folder has 26000 msgs, but it's not the biggest, the zabbix folder has 75000 mgs, but message reading is seamless. That's a point, thunderbird file sizes was big (sum is 3.5 GB), but after manually compacting all folders, the result is 250 MB (and INBOX shrinked from 1.4 GB to 32 MB). The automatic compact setting in advanced/diskspace is the default 20 MB and cache size is 350 MB, so it has no effect? > And can you attach a log file per https://wiki.mozilla.org/MailNews:Logging > for > msgdblog:5 I'll check the speedup and logging tomorrow. > When you say "200-250 simultaneous imap connections" do you mean that it can > potentially handle that many? Or do you mean that it has that many open and > *active*? I mean that currently it has that many imap processes and tcp connections in ESTABLISHED state (so simultaneous imap clients), but not that many processes in running state of course (load is relatively low).
Flags: needinfo?(k.joe)
(In reply to Wayne Mery (:wsmwk) from comment #11) > p.s. when did you first noticing this slowness - in version 24? Not in v24, but in the past, when thunderbird comes with local search features (and sync is probably default turned on?).
(In reply to k.joe from comment #13) > (In reply to Wayne Mery (:wsmwk) from comment #11) > > p.s. when did you first noticing this slowness - in version 24? > > Not in v24, but in the past, when thunderbird comes with local search > features (and sync is probably default turned on?). that would be version 3, in early 2010. (In reply to k.joe from comment #12) > (In reply to Wayne Mery (:wsmwk) from comment #10) > > This is exactly the info I needed. The relatively high but not 100% CPU > > usage suggests some level of IO or server-bound activity. We can probably > > rule out the later, given your testing that shows fast download with no > > filtering and sync enabled, correct? > Sync enabled, continuous downloading messages' bodies, but filtering only > one msg at a time (status bar says moving 1/1 to target folder, then syncing > target folder too), so this is slow. It seems clearly, that while body > download is in progress, then (a paralel thread?) filtering only individual > messages at a time. If no body download (sync off or close thunderbird then > start and run same filters on inbox manually from tools menu), then > filtering similar matching messages together (see original activity > attachments), relatively fast. > > > How big is the snmp folder in Thunderbird - number of messages AND file size? > > Is that the biggest folder being filtered to? > The snmp folder has 26000 msgs, but it's not the biggest, the zabbix folder > has 75000 mgs, but message reading is seamless. what are the MB file sizes of these in folder properties? > That's a point, thunderbird > file sizes was big (sum is 3.5 GB), but after manually compacting all > folders, the result is 250 MB (and INBOX shrinked from 1.4 GB to 32 MB). The > automatic compact setting in advanced/diskspace is the default 20 MB and > cache size is 350 MB, so it has no effect? Interesting. Well, there are rare cases under which compact can fail. For example perhaps you had a bad folder. 1. Do you use "Mark as deleted" model of message deletion? 2. I suggest you set mail.prompt_purge_threshhold to true ** so that you get prompted so you can see when thunderbird wants to compact. It might be interesting to see if a) compact works and b) if there is a correlation to some other activity if it doesn't work. ** bring up "config editor" at tools | options | advanced | general So the smaller folder sizes are having no effect on your filtering speed? > > And can you attach a log file per https://wiki.mozilla.org/MailNews:Logging > > for > > msgdblog:5 > I'll check the speedup and logging tomorrow. correction - msgdb:5
Flags: needinfo?(k.joe)
(In reply to k.joe from comment #7) > I think it is not a CPU related problem. Because you said as follows, it sounds "never performance issue in message filtering". > manually select run filters on folder from the menu, > then all messages are filtered in seconds magically, and moved to corresponding folders. And, you look misunderstanding, because you say as follows. > and when I start Thunderbird for first time, > then THB starts downloading body of all new messages (due to sync incoming folder), > Expected results: > Automatic incoming message filtering should not start while messages/headers downloading is in progress, Please note that ; - "Message filter upon new mail fetch" is invoked only when "message header fetch of new mail". - "Message filter upon new mail fetch" is not invoked upon that "download of entire mail data" is executed by auto-sync for Offline-Use=On folders. - "Message filter upon new mail fetch" is invoked only on Inbox, unless hidden option is enabled by your own-risk. - "Automatic new mail check" is invoked only on Inbox, unless "other than Inbox" is included in "folder for which new mail check is invoked" via Folder Properties. It sounds phenomenon like next ; (a) "Message filter upon new mail fetch" is somehow unreliable in your environment. Some mails are not moved by "Message filter upon new mail fetch" as expected. (b) "manual message filter run" works as expected. (c) Because new mail check of "other than Inbox" is not invoked unless Folder Properties is correctly set as you want, "mail which is moved to filter move target folder" is not automatically detected unless the "filter move target folder" is fortunately selected at a cached connection and IDLE is enabled. There are some known issues which may produce such phenomena. (i) If action=Delete and/or action=Stop Filter Execution is used in message filter, Bug 695671, Bug 552936 occurs, then result of message filtering is inconsistent, unreliable, unpredictable. (ii) When "Message filter upon new mail fetch" is invoked, message body is not fetched yet. Therefore, if filter rule for BODY is used, it looks for Thunderbird user "as if (a) occurred". If entire mail data is already downloaded by auto-sync, (b) is always true. (iii) If (c), detection of "newly added mail to "filter move target folder" is postponed. So, it looks for Thunderbird user "filter move is not executed" or "filter move is slow". IIRC, at least "unread mail count of filter move"updated, so this is perhaps not applicble to your case, but I'm not sure. (Q1) To bug opener : Is these kinds of issue involved in your case? Please surely rule out such phenomena from your bug report. (In reply to k.joe from comment #1) > Created attachment 8374575 [details] > Automatic filtering (In reply to k.joe from comment #2) > Created attachment 8374576 [details] > Manual filtering "Automatic filtering" of comment #1 is activity report by Tb for "Synchronization by auto-sync"(after move by message filter). "Manual filtering" of comment #2 is activity report by Tb for "message copy/move" which is perhaps invoked by filter run. (Q2) To bug opener : What is actual problem in your bug report with next bug summary at B.M.O for developers? > Bug Summary : Bulk message incoming message filter processing is very slow. High CPU usage.
(In reply to WADA from comment #15) > (In reply to k.joe from comment #7) > > I think it is not a CPU related problem. > > Because you said as follows, it sounds "never performance issue in message > filtering". Perhaps there is a side effect or limitation in message filtering and/or syncing when used together, not really CPU related performance issue. I'll check those cases. > "Automatic filtering" of comment #1 is activity report by Tb for > "Synchronization by auto-sync"(after move by message filter). > "Manual filtering" of comment #2 is activity report by Tb for "message > copy/move" which is perhaps invoked by filter run. > > (Q2) To bug opener : What is actual problem in your bug report with next bug > summary at B.M.O for developers? The actual problem is shown by the two cases and screenshots above; the problem related difference between them is the amount of moved messages together: - in "Automatic" case only 1 message moved at a time - in "Manual" case (running manually when message bodies are downloaded) whole bunch of matched messages moved together The two cases above runs on almost same incoming new messages. So, this is the real problem, and the elapsed time, while filtering is done.
Flags: needinfo?(k.joe)
Summary: Bulk message incoming message filter processing is very slow. High CPU usage. → Bulk message incoming message filter processing is very slow.
Flags: needinfo?(k.joe)
> Bug summary : Bulk message incoming message filter processing is very slow. To k.joe, is "problem you cited in this bug" next? When first download of many mails already held in IMAP Inbox after IMAP account creation, if auto-sync is enabled(enabled for all IMAP folders by default), and if Global Indexer of Gloda is enabled(enabled by default), after initial fetch of UID and Flags of all mails, and after initial fetch of standard message headers of all UIDs, actions by (a) "mail move by message filter at Inbox"(select Inbox, uid xx copy MoveTarget for moved mails) is interfered by; (b) at Inbox : fetch of entire mail data of all mails by auto-sync. ("uid aa-bb,pp-qq,yy-zz body.peek[]" is repeated until all mail is downloaded) (contention of Inbox folder, network bandwidth is consumed, CPU is consumed) (c) at other than Inbox including MoveTarget : fetch of entirme mail data of all mails by auto-sync. ("uid aa-bb,pp-qq,yy-zz body.peek[]" is repeated until all mail is downloaded) (contention at MoveTarget folder, network bandwidth is consumed, CPU is consumed) (d) at all IMAP auto-sync'ed folders : heavy CPU consumption by Indexing of all many many mails by Global Indexer This is already known phenomenon/issue since initial release of Auto-sync&Gloda(released as Tb 3.0). If very many mails has to be fetched/auto-sync'ed/indexed, high CPU usage continues for pretty long time, and Tb is unresponsive until "download of all mails by auto-sync" and "indexing of all mails by Gloda" completes. So, if very mails are held in IMAP folders, following is a clever user's action. 1. Disable auto-sync & Gloda, and do "message header fetch of all mails" & "filter move " only. 2. Enable auto-sync, and wait for download of all mail data. 3. Enable Gloda, and wait for indexing of all mails. 4. Daily use with auto-sync & Gloda enabled. Do you see such problem in your daily use of Tb? Does your bug summary properly express problem which you experienced/found?
(In reply to k.joe from comment #16) > (In reply to WADA from comment #15) > > (In reply to k.joe from comment #7) > > > I think it is not a CPU related problem. I'm not sure what you are trying to say, but CPU usage is important to your case. Please leave CPU in the bug summary. > > Because you said as follows, it sounds "never performance issue in message > > filtering". > Perhaps there is a side effect or limitation in message filtering and/or > syncing when used together, not really CPU related performance issue. At the very least, CPU usage is a symptom. We include symptoms in the bug summary. But may I suggest, please refrain from attempting to state what you think is the cause of this problem, and simply report what you see and test. I think confusion can creep into a bug when reporter attempts to diagnose the cause and at the same time describing what you see. (In reply to WADA from comment #17) > > Bug summary : Bulk message incoming message filter processing is very slow. > > To k.joe, is "problem you cited in this bug" next? > When first download of many mails already held in IMAP Inbox after IMAP > account creation, > if auto-sync is enabled(enabled for all IMAP folders by default), > and if Global Indexer of Gloda is enabled(enabled by default), good point - in k.joe's testing the problem was not tested with gloda disabled and sync enabled. And I think we don't know if the message bodies fully downloaded when the manual filter was done. If the message bodies were not downloaded before the manual filter then it's not valid to compare to sync is enabled plus automatic filtering. It would be incorrect then to assume the automatic filter process is slower. Note, you can determine if they were on disk by using the glodaquilla addon. With glodaquilla installed you can add the "on disk" column to the message list. > This is already known phenomenon/issue since initial release of > Auto-sync&Gloda(released as Tb 3.0). perhaps it will be that simple :) > If very many mails has to be fetched/auto-sync'ed/indexed, high CPU usage > continues for pretty long time, and Tb is unresponsive until "download of > all mails by auto-sync" and "indexing of all mails by Gloda" completes. > So, if very mails are held in IMAP folders, following is a clever user's > action. > 1. Disable auto-sync & Gloda, and do "message header fetch of all mails" & > "filter move " only. > 2. Enable auto-sync, and wait for download of all mail data. > 3. Enable Gloda, and wait for indexing of all mails. > 4. Daily use with auto-sync & Gloda enabled. > > Do you see such problem in your daily use of Tb? I'm confused about why you are asking this. This sounds like what someone might do to keep Thunderbird performant when they first bring up Thunderbird with a huge message store. But k.joe already has the entire message store DL and indexed, except for New messages that come in daily.
Summary: Bulk message incoming message filter processing is very slow. → Bulk message incoming message automatic filter is very slow with autosync enabled. ~50% CPU
please skip doing the msgdb log until questions in comment 14 and other comments are resolved/answered. thanks.
It's not that problem, which described above. > Do you see such problem in your daily use of Tb? Yes, I experienced such problem every day, especially for fist run, when there are very many new incoming mails for filtering. It's not an initial sync, but daily starting from a synced state, network bandwidth and CPU resources are not consumed. Today I've got 380 incoming mail, sync is enabled, and filtering/moving runs long-long time (still moving only 1 msg at a time). After 4 minutes at 224 remainning messages I close thunderbird, start it again, and run filters manually on incoming folder (from the tools menu), and filtering the remaining 224 messages is done about 2-3 seconds. I've attached msgdb and stdout/err logs about these cases. If sync is disabled on incoming folder, then automatic new mail filtering works fine too (moving more matching messages at a time to target folder), so this is some hidden limitation or bad filtering strategy issue.
Flags: needinfo?(k.joe)
Summary: Bulk message incoming message automatic filter is very slow with autosync enabled. ~50% CPU → Bulk message incoming message filter processing is very slow.
Summary: Bulk message incoming message filter processing is very slow. → Bulk message incoming message automatic filter is very slow with autosync enabled. ~50% CPU
ok, sorry, skipping logs, and with glodaquilla the "on disk" column shows green dots, so messages are downloaded, I think.
Turning off Global Indexer does not solve the problem, the results are same, only 1 msg filtered at the same time. I hope, finally we tracked down the problem: 2 of my 12 filters has "Mark as read" action beside the move, and if I disable these rules (msgs are matching rarely), then the new messages are not synced/indexed/downloaded to inbox, but landed directly in the filter's target folder, and as fast as I expected (while Sync and Global Indexer are turned on). Thanks and sorry for the other confusing answers. BTW, is it a known limitation/issue? And manual filtering is not affected?
Summary: Bulk message incoming message automatic filter is very slow with autosync enabled. ~50% CPU → Bulk message incoming message automatic filter is very slow when using "Mark as read" and "Move" actions, ~50% CPU, processing 1 message at the same time
If POP3, message filtering is approximately; (call "download mail #1 to #N") (A) Before Classification for(XX=1;XX<=N;XX++){ RETR mail #XX, and append mail data to file named Inbox; Create MsgDBHdr for mail #XX; Apply message filter to the downloaded mail #XX; if(FilterMove is needed){copy mail #XX to move target folder; remove MsgDBHdr for mail #XX; Truncate Inbox file;} Apply Junk Filter to the mail #XX(in Inbox, or in move target folder) } (B) After Classification for(XX=1;XX<=N;XX++){ RETR mail #XX, and append mail data to file named Inbox; Create MsgDBHdr for mail #XX; } Apply Junk Filter to all downloaded mails in Inbox; If Junk mail, move to Junk folder Apply message filter to mails in Inbox which was not moved by Junk filter "message filter application" in this case is similar to "Run Filter on Inbox"("After The Fact" filtering), so "Filter Move" is; (move target folders = F#1 to F#Q) for(ZZ=1;ZZ<=Q;ZZ++){ Move mails to F#ZZ; } If IMAP, header fetch and MsgDBHdr creation is perhaps executed on all new mails in one step. uid aa-bb,pp-qq,yy-zz fetch body.peek[headers(Subject From ...)] Create MsgDBHdr for all UID=aa-bb,pp-qq,yy-zz of new mails => "MsgDBHdr added" event is notified to event listeners. (auto-sync, Gloda, Virtual Folder, Biff etc. are perhaps the "event listener") However, "message filter application after MsgDBHdr creation" is perhaps; (C) Before Classification : Following is executed for each mail. If non-copy/non-move type action is requested, at Inbox, "uid mm store +Flags(\Seen)"(mark as Read case) If copy action is requested, at Inbox, "uid mm copy CopyTarget" If move action is requested, at Inbox, "uid mm copy MoveTarget" + "uid mm store +Flags(\Deleted) (D) After Classification : Following is executed on Inbox. Apply Junk filter to Inbox => If Junk, at Inbox, "uid jj-kk copy JunkFolder" + "uid mm store +Flags(\Deleted)" Apply Message filter to Inbox If non-copy/non-move type action is requested, at Inbox, "uid mm store +Flags(\Seen)"(mark as Read case) This is perhaps "per mail" basis if message filter, I'm not sure though. If copy action is requested, at Inbox, "uid mm-nn copy CopyTarget" for each copy target folder If move action is requested, at Inbox, "uid mm-nn copy MoveTarget" + "uid mm-nn store +Flags(\Deleted)" for each move target folder Because auto-sync already knows new mails, auto-sync can independently invoke following at cached connection for Inbox. "uid gg-hh fetch body.peek[] for some mails" x PP times, with waiting for a while, until all mails are sync'ed. While "uid gg-hh fetch body.peek[] " is executed at cached connection for Inbox, each "uid mm copy MoveTarget" has to wait. (this is a "Interfere by auto-sync" what I called) If After Classification, IMAP command for "message filter move" is perhaps executed in "per move target folder" basis instead of "per mail" basis. k.joe(bug opener), can you observe difference between "Before Classification" and "After Classification"? (In reply to k.joe from comment #22) > 2 of my 12 filters has "Mark as read" action beside the move, > and if I disable these rules (msgs are matching rarely), > then the new messages are not synced/indexed/downloaded to inbox, > but landed directly in the filter's target folder, and as fast as I expected (while Sync and Global Indexer are turned on). If "Mark as read" is requested, "uid xx(-yy) store +Flags(\Seen)" is needed at Inbox before "message filter move" is executed. It takes at least "a while". auto-sync looks to invoke "uid xx-yy fetch body.peek[]" before IMAP commnd for "message filter move" is executed at cached connection for Inbox. With "Mark as read" action, will "After Classification" alter phenomena? (In reply to Wayne Mery (:wsmwk) from comment #18) > I'm not sure what you are trying to say, but CPU usage is important to your case. This bug is for "delay in message filter move when auto-sync is enabled", isn't it? Why can "high CPU usage by auto-sync" be culprit of "delay in message filter move"? "Excess CPU usage by auto-sync & Gloda" is common phenomenon in IMAP & SSL & Gloda of Thunderbird, isn't it? "Excess CPU consumption by SSL" is common phenomenon of Mozilla family, isn't it? "Short freeze while IMAP job is running" is common & well known phenomenon in IMAP of Thunderbird, isn't it?
Sorry, I was wrong, again. One of these two rules has a "hidden" body matching rule, which is cause body downloads (and one by one message filtering?), certainly. Tested without this body matching rule, so move and "Mark as read" works correctly (like without autosync).
Summary: Bulk message incoming message automatic filter is very slow when using "Mark as read" and "Move" actions, ~50% CPU, processing 1 message at the same time → Incoming message automatic filter is slow when using body matching rule and autosync enabled, processing only 1 message at the same time, ~50% CPU
Summary: Incoming message automatic filter is slow when using body matching rule and autosync enabled, processing only 1 message at the same time, ~50% CPU → Delay in automatic message filter move when a body matching rule exists and autosync enabled, processing only 1 message at once, ~50% CPU
(In reply to k.joe from comment #24) > Sorry, I was wrong, again. One of these two rules has a "hidden" body matching rule, > which is cause body downloads (and one by one message filtering?), certainly. > Tested without this body matching rule, so move and "Mark as read" works correctly (like without autosync). "body matching rule in message filter" won't invoke fetch of body by himself. "body matching rule in message filter" merely tries to use message body which is already held in offline-store file by auto-sync. So, following occurs(current design/implementation). - "body matching rule in message filter upon new mail fetch" always returns False, because message body is not fetched by auto-sync yet. - "body matching rule in message filter by Run Filter" can use message body held in offline-store file, if "Run Filter" is manually executed after completion of auto-sync for UID of the mail. Following mechanism? - If "body matching rule" is applied upon new mail fetch, message filter tries to read message body data in offline-store file. - By access of "message body data in offline-store file", auto-sync tries to fetch entire mail data by "uid xx fetch body.peek[]". - "uid xx fetch body.peek[]" or "uid xx-yy fetch body.peek[]" is executed at cached connection for Inbox. - Then IMAP command execution for "mail move be message filter upon new mail fetch" is postponed. If so, another concern; "New mail alert by Biff" tries to fetch first 2048 bytes of mail data, when "Message Preview Text" is checked at General/When new messages arrive:/Show an alert./Customize of preference, regardless of that "[?] Sow an alert" is checked or not checked. (Note: "Message Preview Text" is checked by default) This is done by "uid xx-yy fetch body.peek[text]<0.2048>" at cached connection for Inbox(See Bug 764662). IIUC, "New mail alert by Biff" is invoked after "message filter application upon new mail fetch". If so, problem of Bug 764662 usually occurs only when "body matching rule" is used in message filter?
If "Delay in automatic message filter move when a body matching rule exists and autosync enabled" is correct, workaround is; Use "Body" condition in "Manually Run" filter rule only. Never use "Body" condition in "Getting New Mail" filter rule.
Phenomenon was confirmed: (Test scenario) Several mails only in Inbox(9 mails, UID=xx:yy where xx<yy, existent uid in range xx-yy is 9 mails only) 6 mails : from = aa, body contains cccc 3 mails : from = bb, body contains cccc To force fetch/filtering of all mails in Inbox upon restart of Tb, delete Inbox.msf and restart Tb. (Test case) Filter rules : Apply Filter When: Case-A (without Body Filter) Rule-1 : If Body conatins cccc, Add Tag tag1 : Manually Run only, "Getting New Mail" is not checked Rule-2 : If from is aa or bb, Add Tag tag2 : Manually Run && Geting New Mail(before Classification) Rule-3 : If from is aa or bb, Move to FolderX : Manually Run && Geting New Mail(before Classification) Case-B (with Body Filter) Rule-1 : If Body conatins cccc, Add Tag tag1 : Manually Run only, "Getting New Mail" is unchecked Rule-2 : If from is aa or bb, Add Tag tag2 : Manually Run && Geting New Mail(before Classification) Rule-3 : If from is aa or bb, Move to FolderX : Manually Run && Geting New Mail(before Classification) (Test result, quick check of IMAP log) Case-A (without Body Filter) : uid 1:* fetch (FLAGS) uid fetch 511:519 (UID X-GM-MSGID X-GM-THRID X-GM-LABELS RFC822.SIZE FLAGS BODY.PEEK[HEADER.FIELDS (From To Cc Bcc Subject Date Message-ID Priority X-Priority References Newsgroups In-Reply-To Content-Type Reply-To)]) *** end of folder open of Inbox *** "uid nn store +Flags(tagN)" is executed for each mail in Inbox uid move 511:519 "FolderX" (Gmail IMAP supports MOVE extension, so MOVE command is used) *** end of new mail fetch and message filtering *** After a while, following is executed by auto-sync at FolderX : "UID fetch nn (UID RFC822.SIZE BODY.PEEK[])" for each mail in FolderX Case-B (with Body Filter) : uid 1:* fetch (FLAGS) uid fetch 511:519 (UID X-GM-MSGID X-GM-THRID X-GM-LABELS RFC822.SIZE FLAGS BODY.PEEK[HEADER.FIELDS (From To Cc Bcc Subject Date Message-ID Priority X-Priority References Newsgroups In-Reply-To Content-Type Reply-To)]) *** end of folder open of Inbox *** Just after it, at Inbox, following is requested immediately for all new mails in Inbox. UID fetch 511:519 (UID RFC822.SIZE BODY.PEEK[]) *** end of folder auto-sync of all new mails at Inbox *** "uid nn store +Flags(tagN)" is executed for each mail. Note: because auto-sync of Inbox is already executed, Body filter works. uid move 511:519 "FolderX" (Gmail IMAP supports MOVE extension, so MOVE command is used) *** end of new mail fetch and message filtering *** After a while, following is executed by auto-sync at FolderX : "UID fetch nn (UID RFC822.SIZE BODY.PEEK[])" for each mail in FolderX In this case, report at Activity Manager looks for user as if "move mail by filter" is executed for each mail. From perspective of IMAP protocol level flow, difference is following only : If Body Filter is used, at Inbox, "uid fetch xx:yy (UID RFC822.SIZE BODY.PEEK[])" is executed by single IMAP command just after Inbox open, just before IMAP command execution for "message filtering". Is it intentional change to support "Body Filtering upon new mail check"? By the way, if many new mails exists, "uid fetch xx:yy (UID RFC822.SIZE BODY.PEEK[])" simply takes pretty long. So, "internal phenomenon with Body filter "is merely "queued IMAP requests by message filter" is postponed by auto-sync. However, "external phenomena which is observed at Activity Manager" is pretty different from "no body filter" case.
Status: UNCONFIRMED → NEW
Ever confirmed: true
Component: Filters → Networking: IMAP
OS: Linux → All
Product: Thunderbird → MailNews Core
Hardware: x86_64 → All
If "Filter after Junk Classification", phenomenon was different from "Filter before Junk Classification". Case-C (with Body Filter, with Filter after Junk Classification) Rule-1 : If Body contins cccc, Add Tag tag1 : Manually Run && Geting New Mail(after Classification) Rule-2 : If from is aa or bb, Add Tag tag2 : Manually Run && Geting New Mail(after Classification) Rule-3 : If from is aa or bb, Move to FolderX : Manually Run && Geting New Mail(after Classification) After open Inbox and heder fetch for uid=556:554, fetch of entire mail data is executed for first mail only. at Inbox, UID fetch 556 (UID RFC822.SIZE BODY.PEEK[]) After it, tag2 only is stored by filter. uid store 556:564 +FLAGS (tag2) Note: Rule-1(body filter) is not hit, because auto-sync is not executed yet for uid=554:554, and auto-sync of first mail, "UID fetch 556 (UID RFC822.SIZE BODY.PEEK[])" is perhaps done after filter aappliction. And, move to MoveTarget folder is executed for all mails. uid move 556:564 "FolderX" Then, at Inbox, fetch of entire mail is requested for each mial, although nothing is returned because already moved. at Inbox : UID fetch nn (UID BODY.PEEK[HEADER.FIELDS ( ... )] BODY.PEEK[] and, at FolderX, "uid store 96:104 +FLAGS (tag2)" is executed by "filter move of tagged mails" In this case, "fetch of entire mail data of new mails at Inbox by auto-sync " is apparently executed after "message filter". Newly found workaround of "Delay in filter move due to Body filter" : Filter after Junk Classification Body filter won't work in this case, but filter move is executed immediately. So, if "number of mails which should be moved by Body filter" is not so large, and if almost all "new mails which should be moved by filter upon new mail check" is irrelevant to "Body Filter rules" "Filter after Junk Classification" has advantage.
To reduce IMAP log lines, tested again with crafted small text mails, with CONDSTORE support disabled. Test mails : 5 mails From: sender@sample.com Message-Id: header = <... ... .test-001>, <... ... .test-002>, ... , <... ... .test-005>, Subject: heder = test-001, test-002, ... , test-005 Message Body text = test-001, test-002, ... , test-005 uid of mails in Inbox : Case-B, "Filter after J unk Classificaation" case : 588, 589, 590, 591, 592 Case-C, "Filter before Junk Classificaation" case : 593, 594, 595, 596, 597 Filter Rules : Rule-1 : If Bdy contains test-0, Add Tag tag1 Rule-2 : If From is sender@sample.com, Add Tag tag2 Rule-3 : If Subject begins with test-0, Move to MoveTarget All 5 mails are moved to MoveTarget folder by Rule-3. IMAP log options : SET NSPR_LOG_MODULES=imap:5,ImapAutoSync:5,IMAPOFFLINE:5,MsgCopyService:5 Log line before first "uid fetch 1:* (Flags)" at Inbox are removed.
When "Filter before junk Classification", following was observed in IMAP log. 1. Just after initial fetch of headers by "uid fetch ... body.peek[Heders( ...)] Entire mail data of all new mils is executed : uid fetch ... body.peek[] 2. upon each end of download of mail data of each uid=UID_nn, following is requested or queued. customKeywords>UID>/INBOX>UID_nn,>tag1> customKeywords>UID>/INBOX>UID_nn,>tag2> CopyMessages request - src imap://yatter.king%40gmail.com@imap.gmail.com/INBOX dest imap://yatter.king%40gmail.com@imap.gmail.com/MoveTarget numItems 0 type=0 DoCopy(or QueueRequest) - src imap://yatter.king%40gmail.com@imap.gmail.com/INBOX dest imap://yatter.king%40gmail.com@imap.gmail.com/MoveTarget numItems 1 type=0 3. After these requests, "move message" is executed by "uid UID_nn move MoveTarget" for each uid. This "CopyMessage request foe each moved mail" is perhaps cause of phenomenon like "move each mail at Activity Manager" at Activity Manager. When "Filter after Junk Classification", "fetch of entire mail data of all uid=xx:yy for auto-sync" was also requested and was queued just after initial heder fetch by "uid xx:yy ... body.peek[Heders(...)]". However, before execution of "uid fetch xx:yy ... body.peek[]" command, request of "store flag tag2 to all mail" and "DoCopy(==move) aall mails to MoveTarget " is also requested and is queued. fetch>UID>/INBOX>588,589:592 customKeywords>UID>/INBOX>588:592>tag2> CopyMessages request - src imap://yatter.king%40gmail.com@imap.gmail.com/INBOX dest imap://yatter.king%40gmail.com@imap.gmail.com/MoveTarget numItems 0 type=0 DoCopy - src imap://yatter.king%40gmail.com@imap.gmail.com/INBOX dest imap://yatter.king%40gmail.com@imap.gmail.com/MoveTarget numItems 5 type=0 onlinemove>UID>/INBOX>588,589:592>/MoveTarget i.e. If "After Classification", message filter won't wait for end of "uid fetch xx:yy ... body.peek[]" requested by auto-sync, and DoCopy request(=move mails to MoveTarget request by message filter) is executed by single request/single "uid move xx:yy MoveTarget" command.
Component: Networking: IMAP → Filters
Test-Case : Add tag2, Move to MoveTarget = Before Classification / Body Filter(Add tag1) = After Classification uid of mails in Inbox : 603, 604, 605, 606, 607 Filter Rules : Rule-1 : (After Junk Classification) If Bdy contains test-0, Add Tag tag1 Rule-2 : (Before Junk Classification) If From is sender@sample.com, Add Tag tag2 Rule-3 : (Before Junk Classification) If Subject begins with test-0, Move to MoveTarget In this case, because Body Filter is contained, "uid fetch xx:yy ... body.peek[]" is requested/issued first just after initial header fetch. However, message filter execution at "Before Junk Classification" step won't wait for "download completion of entire mail data for relevant UID". So, Rule-2/Rule-3 is executed at "Before Junk Classification" step before auto-sync of Inbox, then, "Add tag2" is queued for each UID, and DoCopy for "Move to MoveTarget" is requested/queued for all 5 moved mails, before/while executing auto-sync. DoCopy - src imap://yatteer.king%40gmail.com@imap.gmail.com/INBOX dest imap://yatter.king%40gmail.com@imap.gmail.com/MoveTarget numItems 5 type=0 Because "move to MoveTarget" is requested for any mail at "Before Classification" step, Rule-1(After Classification) won't be executed in this test. Therefore, even though "uid nn store flags(tag2)" for each mail by Rule-2, and "uid move xx:yy MoveTarget" for all mails by Rule-3, are executed after "download of entire mail body of all mails at Inbox" by auto-sync, feedback of "move to MoveTarget"(executed by CopyMessages request/single DoCopy for all 5 mails) is done at Activity Manager panel only once, and feedback of "new mail count at Folder Pane" is also done only once. Workaround of this bug : If Body Filter Rule is needed in IMAP, set "Filter after Junk Classification" instead of "Filter before Junk Classification"
Previous comment was partially wrong. When "Body Filter Rule" is changed to "After Junk Classification", "First Body.Peek after initial header fetch" was "uid fetch xx:yy ... body.peel[TEXT]<0.2048>" for PreviewText by Biff. (1) Initial header fetch of all new mails (2) "uid fetch xx:yy ... body.peel[TEXT]<0.2048>" is requested by Biff. No "queued" log, because connection is free. (3) By filter(Before Junk Classification), "store +Flag(tag2)" is queued for each UID By filter(Before Junk Classification), "Move all mails to MoveTarget"(==DoCopy of 5 new mails) is requested. (4) After end of "Before Classification" step, "fetch of entire mail data of all mails" is queued. This is perhaps by "Body Filter with After Classification". (5) Then, following are executed in this order. uid fetch xx:yy ... body.peel[TEXT]<0.2048> (for PreviewText of Biff) uid store nn +Flags(tag2) for each mail uid xx:yy move MoveTarget uid fetch xx:yy ... body.peel[] (for auto-sync) Note: Because all mails are already moved by Move command in this test, nothing is returned in this case. If Move=="copy MoveTarget" + "store Flad(\Deleted)", "entire mail data of all mails" are downloaded at this step. (6) If some new mails are not moved by "Before Junk Classification" rules, filter rules of "After Classification" are applied to remaining new mails. This is perhaps independent from "entire mail data fetch by auto-sync", because "After Classification". "Body filter at After Classification works or not" perhaps depends on "uid fetch xx:yy ...body.peek[] by auto-sync" ended before "After Classification" step or not.
To see difference in IMAP flow between "Before Junk Classicfication" and "After Junk Classification", tested next case. Gmail IMAP is used(Move extension is supported), Tb's CONDSTORE support is disabled. Max cached connections=1, to force serializing of all IMAP command execution, and for simple log. 6 small test mails. mail-1 = Subject: test-001, body = test-001 uid in Inbox = 638 mail-2 = Subject: test-002, body = test-002 uid in Inbox = 639 mail-3 = Subject: test-003, body = test-003 uid in Inbox = 640 mail-4 = Subject: test-101, body = test-101 uid in Inbox = 641 mail-5 = Subject: test-102, body = test-102 uid in Inbox = 642 mail-6 = Subject: test-103, body = test-103 uid in Inbox = 643 Filter Rules : Rule-1-1 : Before Junk Classification : If Subject begins with test-0, Add tag1 Rule-1-2 : Before Junk Classification : If Subject begins with test-0, Move to MoveTarget Rule-2-1 : After Junk Classification : If Body contains test-1, Add tag2 Rule-2-2 : After Junk Classification : If Subject begins with test-1, Add tag3 Rule-2-3 : After Junk Classification : If Subject begins with test-1, Move to MoveTarget Auto-Sync is enabled, but Offline-Use=On is set for Inbox & MoveTarget only, to avoid excess log. IMAP log option : SET NSPR_LOG_MODULES=imap:5,ImapAutoSync:5,IMAPOFFLINE:5,MsgCopyService:5 To ease of log reading, following is done. Log lines before first open of Inbox after restart of Tb. Because Subject: header is sufficient to identify a mail in test, "mail data line except Subject: header" is removed from response to FETCH BODY.PEEK[]. Add New Line before/after each IMAP command for ease of reading. Remove following log lines for data stream log. ": ReadNextLine [" ; Remove following log lines in IMAP url scheduling. ": proposed url = " ; ": considering playing queued url:" ; ": creating protocol instance to play queued url:" ; ": failed creating protocol instance to play queued url:" ; ": playing queued url:" ; ":ProcessCurrentURL: entering" ; By this removal, ": queuing url:" log for request, and :ProcessCurrentURL:" just before requested IMAP command execution, is seen. By ": queuing url:" log and "CopyMessages" log, "when IMAP command execution was requested by filter" is known. "First executed IMAP command after header fetch" is 14 UID fetch 638:643 ( ...BODY.PEEK[TEXT]<0.2048>) for previewText by Biff. There is no corresponding ": queuing url:" log. i.e. "fetch of previewText by Biff." is requested before filter execution. By "Before Junk Classification" step(no Body Filter), " "store tag1" is requested for each mail1 to mail3, and single "move" is requested for mail 1 to mail3. Between "Before Classification" and "After Junk Classification"step, "sync of Inbox(fetch body.peek[] for all mails) is queued. This is perhaps because "Body Filter" is used in "After Junk Classification". By "After Junk Classification" step(with Body Filter), Request for "store tag2"(by Body Filter) is not logged. This indicates that "Body contains test-1" returned false. Single "store tag3" is requested for mail4 to mail6, and single "move" is requested for mail 4 to mail6. Note-1: This is executed before actual execution of "uid fetch 638:643 body.peek[]". i.e. Body filter of "After Classification" won't work because auto-sync is not completed yet. Note-2: "store tag3" is requested for uid=641,642,643" at once. This is different from "Before Junk Classification". When "Before Junk Classification", "store tag" is requested for each tag of each mail. Because "uid fetch 638:643 body.peek[]" for auto-sync is executed after execution of "uid move 638,639,640 MoveTarget" requested by "Before Classification", entire mail data of only 3 mails(uid=641,642,643) is returned from IMAP server when "fetch body.peek[]" command is actually executed. After them, "UID fetch 638:643 ( ...BODY.PEEK[TEXT]<0.2048>)" is seen again. Biff perhaps requests previewText after filter execution again. As seen in above test, if "Body Filter in "After Junk Classification" only(i.e. no Body Filter in "Before Junk Classification"), "Body Filter of After Junk Classification" was useless. So workaround of this bug is; If Body Filter Rule for IMAP, use "Apply filter on/Manual Run" only, and never use "Apply filter on/Getting New Mail(any of Before, After)". And, if Body Filter is used in both "Before Junk Classification" and in "Before Junk Classification", this bug occurs at "Before Junk Classification" phase。 Further, funny phenomenon was observed in "After Junk Classification" phase and result was unpredictable and unreliable. Body Filter of "After Junk Classification" didn't work on any new mail in some cases, because entire mail data is not stored in offline-store by auto-sync. However, in some other cases, Body Filter of "After Junk Classification" worked on a few new mails, but didn't work on other new mails. So, if Body Filter in IMAP is mandatory for Thunderbird user, and it it should work upon Getting New Mail, - "Apply filter on/Getting New Mail(Body Filter in Before Junk Classification only)" is needed. - User should accept phenomenon of this bug(Delay in filter move) : Filter application is executed after download of entire mail data of new mails, so it takes long. "Filter move" is executed by "one DoCopy request per one moved mail", so excess job is needed, then it takes long.
Attachment #8488980 - Attachment is obsolete: true
Attachment #8489046 - Attachment is obsolete: true
Attachment #8489211 - Attachment description: IMAP Log for Filter Move : Add tag & move without Body filter at "Before Classicfiction", Add tag & move with Body Filter at "After Classicfiction" → Full IMAP Log for Filter Move : Add tag & move without Body filter at "Before Classicfiction", Add tag & move with Body Filter at "After Classicfiction"
Summary: Delay in automatic message filter move when a body matching rule exists and autosync enabled, processing only 1 message at once, ~50% CPU → Delay in automatic message filter move when a body matching rule exists(Body condition, with Apply filter on/Getting New Mail/Filter before Junk Classification) and autosync enabled, processing only 1 message at once, ~50% CPU
FYI. I've opened Bug 1067706 for funny phenomenon observed by "Body Filter" of both "Before Classifiction" and "After Classification".
See Also: → 1067706
FYI. If Body is used as condition, or if action requires message body, filter application is executed after download of entire mail data. Following is seen in IMAP log. "uid xx:yy ( ... FETCH.BODY.PEEK[])" is issued first. upon "Normal Message End Download Stream" of ech UID, message filter for the UID is invoked, and IMAP request by filter action is queued. > http://mxr.mozilla.org/comm-central/source/mailnews/imap/src/nsImapMailFolder.cpp#668 > 668 // If a body filter is enabled for an offline folder, delay the filter > 669 // application until after message has been downloaded. See also code where m_filterListRequiresBody is referred. > http://mxr.mozilla.org/comm-central/search?string=m_filterListRequiresBody&find=&findi=&filter=^[^\0]*%24&hitlimit=&tree=comm-central "delayed filter application until message has been downloaded" doesn't look "new feature". Message Filter = "Filter upon new mail fetch" and "Manual filter run on folder"(AterTheFact filter). Because standard headers only is fetched if IMAP, message header data is unfolded upon message header fetch, because unfolding is needed for header parsing. if custom header is needed, mailnews.customHeaders is used and additional headers are fetched. if message body is needed, "uid xx:yy BODY.PEEK[]" is issued, and filter execution is delayed until message body download. note: message header is not unfolded, because mail data is held in buffer for data stream . mailnews.customDBHeaders was added. "Filter upon new mail fetch" was same as current "Filter before Junk Classification". "Apply selected filters on selected messages" is supported, an addition to "Manual filter run on folder"(AterTheFact filter). Auto-sync is added to IMAP. After these, each filter rule now has option of "Filter before Junk Classification" or "Filter after Junk Classification". Each added new feature is for different purpose, then mismatches among added new features was produced.
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".
See Also: → 935934
Kent James (:rkent), is this bug intended behavior?
Flags: needinfo?(kent)
Certainly the delay in applying the filter when the body is downloaded, and a body search is needed, was added in 'Bug 127250 - "Body" filter for IMAP messages downloaded for offline use' and is intended behavior. Otherwise body search would not work at all in incoming filters. But both cases use the IMAP filter action code in nsImapMailFolder::ApplyFilterHit to perform the filter actions, rather than the manual filter code. The request of this bug in comment 0 is not desirable: "Automatic incoming message filtering should not start while messages/headers downloading is in progress, or must index/filter all downloaded new messages in one round (like manual run, which is significantly faster), not just one by one." Desired behavior is that 1) messages that are moved by a filter never appear in the initial folder, and 2) messages appear as soon as possible, so that if there are a lot of messages to download, we see the first messages before the last message is downloaded. This pretty much requires that filtering takes place on each message as it is downloaded, without waiting for all messages. So the expected behavior in comment 0 is WONTFIX. Yet the reporter's problems are real, and I do not mean to discount them. A body search term will dramatically slow down IMAP download, I don't see how this is avoidable unless you could use a server search for this instead. The application of the move already uses the IMAP move coalescer which tries to combine multiple moves to improve performance. I have not investigated how the combination of circumstances in this bug affects the move coalescer, perhaps there is some possible improvement there. You would need to prove though that the slowdown is due to the move action rather than the body search. Perhaps that has already been established, I did not review all of the details in this bug.
Flags: needinfo?(kent)
(In reply to Kent James (:rkent) from comment #41) > ... > perhaps there is some possible improvement there [in the imap move coalescer]. You would need to prove > though that the slowdown is due to the move action rather than the body > search. Perhaps that has already been established, I did not review all of > the details in this bug. k.joe, a profile of this activity would be very helpful. See instructions at https://developer.mozilla.org/en-US/docs/Mozilla/Performance/Reporting_a_Thunderbird_Performance_Problem_with_G (note: I'm emailing you the addon to install for step 3 because newer versions of the addon do no run on Thunderbird)
Flags: needinfo?(k.joe)
Sorry, I don't produce profile output till now, but the problem still exists in Thunderbird 45.2.0, and I try to find a relatively easy way to reproduce this issue: Step1: - create one filter with subject matching: bsd, action: move - create another one with body matching: aaasd, action: delete Step2: - send some small email from bash, and wait 1-2 minutes after this: for i in $(seq 1 15) ; do echo bsd$i | mail -s bsd$i xxx.yyy@gmail.com ; echo aaasd$i | mail -s aaasd$i xxx.yyy@gmail.com ; done Experiment1: - close TB - do Step2 - start TB Results: - first all incoming email appears in inbox (with bold letters) - the body matched ones does not contain new icon (spark?) before the subject, while the subject matched contains - filtering takes 20 secs, activity displaying 1 move and 1 delete (move to trash) action repeatedly Experiment2: - disable filters - close THB - do Step2 - start THB - enable filters - select the new emails, and run manual filtering on them Results: - all incoming email appears in inbox (with bold letters and new icon) - filtering takes 2 secs, activity displaying 15 move and 15 delete (move to trash) actions Experiment3: - disable body matching filter - close THB - do Step2 - start THB Results: - only unfiltered emails appears in inbox (with bold letters and new icon) - filters seems applying immediately in the background, activity displaying 15 move actions
Flags: needinfo?(k.joe)
József During the DL and filtering process, is the UI responsive? Or, is it super slow?
Flags: needinfo?(k.joe)
The UI is reponsive normally, I can read those and other emails too during filtering. All incoming emails appears at once, and then filtering. Reproduced with the steps above on two independent TB and IMAP email service provider.
Flags: needinfo?(k.joe)

Please run the performance profiler:

  1. install profiler add-on into thunderbird - download the file from https://github.com/firefox-devtools/Gecko-Profiler-Addon/blob/master/gecko_profiler.xpi?raw=true and in Tools > add-ons click the gear to install add-on from file
  2. Follow instructions at https://profiler.firefox.com/ (videos BASED ON FIREFOX at https://profiler.firefox.com/docs/#/./videos-intro )
  3. Create a profiler URL and post it here.

You must be using Thunderbird beta from https://www.thunderbird.net/en-US/channel/ or current nightly build from https://archive.mozilla.org/pub/thunderbird/nightly/latest-comm-central/

Flags: needinfo?(k.joe)

Alfred, can you reproduce?

Flags: needinfo?(infofrommozilla)

József writes "now I use completely different setup, sp and server side filtering, so I can't experiencing this issue."

Flags: needinfo?(k.joe)
Flags: needinfo?(infofrommozilla)
Whiteboard: [see comment 41][needs profile?]

Still an issue - I'm seeing this now that I have a few body filters.

Profile instructions at https://support.mozilla.org/en-US/kb/profiling-thunderbird-performance

No longer blocks: 1067706
Depends on: 1067706
See Also: 1067706 →
Summary: Delay in automatic message filter move when a body matching rule exists(Body condition, with Apply filter on/Getting New Mail/Filter before Junk Classification) and autosync enabled, processing only 1 message at once, ~50% CPU → Severe delay with body matching rule exists(Body condition, with Apply filter on/Getting New Mail/Filter before Junk Classification) and autosync enabled, processing only 1 message at a time, ~50% CPU
Whiteboard: [see comment 41][needs profile?] → [see comment 35,41,43][needs profile?]

I've been using body filter in one of my rules for a few months now - all it takes is one filter to make downloading messages terminally slow.
imap. filter before junk classification. gloda enabled. autosync enabled.

performance profile:

ref comment 35, comment 41. Not sure why I changed bug 1067706 to be blocking this one.

Whiteboard: [see comment 35,41,43][needs profile?] → [see comment 35,41,43]
Severity: normal → S3

Let's make a new profile

Flags: needinfo?(vseerror)
Whiteboard: [see comment 35,41,43] → [see comment 35,41,43][needs performance profile]

Andreas, do you still encounter this problem?

Flags: needinfo?(vseerror)
Flags: needinfo?(as2014+bugzilla)

Did I get tagged needinfo? accidentally? I cannot recall that I was ever directly affected by this bug. I don't think I ever reproduced anything here. Maybe I CCed myself instead of just following b/c in 2019 I had issues with opening attachments in a particular setting, and I vaguely suspected some connections between this report and bug #216308, bug #770888, bug #1430480, and bug #680004

Flags: needinfo?(as2014+bugzilla)
Flags: needinfo?(vseerror)

Is there sufficient information in the bug report for you to profile this?
https://support.mozilla.org/en-US/kb/profiling-thunderbird-performance

Flags: needinfo?(vseerror)
Flags: needinfo?(vlucaci)
Flags: needinfo?(ramona)

Hello,

I have tried to reproduce this issue with 129.0b1(20240708223515), 1280.esr(20240710185639), and 115.13.0(20240709183211) with macOS 14, Windows 11 and Ubuntu 22.04 using STR and relevant information from comment 43, comment 49 and comment 50 but did not succeed.

Flags: needinfo?(vlucaci)
Flags: needinfo?(ramona)
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: