562977 - thunderbird progress bar activity puts CPU at 20%

Status: NEW

Description

[Kevin Hunter]

User-Agent:       Mozilla/5.0 (X11; U; Linux x86_64; en-US; rv:1.9.2.3) Gecko/20100423 Ubuntu/10.04 (lucid) Firefox/3.6.3
Build Identifier: Mozilla/5.0 (X11; U; Linux i686 (x86_64); en-US; rv:1.9.3a5pre) Gecko/20100426 Shredder/3.2a1pre

Symptom: any progress bar that appears seems to bring with it a pegged CPU core.

I suggest it's the progress bar code that is polling the CPU.  If I send a message, and the send process fails for some reason, the progress bar continues to animate, while a new dialog box appears with a reason for error.  Meanwhile, a CPU core is still pegged, even though there is no "real" work being done, just the progress bar animation.

I've noticed the high CPU core usage with *any* progress bar activity, not just the above example.  For example, on this latest build, the progress bar in the lower right is attempting to complete while I type this bug report, I presume while it indexes for the first time (first time with /this/ build) my inbox,(>8000 messages).  Meanwhile, my CPU graph shows one core in full usage.

Reproducible: Always

Steps to Reproduce:
Here is one method to get a status bar

1. Open Thunderbird.
2. Clear your password
3. Send a message
4. Type in an incorrect password
5. Note the CPU usage when it gives you the SMTP error dialog.

If it matters, I'm using IMAP, but again, I doubt that's the issue.  I think it's the scroll bar code.
Actual Results:  
When any progress bar is visible, a processor goes berserk.

Expected Results:  
When any progress bar is visible, the CPU usage caused by the progress bar should be pert near zero.

These bugs may be relevant, or may turn out to be duplicates.  I couldn't quite tell from the descriptions:

https://bugzilla.mozilla.org/show_bug.cgi?id=367431
https://bugzilla.mozilla.org/show_bug.cgi?id=538283
https://bugzilla.mozilla.org/show_bug.cgi?id=543422

Comment 1

[Kevin Hunter]

Another reason why I think the issue is specifically with the progress bar code and not, for example, the Gloda code: this issue has been around since at least Thunderbird v1.5.  As referenced by Bug 543422, Gloda may *also* be a CPU hog, but I think the this merits it's own bug report.

Comment 2

[Wayne Mery (:wsmwk)]

Kevin, I don't put any stock in those other bugs.  

Are you seeing this mainly with trunk build? ( Trunk builds are currently badly broken.) 

Do you see this issue with indexing disabled?  (restart after disabling)
If it's only with indexing enabled, can you follow the first two steps at
https://developer.mozilla.org/en/Thunderbird/Gloda_debugging, this should show
you errors in the error console.

Comment 3

[Kevin Hunter]

Index disabled, restarted.  Problem persists.

I checked with both the stock Ubuntu Lucid version (v3.0.4) and with the trunk version built 4 days ago (2010 Apr 26).

I recreated the issue as I described above, removing my saved password, sending an email, and then pausing to observe the effects when it asked for my password.  High CPU usage until I canceled the "Give me your password" dialog.

Comment 4

[Kevin Hunter]

John McPherson just performed a perhaps telling strace of Thunderbird 3.0.4:

https://bugs.launchpad.net/ubuntu/+source/thunderbird/+bug/109943/comments/15

The telling bit from his comment:

It looks like the animation code is doing something very inefficient if it's calling gettimeofday() thousands of times per second.

From there, here's a similar analysis on May 12th's nightly build:

Mozilla/5.0 (X11; U; Linux i686 (x86_64); en-US; rv:1.9.3a5pre) Gecko/20100512 Shredder/3.2a1pre

----------
$ ps -elF | grep thunderbird
0 S kevin    27405 26060 10  80   0 - 99236 poll_s 81960   1 15:06 pts/0    00:01:33 ./thunderbird-bin
0 S kevin    30204 29053  0  80   0 -  1904 pipe_w   916   0 15:20 pts/2    00:00:00 grep --color=always thunderbird

