Hi. Last night I upgraded to the most recent -current source and
rebuilt everything, and decided on building the kernel to try the new
SCHED_ULE scheduler (I had been using SCHED_4BSD before). Alas, the
experiment did not go well; every time I booted the machine, I got a
panic just as the system was about to put up the login prompt.
Switching the kernel config back to SCHED_4BSD and building a kernel
with the same (last night's) sources gave me a working kernel. This
is on a dual-processor PII/400 box. Below I list what I've got from a
kernel coredump of the SCHED_ULE kernel; I've added my comments on the gdb
listing preceded by "#" signs.
ichotolot# gdb -k ./kernel.debug ./vmcore.45
GNU gdb 5.2.1 (FreeBSD)
Copyright 2002 Free Software Foundation, Inc.
GDB is free software, covered by the GNU General Public License, and you are
welcome to change it and/or distribute copies of it under certain conditions.
Type "show copying" to see the conditions.
There is absolutely no warranty for GDB. Type "show warranty" for details.
This GDB was configured as "i386-undermydesk-freebsd"...
panic: page fault
panic messages:
---
Fatal trap 12: page fault while in kernel mode
cpuid = 1; lapic.id = 01000000
fault virtual address = 0x38
fault code = supervisor read, page not present
instruction pointer = 0x8:0xc036835d
stack pointer = 0x10:0xe1cfbbbc
frame pointer = 0x10:0xe1cfbbcc
code segment = base 0x0, limit 0xfffff, type 0x1b
= DPL 0, pres 1, def32 1, gran 1
processor eflags = interrupt enabled, resume, IOPL = 0
current process = 649 (squid)
trap number = 12
panic: page fault
cpuid = 1; lapic.id = 01000000
boot() called on cpu#1
syncing disks, buffers remaining... panic: absolutely cannot call smp_ipi_shootdown
with interrupts already disabled
cpuid = 1; lapic.id = 01000000
boot() called on cpu#1
Uptime: 1m12s
Dumping 638 MB
16 32 48 64 80 96 112 128 144 160 176 192 208 224 240 256 272 288 304 320 336 352 368
384 400 416 432 448 464 480 496 512 528 544 560 576 592 608 624
---
Reading symbols from
/usr/src/sys/i386/compile/ICHOTOLOTSMP/modules/usr/src/sys/modules/acpi/acpi.ko.debug...done.
Loaded symbols for
/usr/src/sys/i386/compile/ICHOTOLOTSMP/modules/usr/src/sys/modules/acpi/acpi.ko.debug
Reading symbols from
/usr/src/sys/i386/compile/ICHOTOLOTSMP/modules/usr/src/sys/modules/linprocfs/linprocfs.ko.debug...done.
Loaded symbols for
/usr/src/sys/i386/compile/ICHOTOLOTSMP/modules/usr/src/sys/modules/linprocfs/linprocfs.ko.debug
Reading symbols from
/usr/src/sys/i386/compile/ICHOTOLOTSMP/modules/usr/src/sys/modules/linux/linux.ko.debug...done.
Loaded symbols for
/usr/src/sys/i386/compile/ICHOTOLOTSMP/modules/usr/src/sys/modules/linux/linux.ko.debug
Reading symbols from /boot/kernel/green_saver.ko...done.
Loaded symbols for /boot/kernel/green_saver.ko
#0 doadump () at ../../../kern/kern_shutdown.c:240
240 dumping++;
(kgdb) bt
#0 doadump () at ../../../kern/kern_shutdown.c:240
#1 0xc03547c0 in boot (howto=260) at ../../../kern/kern_shutdown.c:372
#2 0xc0354ba6 in panic () at ../../../kern/kern_shutdown.c:550
#3 0xc050f9db in smp_tlb_shootdown (vector=0, addr1=0, addr2=0)
at ../../../i386/i386/mp_machdep.c:2387
#4 0xc050fc79 in smp_invlpg_range (addr1=0, addr2=0)
at ../../../i386/i386/mp_machdep.c:2519
#5 0xc0511df8 in pmap_invalidate_range (pmap=0xc06dc620, sva=3568271360,
eva=1) at ../../../i386/i386/pmap.c:719
#6 0xc0512118 in pmap_qenter (sva=3568271360, m=0xe1cfb8c0, count=-1)
at ../../../i386/i386/pmap.c:943
#7 0xc03a0448 in vm_hold_load_pages (bp=0xd199d440, from=3568271360,
to=3568279552) at ../../../kern/vfs_bio.c:3574
#8 0xc039ea5c in allocbuf (bp=0xd199d440, size=6144)
at ../../../kern/vfs_bio.c:2752
#9 0xc039e6fe in geteblk (size=6144) at ../../../kern/vfs_bio.c:2634
#10 0xc039b210 in bwrite (bp=0xd188b8e0) at ../../../kern/vfs_bio.c:818
#11 0xc039bc6c in bawrite (bp=0x0) at ../../../kern/vfs_bio.c:1153
#12 0xc03a4860 in vop_stdfsync (ap=0xe1cfba14)
at ../../../kern/vfs_default.c:742
#13 0xc031ba10 in spec_fsync (ap=0xe1cfba14)
at ../../../fs/specfs/spec_vnops.c:417
#14 0xc031ae38 in spec_vnoperate (ap=0x0)
at ../../../fs/specfs/spec_vnops.c:122
#15 0xc04ad2d7 in ffs_sync (mp=0xc5336400, waitfor=2, cred=0xc1c27e80,
td=0xc0669ec0) at vnode_if.h:624
#16 0xc03b0b1b in sync (td=0xc0669ec0, uap=0x0)
at ../../../kern/vfs_syscalls.c:142
#17 0xc03542e2 in boot (howto=256) at ../../../kern/kern_shutdown.c:281
#18 0xc0354ba6 in panic () at ../../../kern/kern_shutdown.c:550
#19 0xc0517292 in trap_fatal (frame=0xe1cfbb7c, eva=0)
at ../../../i386/i386/trap.c:836
#20 0xc0516863 in trap (frame=
{tf_fs = -1067057128, tf_es = 16, tf_ds = -1067974640, tf_edi = -982159056,
tf_esi = -1066987296, tf_ebp = -506479668, tf_isp = -506479704, tf_ebx = 0, tf_edx =
2, tf_ecx = 1, tf_eax = 0, tf_trapno = 12, tf_err = 0, tf_eip = -1070169251, tf_cs =
8, tf_eflags = 66178, tf_esp = -1066987296, tf_ss = 0})
at ../../../i386/i386/trap.c:256
#21 0xc04ff988 in calltrap () at {standard input}:97
#22 0xc036947b in sched_choose () at ../../../kern/sched_ule.c:1164
#23 0xc035a636 in choosethread () at ../../../kern/kern_switch.c:140
#24 0xc035c340 in mi_switch () at ../../../kern/kern_synch.c:524
#25 0xc034b686 in _mtx_lock_sleep (m=0xc066e680, opts=0,
file=0xc058251d "../../../kern/kern_descrip.c", line=826)
at ../../../kern/kern_mutex.c:641
#26 0xc034b0f8 in _mtx_lock_flags (m=0xc066e680, opts=0,
file=0xc058251d "../../../kern/kern_descrip.c", line=826)
at ../../../kern/kern_mutex.c:331
#27 0xc0335e11 in close (td=0xc5757130, uap=0x0)
at ../../../kern/kern_descrip.c:826
#28 0xc05175ee in syscall (frame=
{tf_fs = 47, tf_es = 47, tf_ds = 47, tf_edi = -1077936744, tf_esi = 0, tf_ebp =
-1077936840, tf_isp = -506479244, tf_ebx = 689, tf_edx = -1, tf_ecx = 9, tf_eax = 6,
tf_trapno = 12, tf_err = 2, tf_eip = 672626595, tf_cs = 31, tf_eflags = 663, tf_esp =
-1077936900, tf_ss = 47}) at ../../../i386/i386/trap.c:1023
#29 0xc04ff9dd in Xint0x80_syscall () at {standard input}:139
---Can't read userspace from dump, or kernel process---
# The initial panic seems to be around frame 22, so let's go there.
(kgdb) fr 22
#22 0xc036947b in sched_choose () at ../../../kern/sched_ule.c:1164
1164 kseq_move(kseq, PCPU_GET(cpuid));
(kgdb) p kseq
$1 = (struct kseq *) 0x0
(kgdb) l 1160
1155 */
1156 if ((kseq = kseq_load_highest()) == NULL)
1157 return (NULL);
1158
1159 /*
1160 * Remove this kse from this kseq and runq and then requeue
1161 * on the current processor. Then we will dequeue it
1162 * normally above.
1163 */
1164 kseq_move(kseq, PCPU_GET(cpuid));
# Hmm, that's odd. You'd think that if kseq returned by kseq_load_highest()
# was null, line 1157 would have returned and we'd never hit line 1164.
# Weird. Could be gdb is just being confused here, though. Hard to say.
# Anyway, on further inspection, it seems the fatal trap wasn't in
# sched_choose() at all, but elsewhere; look at the eip in the trap frame:
(kgdb) fr 20
#20 0xc0516863 in trap (frame=
{tf_fs = -1067057128, tf_es = 16, tf_ds = -1067974640, tf_edi = -982159056,
tf_esi = -1066987296, tf_ebp = -506479668, tf_isp = -506479704, tf_ebx = 0, tf_edx =
2, tf_ecx = 1, tf_eax = 0, tf_trapno = 12, tf_err = 0, tf_eip = -1070169251, tf_cs =
8, tf_eflags = 66178, tf_esp = -1066987296, tf_ss = 0})
at ../../../i386/i386/trap.c:256
256 trap_fatal(&frame, eva);
(kgdb) p/x frame.tf_eip
$2 = 0xc036835d
(kgdb) disass 0xc036835d
Dump of assembler code for function kseq_move:
0xc0368340 <kseq_move>: push %ebp
0xc0368341 <kseq_move+1>: mov %esp,%ebp
0xc0368343 <kseq_move+3>: sub $0x10,%esp
0xc0368346 <kseq_move+6>: mov %ebx,0xfffffff8(%ebp)
0xc0368349 <kseq_move+9>: mov %esi,0xfffffffc(%ebp)
0xc036834c <kseq_move+12>: mov 0x8(%ebp),%esi
0xc036834f <kseq_move+15>: mov %esi,(%esp,1)
0xc0368352 <kseq_move+18>: call 0xc03683a0 <kseq_choose>
0xc0368357 <kseq_move+23>: mov %eax,%ebx
0xc0368359 <kseq_move+25>: mov %eax,0x4(%esp,1)
0xc036835d <kseq_move+29>: mov 0x38(%eax),%eax
0xc0368360 <kseq_move+32>: mov 0x4(%eax),%eax
0xc0368363 <kseq_move+35>: mov %eax,(%esp,1)
0xc0368366 <kseq_move+38>: call 0xc035ac50 <runq_remove>
0xc036836b <kseq_move+43>: movl $0x4,0x30(%ebx)
0xc0368372 <kseq_move+50>: mov %ebx,0x4(%esp,1)
0xc0368376 <kseq_move+54>: mov %esi,(%esp,1)
0xc0368379 <kseq_move+57>: call 0xc0367f30 <kseq_rem>
0xc036837e <kseq_move+62>: mov 0x38(%ebx),%edx
0xc0368381 <kseq_move+65>: mov 0xc(%ebp),%eax
0xc0368384 <kseq_move+68>: mov %al,0x14(%edx)
0xc0368387 <kseq_move+71>: mov %ebx,(%esp,1)
0xc036838a <kseq_move+74>: call 0xc0369490 <sched_add>
0xc036838f <kseq_move+79>: mov 0xfffffff8(%ebp),%ebx
0xc0368392 <kseq_move+82>: mov 0xfffffffc(%ebp),%esi
0xc0368395 <kseq_move+85>: mov %ebp,%esp
0xc0368397 <kseq_move+87>: pop %ebp
0xc0368398 <kseq_move+88>: ret
End of assembler dump.
# Aha, the trap occured right at this instruction:
# 0xc036835d <kseq_move+29>: mov 0x38(%eax),%eax
# Note from the trapframe that eax was 0 at that point, hence we're
# dereferencing a NULL pointer. Apparently this NULL was returned by
# kseq_choose, and the actual null deref is the "ke->ke_runq" at line 448:
(kgdb) l kseq_move
439 return (NULL);
440 }
441
442 void
443 kseq_move(struct kseq *from, int cpu)
444 {
445 struct kse *ke;
446
447 ke = kseq_choose(from);
448 runq_remove(ke->ke_runq, ke);
(kgdb) l
449 ke->ke_state = KES_THREAD;
450 kseq_rem(from, ke);
451
452 ke->ke_cpu = cpu;
453 sched_add(ke);
454 }
455 #endif
456
457 struct kse *
458 kseq_choose(struct kseq *kseq)
(kgdb) q
ichotolot#
So that's what I found. Any suggestions on how to track this down further?
_______________________________________________
[EMAIL PROTECTED] mailing list
http://lists.freebsd.org/mailman/listinfo/freebsd-current
To unsubscribe, send any mail to "[EMAIL PROTECTED]"
