Date: Sun, 4 May 2014 19:25:06 +1000 (EST) From: Bruce Evans <brde@optusnet.com.au> To: Andrew Turner <andrew@freebsd.org> Cc: svn-src-projects@freebsd.org, src-committers@freebsd.org Subject: Re: svn commit: r265268 - projects/arm64/sys/arm64/arm64 Message-ID: <20140504182755.K1388@besplex.bde.org> In-Reply-To: <201405031527.s43FRUTg019278@svn.freebsd.org> References: <201405031527.s43FRUTg019278@svn.freebsd.org>
next in thread | previous in thread | raw e-mail | index | archive | help
On Sat, 3 May 2014, Andrew Turner wrote:
> Log:
> Replace panic with printf in spinlock_{enter,exit} as panic makes use of
> spinlocks.
printf has been broken to use spinlocks too. It used to be careful to
use atomic operations to avoid locking. Most console drivers are broken
too. Some serial ones avoid locking in debugger mode only.
> Modified: projects/arm64/sys/arm64/arm64/machdep.c
> ==============================================================================
> --- projects/arm64/sys/arm64/arm64/machdep.c Sat May 3 15:03:47 2014 (r265267)
> +++ projects/arm64/sys/arm64/arm64/machdep.c Sat May 3 15:27:30 2014 (r265268)
> @@ -221,14 +221,14 @@ void
> spinlock_enter(void)
> {
>
> - panic("spinlock_enter");
> + printf("spinlock_enter\n");
> }
>
> void
> spinlock_exit(void)
> {
>
> - panic("spinlock_exit");
> + printf("spinlock_exit\n");
> }
I think panic() often blows away locking (that is another type of
brokenness), but that isn't going to work for the above. Any spinlocking
in a printf in panic is just going to call printf recursively.
The first locking bug in printf is somewhere near:
subr_msgbuf.c:
% /*
% * Append a character to a message buffer.
% */
% void
% msgbuf_addchar(struct msgbuf *mbp, int c)
% {
% mtx_lock_spin(&mbp->msg_lock);
%
% msgbuf_do_addchar(mbp, &mbp->msg_wseq, c);
%
% mtx_unlock_spin(&mbp->msg_lock);
% }
This has about the same density of style bugs as locking bugs.
The mutex here is a non-recursive spinlock, so any printf in its
acquiry will panic recursively if INVARIANTS is enabled. You really
shouldn't call printf from low-level locking code, but for debugging
printf should work in such contexts. Note that it must work when
called by debuggers for single-stepping through such contexts, so
console drivers must work in such contexts and whatever makes that
work needs only relatively trivial changes to work generally.
Some bugs are avoided by not writing to the message buffer in some
contexts, but writing atomically to the message buffer is relatively
trivial.
The non-broken version of this (from FreeBSD-5.1) is:
% /*
% * Append a character to a message buffer. This function can be
% * considered fully reentrant so long as the number of concurrent
% * callers is less than the size of the buffer.
% * However, the message buffer is only guaranteed to be consistent
% * for reading when there are no callers in this function.
% */
% void
% msgbuf_addchar(struct msgbuf *mbp, int c)
% {
% u_int new_seq, pos, seq;
%
% do {
% seq = mbp->msg_wseq;
% new_seq = MSGBUF_SEQNORM(mbp, seq + 1);
% } while (atomic_cmpset_rel_int(&mbp->msg_wseq, seq, new_seq) == 0);
% pos = MSGBUF_SEQ_TO_POS(mbp, seq);
% atomic_add_int(&mbp->msg_cksum, (u_int)(u_char)c -
% (u_int)(u_char)mbp->msg_ptr[pos]);
% mbp->msg_ptr[pos] = c;
% }
I use similar methods to unbreak some versions syscons a little. The
unbreakage detects some cases of deadlock for normal locking (these
occur mainly for buggy recursion like printf from low levels), and
when they occur the handling is not to panic recursively but is to
splat the message together with some extra debugging info onto the vga
frame buffer using atomic ops like the above, and also to splat the
message into a local message buffer. The local message buffer is
replayed as normal output later if possible.
The first locking bug in console drivers is somewhere near:
% void
% cnputs(char *p)
% {
% int c;
% int unlock_reqd = 0;
%
% if (use_cnputs_mtx) {
% mtx_lock_spin(&cnputs_mtx);
% unlock_reqd = 1;
% }
%
% while ((c = *p++) != '\0')
% cnputc(c);
%
% if (unlock_reqd)
% mtx_unlock_spin(&cnputs_mtx);
% }
The mutex here is a non-recursive spinlock, so any printf that calls
cnputs in its acquiry will panic recursively if INVARIANTS is enabled,
as above. This bug is smaller than the above, since cnputs is not use
for all printfs. It is used unconditionally mainly if the
PRINTF_BUFR_SIZE bug is configured. This is now the default in GENERIC
:-(. printf buffering is turned off in some low-level contexts
including debugger contexts, but I don't see anything to do that for
a generic printf when PRINTF_BUFR_SIZE is configured. PRINTF_BUFR_SIZE
is broken as designed, since you just can't have serialization of
printfs for printfs from lower levels. Serialization of a printf from
spinlock_enter asks for either blocking spinlock_enter if the
serialization buffer is locked by another CPU, or deadlock if the
serialization buffer is locked by the same CPU.
Here is an old version of my printf serialization patches. See the
accompanying mail in 2009 for more details
% Index: subr_prf.c
% ===================================================================
% RCS file: /home/ncvs/src/sys/kern/subr_prf.c,v
% retrieving revision 1.130.2.1
% diff -u -2 -r1.130.2.1 subr_prf.c
% --- subr_prf.c 21 Jan 2009 00:26:45 -0000 1.130.2.1
% +++ subr_prf.c 15 Jun 2009 05:32:03 -0000
% @@ -112,4 +112,27 @@
% &always_console_output, 0, "Always output to console despite TIOCCONS.");
%
% +static int printf_lockcount;
% +
% +static void
% +printf_lock(void)
% +{
% + int timeout;
% +
% + timeout = 1000;
% + do {
% + if (atomic_cmpset_acq_int(&printf_lockcount, 0, 1))
% + return;
% + DELAY(1000);
% + } while (--timeout != 0);
% + atomic_add_acq_int(&printf_lockcount, 1);
% +}
% +
% +static void
% +printf_unlock(void)
% +{
% +
% + atomic_add_rel_int(&printf_lockcount, -1);
% +}
% +
% /*
% * Warn that a system table is full.
% @@ -198,5 +221,9 @@
% pca.flags = flags;
% va_start(ap, fmt);
% + if (pri != -1)
% + printf_lock(); /* To serialize msgbuf. XXX: long-held lock? */
% kvprintf(fmt, putchar, &pca, 10, ap);
% + if (pri != -1)
% + printf_unlock();
% va_end(ap);
% if (sess != NULL)
% @@ -243,5 +270,7 @@
%
% va_start(ap, fmt);
% + printf_lock(); /* Even for TOLOG, for serializing msgbuf. */
% kvprintf(fmt, putchar, &pca, 10, ap);
% + printf_unlock();
% va_end(ap);
%
% @@ -312,5 +341,7 @@
% #endif
%
% + printf_lock();
% retval = kvprintf(fmt, putchar, &pca, 10, ap);
% + printf_unlock();
% va_end(ap);
%
% @@ -350,5 +381,7 @@
% #endif
%
% + printf_lock();
% retval = kvprintf(fmt, putchar, &pca, 10, ap);
% + printf_unlock();
%
% #ifdef PRINTF_BUFR_SIZE
When recursion occurs, the locking is blown away, and the output occurs
unserialized and _very slowly_ (about 1 character for every timeout
period). You can contemplate the bug that causes the recursion while
this is occuring. One such bug is in debugger entry. printf is called
from kdb_enter improperly _before_ entering debugging context. So
if you sprinkle kdb_enter calls in low-level functions like spinlock_enter,
as sometimes is needed to debug such functions, you get either:
- recursive panics from broken printfs
- very slow output from my version.
Putting breakpoints in the functions works better, at least on x86, since
it gives a cleaner debugger entry with no buggy printf in it. Locking
hacks for debugger mode then allow the console i/o to sort of work.
Bruce
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?20140504182755.K1388>