$ time strace -p 27405 2>&1 | head -10000 | grep gettimeofday | wc -l
3803

real	0m2.532s
user	0m0.200s
sys	0m0.440s
----------

That's almost 4,000 requests for gettimeofday() in 10,000 lines retrieved by strace, all in 2.5 seconds.  The question is why does some piece of code need to know gettimeofday several thousand times per second?

Note that to recreate this, the same trick of "forgetting" the password when sending a message was used.  Also note that indexing is *still* disabled.  No Gloda.

Comment 5

[Wayne Mery (:wsmwk)]

Peter, Nir
Does this reproduce in your environment?  
And even if it doesn't, any thoughts or advice?

Kevin as a practical matter - is it at 100% during the entire time the progress bar is animated?

Comment 6

[Kevin Hunter]

I have 2 cores on my machine.  Speaking as an end-user, yes, a single core is pegged at 100% during the entire time the progress bar is active.

Comment 7

[Wayne Mery (:wsmwk)]

Kevin, do you still see this problem in version 3.1?
Do one of the bugs in comment 0 really describe your problem well?

Comment 8

[Kevin Hunter]

(In reply to comment #7)
> Kevin, do you still see this problem in version 3.1?

Yes, but not nearly as badly.  Now the CPU is about 20%, not 100%.  To be clear, I believe from personal experience that animating a simple scroll bar and waiting for user input ought to register at 1% or less CPU utilization.

Performing a similar analysis as above, with Thunderbird waiting for a password (and consequently with a scroll bar going), yields the number of gettimeofday calls to be in the same vicinity (3,500 to 4,000 calls) in 10,000 lines retrieved via strace, and a much more consistent 2,275 POLL events.

Note that I just downloaded and tested Mozilla's copy of 3.1.7 (not my distribution's).

> Do one of the bugs in comment 0 really describe your problem well?

No.  I wasn't sure at the time I wrote this bug report, but I became more confident later.

Comment 9

[Wayne Mery (:wsmwk)]

with trunk Thunderbird on windows, I see steady cpu usage of 5-30% (avg 9%) when any modal dialog box is up (error, password, etc).  Thus, I suspect this is a duplicate.


when NOT logged in to imap account and no dialog box left open, ~2%  (new bug?)

when logged in to imap account, and no dialog box left open, ~0%

Comment 10

[Tsu Jan]

I encountered this issue with 64-bit Thunderbird 5.0 on Linux (Debian). When the progress bar oscillates between left and right, CPU usage increases so that one of CPU cores is at 100%.

For now, I downgraded to TB 3.1.11, that doesn't show this issue or, at least, not to such an extent.

Comment 11

[Wayne Mery (:wsmwk)]

Tsu, Kevin, does CPU go down substantially if you start thunderbird in safe mode?  (as it does in Bug 693852)
ref: http://support.mozillamessaging.com/en-US/kb/safe-mode

Comment 12

[Kevin Hunter]

I have just updated the original test with a stock (direct from mozilla.org) copy of Thunderbird, version 7.0.1 (64-bit).

Answer: no.  It remains high, between 20% and 50% of a core.

That other bug sounds related, and I would not be surprised if the buggy code is at least partially shared.

Comment 13

[Tsu Jan]

Thunderbird 8.0 also suffers from this bug.

Comment 14

[Infinality]

This has been happening to me for years, and still happens in 12.0.1.  I'm pretty surprised this hasn't gotten more attention.  I've had cases where it completely pegs a core- 99 or 100%.

Comment 15

[Tsu Jan]

This was the only reason I left TB and used Evolution (in Gnome).

Comment 16

[Kevin Hunter]

As of yesterday, I've gotten fed up with the resource hogishness and stability issues of the default Ubuntu window and desktop managers.  I've now installed and configured OpenBox.

