From owner-freebsd-arch@FreeBSD.ORG Mon May 2 20:02:06 2011 Return-Path: Delivered-To: arch@freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:4f8:fff6::34]) by hub.freebsd.org (Postfix) with ESMTP id 1EB9F1065675 for ; Mon, 2 May 2011 20:02:06 +0000 (UTC) (envelope-from jhb@freebsd.org) Received: from cyrus.watson.org (cyrus.watson.org [65.122.17.42]) by mx1.freebsd.org (Postfix) with ESMTP id EAD428FC0A for ; Mon, 2 May 2011 20:02:05 +0000 (UTC) Received: from bigwig.baldwin.cx (66.111.2.69.static.nyinternet.net [66.111.2.69]) by cyrus.watson.org (Postfix) with ESMTPSA id 9DDFF46B4C; Mon, 2 May 2011 16:02:05 -0400 (EDT) Received: from jhbbsd.localnet (unknown [209.249.190.124]) by bigwig.baldwin.cx (Postfix) with ESMTPSA id 2AE548A027; Mon, 2 May 2011 16:02:05 -0400 (EDT) From: John Baldwin To: Kostik Belousov Date: Mon, 2 May 2011 16:02:02 -0400 User-Agent: KMail/1.13.5 (FreeBSD/8.2-CBSD-20110325; KDE/4.5.5; amd64; ; ) References: <201105021537.19507.jhb@freebsd.org> <20110502195555.GC48734@deviant.kiev.zoral.com.ua> In-Reply-To: <20110502195555.GC48734@deviant.kiev.zoral.com.ua> MIME-Version: 1.0 Content-Type: Text/Plain; charset="iso-8859-15" Content-Transfer-Encoding: 7bit Message-Id: <201105021602.02668.jhb@freebsd.org> X-Greylist: Sender succeeded SMTP AUTH, not delayed by milter-greylist-4.2.6 (bigwig.baldwin.cx); Mon, 02 May 2011 16:02:05 -0400 (EDT) Cc: arch@freebsd.org Subject: Re: [PATCH] Add ktrace records for user page faults X-BeenThere: freebsd-arch@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list List-Id: Discussion related to FreeBSD architecture List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Mon, 02 May 2011 20:02:06 -0000 On Monday, May 02, 2011 3:55:55 pm Kostik Belousov wrote: > On Mon, May 02, 2011 at 03:37:19PM -0400, John Baldwin wrote: > > One thing I have found useful is knowing when processes are in the kernel > > instead of in userland. ktrace already provides records for syscall > > entry/exit. The other major source of time spent in the kernel that I've seen > > is page fault handling. To that end, I have a patch that adds ktrace records > > to the beginning and end of VM faults. This gives a pair of records so a user > > can see how long a fault took (similar to how one can see how long a syscall > > takes now). Sample output from kdump is below: > > > > 47565 echo CALL mmap(0x800a87000,0x179000,PROT_READ| > > PROT_WRITE,MAP_PRIVATE|MAP_ANON,0xffffffff,0) > > 47565 echo RET mmap 34370777088/0x800a87000 > > 47565 echo PFLT 0x800723000 VM_PROT_EXECUTE > > 47565 echo RET KERN_SUCCESS > > 47565 echo CALL munmap(0x800887000,0x179000) > > 47565 echo RET munmap 0 > > 47565 echo PFLT 0x800a00000 VM_PROT_WRITE > > 47565 echo RET KERN_SUCCESS > > > > The patch is available at www.freebsd.org/~jhb/patches/ktrace_fault.patch and > > included below. > > One immediate detail is that trap() truncates the fault address to the > page address, that arguably looses useful information. It is true that it would be nice to have the exact faulting address, though having page granularity has been sufficient for the few times I've actually used the address itself (e.g. I could figure out which page of libstdc++ a fault occurred on and narrow down from there as to which of the routines most likely was executed given what the app was doing at the time). In my case knowing how much time was spent handling a page fault has been useful. Would we have to push this logic out of vm_fault and into every trap() routine to get the original address? That would make the patch quite a bit bigger (touching N MD files vs 1 MI file). -- John Baldwin