Date: Tue, 6 Nov 2012 19:01:49 +1100 (EST) From: Bruce Evans <brde@optusnet.com.au> To: Hans Petter Selasky <hselasky@FreeBSD.org> Cc: svn-src-head@FreeBSD.org, svn-src-all@FreeBSD.org, src-committers@FreeBSD.org Subject: Re: svn commit: r242619 - in head/sys: dev/usb/serial sys Message-ID: <20121106161421.F4852@besplex.bde.org> In-Reply-To: <201211051750.qA5Hof8U049831@svn.freebsd.org> References: <201211051750.qA5Hof8U049831@svn.freebsd.org>
next in thread | previous in thread | raw e-mail | index | archive | help
This message is in MIME format. The first part should be readable text,
while the remaining parts are likely unreadable without MIME-aware tools.
--0-479278205-1352188909=:4852
Content-Type: TEXT/PLAIN; charset=X-UNKNOWN; format=flowed
Content-Transfer-Encoding: QUOTED-PRINTABLE
On Mon, 5 Nov 2012, Hans Petter Selasky wrote:
> Log:
> Add a jitter buffer in the common USB serial driver code which
> temporarily stores characters if the TTY buffer is full when
> used a as a console. This can happen when a console is suspended.
(Non-broken) console drivers cannot block or even use normal locking
(except possibly mtx_trylock()). That's for the low-level part.
> Also properly do the flow stop signalling when this happens and
> flow start when the condition changes back to normal again.
For the high-level part, (non-broken) console drivers have hardware
flow control locked off in their lock state flags. It may be
unlocked by users with write access to the lock state device, but
then it is the user's fault for breaking console i/o by blocking it.
This might be fixed in the following:
% diff -c2 ./dev/usb/serial/usb_serial.c~ ./dev/usb/serial/usb_serial.c
% *** ./dev/usb/serial/usb_serial.c~=09Tue Apr 10 01:48:34 2012
% --- ./dev/usb/serial/usb_serial.c=09Tue Apr 10 01:48:57 2012
% ***************
% *** 331,336 ****
%=20
% =09tp =3D tty_alloc_mutex(&ucom_class, sc, sc->sc_mtx);
% - =09if (tp =3D=3D NULL)
% - =09=09return (ENOMEM);
%=20
% =09/* Check if the client has a custom TTY name */
% --- 331,334 ----
% ***************
% *** 369,376 ****
% =09=09ucom_cons_softc =3D sc;
%=20
% ! =09=09memset(&t, 0, sizeof(t));
% ! =09=09t.c_ispeed =3D ucom_cons_baud;
% ! =09=09t.c_ospeed =3D t.c_ispeed;
% =09=09t.c_cflag =3D CS8;
%=20
% =09=09mtx_lock(ucom_cons_softc->sc_mtx);
% --- 367,375 ----
% =09=09ucom_cons_softc =3D sc;
%=20
% ! =09=09tty_init_console(tp, ucom_cons_baud);
% ! =09=09t =3D tp->t_termios_init_in;
% ! #ifdef GARBAGE /* maybe usb can't do all modes, but CS8 by itself is in=
valid */
% =09=09t.c_cflag =3D CS8;
% + #endif
%=20
% =09=09mtx_lock(ucom_cons_softc->sc_mtx);
% ***************
% *** 1080,1084 ****
%=20
% =09=09/* XXX the TTY layer should call "open()" first! */
% !=20
% =09=09error =3D ucom_open(tp);
% =09=09if (error) {
% --- 1079,1087 ----
%=20
% =09=09/* XXX the TTY layer should call "open()" first! */
% ! =09=09/*
% ! =09=09 * Not quite; its ordering is partly backwards, but some
% ! =09=09 * parameters must be set early in ttydev_open(), possibly
% ! =09=09 * before calling ttydevsw_open().
% ! =09=09 */
% =09=09error =3D ucom_open(tp);
% =09=09if (error) {
% ***************
% *** 1091,1094 ****
% --- 1094,1098 ----
% =09/* Check requested parameters. */
% =09if (t->c_ispeed && (t->c_ispeed !=3D t->c_ospeed)) {
% + =09=09/* XXX c_ospeed =3D=3D 0 is perfectly valid. */
% =09=09DPRINTF("mismatch ispeed and ospeed\n");
% =09=09error =3D EINVAL;
Without the tty_init_console() call, the special lock state initialization
for consoles can't work.
This is part of a larger patch set for console initialization. Most
drivers aren't missing the tty_init_console() call, but many don't
pass the speed, so the speed isn't locked properly. The upper layers
are broken too.
The idea of a replay buffer for fixing console drivers is good, but
quite complicated. I use one in the following to fix syscons a little.
It must use atomic ops quite carefully. Note that it is for an old
version of FreeBSD. syscons is also missing the tty_init_console()
call, but the old version of FreeBSD is too old to have tty_init_console()
so the patch is missing the fix for that.
% diff -c2 ./dev/syscons/scmouse.c~ ./dev/syscons/scmouse.c
% *** ./dev/syscons/scmouse.c~=09Fri May 25 15:01:31 2007
% --- ./dev/syscons/scmouse.c=09Wed Feb 22 21:21:47 2012
% ***************
% *** 35,38 ****
% --- 35,39 ----
% #include <sys/consio.h>
% #include <sys/fbio.h>
% + #include <sys/kdb.h>
% #include <sys/limits.h>
% #include <sys/lock.h>
For kdb_active in some macros in syscons.h.
% diff -c2 ./dev/syscons/syscons.c~ ./dev/syscons/syscons.c
% *** ./dev/syscons/syscons.c~=09Thu Aug 14 15:47:30 2008
% --- ./dev/syscons/syscons.c=09Fri Mar 2 08:44:37 2012
% ***************
% *** 1,2 ****
% --- 1,6 ----
% + int bde_kill_bde_wait =3D 1;
% + int bde_wait_delay =3D 10 * 1000;
% + int bde_wait_verbose =3D 0;
% +=20
% /*-
% * Copyright (c) 1992-1998 S=F8ren Schmidt
Debugging cruft.
% ***************
% *** 70,73 ****
% --- 74,78 ----
% #include <machine/frame.h>
% #endif
% + #include <machine/stdarg.h>
%=20
% #include <dev/kbd/kbdreg.h>
% ***************
% *** 166,170 ****
% #define ISTTYOPEN(tp)=09((tp) && ((tp)->t_state & TS_ISOPEN))
%=20
% ! static=09int=09=09debugger;
%=20
% /* prototypes */
% --- 171,175 ----
% #define ISTTYOPEN(tp)=09((tp) && ((tp)->t_state & TS_ISOPEN))
%=20
% ! static=09int=09=09debugger =3D 1;
%=20
% /* prototypes */
Unbreak the `debugger' flag a little. This flag used to be set on
debugger entry to avoid bugs like calling wakeup() for screen savers
in debugger mode. This flag is still checked, but the console call
for setting it was axed. Now there is a different console call (with
differently wrong semantics) for setting it, but it is still not set
there. But this version is too old to have the new console call,
though old enough to not have the axed one. So hack on the variable
by setting it here. This doesn't cause too many problems in non-debugger
mode. The current version of this patch doesn't have the replay buffer,
but handles this variable as well as possible by setting it in the
new console call.
% ***************
% *** 246,249 ****
% --- 251,315 ----
% };
%=20
% + static char bde_putc_log[0x40000];
% + static int bde_putc_logindex;
% + static int bde_putc_scrindex;
This is the replay buffer.
% +=20
% + static void
% + bde_putc(int c)
% + {
% + =09static u_short attrs[2] =3D { FG_YELLOW << 8, FG_LIGHTRED << 8 };
% + =09static u_short * const scrptr =3D (short *)0xc00b8000;
% + =09int attr, ind;
% +=20
% + =09attr =3D attrs[PCPU_GET(cpuid) % 2];
% + =09do
% + =09=09ind =3D bde_putc_scrindex;
% + =09while (atomic_cmpset_rel_int(&bde_putc_scrindex, ind, ind + 1) =3D=
=3D 0);
% + =09scrptr[5 * 80 + (ind % (15 * 80))] =3D attr | (c & 0xff);
% + =09bde_putc_log[ind % sizeof(bde_putc_log)] =3D c;
% + }
When normal output is blocked, it is not completely blocked but is
always atomically splatted into the frame buffer, which is assumed to
exist and to be CGA/EGA/VGA 80x25 text mode. This makes a mess of
the frame buffer, but it is readable enough to debug deadlocks where
normal output is never unblocked. The special output in the frame
buffer is completely overwritten by screen updates if normal output
is unblocked. It is replayed as normal output then.
% +=20
% + static void
% + bde_puts(const char *s)
% + {
% + =09while (*s !=3D '\0')
% + =09=09bde_putc(*s++);
% + }
Convenience function. It has no formatting. Linefeeds get put into the
frame buffer as hard 0xa characters.
% +=20
% + static void
% + bde_wait(void)
% + {
% + =09int timeout;
% +=20
% + =09if (bde_kill_bde_wait)
% + =09=09return;
% + =09if (!bde_wait_verbose) {
% + =09=09DELAY(bde_wait_delay);
% + =09=09return;
% + =09}
% + =09bde_puts("hit any key to abort wait of 300 seconds...");
% + =09timeout =3D 300 * 1000;
% + =09do {
% + =09=09if (cncheckc() !=3D -1)
% + =09=09=09break;
% + =09=09DELAY(1000);
% + =09} while (--timeout !=3D 0);
% + =09bde_puts("done");
% + }
A delay is sometimes need to see the special output in its special place,
to watch deadlocks building up.
% +=20
% + void bde_printf_emerg(const char *fmt, ...);
% + void
% + bde_printf_emerg(const char *fmt, ...)
% + {
% + =09va_list ap;
% + =09char buf[256];
% +=20
% + =09va_start(ap, fmt);
% + =09vsnprintf(buf, sizeof(buf) - 3, fmt, ap);
% + =09// strcat(buf, "!E!");
% + =09bde_puts(buf);
% + =09// bde_wait();
% + }
% +=20
% int
% sc_probe_unit(int unit, int flags)
This is called in places where printf() is likely to deadlock. Printf()
and the message buffer and top-level console output have been broken
using locking in code that cannot use normal locks. My version avoids
some of these deadlocks essentially by blowing the locks open after a
delay. The above can be used to force some output without waiting for
the full top-level delay, with the output normally containing info about
the deadlock state and it being blown open.
% ***************
% *** 1463,1467 ****
% --- 1529,1535 ----
% =09 len =3D q_to_b(rbp, buf, PCBURST);
% =09 splx(s);
% + =09 mtx_lock_spin(&scp->scr_lock);
% =09 sc_puts(scp, buf, len);
% + =09 mtx_unlock_spin(&scp->scr_lock);
% =09 s =3D spltty();
% =09}
Locking like this tends to deadlock, but syscons uses it elsewhere and
IIRC I added it here so that I could assert that lock is always held
in sc_puts().
The easiest way for this to deadlock is for the system to be UP and
be doing normal (non-console) syscons output via sc_puts() (perhaps
not from here) and for a fast interrupt or NMI handler to call printf().
It is a bug for them to call printf(), but printf() might be needed
to debug them, and at least NMI handlers on at least x86 have always
had this bug. printf()s are also useful in trap(), and most traps are
not prevented by spinlocking.
OTOH, syscons output is highly non-reentrant, so some locking is needed.
The printf() from NMI will just have to block while the lock is held.
But only normal output needs to block. A less-highly non-reentrant
console driver would merge the special output into the normal output
better. One way to do this is to have separate vty for this and to
atomically switch to and from this vty for all low-level console output.
This has the advantage and the disadvantage that alll low-level console
output is kept completely separate. It is easier to read but harder
to see when it is separate.
% ***************
% *** 1534,1541 ****
% struct tty *tp;
% #endif /* !SC_NO_HISTORY */
% ! int s;
%=20
% /* assert(sc_console !=3D NULL) */
%=20
% #ifndef SC_NO_HISTORY
% if (scp =3D=3D scp->sc->cur_scp && scp->status & SLKED) {
% --- 1602,1634 ----
% struct tty *tp;
% #endif /* !SC_NO_HISTORY */
% ! int need_unlock, s;
%=20
% /* assert(sc_console !=3D NULL) */
%=20
% + /*
% + * syscons has extremely confused and dysfunctional locking, with
% + * not just 1, but 2 deadlocking spin mutexes to work around here,
% + * plus a tty lock which doesn't work automatically since these
% + * (tty lock only in -current)
% + * spin mutexes provide some necessary additional locking in a bad
% + * way, plus old spltty() locking which has no effect except to
% + * mark some of the places that may be missing mutex locking.
% + *
% + * Yikes, mtx_trylock() is not implemented for spin mutexes.
% + */
% + if (!cold &&
% + =09(mtx_owned(&scp->sc->video_mtx) || mtx_owned(&scp->scr_lock))) {
% + =09bde_putc(c);
% + =09bde_wait();
% + =09return;
% + }
This just detects if the console is locked and does only the special
output when it is.
% + need_unlock =3D 0;
% + if (!cold && !kdb_active) {
% + =09/* XXX, races from no trylock, problems with later vidlocks... */
% + =09mtx_lock_spin(&scp->scr_lock);
% + =09SC_VIDEO_LOCK(scp->sc);
% + =09need_unlock =3D 1;
% + }
% +
This locks the console for the case of direct low-level console output.
Without mtx_trylock(), it is racy.
% #ifndef SC_NO_HISTORY
% if (scp =3D=3D scp->sc->cur_scp && scp->status & SLKED) {
% ***************
% *** 1558,1561 ****
% --- 1651,1660 ----
% if (kernel_console_ts !=3D NULL)
% =09scp->ts =3D kernel_console_ts;
% +=20
% + /* Replay log. */
% + while (bde_putc_logindex !=3D atomic_load_acq_int(&bde_putc_scrinde=
x))
% + =09sc_puts(scp, &bde_putc_log[bde_putc_logindex++ % sizeof(bde_putc_log=
)],
% + =09=091);
% +=20
% buf[0] =3D c;
% sc_puts(scp, buf, 1);
Log replay is very easy, even with sufficient atomicity.
% ***************
% *** 1565,1568 ****
% --- 1664,1671 ----
% sccnupdate(scp);
% splx(s);
% + if (need_unlock) {
% + =09SC_VIDEO_UNLOCK(scp->sc);
% + =09mtx_unlock_spin(&scp->scr_lock);
% + }
% }
%
This unlocks the console for the case of direct low-level console output.
% ***************
% *** 2506,2511 ****
% sc_puts(scr_stat *scp, u_char *buf, int len)
% {
% - int need_unlock =3D 0;
% -=20
% #ifdef DEV_SPLASH
% /* make screensaver happy */
% --- 2609,2612 ----
% ***************
% *** 2514,2527 ****
% #endif
%=20
% ! if (scp->tsw) {
% ! =09if (!kdb_active && !mtx_owned(&scp->scr_lock)) {
% ! =09=09need_unlock =3D 1;
% ! =09=09mtx_lock_spin(&scp->scr_lock);
% ! =09}
% =09(*scp->tsw->te_puts)(scp, buf, len);
% - =09if (need_unlock)
% - =09=09mtx_unlock_spin(&scp->scr_lock);
% - }
% -=20
% if (scp->sc->delayed_next_scr)
% =09sc_switch_scr(scp->sc, scp->sc->delayed_next_scr - 1);
% --- 2615,2620 ----
% #endif
%=20
% ! if (scp->tsw)
% =09(*scp->tsw->te_puts)(scp, buf, len);
% if (scp->sc->delayed_next_scr)
% =09sc_switch_scr(scp->sc, scp->sc->delayed_next_scr - 1);
Here (at the start of scr_puts()) is too late to acquire the necessary
locks. Deadlock would have to be handled... Now, scr_lock is supposed
to be acquired by callers, and deadlocks there are supposed not to
happen.
This also fixes some style bugs -- the kdb_active code was copied from
somwhere with a more normal style and it has wrong indentation for
syscons.
% diff -c2 ./dev/syscons/syscons.h~ ./dev/syscons/syscons.h
% *** ./dev/syscons/syscons.h~=09Sat Mar 8 23:59:07 2008
% --- ./dev/syscons/syscons.h=09Fri Mar 2 08:44:25 2012
% ***************
% *** 35,40 ****
% #define=09_DEV_SYSCONS_SYSCONS_H_
%=20
% ! #include <sys/lock.h>
% ! #include <sys/mutex.h>
%=20
% /* machine-dependent part of the header */
% --- 35,40 ----
% #define=09_DEV_SYSCONS_SYSCONS_H_
%=20
% ! #include <sys/_lock.h>
% ! #include <sys/_mutex.h>
%=20
% /* machine-dependent part of the header */
Namespace de-pollution.
% ***************
% *** 517,520 ****
% --- 517,546 ----
% #define ISSIGVALID(sig)=09((sig) > 0 && (sig) < NSIG)
%=20
% + /*
% + * XXX this must (bogusly) be recursive, else we get instant reboots
% + * (instead of deadlock like we would expect) when the ipi NMI
% + * handler calls printf(). Note that this locking is completely
% + * wrong. Before it, the videoio_in_progress counter was used
% + * to avoid some harmful things including recursion which may be
% + * the start of more harmful things. Now the locking just allows
% + * recursion and any harmful things reachable by it. The locking
% + * should at least use trylock and avoid recursion, as before.
% + *
% + * Also, this locking is mostly unrelated to its claimed purpose of
% + * protecting printf() output. Recursion can happen for that, and
% + * then the locking provides no protection. Our own console grabbing
% + * now handles this better anyway. Grabbing doesn't prevent recursion,
% + * but printf() now has some serialization that limits recursion.
% + * For user writes versus each other, we had Giant locking of everythin=
g
% + * at the time that this locking was added. Now we hopefully have tty
% + * locking instead, but it is not so clear that we have it for everythi=
ng
% + * (I think we have it for writes but not for all parts of reads).
% + *
% + * One very broken case remains: debugger output vs everything else:
% + * - in the recursive case, we just allow debugger output, so we have
% + * large races
% + * - int the non-recursive case, we used to deadlock. Now we ignore th=
e
% + * lock, so we have large races in this case too.
% + */
% #define SC_VIDEO_LOCKINIT(sc)=09=09=09=09=09=09\
% =09=09mtx_init(&(sc)->video_mtx, "syscons video lock", NULL,=09\
Previous versions tried to kill this lock and run into the above problems.
There are still 2 spinlocks and now in -current 1 tty-level lock where this
version has only Giant (but IIRC the tty-level lock is still just Giant,
and there are cases during initialization where there is still only Giant
and no tty-level lock for all types of tty drivers (for new-bus parts).
% ***************
% *** 522,531 ****
% #define SC_VIDEO_LOCK(sc)=09=09=09=09=09=09\
% =09=09do {=09=09=09=09=09=09=09\
% ! =09=09=09if (!cold)=09=09=09=09=09\
% =09=09=09=09mtx_lock_spin(&(sc)->video_mtx);=09\
% =09=09} while(0)
% #define SC_VIDEO_UNLOCK(sc)=09=09=09=09=09=09\
% =09=09do {=09=09=09=09=09=09=09\
% ! =09=09=09if (!cold)=09=09=09=09=09\
% =09=09=09=09mtx_unlock_spin(&(sc)->video_mtx);=09\
% =09=09} while(0)
% --- 548,557 ----
% #define SC_VIDEO_LOCK(sc)=09=09=09=09=09=09\
% =09=09do {=09=09=09=09=09=09=09\
% ! =09=09=09if (!cold && !kdb_active)=09=09=09\
% =09=09=09=09mtx_lock_spin(&(sc)->video_mtx);=09\
% =09=09} while(0)
% #define SC_VIDEO_UNLOCK(sc)=09=09=09=09=09=09\
% =09=09do {=09=09=09=09=09=09=09\
% ! =09=09=09if (!cold && !kdb_active)=09=09=09\
% =09=09=09=09mtx_unlock_spin(&(sc)->video_mtx);=09\
% =09=09} while(0)
As in some serial console drivers, ignore our locking when kdb_active.
The special output makes this less necessary. Normal locking calls
while (kdb_active) might deadlock and should cause assertion failures.
-current doesn't do the assertions, and the above anti-deadlock code in
console output turns deadlock into special output that you can seee
and a return to avoid deadlock.
Any console driver can use a replay buffer to avoid deadlocks in the
driver itself and guarantee that the output actually goes out provided
there are no deadlocks in upper layers. But it needs to actually do
the i/o to a readable place without blocking or otherwise delaying or
de-serializing the output for printf() to work properly.
Bruce
--0-479278205-1352188909=:4852--
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?20121106161421.F4852>