panic: vn_finished_write: neg cnt

Tim Zingelman zingelman at fnal.gov
Tue Jan 2 08:56:07 PST 2007


# cd /usr/obj/usr/src/sys/SMP/
# kgdb kernel.debug /var/crash/vmcore.0
[GDB will not be able to debug user-mode threads:
/usr/lib/libthread_db.so: Undefined symbol "ps_pglobal_lookup"]
GNU gdb 6.1.1 [FreeBSD]
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-marcel-freebsd".

Unread portion of the kernel message buffer:
panic: vn_finished_write: neg cnt
cpuid = 1
Uptime: 4d21h14m32s
Dumping 2047 MB (2 chunks)
  chunk 0: 1MB (159 pages) ... ok
  chunk 1: 2047MB (524016 pages) 2031 2015 1999 1983 1967 1951 1935 1919 1903 1887 1871 1855 1839 1823 1807 1791 1775 1759 1743 1727 1711 1695 1679 1663 1647 1631 1615 1599 1583 1567 1551 1535 1519 1503 1487 1471 1455 1439 1423 1407 1391 1375 1359 1343 1327 1311 1295 1279 1263 1247 1231 1215 1199 1183 1167 1151 1135 1119 1103 1087 1071 1055 1039 1023 1007 991 975 959 943 927 911 895 879 863 847 831 815 799 783 767 751 735 719 703 687 671 655 639 623 607 591 575 559 543 527 511 495 479 463 447 431 415 399 383 367 351 335 319 303 287 271 255 239 223 207 191 175 159 143 127 111 95 79 63 47 31 15

#0  doadump () at pcpu.h:165
165             __asm __volatile("movl %%fs:0,%0" : "=r" (td));
(kgdb) backtrace
#0  doadump () at pcpu.h:165
#1  0xc06754ea in boot (howto=260) at /usr/src/sys/kern/kern_shutdown.c:409
#2  0xc0675811 in panic (fmt=0xc090613a "vn_finished_write: neg cnt")
    at /usr/src/sys/kern/kern_shutdown.c:565
#3  0xc06dc82f in vn_finished_write (mp=0xc675d530)
    at /usr/src/sys/kern/vfs_vnops.c:1048
#4  0xc06dbb68 in vn_write (fp=0xccded2d0, uio=0xea002cbc,
    active_cred=0xc6e5a580, flags=0, td=0xc8623900)
    at /usr/src/sys/kern/vfs_vnops.c:583
#5  0xc0698f43 in dofilewrite (td=0xc8623900, fd=11, fp=0xccded2d0,
    auio=0xea002cbc, offset=Unhandled dwarf expression opcode 0x93
) at file.h:252
#6  0xc0698de7 in kern_writev (td=0xc8623900, fd=11, auio=0xea002cbc)
    at /usr/src/sys/kern/sys_generic.c:402
#7  0xc0698d0d in write (td=0xc8623900, uap=0x0)
    at /usr/src/sys/kern/sys_generic.c:326
#8  0xc088e583 in syscall (frame=
      {tf_fs = 59, tf_es = 59, tf_ds = 59, tf_edi = 134973792, tf_esi = 135065600, tf_ebp = -1077968696, tf_isp = -369087132, tf_ebx = 4096, tf_edx = 4096, tf_ecx = 0, tf_eax = 4, tf_trapno = 4096, tf_err = 2, tf_eip = 134840319, tf_cs = 51, tf_eflags = 582, tf_esp = -1077968756, tf_ss = 59})
    at /usr/src/sys/i386/i386/trap.c:983
#9  0xc0879d3f in Xint0x80_syscall () at /usr/src/sys/i386/i386/exception.s:200
#10 0x00000033 in ?? ()
Previous frame inner to this frame (corrupt stack?)
(kgdb) up 3
#3  0xc06dc82f in vn_finished_write (mp=0xc675d530)
    at /usr/src/sys/kern/vfs_vnops.c:1048
