TODO list status update

Kris Kennaway kris at obsecurity.org
Mon Mar 20 21:35:51 UTC 2006


On Mon, Mar 20, 2006 at 12:31:34PM -0500, Kris Kennaway wrote:

> > > Another problem is in hardclock:
> > > 
> > > panic: blockable sleep lock (sleep mutex) system map @ vm/vm_map.c:2995
> > > cpuid = 2
> > > KDB: enter: panic
> > > [thread pid 35 tid 100037 ]
> > > Stopped at      kdb_enter+0x3c: ta              %xcc, 1
> > > db> wh
> > > Tracing pid 35 tid 100037 td 0xfffff803fe9faac0
> > > panic() at panic+0x164
> > > witness_checkorder() at witness_checkorder+0xc8
> > > _mtx_lock_flags() at _mtx_lock_flags+0x80
> > > _vm_map_lock_read() at _vm_map_lock_read+0x3c
> > > vm_map_lookup() at vm_map_lookup+0x1c
> > > vm_fault() at vm_fault+0x68
> > > trap_pfault() at trap_pfault+0x1a8
> > > trap() at trap+0x2b0
> > > -- fast data access mmu miss tar=0x18c0790000 %o7=0xc01c24d0 --
> > > witness_checkorder() at witness_checkorder+0x1c4
> > > _mtx_lock_spin_flags() at _mtx_lock_spin_flags+0x7c
> > > hardclock_cpu() at hardclock_cpu+0x20
> > > tick_hardclock() at tick_hardclock+0xc4
> > > -- interrupt level=0xe pil=0 %o7=0xc01c2f9c --
> > 
> > Sorry, I'm missing the big picture to determine what's at
> > fault here. Knowing what tick_hardclock() did interrupt
> > probably would help. Shouldn't be the another page fault
> > though as then PIL still would be set to 14 which in
> > turn means tick interrupts are turned off in the first
> > place.
> 
> I'll grab another trace next time it happens.

Here's another panic:

