Open Bug 444793 Opened 16 years ago Updated 3 days ago

Edit Message Filter window is scrolling slowly, bad performance for large multi-criteria filters

Categories

(Thunderbird :: Filters, defect)

x86
All
defect

Tracking

(Not tracked)

People

(Reporter: mcow, Unassigned)

References

(Blocks 1 open bug, )

Details

(Keywords: perf, testcase, Whiteboard: [needs profile][filter-mgmt])

Attachments

(3 files, 2 obsolete files)

If you have a filter with a number of criteria, the Edit Filter window takes a long time to initialize and performs badly -- scrolling the list, in particular, is slow.

I'm attaching an example filter that has ten criteria.  This comes from a filter that had thirty or so criteria, which I had to split into three parts because it became impossible to edit at the larger size.  Even this smaller one has what I think is unacceptable performance.  I do have a slow machine: 750MHz P4 from c. 2000.  But compared to, say, the performance of the tree widget in the folder pane, the edit filter interface is "teh suck."

I imagine the slowness is due to the complexity of the widget.  Probably the way to fix it is to create a custom widget with some smart XBL and so on, rather than the widget hierarchy in place.
Has the pref changed compared to branch?
You mean "perf"?  No, I don't think so, but I don't have any metric.
Product: Core → MailNews Core
Checked with Tb trunk(2009/2/16 build) and Tb 2.0.0.19 on MS Win(Core2 Duo PC).
 - 60 conditions in a filter rule
 - CPU utilization of Tb by Task Manager of MS Win, during scroll of conditions
   - Tb trunk    : 40 to 50 % (if single CPU, 80 to 100 %)
   - Tb 2.0.0.19 : around 22% (if single CPU, 44 %)
 - "Slowness of scroll" was not observed on Core2 Duo PC/MS Win.
do testcases also use much memory? 
XBL bug query: http://bit.ly/b9INVB