1048                    panic("vn_finished_write: neg cnt");
(kgdb) list
1043            if (mp == NULL)
1044                    return;
1045            MNT_ILOCK(mp);
1046            mp->mnt_writeopcount--;
1047            if (mp->mnt_writeopcount < 0)
1048                    panic("vn_finished_write: neg cnt");
1049            if ((mp->mnt_kern_flag & MNTK_SUSPEND) != 0 &&
1050                mp->mnt_writeopcount <= 0)
1051                    wakeup(&mp->mnt_writeopcount);
1052            MNT_IUNLOCK(mp);
(kgdb) print *mp
$1 = {mnt_list = {tqe_next = 0xc675d298, tqe_prev = 0xc675d7c8},
  mnt_op = 0xc09ae620, mnt_vfc = 0xc09ae660, mnt_vnodecovered = 0xc6794660,
  mnt_syncer = 0xc694b660, mnt_nvnodelist = {tqh_first = 0xc7595330,
    tqh_last = 0xcab48014}, mnt_lock = {lk_interlock = 0xc09dceb8,
    lk_flags = 0, lk_sharecount = 0, lk_waitcount = 0, lk_exclusivecount = 0,
    lk_prio = 80, lk_wmesg = 0xc09056c9 "vfslock", lk_timo = 0,
    lk_lockholder = 0xffffffff, lk_newlock = 0x0}, mnt_mtx = {mtx_object = {
      lo_class = 0xc09750e4, lo_name = 0xc09056b8 "struct mount mtx",
      lo_type = 0xc09056b8 "struct mount mtx", lo_flags = 196608, lo_list = {
        tqe_next = 0x0, tqe_prev = 0x0}, lo_witness = 0x0},
    mtx_lock = 3361880322, mtx_recurse = 0}, mnt_writeopcount = -1,
  mnt_flag = 2101504, mnt_opt = 0xc68098e0, mnt_optnew = 0x0,
  mnt_kern_flag = 536870912, mnt_maxsymlinklen = 120, mnt_stat = {
    f_version = 537068824, f_type = 7, f_flags = 2101504, f_bsize = 2048,
    f_iosize = 16384, f_blocks = 292488222, f_bfree = 188891807,
    f_bavail = 165492750, f_files = 75601918, f_ffree = 66247979,
    f_syncwrites = 0, f_asyncwrites = 0, f_syncreads = 0, f_asyncreads = 0,
    f_spare = {0, 0, 0, 0, 0, 0, 0, 0, 0, 0}, f_namemax = 255, f_owner = 0,
    f_fsid = {val = {1164144299, -1500130876}},
    f_charspare = '\0' <repeats 79 times>,
    f_fstypename = "ufs", '\0' <repeats 12 times>,
    f_mntfromname = "/dev/da0s1f", '\0' <repeats 76 times>,
    f_mntonname = "/usr", '\0' <repeats 83 times>}, mnt_cred = 0xc695ad00,
  mnt_data = 0xc6749b00, mnt_time = 0, mnt_iosize_max = 131072,
  mnt_export = 0xc674cc00, mnt_mntlabel = 0x0, mnt_fslabel = 0x0,
  mnt_nvnodelistsize = 58931, mnt_hashseed = 3969027219, mnt_markercnt = 0,
  mnt_holdcnt = 0, mnt_holdcntwaiters = 0, mnt_secondary_writes = 0,
  mnt_secondary_accwrites = 504046284, mnt_ref = 58931, mnt_gen = 1}
(kgdb) up
#4  0xc06dbb68 in vn_write (fp=0xccded2d0, uio=0xea002cbc,
    active_cred=0xc6e5a580, flags=0, td=0xc8623900)
    at /usr/src/sys/kern/vfs_vnops.c:583
