273310 - after firefox is running for many hours, it uses 100% cpu for a few seconds before it loads ANY page (calling gettimeofday() thousands of times)

Status: RESOLVED INCOMPLETE

(Firefox :: General, defect)

Description

[Nir Perry]

User-Agent:       Mozilla/5.0 (X11; U; Linux i686; en-US; rv:1.7.5) Gecko/20041107 Firefox/1.0
Build Identifier: Mozilla/5.0 (X11; U; Linux i686; en-US; rv:1.7.5) Gecko/20041107 Firefox/1.0

After many hours of running (currently - I've got it running for about ~10days,
and its CPU time (of being actually scheduled) is almost 42 hours), firefox
enters a weird state in which whenever I refresh the current page or go to a new
URL, it takes a few seconds (~20) to even get started, during this time the CPU
goes as high as 100%. Btw, I've seen this on 1.0PR and now on final 1.0, and as
far as I recall on the older version I used (0.8) - it didn't happen.

It doesn't seem to be any URL specific - when it starts, any URL will cause same
behavior.

I think sometimes closing some tabs/windows help, but now I've reproduced it
with only 3 open tabs, one reading mail from yahoo, and two other that contain
just some plain HTML (no flash, fancy scripts, etc.).

Currently, it is using ~51MB virtual memory, of which ~45MB is resident (~34MB
shared). It has 4 open threads, but only one of them is going 100% - it is the
first one (the owner of the others). My machine has 320MB physical ram, with
plenty more on swap (more than ~200MB free at the moment).

Important - at the same the above is happening, I've got another firefox process
open from a different user - it reached ~139MB virtual memory holding 13 tabs on
two windows, being alive for ~8 days but was scheduled much more (~92hours cpu
time), without ever showing the 100% cpu behavior, while the other firefox is
still having that problem. Therefore I think the system state is "less" guilty
(as both processes live in the same system at the same time, and only one is
showing the problem). In the past, I've had situations where both users had the
100% cpu problem, but I didn't invetigate it then.

I've run "strace" on the thread that reaches 100% cpu, and found out it called
gettimeofday() thousands of times each second (~9000 calls per second, overall
it called it 207367 times during 22 seconds) while normally it only calls it
~100-200 times a seconds.
Here's the few lines just before those ~20 seconds (the thread that goes 100% is
9315, it has a child 9317 which itself has 9318 and 9322 has childs):

** read(3, *** some data *** ..., 32) = 32
** readv(3, [{ *** some data *** ..., 512}, {"", 0}], 2) = 512
** write(3, *** some data ***..., 640) = 640
** ioctl(3, FIONREAD, [0])                 = 0
** poll([{fd=3, events=POLLIN}, {fd=12, events=POLLIN}, {fd=16,
events=POLLIN|POLLPRI}, {fd=10, events=POLLIN|POLLPRI}, {fd=11,
events=POLLIN|POLLPRI}, {fd=18, events=POLLIN|POLLPRI}, {fd=19, events=POLLIN},
{fd=4, events=POLLIN, revents=POLLIN}], 8, -1) = 1
** gettimeofday({1102289757, 199436}, NULL) = 0
** gettimeofday({1102289757, 199517}, NULL) = 0
** gettimeofday({1102289757, 199617}, NULL) = 0
** gettimeofday({1102289757, 199675}, NULL) = 0
** kill(9322, SIGRTMIN)                    = 0
** read(4, "\372", 1)                      = 1
** ioctl(3, FIONREAD, [0])                 = 0
** poll([{fd=3, events=POLLIN}, {fd=12, events=POLLIN}, {fd=16,
events=POLLIN|POLLPRI}, {fd=10, events=POLLIN|POLLPRI}, {fd=11,
events=POLLIN|POLLPRI}, {fd=18, events=POLLIN|POLLPRI}, {fd=19, events=POLLIN},
{fd=4, events=POLLIN, revents=POLLIN}], 8, -1) = 1
** gettimeofday({1102289757, 207390}, NULL) = 0
** gettimeofday({1102289757, 207545}, NULL) = 0
** gettimeofday({1102289757, 208049}, NULL) = 0
** gettimeofday({1102289757, 208376}, NULL) = 0
** gettimeofday({1102289757, 211306}, NULL) = 0
** gettimeofday({1102289757, 211537}, NULL) = 0
** gettimeofday({1102289757, 211621}, NULL) = 0
** gettimeofday({1102289757, 211680}, NULL) = 0
** kill(9318, SIGRTMIN)                    = 0
** gettimeofday({1102289757, 694520}, NULL) = 0
***** -- starting here, we have only gettimeofday() calls, for ~22 seconds.

