Closed Bug 682693 Opened 13 years ago Closed 13 years ago

High cpu usage when not doing anything on Mac

Categories

(MailNews Core :: Networking: IMAP, defect)

Product:
MailNews Core
Component:
Networking: IMAP
Platform:
x86
macOS
Type:
defect
Priority:
Not set
Severity:
normal

Tracking

(Not tracked)

Status:
RESOLVED WORKSFORME

People

(Reporter: robin.rosenberg, Unassigned)

Details

(Keywords: perf) 

User Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10.6; rv:5.0.1) Gecko/20100101 Firefox/5.0.1
Build ID: 20110707182747



Actual results:

Thunderbird (6.0) is consuming about 20% CPU on Macbook Pro when I am not doing anything, keeping it pretty warm and draining batteries.

According to dtruss it's not performing much useful work either. I get output like
this (repeatedly).
 1515/0xb80c:  mmap(0x0, 0x3000, 0x3, 0x1002, 0x34000000, 0x100000000)         = 0x603B000 0
 1515/0xb80c:  geteuid(0x7FFF702C0260, 0x0, 0x0)         = 501 0
 1515/0xb80c:  geteuid(0x7FFF702AD1F0, 0x7FFF702AD1F0, 0x0)         = 501 0
 1515/0xb80c:  getuid(0x7FFF702AD1F0, 0x7FFF702AD1F0, 0x0)         = 501 0
 1515/0xb80c:  geteuid(0x7FFF702C0260, 0x0, 0x0)         = 501 0
 1515/0xb80c:  munmap(0x10603B000, 0x3000)         = 0 0
 1515/0xb80c:  geteuid(0x7FFF702C0260, 0x0, 0x0)         = 501 0
 1515/0xb80c:  geteuid(0x7FFF702C0260, 0x0, 0x0)         = 501 0
 1515/0xb80c:  geteuid(0x7FFF702C0260, 0x0, 0x0)         = 501 0
 1515/0xb80c:  geteuid(0x7FFF702C0260, 0x0, 0x0)         = 501 0
 1515/0xb80c:  geteuid(0x7FFF702C0260, 0x0, 0x0)         = 501 0
 1515/0xb80c:  geteuid(0x7FFF702C0260, 0x0, 0x0)         = 501 0
 1515/0xb80c:  geteuid(0x7FFF702C0260, 0x0, 0x0)         = 501 0
 1515/0xb80c:  geteuid(0x7FFF702C0260, 0x0, 0x0)         = 501 0
 1515/0xb80c:  geteuid(0x7FFF702C0260, 0x0, 0x0)         = 501 0
 1515/0xb80c:  mmap(0x0, 0x3000, 0x3, 0x1002, 0x34000000, 0x100000000)         = 0x603B000 0
 1515/0xb80c:  geteuid(0x7FFF702C0260, 0x0, 0x0)         = 501 0
 1515/0xb80c:  geteuid(0x7FFF702AD1F0, 0x7FFF702AD1F0, 0x0)         = 501 0
 1515/0xb80c:  getuid(0x7FFF702AD1F0, 0x7FFF702AD1F0, 0x0)         = 501 0
 1515/0xb80c:  geteuid(0x7FFF702C0260, 0x0, 0x0)         = 501 0
 1515/0xb80c:  geteuid(0x7FFF702C0260, 0x0, 0x0)         = 501 0
 1515/0xb80c:  geteuid(0x7FFF702C0260, 0x0, 0x0)         = 501 0
 1515/0xb80c:  geteuid(0x7FFF702C0260, 0x0, 0x0)         = 501 0
 1515/0xb80c:  geteuid(0x7FFF702C0260, 0x0, 0x0)         = 501 0
 1515/0xb80c:  geteuid(0x7FFF702C0260, 0x0, 0x0)         = 501 0
 1515/0xb80c:  geteuid(0x7FFF702C0260, 0x0, 0x0)         = 501 0
 1515/0xb80c:  geteuid(0x7FFF702C0260, 0x0, 0x0)         = 501 0
 1515/0xb80c:  geteuid(0x7FFF702C0260, 0x0, 0x0)         = 501 0
 1515/0xb80c:  geteuid(0x7FFF702C0260, 0x0, 0x0)         = 501 0
...

Sorted and uniq'd dtruss for about 10 seconds looks like this (first number is number of identical calls).

   1 	PID/THRD  SYSCALL(args) 		 = return
 350  1515/0xb80c:  geteuid(0x7FFF702AD1F0, 0x7FFF702AD1F0, 0x0)		 = 501 0
