Mark Kettenis <[email protected]> writes:

>> From: Dave Voutila <[email protected]>
>> Date: Mon, 29 Nov 2021 07:18:23 -0500
>>
>> Mark Kettenis <[email protected]> writes:
>>
>> >> From: Dave Voutila <[email protected]>
>> >> Date: Sun, 28 Nov 2021 22:51:59 -0500
>> >>
>> >> The last vmm diff I'll be sending tonight...promise! This swaps out
>> >> usage of printf(9) outside the autoconf(4) functions.
>> >>
>> >> The reason for this change is printf(9) could acquire a sleepable
>> >> lock.
>> >
>> > Huh?
>> >
>> > /*
>> >  * printf: print a message to the console and the log
>> >  */
>> > int
>> > printf(const char *fmt, ...)
>> > {
>> >    va_list ap;
>> >    int retval;
>> >
>> >    va_start(ap, fmt);
>> >    mtx_enter(&kprintf_mutex);
>> >    retval = kprintf(fmt, TOCONS | TOLOG, NULL, NULL, ap);
>>
>> The thread I'm pulling on here is longer than kprintf.
>
> Well, my point is that it doesn't matter how long the thread is.  The
> kernel is not supposed to sleep while holding a mutex.  And
> assertwaitok() enforces this.  If that kprintf() ends up sleeping we
> have a serious bug as we call printf(9) from things like interrupt
> context.
>
>> Calling kprintf with TOCONS results in calls to kputchar, which can call
>> tputchar as a result as it can add the TOTTY flag:
>>
>>
>>    305       void
>>    306       kputchar(int c, int flags, struct tty *tp)
>>    307       {
>>    308               extern int msgbufmapped;
>>
>>    309               if (panicstr)
>>    310                       constty = NULL;
>>
>>    311               if ((flags & TOCONS) && tp == NULL && constty != NULL 
>> && !db_active) {
>>    312                       tp = constty;
>>    313                       flags |= TOTTY;
>>    314               }
>>    315               if ((flags & TOTTY) && tp && tputchar(c, tp) < 0 &&
>>    316                   (flags & TOCONS) && tp == constty)
>>    317                       constty = NULL;
>>    318               if ((flags & TOLOG) &&
>>    319                   c != '\0' && c != '\r' && c != 0177 && msgbufmapped)
>>    320                       msgbuf_putchar(msgbufp, c);
>>    321               if ((flags & TOCONS) && (constty == NULL || db_active) 
>> && c != '\0')
>>    322                       (*v_putc)(c);
>>    323       #ifdef DDB
>>    324               if (flags & TODDB)
>>    325                       db_putchar(c);
>>    326       #endif
>>    327       }
>>
>>
>> tputchar() can end up calling ttstart(), which on my system results in
>> calling ptsstart(). Which results in a call to ptsstart(). Then
>> selwakeup() which attempts to grab KERNEL_LOCK.
>
> But that's fine; KERNEL_LOCK does not sleep, it spins.
>

That's what I thought, but I'm going off what witness was telling
me. Maybe my faith is misplaced.

>> >    mtx_leave(&kprintf_mutex);
>> >    va_end(ap);
>> >    if (!panicstr)
>> >            logwakeup();
>> >
>> >    return(retval);
>> > }
>> >
>> > The guts of the the code runs while holding a mutex, which means it
>> > can't sleep.  And logwakeup() doesn't sleep either.
>>
>> witness(4) begs to differ here. /shrug
>
> In what way?

Is mispeaking? This is what I experienced:

  panic: acquiring blockable sleep lock with spinlock or critical section
  held (kernel_lock) &kernel_lock

Full backtraces of two occurrences: https://imgur.com/a/vKIe3k7

-dv

Reply via email to