583                     vn_finished_write(mp);
(kgdb) list
578             if ((flags & FOF_OFFSET) == 0)
579                     fp->f_offset = uio->uio_offset;
580             fp->f_nextoff = uio->uio_offset;
581             VOP_UNLOCK(vp, 0, td);
582             if (vp->v_type != VCHR)
583                     vn_finished_write(mp);
584     unlock:
585             VFS_UNLOCK_GIANT(vfslocked);
586             return (error);
587     }
(kgdb) print flags
$5 = 0
(kgdb) print *uio
$6 = {uio_iov = 0xea002cb4, uio_iovcnt = 1, uio_offset = 1245192,
  uio_resid = 0, uio_segflg = UIO_USERSPACE, uio_rw = UIO_WRITE,
  uio_td = 0xc8623900}
(kgdb) print *vp
$3 = {v_type = VREG, v_tag = 0xc0904786 "ufs", v_op = 0xc09ae980,
  v_data = 0xcce7edec, v_mount = 0xc675d530, v_nmntvnodes = {
    tqe_next = 0xcd9dc660, tqe_prev = 0xc7902014}, v_un = {vu_mount = 0x0,
    vu_socket = 0x0, vu_cdev = 0x0, vu_fifoinfo = 0x0}, v_hashlist = {
    le_next = 0xcda56770, le_prev = 0xc65f5b14}, v_hash = 26239538,
  v_cache_src = {lh_first = 0x0}, v_cache_dst = {tqh_first = 0xc86c3594,
    tqh_last = 0xc86c35a4}, v_dd = 0x0, v_cstart = 72, v_lasta = 419301280,
  v_lastw = 75, v_clen = 7, v_lock = {lk_interlock = 0xc09dd218,
    lk_flags = 64, lk_sharecount = 0, lk_waitcount = 0, lk_exclusivecount = 0,
    lk_prio = 80, lk_wmesg = 0xc0904786 "ufs", lk_timo = 51,
    lk_lockholder = 0xffffffff, lk_newlock = 0x0}, v_interlock = {
    mtx_object = {lo_class = 0xc09750e4,
      lo_name = 0xc0905d01 "vnode interlock",
      lo_type = 0xc0905d01 "vnode interlock", lo_flags = 196608, lo_list = {
        tqe_next = 0x0, tqe_prev = 0x0}, lo_witness = 0x0}, mtx_lock = 4,
    mtx_recurse = 0}, v_vnlock = 0xc8de09e8, v_holdcnt = 80, v_usecount = 1,
  v_iflag = 0, v_vflag = 0, v_writecount = 1, v_freelist = {tqe_next = 0x0,
    tqe_prev = 0x0}, v_bufobj = {bo_mtx = 0xc8de0a0c, bo_clean = {bv_hd = {
        tqh_first = 0xda668910, tqh_last = 0xda524060}, bv_root = 0xda524028,
      bv_cnt = 72}, bo_dirty = {bv_hd = {tqh_first = 0xda6651f8,
        tqh_last = 0xda560670}, bv_root = 0xda560638, bv_cnt = 6},
    bo_numoutput = 0, bo_flag = 1, bo_ops = 0xc097b364, bo_bsize = 16384,
    bo_object = 0xcd26c39c, bo_synclist = {le_next = 0xca39c3f0,
      le_prev = 0xcab480f8}, bo_private = 0xc8de0990,
    __bo_vnode = 0xc8de0990}, v_pollinfo = 0x0, v_label = 0x0}
