Re: panic on exit; KDB "ps" cmd says "oops, ran out of processes early!"

From: Jeff Roberson <jroberson_at_chesapeake.net>
Date: Tue, 11 Mar 2008 13:05:49 -1000 (HST)
On Tue, 11 Mar 2008, David Wolfskill wrote:

> 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).
>

Are any of these compat binaries using kse?  If so I believe I know the 
problem.  That cpuset_rel() call needs an "if (td->td_cpuset != NULL)" in 
front of it for kse.  If you can confirm that kse was the problem I'll 
commit a fix for that.

Thanks,
Jeff

> 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=0x53fcc data=0x25e0+0x186c syms=[0x4+0x8a20+0x4+0xbbc7]
> GDB: no debug ports present
> KDB: debugger backends: ddb
> KDB: current backend: ddb
> SMAP type=01 base=0000000000000000 len=000000000009fc00
> SMAP type=02 base=000000000009fc00 len=0000000000000400
> SMAP type=01 base=0000000000100000 len=000000003fee2800
> SMAP type=02 base=000000003ffe2800 len=000000000001d800
> SMAP type=02 base=00000000feda0000 len=0000000000060000
> SMAP type=02 base=00000000ffb80000 len=0000000000480000
> 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_at_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 CPU)
>  Origin = "GenuineIntel"  Id = 0xf27  Stepping = 7
>  Features=0xbfebf9ff<FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CLFLUSH,DTS,ACPI,MMX,FXSR,SSE,SSE2,SS,HTT,TM,PBE>
>  Features2=0x400<CNXT-ID>
>
> 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 line size
> real memory  = 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 = 1038028800 (989 MB)
> ...
> lock order reversal:
> 1st 0xc4154e28 devfs (devfs) _at_ /usr/src/sys/kern/vfs_subr.c:2063
> 2nd 0xc4263294 devfsmount (devfsmount) _at_ /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_backtrace+0x29
> witness_checkorder(c4263294,9,c0ab8891,c9,c7,...) at witness_checkorder+0x6de
> _sx_xlock(c4263294,0,c0ab8891,c9,c4263294,...) at _sx_xlock+0x7d
> devfs_allocv(c424c080,c4265000,e2886c28,c3e22d20,c0acd19c,...) at devfs_allocv+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 = 0, esp = 0xe2886d70, ebp = 0 ---
> Trying to mount root from ufs:/dev/ad0s4a
> lock order reversal:
> 1st 0xc41549e8 ufs (ufs) _at_ /usr/src/sys/kern/vfs_subr.c:2063
> 2nd 0xc4265000 vfslock (vfslock) _at_ /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_backtrace+0x29
> witness_checkorder(c4265000,1,c0acd837,16c,e2886a18,...) at witness_checkorder+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_mountroot_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 = 0, esp = 0xe2886d70, ebp = 0 ---
> start_init: trying /sbin/init
> lock order reversal:
> 1st 0xc3e26044 user map (user map) _at_ /usr/src/sys/vm/vm_map.c:3111
> 2nd 0xc41547c8 ufs (ufs) _at_ /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_backtrace+0x29
> witness_checkorder(c41547c8,1,c0acd837,80f,e28869e8,...) at witness_checkorder+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+0xa5
> _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 = 0x80480e5, esp = 0xbfbfeef0, ebp = 0xbfbfef10 ---
> xl0: link state changed to DOWN
> lock order reversal:
> 1st 0xc4377c08 pseudofs (pseudofs) _at_ /usr/src/sys/kern/vfs_subr.c:2063
> 2nd 0xc4382538 vfslock (vfslock) _at_ /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_backtrace+0x29
> witness_checkorder(c4382538,1,c0acd837,16c,e6582a58,...) at witness_checkorder+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 = 0x280d715b, esp = 0xbfbfe96c, ebp = 0xbfbfedb8 ---
> drm0: <ATI Radeon Lf RV250 Mobility 9000 M9 / FireMV 2400 PCI> 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 = 0x2814713b, esp = 0xbfbfe34c, ebp = 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        = 0
> curthread    = 0xc4719af0: pid 1326 "sh"
> curpcb       = 0xe6958d90
> fpcurthread  = none
> idlethread   = 0xc3e22af0: pid 11 "idle: cpu0"
> APIC ID      = 0
> currentldt   = 0x50
> spin locks held:
> db>
>
> 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
> -- 
> David H. Wolfskill				david_at_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.
>
Received on Tue Mar 11 2008 - 22:06:57 UTC

This archive was generated by hypermail 2.4.0 : Wed May 19 2021 - 11:39:28 UTC