Re: chromium port causing massive I/O faults

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_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

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