Bug #1893

Firefox consumes 100% CPU while polling

Added by matthias about 4 years ago. Updated about 3 years ago.

Status:ClosedStart date:
Priority:NormalDue date:
Assignee:-% Done:

0%

Category:-
Target version:-

Description

Hi,

I compiled a new version of Firefox from pkgsrc (3.6.11) and after some
time Firefox consumes 100% CPU even if only one empty tab is open.

The machine runs

DragonFly hades 2.9-DEVELOPMENT DragonFly v2.9.0.90.g20134-DEVELOPMENT
#0: Sun Oct 31 08:56:28 CET 2010
matthias@hades:/usr/obj/usr/src/sys/T42 i386

and is a UP machine.

Precisely the CPU is consumed by the xulrunner process. Truss revealed
the following repeating pattern:

poll(0x2b332ab8,0x3,0xffffffff) = 209 (0xd1)
poll(0x2b332ab8,0x3) = 209 (0xd1)
poll(0x2b332ab8,0x3,0xffffffff) = 209 (0xd1)
poll(0x2b332ab8,0x3) = 209 (0xd1)
poll(0x2b332ab8,0x3) = 209 (0xd1)
poll(0x2b332ab8,0x3) = 209 (0xd1)
poll(0x2b332ab8,0x3) = 209 (0xd1)
poll(0x2b332ab8,0x3,0xffffffff) = 209 (0xd1)
poll(0x2b332ab8,0x3) = 209 (0xd1)
poll(0x2b332ab8,0x3,0xffffffff) = 209 (0xd1)
poll(0x2b332ab8,0x3,0xffffffff) = 209 (0xd1)
poll(0x2b332ab8,0x3,0xffffffff) = 209 (0xd1)
poll(0x2b332ab8,0x3) = 209 (0xd1)
poll(0x2b332ab8,0x3) = 209 (0xd1)
poll(0x2b332ab8,0x3,0xffffffff) = 1 (0x1)
read(0x9,0xbfbfea9f,0x1) = 3 (0x3)
gettimeofday(0xbfbfebcc,0x0) = 0 (0x0)
write(8,0x290ca7e1,1) = 4 (0x4)
gettimeofday(0xbfbfeb9c,0x0) = 0 (0x0)
gettimeofday(0xbfbfeb6c,0x0) = 116 (0x74)
gettimeofday(0xbfbfebec,0x0) = 0 (0x0)
read(0x3,0x2a200018,0x1000) = 3 (0x3)
poll(0x2b332ab8,0x3,0x0) = 0 (0x0)
gettimeofday(0xbfbfebec,0x0) = 116 (0x74)
read(0x3,0x2a200018) ERR#35 'Resource
temporarily unavailable'

A longer output is available here:
http://leaf.dragonflybsd.org/~matthias/truss_ff.txt

It looks similar to issue1886, but that's a wild guess.

Cheers

Matthias

History

#1 Updated by ftigeot about 4 years ago

On Sun, Oct 31, 2010 at 06:44:43PM +0100, Matthias Schmidt wrote:
>
> I compiled a new version of Firefox from pkgsrc (3.6.11) and after some
> time Firefox consumes 100% CPU even if only one empty tab is open.

FWIW, I see a similar behaviour with seamonkey.

When viewing web sites, it seems to be timing dependent: if the remote hosts
respond instantly, there's no problem.
If one host is slow to answer (2-3 seconds delay), the browser begins to
spin with 100% CPU.

Using a proxy on my ISP network is enough to alleviate this problem.

#2 Updated by ftigeot almost 4 years ago

[...]

faxgetty from the comms/hylafax package also takes 100% CPU without any
reason

It is also always repeating the same pattern [kdump -R output]:

0.000024 CALL gettimeofday(0x7ffffffff850,0)
0.000011 RET gettimeofday 0
0.000011 CALL gettimeofday(0x7ffffffff810,0)
0.000010 RET gettimeofday 0
0.000010 CALL select(0x4,0x7ffffffffa00,0x7ffffffff980,0x7ffffffff900,0x595c80)
0.000016 RET select 1
0.000022 CALL gettimeofday(0x7ffffffff810,0)
0.000011 RET gettimeofday 0
0.000010 CALL read(0x1,0x7ffffffff030,0x7ff)
0.000012 GIO fd 1 read 0 bytes ""
0.000009 RET read 0

