From owner-freebsd-current@FreeBSD.ORG Tue Mar 11 17:05:00 2008 Return-Path: Delivered-To: current@freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:4f8:fff6::34]) by hub.freebsd.org (Postfix) with ESMTP id 262451065674 for ; Tue, 11 Mar 2008 17:05:00 +0000 (UTC) (envelope-from david@catwhisker.org) Received: from bunrab.catwhisker.org (adsl-63-193-123-122.dsl.snfc21.pacbell.net [63.193.123.122]) by mx1.freebsd.org (Postfix) with ESMTP id 992CA8FC17 for ; Tue, 11 Mar 2008 17:04:59 +0000 (UTC) (envelope-from david@catwhisker.org) Received: from bunrab.catwhisker.org (localhost [127.0.0.1]) by bunrab.catwhisker.org (8.13.3/8.13.3) with ESMTP id m2BH4x9X003622 for ; Tue, 11 Mar 2008 10:04:59 -0700 (PDT) (envelope-from david@bunrab.catwhisker.org) Received: (from david@localhost) by bunrab.catwhisker.org (8.13.3/8.13.1/Submit) id m2BH4xK0003621 for current@freebsd.org; Tue, 11 Mar 2008 10:04:59 -0700 (PDT) (envelope-from david) Date: Tue, 11 Mar 2008 10:04:59 -0700 From: David Wolfskill To: current@freebsd.org Message-ID: <20080311170459.GL53010@bunrab.catwhisker.org> Mail-Followup-To: David Wolfskill , current@freebsd.org Mime-Version: 1.0 Content-Type: multipart/signed; micalg=pgp-sha1; protocol="application/pgp-signature"; boundary="QyKdZyDmv5hkaBi2" Content-Disposition: inline User-Agent: Mutt/1.4.2.1i Cc: Subject: panic on exit; KDB "ps" cmd says "oops, ran out of processes early!" 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: Tue, 11 Mar 2008 17:05:00 -0000 --QyKdZyDmv5hkaBi2 Content-Type: text/plain; charset=us-ascii Content-Disposition: inline Content-Transfer-Encoding: quoted-printable I noticed this on my laptop, running HEAD as of this monring, while exiting a run of bsd-airtools (that had been built under RELENG_6; I have misc/compat6x installed). I just re-created it on exit of firefox (also built under RELENG_6, if that's relevant -- indeed, all of the ports except misc/compat6x were built under RELENG_6). Following is cut/paste from my laptop's serial console; the whine about "oops, ran out of processes early!" is near the end: /boot/kernel/acpi.ko text=3D0x53fcc data=3D0x25e0+0x186c syms=3D[0x4+0x8a20= +0x4+0xbbc7] GDB: no debug ports present KDB: debugger backends: ddb KDB: current backend: ddb SMAP type=3D01 base=3D0000000000000000 len=3D000000000009fc00 SMAP type=3D02 base=3D000000000009fc00 len=3D0000000000000400 SMAP type=3D01 base=3D0000000000100000 len=3D000000003fee2800 SMAP type=3D02 base=3D000000003ffe2800 len=3D000000000001d800 SMAP type=3D02 base=3D00000000feda0000 len=3D0000000000060000 SMAP type=3D02 base=3D00000000ffb80000 len=3D0000000000480000 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 #710: Tue Mar 11 07:44:13 PDT 2008 root@g1-37.catwhisker.org:/common/S4/obj/usr/src/sys/CANARY WARNING: WITNESS option enabled, expect reduced performance. Preloaded elf kernel "/boot/kernel/kernel" at 0xc0e10000. Preloaded elf module "/boot/kernel/linux.ko" at 0xc0e1014c. Preloaded elf module "/boot/kernel/if_an.ko" at 0xc0e101f8. Preloaded elf module "/boot/kernel/acpi.ko" at 0xc0e102a4. Calibrating clock(s) ... i8254 clock: 1193185 Hz CLK_USE_I8254_CALIBRATION not specified - using default frequency Timecounter "i8254" frequency 1193182 Hz quality 0 Calibrating TSC clock ... TSC clock: 2392952788 Hz CPU: Mobile Intel(R) Pentium(R) 4 - M CPU 2.40GHz (2392.95-MHz 686-class CP= U) Origin =3D "GenuineIntel" Id =3D 0xf27 Stepping =3D 7 Features=3D0xbfebf9ff Features2=3D0x400 Instruction TLB: 4 KB, 2 MB or 4 MB pages, fully associative, 128 entries Data TLB: 4 KB or 4 MB pages, fully associative, 64 entries 1st-level data cache: 8 KB, 4-way set associative, sectored cache, 64 byte = line size Trace cache: 12K-uops, 8-way set associative 2nd-level cache: 512 KB, 8-way set associative, sectored cache, 64 byte lin= e size real memory =3D 1073618944 (1023 MB) Physical memory chunk(s): 0x0000000000001000 - 0x000000000009efff, 647168 bytes (158 pages) 0x0000000000100000 - 0x00000000003fffff, 3145728 bytes (768 pages) 0x0000000001025000 - 0x000000003ee99fff, 1038569472 bytes (253557 pages) avail memory =3D 1038028800 (989 MB) =2E.. lock order reversal: 1st 0xc4154e28 devfs (devfs) @ /usr/src/sys/kern/vfs_subr.c:2063 2nd 0xc4263294 devfsmount (devfsmount) @ /usr/src/sys/fs/devfs/devfs_vnops= .c:201 KDB: stack backtrace: db_trace_self_wrapper(c0ac4e80,e2886bbc,c078235e,c0ac73a9,c4263294,...) at = db_trace_self_wrapper+0x26 kdb_backtrace(c0ac73a9,c4263294,c0ab8850,c0ab8850,c0ab8891,...) at kdb_back= trace+0x29 witness_checkorder(c4263294,9,c0ab8891,c9,c7,...) at witness_checkorder+0x6= de _sx_xlock(c4263294,0,c0ab8891,c9,c4263294,...) at _sx_xlock+0x7d devfs_allocv(c424c080,c4265000,e2886c28,c3e22d20,c0acd19c,...) at devfs_all= ocv+0x144 devfs_root(c4265000,2,c0c251d8,c3e22d20,ca,...) at devfs_root+0x51 set_rootvnode(c0c251c0,0,c0acd19c,5f4,c07c02f0,...) at set_rootvnode+0x2b vfs_mountroot(c0bd3090,4,c0abcce6,262,0,...) at vfs_mountroot+0x356 start_init(0,e2886d38,c0abe65b,30c,c3e20ab0,...) at start_init+0x65 fork_exit(c070f200,0,e2886d38) at fork_exit+0xb8 fork_trampoline() at fork_trampoline+0x8 --- trap 0, eip =3D 0, esp =3D 0xe2886d70, ebp =3D 0 --- Trying to mount root from ufs:/dev/ad0s4a lock order reversal: 1st 0xc41549e8 ufs (ufs) @ /usr/src/sys/kern/vfs_subr.c:2063 2nd 0xc4265000 vfslock (vfslock) @ /usr/src/sys/kern/vfs_subr.c:364 KDB: stack backtrace: db_trace_self_wrapper(c0ac4e80,e28869d8,c078235e,c0ac73a9,c4265000,...) at = db_trace_self_wrapper+0x26 kdb_backtrace(c0ac73a9,c4265000,c0acd29a,c0acd29a,c0acd837,...) at kdb_back= trace+0x29 witness_checkorder(c4265000,1,c0acd837,16c,e2886a18,...) at witness_checkor= der+0x6de _lockmgr_args(c4265000,20001,c4265030,0,ffffffff,...) at _lockmgr_args+0x1d5 vfs_busy(c4265000,0,0,c3e22d20,e2886b58,...) at vfs_busy+0x1b0 lookup(e2886b44,c0accf4a,c6,bf,c3dee82c,...) at lookup+0x7bf namei(e2886b44,c4265030,1c1,c0acd19c,e2886b54,...) at namei+0x34b kern_unlink(c3e22d20,c0acd5d9,1,62f,0,...) at kern_unlink+0x40 vfs_mountroot_try(c0acd793,c0abba07,c0ab4fac,1,c07c02f0,...) at vfs_mountro= ot_try+0x470 vfs_mountroot(c0bd3090,4,c0abcce6,262,0,...) at vfs_mountroot+0x418 start_init(0,e2886d38,c0abe65b,30c,c3e20ab0,...) at start_init+0x65 fork_exit(c070f200,0,e2886d38) at fork_exit+0xb8 fork_trampoline() at fork_trampoline+0x8 --- trap 0, eip =3D 0, esp =3D 0xe2886d70, ebp =3D 0 --- start_init: trying /sbin/init lock order reversal: 1st 0xc3e26044 user map (user map) @ /usr/src/sys/vm/vm_map.c:3111 2nd 0xc41547c8 ufs (ufs) @ /usr/src/sys/kern/vfs_subr.c:2063 KDB: stack backtrace: db_trace_self_wrapper(c0ac4e80,e28869c4,c078235e,c0ac73a9,c41547c8,...) at = db_trace_self_wrapper+0x26 kdb_backtrace(c0ac73a9,c41547c8,c0abc2ba,c0abc2ba,c0acd837,...) at kdb_back= trace+0x29 witness_checkorder(c41547c8,1,c0acd837,80f,e28869e8,...) at witness_checkor= der+0x6de _lockmgr_args(c41547c8,30041,c41547f8,0,ffffffff,...) at _lockmgr_args+0x1d5 ffs_lock(e2886a78,c073a2cd,c0bde394,30041,c4154770,...) at ffs_lock+0xa3 VOP_LOCK1_APV(c0b9b760,e2886a78,c0abba05,3,c41547f8,...) at VOP_LOCK1_APV+0= xa5 _vn_lock(c4154770,30041,c0acd837,80f,0,...) at _vn_lock+0xf7 vget(c4154770,30041,c3e22d20,4a9,c1460580,...) at vget+0x10b vnode_pager_lock(c1460400,0,c0ae55b6,127,e2886be8,...) at vnode_pager_lock+= 0x1ad vm_fault(c3e26000,80d3000,2,8,80d3a20,...) at vm_fault+0x1df trap_pfault(5,0,c0af1f43,2c8,c3e20ab0,...) at trap_pfault+0x118 trap(e2886d38) at trap+0x267 calltrap() at calltrap+0x6 --- trap 0xc, eip =3D 0x80480e5, esp =3D 0xbfbfeef0, ebp =3D 0xbfbfef10 --- xl0: link state changed to DOWN lock order reversal: 1st 0xc4377c08 pseudofs (pseudofs) @ /usr/src/sys/kern/vfs_subr.c:2063 2nd 0xc4382538 vfslock (vfslock) @ /usr/src/sys/kern/vfs_subr.c:364 KDB: stack backtrace: db_trace_self_wrapper(c0ac4e80,e6582a18,c078235e,c0ac73a9,c4382538,...) at = db_trace_self_wrapper+0x26 kdb_backtrace(c0ac73a9,c4382538,c0acd29a,c0acd29a,c0acd837,...) at kdb_back= trace+0x29 witness_checkorder(c4382538,1,c0acd837,16c,e6582a58,...) at witness_checkor= der+0x6de _lockmgr_args(c4382538,20001,c4382568,0,ffffffff,...) at _lockmgr_args+0x1d5 vfs_busy(c4382538,10,0,c3f6a690,8,...) at vfs_busy+0x1b0 vfs_donmount(810f080,c,e6582c70,c4274580,810be68,...) at vfs_donmount+0xdb5 nmount(c3f6a690,e6582cfc,c,c0ac8065,c0b7b4f0,...) at nmount+0xb2 syscall(e6582d38) at syscall+0x2b3 Xint0x80_syscall() at Xint0x80_syscall+0x20 --- syscall (378, FreeBSD ELF32, nmount), eip =3D 0x280d715b, esp =3D 0xbfb= fe96c, ebp =3D 0xbfbfedb8 --- drm0: on vgapci0 info: [drm] AGP at 0xe8000000 64MB info: [drm] Initialized radeon 1.25.0 20060524 vgapci0: Reserved 0x10000 bytes for rid 0x18 type 3 at 0xfcff0000 vgapci0: Reserved 0x8000000 bytes for rid 0x10 type 3 at 0xe0000000 agp0: Setting AGP v2 mode 4 info: [drm] Setting GART location based on new memory map info: [drm] Loading R200 Microcode info: [drm] writeback test succeeded in 1 usecs drm0: [MPSAFE] drm0: [ITHREAD] FreeBSD/i386 (localhost) (ttyd0) login: [thread pid 1326 tid 100097 ] Stopped at cpuset_rel+0x17: lock xaddl %eax,0x4(%esi) db> bt Tracing pid 1326 tid 100097 td 0xc4719af0 cpuset_rel(0,c0ac0bbd,f4,c494dd20,e6958bac,...) at cpuset_rel+0x17 thread_free(c494dd20,0,c0ac2ffd,131,c4602690,...) at thread_free+0x15 thread_reap(c4446a00,0,c0ac2ffd,210) at thread_reap+0xc0 thread_wait(c4448804,ffffffff,0,2f7,0,...) at thread_wait+0x11c kern_wait(c4719af0,ffffffff,e6958c2c,2,0,...) at kern_wait+0x65b wait4(c4719af0,e6958cfc,10,c0ac7c4b,c0b79228,...) at wait4+0x3b syscall(e6958d38) at syscall+0x2b3 Xint0x80_syscall() at Xint0x80_syscall+0x20 --- syscall (7, FreeBSD ELF32, wait4), eip =3D 0x2814713b, esp =3D 0xbfbfe3= 4c, ebp =3D 0xbfbfe368 --- db> ps pid ppid pgrp uid state wmesg wchan cmd 1337 1032 1032 80 S accept 0xc43e7c5a httpd 1335 1032 1032 80 S accept 0xc43e7c5a httpd 1332 1 1270 1001 S select 0xc4611428 gconfd-2 1326 1322 1270 1001 R CPU 0 sh 1322 1 1270 1001 S wait 0xc46e02ac sh 1278 1271 1278 1001 Ss+ ttyin 0xc422d810 csh 1277 1264 1277 1001 Ss+ ttyin 0xc407b810 csh 1271 1217 1217 1001 S select 0xc4610ca8 xterm 1270 1217 1270 1001 S select 0xc421e5a8 piewm 1268 1217 1268 1001 S select 0xc4610aa8 oclock 1267 1217 1267 1001 S select 0xc4610728 ical-2.2 1264 1217 1264 1001 S select 0xc4263128 xterm 1257 1217 1257 1001 S select 0xc4610be8 xbattbar 1256 1217 1256 1001 S nanslp 0xc0bd3804 xautolock 1235 1 1235 1001 Ss select 0xc42631e8 ssh-agent 1217 1155 1217 1001 Ss pause 0xc46df5b8 csh 1214 1 1214 0 Ss+ ttyin 0xc406b010 getty 1171 1137 1171 1001 S+ ttyin 0xc407f010 csh 1155 1151 1155 0 Ss wait 0xc45fc2ac xdm 1154 1151 1154 0 Rs Xorg 1151 1144 1 0 S pause 0xc4449864 xdm 1144 1 1 0 S wait 0xc45fcab0 sh 1143 1 1143 0 Ss+ ttyin 0xc407fc10 getty 1142 1 1142 0 Ss+ ttyin 0xc407ec10 getty 1141 1 1141 0 Ss+ ttyin 0xc407d810 getty 1140 1 1140 0 Ss+ ttyin 0xc407dc10 getty 1139 1 1139 0 Ss+ ttyin 0xc4080410 getty 1138 1 1138 0 Ss+ ttyin 0xc4078010 getty 1137 1 1137 0 Ss+ wait 0xc44492ac login 1136 1 1136 0 Ss+ ttyin 0xc4074810 getty 1094 1 1094 0 Rs moused 1067 1 1067 0 Ss nanslp 0xc0bd3804 cron 1062 1032 1032 80 S accept 0xc43e7c5a httpd 1061 1032 1032 80 S accept 0xc43e7c5a httpd 1060 1032 1032 80 S accept 0xc43e7c5a httpd 1059 1032 1032 80 S accept 0xc43e7c5a httpd 1058 1032 1032 80 S accept 0xc43e7c5a httpd 1056 1 1056 25 Ss pause 0xc444830c sendmail 1050 1 1050 0 Ss select 0xc421e7a8 sendmail 1044 1 1044 0 Ss select 0xc40864e8 sshd 1032 1 1032 0 Ss select 0xc421ede8 httpd 959 1 959 0 Ss select 0xc42633e8 powerd 905 1 903 0 S select 0xc4086d28 snmpd 888 883 883 0 S - 0xc43ac000 nfsd 887 883 883 0 S - 0xc43ac400 nfsd 886 883 883 0 S - 0xc43ac600 nfsd 885 883 883 0 S - 0xc43ac800 nfsd 883 1 883 0 Ss select 0xc421eae8 nfsd 874 1 874 0 Ss select 0xc421e728 mountd 843 1 843 0 Ss select 0xc4262ae8 rpcbind 824 1 824 0 Ss select 0xc4263268 syslogd 792 0 0 0 SL mdwait 0xc439a800 [md0] 729 1 729 0 Ss select 0xc421d0e8 devd 34 0 0 0 SL sdflush 0xc0c30d70 [softdepflush] 33 0 0 0 SL vlruwt 0xc423b558 [vnlru] 32 0 0 0 SL syncer 0xc0bd362c [syncer] 31 0 0 0 SL psleep 0xc0c24fc4 [bufdaemon] 30 0 0 0 SL pgzero 0xc0c31960 [pagezero] 29 0 0 0 SL psleep 0xc0c3157c [vmdaemon] 28 0 0 0 SL psleep 0xc0c31544 [pagedaemon] 27 0 0 0 SL - 0xc41a0700 [dummynet] 26 0 0 0 SL waiting_ 0xc0c2724c [sctp_iterator] 25 0 0 0 SL tzpoll 0xc0df8f80 [acpi_thermal] 24 0 0 0 SL - 0xc405763c [fdc0] 23 0 0 0 SL cbb cv 0xc3f11bf0 [cbb2 event thread] 22 0 0 0 SL - 0xc3f76000 [fw0_probe] 21 0 0 0 SL - 0xc3f5b280 [fw0_taskq] 20 0 0 0 SL cbb cv 0xc3f0f3f0 [cbb1 event thread] 19 0 0 0 SL cbb cv 0xc3f113f0 [cbb0 event thread] 18 0 0 0 SL usbevt 0xc3f53210 [usb1] 17 0 0 0 SL usbtsk 0xc0bd0ed4 [usbtask-dr] 16 0 0 0 SL usbtsk 0xc0bd0ec0 [usbtask-hc] 15 0 0 0 SL usbevt 0xc3f1b210 [usb0] 14 0 0 0 SL - 0xc3e7c580 [kqueue taskq] 9 0 0 0 SL - 0xc3e7c800 [thread taskq] 8 0 0 0 SL - 0xc3e7c880 [acpi_task_2] 7 0 0 0 SL - 0xc3e7c880 [acpi_task_1] 6 0 0 0 SL - 0xc3e7c880 [acpi_task_0] 5 0 0 0 SL ccb_scan 0xc0bb4014 [xpt_thrd] 13 0 0 0 SL - 0xc0bd3634 [yarrow] 4 0 0 0 SL - 0xc0bd162c [g_down] 3 0 0 0 SL - 0xc0bd1628 [g_up] 2 0 0 0 SL - 0xc0bd1620 [g_event] 12 0 0 0 WL (threaded) intr 100039 I [irq7: ppbus0 ppc0] 100037 I [swi0: sio] 100035 I [irq12: psm0] 100034 I [irq1: atkbd0] 100033 I [irq15: ata1] 100032 I [irq14: ata0] 100022 I [irq11: cbb0 cbb1+*] 100021 I [irq9: pcm0 acpi0] 100019 I [swi6: task queue] 100018 I [swi6: Giant taskq] 100013 I [swi5: +] 100012 I [swi2: cambio] 100006 I [swi3: vm] 100005 I [swi4: clock sio] 100004 I [swi1: net] 11 0 0 0 RL [idle: cpu0] 1 0 1 0 SLs wait 0xc3e20ab0 [init] 10 0 0 0 SL audit_wo 0xc0c307cc [audit] 0 0 0 0 WLs [swapper] oops, ran out of processes early! db> show locks db> show pcpu cpuid =3D 0 curthread =3D 0xc4719af0: pid 1326 "sh" curpcb =3D 0xe6958d90 fpcurthread =3D none idlethread =3D 0xc3e22af0: pid 11 "idle: cpu0" APIC ID =3D 0 currentldt =3D 0x50 spin locks held: db>=20 I don't need to use my laptop while I'm at work, so I can poke at it in other ways if I get a clue what to do. This sort of thing did not happen when I ran some smallish programs from vty1 (logged in (/bin/csh); used RCS co & ci commands; used vi(1) to edit /etc/ttys; sent a SIGHUP to init). Peace, david --=20 David H. Wolfskill david@catwhisker.org I submit that "conspiracy" would be an appropriate collective noun for cats. See http://www.catwhisker.org/~david/publickey.gpg for my public key. --QyKdZyDmv5hkaBi2 Content-Type: application/pgp-signature Content-Disposition: inline -----BEGIN PGP SIGNATURE----- Version: GnuPG v1.4.0 (FreeBSD) iEYEARECAAYFAkfWu7oACgkQmprOCmdXAD2H0ACeNJX2Ld4n9Zn3zuLAcAOacwzO 5agAn2Hv3ksMjHEvAZNI1PpVlv4TMw/h =qtcp -----END PGP SIGNATURE----- --QyKdZyDmv5hkaBi2--