Re: chromium port causing massive I/O faults

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_at_.
> > 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_at_ 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