SMP: AP CPU #3 Launched!
SMP: AP CPU #2 Launched!
SMP: AP CPU #1 Launched!
sssiinnlckkssched loc  hhl bbb 0xfffff802be9e22d0fooo   55seconds
spin lock sched lock held by 0xfffff802be9eb2d0 for > 5 seconds
KDB: stack backtrace:
_mtx_lock_spin_flags() at _mtx_lock_spin_flags+0xdc
hardclock_cpu() at hardclock_cpu+0x20
hardclock() at hardclock+0x8
tick_hardclock() at tick_hardclock+0xac
-- interrupt level=0xe pil=0 %o7=0xc01c4898 --
strncmp() at strncmp+0x54
witness_unlock() at witness_unlock+0x5c
_mtx_unlock_flags() at _mtx_unlock_flags+0x7c
fdinit() at fdinit+0xc0
fdcopy() at fdcopy+0x10
fork1() at fork1+0x768
kthread_create() at kthread_create+0x3c
kproc_start() at kproc_start+0x24
mi_startup() at mi_startup+0x12c
btext() at btext+0x34
panic: spin lock held too long
cpuid = 0
KDB: enter: panic
[thread pid 0 tid 0 ]
Stopped at      kdb_enter+0x3c: ta              %xcc, 1
db> KDB: stack backtrace:
_mtx_lock_spin_flags() at _mtx_lock_spin_flags+0xdc
hardclock_cpu() at hardclock_cpu+0x20
tick_hardclock() at tick_hardclock+0xc4
-- interrupt level=0xe pil=0 %o7=0xc018a278 --
_mtx_lock_spin() at _mtx_lock_spin+0x110
_mtx_lock_spin_flags() at _mtx_lock_spin_flags+0xdc
cpu_mp_bootstrap() at cpu_mp_bootstrap+0xa8
mp_startup() at mp_startup+0xbc
mtx_pool_destroy() at mtx_pool_destroy+0x8
KDB: stack backtrace:
_mtx_lock_spin_flags() at _mtx_lock_spin_flags+0xdc
hardclock_cpu() at hardclock_cpu+0x20
tick_hardclock() at tick_hardclock+0xc4
-- interrupt level=0xe pil=0 %o7=0xc018a184 --
_mtx_lock_sleep() at _mtx_lock_sleep+0x140
_mtx_lock_flags() at _mtx_lock_flags+0xb8
start_init() at start_init+0x18
fork_exit() at fork_exit+0x94
fork_trampoline() at fork_trampoline+0x8
KDB: stack backtrace:
_mtx_lock_spin_flags() at _mtx_lock_spin_flags+0xdc
hardclock_cpu() at hardclock_cpu+0x20
tick_hardclock() at tick_hardclock+0xc4
-- interrupt level=0xe pil=0 %o7=0xc018a278 --
_mtx_lock_spin() at _mtx_lock_spin+0x114
_mtx_lock_spin_flags() at _mtx_lock_spin_flags+0xdc
ithread_loop() at ithread_loop+0xf0
fork_exit() at fork_exit+0x94
fork_trampoline() at fork_trampoline+0x8
KDB: stack backtrace:
_mtx_lock_spin_flags() at _mtx_lock_spin_flags+0xdc
hardclock_cpu() at hardclock_cpu+0x20
tick_hardclock() at tick_hardclock+0xc4
-- interrupt level=0xe pil=0 %o7=0xc018a278 --
_mtx_lock_spin() at _mtx_lock_spin+0x114
_mtx_lock_spin_flags() at _mtx_lock_spin_flags+0xdc
cpu_mp_bootstrap() at cpu_mp_bootstrap+0xa8
mp_startup() at mp_startup+0xbc
KDB: stack backtrace:
_mtx_lock_spin_flags() at _mtx_lock_spin_flags+0xdc
hardclock_cpu() at hardclock_cpu+0x20
tick_hardclock() at tick_hardclock+0xc4
-- interrupt level=0xe pil=0 %o7=0xc018a184 --
_mtx_lock_sleep() at _mtx_lock_sleep+0x140
_mtx_lock_flags() at _mtx_lock_flags+0xb8
ithread_execute_handlers() at ithread_execute_handlers+0x138
ithread_loop() at ithread_loop+0xa4
fork_exit() at fork_exit+0x94
fork_trampoline() at fork_trampoline+0x8
KDB: stack backtrace:
_mtx_lock_spin_flags() at _mtx_lock_spin_flags+0xdc
hardclock_cpu() at hardclock_cpu+0x20
tick_hardclock() at tick_hardclock+0xc4
-- interrupt level=0xe pil=0 %o7=0xc018a278 --
_mtx_lock_spin() at _mtx_lock_spin+0x110
_mtx_lock_spin_flags() at _mtx_lock_spin_flags+0xdc
cpu_mp_bootstrap() at cpu_mp_bootstrap+0xa8
mp_startup() at mp_startup+0xbc
blk_dump() at blk_dump+0x10c
KDB: stack backtrace:
_mtx_lock_spin_flags() at _mtx_lock_spin_flags+0xdc
hardclock_cpu() at hardclock_cpu+0x20
tick_hardclock() at tick_hardclock+0xc4
-- interrupt level=0xe pil=0 %o7=0xc018a278 --
_mtx_lock_spin() at _mtx_lock_spin+0x114
_mtx_lock_spin_flags() at _mtx_lock_spin_flags+0xdc
roundrobin() at roundrobin+0x18
softclock() at softclock+0x238
ithread_execute_handlers() at ithread_execute_handlers+0x144
ithread_loop() at ithread_loop+0xa4
fork_exit() at fork_exit+0x94
fork_trampoline() at fork_trampoline+0x8
KDB: stack backtrace:
_mtx_lock_spin_flags() at _mtx_lock_spin_flags+0xdc
hardclock_cpu() at hardclock_cpu+0x20
tick_hardclock() at tick_hardclock+0xc4
-- interrupt level=0xe pil=0 %o7=0xc01acd24 --
cpu_switch() at cpu_switch+0xa0
tl_text_end() at tl_text_end+0xc
KDB: stack backtrace:
_mtx_lock_spin_flags() at _mtx_lock_spin_flags+0xdc
hardclock_cpu() at hardclock_cpu+0x20
tick_hardclock() at tick_hardclock+0xc4
-- interrupt level=0xe pil=0 %o7=0xc018a184 --
_mtx_lock_sleep() at _mtx_lock_sleep+0x12c
_mtx_lock_flags() at _mtx_lock_flags+0xb8
vm_daemon() at vm_daemon+0x18
fork_exit() at fork_exit+0x94
fork_trampoline() at fork_trampoline+0x8
KDB: stack backtrace:
_mtx_lock_spin_flags() at _mtx_lock_spin_flags+0xdc
hardclock_cpu() at hardclock_cpu+0x20
tick_hardclock() at tick_hardclock+0xc4
-- interrupt level=0xe pil=0 %o7=0xc02ed6c8 --
bzero() at bzero+0x68
uma_zalloc_internal() at uma_zalloc_internal+0xe0
uma_zcreate() at uma_zcreate+0x3c
swap_pager_swap_init() at swap_pager_swap_init+0xf0
vm_pageout() at vm_pageout+0x26c
fork_exit() at fork_exit+0x94
fork_trampoline() at fork_trampoline+0x8
KDB: stack backtrace:
_mtx_lock_spin_flags() at _mtx_lock_spin_flags+0xdc
hardclock_cpu() at hardclock_cpu+0x20
tick_hardclock() at tick_hardclock+0xc4
-- interrupt level=0xe pil=0 %o7=0xc018a184 --
_mtx_lock_sleep() at _mtx_lock_sleep+0x144
_mtx_lock_flags() at _mtx_lock_flags+0xb8
ithread_execute_handlers() at ithread_execute_handlers+0x138
ithread_loop() at ithread_loop+0xa4
fork_exit() at fork_exit+0x94
fork_trampoline() at fork_trampoline+0x8