Hope this helps...

Reproducible: Sometimes
Steps to Reproduce:

Comment 1

[:Gavin Sharp [email: [e-mail]]]

I've seen something similar on my machine. See also the somewhat related bug
34871 which was fixed a long time ago.

Comment 2

[bender2037]

Hi,

i've got the same probelm with Mozilla 1.7.8 GTK2.
Looking on the first Poster it looks like it is a GTK2 Problem.

Gtk2 was introduced in firefox 0.9.

I'm wondering why they switched to gtk2.
Is it realy better?


Bender

Comment 3

[Ryuichi KUBUKI]

*** Bug 288472 has been marked as a duplicate of this bug. ***

Comment 4

[gou]

Hi,

I have the same problem avec FF 2.0.0.1 on a Win XP but a bit different...

My computer is running all the day and the night (but a bit asleep...). I must restart FF each mornings because the CPU usage is at 100% only for FF. I have tried to find a specific page causing the problem or an extension, but it seems it's in the FF core.

I have a colleague who have the same problem vith FF 1.5.0.9. That's really annoying.

Sorry, I'm not a technical guy, I'm just a FF user...

Gou

Comment 5

[Bas]

With FF I see the same Firefox 2.0.0.1 runs at 80-100% CPU utilisation.
I have AMD Athlon 2800XP with 1GB of memory.
WINXP SP2 latest updated build.

Second I believe to have spot a memory leak as I see memory increasing to over 80 Mbyte.

Killing the FF processes bring CPU back to normal low levels.

Bas.

Comment 6

[tcm13]

I have also a similar problem with FireFox 2.0.0.1. At irregular, what seems to be random times FF CPU usage approaches 100% slowing my whole system down. If CPU usage reaches 99% or 100% FF hangs and will also stall the system. I have seen FF 100% CPU usage cause a cascade of other system processes to go to 100% usage making a re-boot or at least log off necessary. At the moment I keep Task Manager open to keep an eye on FF CPU usage. If FF CPU usage near 65% or more I restart FF, this seems to keep the problem under control. Also memory usage stays at near 150,000 K peaking at 250,000 K. I find this excessive memory usage, though this most likely due to one of the extension I am running
My system is AMD Athlon 64 3000+(2.2GHz), 2GB RAM, Nvidia 6800 and running Windows XP Pro x64.

Comment 7

[Arthur]

Bug 371398 might be related as it also shows gettimeofday in the stack trace.

Comment 8

[tfpsly]

Same here under Linux and on Firefox 2.0.0.6, brand new profile created for this test: opening 3 pages from *any* site (matbe.com, news.google.com, any forum, my iGoogle homepage...) will make FF calls gettimeofday thousands of time per second (~11800 in less than 10 secs).

Comment 9

[Wayne Mery (:wsmwk)]

gou, bas, tcm13, on windows, how did you determine gettimeofday() is related to your situation

tfpsly, reporter is gone.  Are you able to confirm this happens also with a trunk build? 

Comment 10

[tfpsly]

> tfpsly, reporter is gone.  Are you able to confirm
> this happens also with a trunk build?

Sorry, no. I don't have the bug anymore after a clean reinstallation. It might have been related to some version of GTK2.

Comment 11

[Bas]

Hello Wayne,