Where I was seeing this issue 3 days ago (albeit not as pronounced as once-upon-a-time), I'm now do not notice anything.  Other than a 4 or 5 second wait to quit TB, things are right-zippy, with no (known) loss of functionality.  I don't know how to confirm, but this certainly leads me to suspect an interaction between Thunderbird and Gnome and Unity.  (And I believe KDE too, but it's now 4 years since I last tried KDE ...)

Another data point.

Comment 17

[Wayne Mery (:wsmwk)]

(In reply to Kevin Hunter from comment #16)
> As of yesterday, I've gotten fed up with the resource hogishness and
> stability issues of the default Ubuntu window and desktop managers.  I've
> now installed and configured OpenBox.

Comment 18

[Kevin Hunter]

Err, to clarify what I think you may be focusing on, the pegged cores were very much attributable to TB (as evidenced by Comments #4 and #8, and my personal observations through ps and htop, etc.), not to the the various Window/Desktop managers.

For purely non-TB reasons, I switched to OpenBox: my computer /really/ bogged down after I installed Ubuntu 12.04 (fresh install -- not upgrade -- if it's of use) on my machine last week.  (This is still the same hardware as when I started this bug report.)  The speedup of Thunderbird was a happy coincidence, and was not an intentional reason for my switch.

TB definitely still has a performance issue, but one that may be exacerbated by the interaction between the more well-known WMs and DMs.

Comment 19

[Wayne Mery (:wsmwk)]

my progress bar was "stuck" running, and no other mail activity going in or out.
http://people.mozilla.com/~bgirard/cleopatra/?1354224788783#report=21c8f8f3b95dacfb84792b2f0e130eb106a28069&jankOnly=true&selection=%255B%2522%28root%29%2522%252C%2522Startup%253A%253AXRE_Main%2522%252C%2522js%253A%253ARunScript%2522%252C%2522gFolderTreeView.OnItemIntPropertyChanged%28%29%2520%2540%2520folderPane.js%253A1837%2522%252C%25220x17f720%2522%255D

Comment 20

[Wayne Mery (:wsmwk)]

Here's another profile http://people.mozilla.com/~bgirard/cleopatra/?1354620938776#report=6210e70a7a1f640f9bcbb57e9af8c95997b58917&search=Paint

xref bug 742697

Comment 21

[Wayne Mery (:wsmwk)]

there is also activity manager.

<Archaeopteryx>	wsm: seem like it starts here: http://mxr.mozilla.org/comm-central/source/mail/components/activity/modules/autosync.js#283
<Archaeopteryx>	and onProgressChange gets called too much: http://mxr.mozilla.org/comm-central/source/mail/components/activity/content/activity.xml#485
<wsm>	Archaeopteryx: see also https://bugzilla.mozilla.org/show_bug.cgi?id=742697#c14
<firebot>	Bug 742697 nor, --, ---, acelists, NEW, SMTP connection progress bar causes high CPU usage
<wsm>	how do you know it is called too much?
<Archaeopteryx>	just a guess because i see no throtteling code. autsync's comment says it want to prevent event overflow, but it don't see bundling messaes per account at http://mxr.mozilla.org/comm-central/source/mail/components/activity/modules/autosync.js#249 which calls setProgress. you could verify with logging enabled, onDownloadStarted logs in the first lines

Comment 22

[:aceman]

That is the question. I have not yet found if there is any throthling or how often these onProgressChange events are fired. I should probably get the time inside the handler and dump it out to see what happens.

Wayne can you come up with good STRs to get a progress bar repeatedly without downloading new messages? So that we can debug the code.

Comment 23

[Wayne Mery (:wsmwk)]

(In reply to :aceman from comment #22)
> Wayne can you come up with good STRs to get a progress bar repeatedly
> without downloading new messages? So that we can debug the code.

bug 791535 is a different situation, but is reproducible.
I assume bug 584643 is also reproducible.


collection of related bugs - https://bugzilla.mozilla.org/buglist.cgi?list_id=5125237;short_desc=progress%20activity%20barber%20spin%20spinner%20spinning;field0-0-0=short_desc;type0-0-1=anywordssubstr;field0-0-1=short_desc;resolution=---;query_format=advanced;short_desc_type=anywords;value0-0-1=indicat%20throb;type0-0-0=anywords;value0-0-0=meter%20bar%20pole;product=MailNews%20Core;product=Thunderbird

Comment 24

[:aceman]

That query is not that good, from 21 bugs there are about 3 about this problem. You should probably add 'CPU' as a needed word.

Comment 25

[Wayne Mery (:wsmwk)]

(In reply to :aceman from comment #24)
> That query is not that good, from 21 bugs there are about 3 about this
> problem. You should probably add 'CPU' as a needed word.

sorry, quite right. I was mainly being hasty/lazy and I didn't mean to imply ALL are related. Looks to be about 1/3.   Most relevant are bug 791535 and bug 742697

I was also being loose because a few bugs which don't cite CPU still are likely impacted.  for example bug 47024, bug 584643

Comment 26

[Wayne Mery (:wsmwk)]

Recent profile http://people.mozilla.org/~bgirard/cleopatra/?1387475933880#report=1757ae9e3f70bc2dff02d261c2782ebdba77872e done under conditions of gmail stuck on "Downloading m of n All Mail" (bug 816327) 

The amount of time spent painting is obscene (screen shot of profile to follow)

Comment 27

[Mike Conley (:mconley) (:⚙️) - Backlogged on reviews and needinfos]

Holy crap, yes, we're spending a *lot* of time painting in that profile. What is being drawn during this sluggishness?

Comment 28

[Wayne Mery (:wsmwk)]

Created attachment 8350260 [details]
profiler - TB All mail gmail CPU throbber profiler from.png

Comment 29

[Mike Conley (:mconley) (:⚙️) - Backlogged on reviews and needinfos]

What was being displayed on screen during this?

Comment 30

[Wayne Mery (:wsmwk)]

Created attachment 8350262 [details]
TB gmail up to date progress bars

screen shots of progress bar.

Note, apparently CPU can be way higher than 20% depending on type of activity.  In the case of waiting for gmail, I'm seeing 60-100% CPU used by Tbird.

Comment 31

[Wayne Mery (:wsmwk)]

N.B. there may be differences in throbber resource usage depending on OS, as suggested in Bug 854093 - Indeterminate progress bar takes entire CPU.

Comment 32

[Philip Chee]

Supposedly fixed:
Bug 304147 - progressmeter in undetermined mode does not work in Mac OS X
Bug 420254 - thunderbird often uses ~10% cpu when idle for no apparent reason
Bug 432028 - Undetermined progressmeter timer isn't stopped, causing high CPU load
Bug 586216 - Animated widgets have one timer per widget
Bug 587876 - Undetermined progress bars should use mozRequestAnimationFrame
Bug 704171 part 1. Stop using the no-argument form of mozRequestAnimationFrame in our chrome

Comment 34

[Wayne Mery (:wsmwk)]

(In reply to Mike Conley (:mconley) from comment #27)
> Holy crap, yes, we're spending a *lot* of time painting in that profile.
> What is being drawn during this sluggishness?

Does this contradict comment 32's bug list?

And what about bug 658829 and bug 729649 (both landed in early 2013) cited in bug 791535?

Comment 35

[:aceman]

Does anybody still see this? With TB32, in Win XP I can't see the high CPU usage any longer. Via DOM Inspector, in TB main window (chrome://messenger/content/messenger.xul) I found <statusbarpanel id="statusbar-progresspanel"> where I set collapsed="true" to uncover the status bar progress meter. Then in <progressmeter id="statusbar-icon"> I set mode="undetermined". The progress bar began spinning without much CPU usage. So the progressbar alone doesn't seem to be the culprit. If we can find the CPU usage in other scenario, maybe something else is contributing to it.

Comment 36

[Kevin Hunter]

As of v24.5, running on Ubuntu 13.10 (64bit) with Openbox, I no longer see gettimeofday calls in the strace output.  TB is still polling like mad, but is at least efficiency polling.  From an strace output like above, I now see:

  (11.6%) futex
  (27.4%) poll
  ( 4.0%) read
  (45.3%) recvfrom
  (11.7%) writev

And no gettimeofday.  So, from the reporter, who has unfortunately changed the desktop he uses (see comments 16, 17, and 18), I no longer see this.  Meanwhile, we still need input from someone running Gnome and Unity, I think.

Comment 37

[David von Oheimb]

This bug still exists. When the SMTP server does not respond (e.g, with misconfigured IP address setting),
I get 12-13% CPU load in my i5 macbook until the connection timeouts.

Comment 38

[Wayne Mery (:wsmwk)]

Please post a profile URL using https://developer.mozilla.org/en-US/docs/Mozilla/Performance/Reporting_a_Thunderbird_Performance_Problem_with_G

Comment 39

[David von Oheimb]

Thanks Wayne for bringing attention back also to this bug.

I can confirm that the bug still exists with the latest released TB version 31.3.0 with a cpu usage increase of about 12-13% on my Macbook Air. As I wrote recently in response on your request regarding the (likely related) bug 919485, unfortunately I cannot afford the time to install the trunk version and use profiling tools. Yet anyone interested could do for himself easily, since this bug can be reproduced in a straightforward way: put any garbage IP address as e.g. the IMAP (or POP or SMTP) server name and try receiving (or sending, respectively) emails.

I suspect that this waste of CPU (and battery on mobile devices!) is due to the same careless chunk of code performing a busy loop somewhere deep in Mozilla's TCP client connect implementation.

BTW, the title of this bug report is misleading, as it is too narrow: the misbehavior also occurs without any progress bar being shown, e.g., when trying to fetch emails.

Comment 40

[sam tygier]

Here is a trace while copying emails between folders on an IMAP server. Some work is actually being done, but there seems to be a lot of time spent in
Paint::PresShell::Paint
nsLayoutUtils::PaintFrame
nsDisplayList::PaintRoot 

https://people.mozilla.org/~bgirard/cleopatra/?1418817484580#report=f2ec94e59158f41a3723d4d2d517587d1476ab41

Comment 41

[Philip Chee]

WAG: Just a guess. Go to about:config and set the following preferences:
layers.acceleration.disabled -> true
layers.offmainthreadcomposition.enabled -> false

Comment 43

[Wayne Mery (:wsmwk)]

(In reply to David von Oheimb from comment #39)
> Thanks Wayne for bringing attention back also to this bug.
> 
> I can confirm that the bug still exists with the latest released TB version
> 31.3.0 with a cpu usage increase of about 12-13% on my Macbook Air....
> 
> I suspect that this waste of CPU (and battery on mobile devices!) is due to
> the same careless chunk of code performing a busy loop somewhere deep in
> Mozilla's TCP client connect implementation.

David, can you do a performance profile during a period of high CPU using the procedure at  https://developer.mozilla.org/en-US/docs/Tools/Remote_Debugging/Thunderbird which uses Firefox as the recorder

- follow instructions at https://developer.mozilla.org/en-US/docs/Tools/Remote_Debugging/Thunderbird
- after connect, pick "main"
- click "Performance" in the developer tool menu
- click "start recording performance" in the center
- do some actions in thunderbird which cause the problem or behavior to be recorded
- click "stop recording performance"  in the center
- click "Save" one the left
- email the json file or attach to this bug report

Comment 44

[David von Oheimb]

Created attachment 8824696 [details]
TB 45.6.0 high CPU load when connecting to unreachable IMAP server

Here is the requested performance profile with TB 45.6.0 on a Mac.
(The setup for getting it was a bit involved, using both FF and TB, but ok.)

Note that anyone can easily reproduce this CPU misuse:
Just set the IMAP Server Name of some account to an unreachable IP address like 1.2.3.4 and try getting emails from there.

This bug is apparently very low-level in the Mozilla network layer and has a number of related bug reports touched again recently also for FF.

Comment 45

[zayne.a]

High CPU usage seems to be caused by status bar animation.

Quick fix for me (works on Ubuntu) is to disable the status bar (for now).

Possible fix for THunderbird team: Remove this animation, and possibly the entire current animation subsytem, and replace all progress bar animations with something simpler, as I suspect that possibly all animations currently use high CPU usage, but on a decent net connection they do not display for very long (Jut a thought)

Comment 46

[Merike Sell (:merike)]

(In reply to :aceman from comment #35)
> Does anybody still see this? With TB32, in Win XP I can't see the high CPU
> usage any longer. Via DOM Inspector, in TB main window
> (chrome://messenger/content/messenger.xul) I found <statusbarpanel
> id="statusbar-progresspanel"> where I set collapsed="true" to uncover the
> status bar progress meter. Then in <progressmeter id="statusbar-icon"> I set
> mode="undetermined". The progress bar began spinning without much CPU usage.
> So the progressbar alone doesn't seem to be the culprit. If we can find the
> CPU usage in other scenario, maybe something else is contributing to it.

I seem to be getting conflicting data here. I did the same on a fresh profile and CPU went up to nearly 20%. The same happened when I used DOMi to add a new progressmeter element without any eventlisteners and such connected to it as long as the mode is set to undetermined. In fact, it even reproduces in Firefox nightly for me when I do the following in browser console:

var parent = window.document.getElementById("urlbar")
var progress = gBrowser.ownerDocument.defaultView.document.createElementNS("http://www.mozilla.org/keymaster/gatekeeper/there.is.only.xul", "progressmeter");
progress.setAttribute("mode", "undetermined");
parent.appendChild(progress);

Could someone confirm that last bit to make sure it's not just me? If so, then the only thing Thunderbird can do is to work around by not using undetermined mode at all..

Comment 47

[Merike Sell (:merike)]

One more observation: using html:progress takes about 1/2 of the CPU that xul:progressmeter takes when animating.

Comment 48

[kwang.m.yi]

I can confirm that this still happens for me in Debian Sid, thunderbird 52.2.0
The CPU usage goes up quite a bit, actually enough to make the fans kick in.
@zayne.a Can you please provide a bit more detail in how you do that? I tried to googling, without much luck.

Comment 49

[zayne.a]

(In reply to kwang.m.yi from comment #48)
> I can confirm that this still happens for me in Debian Sid, thunderbird
> 52.2.0
> The CPU usage goes up quite a bit, actually enough to make the fans kick in.
> @zayne.a Can you please provide a bit more detail in how you do that? I
> tried to googling, without much luck.

View > Toolbars > Status Bar

Comment 50

[Wayne Mery (:wsmwk)]

(In reply to David von Oheimb from comment #44)
> ...
> Just set the IMAP Server Name of some account to an unreachable IP address
> like 1.2.3.4 and try getting emails from there.
> 
> This bug is apparently very low-level in the Mozilla network layer and has a
> number of related bug reports touched again recently also for FF.

Correct, Firefox gets the same issue.  Perhaps a different bug, if the progress meter doesn't spin or your profile is different from the one Merike collected


(In reply to Philip Chee from comment #41)
> WAG: Just a guess. Go to about:config and set the following preferences:
> layers.acceleration.disabled -> true  [HWA disabled]
> layers.offmainthreadcomposition.enabled -> false

Note, we've seen a variety of behavior with HWA disabled or enabled.  For example, in bug 1267662 HWA disabled improved performance on a Mac

Comment 51

[Wayne Mery (:wsmwk)]

Merike, on what OS did you profile?


Note, from bug 781535 comment 24
(In reply to [e-mail] from comment #22)
> Bug 658829 changed the way undetermined progress meters were painted on
> Windows from an XBL implementation to a native implementation. Linux still
> uses the XBL implementation for undetermined progress meters though.

The linux side is bug 854093 - Indeterminate progress bar takes entire CPU - in Widget: Gtk

Comment 52

[Merike Sell (:merike)]

(In reply to Wayne Mery (:wsmwk, NI for questions) from comment #51)
> Merike, on what OS did you profile?

Linux.

Comment 53

[WaltS48]

I can't reproduce this using the Ubuntu Thunderbird 52.3.0 on Ubuntu 16.04