Panic on 1.2.6: "getnewbuf: locked buf"

[Chris Csanady <cc@xxxxxxx>]

Well, it looks like gmail has taken certain liberties with my post,
so I will try again...


I came across this while doing a large file copy between partitions,
but otherwise not much in particular was going on.  Since I was
logged in via ssh, I'm not sure when exactly the panic occurred,
only that the cp never returned.  The target file may have been in
use by a running program.

I can provide a copy of the kernel and core if necessary.  A trace
follows.

Chris

# gdb -k kernel.3 vmcore.3
GNU gdb 6.2.1
Copyright 2004 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-dragonfly"...
panic: getnewbuf: locked buf
panic messages:
---
panic: getnewbuf: locked buf
mp_lock = 00000001; cpuid = 1; lapic.id = 0c000000
boot() called on cpu#1

syncing disks... panic: getnewbuf: locked buf
mp_lock = 00000001; cpuid = 1; lapic.id = 0c000000
boot() called on cpu#1
Uptime: 19d15h34m18s

dumping to dev #ad/0x20011, offset 524288
dump ata1: resetting devices .. done
ad2: timeout waiting for DRQ - resetting
ata1: resetting devices .. ata1-slave: ATA identify retries exceeded
done
128 127 126 125 124 123 122 121 120 119 118 117 116 115 114 113 112 111 110 109 108 107 106 105 104 103 102 101 100 99 98 97 96 95 94 93 92 91 90 89 88 87 86 85 84 83 82 81 80 79 78 77 76 75 74 73 72 71 70 69 68 67 66 65 64 63 62 61 60 59 58 57 56 55 54 53 52 51 50 49 48 47 46 45 44 43 42 41 40 39 38 37 36 35 34 33 32 31 30 29 28 27 26 25 24 23 22 21 20 19 18 17 16 15 14 13 12 11 10 9 8 7 6 5 4 3 2 1 
---
#0  dumpsys () at /usr/src/sys/kern/kern_shutdown.c:508
508             if (dumping++) {
dumpsys () at /usr/src/sys/kern/kern_shutdown.c:508
508             if (dumping++) {
(kgdb) bt   
#0  dumpsys () at /usr/src/sys/kern/kern_shutdown.c:508
#1  0xc01973b3 in boot (howto=260) at /usr/src/sys/kern/kern_shutdown.c:341
#2  0xc019781d in panic (fmt=0xc02dd2e1 "getnewbuf: locked buf")
    at /usr/src/sys/kern/kern_shutdown.c:620
#3  0xc01c75ce in getnewbuf (slpflag=0, slptimeo=0, size=2048, maxsize=16384)
    at /usr/src/sys/kern/vfs_bio.c:1723
#4  0xc01c8176 in getblk (vp=0xc85bfcb8, blkno=0, size=2048, slpflag=0, slptimeo=0)
    at /usr/src/sys/kern/vfs_bio.c:2367
#5  0xc01c611c in bread (vp=0xc85bfcb8, blkno=0, size=2048, bpp=0xc898b49c)
    at /usr/src/sys/kern/vfs_bio.c:567
#6  0xc025834e in ffs_balloc (ap=0xc898b504) at /usr/src/sys/vfs/ufs/ffs_balloc.c:159
#7  0xc01db964 in vop_balloc (ops=<incomplete type>, vp=0xc85bfcb8, startoffset=0, 
    size=256, cred=0xc0cf4f78, flags=2130706433, bpp=0xc898b5a4)
    at /usr/src/sys/kern/vfs_vopops.c:948
#8  0xc02618cf in ffs_write (ap=0xc898b5bc) at /usr/src/sys/vfs/ufs/ufs_readwrite.c:409
#9  0xc01db369 in vop_write (ops=<incomplete type>, vp=0xc85bfcb8, uio=0xc898b624, 
    ioflag=8323104, cred=0xc0cf4f78) at /usr/src/sys/kern/vfs_vopops.c:512
#10 0xc027b49a in vnode_pager_generic_putpages (vp=0xc85bfcb8, m=0xc898b728, 
    bytecount=4096, flags=12, rtvals=0xc898b6fc) at /usr/src/sys/vm/vnode_pager.c:1010
