GENERIC HEAD from Aug 18 17:22 UTC, vmcore.71
Snapshot stress test with Konstantins ufs_inode.c patch
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 #2: Fri Aug 18 19:43:37 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.81-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
swap_pager: indefinite wait buffer: bufobj: 0, blkno: 30056, size: 32768
free ifree inode /tmp/27826 had -2068624 blocks
node /tmp/27825 had -2068624 blocks
handle_workitem_freeblocks: block count
handle_workitem_freeblocks: block count
freebsd4_sigreturn: eflags = 0x0
freebsd4_sigreturn: eflags = 0x0
:
freebsd4_sigreturn: eflags = 0x0
ffrreeee iinnoodde e/ t/mtp/m27p8/2267 8h2a5d h-a2d0 6-82602648 b6l2oc4k sbl
ocks
/tmp: mount pending error: blocks 24823488 files 0
/tmp: mount pending error: blocks 24823488 files 0
/tmp: mount pending error: blocks 24823488 files 0
/tmp: mount pending error: blocks 24823488 files 0
/tmp: unmount pending error: blocks 24823488 files 0
acd0: FAILURE - READ_TRACK_INFO ILLEGAL REQUEST asc=0x24 ascq=0x00 sks=0x40 0x00 0x02
acd0: FAILURE - READ_BIG ILLEGAL REQUEST asc=0x64 ascq=0x00
fsync: giving up on dirty
0xc4037b2c: tag devfs, type VCHR
usecount 1, writecount 0, refcount 519 mountedhere 0xc3f9b300
flags ()
v_object 0xc40c5528 ref 0 pages 2062
lock type devfs: EXCL (count 1) by thread 0xc7423000 (pid 62362)
dev ad0s1e
g_vfs_done():md0[READ(offset=65536, length=8192)]error = 5
fsync: giving up on dirty
0xc4037b2c: tag devfs, type VCHR
usecount 1, writecount 0, refcount 1226 mountedhere 0xc3f9b300
flags ()
v_object 0xc40c5528 ref 0 pages 4894
lock type devfs: EXCL (count 1) by thread 0xc4be16c0 (pid 62984)
dev ad0s1e
fsync: giving up on dirty
0xc4037b2c: tag devfs, type VCHR
usecount 1, writecount 0, refcount 1225 mountedhere 0xc3f9b300
flags ()
v_object 0xc40c5528 ref 0 pages 4890
lock type devfs: EXCL (count 1) by thread 0xc4be16c0 (pid 62984)
dev ad0s1e
g_vfs_done():md0[READ(offset=65536, length=8192)]error = 5
fsync: giving up on dirty
0xc4037b2c: tag devfs, type VCHR
usecount 1, writecount 0, refcount 73 mountedhere 0xc3f9b300
flags ()
v_object 0xc40c5528 ref 0 pages 278
lock type devfs: EXCL (count 1) by thread 0xc4af7a20 (pid 64615)
dev ad0s1e
g_vfs_done():md0[READ(offset=65536, length=8192)]error = 5
ssswwwaaappp__p_apgpaageegrerr:: : ii ndienfndideniftee iwnfiatieint i wtbea iuwfta fietbr u: bbufuffffoeebrj:: r0: , bbublfkonobu:j f:9 o06b1j9,: ,b0,l blkknnoo: 9 :6s 2i87z,e :9s3iz1 ,e4 :0 946s096iz
e: 24576
fsync: giving up on dirty
0xc4037b2c: tag devfs, type VCHR
usecount 1, writecount 0, refcount 1558 mountedhere 0xc3f9b300
flags ()
v_object 0xc40c5528 ref 0 pages 6218
lock type devfs: EXCL (count 1) by thread 0xc726da20 (pid 68587)
dev ad0s1e
g_vfs_done():md0[READ(offset=65536, length=8192)]error = 5
panic: snapacct_ufs2: bad block
cpuid = 1
KDB: enter: panic
[thread pid 69029 tid 100401 ]
Stopped at kdb_enter+0x2b: nop
db> where
Tracing pid 69029 tid 100401 td 0xc5173a20
kdb_enter(c091d9db) at kdb_enter+0x2b
panic(c0935a53,c7592840,d7ebf6c8,c,0,...) at panic+0x14b
snapacct_ufs2(c58ea820,c4e361f8,c4e365d0,db934000,c,0,1) at snapacct_ufs2+0x119
fullacct_ufs2(c58ea820,c4e34000,c4e365d0,db934000,c,0,1,d7e8f378,ddda4000,c4e34000,4000,4000,c09c4b20,2) at fullacct_ufs2+0x23
indiracct_ufs2(c58ea820,c531ab2c,0,883c0,0,fffffff4,ffffffff,c,0,4ba,0,1,0,db934000,c07cba80,1) at indiracct_ufs2+0x1ab
expunge_ufs2(c58ea820,c5d95948,db934000,c07cba80,1) at expunge_ufs2+0x451
ffs_snapshot(c47d3798,c3d63a60,c3d63a60,c6fa8600,c4037b2c,...) at ffs_snapshot+0x1633
ffs_mount(c47d3798,c5173a20,20000000,201300,0,...) at ffs_mount+0x927
vfs_domount(c5173a20,c3f66540,c3f668b0,1211300,c47b1820,c0a0be88,0,c0927577,2b0) at vfs_domount+0x554
vfs_donmount(c5173a20,1211300,e6946bac) at vfs_donmount+0x414
kernel_mount(c3f66bb0,1211300,bfbfecb0,0,0,...) at kernel_mount+0x6d
ffs_cmount(c3f66bb0,bfbfe4d0,1211300,c5173a20,c09da4a0,...) at ffs_cmount+0x5d
mount(c5173a20,e6946d04) at mount+0x15e
syscall(3b,3b,3b,2816772c,bfbfe470,...) at syscall+0x256
Xint0x80_syscall() at Xint0x80_syscall+0x1f
--- syscall (21, FreeBSD ELF32, mount), eip = 0x280c96b3, esp = 0xbfbfe43c, ebp = 0xbfbfeb38 ---
db> show alllocks
Process 69029 (mksnap_ffs) thread 0xc5173a20 (100401)
exclusive sleep mutex Giant r = 1 (0xc0a0be88) locked @ kern/vfs_mount.c:688
Process 68970 (tcp) thread 0xc4afc000 (100144)
exclusive sleep mutex so_snd r = 0 (0xc411d9f4) locked @ kern/uipc_sockbuf.c:534
exclusive sleep mutex inp (tcpinp) r = 0 (0xc4cd9720) locked @ netinet/tcp_usrreq.c:801
db> show lockedvnods
Locked vnodes
0xc531ab2c: tag ufs, type VREG
usecount 1, writecount 1, refcount 812 mountedhere 0
flags ()
v_object 0xc6192b40 ref 0 pages 3236
lock type ufs: EXCL (count 1) by thread 0xc5173a20 (pid 69029)
ino 117866, on dev ad0s1e
0xc58ea820: tag ufs, type VREG
usecount 1, writecount 0, refcount 82 mountedhere 0
flags ()
lock type ufs: EXCL (count 1) by thread 0xc5173a20 (pid 69029)
ino 211968, on dev ad0s1e
db> ps
pid ppid pgrp uid state wmesg wchan cmd
69029 57409 57409 0 R+ CPU 1 mksnap_ffs
69028 68929 58566 1001 S+ sbwait 0xc4d013a0 mkfifo
68982 68909 58566 1001 S+ sbwait 0xc4ce0e00 mkfifo
68980 68907 58566 1001 R+ mkfifo
68978 68913 58566 1001 S+ sbwait 0xc4cfa254 mkfifo
68973 68945 58566 1001 R+ tcp
68972 68948 58566 1001 R+ tcp
68971 68947 58566 1001 R+ tcp
68970 68943 58566 1001 R+ tcp
68969 68950 58566 1001 R+ tcp
68968 68939 58566 1001 R+ tcp
68967 68951 58566 1001 R+ tcp
68965 68911 58566 1001 R+ mkfifo
68963 68926 58566 1001 S+ sbwait 0xc4ce1254 mkfifo
68962 68928 58566 1001 S+ sbwait 0xc4cf03a0 mkfifo
68958 68927 58566 1001 SL+ pfault 0xc0a66558 swap
68957 68927 58566 1001 SL+ swread 0xc26003b0 swap
68956 68927 58566 1001 R+ swap
68955 68927 58566 1001 SL+ pfault 0xc0a66558 swap
68954 68927 58566 1001 SL+ pfault 0xc0a66558 swap
68953 68927 58566 1001 SL+ pfault 0xc0a66558 swap
68952 68927 58566 1001 SL+ pfault 0xc0a66558 swap
68951 68931 58566 1001 S+ sbwait 0xc4cf009c tcp
68950 68931 58566 1001 S+ sbwait 0xc4ce0c48 tcp
68949 68927 58566 1001 SL+ swread 0xc28f30d8 swap
68948 68931 58566 1001 S+ sbwait 0xc411d1e8 tcp
68947 68931 58566 1001 S+ sbwait 0xc4cec480 tcp
68946 68927 58566 1001 SL+ pfault 0xc0a66558 swap
68945 68931 58566 1001 S+ sbwait 0xc4d0509c tcp
68943 68931 58566 1001 S+ sbwait 0xc59d5718 tcp
68942 68927 58566 1001 SL+ pfault 0xc0a66558 swap
68940 68927 58566 1001 SL+ pfault 0xc0a66558 swap
68939 68931 58566 1001 S+ sbwait 0xc59d5afc tcp
68938 68927 58566 1001 SL+ pfault 0xc0a66558 swap
68937 68927 58566 1001 SL+ swread 0xc2075cc8 swap
68936 68927 58566 1001 SL+ pfault 0xc0a66558 swap
68935 68927 58566 1001 R+ swap
68932 68902 58566 1001 SW+ suspfs 0xc47d3804 mkfifo
68931 68891 58566 1001 SW+ wait 0xc4792d38 tcp
68929 68902 58566 1001 R+ mkfifo
68928 68902 58566 1001 R+ mkfifo
68927 68884 58566 1001 SW+ wait 0xc478e69c swap
68926 68902 58566 1001 R+ CPU 3 mkfifo
68925 68902 58566 1001 SW+ suspfs 0xc47d3804 mkfifo
68924 68902 58566 1001 SW+ suspfs 0xc47d3804 mkfifo
68923 68904 58566 1001 SW+ suspfs 0xc47d3804 rw
68922 68904 58566 1001 SW+ suspfs 0xc47d3804 rw
68921 68904 58566 1001 SW+ suspfs 0xc47d3804 rw
68920 68904 58566 1001 SW+ suspfs 0xc47d3804 rw
68919 68904 58566 1001 SW+ suspfs 0xc47d3804 rw
68918 68904 58566 1001 SW+ suspfs 0xc47d3804 rw
68916 68904 58566 1001 SW+ suspfs 0xc47d3804 rw
68915 68902 58566 1001 SW+ suspfs 0xc47d3804 mkfifo
68914 68904 58566 1001 SW+ suspfs 0xc47d3804 rw
68913 68902 58566 1001 R+ mkfifo
68912 68902 58566 1001 SW+ suspfs 0xc47d3804 mkfifo
68911 68902 58566 1001 S+ sbwait 0xc4cfa5cc mkfifo
68909 68902 58566 1001 R+ mkfifo
68907 68902 58566 1001 S+ sbwait 0xc424dc48 mkfifo
68905 68886 58566 1001 R+ mkdir
68904 68888 58566 1001 SW+ wait 0xc49b48d0 rw
68902 68894 58566 1001 SW+ wait 0xc649c69c mkfifo
68900 58573 58566 1001 S+ nanslp 0xc0a0c684 mmap
68894 58573 58566 1001 S+ nanslp 0xc0a0c684 mkfifo
68891 58573 58566 1001 S+ nanslp 0xc0a0c684 tcp
68888 58573 58566 1001 S+ nanslp 0xc0a0c684 rw
68886 58573 58566 1001 S+ nanslp 0xc0a0c684 mkdir
68884 58573 58566 1001 S+ nanslp 0xc0a0c684 swap
67032 0 0 0 SL mdwait 0xc6451000 [md4]
67025 0 0 0 SL mdwait 0xc65e8800 [md3]
67018 0 0 0 SL mdwait 0xc55c4800 [md2]
67011 0 0 0 SL mdwait 0xc5381000 [md1]
58573 58572 58566 1001 SW+ wait 0xc495e000 run
58572 58571 58566 1001 SW+ wait 0xc47b58d0 run
58571 58566 58566 1001 S+ nanslp 0xc0a0c684 run
58566 992 58566 1001 SW+ wait 0xc49b78d0 sh
57409 57404 57409 0 SW+ wait 0xc54bc234 sh
57404 57401 57404 0 SW+ wait 0xc4a5a234 bash
57401 57400 57401 0 SW+ pause 0xc54bc904 csh
57400 57394 57400 1001 SW+ wait 0xc54bcd38 su
57394 57393 57394 1001 SWs+ wait 0xc4663d38 bash
57393 57391 57391 1001 SW select 0xc0a58b3c sshd
57391 845 57391 0 SWs sbwait 0xc59d5864 sshd
1887 1020 1887 1001 S+ select 0xc0a58b3c top
1020 1019 1020 1001 SWs+ wait 0xc4041b04 bash
1019 1017 1017 1001 S select 0xc0a58b3c sshd
1017 845 1017 0 SWs sbwait 0xc4673480 sshd
992 991 992 1001 SWs+ wait 0xc4042d38 bash
991 989 989 1001 SW select 0xc0a58b3c sshd
989 845 989 0 SWs sbwait 0xc412d5cc 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 0xc0a58b3c inetd
935 1 935 0 SWs select 0xc0a58b3c moused
918 1 918 0 Ss nanslp 0xc0a0c684 watchdogd
864 1 864 0 Ss nanslp 0xc0a0c684 cron
858 1 858 25 SWs pause 0xc40f06d0 sendmail
852 1 852 0 Ss select 0xc0a58b3c sendmail
845 1 845 0 SWs select 0xc0a58b3c sshd
825 1 825 0 Ss select 0xc0a58b3c ntpd
767 763 763 0 SW - 0xc3f61000 nfsd
766 763 763 0 SW - 0xc3f61c00 nfsd
765 763 763 0 SW - 0xc3d76c00 nfsd
764 763 763 0 SW - 0xc3fb0800 nfsd
763 1 763 0 SWs select 0xc0a58b3c nfsd
761 1 761 0 SWs select 0xc0a58b3c mountd
701 1 701 0 SWs select 0xc0a58b3c rpcbind
678 1 678 0 SWs select 0xc0a58b3c syslogd
568 1 568 0 SWs select 0xc0a58b3c devd
42 0 0 0 SL - 0xe4364cfc [schedcpu]
41 0 0 0 SL sdflush 0xc0a65f20 [softdepflush]
40 0 0 0 SL vlruwt 0xc3f6dd38 [vnlru]
39 0 0 0 SL syncer 0xc0a0c450 [syncer]
38 0 0 0 SL psleep 0xc0a58fb4 [bufdaemon]
37 0 0 0 RL [pagezero]
36 0 0 0 SL psleep 0xc0a66780 [vmdaemon]
35 0 0 0 RL CPU 2 [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 0xc0a09c04 [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 - 0xc0a07840 [yarrow]
4 0 0 0 SL - 0xc0a0a3bc [g_down]
3 0 0 0 RL [g_up]
2 0 0 0 SL - 0xc0a0a3b0 [g_event]
16 0 0 0 WL [swi3: vm]
15 0 0 0 RL CPU 0 [swi4: clock sio]
14 0 0 0 WL [swi1: net]
13 0 0 0 RL [idle: cpu0]
12 0 0 0 RL [idle: cpu1]
11 0 0 0 RL [idle: cpu2]
10 0 0 0 RL [idle: cpu3]
1 0 1 0 SLs wait 0xc3c32000 [init]
0 0 0 0 WLs [swapper]
68903 68900 58566 1001 Z+ mmap
68917 68904 58566 1001 Z+ rw
68898 58573 58566 1001 Z+ thr2
68887 58573 58566 1001 Z+ thr1
68892 58573 58566 1001 Z+ udp
68901 58573 58566 1001 Z+ socket
68897 58573 58566 1001 Z+ symlink
68890 58573 58566 1001 Z+ sysctl
68895 58573 58566 1001 Z+ shm
68893 58573 58566 1001 Z+ pty
68899 58573 58566 1001 Z+ badcode
68885 58573 58566 1001 Z+ creat
68896 58573 58566 1001 Z+ lockf
68889 58573 58566 1001 Z+ syscall
db> call print_uptime
Uptime: 1d2h59m26s
= 0x4
db> call doadump
Physical memory: 1007 MB
Dumping 203 MB: 188 172 156 140 124 108 92 76 60 44 28 12
Dump complete
= 0xf
db> reset
cpu_reset: Restarting BSP
cpu_reset_proxy: Stopped CPU 1
GDB: no debug ports present
(kgdb) f 10
#10 0xc07cbbe9 in snapacct_ufs2 (vp=0xc58ea820, oldblkp=0xc4e361f8, lastblkp=0xc4e365d0, fs=0xdb934000, lblkno=0xc, expungetype=0x1)
at ../../../ufs/ffs/ffs_snapshot.c:1469
1469 panic("snapacct_ufs2: bad block");
(kgdb) l
1464 if (expungetype == BLK_SNAP && *blkp == BLK_NOCOPY) {
1465 if (lbn >= NDADDR)
1466 brelse(ibp);
1467 } else {
1468 if (*blkp != 0)
1469 panic("snapacct_ufs2: bad block");
1470 *blkp = expungetype;
1471 if (lbn >= NDADDR)
1472 bdwrite(ibp);
1473 }
(kgdb) info loc
ip = (struct inode *) 0xc7592840
blkno = Unhandled dwarf expression opcode 0x93
(kgdb) p *ip
$1 = {i_nextsnap = {tqe_next = 0x0, tqe_prev = 0x0}, i_vnode = 0xc58ea820, i_ump = 0xc6fa8600, i_flag = 0x6, i_dev = 0xc3f9b300,
i_number = 0x33c00, i_effnlink = 0x1, i_fs = 0xc6ec4000, i_dquot = {0x0, 0x0}, i_modrev = 0x17b840e300eaa, i_lockf = 0x0,
i_count = 0x0, i_endoff = 0x0, i_diroff = 0x0, i_offset = 0x0, i_ino = 0x0, i_reclen = 0x0, i_un = {dirhash = 0x0,
snapblklist = 0x0}, i_ea_area = 0x0, i_ea_len = 0x0, i_ea_error = 0x0, i_mode = 0x8100, i_nlink = 0x1, i_size = 0x7d000000,
i_flags = 0x200000, i_gen = 0xfffffffffa5da25a, i_uid = 0x0, i_gid = 0x5, dinode_u = {din1 = 0xc5cfb900, din2 = 0xc5cfb900}}
(kgdb) p *vp
$2 = {v_type = VREG, v_tag = 0xc0925ba1 "ufs", v_op = 0xc09da7c0, v_data = 0xc7592840, v_mount = 0xc47d3798, v_nmntvnodes = {
tqe_next = 0xc7c11e38, tqe_prev = 0xc5112320}, v_un = {vu_mount = 0x0, vu_socket = 0x0, vu_cdev = 0x0, vu_fifoinfo = 0x0},
v_hashlist = {le_next = 0x0, le_prev = 0xc3e1a81c}, v_hash = 0x33c00, v_cache_src = {lh_first = 0x0}, v_cache_dst = {
tqh_first = 0x0, tqh_last = 0xc58ea850}, v_dd = 0x0, v_cstart = 0x0, v_lasta = 0x0, v_lastw = 0x0, v_clen = 0x0, v_lock = {
lk_interlock = 0xc0a0bd38, lk_flags = 0x40040, lk_sharecount = 0x0, lk_waitcount = 0x0, lk_exclusivecount = 0x1, lk_prio = 0x50,
lk_wmesg = 0xc0925ba1 "ufs", lk_timo = 0x33, lk_lockholder = 0xc5173a20, lk_newlock = 0x0}, v_interlock = {mtx_object = {
lo_name = 0xc0921d63 "vnode interlock", lo_type = 0xc0921d63 "vnode interlock", lo_flags = 0x1030000, lo_witness_data = {
lod_list = {stqe_next = 0xc0a1be30}, lod_witness = 0xc0a1be30}}, mtx_lock = 0x4, mtx_recurse = 0x0}, v_vnlock = 0xc58ea878,
v_holdcnt = 0x52, v_usecount = 0x1, v_iflag = 0x0, v_vflag = 0x0, v_writecount = 0x0, v_freelist = {tqe_next = 0x0,
tqe_prev = 0x0}, v_bufobj = {bo_mtx = 0xc58ea89c, bo_clean = {bv_hd = {tqh_first = 0xd7c97bb0, tqh_last = 0xd7cf48c0},
bv_root = 0xd7ca14e0, bv_cnt = 0x36}, bo_dirty = {bv_hd = {tqh_first = 0xd7ebf6c8, tqh_last = 0xd7d6da70},
bv_root = 0xd7ebf6c8, bv_cnt = 0x1b}, bo_numoutput = 0x0, bo_flag = 0x1, bo_ops = 0xc09cde64, bo_bsize = 0x4000,
bo_object = 0x0, bo_synclist = {le_next = 0xc40c7ce4, le_prev = 0xc3e07980}, bo_private = 0xc58ea820, __bo_vnode = 0xc58ea820},
v_pollinfo = 0x0, v_label = 0x0}