Skip site navigation (1)Skip section navigation (2)
Date:      Sat, 18 Feb 2012 02:08:45 +1100 (EST)
From:      Bruce Evans <brde@optusnet.com.au>
To:        Pawel Jakub Dawidek <pjd@FreeBSD.org>
Cc:        marcel@FreeBSD.org, Eitan Adler <eadler@FreeBSD.org>, svn-src-all@FreeBSD.org, "Kenneth D. Merry" <ken@FreeBSD.org>, Andriy Gapon <avg@FreeBSD.org>, Marcel Moolenaar <marcel@xcllnt.net>, src-committers@FreeBSD.org, Bruce Evans <brde@optusnet.com.au>, svn-src-head@FreeBSD.org, Julian Elischer <julian@FreeBSD.org>
Subject:   Re: svn commit: r231814 - in head/sys: kern sys
Message-ID:  <20120218013015.L3043@besplex.bde.org>
In-Reply-To: <20120217092038.GD1358@garage.freebsd.pl>
References:  <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> <4F3E18CE.1010700@freebsd.org> <20120217092038.GD1358@garage.freebsd.pl>

next in thread | previous in thread | raw e-mail | index | archive | help
On Fri, 17 Feb 2012, Pawel Jakub Dawidek wrote:

> On Fri, Feb 17, 2012 at 01:07:26AM -0800, Julian Elischer wrote:
>> On 2/17/12 12:58 AM, Pawel Jakub Dawidek wrote:
>>> 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 think that if you want such complications, you get to code them
yourself, as in userland.

>> with locking your example could still be broken up because there is a
>> lock per printf..
>>
>> if you want them done together you really should print parts to a
>> separate assembly buffer and then put it all out at once.

This seems to be necessary.

> Not really. I was thinking about recursive printf-lock that is used
> internally by printf, but can also be used by printfs consumers, eg.
>
> 	mtx_lock(&printf_lock);
> 	printf("first thing ");
> 	printf("second thing");
> 	mtx_unlock(&printf_lock);
>
> Again, printf internally is using printf_lock too.

See my old patches.  They use the printf_lock() function.  Normal mutexes
cannot be used, due to deadlock.  printf_lock() is intentionally not
recursive, and anything that recurses into it is rewarded with its 1
second timeout.  It is private to subr_prf.c, and called from printf().
Apart from that, it would work OK if you called it as above :-).  There
would normally be a 1 second delay when each of the printf()s recursed.
I vaguely remember having recursion in the original version of it, and
then left it out because it caused fragility and minor complications.
Recursion shouldn't happen, and when it does the timeout works well.

>> I actually like the idea of pcpu buffers. witha single atomic sequence
>> number being the only
>> sychroniaation needed.

If you are going to have separate buffers, then you can have one for each
class of log() and printf():
- ddb: normally no buffering; sometimes a special ddb buffer (I think there
   already is one)
- emergency messages: these are exepected to usurp each other if they
   happen
- next level of critical messages
...
- informational messages that go to the console
- highest priority log messages that don't go to the console
...
- see syslog.h for various priorities.  You can have a buffer for each
   priority and not need to put thr priority markup in-band.

But then you have the problem of reassembling everything, and atomic
updates and accesses for this..., and minimizing the resource wastage
(the default MSGBUF size is now 96K.  This size, or complications,
would be needed for each message class on each CPU to ensure not
losing messages that are not lost now, in case all the messages are
in one class on one CPU).

> Maybe I'm over engineering here, but...

The above is over-the-top engineered :-).

> If we store in the thread structure two things: your counter and
> information if the last message stored by this thread had \n at the end
> or not, we could reuse the same counter for the next message by this
> thread if the previous message had no \n. This way my macro will work
> with per-CPU lists and preemption. I'd still need sched_pin() though.

Would that help much?  I think kernel hackers don't look at the msgbuf
much.  They printf() to the console and look at the output there.
If yu don't want it there, use log() and not printf().  log()s that
only use the msgbuf can be made atomic more simply than printf()s,
since they don't have to wait for the console, and shouldn't be used
for emergency messages.  Just excuting them faster gives a better
chance that they wonn't be contended with on other CPUs.

Bruce



Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?20120218013015.L3043>