From owner-freebsd-current@FreeBSD.ORG Wed Jul 27 09:18:08 2011 Return-Path: Delivered-To: freebsd-current@freebsd.org Received: by hub.freebsd.org (Postfix, from userid 1233) id 9653A1065673; Wed, 27 Jul 2011 09:18:08 +0000 (UTC) Date: Wed, 27 Jul 2011 09:18:08 +0000 From: Alexander Best To: Gleb Kurtsou Message-ID: <20110727091808.GA9024@freebsd.org> References: <20110724212544.GA57733@freebsd.org> <20110725072102.GA24938@freebsd.org> <4E2D2C32.5010602@gmx.de> <20110727004850.GA63109@freebsd.org> <20110727083339.GA12233@tops> Mime-Version: 1.0 Content-Type: text/plain; charset=us-ascii Content-Disposition: inline In-Reply-To: <20110727083339.GA12233@tops> Cc: Norberto Lopes , Adrian Chadd , Matthias Andree , freebsd-current@freebsd.org Subject: Re: chromium port causing massive I/O faults X-BeenThere: freebsd-current@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list List-Id: Discussions about the use of FreeBSD-current List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Wed, 27 Jul 2011 09:18:08 -0000 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 cheers. alex > > FreeBSD 9.0-CURRENT #2 r224003+777e962: Thu Jul 14 13:04:55 EEST 2011 > chromium-11.0.696.57_1 > > > i ran the following command twice. first time without running chromium and the > > second time with chromium running: > > > > otaku% vmstat -s|grep "system calls"; sleep 1; vmstat -s|grep "system calls" > > 2178187850 system calls > > 2178189739 system calls > > > > otaku% vmstat -s|grep "system calls"; sleep 1; vmstat -s|grep "system calls" > > 2177998835 system calls > > 2178022003 system calls > > > > so it's 2k/sec vs. 23k/sec!!!! > > > > cheers. > > alex