These are traces from the other CPUs; I have it hacked to do
kdb_backtrace() before trying to enter DDB, since this so often
doesn't work.

Remarkably, it did this time though:

db> show witness
Sleep locks:
0 ip6qlock -- last acquired @ netinet6/frag6.c:682
0 ipqlock -- last acquired @ netinet/ip_input.c:1069
0 if_afdata -- last acquired @ net/if.c:539
0 LED sx -- last acquired @ dev/led/led.c:249
2  unit# allocation -- last acquired @ kern/subr_unit.c:592
6  cdev -- last acquired @ kern/kern_conf.c:61
3  UMA zone -- last acquired @ vm/uma_core.c:1841
0 bio queue -- last acquired @ geom/geom_io.c:68
0 GEOM topology -- last acquired @ geom/geom_event.c:183
2  GEOM orphanage -- last acquired @ geom/geom_event.c:196
3  UMA zone -- (already displayed)
2  UMA lock -- last acquired @ vm/uma_core.c:1315
3   UMA zone -- (already displayed)
2  devstat -- last acquired @ kern/subr_devstat.c:83
1  Giant -- last acquired @ dev/ata/ata-all.c:527
2   filedesc structure -- last acquired @ kern/kern_descrip.c:1404
3    pipe mutex -- last acquired @ order list:0
4     sigio lock -- last acquired @ order list:0
5      process group -- last acquired @ kern/kern_fork.c:589
6       process lock -- last acquired @ kern/kern_fork.c:377
7        session -- last acquired @ kern/kern_fork.c:599
8         uidinfo hash -- last acquired @ kern/kern_resource.c:1039
9          uidinfo struct -- last acquired @ order list:0
10          allprison -- last acquired @ order list:0
9          sleep mtxpool -- last acquired @ kern/kern_resource.c:1147
7        sigacts -- last acquired @ kern/kern_kthread.c:98
9        sleep mtxpool -- (already displayed)
7        ktrace -- last acquired @ kern/kern_fork.c:617
3    accept -- last acquired @ order list:0
4     so_snd -- last acquired @ order list:0
5      so_rcv -- last acquired @ order list:0
6       sellck -- last acquired @ kern/sys_generic.c:1140
6       radix node head -- last acquired @ netinet/if_ether.c:136
7        rtentry -- last acquired @ order list:0
8         ifaddr -- last acquired @ order list:0
3   UMA zone -- (already displayed)
2   UMA lock -- (already displayed)
2   UMA boot pages -- last acquired @ vm/uma_core.c:917
2   eventhandler -- last acquired @ kern/subr_eventhandler.c:212
2   eventhandler list -- last acquired @ kern/subr_eventhandler.c:132
2   kobj -- last acquired @ kern/subr_kobj.c:307
2   kernel linker -- last acquired @ kern/kern_linker.c:470
2   system map -- last acquired @ vm/vm_map.c:1096
4    vm page queue mutex -- last acquired @ sparc64/sparc64/pmap.c:937
5     vnode interlock -- last acquired @ order list:0
6      cdev -- (already displayed)
5     pmap -- last acquired @ sparc64/sparc64/pmap.c:1289
3    kernel object -- last acquired @ vm/vm_object.c:444
4     vm page queue mutex -- (already displayed)
3    KMAP ENTRY -- last acquired @ vm/uma_core.c:1841
3    UMA zone -- (already displayed)
3    kmem object -- last acquired @ vm/vm_kern.c:397
4     vm page queue mutex -- (already displayed)
3   kernel object -- (already displayed)
6   process lock -- (already displayed)
2   vm object_list -- last acquired @ vm/vm_object.c:228
3   KMAP ENTRY -- (already displayed)
8   uidinfo hash -- (already displayed)
9   sleep mtxpool -- (already displayed)
4   vm page queue mutex -- (already displayed)
2   standard object -- last acquired @ vm/vm_glue.c:362
4    vm page queue mutex -- (already displayed)
2   TID lock -- last acquired @ kern/subr_unit.c:592
2   intr event -- last acquired @ kern/kern_intr.c:380
6   cdev -- (already displayed)
2   GEOM orphanage -- (already displayed)
2   taskqueue list -- last acquired @ kern/subr_taskqueue.c:125
2   rman head -- last acquired @ kern/subr_rman.c:172
2   rman -- last acquired @ kern/subr_rman.c:511
3    UMA zone -- (already displayed)
2   eeprom_mtx -- last acquired @ sparc64/sparc64/eeprom.c:184
2   devd -- last acquired @ kern/subr_bus.c:517
6   sellck -- (already displayed)
2   ttylist -- last acquired @ kern/tty.c:2842
2   unit# allocation -- (already displayed)
2   LED mtx -- last acquired @ dev/led/led.c:52
2   network driver -- last acquired @ dev/hme/if_hme.c:203
3   iommu -- last acquired @ sparc64/sparc64/iommu.c:1007
2   ifnet -- last acquired @ net/if.c:1170
2   bpf global lock -- last acquired @ net/bpf.c:1597
3    bpf interface lock -- last acquired @ order list:0
4     bpf cdev lock -- last acquired @ order list:0
2   ncr53c9x lock -- last acquired @ dev/esp/ncr53c9x.c:2143
3    UMA zone -- (already displayed)
3    iommu -- (already displayed)
3    CAM BIOQ lock -- last acquired @ cam/cam_xpt.c:4957
2   random reseed -- last acquired @ dev/random/yarrow.c:280
2   arc4_mtx -- last acquired @ libkern/arc4random.c:137
2   pseudofs -- last acquired @ fs/pseudofs/pseudofs_fileno.c:55
2   nfsd_mtx -- last acquired @ nfsserver/nfs_srvsock.c:812
4    so_snd -- (already displayed)
2   if_clone lock -- last acquired @ net/if_clone.c:161
2   if_cloners lock -- last acquired @ net/if_clone.c:245
2   domain list -- last acquired @ kern/uipc_domain.c:226
3   pfil_head_list lock -- last acquired @ net/pfil.c:114
2   PFil hook read/write mutex -- last acquired @ net/pfil.c:108
3    pfil_head_list lock -- (already displayed)
2   tcp -- last acquired @ netinet/tcp_subr.c:1409
3    tcpinp -- last acquired @ order list:0
4     so_snd -- (already displayed)
6   radix node head -- (already displayed)
2   lo_mtx -- last acquired @ net/if_loop.c:160
2   in6_addr_list -- last acquired @ netinet6/nd6.c:556
3   CAM BIOQ lock -- (already displayed)
2   devstat -- (already displayed)
2   taskqueue -- last acquired @ kern/subr_taskqueue.c:73
6  process lock -- (already displayed)
0 pbuf mutex -- last acquired @ vm/swap_pager.c:403
0 module subsystem sx lock -- last acquired @ kern/kern_module.c:115
0 kernel environment -- last acquired @ kern/kern_environment.c:291
0 user map -- last acquired @ vm/vm_map.c:2485
3  UMA zone -- (already displayed)
2  system map -- (already displayed)
2  vm object_list -- (already displayed)
2  standard object -- (already displayed)
4  vm page queue mutex -- (already displayed)
0 ddp_list_mtx -- last acquired @ order list:0
1  ddp_mtx -- last acquired @ order list:0
0 slip_mtx -- last acquired @ order list:0
1  slip sc_mtx -- last acquired @ order list:0
0 udp -- last acquired @ order list:0
1  udpinp -- last acquired @ order list:0
2   in_multi_mtx -- last acquired @ order list:0
3    igmp_mtx -- last acquired @ netinet/igmp.c:444
4     if_addr_mtx -- last acquired @ order list:0
4   so_snd -- (already displayed)
0 unp -- last acquired @ order list:0
4  so_snd -- (already displayed)
0 proctree -- last acquired @ kern/kern_fork.c:301
1  allproc -- last acquired @ kern/kern_fork.c:310
6   process lock -- (already displayed)
5  process group -- (already displayed)