Since I upgrade to FF 20.0.0.11 and wih it some new version of GTK2 I have not encountered this issue anymore. FF is still very memory hungry runs over 100MB of DRAM. Also FF takes its time to boot up on both by laptop (IBM T43/2GB RAM) and Home system (AMD ATHL XP 2800+/1GB RAM). Both systems running Windows XP SP2 with latest patches etc. OK I have a number of the common used Add-ons installed but takes FF takes its time ;-) compared to i.e. IE 6 and IE 7.

The best wishes for 2008,

Bas.

Comment 12

[tfpsly]

> FF is still very memory hungry runs over 100MB

That's due to the (stupid imho) strategy of the garbage collector, which doesn't free memory as long as there is plenty free available somewhere else. Supposedly to speed up the application :-/

Comment 13

[Bas]

Hello,

Yepp i.e. it started this morning with ~100MB and at the end of the day it is at 165MB. Still having 3 FF windows open with a few Tabs. I use 3 FF windows spread over my 8 Virtual Desktops. FF is second in the the Memory consumption table on my T43/2GB DRAM. Only Outlooks 2003 tops it with ~250 MB. But if my own memory recalls I have seen FF 2.x also in that region of ~250MB.

My next-gen laptop must have for sure 10GB DRAM(or more),Hex-core at 10Ghz and 2 * 10 TByte HDD .... the Vision of Vista. ;-) 

I remember a guy named Bill, he mentioned a while back that 640KB on a PC would be enough to run all the applications you needed (forever).
I can't remember what happened to him, but I heard recently retired :-)

Bas. 

Comment 14

[tfpsly]

If you're under Windows, there's actually a tool that force the Firefox GC to collect every 7s, making it fall down to less than 10mb with only a few pages.

http://firefox-ultimate-optimizer.en.softonic.com/

But I think it also cause Windows to get a bit stupid and start swapping after some time.

Comment 15

[Steen "Miravlix" Poulsen]

This problem seem to have gotten worse with 3.0.4. A freshly started firefox will do a lot of gettimeofday calls pr. second, it goes totally nuts if you have any pages with refresh features.

Seems to me like Fox desperately need a scheduler for gettimeofday, as it seems like every single thing that can make it call gettimeofday does so independently of all others, making it go nuts.

Comment 17

[Kwan Lowe]

This is still happening regularly on my system. Running 3.0.6 on a fully updated CentOS 5.2 32-bit x86 system.  I notice it most often with Flash running, but not exclusively. Even with absolutely nothing happening (tabs already loaded, nothing being refreshed), "top" will show firefox at 99% CPU for minutes at a time. If I connect with strace, I see maybe 60 or so gettimeofday() calls every second. The browser doesn't crash, but becomes so slow that it may as well have crashed...

Comment 18

[Kwan Lowe]

Here's one example...
This is a freshly opened Firefox session with two tabs open. One to Amazon.com, one to Google gmail.com, and one blank tab.  PID of the Firefox process is 32044:

[kwan@ice9 ~]$ time strace -p 32044 >outfile 2>&1

real    0m17.318s
user    0m0.524s
sys     0m1.919s
[kwan@ice9 ~]$ grep gettimeofday outfile |wc
  27344  136720 1227728

In under 18 seconds, there are 27,344 calls to gettimeofday()..  

Even with absolutely nothing happening and Firefox on a completely separate screen with no mouseovers, it's taking 25% CPU just sitting there.

I loaded KDE konqueror browser for comparison. It also makes a lot of these calls. The difference is that if nothing is happening on the konqueror window itself, it's almost dormat and makes very few calls. Regardless of whether firefox is active or not, it still takes huge CPU resources.

Comment 19

[Arthur]

I would mark this as confirmed if I had any idea in what component to put this bug and to whom it should be assigned to. Asking for QA help.

Personally I haven't seen this since using NoScript.

Comment 20

[Arthur]

I have to correct myself with regards to NoScript. FF uses much less CPU with NoScript but there are still 0.3% CPU (1.50GHz Pentium M) usage just for a huge amount of gettimeofday().

