From owner-freebsd-current@FreeBSD.ORG Tue May 31 15:42:16 2011 Return-Path: Delivered-To: current@freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:4f8:fff6::34]) by hub.freebsd.org (Postfix) with ESMTP id C4345106566C for ; Tue, 31 May 2011 15:42:16 +0000 (UTC) (envelope-from ken@kdm.org) Received: from nargothrond.kdm.org (nargothrond.kdm.org [70.56.43.81]) by mx1.freebsd.org (Postfix) with ESMTP id 875B08FC18 for ; Tue, 31 May 2011 15:42:16 +0000 (UTC) Received: from nargothrond.kdm.org (localhost [127.0.0.1]) by nargothrond.kdm.org (8.14.2/8.14.2) with ESMTP id p4VFgFhL046187; Tue, 31 May 2011 09:42:15 -0600 (MDT) (envelope-from ken@nargothrond.kdm.org) Received: (from ken@localhost) by nargothrond.kdm.org (8.14.2/8.14.2/Submit) id p4VFgFYh046186; Tue, 31 May 2011 09:42:15 -0600 (MDT) (envelope-from ken) Date: Tue, 31 May 2011 09:42:15 -0600 From: "Kenneth D. Merry" To: Julian Elischer Message-ID: <20110531154215.GA45877@nargothrond.kdm.org> References: <20110527224523.GA77922@nargothrond.kdm.org> <4DE13E6A.20202@freebsd.org> Mime-Version: 1.0 Content-Type: text/plain; charset=us-ascii Content-Disposition: inline In-Reply-To: <4DE13E6A.20202@freebsd.org> User-Agent: Mutt/1.4.2i Cc: current@freebsd.org Subject: Re: message buffer scrambling fix 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: Tue, 31 May 2011 15:42:16 -0000 On Sat, May 28, 2011 at 11:26:50 -0700, Julian Elischer wrote: > On 5/27/11 3:45 PM, Kenneth D. Merry wrote: > >Hey folks, > > > >I have attached some patches to the kernel message buffer code (this > >affects dmesg(8) output as well as kernel messages that go to the syslog) > >to address log scrambling. > > > >This fixes the same issue that 'options PRINTF_BUFR_SIZE=128' fixes for the > >console. > > > >The problem is that you can have multiple kernel threads writing to the > >message buffer at the same time, and so their characters will get > >interleaved. All of the characters will get in there, because they're > >written with atomic operations, but the output might looked scrambled. > > > >So the fix is to use the same stack buffer that is used for the console > >output (so the stack size doesn't increase), and use a spin lock instead of > >atomic operations to insert the string into the message buffer. > > > >The result is that dmesg and syslog output should look the same as the > >console output. As long as individual kernel prints fit in the printf > >buffer size, they will be put into the message buffer atomically. > > > >I also fixed a couple of other long-standing issues. putcons() (in > >subr_prf.c) was adding a carriage return before calling cnputs(). But > >cnputs() calls cnputc(), which adds a carriage return before every newline. > >So much of the console output (the part that came from putcons() at least) > >had two carriage returns at the end. > > > >The other issue was that log_console() was inserting a newline for any > >console write that didn't already have one at the end. The issue with that > >can be seen if you do a 'dmesg -a' and compare that to the console output. > > > >You'll see something like this on the console: > > > >Updating motd:. > > > >But this in dmesg -a: > > > >Updating motd: > >. > > > >That is because "Updating motd:" is written first, log_console() appends a > >newline, and then ".\n" is written. > > > >I added a loader tunable and sysctl to turn the old behavior back on > >(kern.log_console_add_linefeed) if you want the old behavior, but I think > >we should be able to safely remove it. > > > >Also, the new msgbuf_addstr() function allows the caller to optionally ask > >for carriage returns to be stripped out. However, in my testing I haven't > >seen any carriage returns to strip. > > > >Let me know if you have any comments. I'm planning to check this into head > >next week. > > looks good.. as long as we don't end up with the behaviour that I > think I see on > Linux (it's hard to tell sometimes) where the last message (the one > you really > want to see) doesn't make it out. Everything passed into the kernel printf() call should make it out to the console, message buffer, etc. before the printf call completes. The only way that wouldn't happen is if spin locks break for some reason. One thing I forgot to mention is that I think the PRINTF_BUFR_SIZE option should be made non-optional. Even on smaller embedded machines, I think we should be able to afford the 128 bytes of stack space to keep messages from getting scrambled. Ken -- Kenneth Merry ken@FreeBSD.ORG