Date: Sun, 6 Feb 2011 06:02:10 +0000 (GMT) From: Robert Watson <rwatson@FreeBSD.org> To: dieterbsd@engineer.com Cc: freebsd-hackers@freebsd.org, freebsd@sopwith.solgatos.com Subject: Re: Why does printf(9) hang network? Message-ID: <alpine.BSF.2.00.1102060558390.5437@fledge.watson.org> In-Reply-To: <8CD93C6255B8920-660-30BBA@web-mmc-m06.sysops.aol.com> References: <8CD93C6255B8920-660-30BBA@web-mmc-m06.sysops.aol.com>
next in thread | previous in thread | raw e-mail | index | archive | help
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"
>
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?alpine.BSF.2.00.1102060558390.5437>