A quick grep at the source told me select() should be waiting at
least 1 or 2 seconds :

struct timeval tv;
tv.tv_sec = 2;
tv.tv_usec = 0;

But it returns immediately (only 16 microseconds from the call).

System is an Atom (4 threads) running 2.8-RELEASE/x86_64

#3 Updated by ftigeot about 3 years ago

Seamonkey 2.3.1 also burns 100% cpu. The pattern is a bit different:

973:3 seamonkey-bin CALL poll(0x7fffff7fcbc0,0x9,0x3e7fc18)
973:3 seamonkey-bin RET poll 8
973:3 seamonkey-bin CALL gettimeofday(0x7fffff7fcdf0,0)
973:3 seamonkey-bin RET gettimeofday 0
973:3 seamonkey-bin CALL gettimeofday(0x7fffff7fcdf0,0)
973:3 seamonkey-bin RET gettimeofday 0
973:3 seamonkey-bin CALL getpeername(0x42,0x7fffff7fcaa0,0x7fffff7fca5c)
973:3 seamonkey-bin RET getpeername -1 errno 57 Socket is not connected
973:3 seamonkey-bin CALL getpeername(0x44,0x7fffff7fcaa0,0x7fffff7fca5c)
973:3 seamonkey-bin RET getpeername -1 errno 57 Socket is not connected
973:3 seamonkey-bin CALL getpeername(0x3d,0x7fffff7fcaa0,0x7fffff7fca5c)
973:3 seamonkey-bin RET getpeername -1 errno 57 Socket is not connected
973:3 seamonkey-bin CALL getpeername(0x38,0x7fffff7fcaa0,0x7fffff7fca5c)
973:3 seamonkey-bin RET getpeername -1 errno 57 Socket is not connected
973:3 seamonkey-bin CALL getpeername(0x23,0x7fffff7fcaa0,0x7fffff7fca5c)
973:3 seamonkey-bin RET getpeername -1 errno 57 Socket is not connected
973:3 seamonkey-bin CALL getpeername(0x45,0x7fffff7fcaa0,0x7fffff7fca5c)
973:3 seamonkey-bin RET getpeername -1 errno 57 Socket is not connected
973:3 seamonkey-bin CALL getpeername(0x43,0x7fffff7fcaa0,0x7fffff7fca5c)
973:3 seamonkey-bin RET getpeername -1 errno 57 Socket is not connected
973:3 seamonkey-bin CALL getpeername(0x47,0x7fffff7fcaa0,0x7fffff7fca5c)
973:3 seamonkey-bin RET getpeername -1 errno 57 Socket is not connected
973:3 seamonkey-bin CALL gettimeofday(0x7fffff7fcb60,0)
973:3 seamonkey-bin RET gettimeofday 0
973:3 seamonkey-bin CALL poll(0x7fffff7fcbc0,0x9,0x3e7fc18)
973:3 seamonkey-bin RET poll 8
973:3 seamonkey-bin CALL gettimeofday(0x7fffff7fcdf0,0)
973:3 seamonkey-bin RET gettimeofday 0
973:3 seamonkey-bin CALL gettimeofday(0x7fffff7fcdf0,0)
973:3 seamonkey-bin RET gettimeofday 0
973:3 seamonkey-bin CALL getpeername(0x42,0x7fffff7fcaa0,0x7fffff7fca5c)

fstat output is available in this file:
http://leaf.dragonflybsd.org/~ftigeot/fstat_seamonkey.txt

#4 Updated by sepherosa about 3 years ago

