kern/56965: panic messages are sometimes garbled in syzkaller

[campbell+netbsd%mumble.net@localhost]

>Number:         56965
>Category:       kern
>Synopsis:       panic messages are sometimes garbled in syzkaller
>Confidential:   no
>Severity:       serious
>Priority:       medium
>Responsible:    kern-bug-people
>State:          open
>Class:          sw-bug
>Submitter-Id:   net
>Arrival-Date:   Thu Aug 11 12:35:01 +0000 2022
>Originator:     Taylor R Campbell
>Release:        current
>Organization:
La Fondation NètBSD
>Environment:
not sure
>Description:
Panic messages are sometimes garbled in syzkaller reports, such as this one:

[ 388.47pmap58845] panic: _get_physpage: out of memory

https://syzkaller.appspot.com/bug?id=5458c4ca59f15645a6a7a035a3399b7b1cb18714

Somehow part of the message `pmap_get_physpage: out of memory' has appeared in the middle of the dmesg timestamp, and _before_ the text `panic: ', even though the logic in subr_prf.c is serialized by a mutex and prints `panic: ' first:

    265 	kprintf_lock();
    266 	kprintf_internal("panic: ", TOLOG|TOCONS, NULL, NULL);
    267 	if (panicstr == NULL) {
    268 		/* first time in panic - store fmt first for precaution */
    269 		panicstr = fmt;
    270 
    271 		vsnprintf(scratchstr, sizeof(scratchstr), fmt, ap);
    272 		kprintf_internal("%s", TOLOG|TOCONS, NULL, NULL, scratchstr);
    273 		panicstr = scratchstr;
    274 	} else {
    275 		kprintf(fmt, TOLOG|TOCONS, NULL, NULL, ap);
    276 	}
    277 	kprintf_internal("\n", TOLOG|TOCONS, NULL, NULL);
    278 	kprintf_unlock();

https://nxr.netbsd.org/xref/src/sys/kern/subr_prf.c?r=1.188#265
>How-To-Repeat:
whatever syzbot does -- kernel config for example above:

include "arch/amd64/conf/GENERIC"

options		DEBUG
options		LOCKDEBUG

makeoptions	KMSAN=1
options		KMSAN
no options	SVS
no options	MODULAR
no options	MODULAR_DEFAULT_AUTOLOAD
options		POOL_NOCACHE
options		KMSAN_PANIC

makeoptions	KCOV=1
options		KCOV

options		FAULT

pseudo-device	vhci
usb*	at vhci?
>Fix:
Yes, please!