Re: panic: kmem_malloc(4096): kmem_map too small

On Fri, 13 Jun 2003, John Hay wrote:

> On a 5.1-RELEASE machine I have been able to cause a panic like this:
>
> panic: kmem_malloc(4096): kmem_map too small: 28610560 total allocated
>
> The machine is an old 300MHz Celeron with 64M Ram. I get the panic by
> un-taring a "huge" .tgz file onto a vinum partition which is on a scsi
> disk behind a Adaptec 2940 controller. The "huge" tar file contains a
> ...
> Here follow the output of vinum list and then the panic message and
> a gdb traceback. I'm not sure if the traceback is correct. I think
> it only show the second panic.

It shows mainly bugs in the debugging :-[.

> panic: free locked buf

Debugging bug 1:
The above shows a secondary panic, but is supposed to show the primary
panic.  gdb just prints the contents of the kernel panicstr variable,
but the setting of that variable is broken (see below).

> panic messages:
> ---
> panic: kmem_malloc(4096): kmem_map too small: 28610560 total allocated
>
> syncing disks, buffers remaining... panic: free locked buf
> Uptime: 1h47m5s
> (da0:ahc0:0:6:0): SYNCHRONIZE CACHE. CDB: 35 0 0 0 0 0 0 0 0 0
> (da0:ahc0:0:6:0): error code 54
> Dumping 64 MB
> ata0: resetting devices ..
> done
>  16 32 48
> ---

Debugging bug 2:
gdb then prints the contents of the message buffer starting with the
regexp "^(panic:|Fatal trap) ".  It just uses system("dmesg ... | awk ...").
Eeek.  This may start with a panic for a previous boot and print all
messages in the buffer for subsequent boots.  This doesn't happen here.

> Reading symbols from /usr/src/sys/i386/compile/TRY/modules/usr/src/sys/modules/vinum/vinum.ko.debug...done.
> Loaded symbols for /usr/src/sys/i386/compile/TRY/modules/usr/src/sys/modules/vinum/vinum.ko.debug
> #0  doadump () at ../../../kern/kern_shutdown.c:238
> 238		dumping++;
> (kgdb) bt
> #0  doadump () at ../../../kern/kern_shutdown.c:238
> #1  0xc01ab1ca in boot (howto=260) at ../../../kern/kern_shutdown.c:370
> #2  0xc01ab483 in panic () at ../../../kern/kern_shutdown.c:543
> #3  0xc1064926 in freerq (rq=0xc166c4c0)
>     at /usr/src/sys/dev/vinum/vinuminterrupt.c:252
> #4  0xc106482a in complete_rqe (bp=0xc12a6c24)
>     at /usr/src/sys/dev/vinum/vinuminterrupt.c:230
> #5  0xc01eda81 in bufdone (bp=0xc12a6c24) at ../../../kern/vfs_bio.c:3086
> #6  0xc01ed984 in bufdonebio (bp=0x0) at ../../../kern/vfs_bio.c:3034
> #7  0xc01ed7e2 in biodone (bp=0xc12a6c24) at ../../../kern/vfs_bio.c:2961
> #8  0xc017d4be in g_dev_done (bp2=0xc1552120) at ../../../geom/geom_dev.c:391
> #9  0xc01ed7e2 in biodone (bp=0xc1552120) at ../../../kern/vfs_bio.c:2961
> #10 0xc017fc62 in g_io_schedule_up (tp=0xc0607e40)
>     at ../../../geom/geom_io.c:365
> #11 0xc017fe58 in g_up_procbody () at ../../../geom/geom_kern.c:91
> #12 0xc01986ce in fork_exit (callout=0xc017fe30 <g_up_procbody>, arg=0x0,
>     frame=0x0) at ../../../kern/kern_fork.c:768
> (kgdb) quit

Debugging bug 3:
The primary panic occurred in another thread, and we just got here to
sync() for the other thread.  Then we soon paniced with "free locked buf".
Thus there is no trace of the primary panic in this frame and no
secondary or tertiary panics in this frame.  freerq() just paniced in
BUF_LOCKFREE() and the panic didn't try syncing again since it is
"recursive" (not actually recursive since it is in a diferent thread).

You need to look at other threads to see where the primary panic occurred.
panic() doesn't understand that it may be called from more than 1 thread
(it shouldn't be), so it doesn't print any hints its callers.

Debugging bug 1 (continued):
The setting of `panicstr' was broken in rev.1.38:

% void
% panic(const char *fmt, ...)
% {
% 	struct thread *td = curthread;
% 	int bootopt, newpanic;
% 	va_list ap;
% 	static char buf[256];
%
% #ifdef SMP
% ...
% #endif
%
% 	bootopt = RB_AUTOBOOT | RB_DUMP;
% 	newpanic = 0;
% 	if (panicstr)
% 		bootopt |= RB_NOSYNC;
% 	else {
% 		panicstr = fmt;
  		^^^^^^^^^^^^^^

This sets panicstr for the original panic only.

% 		newpanic = 1;
% 	}
%
% 	va_start(ap, fmt);
% 	(void)vsnprintf(buf, sizeof(buf), fmt, ap);
% 	if (panicstr == fmt)
% 		panicstr = buf;
  	        ^^^^^^^^^^^^^^

This gives a more useful setting of panicstr (rev.1.38).  Unfortunately,
it points panicstr at static storage which is clobbered by secondary
panics.

% 	va_end(ap);
% 	printf("panic: %s\n", buf);

Bruce