From owner-freebsd-smp Sat Sep 16 14:32:36 2000 Delivered-To: freebsd-smp@freebsd.org Received: from ns.plaut.de (ns.plaut.de [194.99.75.166]) by hub.freebsd.org (Postfix) with ESMTP id A03E337B43E; Sat, 16 Sep 2000 14:32:21 -0700 (PDT) Received: (from uucp@localhost) by ns.plaut.de (8.9.3/8.9.3) with UUCP id XAA96156; Sat, 16 Sep 2000 23:32:19 +0200 (CEST) (envelope-from root@nihil.plaut.de) Received: from localhost (root@localhost) by nihil.plaut.de (8.11.0/8.8.8) with ESMTP id e8GMW6A00691; Sun, 17 Sep 2000 00:32:06 +0200 (CEST) (envelope-from root@nihil.plaut.de) Date: Sun, 17 Sep 2000 00:32:01 +0200 (CEST) From: Michael Reifenberger To: FreeBSD-Current Cc: FreeBSD-SMP Subject: Debugging -current SMPNG HANG on heavy disk-io Message-ID: MIME-Version: 1.0 Content-Type: TEXT/PLAIN; charset=US-ASCII Sender: owner-freebsd-smp@FreeBSD.ORG Precedence: bulk X-Loop: FreeBSD.org Hi, -current hangs reliable (as described in another mail) for me. For short: "tar cf /dev/null /usr/ports&; tar cf - /usr/ports | tar tf -" locks the system solid after a few minutes. The first tar itself seems to need some time longer before hang. This is verified to occure with 2 different disks (IDE). Now the questions how to debug this: - How do I get a backtrace of a specific process from within DDB? - How do I determine where the system hangs/loops fromm within DDB? - How do I get the process-list (like ps) from within gdb (postmortem) Below is a first try to debug postmortem with gdb Does this look reasonable? Something else to look? ... Copyright (c) 1992-2000 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 #0: Sat Sep 16 19:32:53 CEST 2000 root@nihil.plaut.de:/usr/obj/usr/src/sys/nihil Timecounter "i8254" frequency 1193182 Hz Timecounter "TSC" frequency 266615847 Hz CPU: Pentium II/Pentium II Xeon/Celeron (266.62-MHz 686-class CPU) Origin = "GenuineIntel" Id = 0x652 Stepping = 2 Features=0x183f9ff real memory = 268369920 (262080K bytes) config> #flags wdc0 0xa0ffa0ff Invalid command or syntax. Type `?' for help. config> #flags wdc1 0xa0ffa0ff Invalid command or syntax. Type `?' for help. config> #iosiz npx0 196608 Invalid command or syntax. Type `?' for help. config> #irq pcic0 11 Invalid command or syntax. Type `?' for help. config> quit avail memory = 257589248 (251552K bytes) Preloaded elf kernel "kernel.ko" at 0xc03ad000. Preloaded userconfig_script "/boot/kernel.conf" at 0xc03ad0ac. Preloaded elf module "linux.ko" at 0xc03ad0fc. Preloaded elf module "linprocfs.ko" at 0xc03ad19c. Pentium Pro MTRR support enabled VESA: v2.0, 2496k memory, flags:0x0, mode table:0xc031ee42 (1000022) VESA: MagicGraph 256 AV 44K PRELIMINARY npx0: on motherboard npx0: INT 16 interface pcib0: on motherboard pci0: on pcib0 pci0: at 4.0 irq 11 isab0: at device 5.0 on pci0 isa0: on isab0 atapci0: port 0xfe60-0xfe6f at device 5.1 on pci0 ata0: at 0x1f0 irq 14 on atapci0 ata1: at 0x170 irq 15 on atapci0 pci0: at 5.2 irq 11 pci0: at 5.3 pci0: at 9.0 irq 11 pcic-pci0: at device 11.0 on pci0 pcic-pci1: at device 11.1 on pci0 fdc0: at port 0x3f0-0x3f5,0x3f7 irq 6 drq 2 on isa0 atkbdc0: at port 0x60,0x64 on isa0 atkbd0: irq 1 on atkbdc0 psm0: irq 12 on atkbdc0 psm0: model GlidePoint, device ID 0 vga0: at port 0x3c0-0x3df iomem 0xa0000-0xbffff on isa0 sc0: on isa0 sc0: VGA <16 virtual consoles, flags=0x200> sio0 at port 0x3f8-0x3ff irq 4 flags 0x10 on isa0 sio0: type 16550A sio1: configured irq 3 not in bitmap of probed irqs 0 ppc0: at port 0x378-0x37f irq 7 flags 0x40 on isa0 ppc0: Generic chipset (ECP/PS2/NIBBLE) in COMPATIBLE mode ppc0: FIFO with 16/16/16 bytes threshold lpt0: on ppbus0 lpt0: Interrupt-driven port ppi0: on ppbus0 pps0: on ppbus0 pcic0: at port 0x3e0-0x3e1 on isa0 pcic0: Polling mode pccard0: on pcic0 pccard1: on pcic0 unknown: can't assign resources unknown: can't assign resources unknown: can't assign resources unknown: can't assign resources unknown: can't assign resources unknown: can't assign resources pcm0: at port 0x220-0x233,0x530-0x537,0x388-0x38f,0x330-0x333,0x538-0x539 irq 5 drq 1,0 on isa0 IP packet filtering initialized, divert enabled, rule-based forwarding disabled, default to deny, logging limited to 100 packets/entry by default IPsec: Initialized Security Association Processing. ad0: 24207MB [49184/16/63] at ata0-master using UDMA33 ad1: 6194MB [13424/15/63] at ata1-master using UDMA33 Mounting root from ufs:/dev/ad0s1a pccard: card inserted, slot 0 panic: from debugger syncing disks... done Uptime: 3h22m40s dumping to dev #ad/0x20001, offset 2547840 dump ata0: resetting devices .. done 255 254 253 252 251 250 249 248 247 246 245 244 243 242 241 240 239 238 237 236 235 234 233 232 231 230 229 228 227 226 225 224 223 222 221 220 219 218 217 216 215 214 213 212 211 210 209 208 207 206 205 204 203 202 201 200 199 198 197 196 195 194 193 192 191 190 189 188 187 186 185 184 183 182 181 180 179 178 177 176 175 174 173 172 171 170 169 168 167 166 165 164 163 162 161 160 159 158 157 156 155 154 153 152 151 150 149 148 147 146 145 144 143 142 141 140 139 138 137 136 135 134 133 132 131 130 129 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 --- #0 dumpsys () at /usr/src/sys/kern/kern_shutdown.c:475 475 dumppcb.pcb_cr3 = rcr3(); (kgdb) bt #0 dumpsys () at /usr/src/sys/kern/kern_shutdown.c:475 #1 0xc017aeb3 in boot (howto=256) at /usr/src/sys/kern/kern_shutdown.c:316 #2 0xc017b255 in panic (fmt=0xc02802b4 "from debugger") at /usr/src/sys/kern/kern_shutdown.c:568 #3 0xc013b2c9 in db_panic (addr=-1071295444, have_addr=0, count=-1, modif=0xc788bd88 "") at /usr/src/sys/ddb/db_command.c:433 #4 0xc013b269 in db_command (last_cmdp=0xc02bf5b4, cmd_table=0xc02bf414, aux_cmd_tablep=0xc03002fc) at /usr/src/sys/ddb/db_command.c:333 #5 0xc013b32e in db_command_loop () at /usr/src/sys/ddb/db_command.c:455 #6 0xc013d4eb in db_trap (type=3, code=0) at /usr/src/sys/ddb/db_trap.c:71 #7 0xc02551ca in kdb_trap (type=3, code=0, regs=0xc788beac) at /usr/src/sys/i386/i386/db_interface.c:163 #8 0xc0260fdc in trap (frame={tf_fs = 16, tf_es = 16, tf_ds = -1070530544, tf_edi = -1070468928, tf_esi = -1070491744, tf_ebp = -947339528, tf_isp = -947339560, tf_ebx = 582, tf_edx = -1072984320, tf_ecx = 32, tf_eax = 38, tf_trapno = 3, tf_err = 0, tf_eip = -1071295444, tf_cs = 8, tf_eflags = 70, tf_esp = -1070930945, tf_ss = -1070944311}) at /usr/src/sys/i386/i386/trap.c:584 #9 0xc025542c in Debugger (msg=0xc02aafc9 "manual escape to debugger") at machine/cpufunc.h:64 #10 0xc0251f36 in scgetc (sc=0xc031f0c0, flags=2) at /usr/src/sys/dev/syscons/syscons.c:3133 #11 0xc024ef59 in sckbdevent (thiskbd=0xc0317f60, event=0, arg=0xc031f0c0) at /usr/src/sys/dev/syscons/syscons.c:634 #12 0xc0246eae in atkbd_intr (kbd=0xc0317f60, arg=0x0) at /usr/src/sys/dev/kbd/atkbd.c:462 #13 0xc026c45c in atkbd_isa_intr (arg=0xc0317f60) at /usr/src/sys/isa/atkbd_isa.c:125 #14 0xc02681a4 in ithd_loop (dummy=0x0) at /usr/src/sys/i386/isa/ithread.c:239 (kgdb) proc 35 (kgdb) bt #0 mi_switch () at /usr/src/sys/kern/kern_synch.c:953 #1 0xc017e2f0 in msleep (ident=0xc1d2fa00, mtx=0x0, priority=8, wmesg=0xc02a2c62 "inode", timo=0) at /usr/src/sys/kern/kern_synch.c:506 #2 0xc01750f2 in acquire (lkp=0xc1d2fa00, extflags=16777280, wanted=1536) at /usr/src/sys/kern/kern_lock.c:147 #3 0xc017537c in lockmgr (lkp=0xc1d2fa00, flags=16842754, interlkp=0xc9b371ec, p=0xc7874d80) at /usr/src/sys/kern/kern_lock.c:354 #4 0xc01a8ba8 in vop_stdlock (ap=0xc9608d34) at /usr/src/sys/kern/vfs_default.c:243 #5 0xc0227bd1 in ufs_vnoperate (ap=0xc9608d34) at /usr/src/sys/ufs/ufs/ufs_vnops.c:2263 #6 0xc01b35e3 in vn_lock (vp=0xc9b37180, flags=65538, p=0xc7874d80) at vnode_if.h:840 #7 0xc01abc8b in vget (vp=0xc9b37180, flags=2, p=0xc7874d80) at /usr/src/sys/kern/vfs_subr.c:1393 #8 0xc01a6d18 in vfs_cache_lookup (ap=0xc9608df0) at /usr/src/sys/kern/vfs_cache.c:470 #9 0xc0227bd1 in ufs_vnoperate (ap=0xc9608df0) at /usr/src/sys/ufs/ufs/ufs_vnops.c:2263 #10 0xc01a9f44 in lookup (ndp=0xc9608e6c) at vnode_if.h:52 #11 0xc01a9968 in namei (ndp=0xc9608e6c) at /usr/src/sys/kern/vfs_lookup.c:153 #12 0xc01afaa9 in lstat (p=0xc7874d80, uap=0xc9608f80) at /usr/src/sys/kern/vfs_syscalls.c:1787 #13 0xc0261aec in syscall2 (frame={tf_fs = -1071316945, tf_es = 47, tf_ds = 47, tf_edi = 134971440, tf_esi = 134971436, tf_ebp = -1077937556, tf_isp = -916418604, tf_ebx = 20, tf_edx = 134935040, tf_ecx = 134935040, tf_eax = 190, tf_trapno = 7, tf_err = 2, tf_eip = 134603604, tf_cs = 31, tf_eflags = 643, tf_esp = -1077937696, tf_ss = 47}) at /usr/src/sys/i386/i386/trap.c:1136 #14 0xc0255b0f in Xint0x80_syscall () #15 0x804b0cd in ?? () #16 0x804b0cd in ?? () #17 0x804b0cd in ?? () #18 0x804b0cd in ?? () #19 0x804a431 in ?? () #20 0x8052801 in ?? () #21 0x8048135 in ?? () (kgdb) up #1 0xc017e2f0 in msleep (ident=0xc1d2fa00, mtx=0x0, priority=8, wmesg=0xc02a2c62 "inode", timo=0) at /usr/src/sys/kern/kern_synch.c:506 506 mi_switch(); (kgdb) up #2 0xc01750f2 in acquire (lkp=0xc1d2fa00, extflags=16777280, wanted=1536) at /usr/src/sys/kern/kern_lock.c:147 147 error = tsleep(lkp, lkp->lk_prio, lkp->lk_wmesg, lkp->lk_timo); (kgdb) up #3 0xc017537c in lockmgr (lkp=0xc1d2fa00, flags=16842754, interlkp=0xc9b371ec, p=0xc7874d80) at /usr/src/sys/kern/kern_lock.c:354 354 error = acquire(lkp, extflags, (LK_HAVE_EXCL | LK_WANT_EXCL)); (kgdb) up #4 0xc01a8ba8 in vop_stdlock (ap=0xc9608d34) at /usr/src/sys/kern/vfs_default.c:243 243 return (lockmgr(l, ap->a_flags, &ap->a_vp->v_interlock, ap->a_p)); (kgdb) up #5 0xc0227bd1 in ufs_vnoperate (ap=0xc9608d34) at /usr/src/sys/ufs/ufs/ufs_vnops.c:2263 2263 return (VOCALL(ufs_vnodeop_p, ap->a_desc->vdesc_offset, ap)); (kgdb) up #6 0xc01b35e3 in vn_lock (vp=0xc9b37180, flags=65538, p=0xc7874d80) at vnode_if.h:840 840 rc = VCALL(vp, VOFFSET(vop_lock), &a); (kgdb) up #7 0xc01abc8b in vget (vp=0xc9b37180, flags=2, p=0xc7874d80) at /usr/src/sys/kern/vfs_subr.c:1393 1393 if ((error = vn_lock(vp, flags | LK_INTERLOCK, p)) != 0) { (kgdb) up #8 0xc01a6d18 in vfs_cache_lookup (ap=0xc9608df0) at /usr/src/sys/kern/vfs_cache.c:470 470 error = vget(vp, LK_EXCLUSIVE, p); (kgdb) up #9 0xc0227bd1 in ufs_vnoperate (ap=0xc9608df0) at /usr/src/sys/ufs/ufs/ufs_vnops.c:2263 2263 return (VOCALL(ufs_vnodeop_p, ap->a_desc->vdesc_offset, ap)); (kgdb) Bye! ---- Michael Reifenberger ^.*Plaut.*$, IT, R/3 Basis, GPS To Unsubscribe: send mail to majordomo@FreeBSD.org with "unsubscribe freebsd-smp" in the body of the message