From owner-freebsd-hackers@FreeBSD.ORG Sun Feb 6 06:02:11 2011 Return-Path: Delivered-To: freebsd-hackers@freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:4f8:fff6::34]) by hub.freebsd.org (Postfix) with ESMTP id 0CB961065670 for ; Sun, 6 Feb 2011 06:02:11 +0000 (UTC) (envelope-from rwatson@FreeBSD.org) Received: from cyrus.watson.org (cyrus.watson.org [65.122.17.42]) by mx1.freebsd.org (Postfix) with ESMTP id DB9128FC0A for ; Sun, 6 Feb 2011 06:02:10 +0000 (UTC) Received: from fledge.watson.org (fledge.watson.org [65.122.17.41]) by cyrus.watson.org (Postfix) with ESMTPS id 3EAE246B17; Sun, 6 Feb 2011 01:02:10 -0500 (EST) Date: Sun, 6 Feb 2011 06:02:10 +0000 (GMT) From: Robert Watson X-X-Sender: robert@fledge.watson.org To: dieterbsd@engineer.com In-Reply-To: <8CD93C6255B8920-660-30BBA@web-mmc-m06.sysops.aol.com> Message-ID: References: <8CD93C6255B8920-660-30BBA@web-mmc-m06.sysops.aol.com> User-Agent: Alpine 2.00 (BSF 1167 2008-08-23) MIME-Version: 1.0 Content-Type: TEXT/PLAIN; charset=US-ASCII; format=flowed Cc: freebsd-hackers@freebsd.org, freebsd@sopwith.solgatos.com Subject: Re: Why does printf(9) hang network? X-BeenThere: freebsd-hackers@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list List-Id: Technical Discussions relating to FreeBSD List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Sun, 06 Feb 2011 06:02:11 -0000 On Sat, 5 Feb 2011, dieterbsd@engineer.com wrote: > Why would doing a printf(9) in a device driver (usb, firewire, probably > others) cause an obscenely long lockout on > /usr/src/sys/kern/uipc_sockbuf.c:148 (sx:so_rcv_sx) ? > > Printf(9) alone isn't the problem, adding printfs to chown(2) does not cause > the problem, but printfs from device drivers do. > > Grep says that uipc_sockbuf.c is the only file that locks/unlocks sb_sx. The > device drivers and printf don't even know that sb_sx exists. I can't speak to the details of your situation, but one possible explanation might be: printf runs at the speed of the console, which for serious consoles can be extremely slowly. Device driver interrupt threads can preempt other threads, possibly while those threads hold locks. That causes them to hold the locks for much longer, as the threads may not get rescheduled for some period (for example, until the device driver is done doing a printf), leading other threads waiting for that lock to wait significantly longer. Especially the case if the other thread was spinning adaptively, in which case it will then yield since the holder of the lock effectively yielded. You might try forcing all the various threads to run on different CPUs using cpuset and see if the variance goes down. You can also use KTR + schedgraph to explore the specific scheduling going on, although be aware that KTR can also noticeably perturb schediling itself. In general, things shouldn't call kernel printf in steady state operation; if they need to log something, they should use log(9) or similar. printf is primarily a tool for printing out device probe information, and for debugging purposes: it is not intended to be fast. Robert > > 135 int > 136 sblock(struct sockbuf *sb, int flags) > 137 { > 138 > 139 KASSERT((flags & SBL_VALID) == flags, > 140 ("sblock: flags invalid (0x%x)", flags)); > 141 > 142 if (flags & SBL_WAIT) { > 143 if ((sb->sb_flags & SB_NOINTR) || > 144 (flags & SBL_NOINTR)) { > 145 sx_xlock(&sb->sb_sx); > 146 return (0); > 147 } > 148 return (sx_xlock_sig(&sb->sb_sx)); > 149 } else { > 150 if (sx_try_xlock(&sb->sb_sx) == 0) > 151 return (EWOULDBLOCK); > 152 return (0); > 153 } > 154 } > > More info at: http://www.freebsd.org/cgi/query-pr.cgi?pr=118093 > > > _______________________________________________ > freebsd-hackers@freebsd.org mailing list > http://lists.freebsd.org/mailman/listinfo/freebsd-hackers > To unsubscribe, send any mail to "freebsd-hackers-unsubscribe@freebsd.org" >