1750  1515/0xb80c:  geteuid(0x7FFF702C0260, 0x0, 0x0)		 = 501 0
   1  1515/0xb80c:  gettimeofday(0x7FFF5FBFCAE0, 0x0, 0x118D9FB60)		 = 1314524070 0
   1  1515/0xb80c:  gettimeofday(0x7FFF5FBFCAE0, 0x0, 0x1558B7660)		 = 1314524074 0
 350  1515/0xb80c:  getuid(0x7FFF702AD1F0, 0x7FFF702AD1F0, 0x0)		 = 501 0
  19  1515/0xb80c:  mmap(0x0, 0x2000, 0x3, 0x1002, 0x34000000, 0x0)		 = 0x6035000 0
  52  1515/0xb80c:  mmap(0x0, 0x2000, 0x3, 0x1002, 0x34000000, 0x100000000)		 = 0x6035000 0
 104  1515/0xb80c:  mmap(0x0, 0x2000, 0x3, 0x1002, 0x34000000, 0x2280F400000000)		 = 0x6035000 0
  18  1515/0xb80c:  mmap(0x0, 0x3000, 0x3, 0x1002, 0x34000000, 0x0)		 = 0x6032000 0
  52  1515/0xb80c:  mmap(0x0, 0x3000, 0x3, 0x1002, 0x34000000, 0x100000000)		 = 0x6032000 0
 105  1515/0xb80c:  mmap(0x0, 0x3000, 0x3, 0x1002, 0x34000000, 0x2280F400000000)		 = 0x6032000 0
 176  1515/0xb80c:  munmap(0x106032000, 0x3000)		 = 0 0
 176  1515/0xb80c:  munmap(0x106035000, 0x2000)		 = 0 0
  49  1515/0xb817:  __semwait_signal(0xA203, 0xDD03, 0x1)		 = -1 Err#60
  82  1515/0xb817:  __semwait_signal(0xA203, 0xDD03, 0x1)		 = 0 0
  49  1515/0xb817:  __semwait_signal(0xDD03, 0xA203, 0x1)		 = -1 Err#60
  92  1515/0xb817:  __semwait_signal(0xDD03, 0xA203, 0x1)		 = 0 0
  39  1515/0xb817:  __semwait_signal(0xDD03, 0xDE03, 0x1)		 = -1 Err#60
  67  1515/0xb817:  __semwait_signal(0xDD03, 0xDE03, 0x1)		 = 0 0
  39  1515/0xb817:  __semwait_signal(0xDE03, 0xDD03, 0x1)		 = -1 Err#60
  64  1515/0xb817:  __semwait_signal(0xDE03, 0xDD03, 0x1)		 = 0 0
   1  1515/0xb817:  gettimeofday(0x114A19DA0, 0x0, 0x1)		 = 1314524072 0
   1  1515/0xb81a:  __semwait_signal(0xA203, 0xD703, 0x1)		 = -1 Err#60
   1  1515/0xb81a:  __semwait_signal(0xD703, 0xA203, 0x0)		 = 0 0
   1  1515/0xb81a:  __semwait_signal(0xD703, 0xDE03, 0x1)		 = -1 Err#60
   1  1515/0xb81a:  __semwait_signal(0xDE03, 0xD703, 0x1)		 = -1 Err#60

Invoking gdb on the process and breaking on mmap always stops like this
Breakpoint 1, 0x00007fff8716d940 in mmap ()

(gdb) bt
#0  0x00007fff8716d940 in mmap ()
#1  0x00007fff864a2d71 in CGBitmapAllocateData ()
#2  0x00007fff864a2a1e in CGBitmapContextInfoCreate ()
#3  0x00007fff864a270f in CGBitmapContextCreateWithData ()
#4  0x00007fff864a2642 in CGBitmapContextCreate ()
#5  0x0000000100cffc5c in JSD_DebuggerOnForUser ()
Previous frame inner to this frame (gdb could not unwind past this frame)




Expected results:

I'd hope it could spend less time on debugging. The installation is a vanilla installation
of release 5 upgraded via beta 6.

I have quite a lot of folders and mail, mostly IMAP.
does it also happen in safe mode ?
 http://support.mozillamessaging.com/en-US/kb/safe-mode
Keywords: perf
(In reply to Wayne Mery (:wsmwk) from comment #1)
> does it also happen in safe mode ?
>  http://support.mozillamessaging.com/en-US/kb/safe-mode

I get no consistent results. For a while It looks like it
did matter when launching with -safe_mode from the command
line, but not from the GUI. However after a while I notes
8-10% CPU usage with -safe_mode too. The reduced CPU usage
from 20 to 10 % might come from uninstalling a brokene enigmail
extension. 10% is still pretty high, since it seems to be
able to idle at less than one per cent CPU usage.

I wait a minute or more before lookung at top. so it looks 
like it's not doing any work like fetch mail or so.
Changing focus to a non-empty IMAP folder triggers high CPU usage. Going
back to an empty folder changes nothing.
Component: General → Networking: IMAP
Product: Thunderbird → MailNews Core
QA Contact: general → networking.imap
When you do that does it trigger a lot of activity imap wise (you can see this by logging imap as described at https://wiki.mozilla.org/MailNews:Logging) ?
There a very short burst of IMAP traffic as I select a folder, then nothing.

NSPR_LOG_MODULES was set to "imap:5"
I don't see much evidence that this is imap/networking related.  IMAP threads in Thunderbird 6 wake up less than they did in 3.1, so it should be better, not worse. Is gloda (global search and indexing) turned on?
Turing off both indexing options (thunderbird's own and spotlight) has no effect.
Is it any better with v7 (beta) or v8 (earlybird) from  http://www.mozilla.com/thunderbird/channel/ ?
Summary: High cpu usage when not doing anything → High cpu usage when not doing anything on Mac
I am using version 7 now. Still the same problem.
Version: 6 → 7
I also tried version 8, which always uses about 10%, so it's worse than v7 in that sense.

New observation: However, if I select a folder that has not had any activity for quite a while (a year or more), thunderbird uses very little CPU (<0.5%) when idle. This phenomenon applies to both v7 and v8. It might be relevant that these folders have not had any new e-mail or changes since I started using Thunderbird.
It seems version 8 beta is much better. It quickly settles at less than one per cent CPU usage in "idle" mode. 

0.9% CPU usage in idle mode is still strange, but that's not why I reported this bug.
You can close this. Disregard my lasts comment. The issue was about very high CPU usage.
WFM per comment 13
Status: UNCONFIRMED → RESOLVED
Closed: 13 years ago
Resolution: --- → WORKSFORME
Whiteboard: [gs]
You need to log in before you can comment on or make changes to this bug.