freebsd stable - Apr 2009 - panic: lockmgr: locking against myself on 7.2-BEA1 (and gmirror dumpdev not working)

Hello.

I have been able to reproduce this panic for a while now, and finally
decided to build in debugging support for my kernel and obtain a
proper panic, backtrace, etc as it's still happening with 7.2-BETA1
(FreeBSD pflog.net 7.2-PRERELEASE FreeBSD 7.2-PRERELEASE #0: Tue Apr
7 16:03:17 EDT 2009
root@pflog.net:/usr/obj/usr/src/sys/PFLOG_DEBUG  amd64).

The way I've found to reproduce this panic is to mount /usr/obj as
tmpfs and repeatedly build world - it generally happens within 30
minutes, but with debugging enabled it took a bit longer to cause it.
Here's the fstab entry for /usr/obj:

tmpfs   /usr/obj        tmpfs   size=2147483648,rw      0       0

Here's the panic on the console when it happened:

panic: lockmgr: locking against myself
cpuid = 2
KDB: enter: panic
[thread pid 61233 tid 100161 ]
Stopped at   kdb_enter_why+0x3d:    movq    $0,0x394136(%rip)
db>

Unfortunately, as mentioned in the subject, I am unable to get a
savecore. After show alllocks and bt, I ran "call doadump", which
appeared to work fine. However, after rebooting, there was no savecore
in /var/crash and running savecore against /dev/mirror/gm1s1b states:

# savecore /var/crash /dev/mirror/gm1s1b
savecore: first and last dump headers disagree on /dev/mirror/gm1s1b
savecore: unsaved dumps found but not saved

If I use savecore -f, I get:

# savecore -f /var/crash /dev/mirror/gm1s1b
savecore: unable to force dump - bad magic
savecore: no dumps found

Which sounds to me like the swap slice's data was already clobbered.

dumpdev appears to be set properly in rc.conf:

dumpdev="/dev/mirror/gm1s1b"
dumpdir="/var/crash"

Here's the gm1 gmirror information, if that's pertinent:

Geom name: gm1
State: COMPLETE
Components: 2
Balance: round-robin
Slice: 4096
Flags: NONE
GenID: 0
SyncID: 1
ID: 3971893092
Providers:
1. Name: mirror/gm1
   Mediasize: 1000204885504 (932G)
   Sectorsize: 512
   Mode: r5w5e6
Consumers:
1. Name: ad4
   Mediasize: 1000204886016 (932G)
   Sectorsize: 512
   Mode: r1w1e1
   State: ACTIVE
   Priority: 0
   Flags: DIRTY
   GenID: 0
   SyncID: 1
   ID: 2996899963
2. Name: ad6
   Mediasize: 1000204886016 (932G)
   Sectorsize: 512
   Mode: r1w1e1
   State: ACTIVE
   Priority: 0
   Flags: DIRTY
   GenID: 0
   SyncID: 1
   ID: 28724068

Here is a transcription of the output from show alllocks and then bt:

show alllocks:

Process 61346 (tsort) thread 0xffffff0008044000 (100084)
exclusive sleep mutex vm page queue mutex r = 0 (0xffffffff80745e00)
locked @ /usr/src/sys/vm/vm_object.c:684
exclusive sleep mutex vm page object (standard object) r = 0
(0xffffff00a5c34798) locked @ /usr/src/sys/vm/vm_object.c:460
exclusive sx user map r = 0 (0xffffff0006ccc0070) locked @
/usr/src/sys/vm/vm_map.c:2425
Process 61226 (sh) thread 0xffffff002ca1aa50 (100318)
exclusive sx user map r = 0 (0xffffff002ca5b070) locked @
/usr/src/sys/vm/vm_map.c:3117
Process 61130 (tsort) thread 0xffffff002c710370 (100270)
exclusive sx user map r = 0 (0xffffff0008049710) locked @
/usr/src/sys/vm/vm_map.c:3117
Process 89194 (sshd) thread 0xffffff002c4356e0 (100229)
exclusive sx so_rcv_sx r = 0 (0xffffff000d8a6100) locked @
/usr/src/sys/kern/uipc_sockbuf.c:148
Process 21453 (sshd) thread 0xffffff0018c336e0 (100307)
exclusive sx so_rcv_sx r = 0 (0xffffff0008c113d0) locked @
/usr/src/sys/kern/uipc_sockbuf.c:148
Process 11200 (pflogd) thread 0xffffff0005eb0000 (100057)
exclusive sx so_rcv_sx r = 0 (0xffffff00080e36a0) locked @
/usr/src/sys/kern/uipc_sockbuf.c:148

and bt:

db> bt
Tracing pid 61233 tid 100161 td 0xffffff00088c0a50
kdb_enter_why() at kdb_enter_why+0x3d
panic() at panic+0x171
_lockmgr() at _lockmgr+0x861
VOP_LOCK1_AVP() at VOP_LOCK1_AVP+0x9b
_vn_lock() at _vn_lock+0x8b
vget() at vget+0x108
vm_object_reference() at vm_object_reference+0xbf
kern_execve() at kern_execve+0x26a
execve() at execve+0x38
syscall() at syscall+0x1d0
Xfast_syscall() at Xfast_syscall+0xab
--- syscall (59, FreeBSD ELF64, execve), rip = 0x80091553c, rsp 0x7fffffffdd28,
rbp = 0x800b07b70 ---

Hopefully this is enough information, as I don't have a dump
obviously. If more information is needed, I'd prefer if I could fix
the gmirror dumpdev issue first so I can have a coredump to use to get
additional information without the tedious transcription from digital
pictures!

Please let me know if anything else is needed, or if there are ideas
for how to fix the dumpdev issue for the gmirror.

Thanks,
Josh

> Unfortunately, as mentioned in the subject, I am unable to get a
> savecore. After show alllocks and bt, I ran "call doadump", which
> appeared to work fine. However, after rebooting, there was no savecore
> in /var/crash and running savecore against /dev/mirror/gm1s1b states:
I was able to reproduce the panic and this time, I booted single user
mode and I was able to manually call savecore to get
/var/crash/vmcore.0

So if there is any additional kgdb output needed, just say the word
and I can get it now.

Curious why /etc/rc.d/savecore didn't work on a normal reboot after
the dump, but that's probably a topic for a separate mail thread.

Thanks,
Josh