Bug #1893: Firefox consumes 100% CPU while polling - DragonFlyBSD - DragonFlyBSD bugtracker

Actions

Copy link

Bug #1893

closed

Firefox consumes 100% CPU while polling

Added by matthias over 13 years ago. Updated over 12 years ago.

Status:

Closed

Priority:

Normal

Assignee:

Category:

Target version:

Start date:

Due date:

% Done:

Estimated time:

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
Notes

Actions

Copy link

Updated by ftigeot over 13 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.

Actions

Copy link

Updated by ftigeot over 13 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

Actions

Copy link

Updated by ftigeot over 12 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

Actions

Copy link

Updated by sepherosa over 12 years ago

On Sun, Sep 25, 2011 at 1:26 AM, Francois Tigeot (via DragonFly issue
tracker) <sinknull@leaf.dragonflybsd.org> wrote:

Francois Tigeot <ftigeot@wolfpond.org> 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

Actions

Copy link

Updated by sepherosa over 12 years ago

On Sun, Sep 25, 2011 at 8:21 PM, Sepherosa Ziehau <sepherosa@gmail.com> wrote:

On Sun, Sep 25, 2011 at 1:26 AM, Francois Tigeot (via DragonFly issue
tracker) <sinknull@leaf.dragonflybsd.org> wrote:

Francois Tigeot <ftigeot@wolfpond.org> 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

Actions

Copy link

Updated by sepherosa over 12 years ago

On Sun, Sep 25, 2011 at 8:34 PM, Sepherosa Ziehau <sepherosa@gmail.com> wrote:

On Sun, Sep 25, 2011 at 8:21 PM, Sepherosa Ziehau <sepherosa@gmail.com> wrote:

On Sun, Sep 25, 2011 at 1:26 AM, Francois Tigeot (via DragonFly issue
tracker) <sinknull@leaf.dragonflybsd.org> wrote:

Francois Tigeot <ftigeot@wolfpond.org> 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

Actions

Copy link

Updated by ftigeot over 12 years ago

On Sun, Sep 25, 2011 at 08:34:25PM +0800, Sepherosa Ziehau wrote:

Francois Tigeot <ftigeot@wolfpond.org> 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.

Actions

Copy link

Updated by ftigeot over 12 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!

Actions

Copy link

Also available in: Atom PDF

Project

General

Profile

DragonFlyBSD

Bug #1893

Firefox consumes 100% CPU while polling

Updated by ftigeot over 13 years ago

Updated by ftigeot over 13 years ago

Updated by ftigeot over 12 years ago

Updated by sepherosa over 12 years ago

Updated by sepherosa over 12 years ago

Updated by sepherosa over 12 years ago

Updated by ftigeot over 12 years ago

Updated by ftigeot over 12 years ago