Spin locks:
0 ap boot -- last acquired @ order list:0
1  rm.mutex_mtx -- last acquired @ order list:0
2   hptlock -- last acquired @ order list:0
3    sio -- last acquired @ order list:0
4     uart_hwmtx -- last acquired @ dev/uart/uart_dev_z8530.c:401
5      sabtty -- last acquired @ order list:0
6       zstty -- last acquired @ order list:0
7        ng_node -- last acquired @ order list:0
8         ng_worklist -- last acquired @ order list:0
9          taskqueue_fast -- last acquired @ order list:0
10          intr table -- last acquired @ sparc64/sparc64/intr_machdep.c:294
11           sleepq chain -- last acquired @ kern/subr_sleepqueue.c:223
12            sched lock -- last acquired @ sparc64/sparc64/mp_machdep.c:366
13             turnstile chain -- last acquired @ kern/subr_turnstile.c:478
14              td_contested -- last acquired @ order list:0
15               callout -- last acquired @ kern/kern_timeout.c:293
16                entropy harvest mutex -- last acquired @ dev/random/randomdev_soft.c:256
17                 allpmaps -- last acquired @ order list:0
18                  vm page queue free mutex -- last acquired @ vm/vm_page.c:792
19                   icu -- last acquired @ order list:0
20                    smp rendezvous -- last acquired @ order list:0
21                     ipi -- last acquired @ order list:0
22                      rtc_mtx -- last acquired @ order list:0
23                       clk -- last acquired @ order list:0
24                        mutex profiling lock -- last acquired @ order list:0
25                         kse zombie lock -- last acquired @ order list:0
26                          ALD Queue -- last acquired @ order list:0
27                           tw_osl_io_lock -- last acquired @ order list:0
28                            tw_osl_q_lock -- last acquired @ order list:0
29                             tw_cl_io_lock -- last acquired @ order list:0
30                              tw_cl_intr_lock -- last acquired @ order list:0
31                               tw_cl_gen_lock -- last acquired @ order list:0
15             callout -- (already displayed)
15            callout -- (already displayed)