(kgdb) print *td
$7 = {td_proc = 0xcda11430, td_ksegrp = 0xcd9f2ba0, td_plist = {
    tqe_next = 0x0, tqe_prev = 0xcda11440}, td_kglist = {tqe_next = 0x0,
    tqe_prev = 0xcd9f2bac}, td_slpq = {tqe_next = 0x0, tqe_prev = 0xc7b0a880},
  td_lockq = {tqe_next = 0x0, tqe_prev = 0xe9fdbb1c}, td_runq = {
    tqe_next = 0x0, tqe_prev = 0x0}, td_selq = {tqh_first = 0x0,
    tqh_last = 0xc8623930}, td_sleepqueue = 0xc7b0a880,
  td_turnstile = 0xc8072280, td_umtxq = 0xc72a8800, td_tid = 101129,
  td_flags = 83951619, td_inhibitors = 0, td_pflags = 0, td_dupfd = 0,
  td_wchan = 0x0, td_wmesg = 0x0, td_lastcpu = 1 '\001', td_oncpu = 0 '\0',
  td_owepreempt = 0 '\0', td_locks = 3, td_blocked = 0x0, td_ithd = 0x0,
  td_lockname = 0x0, td_contested = {lh_first = 0xcd213c00},
  td_sleeplocks = 0x0, td_intr_nesting_level = 0, td_pinned = 0,
  td_mailbox = 0x0, td_ucred = 0xc6e5a580, td_standin = 0x0, td_upcall = 0x0,
  td_sticks = 2330, td_uuticks = 0, td_usticks = 0, td_intrval = 0,
  td_oldsigmask = {__bits = {0, 0, 0, 0}}, td_sigmask = {__bits = {0, 0, 0,
      0}}, td_siglist = {__bits = {0, 0, 0, 0}}, td_generation = 451,
  td_sigstk = {ss_sp = 0x0, ss_size = 0, ss_flags = 4}, td_kflags = 0,
  td_xsig = 0, td_profil_addr = 0, td_profil_ticks = 0, td_base_pri = 216 'X',
  td_priority = 211 'S', td_pcb = 0xea002d90, td_state = TDS_RUNNING,
  td_retval = {0, 4096}, td_slpcallout = {c_links = {sle = {sle_next = 0x0},
      tqe = {tqe_next = 0x0, tqe_prev = 0xda412da8}}, c_time = 422055083,
    c_arg = 0xc8623900, c_func = 0xc0695340 <sleepq_timeout>, c_mtx = 0x0,
    c_flags = 18}, td_frame = 0xea002d38, td_kstack_obj = 0xcd578738,
  td_kstack = 3925872640, td_kstack_pages = 2, td_altkstack_obj = 0x0,
  td_altkstack = 0, td_altkstack_pages = 0, td_critnest = 1, td_md = {
    md_spinlock_count = 1, md_saved_flags = 582}, td_sched = 0xc8623a58,
  td_ar = 0x0}
(kgdb) print *fp
$4 = {f_list = {le_next = 0xce1440d8, le_prev = 0xc6801900}, f_type = 1,
  f_data = 0xc8de0990, f_flag = 3, f_mtxp = 0xc63dbd00, f_ops = 0xc097cfe0,
  f_cred = 0xc6e5a580, f_count = 2, f_vnode = 0xc8de0990, f_offset = 1245192,
  f_vnread_flags = 0, f_gcflag = 0, f_msgcount = 0, f_seqcount = 127,
  f_nextoff = 1245192, f_label = 0x0}

What other info might be of use?

System was doing a buildworld -j26 and downloading a port distfile at the
time of the crash.

System has been attempting to build a package for every port in the tree
while looping over buildworld with various large -j numbers to try and
prove the system is stable.

Twice I have seen:
 twa0: WARNING: (0x04: 0x0036): Verify fixed data/parity mismatch: unit=2
a couple of times... but nothing else.

Here is the interesting part of the dmesg output... more details available
if anyone wants to look at this.

FreeBSD 6.2-RC2 #3: Wed Dec 27 15:22:35 CST 2006
    toor at host.name.xyz:/usr/obj/usr/src/sys/SMP
Timecounter "i8254" frequency 1193182 Hz quality 0
CPU: Dual Core AMD Opteron(tm) Processor 280 (2393.19-MHz 686-class CPU)
  Origin = "AuthenticAMD"  Id = 0x20f12  Stepping = 2

