> Date: Mon, 9 Apr 2018 13:51:34 +0200
> From: Martin Pieuchot <m...@openbsd.org>
>
> Diff below avoids a lock ordering issue between the SCHED_LOCK() and
> printf(9)'s mutex. This problem has been reported multiple times in
> drm(4) code where debug printfs are placed between sleep_setup() and
> sleep_finish().
>
> The problem is easily fixed. logwakeup() must not be called while
> holding the mutex. This function can end up in wakeup_n() which will
> grab the SCHED_LOCK().
>
> While here ensure that the mutex is always when TOCONS is specified.
> This was not the case in the error path of log(9) and addlog(9).
>
> Ok?
That makes a lot of sense; thanks.
ok kettenis@
> Index: kern/subr_prf.c
> ===================================================================
> RCS file: /cvs/src/sys/kern/subr_prf.c,v
> retrieving revision 1.94
> diff -u -p -r1.94 subr_prf.c
> --- kern/subr_prf.c 20 Mar 2018 15:45:32 -0000 1.94
> +++ kern/subr_prf.c 9 Apr 2018 11:35:11 -0000
> @@ -89,8 +89,7 @@
> int kprintf(const char *, int, void *, char *, va_list);
> void kputchar(int, int, struct tty *);
>
> -struct mutex kprintf_mutex =
> - MUTEX_INITIALIZER_FLAGS(IPL_HIGH, "kprintf", MTX_NOWITNESS);
> +struct mutex kprintf_mutex = MUTEX_INITIALIZER(IPL_HIGH);
>
> /*
> * globals
> @@ -264,7 +263,9 @@ log(int level, const char *fmt, ...)
> splx(s);
> if (!log_open) {
> va_start(ap, fmt);
> + mtx_enter(&kprintf_mutex);
> kprintf(fmt, TOCONS, NULL, NULL, ap);
> + mtx_leave(&kprintf_mutex);
> va_end(ap);
> }
> logwakeup(); /* wake up anyone waiting for log msgs */
> @@ -304,7 +305,9 @@ addlog(const char *fmt, ...)
> splx(s);
> if (!log_open) {
> va_start(ap, fmt);
> + mtx_enter(&kprintf_mutex);
> kprintf(fmt, TOCONS, NULL, NULL, ap);
> + mtx_leave(&kprintf_mutex);
> va_end(ap);
> }
> logwakeup();
> @@ -502,15 +505,15 @@ printf(const char *fmt, ...)
> va_list ap;
> int retval;
>
> - mtx_enter(&kprintf_mutex);
>
> va_start(ap, fmt);
> + mtx_enter(&kprintf_mutex);
> retval = kprintf(fmt, TOCONS | TOLOG, NULL, NULL, ap);
> + mtx_leave(&kprintf_mutex);
> va_end(ap);
> if (!panicstr)
> logwakeup();
>
> - mtx_leave(&kprintf_mutex);
>
> return(retval);
> }
> @@ -526,12 +529,11 @@ vprintf(const char *fmt, va_list ap)
> int retval;
>
> mtx_enter(&kprintf_mutex);
> -
> retval = kprintf(fmt, TOCONS | TOLOG, NULL, NULL, ap);
> + mtx_leave(&kprintf_mutex);
> if (!panicstr)
> logwakeup();
>
> - mtx_leave(&kprintf_mutex);
>
> return (retval);
> }
> @@ -686,6 +688,9 @@ kprintf(const char *fmt0, int oflags, vo
> char *xdigs = NULL; /* digits for [xX] conversion */
> char buf[KPRINTF_BUFSIZE]; /* space for %c, %[diouxX] */
> char *tailp = NULL; /* tail pointer for snprintf */
> +
> + if (oflags & TOCONS)
> + MUTEX_ASSERT_LOCKED(&kprintf_mutex);
>
> if ((oflags & TOBUFONLY) && (vp != NULL))
> tailp = *(char **)vp;
>
>