#11 0xc0261f2e in ffs_putpages (ap=0xc898b678)
    at /usr/src/sys/vfs/ufs/ufs_readwrite.c:646
#12 0xc01dba3b in vop_putpages (ops=<incomplete type>, vp=0xc85bfcb8, m=0xc898b728, 
    count=4096, sync=12, rtvals=0xc898b6fc, offset=0)
    at /usr/src/sys/kern/vfs_vopops.c:1003
#13 0xc027b2d8 in vnode_pager_putpages (object=0xc8910540, m=0xc898b728, count=1, 
    sync=12, rtvals=0xc898b6fc) at /usr/src/sys/vm/vnode_pager.c:903
#14 0xc027834b in vm_pageout_flush (mc=0xc898b728, count=1, flags=12)
    at /usr/src/sys/vm/vm_pager.h:146
#15 0xc0274d37 in vm_object_page_collect_flush (object=0xc8910540, p=0xc08f0140, 
    curgeneration=2, pagerflags=12) at /usr/src/sys/vm/vm_object.c:830
#16 0xc0274821 in vm_object_page_clean (object=0xc8910540, start=0, end=0, flags=4)
    at /usr/src/sys/vm/vm_object.c:609
#17 0xc01d34de in vfs_msync_scan2 (mp=<incomplete type>, vp=0xc85bfcb8, data=0x2)
    at /usr/src/sys/kern/vfs_subr.c:1643
#18 0xc01d4aa2 in vmntvnodescan (mp=0xc82d4358, flags=3, 
    fastfunc=0xc01d3408 <vfs_msync_scan1>, slowfunc=0xc01d3470 <vfs_msync_scan2>, 
    data=0x2) at /usr/src/sys/kern/vfs_mount.c:745
#19 0xc01d3406 in vfs_msync (mp=<incomplete type>, flags=2)
    at /usr/src/sys/kern/vfs_subr.c:1598
#20 0xc01d61a0 in sync (uap=0x0) at /usr/src/sys/kern/vfs_syscalls.c:627
#21 0xc019711d in boot (howto=256) at /usr/src/sys/kern/kern_shutdown.c:252
#22 0xc019781d in panic (fmt=0xc02dd2e1 "getnewbuf: locked buf")
    at /usr/src/sys/kern/kern_shutdown.c:620
#23 0xc01c75ce in getnewbuf (slpflag=0, slptimeo=0, size=16384, maxsize=16384)
    at /usr/src/sys/kern/vfs_bio.c:1723
#24 0xc01c8176 in getblk (vp=0xc8c3de18, blkno=10381, size=16384, slpflag=0, slptimeo=0)
    at /usr/src/sys/kern/vfs_bio.c:2367
#25 0xc01cbc40 in cluster_rbuild (vp=0xc8c3de18, filesize=726384544, lbn=10380, 
---Type <return> to continue, or q <return> to quit---
    blkno=4887616, size=16384, run=8, fbp=0x0) at /usr/src/sys/kern/vfs_cluster.c:388
#26 0xc01cb8ab in cluster_read (vp=0xc8c3de18, filesize=726384544, lblkno=10380, 
    size=16384, totread=16384, seqcount=127, bpp=0xc898baf4)
    at /usr/src/sys/kern/vfs_cluster.c:224
#27 0xc02613ed in ffs_read (ap=0xc898bb0c) at /usr/src/sys/vfs/ufs/ufs_readwrite.c:180
#28 0xc01db329 in vop_read (ops=<incomplete type>, vp=0xc8c3de18, uio=0xc898bbe0, 
    ioflag=8323072, cred=0xc87d0668) at /usr/src/sys/kern/vfs_vopops.c:494
#29 0xc01da81c in vn_read (fp=0xc85c1c00, uio=0xc898bbe0, cred=0xc87d0668, flags=0, 
    td=<incomplete type>) at /usr/src/sys/kern/vfs_vnops.c:550
#30 0xc01ae86f in kern_readv (fd=3, auio=0xc898bbe0, flags=0, res=0xc898bc60)
    at /usr/src/sys/sys/file2.h:60
