From owner-freebsd-current Sat Jun 9 14:26:22 2001 Delivered-To: freebsd-current@freebsd.org Received: from kyle.tandemedia.com (kyle.tandemedia.com [216.29.169.3]) by hub.freebsd.org (Postfix) with ESMTP id 37BCF37B401 for ; Sat, 9 Jun 2001 14:26:11 -0700 (PDT) (envelope-from rmtodd@ichotolot.servalan.com) Received: by kyle.tandemedia.com (Postfix, from userid 66) id 0486355401; Sat, 9 Jun 2001 17:26:09 -0400 (EDT) Received: from ichotolot.servalan.com([127.0.0.1]) (18103 bytes) by servalan.servalan.com via sendmail with P:esmtp/R:smart_host/T:hacked-uux (sender: ) id for ; Sat, 9 Jun 2001 16:12:04 -0500 (CDT) (Smail-3.2.0.111 2000-Feb-17 #1 built 2001-Jan-15) Message-Id: To: current@freebsd.org Subject: Couple "Giant not locked" at vm_object.c:261 panics I had today.... Date: Sat, 09 Jun 2001 16:12:03 -0500 From: Richard Todd Sender: owner-freebsd-current@FreeBSD.ORG Precedence: bulk List-ID: List-Archive: (Web Archive) List-Help: (List Instructions) List-Subscribe: List-Unsubscribe: X-Loop: FreeBSD.ORG Backtraces posted here in hopes they might enlighten someone. This is with kernel source from June 6 (specifically, "Sticky Date: 2001.06.06.22.16.24" according to cvs status). The machine is a dual PII/400; dmesg follows the backtraces from the two panics. If you want more information from these two core files, please let me know. Note that the first panic is somewhat muddled by the fact that, while syncing disks from the vm_object.c panic, it apparently paniced again with "Giant locked" at i386/trap.c:1153. That probably confuses the issue greatly. P.S. Stupid -current question: How does one tell what process was running that triggered a panic? This used to be findable with "p *curproc" in gdb, but that doesn't seem to work anymore. Script started on Sat Jun 9 16:02:27 2001 You have mail. ichotolot# gdb -k kernel.debug vmcore.19 GNU gdb 4.18 Copyright 1998 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-unknown-freebsd"... IdlePTD 6516736 initial pcb at 529440 panicstr: witness_restore: lock (sleep mutex) Giant not locked panic messages: --- panic: mutex Giant not owned at ../../vm/vm_object.c:261 cpuid = 1; lapic.id = 01000000 boot() called on cpu#1 syncing disks... exclusive (sleep mutex) Giant (0xc0576ca0) locked @ ../../i386/i386/trap.c:1153 exclusive (spin mutex) sched lock (0xc05763e0) locked @ ../../kern/kern_mutex.c:312 panic: witness_restore: lock (sleep mutex) Giant not locked cpuid = 1; lapic.id = 01000000 boot() called on cpu#1 Uptime: 2d2h35m38s dumping to dev da0s2b, offset 270336 dump 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 ../../kern/kern_shutdown.c:478 478 if (dumping++) { (kgdb) p curproc No symbol "curproc" in current context. (kgdb) bt #0 dumpsys () at ../../kern/kern_shutdown.c:478 #1 0xc026b35f in boot (howto=260) at ../../kern/kern_shutdown.c:321 #2 0xc026b7d1 in panic (fmt=0xc0488ae5 "%s: lock (%s) %s not locked") at ../../kern/kern_shutdown.c:600 #3 0xc02878a5 in witness_restore (lock=0xc0576ca0, file=0xc048bc20 "../../kern/vfs_bio.c", line=1827) at ../../kern/subr_witness.c:1297 #4 0xc0273836 in msleep (ident=0xc054eaec, mtx=0x0, priority=68, wmesg=0xc048c09e "psleep", timo=100) at ../../kern/kern_synch.c:500 #5 0xc02ab0a5 in buf_daemon () at ../../kern/vfs_bio.c:1883 #6 0xc025af78 in fork_exit (callout=0xc02aaf20 , arg=0x0, frame=0xc80cbfa8) at ../../kern/kern_fork.c:727 (kgdb) fr 6 #6 0xc025af78 in fork_exit (callout=0xc02aaf20 , arg=0x0, frame=0xc80cbfa8) at ../../kern/kern_fork.c:727 727 callout(arg, frame); (kgdb) l 722 * cpu_set_fork_handler intercepts this function call to 723 * have this call a non-return function to stay in kernel mode. 724 * initproc has its own fork handler, but it does return. 725 */ 726 KASSERT(callout != NULL, ("NULL callout in fork_exit")); 727 callout(arg, frame); 728 729 /* 730 * Check if a kernel thread misbehaved and returned from its main 731 * function. (kgdb) l 732 */ 733 PROC_LOCK(p); 734 if (p->p_flag & P_KTHREAD) { 735 PROC_UNLOCK(p); 736 mtx_lock(&Giant); 737 printf("Kernel thread \"%s\" (pid %d) exited prematurely.\n", 738 p->p_comm, p->p_pid); 739 kthread_exit(0); 740 } 741 PROC_UNLOCK(p); (kgdb) p frame $1 = (struct trapframe *) 0xc80cbfa8 (kgdb) p frame[0] $2 = {tf_fs = 0, tf_es = 0, tf_ds = 0, tf_edi = 0, tf_esi = 0, tf_ebp = 0, tf_isp = 0, tf_ebx = 0, tf_edx = 1, tf_ecx = 0, tf_eax = 0, tf_trapno = 0, tf_err = 0, tf_eip = 0, tf_cs = 0, tf_eflags = 0, tf_esp = 0, tf_ss = 0} (kgdb) fr 5 #5 0xc02ab0a5 in buf_daemon () at ../../kern/vfs_bio.c:1883 1883 tsleep(&bd_request, PVM, "qsleep", hz / 2); (kgdb) l 1878 /* 1879 * We couldn't find any flushable dirty buffers but 1880 * still have too many dirty buffers, we 1881 * have to sleep and try again. (rare) 1882 */ 1883 tsleep(&bd_request, PVM, "qsleep", hz / 2); 1884 } 1885 } 1886 } 1887 (kgdb) q ichotolot# gdb -k kernel.debug vmcore.20 GNU gdb 4.18 Copyright 1998 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-unknown-freebsd"... IdlePTD 6516736 initial pcb at 529440 panicstr: mutex Giant not owned at ../../vm/vm_object.c:261 panic messages: --- panic: mutex Giant not owned at ../../vm/vm_object.c:261 cpuid = 0; lapic.id = 00000000 boot() called on cpu#0 syncing disks... 191 191 191 191 191 191 191 191 191 191 191 191 191 191 191 191 191 191 191 191 1: dev:da0s2e, flags:31021024, blkno:1559744, lblkno:27 2: dev:da0s2e, flags:21000024, blkno:16, lblkno:16 3: dev:da1s1e, flags:21000024, blkno:16, lblkno:16 4: dev:da0s2e, flags:01000024, blkno:15597616, lblkno:15597616 5: dev:da0s2e, flags:21021024, blkno:14221408, lblkno:14221408 6: dev:da0s2e, flags:31021024, blkno:1626976, lblkno:263 7: dev:da0s2e, flags:21021024, blkno:15598368, lblkno:15598368 8: dev:da0s2e, flags:31021024, blkno:1587520, lblkno:167 9: dev:da0s2e, flags:31021024, blkno:1560272, lblkno:2 10: dev:da0s2e, flags:21021024, blkno:15532128, lblkno:15532128 11: dev:da0s2e, flags:21000024, blkno:2048, lblkno:2048 12: dev:da1s1e, flags:200210a0, blkno:5114176, lblkno:-12 13: dev:da0s2e, flags:21021024, blkno:403004, lblkno:0 14: dev:da0s2e, flags:21021024, blkno:457724, lblkno:0 15: dev:da0s2e, flags:31021024, blkno:1587888, lblkno:279 16: dev:da0s2e, flags:21021024, blkno:1858544, lblkno:2106 17: dev:da0s2e, flags:31021024, blkno:1585376, lblkno:314 18: dev:da0s2e, flags:31021024, blkno:1560624, lblkno:284 19: dev:da1s1e, flags:01000024, blkno:5570608, lblkno:5570608 20: dev:da1s1e, flags:21000024, blkno:2048, lblkno:2048 21: dev:da0s2e, flags:21021024, blkno:401024, lblkno:0 22: dev:da0s2e, flags:21021024, blkno:1507584, lblkno:1507584 23: dev:da0s2e, flags:21021024, blkno:15598352, lblkno:15598352 24: dev:da0s2e, flags:21021024, blkno:406720, lblkno:0 25: dev:da0s2e, flags:31021024, blkno:1581360, lblkno:68 26: dev:da0s2e, flags:21021024, blkno:2294560, lblkno:2294560 27: dev:da0s2e, flags:21021024, blkno:412304, lblkno:0 28: dev:da0s2e, flags:21021024, blkno:409440, lblkno:0 29: dev:da0s2e, flags:21021024, blkno:457776, lblkno:0 30: dev:da0s2e, flags:21021024, blkno:401370, lblkno:0 31: dev:da0s2e, flags:01000024, blkno:393264, lblkno:393264 32: dev:da1s1e, flags:21000024, blkno:2064, lblkno:2064 giving up on 32 buffers Uptime: 10h17m33s dumping to dev da0s2b, offset 270336 dump 128 [CTRL-C to abort] [CTRL-C to abort] [CTRL-C to abort] 127 126 125 124 123 122 121 [CTRL-C to abort] [CTRL-C to abort] 120 [CTRL-C to abort] 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 ../../kern/kern_shutdown.c:478 478 if (dumping++) { (kgdb) bt #0 dumpsys () at ../../kern/kern_shutdown.c:478 #1 0xc026b35f in boot (howto=256) at ../../kern/kern_shutdown.c:321 #2 0xc026b7d1 in panic (fmt=0xc0484808 "mutex %s not owned at %s:%d") at ../../kern/kern_shutdown.c:600 #3 0xc0263c25 in _mtx_assert (m=0xc0576ca0, what=1, file=0xc04ab834 "../../vm/vm_object.c", line=261) at ../../kern/kern_mutex.c:567 #4 0xc03f0fee in vm_object_reference (object=0xc8bbc1e0) at ../../vm/vm_object.c:261 #5 0xc03d6872 in ffs_write (ap=0xc8ce0e80) at ../../ufs/ufs/ufs_readwrite.c:421 #6 0xc025e175 in ktrwrite (vp=0xc8b67680, kth=0xc112df00, uio=0x0) at vnode_if.h:303 #7 0xc025dadb in ktrpsig (vp=0xc8b67680, sig=6, action=0, mask=0xc8b24090, code=0) at ../../kern/kern_ktrace.c:202 #8 0xc0270204 in postsig (sig=6) at ../../kern/kern_sig.c:1542 #9 0xc042983e in userret (p=0xc8b23ee0, frame=0xc8ce0fa8, oticks=2655) at ../../i386/i386/trap.c:175 #10 0xc042c603 in ast (framep=0xc8ce0fa8) at ../../i386/i386/trap.c:1320 #11 0xc0417b00 in doreti_ast () #12 0x80527c7 in ?? () #13 0x804ea6d in ?? () #14 0x8052974 in ?? () #15 0x80520c8 in ?? () #16 0x804d340 in ?? () #17 0x804e176 in ?? () #18 0x8049eb1 in ?? () (kgdb) fr 10 #10 0xc042c603 in ast (framep=0xc8ce0fa8) at ../../i386/i386/trap.c:1320 1320 userret(p, framep, sticks); (kgdb) p *p $1 = {p_procq = {tqe_next = 0x0, tqe_prev = 0xc0529718}, p_slpq = { tqe_next = 0x0, tqe_prev = 0xc05297f8}, p_list = {le_next = 0xc8b23220, le_prev = 0xc8d66db0}, p_ucred = 0xc124cc00, p_fd = 0xc10e3300, p_stats = 0xc8cdfb74, p_limit = 0xc117eb00, p_upages_obj = 0xc8cdd180, p_procsig = 0xc11d0340, p_flag = 16384, p_sflag = 2049, p_stat = 2, p_pid = 27587, p_hash = {le_next = 0x0, le_prev = 0xc0b3bf0c}, p_pglist = { le_next = 0x0, le_prev = 0xc10ff5a8}, p_pptr = 0xc7acac80, p_sibling = { le_next = 0xc8b24760, le_prev = 0xc7acacdc}, p_children = { lh_first = 0x0}, p_oppid = 0, p_dupfd = 0, p_vmspace = 0xc8b1c180, p_estcpu = 295, p_cpticks = 451, p_pctcpu = 1049, p_slpcallout = {c_links = { sle = {sle_next = 0x0}, tqe = {tqe_next = 0x0, tqe_prev = 0x0}}, c_time = 0, c_arg = 0x0, c_func = 0, c_flags = 8}, p_wchan = 0x0, p_wmesg = 0xc048c1a1 "getblk", p_swtime = 36, p_slptime = 0, p_itcallout = { c_links = {sle = {sle_next = 0x0}, tqe = {tqe_next = 0x0, tqe_prev = 0x0}}, c_time = 0, c_arg = 0x0, c_func = 0, c_flags = 0}, p_realtimer = {it_interval = {tv_sec = 0, tv_usec = 0}, it_value = { tv_sec = 0, tv_usec = 0}}, p_runtime = 30433876, p_uu = 0, p_su = 0, p_iu = 0, p_uticks = 7, p_sticks = 3089, p_iticks = 0, p_traceflag = -536870722, p_tracep = 0xc8b67680, p_siglist = {__bits = {0, 0, 0, 0}}, p_textvp = 0xc8b7da40, p_mtx = {mtx_object = { lo_class = 0xc04f81e0, lo_name = 0xc0482f48 "process lock", lo_flags = 196608, lo_list = {stqe_next = 0xc124cc68}, lo_witness = 0xc052be00}, mtx_lock = 3367124704, mtx_recurse = 0, mtx_savecrit = 0, mtx_blocked = {tqh_first = 0x0, tqh_last = 0xc8b2401c}, mtx_contested = {le_next = 0x0, le_prev = 0x0}}, p_spinlocks = 1, p_lock = 0 '\000', p_oncpu = 0 '\000', p_lastcpu = 0 '\000', p_rqindex = 54 '6', p_locks = -32, p_stops = 0, p_stype = 0, p_step = 0 '\000', p_pfsflags = 0 '\000', p_pad3 = "\000", p_retval = {0, 134625376}, p_sigiolst = {slh_first = 0x0}, p_sigparent = 20, p_oldsigmask = {__bits = {0, 0, 0, 0}}, p_sig = 0, p_code = 0, p_klist = { slh_first = 0x0}, p_sleeplocks = 0xc054e930, p_blocked = 0x0, p_mtxname = 0xc04aa634 "vm", p_contested = {lh_first = 0x0}, p_nlminfo = 0x0, p_aioinfo = 0x0, p_ithd = 0x0, p_intr_nesting_level = 0, p_sigmask = {__bits = {0, 0, 0, 0}}, p_sigstk = {ss_sp = 0x0, ss_size = 0, ss_flags = 4}, p_magic = -1091568946, p_pri = {pri_class = 3 '\003', pri_level = 216 'Ø', pri_native = 193 'Á', pri_user = 216 'Ø'}, p_nice = 0 '\000', p_comm = "telnet\000\000\000\000\000\000\000\000\000\000", p_pgrp = 0xc10ff5a0, p_sysent = 0xc04f4780, p_args = 0xc10ff540, p_addr = 0xc8cdf000, p_md = {md_regs = 0xc8ce0fa8}, p_xstat = 0, p_acflag = 0, p_ru = 0x0, p_peers = 0x0, p_leader = 0xc8b23ee0, p_asleep = { as_priority = 0, as_timo = 0}, p_emuldata = 0x0} (kgdb) q ichotolot# dmesg Copyright (c) 1992-2001 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 5.0-CURRENT #30: Wed Jun 6 20:35:34 CDT 2001 rmtodd@ichotolot.servalan.com:/usr/src/sys/compile/ICHOTOLOTSMP Timecounter "i8254" frequency 1193182 Hz CPU: Pentium II/Pentium II Xeon/Celeron (400.91-MHz 686-class CPU) Origin = "GenuineIntel" Id = 0x653 Stepping = 3 Features=0x183fbff real memory = 134217728 (131072K bytes) avail memory = 124346368 (121432K bytes) Programming 24 pins in IOAPIC #0 IOAPIC #0 intpin 2 -> irq 0 FreeBSD/SMP: Multiprocessor System Detected: 2 CPUs cpu0 (BSP): apic id: 0, version: 0x00040011, at 0xfee00000 cpu1 (AP): apic id: 1, version: 0x00040011, at 0xfee00000 io0 (APIC): apic id: 2, version: 0x00170011, at 0xfec00000 Preloaded elf kernel "kernel" at 0xc0618000. Pentium Pro MTRR support enabled WARNING: Driver mistake: destroy_dev on 154/0 npx0: on motherboard npx0: INT 16 interface pcib0: at pcibus 0 on motherboard IOAPIC #0 intpin 19 -> irq 2 IOAPIC #0 intpin 16 -> irq 10 pci0: on pcib0 pcib1: at device 1.0 on pci0 pci1: on pcib1 pci1: at 0.0 (no driver attached) isab0: at device 7.0 on pci0 isa0: on isab0 atapci0: port 0xffa0-0xffaf at device 7.1 on pci0 ata0: at 0x1f0 irq 14 on atapci0 ata1: at 0x170 irq 15 on atapci0 uhci0: port 0xef80-0xef9f irq 2 at device 7.2 on pci0 usb0: on uhci0 usb0: USB revision 1.0 uhub0: Intel UHCI root hub, class 9/0, rev 1.00/1.00, addr 1 uhub0: 2 ports with 2 removable, self powered ums0: Cypress Sem PS2/USB Browser Combo Mouse, rev 1.00/4.9c, addr 2, iclass 3/1 ums0: 5 buttons and Z dir. Timecounter "PIIX" frequency 3579545 Hz pci0: at 7.3 (no driver attached) pcib2: at device 16.0 on pci0 pci2: on pcib2 fxp0: port 0xef40-0xef5f mem 0xfea00000-0xfeafffff,0xfc4ff000-0xfc4fffff irq 2 at device 17.0 on pci0 fxp0: Ethernet address 00:e0:81:10:47:b2 inphy0: on miibus0 inphy0: 10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, auto ahc0: port 0xe400-0xe4ff mem 0xfebfe000-0xfebfefff irq 10 at device 18.0 on pci0 aic7895C: Ultra Wide Channel A, SCSI Id=7, 32/255 SCBs ahc1: port 0xe800-0xe8ff mem 0xfebff000-0xfebfffff irq 10 at device 18.1 on pci0 aic7895C: Ultra Wide Channel B, SCSI Id=7, 32/255 SCBs orm0: