From owner-svn-src-head@FreeBSD.ORG Fri Feb 17 17:25:09 2012 Return-Path: Delivered-To: svn-src-head@FreeBSD.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:4f8:fff6::34]) by hub.freebsd.org (Postfix) with ESMTP id 44AA31065675; Fri, 17 Feb 2012 17:25:09 +0000 (UTC) (envelope-from marcel@xcllnt.net) Received: from mail.xcllnt.net (mail.xcllnt.net [70.36.220.4]) by mx1.freebsd.org (Postfix) with ESMTP id DFE408FC14; Fri, 17 Feb 2012 17:25:08 +0000 (UTC) Received: from [172.23.7.53] (natint3.juniper.net [66.129.224.36]) (authenticated bits=0) by mail.xcllnt.net (8.14.5/8.14.5) with ESMTP id q1HHOrqQ004456 (version=TLSv1/SSLv3 cipher=AES128-SHA bits=128 verify=NO); Fri, 17 Feb 2012 09:25:01 -0800 (PST) (envelope-from marcel@xcllnt.net) Mime-Version: 1.0 (Apple Message framework v1257) Content-Type: text/plain; charset=us-ascii From: Marcel Moolenaar In-Reply-To: <20120217085840.GC1358@garage.freebsd.pl> Date: Fri, 17 Feb 2012 09:24:54 -0800 Content-Transfer-Encoding: 7bit Message-Id: <1AC67C3A-F6D5-419F-BD15-26AACF6BA567@xcllnt.net> References: <201202160511.q1G5BZNk099785@svn.freebsd.org> <20120216181210.K1423@besplex.bde.org> <4F3CC40D.4000307@freebsd.org> <4F3CC5C4.7020501@FreeBSD.org> <4F3CC8A5.3030107@FreeBSD.org> <20120216174758.GA64180@nargothrond.kdm.org> <20120217053341.R1256@besplex.bde.org> <20120217000846.GA7641@nargothrond.kdm.org> <4F3D9D03.6020507@FreeBSD.org> <9CB7ECE8-FF10-43BE-9EBD-16953BE3B193@xcllnt.net> <20120217085840.GC1358@garage.freebsd.pl> To: Pawel Jakub Dawidek X-Mailer: Apple Mail (2.1257) X-Mailman-Approved-At: Fri, 17 Feb 2012 17:56:12 +0000 Cc: marcel@FreeBSD.org, Eitan Adler , svn-src-all@FreeBSD.org, "Kenneth D. Merry" , Andriy Gapon , src-committers@FreeBSD.org, Bruce Evans , svn-src-head@FreeBSD.org, Julian Elischer Subject: Re: svn commit: r231814 - in head/sys: kern sys X-BeenThere: svn-src-head@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list List-Id: SVN commit messages for the src tree for head/-current List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Fri, 17 Feb 2012 17:25:09 -0000 On Feb 17, 2012, at 12:58 AM, Pawel Jakub Dawidek wrote: *snip* >> I think we should lift above the immediate problem and allow for >> single- and multi-line messages that are atomically appended to >> the message buffer. Console output and propagation of messages >> outside of the kernel should all come out of the message buffer >> and preserving the atomicity of the messages. >> >> The message buffer does not have to be a chunk of memory that >> we circularly scribble to. It can be a per-cpu linked list of >> messages even. *snip* > > I agree with everything except for per-CPU buffers. I understand the > need for using printf in low-level code and it indeed complicates things. > The reason I don't like the idea of per-CPU buffers is that locking > would allow me to implement atomicity across multiple printfs. > For example I often use macros like this: > > #define G_MIRROR_DEBUG(lvl, ...) do { \ > if (g_mirror_debug >= (lvl)) { \ > printf("GEOM_MIRROR"); \ > if (g_mirror_debug > 0) \ > printf("[%u]", lvl); \ > printf(": "); \ > printf(__VA_ARGS__); \ > printf("\n"); \ > } \ > } while (0) > > And I'd like all the printfs to be committed as one message without > using some additional buffer first and then single printf. > With some kind of printf-lock we could use recursive locking to achieve > this. In your proposal I may run each printf on different CPU. > I could eventually use sched_pin() around all printfs, I guess. > This still doesn't cover the case when I'm preempted between my printfs, > so maybe I need critical section there? I don't expect printf should be > fast, so it might be ok. I'm sure there's an elegant solution somewhere to be found. In fact, I'm actually thinking broader still: to fundamentally replace printf with logging, similar to syslog and define printf as a macro or wrapper for logging (with some fixed priority and/or facility). The most important aspect of this is that we can better control the verbosity of the boot. The least verbose boot would only print the absolutely required messages (read: legaleze). At the most verbose boot you get whatever log or print exists in the kernel in the code that gets executed. There's many levels in between. The facility allows us to crank up verbosity for components or drivers only and helps us to focus on the area of interest. I.e. if there's a driver that won't attach, it's really nice to have that driver as verbose as it gets without also having to sift through megabytes of unrelated noise. Debug output is no different from "very verbose" output and biggest problem we have is to define a good set of standard priorities that people can use. With the above, I see no problem cuddling up to sbuf(9) and use sbuf to collect fragments and or multiple lines and use it to atomically "print" the message. A simple transactional model should suffice, as in: lt = log_begin(sbuf, priority, facility); log(lt, "foo"); log(lt, "\nbar\n"); : log(lt, "baz"); log_end(lt); This eliminates any need for one-off macros to do this stuff, like the one you typically use. Oh, and it would be nice to have a kernel configuration that controls which priority levels get compiled in, so that you can easily construct a kernel without tons of high verbosity log messages when you don't want them. -- Marcel Moolenaar marcel@xcllnt.net