#31 0xc01ae637 in read (uap=0xc898bc34) at /usr/src/sys/kern/sys_generic.c:121
#32 0xc02aadfa in syscall2 (frame=
      {tf_fs = 134545455, tf_es = 65583, tf_ds = -1078001617, tf_edi = 134586528, tf_esi = 65536, tf_ebp = -1077937756, tf_isp = -929514124, tf_ebx = 65536, tf_edx = 3, tf_ecx = 47, tf_eax = 3, tf_trapno = 0, tf_err = 2, tf_eip = 134524584, tf_cs = 31, tf_eflags = 659, tf_esp = -1077937848, tf_ss = 47}) at /usr/src/sys/i386/i386/trap.c:1350
#33 0xc0295cba in Xint0x80_syscall ()
#34 0x0805002f in ?? ()
#35 0x0001002f in ?? ()
#36 0xbfbf002f in ?? ()
#37 0x0805a0a0 in ?? ()
#38 0x00010000 in ?? ()
#39 0xbfbff9a4 in ?? ()
#40 0xc898bd74 in ?? ()
#41 0x00010000 in ?? ()
#42 0x00000003 in ?? ()
#43 0x0000002f in ?? ()
#44 0x00000003 in ?? ()
#45 0x00000000 in ?? ()
#46 0x00000002 in ?? ()
#47 0x0804aea8 in ?? ()
#48 0x0000001f in ?? ()
#49 0x00000293 in ?? ()
#50 0xbfbff948 in ?? ()
#51 0x0000002f in ?? ()
#52 0x00000000 in ?? ()
#53 0x00000000 in ?? ()
#54 0x00000000 in ?? ()
#55 0x00000000 in ?? ()
#56 0x015f1000 in ?? ()
#57 0x00000006 in ?? ()
#58 0xff808000 in ?? ()
#59 0xc898b9b8 in ?? ()
#60 0xc898b998 in ?? ()
#61 0xff808364 in ?? ()
#62 0xc019c8ea in lwkt_switch () at /usr/src/sys/kern/lwkt_thread.c:643
Previous frame inner to this frame (corrupt stack?)
(kgdb) f 23
#23 0xc01c75ce in getnewbuf (slpflag=0, slptimeo=0, size=16384, maxsize=16384)
    at /usr/src/sys/kern/vfs_bio.c:1723
1723                            panic("getnewbuf: locked buf");
(kgdb) info locals
qindex = 4
bp = (struct buf *) 0xc0d98650
nbp = (struct buf *) 0x10
defrag = 0
nqindex = 4
flushingbufs = 0
(kgdb) p *bp
$1 = {b_hash = {le_next = 0xc0d66ed8, le_prev = 0xc034fc10}, b_vnbufs = {tqe_next = 0x0, 
    tqe_prev = 0xc0dbe1b0}, b_freelist = {tqe_next = 0xc0d66ed8, tqe_prev = 0xc031e360}, 
  b_act = {tqe_next = 0xc0d77a40, tqe_prev = 0xc82b21dc}, b_flags = 269492768, 
  b_qindex = 4, b_xflags = 0 '\0', b_lock = {lk_interlock = {t_cpu = 0xff808000, 
      t_reqcpu = 0xff808000, t_unused01 = 0}, lk_flags = 1024, lk_sharecount = 0, 
    lk_waitcount = 0, lk_exclusivecount = 1, lk_prio = 0, 
    lk_wmesg = 0xc02dce85 "bufwait", lk_timo = 0, lk_lockholder = 0xfffffffe}, 
  b_error = 0, b_bufsize = 0, b_runningbufspace = 0, b_bcount = 16384, b_resid = 0, 
can not access 0xc236c000, invalid address (c236c000)
can not access 0xc236c000, invalid address (c236c000)
can not access 0xc236c000, invalid address (c236c000)
can not access 0xc236c000, invalid address (c236c000)
can not access 0xc236c000, invalid address (c236c000)
can not access 0xc236c000, invalid address (c236c000)
  b_dev = 0xffffffff, b_data = 0xc236c000 <Address 0xc236c000 out of bounds>, 
can not access 0xc236c000, invalid address (c236c000)
can not access 0xc236c000, invalid address (c236c000)
can not access 0xc236c000, invalid address (c236c000)
can not access 0xc236c000, invalid address (c236c000)
can not access 0xc236c000, invalid address (c236c000)
can not access 0xc236c000, invalid address (c236c000)
  b_kvabase = 0xc236c000 <Address 0xc236c000 out of bounds>, b_kvasize = 16384, 
  b_lblkno = 10377, b_blkno = 4887520, b_offset = 170016768, b_iodone = 0, 
  b_iodone_chain = 0x0, b_vp = 0x0, b_dirtyoff = 0, b_dirtyend = 0, b_pblkno = 5248351, 
  b_saveaddr = 0x0, b_driver1 = 0x0, b_caller1 = 0x0, b_pager = {pg_spc = 0x0, 
    pg_reqpage = 0}, b_cluster = {cluster_head = {tqh_first = 0x0, 
      tqh_last = 0xc0dbe254}, cluster_entry = {tqe_next = 0x0, tqe_prev = 0xc0dbe254}}, 
  b_xio = {xio_pages = 0xc0d9871c, xio_npages = 0, xio_offset = 0, xio_bytes = 0, 
    xio_flags = 0, xio_error = 0, xio_internal_pages = {0x0 <repeats 32 times>}}, 
  b_dep = {lh_first = 0x0}, b_chain = {parent = 0x0, count = 0}}