Comment 21

[timeless]

in general, gettimeofday= media, e.g. flash (video) or ogg.

last i checked, gmail used flash to play a new mail sound.

so:
1. disable all your plugins
2. disable all your extensions
3. if you still have problems build --enable-debugger-info-modules and set a breakpoint on gettimeofday

Comment 22

[Tyler Downer [He/Him]]

Any results with the suggestions from comment 21?

Comment 23

[Kwan Lowe]

I just confirmed that even with all plugins disabled (Tools|Addons|Plugins then disable all then restart the browser), there are still thousands of calls to gettimeofday. I will add that the browser doesn't need to be running for any length of time as a strace will immediately show thousands of calls even on a blank page.

Comment 24

[Eduardo E. Silva]

I have the same issues. this is from having firefox on this page. PLease fix this and like many have said. This is affecting EVERYBODY and it is kind of pathetic that firefox it is just getting buggy and buggy.

Would it be too much to ask what is the "logic" behind calling gettimeofday() over and over and over again?

read(15, "\372"..., 1)                  = 1
gettimeofday({1252480523, 723359}, NULL) = 0
gettimeofday({1252480523, 723437}, NULL) = 0
gettimeofday({1252480523, 723494}, NULL) = 0
gettimeofday({1252480523, 723558}, NULL) = 0
read(3, 0xb7d55094, 4096)               = -1 EAGAIN (Resource temporarily unavailable)
poll([{fd=4, events=POLLIN}, {fd=3, events=POLLIN}, {fd=8, events=POLLIN|POLLPRI}, {fd=20, events=POLLIN|POLLPRI}, {fd=21, events=POLLIN|POLLPRI}, {fd=22, events=POLLIN|POLLPRI}, {fd=14, events=POLLIN}, {fd=10, events=POLLIN|POLLPRI}, {fd=29, events=POLLIN}, {fd=51, events=POLLIN}, {fd=15, events=POLLIN}], 11, 0) = 0 (Timeout)
gettimeofday({1252480523, 723863}, NULL) = 0
read(3, 0xb7d55094, 4096)               = -1 EAGAIN (Resource temporarily unavailable)
poll([{fd=4, events=POLLIN}, {fd=3, events=POLLIN}, {fd=8, events=POLLIN|POLLPRI}, {fd=20, events=POLLIN|POLLPRI}, {fd=21, events=POLLIN|POLLPRI}, {fd=22, events=POLLIN|POLLPRI}, {fd=14, events=POLLIN}, {fd=10, events=POLLIN|POLLPRI}, {fd=29, events=POLLIN}, {fd=51, events=POLLIN}, {fd=15, events=POLLIN}], 11, -1) = 1 ([{fd=15, revents=POLLIN}])
read(15, "\372"..., 1)                  = 1
gettimeofday({1252480524, 117408}, NULL) = 0
write(13, "8"..., 1)                    = 1
futex(0xb7d90dc0, FUTEX_WAKE_PRIVATE, 1) = 1
gettimeofday({1252480524, 117846}, NULL) = 0
gettimeofday({1252480524, 117905}, NULL) = 0
gettimeofday({1252480524, 117967}, NULL) = 0
read(3, 0xb7d55094, 4096)               = -1 EAGAIN (Resource temporarily unavailable)
poll([{fd=4, events=POLLIN}, {fd=3, events=POLLIN}, {fd=8, events=POLLIN|POLLPRI}, {fd=20, events=POLLIN|POLLPRI}, {fd=21, events=POLLIN|POLLPRI}, {fd=22, events=POLLIN|POLLPRI}, {fd=14, events=POLLIN}, {fd=10, events=POLLIN|POLLPRI}, {fd=29, events=POLLIN}, {fd=51, events=POLLIN}, {fd=15, events=POLLIN}], 11, 0) = 0 (Timeout)
gettimeofday({1252480524, 118263}, NULL) = 0

Comment 25

[Bas]

Hello,

