From owner-freebsd-current@FreeBSD.ORG Wed Feb 23 01:08:22 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 546011065673 for ; Wed, 23 Feb 2011 01:08:22 +0000 (UTC) (envelope-from rysto32@gmail.com) Received: from mail-ey0-f182.google.com (mail-ey0-f182.google.com [209.85.215.182]) by mx1.freebsd.org (Postfix) with ESMTP id DBFCF8FC16 for ; Wed, 23 Feb 2011 01:08:21 +0000 (UTC) Received: by eyg7 with SMTP id 7so1284495eyg.13 for ; Tue, 22 Feb 2011 17:08:20 -0800 (PST) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=gamma; h=domainkey-signature:mime-version:in-reply-to:references:date :message-id:subject:from:to:cc:content-type; bh=DQApVtOiWNDpVIVpn6q3ksT0vH8R35ZUBoOnCDNDO+s=; b=lsWYcV5CFvjn83/81u4ddOMmeUhIRPW74FYVD1RCDngQjN64xeOVnX98nZc8VZ6F/L egAg17PQZ5tUHBG1ZQw/fnMNk2EzjBZoB30PEv2jwOGt56JycyRTQY/HwvU1ZS4hwl1K CoZapY+VoyBN1PCqyHXtsumjU6plgmYVJW+Og= DomainKey-Signature: a=rsa-sha1; c=nofws; d=gmail.com; s=gamma; h=mime-version:in-reply-to:references:date:message-id:subject:from:to :cc:content-type; b=sRtoBb3yJBSsyxsOP2UkAqBe5yICdOl0R6wvfQcse2NZd3mZGB0NgdYS5YB55vXhhK /uMlCfZC2QR4NQmVEK7ce799aaE1pNZPgT2LJJLbexQtMbNghw+yNQFVLyXDp1ajZJIH 4klZ7bE4PyKtn/5EzQjzEhvy8vcAIMY7cLHNM= MIME-Version: 1.0 Received: by 10.213.26.20 with SMTP id b20mr67447ebc.55.1298423300729; Tue, 22 Feb 2011 17:08:20 -0800 (PST) Received: by 10.213.20.135 with HTTP; Tue, 22 Feb 2011 17:08:20 -0800 (PST) In-Reply-To: <20110222195713.GW66284@funkthat.com> References: <4D6291A5.4050206@netasq.com> <8C8FE4A5-F031-466A-9CB8-46D79EEA280D@mac.com> <4D638050.2010906@netasq.com> <20110222195713.GW66284@funkthat.com> Date: Tue, 22 Feb 2011 20:08:20 -0500 Message-ID: From: Ryan Stone To: Jerome Flesch , Chuck Swiger , freebsd-current@freebsd.org Content-Type: text/plain; charset=ISO-8859-1 Cc: John-Mark Gurney Subject: Re: Process timing issue 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, 23 Feb 2011 01:08:22 -0000 To debug weird scheduling issues I find it helpful to start by looking at a schedgraph. schedgraph is a tool that can display a graphical representation of what the scheduler was doing over a small slice of time. The one downside is that you have to recompile your kernel to get the hooks that collect the necessary data, but it sounds like your problem is pretty easy to reproduce and so that shouldn't be a big problem. To enable the hooks, put the following in your kernel conf: options KTR options KTR_COMPILE=KTR_SCHED options KTR_MASK=KTR_SCHED options KTR_ENTIRES=(128*1024) Then rebuild and install the new kernel. Next, run your test. The instant that your test has detected the long delay, set the sysctl debug.ktr.mask to 0. The scheduler hooks record data into a ring buffer, so the interesting data can be flushed out within seconds. Clearing that sysctl will stop any further events from being logged, which means that the interesting data will stay there until you go and collect it. You can get the raw data by redirecting the output of "ktrdump -ct" into a file. Then from any machine with a graphical interface(FreeBSD with X installed, Windows, Mac, whatever) and python installed, run: $ python schedgraph.py /path/to/ktrdump/output You can get schedgraph.py from /usr/src/tools/sched. If you want to collect the data again, set the sysctl debug.ktr.mask back to 0x20000000 to restart gathering scheduler data. Ryan