(kgdb) 
$2 = {b_hash = {le_next = 0xc0d66ed8, le_prev = 0xc034fc10}, b_vnbufs = {tqe_next = 0x0, 
    tqe_prev = 0xc0dbe1b0}, b_freelist = {tqe_next = 0xc0d66ed8, tqe_prev = 0xc031e360}, 
  b_act = {tqe_next = 0xc0d77a40, tqe_prev = 0xc82b21dc}, b_flags = 269492768, 
  b_qindex = 4, b_xflags = 0 '\0', b_lock = {lk_interlock = {t_cpu = 0xff808000, 
      t_reqcpu = 0xff808000, t_unused01 = 0}, lk_flags = 1024, lk_sharecount = 0, 
    lk_waitcount = 0, lk_exclusivecount = 1, lk_prio = 0, 
    lk_wmesg = 0xc02dce85 "bufwait", lk_timo = 0, lk_lockholder = 0xfffffffe}, 
  b_error = 0, b_bufsize = 0, b_runningbufspace = 0, b_bcount = 16384, b_resid = 0, 
can not access 0xc236c000, invalid address (c236c000)
can not access 0xc236c000, invalid address (c236c000)
can not access 0xc236c000, invalid address (c236c000)
can not access 0xc236c000, invalid address (c236c000)
can not access 0xc236c000, invalid address (c236c000)
can not access 0xc236c000, invalid address (c236c000)
  b_dev = 0xffffffff, b_data = 0xc236c000 <Address 0xc236c000 out of bounds>, 
can not access 0xc236c000, invalid address (c236c000)
can not access 0xc236c000, invalid address (c236c000)
can not access 0xc236c000, invalid address (c236c000)
can not access 0xc236c000, invalid address (c236c000)
can not access 0xc236c000, invalid address (c236c000)
can not access 0xc236c000, invalid address (c236c000)
  b_kvabase = 0xc236c000 <Address 0xc236c000 out of bounds>, b_kvasize = 16384, 
  b_lblkno = 10377, b_blkno = 4887520, b_offset = 170016768, b_iodone = 0, 
  b_iodone_chain = 0x0, b_vp = 0x0, b_dirtyoff = 0, b_dirtyend = 0, b_pblkno = 5248351, 
  b_saveaddr = 0x0, b_driver1 = 0x0, b_caller1 = 0x0, b_pager = {pg_spc = 0x0, 
    pg_reqpage = 0}, b_cluster = {cluster_head = {tqh_first = 0x0, 
      tqh_last = 0xc0dbe254}, cluster_entry = {tqe_next = 0x0, tqe_prev = 0xc0dbe254}}, 
  b_xio = {xio_pages = 0xc0d9871c, xio_npages = 0, xio_offset = 0, xio_bytes = 0, 
    xio_flags = 0, xio_error = 0, xio_internal_pages = {0x0 <repeats 32 times>}}, 
  b_dep = {lh_first = 0x0}, b_chain = {parent = 0x0, count = 0}}