From owner-freebsd-current@FreeBSD.ORG Wed Jul 27 08:35:02 2011 Return-Path: Delivered-To: freebsd-current@freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:4f8:fff6::34]) by hub.freebsd.org (Postfix) with ESMTP id CB85C1065672 for ; Wed, 27 Jul 2011 08:35:02 +0000 (UTC) (envelope-from gleb.kurtsou@gmail.com) Received: from mail-fx0-f44.google.com (mail-fx0-f44.google.com [209.85.161.44]) by mx1.freebsd.org (Postfix) with ESMTP id 52E848FC08 for ; Wed, 27 Jul 2011 08:35:01 +0000 (UTC) Received: by fxe6 with SMTP id 6so63595fxe.17 for ; Wed, 27 Jul 2011 01:35:00 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=gamma; h=date:from:to:cc:subject:message-id:references:mime-version :content-type:content-disposition:in-reply-to:user-agent; bh=YNKfcHDDEi26smW7BNv/X3NBuOorMCXJG42iJR2zk5Q=; b=WSMaN+z8doTXx6iPfrj5Ga19kPsKp2oV+yV/5TBmZz/qFkY0xwe1B/Sc2tZQtYn62o CNfRS4KZcLknwEz5UkC2cim4i98TXW1Tpk17K7R2ViB52+0rbJsjnB9motLx6oxuotqC FZ0Yt+bl1lQl5VRZwQtrSzfhOEW13kBRYn9QI= Received: by 10.223.91.156 with SMTP id n28mr8050534fam.102.1311755700822; Wed, 27 Jul 2011 01:35:00 -0700 (PDT) Received: from localhost (lan-78-157-92-5.vln.skynet.lt [78.157.92.5]) by mx.google.com with ESMTPS id c1sm212409fam.22.2011.07.27.01.34.58 (version=SSLv3 cipher=OTHER); Wed, 27 Jul 2011 01:34:59 -0700 (PDT) Date: Wed, 27 Jul 2011 11:33:39 +0300 From: Gleb Kurtsou To: Alexander Best Message-ID: <20110727083339.GA12233@tops> References: <20110724212544.GA57733@freebsd.org> <20110725072102.GA24938@freebsd.org> <4E2D2C32.5010602@gmx.de> <20110727004850.GA63109@freebsd.org> MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Disposition: inline In-Reply-To: <20110727004850.GA63109@freebsd.org> User-Agent: Mutt/1.5.21 (2010-09-15) 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 08:35:02 -0000 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. 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