Locks which were never acquired:
g_disk_done
MD config lock
arp_inq
rts_inq
addrsel_sxlock
addrsel_lock
scope6_lock
ip6_inq
rip
tcp_hc_entry
ip_inq
pseudofs_vncache
gif_mtx
ppp_softc_list_mtx
tunmtx
msq
sem
semid
Synch NFS reply posting
NFS reqq lock
nfs4dev state
nfs4dev waitq
nfs4dev newq
nullhs
dirhash list
vfs hash
Syncer mtx
vnode_free_list
mntid
if send queue
tty
fast_taskqueue
pt_mtx
nfslock
sf_bufs list lock
ktrace_sx
uma object
p_peers
bpin lock
bdone lock
buffer daemon lock
needsbuffer lock
runningbufspace lock
buf queue lock
umtxq_lock
fifo mutex
Name Cache
UUID generator mutex lock
so_glabel
knlist lock for lockless objects
encapmtx
protect sysfilt_ops
kqueue order
rtsock route_cb lock
mountlist
rawcb
Softdep Lock
accept_filter_mtx
securelevel mutex lock
DEVFS ruleset lock
acct_sx
pmc shared lock
fdesc
filelist lock
sysctl lock
malloc
phys_pager list
dev_pager list
dev_pager create
swapdev
swap_pager list
vm map sleep mutex
db> show locks
exclusive sleep mutex filedesc structure r = 0 (0xfffff80002c89c48) locked @ kern/kern_descrip.c:1404
exclusive sleep mutex Giant r = 0 (0xc0710980) locked @ dev/ata/ata-all.c:527
db> show alllocks
Process 2 (g_event) thread 0xfffff802be9ea000 (100011)
exclusive sx GEOM topology r = 0 (0xc044da50) locked @ geom/geom_event.c:183
Process 0 (swapper) thread 0xc044dfd8 (0)
exclusive sleep mutex filedesc structure r = 0 (0xfffff80002c89c48) locked @ kern/kern_descrip.c:1404
exclusive sleep mutex Giant r = 0 (0xc0710980) locked @ dev/ata/ata-all.c:527
db> show allpcpu
Current CPU: 0

cpuid        = 0
curthread    = 0xc044dfd8: pid 0 "swapper"
curpcb       = 0xc0c17980
fpcurthread  = none
idlethread   = 0xfffff802be9f1ae0: pid 21 "idle: cpu0"
spin locks held:

cpuid        = -371328640
curthread    = 0xfffff802be9f1830: pid 20 "idle: cpu1"
curpcb       = 0xc0080540
fpcurthread  = [hung, grr]

Kris
-------------- next part --------------
A non-text attachment was scrubbed...
Name: not available
Type: application/pgp-signature
Size: 189 bytes
Desc: not available
Url : http://lists.freebsd.org/pipermail/freebsd-sparc64/attachments/20060320/3133cebd/attachment.pgp


More information about the freebsd-sparc64 mailing list