On Sun, Sep 25, 2011 at 1:26 AM, Francois Tigeot (via DragonFly issue
tracker) <> wrote:
>
> Francois Tigeot <> added the comment:
>
> Seamonkey 2.3.1 also burns 100% cpu. The pattern is a bit different:
>
>  973:3    seamonkey-bin CALL  poll(0x7fffff7fcbc0,0x9,0x3e7fc18)
>  973:3    seamonkey-bin RET   poll 8
>  973:3    seamonkey-bin CALL  gettimeofday(0x7fffff7fcdf0,0)
>  973:3    seamonkey-bin RET   gettimeofday 0
>  973:3    seamonkey-bin CALL  gettimeofday(0x7fffff7fcdf0,0)
>  973:3    seamonkey-bin RET   gettimeofday 0
>  973:3    seamonkey-bin CALL  getpeername(0x42,0x7fffff7fcaa0,0x7fffff7fca5c)
>  973:3    seamonkey-bin RET   getpeername -1 errno 57 Socket is not connected
>  973:3    seamonkey-bin CALL  getpeername(0x44,0x7fffff7fcaa0,0x7fffff7fca5c)
>  973:3    seamonkey-bin RET   getpeername -1 errno 57 Socket is not connected
>  973:3    seamonkey-bin CALL  getpeername(0x3d,0x7fffff7fcaa0,0x7fffff7fca5c)
>  973:3    seamonkey-bin RET   getpeername -1 errno 57 Socket is not connected
>  973:3    seamonkey-bin CALL  getpeername(0x38,0x7fffff7fcaa0,0x7fffff7fca5c)
>  973:3    seamonkey-bin RET   getpeername -1 errno 57 Socket is not connected
>  973:3    seamonkey-bin CALL  getpeername(0x23,0x7fffff7fcaa0,0x7fffff7fca5c)
>  973:3    seamonkey-bin RET   getpeername -1 errno 57 Socket is not connected
>  973:3    seamonkey-bin CALL  getpeername(0x45,0x7fffff7fcaa0,0x7fffff7fca5c)
>  973:3    seamonkey-bin RET   getpeername -1 errno 57 Socket is not connected
>  973:3    seamonkey-bin CALL  getpeername(0x43,0x7fffff7fcaa0,0x7fffff7fca5c)
>  973:3    seamonkey-bin RET   getpeername -1 errno 57 Socket is not connected
>  973:3    seamonkey-bin CALL  getpeername(0x47,0x7fffff7fcaa0,0x7fffff7fca5c)
>  973:3    seamonkey-bin RET   getpeername -1 errno 57 Socket is not connected
>  973:3    seamonkey-bin CALL  gettimeofday(0x7fffff7fcb60,0)
>  973:3    seamonkey-bin RET   gettimeofday 0
>  973:3    seamonkey-bin CALL  poll(0x7fffff7fcbc0,0x9,0x3e7fc18)
>  973:3    seamonkey-bin RET   poll 8
>  973:3    seamonkey-bin CALL  gettimeofday(0x7fffff7fcdf0,0)
>  973:3    seamonkey-bin RET   gettimeofday 0
>  973:3    seamonkey-bin CALL  gettimeofday(0x7fffff7fcdf0,0)
>  973:3    seamonkey-bin RET   gettimeofday 0
>  973:3    seamonkey-bin CALL  getpeername(0x42,0x7fffff7fcaa0,0x7fffff7fca5c)
>
> fstat output is available in this file:
> http://leaf.dragonflybsd.org/~ftigeot/fstat_seamonkey.txt

Hmm, could you also post the sockstat for the seamonkey?

Currently it looks like mis-notified "socket is connected" events.

Best Regards,
sephe

#5 Updated by sepherosa about 3 years ago

