Date: Mon, 07 Feb 2011 18:49:12 -0500 From: dieterbsd@engineer.com To: freebsd-hackers@freebsd.org Subject: Re: Why does printf(9) hang network? Message-ID: <8CD9538C148865F-1B10-A4C8@web-mmc-m02.sysops.aol.com>
next in thread | raw e-mail | index | archive | help
Robert writes: >> Why would doing a printf(9) in a device driver (usb, firewire,=20 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=20 not >> cause the problem, but printfs from device drivers do. >> >> Grep says that uipc_sockbuf.c is the only file that locks/unlocks=20 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=20 for > serious consoles can be extremely slowly. But shouldn't the RS-232 driver just fill up the UART's FIFO and then=20 sleep? Why can't the network code run while the RS-232 driver sleeps? Actually this must be happening in the call-printf-from-chown case. There must=20 be something different when printf is called from a device driver. > 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=20 some > period (for example, until the device driver is done doing a printf), If the CPU is mostly idle, shouldn't the network thread get scheduled=20 right away? > leading > other threads waiting for that lock to wait significantly longer. > Especially the case if the other thread was spinning adaptively, in=20 which > case it will then yield since the holder of the lock effectively=20 yielded. My head is spinning attempting to understand this... > You might try forcing all the various threads to run on different CPUs > using cpuset and see if the variance goes down. Uniprocessor > You can also use KTR + schedgraph > to explore the specific scheduling going on, although be aware that=20 KTR > can also noticeably perturb schediling itself. Scheduling? The CPU can be mostly idle and the problem still happens. > In general, things shouldn't call kernel printf in steady state=20 operation; > if they need to log something, they should use log(9) or similar. =20 printf > is primarily a tool for printing out device probe information, and for > debugging purposes: it is not intended to be fast. Sounds fine to me. Is there a consensus on this? If so, does this=20 need to go into some developer's handbook? How do we get developers to fix the existing code?
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?8CD9538C148865F-1B10-A4C8>