Date: Fri, 01 Apr 2016 12:14:10 +0000 From: bugzilla-noreply@freebsd.org To: freebsd-fs@FreeBSD.org Subject: [Bug 204764] Filesystem deadlock, process in vodead state Message-ID: <bug-204764-3630-HviiTroe8W@https.bugs.freebsd.org/bugzilla/> In-Reply-To: <bug-204764-3630@https.bugs.freebsd.org/bugzilla/>
index | next in thread | previous in thread | raw e-mail
https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=204764 --- Comment #19 from Rudolf Čejka <cejkar@fit.vutbr.cz> --- And now the debugging info. Unfortunately, we are new for this bug, so we have the kernel without INVARIANTS and without debugging.patch yet. We have locked bacula-fd, which is backup client with similar function to find & stat and it occured during incremental backup operation: procstat -kk (I can send full procstat -kk -a personally, it has 429876 bytes): 1331 101013 bacula-fd - mi_switch+0xbe sleepq_catch_signals+0xab sleepq_wait_sig+0xc _cv_wait_sig+0x17a seltdwait+0xae kern_select+0x8fa sys_select+0x54 amd64_syscall+0x321 Xfast_syscall+0xfb 1331 101035 bacula-fd - mi_switch+0xbe sleepq_catch_signals+0xab sleepq_timedwait_sig+0xf _sleep+0x238 umtxq_sleep+0x125 do_wait+0x387 __umtx_op_wait_uint_private+0x83 amd64_syscall+0x321 Xfast_syscall+0xfb 1331 102066 bacula-fd - mi_switch+0xbe sleepq_wait+0x3a _sleep+0x287 vnode_create_vobject+0x100 ufs_lookup_ino+0xa0 VOP_CACHEDLOOKUP_APV+0x7a vfs_cache_lookup+0xd6 VOP_LOOKUP_APV+0x7a lookup+0x571 namei+0x344 kern_statat_vnhook+0xae sys_lstat+0x30 amd64_syscall+0x321 Xfast_syscall+0xfb 1331 103370 bacula-fd - mi_switch+0xbe sleepq_catch_signals+0xab sleepq_timedwait_sig+0xf _cv_timedwait_sig_sbt+0x19e seltdwait+0xa4 kern_select+0x8fa sys_select+0x54 amd64_syscall+0x321 Xfast_syscall+0xfb where the important thread is TID 102066, with vnode_create_vobject. (kgdb) info threads ... 701 Thread 102066 (PID=1331: bacula-fd) sched_switch (td=0xfffff803ec526960, newtd=0x0, flags=<value optimized out>) at /usr/src/sys/kern/sched_ule.c:1945 ... (kgdb) thread 701 [Switching to thread 701 (Thread 102066)]#0 sched_switch (td=0xfffff803ec526960, newtd=0x0, flags=<value optimized out>) at /usr/src/sys/kern/sched_ule.c:1945 1945 cpuid = PCPU_GET(cpuid); (kgdb) bt #0 sched_switch (td=0xfffff803ec526960, newtd=0x0, flags=<value optimized out>) at /usr/src/sys/kern/sched_ule.c:1945 #1 0xffffffff80580d4e in mi_switch (flags=260, newtd=0x0) at /usr/src/sys/kern/kern_synch.c:491 #2 0xffffffff805c155a in sleepq_wait (wchan=0x0, pri=0) at /usr/src/sys/kern/subr_sleepqueue.c:618 #3 0xffffffff80580837 in _sleep (ident=<value optimized out>, lock=<value optimized out>, priority=<value optimized out>, wmesg=<value optimized out>, sbt=<value optimized out>, pr=<value optimized out>, flags=<value optimized out>) at /usr/src/sys/kern/kern_synch.c:255 #4 0xffffffff80766e60 in vnode_create_vobject (vp=0xfffff816fe4f3588, isize=512, td=0xfffff803ec526960) at /usr/src/sys/vm/vnode_pager.c:120 #5 0xffffffff8072fe80 in ufs_lookup_ino (vdp=0xfffff816fe4f3588, vpp=0xfffffe17f2e63858, cnp=0xfffffe17f2e63880, dd_ino=0x0) at /usr/src/sys/ufs/ufs/ufs_lookup.c:259 #6 0xffffffff807f897a in VOP_CACHEDLOOKUP_APV (vop=<value optimized out>, a=<value optimized out>) at vnode_if.c:197 #7 0xffffffff806092e6 in vfs_cache_lookup (ap=<value optimized out>) at vnode_if.h:80 #8 0xffffffff807f883a in VOP_LOOKUP_APV (vop=<value optimized out>, a=<value optimized out>) at vnode_if.c:129 #9 0xffffffff806111f1 in lookup (ndp=0xfffffe17f2e637f8) at vnode_if.h:54 #10 0xffffffff80610a04 in namei (ndp=0xfffffe17f2e637f8) at /usr/src/sys/kern/vfs_lookup.c:302 #11 0xffffffff8062631e in kern_statat_vnhook (td=0xfffff803ec526960, flag=<value optimized out>, fd=-100, path=0x43c18128 <Error reading address 0x43c18128: Bad address>, pathseg=UIO_USERSPACE, sbp=0xfffffe17f2e63910, hook=0) at /usr/src/sys/kern/vfs_syscalls.c:2300 #12 0xffffffff80626420 in sys_lstat (td=0x0, uap=0xfffffe17f2e63a40) at /usr/src/sys/kern/vfs_syscalls.c:2280 #13 0xffffffff8078acd1 in amd64_syscall (td=0xfffff803ec526960, traced=0) at subr_syscall.c:141 #14 0xffffffff8076fffb in Xfast_syscall () at /usr/src/sys/amd64/amd64/exception.S:396 #15 0x00000000425a731a in ?? () Previous frame inner to this frame (corrupt stack?) (kgdb) frame 4 #4 0xffffffff80766e60 in vnode_create_vobject (vp=0xfffff816fe4f3588, isize=512, td=0xfffff803ec526960) at /usr/src/sys/vm/vnode_pager.c:120 120 VM_OBJECT_SLEEP(object, object, PDROP | PVM, "vodead", 0); (kgdb) p *vp $1 = {v_tag = 0xffffffff8085c651 "ufs", v_op = 0xffffffff80b0f950, v_data = 0xfffff81488311160, v_mount = 0xfffff8019a27d000, v_nmntvnodes = {tqe_next = 0xfffff816894dc3b0, tqe_prev = 0xfffff80b0d4991f8}, v_un = {vu_mount = 0x0, vu_socket = 0x0, vu_cdev = 0x0, vu_fifoinfo = 0x0}, v_hashlist = {le_next = 0xfffff80824c363b0, le_prev = 0xfffff81742127b48}, v_cache_src = {lh_first = 0x0}, v_cache_dst = {tqh_first = 0xfffff80e5f6a5af0, tqh_last = 0xfffff80e5f6a5b10}, v_cache_dd = 0xfffff80e5f6a5af0, v_lock = {lock_object = {lo_name = 0xffffffff8085c651 "ufs", lo_flags = 117112832, lo_data = 0, lo_witness = 0x0}, lk_lock = 1, lk_exslpfail = 0, lk_timo = 51, lk_pri = 96}, v_interlock = {lock_object = {lo_name = 0xffffffff80870687 "vnode interlock", lo_flags = 16973824, lo_data = 0, lo_witness = 0x0}, mtx_lock = 4}, v_vnlock = 0xfffff816fe4f35f0, v_actfreelist = { tqe_next = 0xfffff80b0d4991d8, tqe_prev = 0xfffff816894dc470}, v_bufobj = {bo_lock = {lock_object = {lo_name = 0xffffffff80870697 "bufobj interlock", lo_flags = 86179840, lo_data = 0, lo_witness = 0x0}, rw_lock = 1}, bo_ops = 0xffffffff80afc070, bo_object = 0xfffff802f8423d00, bo_synclist = {le_next = 0x0, le_prev = 0x0}, bo_private = 0xfffff816fe4f3588, __bo_vnode = 0xfffff816fe4f3588, bo_clean = {bv_hd = {tqh_first = 0x0, tqh_last = 0xfffff816fe4f36a8}, bv_root = {pt_root = 0}, bv_cnt = 0}, bo_dirty = {bv_hd = {tqh_first = 0x0, tqh_last = 0xfffff816fe4f36c8}, bv_root = {pt_root = 0}, bv_cnt = 0}, bo_numoutput = 0, bo_flag = 0, bo_bsize = 32768}, v_pollinfo = 0x0, v_label = 0x0, v_lockf = 0x0, v_rl = {rl_waiters = {tqh_first = 0x0, tqh_last = 0xfffff816fe4f3710}, rl_currdep = 0x0}, v_cstart = 0, v_lasta = 0, v_lastw = 0, v_clen = 0, v_holdcnt = 8, v_usecount = 7, v_iflag = 512, v_vflag = 0, v_writecount = 0, v_hash = 76467851, v_type = VDIR} (kgdb) p *(vp->v_bufobj.bo_object) $2 = {lock = {lock_object = {lo_name = 0xffffffff8088aeb6 "vm object", lo_flags = 90374144, lo_data = 0, lo_witness = 0x0}, rw_lock = 1}, object_list = {tqe_next = 0xfffff802f8423e00, tqe_prev = 0xfffff802f8423c20}, shadow_head = { lh_first = 0x0}, shadow_list = {le_next = 0x0, le_prev = 0xfffff801744afa30}, memq = {tqh_first = 0xfffff8183ea423d0, tqh_last = 0xfffff8183ea423e0}, rtree = {rt_root = 18446735381746688977, rt_flags = 0 '\0'}, size = 1, generation = 1, ref_count = 0, shadow_count = 0, memattr = 6 '\006', type = 2 '\002', flags = 16392, pg_color = 1608, paging_in_progress = 0, resident_page_count = 1, backing_object = 0x0, backing_object_offset = 0, pager_object_list = {tqe_next = 0x0, tqe_prev = 0x0}, rvq = {lh_first = 0x0}, cache = {rt_root = 0, rt_flags = 0 '\0'}, handle = 0xfffff816fe4f3588, un_pager = {vnp = {vnp_size = 512, writemappings = 0}, devp = {devp_pglist = { tqh_first = 0x200, tqh_last = 0x0}, ops = 0x0, dev = 0x0}, sgp = {sgp_pglist = {tqh_first = 0x200, tqh_last = 0x0}}, swp = {swp_tmpfs = 0x200, swp_bcount = 0}}, cred = 0x0, charge = 0} (kgdb) p *td $3 = {td_lock = 0xffffffff80b9d4d0, td_proc = 0xfffff8025dd694f0, td_plist = {tqe_next = 0xfffff801744ac4b0, tqe_prev = 0xfffff805374dd970}, td_runq = {tqe_next = 0x0, tqe_prev = 0xffffffff80b728b0}, td_slpq = { tqe_next = 0xfffff80389d11960, tqe_prev = 0xfffff80223243e80}, td_lockq = {tqe_next = 0x0, tqe_prev = 0xfffffe00003849b8}, td_hash = {le_next = 0x0, le_prev = 0xfffffe00007d7590}, td_cpuset = 0xfffff801100593a8, td_sel = 0xfffff806ce36eb00, td_sleepqueue = 0x0, td_turnstile = 0xfffff80174d07e40, td_rlqe = 0xfffff8017477ba28, td_umtxq = 0xfffff803a5a44f00, td_tid = 102066, td_sigqueue = {sq_signals = {__bits = {0, 0, 0, 0}}, sq_kill = { __bits = {0, 0, 0, 0}}, sq_list = {tqh_first = 0x0, tqh_last = 0xfffff803ec526a18}, sq_proc = 0xfffff8025dd694f0, sq_flags = 1}, td_lend_user_pri = 255 '˙', td_flags = 4, td_inhibitors = 2, td_pflags = 0, td_dupfd = 0, td_sqqueue = 0, td_wchan = 0xfffff802f8423d00, td_wmesg = 0xffffffff8088be0a "vodead", td_lastcpu = 13 '\r', td_oncpu = 255 '˙', td_owepreempt = 0 '\0', td_tsqueue = 0 '\0', td_locks = 26721, td_rw_rlocks = 0, td_lk_slocks = 0, td_stopsched = 0, td_blocked = 0x0, td_lockname = 0x0, td_contested = {lh_first = 0x0}, td_sleeplocks = 0x0, td_intr_nesting_level = 0, td_pinned = 0, td_ucred = 0xfffff8017438e800, td_estcpu = 0, td_slptick = 1266348642, td_blktick = 0, td_swvoltick = 1266348642, td_cow = 0, td_ru = {ru_utime = {tv_sec = 0, tv_usec = 0}, ru_stime = {tv_sec = 0, tv_usec = 0}, ru_maxrss = 7952, ru_ixrss = 21233268, ru_idrss = 1299996, ru_isrss = 13866624, ru_minflt = 1, ru_majflt = 0, ru_nswap = 0, ru_inblock = 2105608, ru_oublock = 0, ru_msgsnd = 1531599, ru_msgrcv = 100, ru_nsignals = 0, ru_nvcsw = 1685809, ru_nivcsw = 9633}, td_rux = {rux_runtime = 2226241352945, rux_uticks = 46227, rux_sticks = 62106, rux_iticks = 0, rux_uu = 365363300, rux_su = 490865795, rux_tu = 856229096}, td_incruntime = 0, td_runtime = 2226241352945, td_pticks = 0, td_sticks = 0, td_iticks = 0, td_uticks = 0, td_intrval = 0, td_oldsigmask = {__bits = {0, 0, 0, 0}}, td_generation = 1695442, td_sigstk = {ss_sp = 0x0, ss_size = 0, ss_flags = 0}, td_xsig = 0, td_profil_addr = 0, td_profil_ticks = 0, td_name = "bacula-fd\000\000\000\000\000\000\000\000\000\000", td_fpop = 0x0, td_dbgflags = 0, td_dbgksi = {ksi_link = {tqe_next = 0x0, tqe_prev = 0x0}, ksi_info = {si_signo = 0, si_errno = 0, si_code = 0, si_pid = 0, si_uid = 0, si_status = 0, si_addr = 0x0, si_value = {sival_int = 0, sival_ptr = 0x0, sigval_int = 0, sigval_ptr = 0x0}, _reason = {_fault = {_trapno = 0}, _timer = {_timerid = 0, _overrun = 0}, _mesgq = {_mqd = 0}, _poll = {_band = 0}, __spare__ = {__spare1__ = 0, __spare2__ = {0, 0, 0, 0, 0, 0, 0}}}}, ksi_flags = 0, ksi_sigq = 0x0}, td_ng_outbound = 0, td_osd = {osd_nslots = 0, osd_slots = 0x0, osd_next = {le_next = 0x0, le_prev = 0x0}}, td_map_def_user = 0x0, td_dbg_forked = 0, td_vp_reserv = 0, td_no_sleeping = 0, td_dom_rr_idx = 0, td_sigmask = {__bits = {0, 0, 0, 0}}, td_rqindex = 48 '0', td_base_pri = 152 '\230', td_priority = 152 '\230', td_pri_class = 3 '\003', td_user_pri = 183 'ˇ', td_base_user_pri = 183 'ˇ', td_pcb = 0xfffffe17f2e63b80, td_state = TDS_INHIBITED, td_retval = {0, 1084620448}, td_slpcallout = {c_links = {le = {le_next = 0x0, le_prev = 0xfffffe0000ad9288}, sle = {sle_next = 0x0}, tqe = {tqe_next = 0x0, tqe_prev = 0xfffffe0000ad9288}}, c_time = 5430875852315327, c_precision = 26843, c_arg = 0xfffff803ec526960, c_func = 0xffffffff805c1370 <sleepq_timeout>, c_lock = 0x0, c_flags = 2, c_iflags = 272, c_cpu = 11}, td_frame = 0xfffffe17f2e63ac0, td_kstack_obj = 0xfffff8076ec32a00, td_kstack = 18446741977545703424, td_kstack_pages = 4, td_critnest = 1, td_md = {md_spinlock_count = 1, md_saved_flags = 582, md_spurflt_addr = 1131679744}, td_sched = 0xfffff803ec526de0, td_ar = 0x0, td_lprof = {{lh_first = 0x0}, {lh_first = 0x0}}, td_dtrace = 0x0, td_errno = 0, td_vnet = 0x0, td_vnet_lpush = 0x0, td_intr_frame = 0x0, td_rfppwait_p = 0xfffff80616f0a000, td_ma = 0x0, td_ma_cnt = 0, td_su = 0x0, td_dbg_sc_code = 0, td_dbg_sc_narg = 0, td_emuldata = 0x0} (kgdb) p *object $4 = {lock = {lock_object = {lo_name = 0xffffffff8088aeb6 "vm object", lo_flags = 90374144, lo_data = 0, lo_witness = 0x0}, rw_lock = 1}, object_list = {tqe_next = 0xfffff802f8423e00, tqe_prev = 0xfffff802f8423c20}, shadow_head = { lh_first = 0x0}, shadow_list = {le_next = 0x0, le_prev = 0xfffff801744afa30}, memq = {tqh_first = 0xfffff8183ea423d0, tqh_last = 0xfffff8183ea423e0}, rtree = {rt_root = 18446735381746688977, rt_flags = 0 '\0'}, size = 1, generation = 1, ref_count = 0, shadow_count = 0, memattr = 6 '\006', type = 2 '\002', flags = 16392, pg_color = 1608, paging_in_progress = 0, resident_page_count = 1, backing_object = 0x0, backing_object_offset = 0, pager_object_list = {tqe_next = 0x0, tqe_prev = 0x0}, rvq = {lh_first = 0x0}, cache = {rt_root = 0, rt_flags = 0 '\0'}, handle = 0xfffff816fe4f3588, un_pager = {vnp = {vnp_size = 512, writemappings = 0}, devp = {devp_pglist = { tqh_first = 0x200, tqh_last = 0x0}, ops = 0x0, dev = 0x0}, sgp = {sgp_pglist = {tqh_first = 0x200, tqh_last = 0x0}}, swp = {swp_tmpfs = 0x200, swp_bcount = 0}}, cred = 0x0, charge = 0} -- You are receiving this mail because: You are the assignee for the bug.home | help
Want to link to this message? Use this
URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?bug-204764-3630-HviiTroe8W>