On Sun, Sep 25, 2011 at 8:21 PM, Sepherosa Ziehau <> wrote:
> On Sun, Sep 25, 2011 at 1:26 AM, Francois Tigeot (via DragonFly issue
> tracker) <> wrote:
>>
>> Francois Tigeot <> added the comment:
>>
>> Seamonkey 2.3.1 also burns 100% cpu. The pattern is a bit different:
>>
>>  973:3    seamonkey-bin CALL  poll(0x7fffff7fcbc0,0x9,0x3e7fc18)
>>  973:3    seamonkey-bin RET   poll 8
>>  973:3    seamonkey-bin CALL  gettimeofday(0x7fffff7fcdf0,0)
>>  973:3    seamonkey-bin RET   gettimeofday 0
>>  973:3    seamonkey-bin CALL  gettimeofday(0x7fffff7fcdf0,0)
>>  973:3    seamonkey-bin RET   gettimeofday 0
>>  973:3    seamonkey-bin CALL  getpeername(0x42,0x7fffff7fcaa0,0x7fffff7fca5c)
>>  973:3    seamonkey-bin RET   getpeername -1 errno 57 Socket is not connected
>>  973:3    seamonkey-bin CALL  getpeername(0x44,0x7fffff7fcaa0,0x7fffff7fca5c)
>>  973:3    seamonkey-bin RET   getpeername -1 errno 57 Socket is not connected
>>  973:3    seamonkey-bin CALL  getpeername(0x3d,0x7fffff7fcaa0,0x7fffff7fca5c)
>>  973:3    seamonkey-bin RET   getpeername -1 errno 57 Socket is not connected
>>  973:3    seamonkey-bin CALL  getpeername(0x38,0x7fffff7fcaa0,0x7fffff7fca5c)
>>  973:3    seamonkey-bin RET   getpeername -1 errno 57 Socket is not connected
>>  973:3    seamonkey-bin CALL  getpeername(0x23,0x7fffff7fcaa0,0x7fffff7fca5c)
>>  973:3    seamonkey-bin RET   getpeername -1 errno 57 Socket is not connected
>>  973:3    seamonkey-bin CALL  getpeername(0x45,0x7fffff7fcaa0,0x7fffff7fca5c)
>>  973:3    seamonkey-bin RET   getpeername -1 errno 57 Socket is not connected
>>  973:3    seamonkey-bin CALL  getpeername(0x43,0x7fffff7fcaa0,0x7fffff7fca5c)
>>  973:3    seamonkey-bin RET   getpeername -1 errno 57 Socket is not connected
>>  973:3    seamonkey-bin CALL  getpeername(0x47,0x7fffff7fcaa0,0x7fffff7fca5c)
>>  973:3    seamonkey-bin RET   getpeername -1 errno 57 Socket is not connected
>>  973:3    seamonkey-bin CALL  gettimeofday(0x7fffff7fcb60,0)
>>  973:3    seamonkey-bin RET   gettimeofday 0
>>  973:3    seamonkey-bin CALL  poll(0x7fffff7fcbc0,0x9,0x3e7fc18)
>>  973:3    seamonkey-bin RET   poll 8
>>  973:3    seamonkey-bin CALL  gettimeofday(0x7fffff7fcdf0,0)
>>  973:3    seamonkey-bin RET   gettimeofday 0
>>  973:3    seamonkey-bin CALL  gettimeofday(0x7fffff7fcdf0,0)
>>  973:3    seamonkey-bin RET   gettimeofday 0
>>  973:3    seamonkey-bin CALL  getpeername(0x42,0x7fffff7fcaa0,0x7fffff7fca5c)
>>
>> fstat output is available in this file:
>> http://leaf.dragonflybsd.org/~ftigeot/fstat_seamonkey.txt
>
> Hmm, could you also post the sockstat for the seamonkey?
>
> Currently it looks like mis-notified "socket is connected" events.

Well, I don't think its our kernel problem, please test the patch posted at:
http://www.freebsd.org/cgi/query-pr.cgi?pr=156889

Best Regards,
sephe

#6 Updated by sepherosa about 3 years ago

