ktr/alq/witness failure.

From: Julian Elischer (julian_at_elischer.org)
Date: 09/27/04

  • Next message: Andreas Klemm: "Re: Fatal error 'Spinlock called when not threaded.' ... (Re: FreeBSD 5.3-BETA6 available)"
    Date: Sun, 26 Sep 2004 23:15:05 -0700
    To: Current <freebsd-current@freebsd.org>, John Baldwin <jhb@freebsd.org>
    
    

    I'm not going to stop and debug this now because I'm chasing another
    problem but I can probably stash a corefile somewhere if people want it..

    ref4# sysctl debug.ktr.mask=0x2fffffff
    debug.ktr.mask: 262144
      ->
    805306367
    ref4#
    ref4#
    ref4# sysctl debug.ktr.mask=0x0
    kernel trap 12 with interrupts disabled

    Fatal double fault:
    eip = 0xc053336e
    esp = 0xcbaa3ff4
    ebp = 0xcbaa401c
    cpuid = 0; apic id = 00
    panic: double fault
    cpuid = 0
    KDB: enter: panic
    [thread 100027]
    Stopped at kdb_enter+0x2b: nop
    db> tr
    kdb_enter(c069adef) at kdb_enter+0x2b
    panic(c06b581a,c06b59c4,0,0,0) at panic+0x127
    dblfault_handler() at dblfault_handler+0x7a
    --- trap 0x17, eip = 0xc053336e, esp = 0xcbaa3ff4, ebp = 0xcbaa401c ---
    witness_checkorder(c111776c,9,c06b5972,2bb) at witness_checkorder+0x6a
    _mtx_lock_flags(c111776c,0,c06b5972,2bb,c10e3a80) at _mtx_lock_flags+0x5b
    trap_pfault(cbaa40ac,0,608) at trap_pfault+0xb4
    trap(18,5f660010,63730010,9,c111776c) at trap+0x335
    calltrap() at calltrap+0x5
    --- trap 0xc, eip = 0xc0533495, esp = 0xcbaa40ec, ebp = 0xcbaa4114 ---
    witness_checkorder(c111776c,9,c06b597b,2bb) at witness_checkorder+0x191
    _mtx_lock_flags(c111776c,0,c06b5972,2bb,c10e3a80) at _mtx_lock_flags+0x5b
    trap_pfault(cbaa41a4,0,608) at trap_pfault+0xb4
    trap(9700018,705f0010,6b2e0010,9,c111776c) at trap+0x335

    ----
    etc. (LOTS OF IDENTICAL FRAMES REMOVED)
    ----
    --- trap 0xc, eip = 0xc0533495, esp = 0xcbaa5734, ebp = 0xcbaa575c ---
    witness_checkorder(c111776c,9,c06b597b,2bb) at witness_checkorder+0x191
    _mtx_lock_flags(c111776c,0,c06b5972,2bb,c10e3a80) at _mtx_lock_flags+0x5b
    trap_pfault(cbaa57ec,0,608) at trap_pfault+0xb4
    trap(18,10,c0710010,9,c111776c) at trap+0x335
    calltrap() at calltrap+0x5
    --- trap 0xc, eip = 0xc0533495, esp = 0xcbaa582c, ebp = 0xcbaa5854 ---
    witness_checkorder(c111776c,9,c06b597b,2bb) at witness_checkorder+0x191
    _mtx_lock_flags(c111776c,0,c06b5972,2bb,c10e3a80) at _mtx_lock_flags+0x5b
    trap_pfault(cbaa58e4,0,608) at trap_pfault+0xb4
    trap(c10e0018,c0750010,c0750010,9,c111776c) at trap+0x335
    calltrap() at calltrap+0x5
    --- trap 0xc, eip = 0xc0533495, esp = 0xcbaa5924, ebp = 0xcbaa594c ---
    witness_checkorder(c111776c,9,c06b597b,2bb) at witness_checkorder+0x191
    _mtx_lock_flags(c111776c,0,c06b5972,2bb,c10e3a80) at _mtx_lock_flags+0x5b
    trap_pfault(cbaa59dc,0,608) at trap_pfault+0xb4
    trap(18,c10e0010,cbaa0010,9,c06fa2e0) at trap+0x335
    calltrap() at calltrap+0x5
    --- trap 0xc, eip = 0xc0533495, esp = 0xcbaa5a1c, ebp = 0xcbaa5a44 ---
    witness_checkorder(c06fa2e0,9,c0697593,1d3) at witness_checkorder+0x191
    _mtx_lock_flags(c06fa2e0,0,c069758a,1d3,c069851a) at _mtx_lock_flags+0x5b
    alq_post(c13f3300,c15f5638) at alq_post+0x60
    ktr_tracepoint(200,c0698511,186,c06985f6,c0674241,19,c10e2a08,0,0,0) at 
    ktr_tracepoint+0x17e
    ithread_schedule(c10d7900,e,c10e3a80,c15e7420,c06f00d0) at ithread_schedule+0x6b
    intr_execute_handlers(c06f00d0,cbaa5b50,c15e7420,5fb,c10e3af0) at 
    intr_execute_handlers+0x131
    atpic_handle_intr(e) at atpic_handle_intr+0x92
    Xatpic_intr14() at Xatpic_intr14+0x20
    --- interrupt, eip = 0xc053392a, esp = 0xcbaa5b94, ebp = 0xcbaa5ba4 ---
    witness_lock(c15e7420,8,c06a219e,5fb,c6342b10) at witness_lock+0xc2
    _mtx_lock_flags(c15e7420,0,c06a2195,5fb) at _mtx_lock_flags+0x97
    bqrelse(c6342b10) at bqrelse+0xe7
    bufdone(c6342b10) at bufdone+0x446
    cluster_callback(c62e64c0) at cluster_callback+0xa6
    bufdone(c62e64c0,c0709820,0,c06a2195,c14) at bufdone+0x13b
    bufdonebio(c62e64c0) at bufdonebio+0x24
    biodone(c62e64c0,c15da18c,c15da18c,cbaa5cd0,cbaa5cb0) at biodone+0x57
    g_dev_done(c15da18c) at g_dev_done+0x5b
    biodone(c15da18c,cbaa5cd0,0,c0695cbe,1c1) at biodone+0x57
    g_io_schedule_up(c10e3a80) at g_io_schedule_up+0xb5
    g_up_procbody(0,cbaa5d48,0,c04e4dbc,0) at g_up_procbody+0x32
    fork_exit(c04e4dbc,0,cbaa5d48) at fork_exit+0xd4
    fork_trampoline() at fork_trampoline+0x8
    --- trap 0x1, eip = 0, esp = 0xcbaa5d7c, ebp = 0 ---
    db>  show pcpu
    cpuid        = 0
    curthread    = 0xc10e3a80: pid 3 "g_up"
    curpcb       = 0xcbaa5da0
    fpcurthread  = none
    idlethread   = 0xc10da480: pid 11 "idle: cpu0"
    APIC ID      = 0
    currentldt   = 0x28
    spin locks held:
    db> db> show witness
    Sleep locks:
    0 ATAPI CD bioqueue lock -- last acquired @ dev/ata/atapi-cd.c:1100
    0 g_xdown -- last acquired @ geom/geom_io.c:392
    4  ATA disk bioqueue lock -- last acquired @ dev/ata/ata-disk.c:236
    4  ATA queue lock -- last acquired @ dev/ata/ata-queue.c:176
    5   ATA state lock -- last acquired @ dev/ata/ata-queue.c:182
    4  bio queue -- last acquired @ geom/geom_io.c:65
    12 system map -- last acquired @ vm/vm_kern.c:296
    13  kmem object -- last acquired @ vm/vm_kern.c:398
    14   vm page queue mutex -- last acquired @ kern/vfs_bio.c:3217
    15    CMAPCADDR12 -- last acquired @ i386/i386/pmap.c:2473
    15    vnode interlock -- last acquired @ kern/vfs_bio.c:1531
    16     cdev -- last acquired @ kern/kern_conf.c:81
    16     vnode_free_list -- last acquired @ kern/vfs_subr.c:575
    16     Syncer mtx -- last acquired @ kern/vfs_subr.c:1846
    16     Name Cache -- last acquired @ kern/vfs_cache.c:352
    15    pmap -- last acquired @ i386/i386/pmap.c:1901
    16     uma object -- last acquired @ vm/uma_core.c:963
    16     UMA pcpu -- last acquired @ vm/uma_core.c:2206
    17      KMAP ENTRY -- last acquired @ vm/uma_core.c:2224
    18       UMA zone -- last acquired @ vm/uma_core.c:2224
    13  kernel object -- last acquired @ kern/vfs_bio.c:3671
    14   vm page queue mutex -- (already displayed)
    0 g_xup -- last acquired @ geom/geom_io.c:449
    1  g_disk_done -- last acquired @ geom/geom_disk.c:196
    4   bio queue -- (already displayed)
    16  UMA pcpu -- (already displayed)
    3  Giant -- last acquired @ kern/vfs_bio.c:3092
    4   struct mount mtx -- last acquired @ ufs/ffs/ffs_vfsops.c:1147
    15   vnode interlock -- (already displayed)
    4   UMA lock -- last acquired @ vm/uma_core.c:1466
    12   Malloc Stats -- last acquired @ kern/kern_malloc.c:210
    16   UMA pcpu -- (already displayed)
    4   eventhandler -- last acquired @ kern/subr_eventhandler.c:213
    5    eventhandler list -- last acquired @ kern/kern_exit.c:199
    4   standard object -- last acquired @ kern/vfs_bio.c:3198
    5    vm object_list -- last acquired @ vm/vm_object.c:643
    14   vm page queue mutex -- (already displayed)
    4   kernel linker -- last acquired @ kern/kern_linker.c:1061
    4   vm86 lock -- last acquired @ i386/i386/vm86.c:582
    4   TID lock -- last acquired @ kern/kern_thread.c:206
    4   kobj -- last acquired @ kern/subr_kobj.c:298
    4   GEOM orphanage -- last acquired @ geom/geom_event.c:170
    4   ithread -- last acquired @ kern/kern_intr.c:276
    4   bounce pages lock -- last acquired @ i386/i386/busdma_machdep.c:860
    4   bpf global lock -- last acquired @ net/bpf.c:1446
    5    bpf interface lock -- last acquired @ order list:0
    6     bpf cdev lock -- last acquired @ order list:0
    4   rman -- last acquired @ kern/subr_rman.c:448
    12   Malloc Stats -- (already displayed)
    12   system map -- (already displayed)
    4   taskqueue list -- last acquired @ kern/subr_taskqueue.c:85
    4   rman head -- last acquired @ kern/subr_rman.c:111
    4   sf_buf -- last acquired @ i386/i386/vm_machdep.c:674
    4   bio queue -- (already displayed)
    4   rtsock route_cb lock -- last acquired @ net/rtsock.c:234
    4   devstat -- last acquired @ kern/subr_devstat.c:190
    4   if_cloners lock -- last acquired @ net/if_clone.c:199
    4   buffer daemon lock -- last acquired @ kern/vfs_bio.c:408
    4   pseudofs -- last acquired @ fs/pseudofs/pseudofs_fileno.c:86
    4   ttylist -- last acquired @ kern/tty.c:2757
    11   tty -- last acquired @ kern/kern_event.c:1451
    4   fdesc -- last acquired @ kern/kern_descrip.c:1614
    5    filedesc structure -- last acquired @ kern/kern_descrip.c:1926
    6     devd -- last acquired @ kern/subr_bus.c:497
    9      sellck -- last acquired @ kern/sys_generic.c:726
    6     accept -- last acquired @ kern/uipc_socket.c:334
    7      so_snd -- last acquired @ kern/uipc_socket.c:2091
    8       so_rcv -- last acquired @ kern/uipc_socket.c:2092
    9        sellck -- (already displayed)
    9        radix node head -- last acquired @ netinet/if_ether.c:139
    10        ifnet -- last acquired @ net/if.c:1019
    10        rtentry -- last acquired @ netinet/if_ether.c:785
    11         rts_inq -- last acquired @ net/netisr.c:231
    11         network driver -- last acquired @ dev/fxp/if_fxp.c:1756
    12          knlist lock for lockless objects -- last acquired @ 
    kern/kern_event.c:1451
    12          Malloc Stats -- (already displayed)
    12          if send queue -- last acquired @ dev/fxp/if_fxp.c:1268
    12          system map -- (already displayed)
    11         ifaddr -- last acquired @ netinet6/nd6_nbr.c:1235
    9        process lock -- last acquired @ ufs/ffs/ffs_vnops.c:613
    10        sigacts -- last acquired @ kern/kern_sig.c:294
    10        ktrace -- last acquired @ kern/kern_fork.c:607
    10        struct pargs.ref -- last acquired @ kern/kern_proc.c:1078
    10        session -- last acquired @ kern/kern_proc.c:317
    11         tty -- (already displayed)
    15         vnode interlock -- (already displayed)
    11         uidinfo hash -- last acquired @ kern/kern_resource.c:1001
    12          sleep mtxpool -- last acquired @ kern/kern_prot.c:1755
    12          uidinfo struct -- last acquired @ order list:0
    13           allprison -- last acquired @ kern/kern_jail.c:460
    6     pipe mutex -- last acquired @ kern/sys_pipe.c:1520
    9      sellck -- (already displayed)
    7      sigio lock -- last acquired @ kern/kern_descrip.c:729
    8       process group -- last acquired @ kern/kern_proc.c:393
    9        process lock -- (already displayed)
    4   if_clone lock -- last acquired @ net/if_clone.c:321
    4   pfil_head_mtx -- last acquired @ net/pfil.c:166
    5    pfil_head_list lock -- last acquired @ net/pfil.c:172
    4   lo_mtx -- last acquired @ net/if_loop.c:154
    4   nfsd_mtx -- last acquired @ nfsserver/nfs_srvsock.c:811
    4   pbuf mutex -- last acquired @ vm/vm_pager.c:414
    4   domain list -- last acquired @ kern/uipc_domain.c:110
    4   mntid -- last acquired @ kern/vfs_subr.c:400
    5    mountlist -- last acquired @ kern/vfs_subr.c:3456
    4   ATA disk bioqueue lock -- (already displayed)
    4   ATA queue lock -- (already displayed)
    4   taskqueue -- last acquired @ kern/subr_taskqueue.c:193
    4   pseudofs_vncache -- last acquired @ fs/pseudofs/pseudofs_vncache.c:239
    4   udp -- last acquired @ netinet/udp_usrreq.c:1052
    5    udp6inp -- last acquired @ netinet6/udp6_usrreq.c:670
    8     so_rcv -- (already displayed)
    5    udpinp -- last acquired @ netinet/udp_usrreq.c:1058
    6     arc4_mtx -- last acquired @ libkern/arc4random.c:137
    6     accept -- (already displayed)
    4   ufs ihash -- last acquired @ ufs/ufs/ufs_ihash.c:120
    15   vnode interlock -- (already displayed)
    4   dirhash list -- last acquired @ ufs/ufs/ufs_dirhash.c:348
    5    dirhash -- last acquired @ ufs/ufs/ufs_dirhash.c:349
    4   runningbufspace lock -- last acquired @ kern/vfs_bio.c:317
    5    ALDmtx -- last acquired @ kern/kern_alq.c:195
    4   bdone lock -- last acquired @ kern/vfs_bio.c:3012
    4   needsbuffer lock -- last acquired @ kern/vfs_bio.c:298
    4   buf queue lock -- last acquired @ kern/vfs_bio.c:1520
    15   vnode interlock -- (already displayed)
    4   accounting -- last acquired @ kern/kern_acct.c:232
    4   tcp -- last acquired @ netinet/tcp_timer.c:138
    5    tcpinp -- last acquired @ netinet/tcp_timer.c:184
    6     so_glabel -- last acquired @ kern/uipc_socket.c:282
    6     tcp_hc_entry -- last acquired @ netinet/tcp_hostcache.c:713
    6     random reseed -- last acquired @ dev/random/yarrow.c:193
    6     arc4_mtx -- (already displayed)
    6     accept -- (already displayed)
    4   protect sysfilt_ops -- last acquired @ kern/kern_event.c:667
    4   unp -- last acquired @ kern/uipc_usrreq.c:247
    6    accept -- (already displayed)
    0 arp_inq -- last acquired @ net/netisr.c:231
    0 ip6qlock -- last acquired @ netinet6/frag6.c:682
    0 igmp_mtx -- last acquired @ netinet/igmp.c:431
    0 ip_inq -- last acquired @ net/netisr.c:231
    0 ipqlock -- last acquired @ netinet/ip_input.c:1096
    0 sem -- last acquired @ kern/sysv_sem.c:1174
    0 if_afdata -- last acquired @ net/if.c:489
    0 GEOM topology -- last acquired @ geom/geom_event.c:202
    4  bio queue -- (already displayed)
    4  GEOM orphanage -- (already displayed)
    4  bdone lock -- (already displayed)
    12 Malloc Stats -- (already displayed)
    4  devstat -- (already displayed)
    12 system map -- (already displayed)
    4  ATA queue lock -- (already displayed)
    1  swapdev -- last acquired @ vm/swap_pager.c:2127
    0 p_peers -- last acquired @ kern/kern_exit.c:243
    0 module subsystem sx lock -- last acquired @ kern/kern_module.c:404
    0 rawcb -- last acquired @ net/raw_usrreq.c:80
    8  so_rcv -- (already displayed)
    0 kernel environment -- last acquired @ kern/kern_environment.c:285
    0 sysctl lock -- last acquired @ kern/kern_sysctl.c:1315
    1  addrsel_lock -- last acquired @ netinet6/in6_src.c:1137
    1  malloc -- last acquired @ kern/kern_malloc.c:588
    1  rip -- last acquired @ netinet/raw_ip.c:845
    1  filelist lock -- last acquired @ kern/kern_descrip.c:1388
    5   filedesc structure -- (already displayed)
    1  allproc -- last acquired @ kern/sched_4bsd.c:428
    2   user map -- last acquired @ vm/vm_glue.c:175
    3    Giant -- (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 proctree -- last acquired @ kern/kern_prot.c:401
    1  allproc -- (already displayed)
    Spin locks:
    Locks which were never acquired:
    swap_pager swhash
    scope6_lock
    ip6_inq
    pseudofs_fileno
    tunmtx
    msq
    semid
    msdosfs dehash
    nfs4dev state
    nfs4dev waitq
    nfs4dev newq
    cd9660_ihash
    agp lock
    callout_wait_lock
    fifo mutex
    UUID generator mutex lock
    umtx
    jumbo mutex
    accept_filter_mtx
    encapmtx
    securelevel mutex lock
    kqueue order
    phys_pager list
    dev_pager list
    dev_pager create
    swap_pager list
    vm map sleep mutex
    lockmgr
    PMAP2
    db>
    _______________________________________________
    freebsd-current@freebsd.org mailing list
    http://lists.freebsd.org/mailman/listinfo/freebsd-current
    To unsubscribe, send any mail to "freebsd-current-unsubscribe@freebsd.org"
    

  • Next message: Andreas Klemm: "Re: Fatal error 'Spinlock called when not threaded.' ... (Re: FreeBSD 5.3-BETA6 available)"

    Relevant Pages

    • Re: Recursive mutex that can be waited upon (pthread)
      ... While you can use a mutex to avoid that data is changed, for me having a mutex does not mean that data is not changed, it only means that data is not changed by a different thread. ... My own thread may of course change the data, hence functions I call may want to change the data and if they do so, they must be sure that these changes are atomically, hence they must lock the object and they simply can't rely that I locked the object before -> thus I need recursive locks. ... Then I could as well throw out threads of my code and just use a single thread going through an event queue. ... you have a predicate condition on an invariant. ...
      (comp.programming.threads)
    • Re: crash via vm_page_sleep_if_busy() and contigmalloc
      ... and unlock its mutex. ... > page queue mutex was relinquished. ... I think callers need to either lock the vm_object in every case ...
      (freebsd-hackers)
    • crash via vm_page_sleep_if_busy() and contigmalloc
      ... and unlock its mutex. ... page queue mutex was relinquished. ... from other callers of vm_page_sleep_if_busysuch that they know the ... I think callers need to either lock the vm_object in every case ...
      (freebsd-hackers)
    • Queue can result in nested monitor deadlock
      ... I think there's a slight design flaw in the Queue class that makes it ... The problem is that the mutex ... so you are subject to nested monitor deadlock. ... "Optionally takes a lock to ...
      (comp.lang.python)
    • Re: Seeing lock order reversal
      ... 21 vm page queue free mutex -- ... 18 UMA zone -- ... 18 sleep mtxpool -- ... 15 process lock -- ...
      (freebsd-current)