GENERIC HEAD from Aug 12 12:55 UTC, vmcore.69
Livelock while testing loopback nfs and snapshots.
GDB: no debug ports present
KDB: debugger backends: ddb
KDB: current backend: ddb
Copyright (c) 1992-2006 The FreeBSD Project.
Copyright (c) 1979, 1980, 1983, 1986, 1988, 1989, 1991, 1992, 1993, 1994
The Regents of the University of California. All rights reserved.
FreeBSD 7.0-CURRENT #1: Sat Aug 12 15:06:41 CEST 2006
pho@crashbox.osted.lan:/usr/src/sys/i386/compile/PHO
WARNING: WITNESS option enabled, expect reduced performance.
Timecounter "i8254" frequency 1193182 Hz quality 0
CPU: Intel(R) XEON(TM) CPU 1.80GHz (1799.80-MHz 686-class CPU)
Origin = "GenuineIntel" Id = 0xf24 Stepping = 4
Features=0x3febfbff<FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CLFLUSH,DTS,ACPI,MMX,FXSR,SSE,SSE2,SS,HTT,TM>
Logical CPUs per core: 2
real memory = 1073676288 (1023 MB)
avail memory = 1033048064 (985 MB)
:
Trying to mount root from ufs:/dev/ad0s1a
WARNING: / was not properly dismounted
fxp0: link state changed to UP
fsync: giving up on dirty
0xc4016514: tag devfs, type VCHR
usecount 1, writecount 0, refcount 847 mountedhere 0xc3f9b300
flags ()
v_object 0xc185a168 ref 0 pages 3366
lock type devfs: EXCL (count 1) by thread 0xc519b870 (pid 35566)
dev ad0s1e
g_vfs_done():md0[READ(offset=65536, length=8192)]error = 5
fsync: giving up on dirty
0xc4016514: tag devfs, type VCHR
usecount 1, writecount 0, refcount 32 mountedhere 0xc3f9b300
flags ()
v_object 0xc185a168 ref 0 pages 707
lock type devfs: EXCL (count 1) by thread 0xc4b7bbd0 (pid 29914)
dev ad0s1e
fsync: giving up on dirty
0xc4016514: tag devfs, type VCHR
usecount 1, writecount 0, refcount 30 mountedhere 0xc3f9b300
flags ()
v_object 0xc185a168 ref 0 pages 699
lock type devfs: EXCL (count 1) by thread 0xc4b7bbd0 (pid 29914)
dev ad0s1e
g_vfs_done():md0[READ(offset=65536, length=8192)]error = 5
~KDB: enter: Line break on console
[thread pid 13 tid 100003 ]
Stopped at kdb_enter+0x2b: nop
db> ps
pid ppid pgrp uid state wmesg wchan cmd
65927 1 65927 1001 S+ suspfs 0xc40ca57c ls
65870 0 0 0 SL mdwait 0xc6d55000 [md4]
65863 0 0 0 SL mdwait 0xc6d4d800 [md3]
65856 0 0 0 SL mdwait 0xc6d79000 [md2]
65849 0 0 0 SL mdwait 0xc6ec5000 [md1]
63239 63237 63235 0 S suspfs 0xc40ca57c mktemp
63237 63235 63235 0 S piperd 0xc4067948 sh
63235 63233 63235 0 Ss wait 0xc4834d38 sh
63233 864 864 0 S piperd 0xc416318c cron
62981 1989 1989 0 S+ ufs 0xc59bc878 mksnap_ffs
62903 0 0 0 SL nfsreq 0xc4b8a080 [nfsiod 1]
62902 0 0 0 SL nfsreq 0xc5637300 [nfsiod 0]
62873 62872 2017 1001 S+ getblk 0xd7e89878 rw
62872 62865 2017 1001 S+ wait 0xc47bad38 rw
62865 2021 2017 1001 S+ wait 0xc6c028d0 rw
2021 2020 2017 1001 S+ wait 0xc3fd969c run
2020 2019 2017 1001 SW+ wait 0xc46e2468 run
2019 2017 2017 1001 S+ nanslp 0xc0a0b8c4 run
2017 992 2017 1001 SW+ wait 0xc3f6d69c sh
2005 1032 2005 1001 S+ select 0xc0a57d7c top
1989 1986 1989 0 S+ wait 0xc3de069c sh
1986 1985 1986 0 SW+ pause 0xc4713034 csh
1985 1979 1985 1001 SW+ wait 0xc403369c su
1979 1978 1979 1001 SWs+ wait 0xc40338d0 bash
1978 1976 1976 1001 S select 0xc0a57d7c sshd
1976 845 1976 0 SWs sbwait 0xc4759480 sshd
1032 1031 1032 1001 SWs+ wait 0xc40f58d0 bash
1031 1029 1029 1001 S select 0xc0a57d7c sshd
1029 845 1029 0 SWs sbwait 0xc424cc48 sshd
992 991 992 1001 SWs+ wait 0xc403769c bash
991 989 989 1001 S select 0xc0a57d7c sshd
989 845 989 0 SWs sbwait 0xc412d09c sshd
988 1 988 0 SWs+ ttyin 0xc3df3810 getty
987 1 987 0 SWs+ ttyin 0xc3dfb810 getty
986 1 986 0 SWs+ ttyin 0xc3dfa810 getty
985 1 985 0 SWs+ ttyin 0xc3dfa010 getty
984 1 984 0 SWs+ ttyin 0xc3df5c10 getty
983 1 983 0 SWs+ ttyin 0xc3dfbc10 getty
982 1 982 0 SWs+ ttyin 0xc3dfc010 getty
981 1 981 0 SWs+ ttyin 0xc3dfac10 getty
964 1 964 0 SWs select 0xc0a57d7c inetd
935 1 935 0 SWs select 0xc0a57d7c moused
918 1 918 0 Ss nanslp 0xc0a0b8c4 watchdogd
864 1 864 0 Ss nanslp 0xc0a0b8c4 cron
858 1 858 25 Ss pause 0xc401949c sendmail
852 1 852 0 Ss select 0xc0a57d7c sendmail
845 1 845 0 Ss select 0xc0a57d7c sshd
825 1 825 0 Ss select 0xc0a57d7c ntpd
767 763 763 0 S - 0xc3fa0000 nfsd
766 763 763 0 S - 0xc3f61000 nfsd
765 763 763 0 S ufs 0xc59bc878 nfsd
764 763 763 0 S suspfs 0xc40ca57c nfsd
763 1 763 0 SWs select 0xc0a57d7c nfsd
761 1 761 0 Ss select 0xc0a57d7c mountd
701 1 701 0 Ss select 0xc0a57d7c rpcbind
678 1 678 0 Ss select 0xc0a57d7c syslogd
568 1 568 0 SWs select 0xc0a57d7c devd
42 0 0 0 SL - 0xe4364d04 [schedcpu]
41 0 0 0 SL sdflush 0xc0a65160 [softdepflush]
40 0 0 0 SL vlruwt 0xc3f6dd38 [vnlru]
39 0 0 0 SL syncer 0xc0a0b690 [syncer]
38 0 0 0 SL psleep 0xc0a581f4 [bufdaemon]
37 0 0 0 SL pgzero 0xc0a6da90 [pagezero]
36 0 0 0 SL psleep 0xc0a659c0 [vmdaemon]
35 0 0 0 SL psleep 0xc0a65980 [pagedaemon]
34 0 0 0 WL [irq7: ppc0]
33 0 0 0 SL - 0xc3d7603c [fdc0]
32 0 0 0 WL [swi0: sio]
31 0 0 0 WL [irq12: psm0]
30 0 0 0 WL [irq1: atkbd0]
29 0 0 0 WL [irq15: ata1]
28 0 0 0 WL [irq14: ata0]
27 0 0 0 WL [irq17: fxp0]
26 0 0 0 SL usbtsk 0xc0a08e44 [usbtask]
25 0 0 0 SL usbevt 0xc3d67210 [usb0]
24 0 0 0 WL [irq16: uhci0]
23 0 0 0 SL - 0xc3d51480 [em0 taskq]
22 0 0 0 WL [irq9: acpi0]
9 0 0 0 SL - 0xc3d40980 [thread taskq]
21 0 0 0 WL [swi6: Giant taskq]
20 0 0 0 WL [swi6: task queue]
8 0 0 0 SL - 0xc3c7b280 [acpi_task_2]
7 0 0 0 SL - 0xc3c7b280 [acpi_task_1]
6 0 0 0 SL - 0xc3c7b280 [acpi_task_0]
5 0 0 0 SL - 0xc3c7b300 [kqueue taskq]
19 0 0 0 WL [swi2: cambio]
18 0 0 0 WL [swi5: +]
17 0 0 0 SL - 0xc0a06a80 [yarrow]
4 0 0 0 SL - 0xc0a095fc [g_down]
3 0 0 0 SL - 0xc0a095f8 [g_up]
2 0 0 0 SL - 0xc0a095f0 [g_event]
16 0 0 0 WL [swi3: vm]
15 0 0 0 WL [swi4: clock sio]
14 0 0 0 WL [swi1: net]
13 0 0 0 RL CPU 0 [idle: cpu0]
12 0 0 0 RL CPU 1 [idle: cpu1]
11 0 0 0 RL CPU 2 [idle: cpu2]
10 0 0 0 RL CPU 3 [idle: cpu3]
1 0 1 0 SLs wait 0xc3c32000 [init]
0 0 0 0 WLs [swapper]
62866 2021 2017 1001 Z+ swap
62868 2021 2017 1001 Z+ mkdir
62883 62872 2017 1001 Z+ rw
62880 62872 2017 1001 Z+ rw
62887 62872 2017 1001 Z+ rw
62889 62872 2017 1001 Z+ rw
62875 62872 2017 1001 Z+ rw
62892 62872 2017 1001 Z+ rw
62894 62872 2017 1001 Z+ rw
62878 62872 2017 1001 Z+ rw
62885 62872 2017 1001 Z+ rw
62874 62872 2017 1001 Z+ rw
62896 62872 2017 1001 Z+ rw
62897 62872 2017 1001 Z+ rw
62879 62872 2017 1001 Z+ rw
62876 62872 2017 1001 Z+ rw
62870 2021 2017 1001 Z+ udp
62871 2021 2017 1001 Z+ tcp
62869 2021 2017 1001 Z+ thr1
62867 2021 2017 1001 Z+ creat
db> show alllocks
db> show sleepqueue 0xc40ca57c
Wait channel: 0xc40ca57c
Queue type: 0
Associated Interlock: 0xc40ca534 - (sleep mutex) struct mount mtx
Blocked threads:
0xc3fdb870 (tid 100076, pid 764, "nfsd")
0xc65d4510 (tid 100208, pid 63239, "mktemp")
0xc4795bd0 (tid 100286, pid 65927, "ls")
db> show lock 0xc40ca534
class: sleep mutex
name: struct mount mtx
flags: {DEF}
state: {UNOWNED}
db> show sleepqueue 0xc59bc878
Wait channel: 0xc59bc878
Queue type: 0
Associated Interlock: 0xc0a0a930 - (sleep mutex) lockbuilder mtxpool
Blocked threads:
0xc4034510 (tid 100082, pid 765, "nfsd")
0xc46e3d80 (tid 100135, pid 62981, "mksnap_ffs")
db> show lock 0xc0a0a930
class: sleep mutex
name: lockbuilder mtxpool
flags: {DEF}
state: {UNOWNED}
db> where 764
Tracing pid 764 tid 100076 td 0xc3fdb870
sched_switch(c3fdb870,0,1) at sched_switch+0x183
mi_switch(1,0) at mi_switch+0x280
sleepq_switch(c40ca57c,c0a0b0b0,0,c092000a,211,...) at sleepq_switch+0xcd
sleepq_wait(c40ca57c,0,c0927acf,3f3,c093229c,...) at sleepq_wait+0x46
msleep(c40ca57c,c40ca534,29f,c0927b18,0,...) at msleep+0x27d
vn_start_secondary_write(c59bc820,e6586988,1) at vn_start_secondary_write+0x122
ufs_inactive(e65869b8) at ufs_inactive+0x257
VOP_INACTIVE_APV(c09d9a00,e65869b8) at VOP_INACTIVE_APV+0x7e
vinactive(c59bc820,c3fdb870) at vinactive+0x72
vput(c59bc820,c0a0b0c8,1,c0932293,407,...) at vput+0x1b3
nfsrv_read(c4703600,c3f12900,c3fdb870,e6586c40) at nfsrv_read+0xc21
nfssvc_nfsd(c3fdb870) at nfssvc_nfsd+0x409
nfssvc(c3fdb870,e6586d04) at nfssvc+0x18c
syscall(3b,3b,3b,1,0,...) at syscall+0x256
Xint0x80_syscall() at Xint0x80_syscall+0x1f
--- syscall (155, FreeBSD ELF32, nfssvc), eip = 0x280cb193, esp = 0xbfbfeb2c, ebp = 0xbfbfeb48 ---
db> where 765
Tracing pid 765 tid 100082 td 0xc4034510
sched_switch(c4034510,0,1) at sched_switch+0x183
mi_switch(1,0) at mi_switch+0x280
sleepq_switch(c59bc878,c0a0b0b0,0,c092000a,211,...) at sleepq_switch+0xcd
sleepq_wait(c59bc878,0,c59bc89c,b1,c091ab43,...) at sleepq_wait+0x46
msleep(c59bc878,c0a0a930,50,c0924f24,0,...) at msleep+0x27d
acquire(e65ef828,40,60000,c4034510,0,...) at acquire+0x76
lockmgr(c59bc878,2002,c59bc89c,c4034510) at lockmgr+0x44a
ffs_lock(e65ef880) at ffs_lock+0x6e
VOP_LOCK_APV(c09d9a00,e65ef880) at VOP_LOCK_APV+0x87
vn_lock(c59bc820,2002,c4034510,c59bc820) at vn_lock+0xa8
vget(c59bc820,2002,c4034510) at vget+0xba
vfs_hash_get(c40ca510,17017,2,c4034510,e65ef998,0,0) at vfs_hash_get+0x8a
ffs_vget(c40ca510,17017,2,e65ef998) at ffs_vget+0x27
ufs_fhtovp(c40ca510,e65efb8c,e65efa78,c40ca510,e65efa00,...) at ufs_fhtovp+0x22
ffs_fhtovp(c40ca510,e65efb8c,e65efa78) at ffs_fhtovp+0x3a
nfsrv_fhtovp(e65efb84,1,e65efa78,c4519800,c3f12900,c3f66950,e65efa7c,1) at nfsrv_fhtovp+0xf9
nfsrv_read(c4718b00,c3f12900,c4034510,e65efc40) at nfsrv_read+0x275
nfssvc_nfsd(c4034510) at nfssvc_nfsd+0x409
nfssvc(c4034510,e65efd04) at nfssvc+0x18c
syscall(3b,3b,3b,1,0,...) at syscall+0x256
Xint0x80_syscall() at Xint0x80_syscall+0x1f
--- syscall (155, FreeBSD ELF32, nfssvc), eip = 0x280cb193, esp = 0xbfbfeb2c, ebp = 0xbfbfeb48 ---
db> where 63239
Tracing pid 63239 tid 100208 td 0xc65d4510
sched_switch(c65d4510,0,1) at sched_switch+0x183
mi_switch(1,0) at mi_switch+0x280
sleepq_switch(c40ca57c) at sleepq_switch+0xcd
sleepq_wait_sig(c40ca57c) at sleepq_wait_sig+0x1d
msleep(c40ca57c,c40ca534,19f,c0927b18,0) at msleep+0x26e
vn_start_write(0,e6b50a10,104) at vn_start_write+0xbf
vn_open_cred(e6b50b7c,e6b50c7c,180,c461d780,3,...) at vn_open_cred+0x12f
vn_open(e6b50b7c,e6b50c7c,180,3) at vn_open+0x1e
kern_open(c65d4510,8208140,0,a03,180,...) at kern_open+0xb9
open(c65d4510,e6b50d04) at open+0x18
syscall(3b,3b,3b,8208140,8208144,...) at syscall+0x256
Xint0x80_syscall() at Xint0x80_syscall+0x1f
--- syscall (5, FreeBSD ELF32, open), eip = 0x28142c5f, esp = 0xbfbfed0c, ebp = 0xbfbfedb8 ---
db> where 62981
Tracing pid 62981 tid 100135 td 0xc46e3d80
sched_switch(c46e3d80,0,1) at sched_switch+0x183
mi_switch(1,0) at mi_switch+0x280
sleepq_switch(c59bc878,c0a0b0b0,0,c092000a,211,...) at sleepq_switch+0xcd
sleepq_wait(c59bc878,0,c59bc89c,b1,c0926903,...) at sleepq_wait+0x46
msleep(c59bc878,c0a0a930,50,c0924f24,0,...) at msleep+0x27d
acquire(e66ee5a8,40,60000,c46e3d80,0,...) at acquire+0x76
lockmgr(c59bc878,2002,c59bc89c,c46e3d80) at lockmgr+0x44a
ffs_lock(e66ee600) at ffs_lock+0x6e
VOP_LOCK_APV(c09d9a00,e66ee600) at VOP_LOCK_APV+0x87
vn_lock(c59bc820,2002,c46e3d80,c59bc820) at vn_lock+0xa8
ffs_snapshot(c40ca510,c3defb60,c3defb60,c401e000,c4016514,...) at ffs_snapshot+0x1210
ffs_mount(c40ca510,c46e3d80,20000000,201300,0,...) at ffs_mount+0x927
vfs_domount(c46e3d80,c3dffa80,c3d45b40,1211300,c3f662c0,c0a0b0c8,0,c09268fa,2b0) at vfs_domount+0x554
vfs_donmount(c46e3d80,1211300,e66eebac) at vfs_donmount+0x414
kernel_mount(c3fc5690,1211300,bfbfecdc,0,0,...) at kernel_mount+0x6d
ffs_cmount(c3fc5690,bfbfe500,1211300,c46e3d80,c09d96e0,...) at ffs_cmount+0x5d
mount(c46e3d80,e66eed04) at mount+0x15e
syscall(3b,3b,3b,2816772c,bfbfe4a0,...) at syscall+0x256
Xint0x80_syscall() at Xint0x80_syscall+0x1f
--- syscall (21, FreeBSD ELF32, mount), eip = 0x280c96b3, esp = 0xbfbfe46c, ebp = 0xbfbfeb68 ---
db> show lockedvnods
Locked vnodes
0xc59bc820: tag ufs, type VREG
usecount 0, writecount 0, refcount 4 mountedhere 0
flags ()
v_object 0xc4198780 ref 0 pages 4356
lock type ufs: EXCL (count 1) by thread 0xc3fdb870 (pid 764) with 2 pending
ino 94231, on dev ad0s1e
0xc613a618: tag ufs, type VREG
usecount 1, writecount 0, refcount 3 mountedhere 0
flags ()
lock type ufs: EXCL (count 1) by thread 0xc46e3d80 (pid 62981)
ino 211984, on dev ad0s1e
0xc5f0d71c: tag nfs, type VREG
usecount 1, writecount 0, refcount 4 mountedhere 0
flags ()
v_object 0xc5df5168 ref 0 pages 1168
lock type nfs: SHARED (count 1)
fileid -496748184 fsid 0xc0a0b0c8
db> call doadump
Physical memory: 1007 MB
Dumping 149 MB: 134 118 102 86 70 54 38 22 6
Dump complete
= 0xf
db> reset
GDB: no debug ports present
(kgdb) p *(struct mount *)0xc40ca510
$1 = {mnt_lock = {lk_interlock = 0xc0a0a918, lk_flags = 0x1000000, lk_sharecount = 0x1, lk_waitcount = 0x0, lk_exclusivecount = 0x0,
lk_prio = 0x50, lk_wmesg = 0xc0926925 "vfslock", lk_timo = 0x0, lk_lockholder = 0xffffffff, lk_newlock = 0x0}, mnt_mtx = {
mtx_object = {lo_name = 0xc0926914 "struct mount mtx", lo_type = 0xc0926914 "struct mount mtx", lo_flags = 0x1030000,
lo_witness_data = {lod_list = {stqe_next = 0xc0a197e8}, lod_witness = 0xc0a197e8}}, mtx_lock = 0x4, mtx_recurse = 0x0},
mnt_list = {tqe_next = 0xc40ca288, tqe_prev = 0xc3fbda5c}, mnt_op = 0xc09d96a0, mnt_vfc = 0xc09d96e0,
mnt_vnodecovered = 0xc4012c30, mnt_syncer = 0xc40c5820, mnt_ref = 0x17f, mnt_nvnodelist = {tqh_first = 0xc40c5924,
tqh_last = 0xc4f1662c}, mnt_nvnodelistsize = 0x17a, mnt_writeopcount = 0x0, mnt_kern_flag = 0x2c000000, mnt_flag = 0x1211300,
mnt_opt = 0xc60ce920, mnt_optnew = 0xc3f662c0, mnt_maxsymlinklen = 0x78, mnt_stat = {f_version = 0x20030518, f_type = 0x6,
f_flags = 0x201300, f_bsize = 0x800, f_iosize = 0x4000, f_blocks = 0xf20a7, f_bfree = 0x6b37b, f_bavail = 0x57dac,
f_files = 0x3f3fe, f_ffree = 0x3f140, f_syncwrites = 0x0, f_asyncwrites = 0x0, f_syncreads = 0x0, f_asyncreads = 0x0, f_spare = {
0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}, f_namemax = 0xff, f_owner = 0x0, f_fsid = {val = {0x434f6181, 0xa1e353a3}},
f_charspare = '\0' <repeats 79 times>, f_fstypename = "ufs", '\0' <repeats 12 times>,
f_mntfromname = "/dev/ad0s1e", '\0' <repeats 76 times>, f_mntonname = "/tmp", '\0' <repeats 83 times>}, mnt_cred = 0xc3f93980,
mnt_data = 0xc401e000, mnt_time = 0x0, mnt_iosize_max = 0x20000, mnt_export = 0xc6b9cc00, mnt_mntlabel = 0x0, mnt_fslabel = 0x0,
mnt_hashseed = 0xea73cfb7, mnt_markercnt = 0x1, mnt_holdcnt = 0x1, mnt_holdcntwaiters = 0x0, mnt_secondary_writes = 0x0,
mnt_secondary_accwrites = 0x3c1931}