I have FF 3.0.13 installed on my Lenovo T61p (Core Dual Intel) business laptop.
I have also FF 3.5.2 installed om my private PC with AMD Athlon Dual 6000+.

Both machine show a symptom that after a while the CPU goes overall to 50% CPU.
However if you you check per CPU you see that 1 CPU is at 100%.
Killing FF process brings thing back to normal for a while.

This old problem start to come back again to me since FF 3.0.12. Before I didn't had this CPU Hog for a long time.

Brgds,

Bas.

Comment 26

[Enrique]

Hi,

using FF 3.5.3 with Linux 2.6.30. The same problem appears whenever I embbed a video tag similar to:


<video id="gvideo" class="gplayer" src="trailers/video1.ogg" autoplay="true"></video>

When embbeding flash player videos it start calling the "gettimeofday" like a mad, but once I exit the page Firefox rest "peaceful". On the opposite once I visit a page with ogg videos it start calling to the gettimeofday like a mad and it never ever stop again until I kill the full firefox-bin process.

Important:
 In this case, the problem is deterministic, even if I just started a new browser application.

Other observations:

 The logs looks something like:
 158  gettimeofday({1257857790, 44594}, NULL) = 0
 159  gettimeofday({1257857790, 44664}, NULL) = 0
 160  gettimeofday({1257857790, 46680}, NULL) = 0
 161  gettimeofday({1257857790, 46756}, NULL) = 0
 ...
 The second parameter to gettimeofday is a timezone structure (a fixed data for each system). Still strace shows firefox is "mallocating" a new struct for the static timezone. It doesn't make any sense to me.

Comment 27

[Bas]

Hello,

Updated the FF version in the meantime.
I have FF 3.0.15 installed on my Lenovo T61p (Core Dual Intel) business laptop.
I have also FF 3.5.5 installed om my private PC with AMD Athlon Dual 6000+.

It seems to typical happens if the machines are left idle for a while. Hence I come back from lunch or another break.
Both machine show a symptom that after a while the CPU goes overall to 50% CPU.
However if you you check per CPU you see that 1 CPU is at 100%.
Killing FF process brings thing back to normal for a while.

This old problem start to come back again to me since FF 3.0.12. Before I
didn't had this CPU Hog for a long time.

Brgds,

Bas.

Comment 28

[Tyler Downer [He/Him]]

Reporter, are you still seeing this issue with Firefox 3.6.13 or later in safe mode? If not, please close. These links can help you in your testing.
http://support.mozilla.com/kb/Safe+Mode
http://support.mozilla.com/kb/Managing+profiles

You can also try to reproduce in Firefox 4 Beta 8 or later, there are many improvements in the new version, http://www.mozilla.com/en-US/firefox/all-beta.html

Comment 29

[Tyler Downer [He/Him]]

No reply, INCOMPLETE. Please retest with Firefox 3.6.13 or later and a new profile (http://support.mozilla.com/kb/Managing+profiles). If you continue to see this issue with the newest firefox and a new profile, then please comment on this bug.

Comment 30

[Maxim Britov]

It seems I have this issue now in safe mode (not new profile)
ff and xulrunner ebuilded from firefox-4.0b12_pre_366d47bce128.source.tar.bz2
A lot of gettimeofday and high cpu load.

Comment 31

[Mike Hommey [:glandium]]

What you really should try is to use, e.g. top to see what *thread* is sucking the CPU (use the H key to display individual threads), then attach gdb to that thread and get a backtrace (which would probably require debugging symbols)

Comment 32

[Maxim Britov]

Attachment: backtrace for gettimeofday

Comment 33

[Mike Hommey [:glandium]]

Please re-read comment 31.

Comment 34

[Maxim Britov]

(In reply to comment #33)
> Please re-read comment 31.

Just backtrace, not for getofthetime? Like:
gdb program <thread>
...
bt full

Right?

Comment 35

[Mike Hommey [:glandium]]

yes

Comment 36

[Maxim Britov]

Attachment: backtrace