From owner-freebsd-current@FreeBSD.ORG Fri Jun 6 19:11:01 2008 Return-Path: Delivered-To: freebsd-current@freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:4f8:fff6::34]) by hub.freebsd.org (Postfix) with ESMTP id D9CD1106567F for ; Fri, 6 Jun 2008 19:11:01 +0000 (UTC) (envelope-from gbell72@rogers.com) Received: from web88002.mail.re2.yahoo.com (web88002.mail.re2.yahoo.com [206.190.37.189]) by mx1.freebsd.org (Postfix) with SMTP id 7E1238FC17 for ; Fri, 6 Jun 2008 19:11:01 +0000 (UTC) (envelope-from gbell72@rogers.com) Received: (qmail 22932 invoked by uid 60001); 6 Jun 2008 19:11:00 -0000 DomainKey-Signature: a=rsa-sha1; q=dns; c=nofws; s=s1024; d=rogers.com; h=X-YMail-OSG:Received:Date:From:Subject:To:MIME-Version:Content-Type:Content-Transfer-Encoding:Message-ID; b=JEqdoPx5vj1qs/Y805pV/wWceOyQejfOMmpWimSzEXCfJISGfkABiBpNuNZfDKeLnZmMYjAJtyvzN4Xbsexrah9hobW2a50GKQg4Vy6UibDReqysJNcpsTmZzQJojjCvL8lHAFGZPq5Qj23T1idOwBumZYePcjfIkueIogtPnCQ=; X-YMail-OSG: Eiu1MwUVM1lFMfa94jyK37Fb4uADLehtpCTrmRN.bR6mAbdoSyLAE2Uz6XD3nGyqySOEUWmtvZ1EhwefoZbUvQaHA9JYaTiJIrIRBg-- Received: from [99.233.178.192] by web88002.mail.re2.yahoo.com via HTTP; Fri, 06 Jun 2008 15:11:00 EDT Date: Fri, 6 Jun 2008 15:11:00 -0400 (EDT) From: Gardner Bell To: freebsd-current@freebsd.org MIME-Version: 1.0 Content-Type: text/plain; charset=iso-8859-1 Content-Transfer-Encoding: 8bit Message-ID: <509906.20720.qm@web88002.mail.re2.yahoo.com> X-Mailman-Approved-At: Fri, 06 Jun 2008 21:48:10 +0000 Subject: calcru: runtime went backwards X-BeenThere: freebsd-current@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list List-Id: Discussions about the use of FreeBSD-current List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Fri, 06 Jun 2008 19:11:01 -0000 Hello, I'm seeing the following printed on my screen after my system became unresponsive while background fsck was running for ~10 mins or so. Previous to this, my machine crashed after a power outage in my neighborhood. Copyright (c) 1992-2008 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 is a registered trademark of The FreeBSD Foundation. FreeBSD 8.0-CURRENT #0: Wed May 28 10:43:47 EDT 2008 root@home:/usr/obj/usr/src/sys/TYAN lock order reversal: 1st 0xffffff0001282430 snaplk (snaplk) @ /usr/src/sys/kern/vfs_vnops.c:292 2nd 0xffffff0001750270 ufs (ufs) @ /usr/src/sys/ufs/ffs/ffs_snapshot.c:1578 KDB: stack backtrace: db_trace_self_wrapper() at db_trace_self_wrapper+0x2a witness_checkorder() at witness_checkorder+0x665 __lockmgr_args() at __lockmgr_args+0x521 ffs_snapremove() at ffs_snapremove+0xe7 softdep_releasefile() at softdep_releasefile+0x139 ufs_inactive() at ufs_inactive+0x1ea vinactive() at vinactive+0x72 vput() at vput+0x22b vn_close() at vn_close+0xbb vn_closefile() at vn_closefile+0x80 _fdrop() at _fdrop+0x23 closef() at closef+0x1e2 kern_close() at kern_close+0x10c syscall() at syscall+0x1bf Xfast_syscall() at Xfast_syscall+0xab --- syscall (6, FreeBSD ELF64, close), rip = 0x80081789c, rsp = 0x7ffffffee6b8, rbp = 0x80 --- KDB: enter: witness_checkorder exclusive lockmgr snaplk r = 0 (0xffffff0001282430) locked @ /usr/src/sys/kern/vfs_vnops.c:292 exclusive lockmgr snaplk r = 0 (0xffffff0001282430) locked @ /usr/src/sys/kern/vfs_vnops.c:292 0xffffff00013c01d8: tag ufs, type VREG usecount 1, writecount 0, refcount 2 mountedhere 0 flags (VV_SYSTEM) lock type snaplk: EXCL by thread 0xffffff0001289360 (pid 1013) ino 5, on dev ad0s1h 0xffffff00013c0000: tag ufs, type VREG usecount 1, writecount 0, refcount 1569 mountedhere 0 flags (VV_SYSTEM) lock type snaplk: EXCL by thread 0xffffff0001289360 (pid 1013) ino 6, on dev ad0s1h 0xffffff0001382ce8: tag ufs, type VREG usecount 1, writecount 0, refcount 1736 mountedhere 0 flags (VV_SYSTEM) lock type snaplk: EXCL by thread 0xffffff0001289360 (pid 1013) ino 4, on dev ad0s1h 0xffffff0001382b10: tag ufs, type VREG usecount 1, writecount 0, refcount 1736 mountedhere 0 flags (VV_SYSTEM) lock type snaplk: EXCL by thread 0xffffff0001289360 (pid 1013) ino 7, on dev ad0s1h 0xffffff00017501d8: tag ufs, type VREG usecount 0, writecount 0, refcount 2063 mountedhere 0 flags (VV_SYSTEM|VI_DOINGINACT) v_object 0xffffff0001739bb8 ref 0 pages 80 lock type snaplk: EXCL by thread 0xffffff0001289360 (pid 1013) ino 8, on dev ad0s1h 0xffffff00013c01d8: tag ufs, type VREG usecount 1, writecount 0, refcount 2 mountedhere 0 flags (VV_SYSTEM) lock type snaplk: EXCL by thread 0xffffff0001289360 (pid 1013) ino 5, on dev ad0s1h 0xffffff00013c0000: tag ufs, type VREG usecount 1, writecount 0, refcount 1569 mountedhere 0 flags (VV_SYSTEM) lock type snaplk: EXCL by thread 0xffffff0001289360 (pid 1013) ino 6, on dev ad0s1h 0xffffff0001382ce8: tag ufs, type VREG usecount 1, writecount 0, refcount 1736 mountedhere 0 flags (VV_SYSTEM) lock type snaplk: EXCL by thread 0xffffff0001289360 (pid 1013) ino 4, on dev ad0s1h 0xffffff0001382b10: tag ufs, type VREG usecount 1, writecount 0, refcount 1736 mountedhere 0 flags (VV_SYSTEM) lock type snaplk: EXCL by thread 0xffffff0001289360 (pid 1013) ino 7, on dev ad0s1h 0xffffff00017501d8: tag ufs, type VREG usecount 0, writecount 0, refcount 2063 mountedhere 0 flags (VV_SYSTEM|VI_DOINGINACT) v_object 0xffffff0001739bb8 ref 0 pages 80 lock type snaplk: EXCL by thread 0xffffff0001289360 (pid 1013) ino 8, on dev ad0s1h exclusive lockmgr snaplk r = 0 (0xffffff0001282430) locked @ /usr/src/sys/kern/vfs_vnops.c:292 exclusive lockmgr snaplk r = 0 (0xffffff0001282430) locked @ /usr/src/sys/kern/vfs_vnops.c:292 calcru: runtime went backwards from 33275 usec to 290 usec for pid 999 (csh) calcru: runtime went backwards from 469322 usec to 3929 usec for pid 999 (csh) calcru: runtime went backwards from 13323 usec to 109 usec for pid 998 (su) calcru: runtime went backwards from 22204 usec to 182 usec for pid 996 (csh) calcru: runtime went backwards from 931 usec to 7 usec for pid 996 (csh) calcru: runtime went backwards from 7439 usec to 63 usec for pid 995 (getty) calcru: runtime went backwards from 7745 usec to 63 usec for pid 994 (getty) calcru: runtime went backwards from 24782 usec to 204 usec for pid 993 (login) calcru: runtime went backwards from 6403 usec to 58 usec for pid 937 (cron) calcru: runtime went backwards from 23019 usec to 258 usec for pid 910 (ntpd) calcru: runtime went backwards from 11411 usec to 127 usec for pid 809 (syslogd) calcru: runtime went backwards from 1536 usec to 12 usec for pid 742 (natd) calcru: runtime went backwards from 376 usec to 3 usec for pid 686 (devd) calcru: runtime went backwards from 1019 usec to 8 usec for pid 140 (adjkerntz) calcru: runtime went backwards from 6097 usec to 1477 usec for pid 20 (softdepflush) calcru: runtime went backwards from 26107 usec to 404 usec for pid 19 (syncer) calcru: runtime went backwards from 10580 usec to 99 usec for pid 18 (vnlru) calcru: runtime went backwards from 1251 usec to 19 usec for pid 9 (bufdaemon) calcru: runtime went backwards from 8 usec to 0 usec for pid 8 (pagezero) calcru: runtime went backwards from 18 usec to 0 usec for pid 7 (vmdaemon) calcru: runtime went backwards from 508 usec to 6 usec for pid 6 (pagedaemon) calcru: runtime went backwards from 39 usec to 0 usec for pid 17 (usb1) calcru: runtime went backwards from 73 usec to 0 usec for pid 14 (usb0) calcru: runtime went backwards from 17290 usec to 285 usec for pid 13 (yarrow) calcru: runtime went backwards from 287038 usec to 4917 usec for pid 4 (g_down) calcru: runtime went backwards from 355326 usec to 5779 usec for pid 3 (g_up) calcru: runtime went backwards from 19316 usec to 251 usec for pid 2 (g_event) calcru: runtime went backwards from 313682281 usec to 5240711 usec for pid 11 (idle) calcru: runtime went backwards from 432516 usec to 3561 usec for pid 1 (init) calcru: runtime went backwards from 11606 usec to 95 usec for pid 0 (kernel)