Skip site navigation (1)Skip section navigation (2)
Date:      Wed, 27 Jul 2011 11:08:36 +0000
From:      Alexander Best <arundel@freebsd.org>
To:        Gleb Kurtsou <gleb.kurtsou@gmail.com>
Cc:        Norberto Lopes <nlopes.ml@gmail.com>, Adrian Chadd <adrian@freebsd.org>, Matthias Andree <matthias.andree@gmx.de>, freebsd-current@freebsd.org
Subject:   Re: chromium port causing massive I/O faults
Message-ID:  <20110727110836.GA22511@freebsd.org>
In-Reply-To: <20110727104316.GA6040@tops>
References:  <20110724212544.GA57733@freebsd.org> <CAJ-VmonHcDM_p3%2BYPO2vyF9a054VavQmVQqcKt369w28M%2BtaXg@mail.gmail.com> <20110725072102.GA24938@freebsd.org> <4E2D2C32.5010602@gmx.de> <20110727004850.GA63109@freebsd.org> <20110727083339.GA12233@tops> <20110727091808.GA9024@freebsd.org> <20110727104316.GA6040@tops>

next in thread | previous in thread | raw e-mail | index | archive | help
On Wed Jul 27 11, Gleb Kurtsou wrote:
> On (27/07/2011 09:18), Alexander Best wrote:
> > On Wed Jul 27 11, Gleb Kurtsou wrote:
> > > On (27/07/2011 00:48), Alexander Best wrote:
> > > > On Mon Jul 25 11, Matthias Andree wrote:
> > > > > Am 25.07.2011 09:21, schrieb Alexander Best:
> > > > > > On Mon Jul 25 11, Adrian Chadd wrote:
> > > > > >> Is it perhaps doing disk IO using mmap?
> > > > > > 
> > > > > > how can i check, whether that's the case or not?
> > > > > 
> > > > > Use truss(1) for instance.
> > > > > 
> > > > > However, unless there are *practical* problems, a high number of page
> > > > > faults is not an indication for problems.  Although it may sound scary,
> > > > > page faults are a feature of the memory management.
> > > > 
> > > > unfortunately truss(1) is crashing chromium :( i opened up a new thread
> > > > reagarding this issue on freebsd-current@.
> > > Could you try ktrace? It works for me
> > > 
> > > > another thing i noticed is the increase in system calls caused by chromium.
> > > > let's have a look at hub.freebsd.org:
> > > > 
> > > > uptime = 149 days
> > > > 
> > > > and 'vmstat -s' reports:
> > > > 
> > > > 2168697753 cpu context switches
> > > > 2266220366 device interrupts
> > > > 2902880931 software interrupts
> > > > 3779075897 traps
> > > > 902107847 system calls
> > > > 
> > > > now on my box:
> > > > 
> > > > uptime = 2 days
> > > > 
> > > > and 'vmstat -s' reports:
> > > > 
> > > > 1155995386 cpu context switches
> > > > 164577882 device interrupts
> > > > 189456976 software interrupts
> > > > 137007580 traps
> > > > 2178434582 system calls
> > > About 2.5k syscalls with chrome + a lot of other stuff running. 1.5k
> > > without chrome.
> > > 
> > > Looks like there is a lot of clock_gettime and gettimeofday syscalls.
> > > ~ % kdump -m 1 -f ktrace.out | grep 'CALL .*gettime' | wc -l
> > >    24343
> > > 
> > > ~ % kdump -E -m 1 -f ktrace.out | grep 'CALL .*gettime' | tail -20
> > >  12747 chrome   15.077376 CALL  gettimeofday(0x7fffff7f9630,0x7fffff7f9640)
> > >  12747 chrome   15.077396 CALL  clock_gettime(0x4,0x7fffffbfb6f0)
> > >  12747 chrome   15.077497 CALL  gettimeofday(0x7fffffbfb650,0x7fffffbfb660)
> > >  12747 chrome   15.077609 CALL  gettimeofday(0x7fffffbfb650,0x7fffffbfb660)
> > >  12747 chrome   15.077723 CALL  gettimeofday(0x7fffffbfb650,0)
> > >  12747 chrome   15.077845 CALL  clock_gettime(0,0x7fffffbfb2b0)
> > >  12747 chrome   15.078337 CALL  clock_gettime(0x4,0x7fffff9fa630)
> > >  12747 chrome   15.078544 CALL  clock_gettime(0x4,0x7fffff9fa650)
> > >  12747 chrome   15.078587 CALL  clock_gettime(0x4,0x7fffff9fa650)
> > >  12747 chrome   15.078632 CALL  clock_gettime(0x4,0x7fffff9fa650)
> > >  12747 chrome   15.078674 CALL  clock_gettime(0x4,0x7fffff9fa650)
> > >  12747 chrome   15.082803 CALL  gettimeofday(0x7ffffedd3630,0x7ffffedd3640)
> > >  12747 chrome   15.084644 CALL  gettimeofday(0x7fffffbfb650,0x7fffffbfb660)
> > >  12747 chrome   15.084746 CALL  clock_gettime(0x4,0x7fffffbfb670)
> > >  12747 chrome   15.084815 CALL  clock_gettime(0x4,0x7fffffbfb670)
> > >  12747 chrome   15.086620 CALL  gettimeofday(0x7ffffefd4650,0x7ffffefd4660)
> > >  12747 chrome   15.086736 CALL  clock_gettime(0x4,0x7ffffefd4670)
> > >  12747 chrome   15.086815 CALL  clock_gettime(0x4,0x7ffffefd4670)
> > >  12747 chrome   15.098315 CALL  gettimeofday(0x7fffffffafe0,0x7fffffffaff0)
> > >  12747 chrome   15.098680 CALL  clock_gettime(0x4,0x7fffffffb250)
> > > 
> > > Some work was done by kib@ to create a kernel page strong current time
> > > and other misc info to eliminate gettimeofday kind syscalls.  Bits of it
> > > were commited but I'm not sure if it was finished.
> > > But anyway calling gettimeofday hundreds of times per second is a chrome
> > > bug.
> > 
> > *lol* i did exactly the same measurements, you did. :) here are my results:
> > 
> > otaku% kdump|grep "CALL  mmap"|wc
> >      724    2896   58468
> > otaku% kdump -s|grep "CALL  clock_gettime"|wc
> >    49545  198180 2772674
> > otaku% kdump -s|grep "CALL  linux_clock_gettime"|wc
> >    40185  160740 2491298
> > otaku% kdump -s|grep "CALL  linux_gettimeofday"|wc 
> >    21670   86680 1278530
> > otaku% kdump -s|grep "CALL  gettimeofday"|wc 
> >     8173   32692  525053
> > otaku% kdump -s|grep "CALL  linux_sys_futex"|wc
> >     6191   24764  548800
> I suppose linux_* stuff comes from flashplugin. Clearly flash generates
> more gettime syscalls than chrome itself. Unfortunately the only way to
> fix this mess in a linux centric world is to implement syscall free
> gettimeofday with linux ABI support.
> 
> syscall-free gettimeofday discussion:
> http://freebsd.1045724.n5.nabble.com/fast-syscall-free-gettimeofday-td4488301.html

thanks. this linux article is also very interesting in this context:
http://lwn.net/Articles/18411/

...they sorta claim that implementing gettimeofday() in userland is extremely
difficult.

cheers.
alex



Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?20110727110836.GA22511>