On Sun, Sep 25, 2011 at 8:34 PM, Sepherosa Ziehau <> wrote:
> On Sun, Sep 25, 2011 at 8:21 PM, Sepherosa Ziehau <> wrote:
>> On Sun, Sep 25, 2011 at 1:26 AM, Francois Tigeot (via DragonFly issue
>> tracker) <> wrote:
>>>
>>> Francois Tigeot <> added the comment:
>>>
>>> Seamonkey 2.3.1 also burns 100% cpu. The pattern is a bit different:
>>>
>>>  973:3    seamonkey-bin CALL  poll(0x7fffff7fcbc0,0x9,0x3e7fc18)
>>>  973:3    seamonkey-bin RET   poll 8
>>>  973:3    seamonkey-bin CALL  gettimeofday(0x7fffff7fcdf0,0)
>>>  973:3    seamonkey-bin RET   gettimeofday 0
>>>  973:3    seamonkey-bin CALL  gettimeofday(0x7fffff7fcdf0,0)
>>>  973:3    seamonkey-bin RET   gettimeofday 0
>>>  973:3    seamonkey-bin CALL  getpeername(0x42,0x7fffff7fcaa0,0x7fffff7fca5c)
>>>  973:3    seamonkey-bin RET   getpeername -1 errno 57 Socket is not connected
>>>  973:3    seamonkey-bin CALL  getpeername(0x44,0x7fffff7fcaa0,0x7fffff7fca5c)
>>>  973:3    seamonkey-bin RET   getpeername -1 errno 57 Socket is not connected
>>>  973:3    seamonkey-bin CALL  getpeername(0x3d,0x7fffff7fcaa0,0x7fffff7fca5c)
>>>  973:3    seamonkey-bin RET   getpeername -1 errno 57 Socket is not connected
>>>  973:3    seamonkey-bin CALL  getpeername(0x38,0x7fffff7fcaa0,0x7fffff7fca5c)
>>>  973:3    seamonkey-bin RET   getpeername -1 errno 57 Socket is not connected
>>>  973:3    seamonkey-bin CALL  getpeername(0x23,0x7fffff7fcaa0,0x7fffff7fca5c)
>>>  973:3    seamonkey-bin RET   getpeername -1 errno 57 Socket is not connected
>>>  973:3    seamonkey-bin CALL  getpeername(0x45,0x7fffff7fcaa0,0x7fffff7fca5c)
>>>  973:3    seamonkey-bin RET   getpeername -1 errno 57 Socket is not connected
>>>  973:3    seamonkey-bin CALL  getpeername(0x43,0x7fffff7fcaa0,0x7fffff7fca5c)
>>>  973:3    seamonkey-bin RET   getpeername -1 errno 57 Socket is not connected
>>>  973:3    seamonkey-bin CALL  getpeername(0x47,0x7fffff7fcaa0,0x7fffff7fca5c)
>>>  973:3    seamonkey-bin RET   getpeername -1 errno 57 Socket is not connected
>>>  973:3    seamonkey-bin CALL  gettimeofday(0x7fffff7fcb60,0)
>>>  973:3    seamonkey-bin RET   gettimeofday 0
>>>  973:3    seamonkey-bin CALL  poll(0x7fffff7fcbc0,0x9,0x3e7fc18)
>>>  973:3    seamonkey-bin RET   poll 8
>>>  973:3    seamonkey-bin CALL  gettimeofday(0x7fffff7fcdf0,0)
>>>  973:3    seamonkey-bin RET   gettimeofday 0
>>>  973:3    seamonkey-bin CALL  gettimeofday(0x7fffff7fcdf0,0)
>>>  973:3    seamonkey-bin RET   gettimeofday 0
>>>  973:3    seamonkey-bin CALL  getpeername(0x42,0x7fffff7fcaa0,0x7fffff7fca5c)
>>>
>>> fstat output is available in this file:
>>> http://leaf.dragonflybsd.org/~ftigeot/fstat_seamonkey.txt
>>
>> Hmm, could you also post the sockstat for the seamonkey?
>>
>> Currently it looks like mis-notified "socket is connected" events.
>
> Well, I don't think its our kernel problem, please test the patch posted at:
> http://www.freebsd.org/cgi/query-pr.cgi?pr=156889

Hmm, even though the above patch is correct, but we probably should
set POLLERR if errors happened on the connection, please test the
latest master:
aa622c3d0448dbcf9cad62ea40234b9b01173663

I believe even without the patching firefox, the bug should have been fixed.

Best Regards,
sephe

#7 Updated by ftigeot about 3 years ago

On Sun, Sep 25, 2011 at 08:34:25PM +0800, Sepherosa Ziehau wrote:
> >>
> >> Francois Tigeot <> added the comment:
> >> Seamonkey 2.3.1 also burns 100% cpu. The pattern is a bit different:
>
> Well, I don't think its our kernel problem, please test the patch posted at:
> http://www.freebsd.org/cgi/query-pr.cgi?pr=156889

The patch fixes the issue.

#8 Updated by ftigeot about 3 years ago

On Sun, Sep 25, 2011 at 10:33:40PM +0800, Sepherosa Ziehau wrote:
>
> Hmm, even though the above patch is correct, but we probably should
> set POLLERR if errors happened on the connection, please test the
> latest master:
> aa622c3d0448dbcf9cad62ea40234b9b01173663
>
> I believe even without the patching firefox, the bug should have been fixed.

It is. With the new kernel, a few seconds after loading web pages, a
non-patched seamonkey goes back to using 0% cpu.

Thank you!

Also available in: Atom PDF