Page MenuHomeFreeBSD
Paste P168

panic: deadlkres: possible deadlock detected for 0xfffff80141b04560, blocked for 1801695 ticks
ActivePublic

Authored by eadler on Apr 12 2018, 3:59 AM.
How to reproduce?
# kldload sem
# kldunload sem
< wait debug.deadlkres.slptime_threshold seconds >
Reading symbols from ./kernel/kernel...Reading symbols from /usr/home/eax/crashes/sem_load_dklres/kernel/kernel.debug...done.
done.
Unread portion of the kernel message buffer:
[29474] panic: deadlkres: possible deadlock detected for 0xfffff80141b04560, blocked for 1801695 ticks
[29474]
[29474] cpuid = 31
[29474] time = 1523493929
[29474] KDB: stack backtrace:
[29474] db_trace_self_wrapper() at db_trace_self_wrapper+0x2b/frame 0xfffffe00a6204960
[29474] vpanic() at vpanic+0x18d/frame 0xfffffe00a62049c0
[29474] panic() at panic+0x43/frame 0xfffffe00a6204a20
[29474] deadlkres() at deadlkres+0x3a6/frame 0xfffffe00a6204a70
[29474] fork_exit() at fork_exit+0x84/frame 0xfffffe00a6204ab0
[29474] fork_trampoline() at fork_trampoline+0xe/frame 0xfffffe00a6204ab0
[29474] --- trap 0, rip = 0, rsp = 0, rbp = 0 ---
[29474] KDB: enter: panic
__curthread () at ./machine/pcpu.h:230
230 __asm("movq %%gs:%1,%0" : "=r" (td)
(kgdb) bt
#0 __curthread () at ./machine/pcpu.h:230
#1 doadump (textdump=0x1) at /usr/src/sys/kern/kern_shutdown.c:361
#2 0xffffffff80434f4c in db_fncall_generic (addr=<optimized out>, rv=<optimized out>, nargs=<optimized out>, args=<optimized out>)
at /usr/src/sys/ddb/db_command.c:609
#3 db_fncall (dummy1=<optimized out>, dummy2=<optimized out>, dummy3=<optimized out>, dummy4=<optimized out>) at /usr/src/sys/ddb/db_command.c:657
#4 0xffffffff80434a99 in db_command (last_cmdp=<optimized out>, cmd_table=<optimized out>, dopager=<optimized out>) at /usr/src/sys/ddb/db_command.c:481
#5 0xffffffff80434814 in db_command_loop () at /usr/src/sys/ddb/db_command.c:534
#6 0xffffffff80437a3f in db_trap (type=<optimized out>, code=<optimized out>) at /usr/src/sys/ddb/db_main.c:250
#7 0xffffffff80babf53 in kdb_trap (type=0x3, code=0xffff0ff0, tf=<optimized out>) at /usr/src/sys/kern/subr_kdb.c:697
#8 0xffffffff81024aa8 in trap (frame=0xfffffe00a6204890) at /usr/src/sys/amd64/amd64/trap.c:548
#9 <signal handler called>
#10 kdb_enter (why=0xffffffff8129f663 "panic", msg=<optimized out>) at /usr/src/sys/kern/subr_kdb.c:479
#11 0xffffffff80b66b5a in vpanic (fmt=<optimized out>, ap=0xfffffe00a6204a00) at /usr/src/sys/kern/kern_shutdown.c:826
#12 0xffffffff80b66be3 in panic (fmt=0xffffffff81deab08 <cnputs_mtx> "5i&\201\377\377\377\377") at /usr/src/sys/kern/kern_shutdown.c:764
#13 0xffffffff80b00466 in deadlkres () at /usr/src/sys/kern/kern_clock.c:288
#14 0xffffffff80b26e34 in fork_exit (callout=0xffffffff80b000c0 <deadlkres>, arg=0x0, frame=0xfffffe00a6204ac0) at /usr/src/sys/kern/kern_fork.c:1039
#15 <signal handler called>
(kgdb)
#13 0xffffffff80b00466 in deadlkres () at /usr/src/sys/kern/kern_clock.c:288
288 panic("%s: possible deadlock detected for %p, blocked for %d ticks\n",
(kgdb) info locals
tryl = <optimized out>
slpticks = 0x1b7740
blkticks = 0xdbba0
p = 0xfffff80141b00538
td = <optimized out>
wchan = 0xffffffff81deb2d8 <kld_sx>
tticks = 0x1b7ddf
slptype = <optimized out>
i = <error reading variable i (Cannot access memory at address 0x2)>
(kgdb) info registers
rax 0x12 0x12
rbx 0xffffffff81deb2d8 0xffffffff81deb2d8
rcx 0x80 0x80
rdx 0xfffffe00a6204850 0xfffffe00a6204850
rsi 0x80 0x80
rdi 0xffffffff81deab08 0xffffffff81deab08
rbp 0xfffffe00a6204a70 0xfffffe00a6204a70
rsp 0xfffffe00a6204a30 0xfffffe00a6204a30
r8 0x1 0x1
r9 0x0 0x0
r10 0xffffffff81cdc698 0xffffffff81cdc698
r11 0x0 0x0
r12 0xfffff80141b04560 0xfffff80141b04560
r13 0xdbba0 0xdbba0
r14 0xfffff80141b00538 0xfffff80141b00538
r15 0x1b7ddf 0x1b7ddf
rip 0xffffffff80b00466 0xffffffff80b00466 <deadlkres+934>
eflags 0x82 [ SF ]
cs 0x20 0x20
ss 0x28 0x28
ds <unavailable>
es <unavailable>
fs <unavailable>
gs <unavailable>
fs_base <unavailable>
gs_base <unavailable>
(kgdb) p *p
$3 = {
p_list = {
le_next = 0xfffff80200103000,
le_prev = 0xfffff8001f187000
},
p_threads = {
tqh_first = 0xfffff80141b04560,
tqh_last = 0xfffff80141b04570
},
p_slock = {
lock_object = {
lo_name = 0xffffffff8129ab1c "process slock",
lo_flags = 0x20030000,
lo_data = 0x0,
lo_witness = 0x0
},
mtx_lock = 0x0
},
p_ucred = 0xfffff80200216c00,
p_fd = 0xfffff800398548a0,
p_fdtol = 0x0,
p_stats = 0xfffff80012fea000,
p_limit = 0xfffff8001fa23500,
p_limco = {
c_links = {
le = {
le_next = 0x0,
le_prev = 0x0
},
sle = {
sle_next = 0x0
},
tqe = {
tqe_next = 0x0,
tqe_prev = 0x0
}
},
c_time = 0x0,
c_precision = 0x0,
c_arg = 0x0,
c_func = 0x0,
c_lock = 0xfffff80141b00658,
c_flags = 0x0,
c_iflags = 0x0,
c_cpu = 0x0
},
p_sigacts = 0xfffff80285537000,
p_flag = 0x10004002,
p_flag2 = 0x0,
p_state = PRS_NORMAL,
p_pid = 0xbc73,
p_hash = {
le_next = 0x0,
le_prev = 0xfffffe00063ae398
},
p_pglist = {
le_next = 0x0,
le_prev = 0xfffff800390bc710
},
p_pptr = 0xfffff80003696538,
p_sibling = {
le_next = 0xfffff80294339a70,
le_prev = 0xfffff8001f5c4620
},
p_children = {
lh_first = 0x0
},
p_reaper = 0xfffff80003696538,
p_reaplist = {
lh_first = 0x0
},
p_reapsibling = {
le_next = 0xfffff80200103000,
le_prev = 0xfffff8001f187110
},
p_mtx = {
lock_object = {
lo_name = 0xffffffff812297e6 "process lock",
lo_flags = 0x21430000,
lo_data = 0x0,
lo_witness = 0xfffff8087f063400
},
mtx_lock = 0x0
},
p_statmtx = {
lock_object = {
lo_name = 0xffffffff811e2c04 "pstatl",
lo_flags = 0x20030000,
lo_data = 0x0,
lo_witness = 0x0
},
mtx_lock = 0x0
},
p_itimmtx = {
lock_object = {
lo_name = 0xffffffff8121fea2 "pitiml",
lo_flags = 0x20030000,
lo_data = 0x0,
lo_witness = 0x0
},
mtx_lock = 0x0
},
p_profmtx = {
lock_object = {
lo_name = 0xffffffff8127b6d4 "pprofl",
lo_flags = 0x20030000,
lo_data = 0x0,
lo_witness = 0x0
},
mtx_lock = 0x0
},
p_ksi = 0xfffff8000756a000,
p_sigqueue = {
sq_signals = {
__bits = {0x100,
0x0,
0x0,
0x0}
},
sq_kill = {
__bits = {0x100,
0x0,
0x0,
0x0}
},
sq_ptrace = {
__bits = {0x0,
0x0,
0x0,
0x0}
},
sq_list = {
tqh_first = 0x0,
tqh_last = 0xfffff80141b00710
},
sq_proc = 0xfffff80141b00538,
sq_flags = 0x1
},
p_oppid = 0x0,
p_vmspace = 0xfffff80141f6c000,
p_swtick = 0x819d1360,
p_cowgen = 0x2,
p_realtimer = {
it_interval = {
tv_sec = 0x0,
tv_usec = 0x0
},
it_value = {
tv_sec = 0x0,
tv_usec = 0x0
}
},
p_ru = {
ru_utime = {
tv_sec = 0x0,
tv_usec = 0x0
},
ru_stime = {
tv_sec = 0x0,
tv_usec = 0x0
},
ru_maxrss = 0x0,
ru_ixrss = 0x0,
ru_idrss = 0x0,
ru_isrss = 0x0,
ru_minflt = 0x0,
ru_majflt = 0x0,
ru_nswap = 0x0,
ru_inblock = 0x0,
ru_oublock = 0x0,
ru_msgsnd = 0x0,
ru_msgrcv = 0x0,
ru_nsignals = 0x0,
ru_nvcsw = 0x0,
ru_nivcsw = 0x0
},
p_rux = {
rux_runtime = 0x300256,
rux_uticks = 0x0,
rux_sticks = 0x0,
rux_iticks = 0x0,
rux_uu = 0x0,
rux_su = 0x39f,
rux_tu = 0x39f
},
p_crux = {
rux_runtime = 0x0,
rux_uticks = 0x0,
rux_sticks = 0x0,
rux_iticks = 0x0,
rux_uu = 0x0,
rux_su = 0x0,
rux_tu = 0x0
},
p_profthreads = 0x0,
p_exitthreads = 0x0,
p_traceflag = 0x0,
p_tracevp = 0x0,
p_tracecred = 0x0,
p_textvp = 0xfffff80014df4d20,
p_lock = 0x0,
p_sigiolst = {
slh_first = 0x0
},
p_sigparent = 0x14,
p_sig = 0x0,
p_code = 0x0,
p_stops = 0x0,
p_stype = 0x0,
p_step = 0x0,
p_pfsflags = 0x0,
p_ptevents = 0x0,
p_nlminfo = 0x0,
p_aioinfo = 0x0,
p_singlethread = 0x0,
p_suspcount = 0x0,
p_xthread = 0x0,
p_boundary_count = 0x0,
p_pendingcnt = 0x0,
p_itimers = 0x0,
p_procdesc = 0x0,
p_treeflag = 0x0,
p_pendingexits = 0x0,
p_filemon = 0x0,
p_magic = 0xbeefface,
p_osrel = 0x124fbd,
p_comm = "kldload",
p_sysent = 0xffffffff81b68d48 <elf64_freebsd_sysvec>,
p_args = 0xfffff80039abd280,
p_cpulimit = 0x7fffffffffffffff,
p_nice = 0x0,
p_fibnum = 0x0,
p_reapsubtree = 0xcbc,
p_elf_machine = 0x3e,
p_elf_flags = 0x0,
p_xexit = 0x0,
p_xsig = 0x0,
p_pgrp = 0xfffff800390bc700,
p_klist = 0xfffff800031068c0,
p_numthreads = 0x1,
p_md = {
md_ldt = 0x0,
md_ldt_sd = {
sd_lolimit = 0x0,
sd_lobase = 0x0,
sd_type = 0x0,
sd_dpl = 0x0,
sd_p = 0x0,
sd_hilimit = 0x0,
sd_xx0 = 0x0,
sd_gran = 0x0,
sd_hibase = 0x0,
sd_xx1 = 0x0,
sd_mbz = 0x0,
sd_xx2 = 0x0
}
},
p_itcallout = {
c_links = {
le = {
le_next = 0x0,
le_prev = 0x0
},
sle = {
sle_next = 0x0
},
tqe = {
tqe_next = 0x0,
tqe_prev = 0x0
}
},
c_time = 0x0,
c_precision = 0x0,
c_arg = 0x0,
c_func = 0x0,
c_lock = 0xfffff80141b00658,
c_flags = 0x0,
c_iflags = 0x0,
c_cpu = 0x0
},
p_acflag = 0x0,
p_peers = 0x0,
p_leader = 0xfffff80141b00538,
p_emuldata = 0x0,
p_label = 0x0,
p_ktr = {
stqh_first = 0x0,
stqh_last = 0xfffff80141b00a00
},
p_mqnotifier = {
lh_first = 0x0
},
p_dtrace = 0xfffff80200ed04c0,
p_pwait = {
cv_description = 0xffffffff811f7ade "ppwait",
cv_waiters = 0x0
},
p_dbgwait = {
cv_description = 0xffffffff8125c296 "dbgwait",
cv_waiters = 0x0
},
p_prev_runtime = 0x0,
p_racct = 0x0,
p_throttled = 0x0,
p_orphan = {
le_next = 0x0,
le_prev = 0x0
},
p_orphans = {
lh_first = 0x0
}
}
(kgdb) p (*(struct thread*)0xfffff80141b04560).td_tid
$2 = 0x18bd8
(kgdb) tid 18bd8
(kgdb) bt
#0 sched_switch (td=0xfffff80141b04560, newtd=0xfffff80003699000, flags=<optimized out>) at /usr/src/sys/kern/sched_ule.c:2115
#1 0xffffffff80b7156c in mi_switch (flags=0x104, newtd=0x0) at /usr/src/sys/kern/kern_synch.c:437
#2 0xffffffff80bba7ed in sleepq_switch (wchan=0xffffffff81deb2d8 <kld_sx>, pri=0x0) at /usr/src/sys/kern/subr_sleepqueue.c:613
#3 0xffffffff80bba693 in sleepq_wait (wchan=0xffffffff81deb2d8 <kld_sx>, pri=0x0) at /usr/src/sys/kern/subr_sleepqueue.c:692
#4 0xffffffff80b6f329 in _sx_xlock_hard (sx=0xffffffff81deb2d8 <kld_sx>, x=<optimized out>, opts=<optimized out>, file=<optimized out>, line=<optimized out>) at /usr/src/sys/kern/kern_sx.c:777
#5 0xffffffff80b6ef31 in _sx_xlock (sx=0xffffffff81deb2d8 <kld_sx>, opts=0x0, file=0xffffffff811a5d65 "/usr/src/sys/kern/kern_linker.c", line=0x42e) at /usr/src/sys/kern/kern_sx.c:319
#6 0xffffffff80b3834e in kern_kldload (td=<optimized out>, file=<optimized out>, fileid=0xfffffe00af1f8964) at /usr/src/sys/kern/kern_linker.c:1070
#7 0xffffffff80b3848b in sys_kldload (td=0xfffff80141b04560, uap=<optimized out>) at /usr/src/sys/kern/kern_linker.c:1097
#8 0xffffffff8102606b in syscallenter (td=0xfffff80141b04560) at /usr/src/sys/amd64/amd64/../../kern/subr_syscall.c:134
#9 amd64_syscall (td=0xfffff80141b04560, traced=0x0) at /usr/src/sys/amd64/amd64/trap.c:936
#10 <signal handler called>
#11 0x00000008002cfd8a in ?? ()
Backtrace stopped: Cannot access memory at address 0x7fffffffd478
(kgdb) frame
Stack level 3, frame at 0xfffffe00af1f8820:
rip = 0xffffffff80bba693 in sleepq_wait (/usr/src/sys/kern/subr_sleepqueue.c:692); saved rip = 0xffffffff80b6f329
called by frame at 0xfffffe00af1f88d0, caller of frame at 0xfffffe00af1f87f0
source language c.
Arglist at 0xfffffe00af1f8810, args: wchan=0xffffffff81deb2d8 <kld_sx>, pri=0x0
Locals at 0xfffffe00af1f8810, Previous frame's sp is 0xfffffe00af1f8820
Saved registers:
rbx at 0xfffffe00af1f87f8, rbp at 0xfffffe00af1f8810, r14 at 0xfffffe00af1f8800, r15 at 0xfffffe00af1f8808, rip at 0xfffffe00af1f8818
wchan = 0xffffffff81deb2d8 <kld_sx>
pri = 0x0
td = 0xfffff80141b04560
(kgdb) p td
$4 = (struct thread *) 0xfffff80141b04560
(kgdb) p *td
$5 = {
td_lock = 0xffffffff81ed3648 <sleepq_chains+6792>,
td_proc = 0xfffff80141b00538,
td_plist = {
tqe_next = 0x0,
tqe_prev = 0xfffff80141b00548
},
td_runq = {
tqe_next = 0x0,
tqe_prev = 0xffffffff81e06448 <tdq_cpu+7112>
},
td_slpq = {
tqe_next = 0xfffff802946fb560,
tqe_prev = 0xfffff80007f33080
},
td_lockq = {
tqe_next = 0xfffff80039b57000,
tqe_prev = 0xfffffe01020e55e8
},
td_hash = {
le_next = 0x0,
le_prev = 0xfffffe00063c5ec0
},
td_cpuset = 0xfffff8000366ef00,
td_domain = {
dr_policy = 0xffffffff81deac18 <domainset0>,
dr_iterator = 0x0
},
td_sel = 0xfffff8001f462c80,
td_sleepqueue = 0x0,
td_turnstile = 0xfffff8001f627540,
td_rlqe = 0xfffff80014fe1280,
td_umtxq = 0xfffff8001ffd5280,
td_tid = 0x18bd8,
....

Event Timeline

eadler created this object in space S1 Global.