Features=0x178bfbff<FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CLFLUSH,MMX,FXSR,SSE,SSE2,HTT>
  Features2=0x1<SSE3>
  AMD Features=0xe2500800<SYSCALL,NX,MMX+,FFXSR,LM,3DNow+,3DNow>
  AMD Features2=0x3<LAHF,CMP>
  Cores per package: 2
real memory  = 2147418112 (2047 MB)
avail memory = 2096295936 (1999 MB)
ACPI APIC Table: <A M I  OEMAPIC >
FreeBSD/SMP: Multiprocessor System Detected: 4 CPUs
 cpu0 (BSP): APIC ID:  0
 cpu1 (AP): APIC ID:  1
 cpu2 (AP): APIC ID:  2
 cpu3 (AP): APIC ID:  3
MADT: Forcing active-low polarity and level trigger for SCI
ioapic0 <Version 1.1> irqs 0-23 on motherboard
ioapic1 <Version 1.1> irqs 24-27 on motherboard
ioapic2 <Version 1.1> irqs 28-31 on motherboard
kbd1 at kbdmux0
ath_hal: 0.9.17.2 (AR5210, AR5211, AR5212, RF5111, RF5112, RF2413, RF5413)
acpi0: <A M I OEMRSDT> on motherboard
acpi0: Power Button (fixed)
Timecounter "ACPI-fast" frequency 3579545 Hz quality 1000
acpi_timer0: <24-bit timer at 3.579545MHz> port 0x5008-0x500b on acpi0

bge0: <Broadcom BCM5704 B0, ASIC rev. 0x2100> mem 0xfc9e0000-0xfc9effff
irq 26 at device 5.0 on pci2
miibus0: <MII bus> on bge0
brgphy0: <BCM5704 10/100/1000baseTX PHY> on miibus0
brgphy0:  10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, 1000baseTX,
1000baseTX-FDX, auto
bge0: Ethernet address: 00:30:48:5a:8f:92
bge1: <Broadcom BCM5704 B0, ASIC rev. 0x2100> mem 0xfc9b0000-0xfc9bffff
irq 27 at device 5.1 on pci2
miibus1: <MII bus> on bge1
brgphy1: <BCM5704 10/100/1000baseTX PHY> on miibus1
brgphy1:  10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, 1000baseTX,
1000baseTX-FDX, auto
bge1: Ethernet address: 00:30:48:5a:8f:93

3ware device driver for 9000 series storage controllers, version:
3.60.02.012
twa0: <3ware 9000 series Storage Controller> port 0xac00-0xac3f mem
0xfa000000-0xfbffffff,0xfc8ff000-0xfc8fffff irq 29 at device 3.0 on pci1
twa0: [FAST]
twa0: INFO: (0x04: 0x0053): Battery capacity test is overdue:
twa0: INFO: (0x15: 0x1300): Controller details:: Model 9550SX-12MI, 12
ports, Firmware FE9X 3.04.00.005, BIOS BE9X 3.04.00.002

da0 at twa0 bus 0 target 2 lun 0
da0: <AMCC 9550SX-12M DISK 3.04> Fixed Direct Access SCSI-3 device
da0: 100.000MB/s transfers
da0: 915495MB (1874933760 512 byte sectors: 255H 63S/T 116709C)
SMP: AP CPU #1 Launched!
SMP: AP CPU #3 Launched!
SMP: AP CPU #2 Launched!
Trying to mount root from ufs:/dev/da0s1a
bge0: link state changed to UP
vmmon: SMP support for this release is BROKEN.
module_register_init: MOD_LOAD (vmmon, 0xc6c020b4, 0) error 22
vmnet1: Ethernet address: 00:bd:a0:4f:00:01

(note that vmmon is not used, just loaded because I've been building
 packages for the whole ports tree to burn in this box)


More information about the freebsd-stable mailing list