Bug 518305 also has testcases
Keywords: testcase
Summary: Edit Message Filter window slow, bad performance for multi-criteria filters → Edit Message Filter window slow, bad performance for large multi-criteria filters, slow loading and scrolling
This is a major issue that is frequently complained about on GS (see for example http://getsatisfaction.com/mozilla_messaging/topics/reordering_message_filter_is_slow#) The changes in TB3 have essentially made it unusable for users with large numbers of filters.

I reset the severity to try to increase the visibility of this bug somewhat, though in practice that has little effect I suppose. If there is any triage of issues for TB 3.2, it would be great if one of the UI gurus could seriously consider taking this.
Severity: minor → major
For slow loading part.
Slow at any loaing? First load only?
If slowness in first load only, is bug 571419 relevant?
I don't know if bug 571419 is part of it or not.
(In reply to comment #10)
> I don't know if bug 571419 is part of it or not.

let's assume the worst, and someone needs to test it :)


unclear if http://getsatisfaction.com/mozilla_messaging/topics/message_filters_are_not_autoscrolling_when_you_click_move_down is related
Depends on: 571419
Whiteboard: [gs][needs testing in against bug 571419]
(In reply to comment #11)
Thanks Wayne for sending the correct location to followup on the bug. I will help in any way I can to keep from having to revert to TB2.  I am up for any Beta testing needed.
Attached image filter list screen shot (obsolete) —
I tested Andy's filter file (about 320 filters, combined with my 120 filters over various accounts) in v3.0.4, 3.1.2 and 3.1.5 and trunk with pretty much similar results, although 3.0 "seemed" better.  Results on a fairly fast machine : 4-5 seconds to load and display the UI. Scrolling isn't slow, but it lags. Lagging meaning a) clicking the scroll arrow has reasonable speed, but it's not fast, and b) I can drag the scroll bar but the window of filter names doesn't paint as fast as I scroll. And when I stop scrolling after dragging to the top, sometimes the full pane has not been painted, per attached image. Will try on laptop tonight where I'd be surprised if it didn't take much longer.

Andy's issue might not be the same issue as this bug. Perhaps someone can point out a better choice of bug.
Blocks: 627991
(1) Enable JavaScript of browser,
    Load the html, specify number of rules, Generate.
(2) Select+All, Copy
(3) Open msgFilterRules.dat by text editor,
    Select+All, Paste, Delete top most next two lines. 
    > Number of filter rules:    
    >

When 10000 is specified, 10000 rules are defined, and file size of msgFilterRules.dat becomes 1,259 KB (1.26MB).
First display of filter just after restart of Tb :
  it takes sufficiently long for me.
Second or later display of filter :
  not quick, time lag exists, but not very slow for me.

I didn't check performance of scroll, edit etc. of filter.
Checked only difference between (a) "initial load"(physical read of msgFilterRules.dat for each one byte is executed) and (b) "second or later load"(file read of msgFilrerRules.dat is not executed, because loaded in memory after first load).

Please never mis-evaluate impact on "first filter load time" by "physical read for each one byte upon first load of filter rule" when file size of msgFilterRules.dat is big.
If message filter runs(by mail download) just after restart of Tb, msgFilterRules.dat is loaded by the "filter run" before you open message filter.
If you are discussing about "performance, time to take to do something on filter", rule out affect by "increase of first filter load time due to physical read of each one byte" first, please.
I still haven't reverted to TB2.  Still painfully slow whenever I add a filter and need to alphabetize my list by using "Move Down" button since the added filter is always at the top. Would be nice if filter were added wherever in the list the cursor happens to be when you click "New" for new filter. Up to 350 filters and growing... :(
Andy, 
3 things:
Is your performance worse than what I found described in comment 13?
While you are waiting and it is slow, is CPU high and IO rate low? Or CPU low?
Describe your computer hardware.
Performance is about the same. CPU is a Pentium 4 3.20GHz with 2GB RAM, commit charge before is 1,630,000Kb and reaches 1,701,000Kb after it takes 83 seconds to move one filter from top of list to bottom. The CPU goes high to 50% at the start and grows to about 80% at the end. Commit spikes at the end to around 1,770,000 Kb and then returns to 1,630,000 Kb after catching up at the end. XP Media Center Version 2002 SP3.  I didn't know how to check IO rate. IO rate of RAM I'm assuming? If you specify a parameter to graph during scroll, I can monitor under Performance graph...Currently File Data Operations/sec. and File Control Bytes/sec. don't show any great increase during the scroll.
I couldn't observe slowness in scrolling/editing with 10000 rules of next simple rule only(1.26MB). I could see only very long first load time, short time lag in second or later load, and short time lag after close(write of 1.26MB occurs).
> name="ABC-nnnn"
> enabled="yes"
> type="17"
> action="Change priority"
> actionValue="Normal"
> condition="AND (to,begins with,ABC)"
I also saw slowness in scroll with several real message filters of test accounts of test profiles in the past, and I also saw large memory use with a very big message filter which was intentionally generated for testing in the past.
I guess next are relevant to slowness in scroll or large memory use.
(a) number of "move/copy to folder" actions.
    As rename of folder is reflected to filter immediately(asked by dialog),
    event listner is generated for each mail folder used in filter. 
(b) number of actions in a filter rules.
    As priority of actions is defined, internal sorting of actions is neded.
(c) line length of data in msgFlterRules.dat.
    (depends on number of conditions in a filter rule)
(d) number of mail folders in Tb.
    IIRC, "large memory use by filter loading" was observed with very many
    local folders.
    (I intentionally created 10000 mail folderes for testing. A/0 to A/9999)
How many mail folders are refered by your message filter?
What is average length of "conditions=" line in msgFilterRules.dat?
What is largest length of "conditions=" line in msgFilterRules.dat?
How many mail folders do you have?
New version of JavaScript to generate many conditions(long conditions= line).

Following filter rules is generated by JavaScript.
> name="ABC-<rule_sequence_number>/<number_of_conditions>(<length_of_condition_line>bytes)"
> enabled="yes"
> type="17"
> action="Change priority"
> actionValue="Normal"
> condition="OR (to,begins with,ABC-1) OR ... OR (to,begins with,ABC-nnnn)"

Next can be specified.
 - Number of filter rules to generate (NNN) 
 - Number of conditions of first rule (CCC)
 - Increment of number of conditions  (XXX)
 For <rule_sequence_number>=SSS, number of conditions = CCC + (SSS-1)*XXX

When NNN=20, CCC=100, XXX=100, ABC-1/100(2704bytes) to name="ABC-20/2000(56905bytes) is generated, and file size of msgFilterRules.dat becomes 580KB.
Quick check result with this test case, using Tb 3.1.7/Win-XP, on Core2Duo Notebook.
(1) As 580KB, initial load of msgFilterRules.dat doesn't takes long.
(2) When Edit of a filter rule, time to show conditions is not so slow, although time lag exists. It's true even when name="ABC-20/2000(56905bytes) case(20-th rule, number of conditions is 2000, length of conditions= line is 56905bytes).
(3) Time lag is observed in scroll at Edit panel, but it is not *Slow!*, and doesn't depend on number of conditions. Difference of time lag of scroll between filters is not observed.
(4) Scroll speed at Edit of filter panel depends on number of conditions which is shown at Edit filter panel.
(4-1) panel height is increased and 18 conditions are displayed.
      CPU utilization by Tb is 20% to 40%(Core2Duo. 40% to 80% if single CPU)
      Time lag is not so small, but not so large. 
(4-2) panel height is decreased only 3 conditions are displayed.
      CPU utilization by Tb is 10% to 20%(Core2Duo. 20% to 40% if single CPU)
      Time lag is shorter than (4-1). It doesn't look slow.
(5) Problem in test with rule like above is observed when OK button is clicked.
(5-1) Error message like "unable to save because of incorrect condition" is observed several time, when OK is clicked just after conditions are shown.
It looks that load of all conditions doesn't complete yet when OK buton is enabled.
(5-2) When OK is clicked without any change, slowness is observed with filter rule of many coditions. In my test, ABC-9/900(25104bytes) is sufficiently long to sav filter rule. (When I check ABC-20/2000(56905bytes) case, I couldn't wait, then I killed Tb). High CPU utilization and large memory use is observed when OK is clicked.
"Time to take save a filter rule" doesn't seem O(n) where n=number of conditions. It may be O(n**2) or (factorial(n)). 
Summary.
I couldn't see very slow loading, very slow scroll, although time lag was always observed and high CPU utilization was always observed in scroll test and OK click test.
I colud see "very slow save when OK is clicked" only with above test case in my enviroment.

As it looks CPU bound process, *slowness* depends of environment.
And, as performance problem, both of (a) comparison of data such as CPU utilization with same test case on different environments, and (b) comparison of data such as CPU utilization with different conditions(e.g. number of conditions) on single environmnt, are needed.
Attachment #513847 - Attachment is obsolete: true
I think you have the jist of the problem I've observed but the .DAT file doesn't have to be all that big. Mine is probably less than 300 filters and I used to get the scroll lag behavior always. If I merely scroll the list more than a window's worth, I start getting the lagging, jerky action. Since the last Tb update, 3.1.7, scrolling is smooth as silk and no evidence of "move" problem either. The move issue could be eliminated completely if the list could be sorted like hundreds, perhaps thousands of lists all over the world, by simply clicking on the column heading. But that's another issue. Good work, guys!
Updated to 3.1.7 today.  Remember, I'm having no problem with the scrolling as such. Still seeing the same behaviour as before. Only the "Move Up" and "Move Down" are causing delays. Since I have 350 filters I like to move them up and down to alphabetize them. When you add a new one, it goes to the very top - then I highlight that top new filter and press and hold Alt-D until it falls into its alphabetized "home". There has to be something that has changed with the way the screen refresh was re-written or changed from 2.0 to 3.0 since it kind of jumps the scroll bar indicator up a certain amount and then back down to where it should be in the list with each successive depress of the ALT-D or "Move Down" widget acknowledgement. Same does seem to happen when going UP. It refreshes the screen with the scroll bar moving to 2 different locations with each depress.  Not sure if there were any changes that were supposed to address this issue in 3.1.7 but just chiming in that this issue remains for me...
Your suggestion for changing the panel size gave me an idea.  Tried moving one filter from top to bottom with the panel showing 2 conditions and tried the same with a full windows worth or 60 conditions.  Big difference in the time it took.  Only took 1 minute with the 2 conditions showing.  It took 3 minutes and 2 seconds with 60 conditions showing. hmmm...
Your suggestion for changing the panel size gave me an idea.  Tried moving one filter from top to bottom with the panel showing 2 conditions and tried the same with a full windows worth or 60 conditions.  Big difference in the time it took.  Only took 1 minute with the 2 conditions showing.  It took 3 minutes and 2 seconds with 60 conditions showing. hmmm...
(In reply to comment #23)

As seen in comment #0, initial/main slowness in this bug was slowness at "Edit panel of a message filter rule"((conditions of a filter rule are listed).
It looks for me that there are at least 4 kinds of severe slowness in this bug;
(1) Slowness of initial load of message filter after restart of Tb when file
    size of msgFilterRules.dat is large, due to "physical read request for
    each one byte". It looks for me involved in bug summary and comment #0.
(2) Slowness at Tools/Message Filter panel(filter rule list). Your case.
(3) Slowness at "Edit of a filter rule" panel(conditions are listed).
    Main issue in comment #0.
(4) Slowness when OK is clicked at "Edit of a filter rule" panel
    (conditions are listed). I saw it in my intentional test.
Please distinguish them, in order to avoid confusions in this bug.

As "number of shown rules, or number of shown conditions" seems to affect on slowness of both (2) and (3), (2) and (3) seems mainly caused by inefficiency in UI process. It may be relevant to number of event listeners at UI and each process by the event listeners.
Andy, I hope your further/detailed observation of your case.

By the way, both 1 minutes and 3 minutes and 2 seconds is too long to merely move top most rule to bottom.
In this case, I think next is best workaround;
1. Terminate Tb, 2. Edit msgFilterRules.dat by text editor, 3. Move top rule to bottom and save file, 4. Restart Tb, 5. Tools/Message Filters.
Even if it takes longer than 3 minutes, frustration is far small :-)
I can confirm drawing problem from comment 13. Sometimes I also got into a state where some filters appeared missing (I scrolled to the top where they should be but weren't, others were drawn there). See also bug 546275.
Also there was relatively slow scrolling but only when editing a filter with 10 conditions (point (3) in comment 24). This was on a 159 filters file created using WADA's generator. The slowness was caused by 100% CPU load.
Whiteboard: [gs][needs testing in against bug 571419] → [gs][needs testing in against bug 571419][filter-mgmt]
Wayne, could you somehow disambiguate the topic of this bug. It originally was about scrolling within one filter that has many rules. That bug is valid. It doesn't matter how many other filters exist besides that one filter.

But the comments already stray away from that and focus on scrolling the filter list with many filters. That should not belong here.

Also, there is another problem mixed in here and that is that it is tedious to Move up/down a filter by many positions.
That also should not be here. Can you move these GS topics to e.g. bug 668995:
https://getsatisfaction.com/mozilla_messaging/topics/reordering_message_filter_is_slow (you have this behind the http://getsatisfaction.com/mozilla_messaging/tags/bug_444793 link in the URL field),
https://getsatisfaction.com/mozilla_messaging/topics/message_filters_are_not_autoscrolling_when_you_click_move_down

And I also think attachment 483655 [details] does not belong here.
No longer depends on: 571419
Depends on: 571419
(In reply to :aceman from comment #26)
> And I also think attachment 483655 [details] does not belong here.

Obsoleting it and changing back bug summary to original one, to avoid confusion and to focus on original problem of comment #0.
Summary: Edit Message Filter window slow, bad performance for large multi-criteria filters, slow loading and scrolling → Edit Message Filter window slow, bad performance for large multi-criteria filters
Attachment #483655 - Attachment is obsolete: true
If I understand it mailWidgets.xml correctly then each search term line (header name, operator, value) displays 3 fields, but behind the value field all the other different value types are hidden (in a deck). It may be possible that if there are many term lines like this that the scrolling of this a heavy layout operation.

But since the report (2008) the gecko layout and javascript changes may have sped up the operation.
On a 2Ghz Core 2 CPU I get acceptable (albeit choppy) scrolling even with 100 rules. I'll try a slower machine later.
Depends on: 777287
On a Phenom II machine downclocked to 800Mhz on Linux the scrolling with 100 rules is quite choppy. Also with 10-30 rules as the original report claims. But the rest of TB is too at this speed. So I am not sure there is anything especially slow in the filter editor.
Depends on: 202036
I have added some bugs into "depends on" that could help this bug as they remove unnecessary elements and bindings from the editor.

Wayne, the GS list of topics in the link http://getsatisfaction.com/mozilla_messaging/tags/bug_444793 is correct, but please remove the "Reordering Message Filter is slow" topic from the list, it is not this issue.

In that topic, please mention bug 780473, bug 450302 and bug 668995.

I could not yet find which bug is for scrolling the FILTER LIST (versus scrolling the FILTER RULES IN ONE FILTER). Wayne, WADA, can you spot it?
(In reply to :aceman from comment #30)
> I have added some bugs into "depends on" that could help this bug as they
> remove unnecessary elements and bindings from the editor.
> 
> Wayne, the GS list of topics in the link
> http://getsatisfaction.com/mozilla_messaging/tags/bug_444793 is correct, but
> please remove the "Reordering Message Filter is slow" topic from the list,
> it is not this issue.
> 
> In that topic, please mention bug 780473, bug 450302 and bug 668995.

done

> I could not yet find which bug is for scrolling the FILTER LIST (versus
> scrolling the FILTER RULES IN ONE FILTER). Wayne, WADA, can you spot it?

the closest I find is a lot of discussion of speed in bug 549577
Thanks, but bug 549577 is completelly different. Even though some comments say about slowness. But I can't see any in current versions so I'd like to see a serious bug about that.
Summary: Edit Message Filter window slow, bad performance for large multi-criteria filters → Edit Message Filter window is scrolling slowly, bad performance for large multi-criteria filters
OK, after the linked bugs were fixed, can anybody still see any slowness in a current Nightly 19?

Remember this is about scrolling inside one filter (the "Filter rules" dialog), NOT about scrolling the filter list (the "Message filters" dialog).
The frame appears at about 9sec, the contents at ~1min 15sec. I just confirmed this using Thunderbird 24.3.0 on a quad core i5 (4789.32 bogomips/core) 6GB Fedora 20 laptop under Gnome.
Clicking Edit on that sample filter takes at most 2 seconds on my PC (Phenom II, 4000 bogomips/core, TB30). After that I can scroll the conditions. Yes, the scrolling is choppy. But I do not see the pathological open time as reported.
Interesting... Thanks!

Simple summary of an hour+ of ioslation work is rebuilding the dconf database fixed speed opening the message filter edit window.

The quick and simple fix is:
dconf dump  / > dconf-dump
dconf load  / < dconf-dump

I have even tested post reboot and the startup of the Edit is still less than a second now.

--- details of the tests I used to isolate the problem ---
I created a new test email user and used IMAP for the tests below:
Again, this is time from clicking edit using a stopwatch.

1) XPee Pro SP3
3.1.9 ~3-4sec
3.1.20 ~4sec
24.3.0 ~1sec

2) Same Linux user as my 1min 15sec time (orig), same Thunderbird, added filter to the new ImapMail account
24.3.0 1min 17sec

3) I created a new Linux user on the same laptop I tested above, same IMAP account as other two tests
24.3.0 < 1sec

4) Original user again (moved TB accounts, added just the new test account)
cd .thunderbird
mkdir save
mv Profiles/ profiles.ini registry.dat save/
re-start Thunderbird, add test IMAP account.
Edit: ~8s frame, ~1min for the rows/content to appear

So the problem has something to do with the per-user Linux config vs Thunderbird.
Next would be to move everything out of the way, and test piece by piece to isolate.

Comparing my to the new test user's ~/.config directory and doing a binary search between revealed ~/.config/dconf/user was the only difference that mattered. 
Interesting if I copied my .config/dconf/user into the test user before logging in as test, it was slow. The default config was fine.

So I backed mine up, dumped and reloaded my dconf and editing the Thunderbird filter is fine now. (dconf dump & load above).
(In reply to Jeff Buhrt from comment #36)
> 1) XPee Pro SP3
> 3.1.9 ~3-4sec
> 3.1.20 ~4sec
> 24.3.0 ~1sec

Nice to see this improvement, I have done some work to speed up the dialog :)

I can't comment on the dconf stuff, I hopefully do not use it.
I have no idea what info TB could store in dconf and whether it somehow queries it in the filter editor dialog.
Having not profiled TB's read access to dconf, my best guess is a sizing property read.
dconf would be used for GUI or other display settings, maybe some config/size value is requested inside a loop vs once. 

I just retested with my test Fedora user and the problem repeats.
The problem is not in the dconf database changes during the dump/load, so it must be a dconf db corruption, etc.

I confirmed TB isn't writing to dconf, using: dconf watch /

Ironically I ended up creating an ltrace bug while testing this: https://bugzilla.redhat.com/show_bug.cgi?id=1064406

The good gconf user has the same output from strace & ltrace, but the gettimeofday call only seems to loop a couple times while the 'bad' gconf user loops many 1000's of times. Each gettimeofday() loop below runs about 10000 times and repeats continuously for the 1min+ to open the edit window along with matching heavy pthread activity. The question is what display function makes the call to gettimeofday() and the heavy pthread activity...

strace -p <TB pid>
...
gettimeofday({1392213196, 406641}, NULL) = 0
gettimeofday({1392213196, 406669}, NULL) = 0
gettimeofday({1392213196, 405922}, NULL) = 0
gettimeofday({1392213196, 405951}, NULL) = 0
gettimeofday({1392213196, 405978}, NULL) = 0
gettimeofday({1392213196, 406036}, NULL) = 0
gettimeofday({1392213196, 406064}, NULL) = 0
gettimeofday({1392213196, 406094}, NULL) = 0
gettimeofday({1392213196, 406121}, NULL) = 0
gettimeofday({1392213196, 406150}, NULL) = 0
gettimeofday({1392213196, 406177}, NULL) = 0
gettimeofday({1392213196, 406234}, NULL) = 0
gettimeofday({1392213196, 406262}, NULL) = 0
gettimeofday({1392213196, 406292}, NULL) = 0
...
clock_gettime(CLOCK_MONOTONIC, {53936, 317501085}) = 0
...
gettimeofday({1392213343, 990836}, NULL) = 0
gettimeofday({1392213343, 990859}, NULL) = 0
gettimeofday({1392213344, 6356}, NULL)  = 0
gettimeofday({1392213344, 6436}, NULL)  = 0
gettimeofday({1392213344, 6481}, NULL)  = 0

ltrace -p <TB pid>
...
pthread_mutex_lock(0xb76d0044, 0xb76d0040, 0x91201f80, 0xb76d0044)           = 0
pthread_mutex_unlock(0xb76d0044, 0xb76d0040, 0x91201f80, 16)                 = 0
pthread_mutex_lock(0xb76d0044, 0xb77e3bd3, 0xb72fa000, 0x8061000)            = 0
pthread_mutex_unlock(0xb76d0044, 0xb77e3bd3, 0xb72fa000, 0x8061000)          = 0
pthread_mutex_lock(0xb76d0044, 0, 0, 0xf25c4100)                             = 0
pthread_mutex_unlock(0xb76d0044, 0, 0, 0xf25c4100)                           = 0
pthread_mutex_lock(0xb76d0044, 63, 0xbfd0670c, 0xb5cba9c6)                   = 0
pthread_mutex_unlock(0xb76d0044, 63, 0xbfd0670c, 0xb5cba9c6)                 = 0
pthread_mutex_lock(0xb76d0044, 1, 0xb49c3e09, 0xb72fa000)                    = 0
pthread_mutex_unlock(0xb76d0044, 1, 0xb49c3e09, 0xb72fa000)                  = 0
pthread_mutex_lock(0xb76d0044, 1, 0xbfd067c8, 0xf25c4100)                    = 0
...

I did a quick test using iotop and top. Thunderbird is 99%+ processor, it is possible there is read access on dconf. If this is something that should be explored further, I guess I could install a debug kernel and use SystemTap, unless you have a better suggestion, or want to just suggest to people with further issues to just rebuild their dconf db.
I have a similar problem on Windows 8.1.

Until a few months ago there were no problems. 

Now, I can edit short message filters with no problem, but others vary from slow to infinitely slow. For example:

My largest message filter takes 1 minute 40 seconds from hitting the 'edit' button until it opens - then just sits there with the spinner going saying 'not responding' apparently indefinitely - certainly for over 20 minutes, before I give up and kill it. During this my CPU is running at around 14% and memory about 10%, so lack of resources isn't a problem.

My second largest (about 120 lines) takes 1 minute 7 seconds from hitting the 'edit' button, then is editable but with a significant scrolling & editing lag.

Neither compacting nor vacuuming with sqlite3 make any difference, nor does reinstalling Windows and Thunderbird.
Is that with TB31?
I no longer have this problem since I no longer use Thunderbird. I see no advantage in it and it's more overhead.
@aceman

I'd missed the release of v31 so have now updated. Yes, it is still lagging - but not quite as badly nor in quite the same way, and I did manage to open my largest list. In detail:


I just timed the largest filter (which I've now been able to estimate has around 350 lines) and...

- It took 2 minutes 30 seconds to open (accompanied by a 'non-responsive script' dialog box).

- When I quit that, it then took about 7 seconds to scroll from top to bottom and I could edit it.

- Attempting to scroll back up then triggered a 'not responding' message in the title bar, followed after a couple of minutes by another 'non-responsive script' dialog box. 

- A few seconds after quitting that I was able to scroll up.

- Then 6 seconds before it scrolled down again.

- Scrolled back up OK.

- Attempting to scroll down again then triggered a 'not responding' message in the title bar, followed after a couple of minutes by another 'non-responsive script' dialog box.
That seems to be a lot of time.
Would you be able to share the filter definition with us? It is stored in the file msgFilterRules.dat in the "Local directory" of that account. If there are any private data (like email addresses) in the code, you can censor them (replace with any characters). They are probably not needed to reproduce it.
Bluehorizon provided a sample filter with 350 terms on a single 31k line. The fillter edit list opens <2 seconds on my old, not fast laptop running nightly build - it is not slow.  My guess is something on Bluehorizon's system makes this slow. 

Dragging the scroll  bar  is not slow. But holding down the bottom scroll arrow is a little slow and janky. I scrolled roughly  1/4 of the terms to profille - http://people.mozilla.org/~bgirard/cleopatra/?1409706552539#report=d398ab4b95abc679a8e8fc8f5ef3c0b7ab573183
Whiteboard: [gs][needs testing in against bug 571419][filter-mgmt] → [has profile][filter-mgmt]
Interesting. This problem has persisted despite reinstalling Windows and Thunderbird from scratch, it's the only program out of well over 100 installed that's causing problems, it's a fast machine (AMD FX-8350 + 32GB RAM + SSD), TB is only using CPU @ around 14% and memory @ about 10%, and there's no significant disk usage. And, until a few months ago, it wasn't a problem.

The only 'peculiarity' I can think of is the AMD CPU; I don't suppose that TB is tapping into any Intel specific instructions?

Is there any diagnostic software I could run to help identify the problem?
You could run the profiler inside TB so we can see which code function takes most of the time.
Probably Wayne can give you instructions on how to use it.

Actually, you say TB is using about 10% of your 32GB RAM? Is that really 3GB? That would be quite a lot and could cause the problem (e.g. constant garbage collection from the JS engine).
Is that RAM usage constant? Or is it some peak shown only when you open the filter and then falls down when you close the filter editor?
Sorry - I obviously calculated RAM usage incorrectly.

I've just run a couple of tests using Task Manager. Initially TB is using around 127MB RAM. After pressing the button to edit the largest filter, RAM usage rose steadily to about 590MB before the 'non-responsive script' dialog box was triggered, when it dropped back to about 493MB (with CPU dedicated to TB running at around 13.5%, and almost no use from anything else).

On scrolling, memory rose steadily from 480MB to 557MB before triggering the 'non-responsive script' dialog.

On closing all message filter editing, memory dropped back to 134MB.

Will look out for a message from Wayne re profiler.
Install https://developer.mozilla.org/en-US/docs/Mozilla/Performance/Profiling_with_the_Built-in_Profiler

In thunderbird the controls are in the status bar, bottom right.
- click on "disabled" to enable the profiler
- do your testing stuff 
- click on "dump profile" 
- click on "upload" to save the profile
- click on "enabled" to disable the profiler


> until a few months ago, it wasn't a problem.

... which suggests a regression either in your environment, or in Thunderbird.  And you can possibly determine which it is by installing older versions of Thunderbird until you find the first version that fails.  If by a few months ago it worked you mean less than 6, then please try installing version 24.2.0.  If longer ago try version 17.0.8. You can download them from http://ftp.mozilla.org/pub/mozilla.org/thunderbird/releases/
The profiler is now installed, but I don't see the controls (I don't have any hidden toolbars). Any clues about how to enable it / how else to access it?

I've tested out some past versions using a shorter filter file (the filter would have been shorter a few months ago too).

v17.0.8 and the current version both opened the file for editing after about 30 seconds, both were lagging when scrolling, but neither threw 'unresponsive script' dialogs. v17.0.8 memory usage went from 91MB to a peak of 291MB; v31.1.0 went from 125MB initially to a peak of 333MB.

v24.2.0 did display the file but the spinner kept spinning over the top, preventing me from editing it (I gave up waiting after 3.5 minutes). Memory usage went from 80MB to a peak of 266MB.

v20.0b1 did open the list on the first occasion (but remained non-responsive for several minutes), then failed to open it after several minutes on the subsequent couple of occasions. Memory usage went from 89MB to a peak of 304MB when I quit after 3.5 minutes.

So it appears that v31.1 has now brought the performance back to roughly where it was at the time of v17. I guess it seems worse because my filter file is now bigger.
No doubt already occurred to you, but since my largest filter file amounts to only around 28KB, and presumably TB doesn't have much more to do than to open the file, the editor and any associated tools, presumably several hundred MB of additional memory should not be needed?

I can, for example, open the file instantly in LibreOffice, increasing LibreOffice's memory use by about 3MB, from about 65MB to 68MB.
Bluehorizon, Jeff,

Can you reproduce this with version 52??
Flags: needinfo?(buhrt)
Flags: needinfo?(absort-mozilla)
Product: MailNews Core → Thunderbird
I'm not going have access to the PC with the filters on until the spring next year, so can't comment on this right now. Will try to remember to do so in due course.
Flags: needinfo?(absort-mozilla)

(In reply to BlueHorizon from comment #52)

I'm not going have access to the PC with the filters on until the spring
next year, so can't comment on this right now. Will try to remember to do so
in due course.

possible to test now?

Severity: major → normal
Flags: needinfo?(buhrt) → needinfo?(absort-mozilla)

(In reply to Wayne Mery (:wsmwk) from comment #53)

possible to test now?

Unfortunately that PC is still inaccessible. That will change - I hope before the year end.

Flags: needinfo?(absort-mozilla)
OS: Windows 2000 → All
Whiteboard: [has profile][filter-mgmt] → [needs profile][filter-mgmt]

Using 68.1.2 I don't see a scrolling problem. Opening/clicking edit uses signficant time and memory. Cutting BlueHorizon's testcase by 2/3 for an 11k filter file:

  • memory grows 2gb
  • 28% of time spent in filterEditorOnLoad of which 18% is initializeDialog
  • 24% doing I think disk IO - which makes me wonder if bug 571419 did enough
  • 4% in cycle collector

Profile at https://perfht.ml/35st0HH

Flags: needinfo?(acelists)
See Also: → 1588155

Yes, I can also see the slow opening of Edit filter dialog, with just 100 filter rules.

(In reply to Wayne Mery (:wsmwk) from comment #55)

Using 68.1.2 I don't see a scrolling problem. Opening/clicking edit uses signficant time and memory. Cutting BlueHorizon's testcase by 2/3 for an 11k filter file:

  • memory grows 2gb
  • 28% of time spent in filterEditorOnLoad of which 18% is initializeDialog

But the times in the profile seem to be displayed accumulated, so these functions didn't actually take any time. It seems to me all that time is spent in the call stack below CustomElementRegistry.upgrade, which looks like building the elements for the rule rows.

  • 24% doing I think disk IO - which makes me wonder if bug 571419 did enough

When did you start the profiling? Reading the filter file should happen when showing the Filter list dialog, not at editing a particular filter. And also when the Filter list dialog is closed.

I would have started the profiler after opening filters and just before clicking edit.

Flags: needinfo?(acelists)

I have always had this issue. If a filter only contained a few line items, it will open within a second or two for edit. However, if I have 20 "match any of these" items (triggers), with a few action line items, it may take 5-10 seconds for the window to open for edit. It drives me nuts at times. When the filter does pop up for editing, the length of the list of triggers determines if scrolling around in that window is slow or not as well (20+ triggers means it might lag for a second or two before you can scroll to the bottom to add another). To this day it does that, and my systems are built to be a beast (the current one, i7-6700k, 64GB RAM, NVMe, etc).

I've always wondered why this was.

TB 78.3.3 32-bit on Windows 10 and this problem is still occurring. The dialog to edit filters of non-trivial size is nearly useless. Surprised that this problem has been lingering for 12+ years.

This is definitely still happening and very frustrating.

Wow, this is 13 years old?
I have 14 filters. One of them has about 100 in the list. It is VERY slow to open, almost impossible to scroll, I can barely add new items to it without thunderbird locking up entirely.

This is retarded that a simple listing of text should run so slowly.

Hi,
Thought I'd add something to help with this discussion. I too am finding the same problem, and yes I do have some filters with a lot (>100) of rules.

I've monitored task manager as I use thunderbird so I'll first say how my memory/CPU usage changes:

  1. When TB starts the computer uses 300MB RAM and 0% CPU usage
  2. Opening the "Message Filters" dialog doesn't change usage
  3. When opening "Edit" dialog on one of the filters with >100 rules, RAM usage spikes to ~4000MB and 10% CPU usage. This stays like that for ~5 minutes before stabilising
  4. After stabilising RAM usage rests at 1800 MB and CPU to 0, the filter edit dialog also is opened and looks like it is ready for me to use it.
  5. Bus as soon as I tried to do anything (scroll, close, minimize the window) CPU usage spikes to 10 % (RAM stays the same) and the application freezes.

I've got screenshots for the above if anyone would like to see them. I've now given up trying to edit filter rules using TB, and looking into how to edit the raw .dat files using python.....

I've also used the TB profiler to investigate the reason for this behaviour and I think the profiler did not record any events during the slow period? I have a .json file, but I'm not sure how to "publish" it or share it for others to see? Should I just attach it to this bug?

I'm not a developer but know enough to sound smart, so if there are other things I can try to investigate further let me know and I'll be happy to try it when I get a free moment. Thunderbird is a great software and it is quite disappointing to have to deal with this odd slowness.

Re: environment, I'm running Windows 10, TB 78.13.0 (64-bit) and my machine is built with high specifications.

Severity: normal → S3

Problem w slow work of message filter still exist. My env: Win7 x64, TB 115.9.0(64bit), i7 6700K, 64GB RAM. Obviously such config you'll barely blame for "slow".
What I do/experience:

  1. Select menu Tools->Message Filters (quite inconvenient, I need BUTTON ON TOOLBAR!).
  2. "Message Filters" dialog appears - OK, fast enough (I have literally 40 rules just to dispatch emails to different folders).
  3. But there is one rule (last one) to block all spam from specific IP. That one rule opened enormously slow!! First, you quickly see dialog w settings of the rule("Filter Rules"), but... you simply cannot interact with it!! This window doesn't respond to anything (including movement) and periodically it's hidden by.... PARENT WINDOW!!! ("Message Filters") This enormous behaviour happen around 1 minute after what you CAN move window. But even this action is not happen immediately - you click on the header, move mouse, NOTHING moves on the screen and only after 5 sec delay window moves to place of mouse. What the hell is that window?? Why it's unresponsive? WHAT so heavy computed inside? Is it real window or just mozilla imitation?
  4. Even after some BG work finished, you CANNOT work properly w window - it still does some computations, which are so heavy that you wait SECONDS until mouse become "resize cursor" to adjust controls.
  5. Some "smartie" removed restoring of size/position for "Filter Rules" dialog - WHY? I'm forced EVERY TIME to expand the window and extend "rules" listbox.
  6. Scrolling of the rules list also WORKS SLOW. You click on the scrollbar, move mouse, but nothing scrolls! And only after 3 sec of "thinking" scrollbar moves. It's unacceptable level of code! So dilettantish that even SIMPLISTIC actions (standard to Windows) take enormous time.
  7. And finally when you press [OK], "Filter Rules" freezes (not closes!), switches back and forth to "Message Filters" dialog, then closes (after SECOND press of [OK]), but "Message Filters" still not responsive - again some BG work happen so slow, that SECONDS past until you can interact with it.

People, I understand that not all code is quality, but you have YEARS(!!!!!!) to polish it! Which are enormous computations you do to show plain dialog with filters???? It's ridiculously SIMPLE task which must not take so much efforts and PC resources. We used mail even on 80386, but never experience so HORRIBLE QUALITY of code! Looks like somebody in a rush to make "multiplatform code" made WORST code on ALL platforms!

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

Attachment

General

Created:
Updated:
Size: