From owner-freebsd-current Fri Feb 8 16:18:31 2002 Delivered-To: freebsd-current@freebsd.org Received: from alicia.nttmcl.com (alicia.nttmcl.com [216.69.69.10]) by hub.freebsd.org (Postfix) with ESMTP id DFC6F37B416 for ; Fri, 8 Feb 2002 16:18:14 -0800 (PST) Received: (from gene@localhost) by alicia.nttmcl.com (8.10.1/8.10.1) id g190Hg528904; Fri, 8 Feb 2002 16:17:42 -0800 (PST) Date: Fri, 8 Feb 2002 16:17:41 -0800 From: "Eugene M. Kim" To: Julian Elischer Cc: David Wolfskill , current@FreeBSD.ORG Subject: Re: Hang on flushing buffers w/today's -CURRENT, SMP system Message-ID: <20020208161740.A28661@alicia.nttmcl.com> References: <20020208152145.B24821@alicia.nttmcl.com> Mime-Version: 1.0 Content-Type: multipart/mixed; boundary="BOKacYhQ+x31HxR3" Content-Disposition: inline User-Agent: Mutt/1.2i In-Reply-To: ; from julian@elischer.org on Fri, Feb 08, 2002 at 03:56:21PM -0800 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 --BOKacYhQ+x31HxR3 Content-Type: text/plain; charset=us-ascii Content-Disposition: inline On Fri, Feb 08, 2002 at 03:56:21PM -0800, Julian Elischer wrote: > > In your case we need totrace proc 1 I think.. > I got the `reboot' process at this session, so I traced that process. Before I had used `shutdown -r', which probably SIGINT'ed the init process so it's init (pid 1) calling reboot()... The attached log also has its trace JFYI. One more bit of info: as you see from the pcpu output, mine is not an SMP but an UP box. Thanks, Eugene --BOKacYhQ+x31HxR3 Content-Type: text/plain; charset=us-ascii Content-Disposition: attachment; filename="screenlog.0" Content-Transfer-Encoding: quoted-printable show locks=0D exclusive (sleep mutex) Giant (0xc02e60c0) locked @ /usr/src/sys/kern/kern_= intr.c:532=0D db> ps=0D pid proc addr uid ppid pgrp flag stat wmesg wchan cmd=0D 279 cdbdc500 cdc6e000 0 1 279 0004002 2 reboot= =0D 185 cc988900 cdbbc000 0 0 0 0000204 3 nfsidl c1d053ac nfsiod= 3=0D 184 cc988c00 cdbb8000 0 0 0 0000204 3 nfsidl c1d053a8 nfsiod= 2=0D 183 cc988f00 cdbb4000 0 0 0 0000204 3 nfsidl c1d053a4 nfsiod= 1=0D 182 cc989200 cdbb0000 0 0 0 0000204 3 nfsidl c1d053a0 nfsiod= 0=0D 7 cc98b600 cd1a6000 0 0 0 0000204 3 ktsusp cc98b800 syncer= =0D 6 cc98b900 cd1a2000 0 0 0 0000204 3 ktsusp cc98bb00 vnlru= =0D 5 cc98bc00 cd19e000 0 0 0 0000204 3 ktsusp cc98be00 bufdae= mon=0D 4 cc98bf00 cd19a000 0 0 0 0000204 3 pgzero c0327f88 pageze= ro=0D 3 cc98c200 cd196000 0 0 0 0000204 3 psleep c0327f9c vmdaem= on=0D 2 cc98c500 cd192000 0 0 0 0000204 3 psleep c02e0698 pageda= emon=0D 31 cc98c800 cc991000 0 0 0 0000204 6 irq8: = rtc=0D 30 cc98cb00 cc98d000 0 0 0 0000204 6 irq0: = clk=0D 29 cc321f00 cc984000 0 0 0 0000204 6 irq4: = sio0=0D 28 cc322200 cc980000 0 0 0 0000204 6 swi0: = tty:sio=0D 27 cc322500 cc97c000 0 0 0 0000204 6 irq7: = ppc0=0D 26 cc322800 cc978000 0 0 0 0000204 6 irq12:= psm0=0D 25 cc322b00 cc974000 0 0 0 0000204 2 irq1: = atkbd0=0D 24 cc322e00 cc970000 0 0 0 0000204 3 usbevt c1b60210 usb0=0D 23 cc323100 cc96c000 0 0 0 0000204 6 irq11:= uhci0=0D --More--=0D 22 cc323400 cc968000 0 0 0 0000204 6 = irq15: ata1=0D 21 cc323700 cc964000 0 0 0 0000204 6 irq14:= ata0=0D 20 cc323a00 cc95b000 0 0 0 0000204 6 irq5: = pcm0=0D 19 cc323d00 cc953000 0 0 0 0000204 6 irq13:= =0D 18 cc324000 cc94f000 0 0 0 0000204 6 swi5: = acpitaskq=0D 17 cc324300 cc94b000 0 0 0 0000204 6 swi5: = task queue=0D 16 cc324600 cc947000 0 0 0 0000204 6 swi3: = cambio=0D 15 cc324900 cc943000 0 0 0 0000204 6 swi2: = camnet=0D 14 cc324c00 cc93f000 0 0 0 0000204 3 sleep c04141c0 random= =0D 13 cc324f00 cc93b000 0 0 0 0000204 6 swi4: = vm=0D 12 cc325200 cc937000 0 0 0 000020c 2 swi6: = tty:sio clock=0D 11 cc325500 cc933000 0 0 0 0000204 6 swi1: = net=0D 10 cc325800 cc32e000 0 0 0 000020c 2 idle=0D 1 cc325b00 cc32a000 0 0 1 0004200 3 wait cc325b00 init=0D 0 c02c41c0 c047c000 0 0 0 0000200 3 sched c02c41c0 swappe= r=0D db> tr 279=0D mi_switch(0,cdbdc500,cdbdc604,10,0) at mi_switch+0x153=0D boot(0,cdbdc714,cdc71d40,c0262b80,cdbdc604) at boot+0x200=0D reboot(cdbdc604,cdc71d20,2,0,0) at reboot+0x37=0D syscall(2f,2f,2f,0,0) at syscall+0x254=0D syscall_with_err_pushed() at syscall_with_err_pushed+0x1b=0D --- syscall (55, FreeBSD ELF, reboot), eip =3D 0x8048b8b, esp =3D 0xbfbffb1= c, ebp =3D 0xbfbffb48 ---=0D db> tr 1=0D mi_switch(1,0,cc32dd20,1,0) at mi_switch+0x153=0D msleep(cc325b00,0,15c,c0287e85,0) at msleep+0x322=0D wait1(cc325c04,cc32dd20,0,cc32dd40,c0262b80) at wait1+0x617=0D wait4(cc325c04,cc32dd20,0,bfbffe18,bfbffe24) at wait4+0x12=0D syscall(2f,2f,2f,bfbffe24,bfbffe18) at syscall+0x254=0D syscall_with_err_pushed() at syscall_with_err_pushed+0x1b=0D --- syscall (7, FreeBSD ELF, wait4), eip =3D 0x8050c37, esp =3D 0xbfbffcf8,= ebp =3D 0xbfbffd14 ---=0D db> tr 0=0D mi_switch(c02def10,0,483000,1,0) at mi_switch+0x153=0D msleep(c02c41c0,0,44,c02a7570,3e8) at msleep+0x322=0D scheduler(0,47bc00,47b000,0,c0121d1c) at scheduler+0x146=0D mi_startup() at mi_startup+0x95=0D begin() at begin+0x43=0D db> ~~=08 =08=08 =08show witness=0D Sleep locks:=0D 0 (dead) -- last acquired @ (dead):0=0D 0 (dead) -- last acquired @ (dead):0=0D 0 Giant -- last acquired @ /usr/src/sys/kern/kern_intr.c:532=0D 1 ithread -- last acquired @ /usr/src/sys/kern/kern_intr.c:269=0D 2 struct filedesc -- last acquired @ /usr/src/sys/kern/kern_descrip.c:117= 0=0D 2 fork list -- last acquired @ /usr/src/sys/kern/kern_fork.c:649=0D 3 lockmgr -- last acquired @ /usr/src/sys/kern/kern_lock.c:227=0D 2 proctree -- last acquired @ /usr/src/sys/kern/kern_exit.c:491=0D 3 malloc -- last acquired @ /usr/src/sys/kern/kern_malloc.c:303=0D 3 allproc -- last acquired @ /usr/src/sys/kern/kern_synch.c:267=0D 4 zone -- last acquired @ /usr/src/sys/vm/vm_zone.c:506=0D 4 process lock -- last acquired @ /usr/src/sys/kern/kern_kthread.c:178= =0D 5 ucred -- last acquired @ /usr/src/sys/kern/kern_prot.c:1601=0D 5 uidinfo hash -- last acquired @ /usr/src/sys/kern/kern_resource.c:84= 4=0D 6 uidinfo struct -- last acquired @ order list:0=0D 1 mbuf PCPU list lock -- last acquired @ /usr/src/sys/kern/subr_mbuf.c:784= =0D 1 eventhandler -- last acquired @ /usr/src/sys/kern/subr_eventhandler.c:16= 2=0D 3 lockmgr -- last acquired @ /usr/src/sys/kern/kern_lock.c:227=0D 3 malloc -- last acquired @ /usr/src/sys/kern/kern_malloc.c:303=0D 4 zone -- last acquired @ /usr/src/sys/vm/vm_zone.c:506=0D 1 sndstat -- last acquired @ /usr/src/sys/modules/sound/pcm/../../../dev/s= ound/pcm/sndstat.c:231=0D 1 sf_bufs list lock -- last acquired @ /usr/src/sys/kern/uipc_syscalls.c:1= 556=0D 3 malloc -- last acquired @ /usr/src/sys/kern/kern_malloc.c:303=0D 3 lockmgr -- last acquired @ /usr/src/sys/kern/kern_lock.c:227=0D 4 zone -- last acquired @ /usr/src/sys/vm/vm_zone.c:506=0D 1 zone subsystem -- last acquired @ /usr/src/sys/vm/vm_zone.c:179=0D 4 zone -- last acquired @ /usr/src/sys/vm/vm_zone.c:506=0D 1 rman -- last acquired @ /usr/src/sys/kern/subr_rman.c:194=0D 3 malloc -- last acquired @ /usr/src/sys/kern/kern_malloc.c:303=0D 1 bpf global lock -- last acquired @ /usr/src/sys/net/bpf.c:1270=0D 1 taskqueue list -- last acquired @ /usr/src/sys/kern/subr_taskqueue.c:85= =0D 1 rman head -- last acquired @ /usr/src/sys/kern/subr_rman.c:107=0D 1 ACPI semaphore -- last acquired @ /usr/src/sys/modules/acpi/../../dev/ac= pica/Osd/OsdSynch.c:296=0D 1 vm86 lock -- last acquired @ /usr/src/sys/i386/i386/vm86.c:578=0D 1 pcm0:play:2 -- last acquired @ /usr/src/sys/modules/sound/pcm/../../../d= ev/sound/pcm/channel.c:674=0D 3 lockmgr -- last acquired @ /usr/src/sys/kern/kern_lock.c:227=0D 3 malloc -- last acquired @ /usr/src/sys/kern/kern_malloc.c:303=0D 4 zone -- last acquired @ /usr/src/sys/vm/vm_zone.c:506=0D 1 pcm0:play:3 -- last acquired @ /usr/src/sys/modules/sound/pcm/../../../d= ev/sound/pcm/channel.c:674=0D 3 lockmgr -- last acquired @ /usr/src/sys/kern/kern_lock.c:227=0D 3 malloc -- last acquired @ /usr/src/sys/kern/kern_malloc.c:303=0D 4 zone -- last acquired @ /usr/src/sys/vm/vm_zone.c:506=0D 1 pcm0:play:1 -- last acquired @ /usr/src/sys/modules/sound/pcm/../../../d= ev/sound/pcm/channel.c:674=0D 3 lockmgr -- last acquired @ /usr/src/sys/kern/kern_lock.c:227=0D 3 malloc -- last acquired @ /usr/src/sys/kern/kern_malloc.c:303=0D 4 zone -- last acquired @ /usr/src/sys/vm/vm_zone.c:506=0D 1 pcm0:record:0 -- last acquired @ /usr/src/sys/modules/sound/pcm/../../..= /dev/sound/pcm/channel.c:674=0D 3 lockmgr -- last acquired @ /usr/src/sys/kern/kern_lock.c:227=0D 3 malloc -- last acquired @ /usr/src/sys/kern/kern_malloc.c:303=0D 4 zone -- last acquired @ /usr/src/sys/vm/vm_zone.c:506=0D 1 pcm0:play:0 -- last acquired @ /usr/src/sys/modules/sound/pcm/../../../d= ev/sound/pcm/channel.c:674=0D 3 lockmgr -- last acquired @ /usr/src/sys/kern/kern_lock.c:227=0D 3 malloc -- last acquired @ /usr/src/sys/kern/kern_malloc.c:303=0D 4 zone -- last acquired @ /usr/src/sys/vm/vm_zone.c:506=0D 1 pcm0 -- last acquired @ /usr/src/sys/modules/sound/pcm/../../../dev/soun= d/pcm/sound.c:134=0D 2 pcm0:fake -- last acquired @ /usr/src/sys/modules/sound/pcm/../../../de= v/sound/pcm/channel.c:674=0D 3 lockmgr -- last acquired @ /usr/src/sys/kern/kern_lock.c:227=0D 3 malloc -- last acquired @ /usr/src/sys/kern/kern_malloc.c:303=0D 4 zone -- last acquired @ /usr/src/sys/vm/vm_zone.c:506=0D 1 mntid -- last acquired @ /usr/src/sys/kern/vfs_subr.c:440=0D 2 mountlist -- last acquired @ /usr/src/sys/kern/vfs_syscalls.c:674=0D 1 pbuf mutex -- last acquired @ /usr/src/sys/vm/vm_pager.c:466=0D 5 ucred -- last acquired @ /usr/src/sys/kern/kern_prot.c:1601=0D 1 random reseed -- last acquired @ /usr/src/sys/modules/random/../../dev/r= andom/yarrow.c:172=0D 1 pcm0:mixer -- last acquired @ /usr/src/sys/modules/sound/pcm/../../../de= v/sound/pcm/sound.c:134=0D 2 pcm0:ac97 -- last acquired @ /usr/src/sys/modules/sound/pcm/../../../de= v/sound/pcm/sound.c:134=0D 3 malloc -- last acquired @ /usr/src/sys/kern/kern_malloc.c:303=0D 4 zone -- last acquired @ /usr/src/sys/vm/vm_zone.c:506=0D 1 ufs ihash -- last acquired @ /usr/src/sys/ufs/ufs/ufs_ihash.c:148=0D 3 vnode interlock -- last acquired @ /usr/src/sys/kern/vfs_vnops.c:697=0D 4 spechash -- last acquired @ /usr/src/sys/kern/vfs_subr.c:2287=0D 4 vnode_free_list -- last acquired @ /usr/src/sys/kern/vfs_subr.c:2238= =0D 4 mntvnode -- last acquired @ /usr/src/sys/kern/vfs_subr.c:2598=0D 1 buftime lock -- last acquired @ /usr/src/sys/sys/buf.h:278=0D 1 dirhash list -- last acquired @ /usr/src/sys/ufs/ufs/ufs_dirhash.c:334=0D 2 dirhash -- last acquired @ /usr/src/sys/ufs/ufs/ufs_dirhash.c:353=0D 1 filelist lock -- last acquired @ /usr/src/sys/kern/kern_descrip.c:1074=0D 2 filedesc structure -- last acquired @ /usr/src/sys/kern/kern_descrip.c:= 1259=0D 3 vnode interlock -- last acquired @ /usr/src/sys/kern/vfs_vnops.c:697=0D 4 spechash -- last acquired @ /usr/src/sys/kern/vfs_subr.c:2287=0D 4 vnode_free_list -- last acquired @ /usr/src/sys/kern/vfs_subr.c:2238= =0D 4 mntvnode -- last acquired @ /usr/src/sys/kern/vfs_subr.c:2598=0D 5 ucred -- last acquired @ /usr/src/sys/kern/kern_prot.c:1601=0D 4 zone -- last acquired @ /usr/src/sys/vm/vm_zone.c:506=0D 1 dksort -- last acquired @ /usr/src/sys/kern/subr_disklabel.c:95=0D 1 ifsvgt -- last acquired @ /usr/src/sys/ufs/ffs/ffs_vfsops.c:1223=0D 1 vnode pollinfo -- last acquired @ /usr/src/sys/kern/vfs_subr.c:2776=0D 1 vm object_list -- last acquired @ /usr/src/sys/vm/vm_object.c:553=0D 1 pseudofs_vncache -- last acquired @ /usr/src/sys/modules/pseudofs/../../= fs/pseudofs/pseudofs_vncache.c:211=0D 1 pseudofs -- last acquired @ /usr/src/sys/modules/pseudofs/../../fs/pseud= ofs/pseudofs_fileno.c:87=0D 1 msdosfs dehash -- last acquired @ /usr/src/sys/modules/msdosfs/../../fs/= msdosfs/msdosfs_denode.c:133=0D 3 vnode interlock -- last acquired @ /usr/src/sys/kern/vfs_vnops.c:697=0D 4 spechash -- last acquired @ /usr/src/sys/kern/vfs_subr.c:2287=0D 4 vnode_free_list -- last acquired @ /usr/src/sys/kern/vfs_subr.c:2238= =0D 4 mntvnode -- last acquired @ /usr/src/sys/kern/vfs_subr.c:2598=0D 1 ip_inq -- last acquired @ /usr/src/sys/netinet/ip_input.c:857=0D =0D Spin locks:=0D 0 sio -- last acquired @ /usr/src/sys/dev/sio/sio.c:3137=0D 1 cy -- last acquired @ order list:0=0D 2 ng_node -- last acquired @ order list:0=0D 3 ng_worklist -- last acquired @ order list:0=0D 4 ithread table lock -- last acquired @ /usr/src/sys/i386/isa/intr_mach= dep.c:618=0D 5 sched lock -- last acquired @ /usr/src/sys/kern/kern_clock.c:470=0D 6 callout -- last acquired @ /usr/src/sys/kern/kern_clock.c:232=0D 7 allpmaps -- last acquired @ order list:0=0D 8 icu -- last acquired @ /usr/src/sys/i386/isa/intr_machdep.c:584=0D 9 clk -- last acquired @ /usr/src/sys/i386/isa/clock.c:1232=0D =0D Locks which were never acquired:=0D gif=0D pseudofs_fileno=0D arp_inq=0D ip6_inq=0D bpf interface lock=0D lo=0D ACPI global lock=0D taskqueue=0D mbuf subsystem general lists lock=0D phys_pager list=0D dev_pager list=0D dev_pager create=0D swap_pager list=0D vm buckets hash mutexes=0D vm pageq mutex=0D db> p=08 =08show pcpu=0D cpuid =3D 0=0D curthread =3D 0xcc322c04: pid 25 "irq1: atkbd0"=0D curpcb =3D 0xcc977da0=0D fpcurthread =3D none=0D idlethread =3D 0xcc325904: pid 10 "idle"=0D currentldt =3D 0x28=0D spin locks held:=0D db>=20 --BOKacYhQ+x31HxR3-- To Unsubscribe: send mail to majordomo@FreeBSD.org with "unsubscribe freebsd-current" in the body of the message