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/> References: <bug-204764-3630@https.bugs.freebsd.org/bugzilla/>
next in thread | previous in thread | raw e-mail | index | archive | help
https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=3D204764 --- Comment #19 from Rudolf =C4=8Cejka <cejkar@fit.vutbr.cz> --- And now the debugging info. Unfortunately, we are new for this bug, so we h= ave the kernel without INVARIANTS and without debugging.patch yet. We have locked bacula-fd, which is backup client with similar function to f= ind & stat and it occured during incremental backup operation: procstat -kk (I can send full procstat -kk -a personally, it has 429876 byt= es): 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=20 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=20 1331 102066 bacula-fd - mi_switch+0xbe sleepq_wait+0= x3a _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=20 1331 103370 bacula-fd - mi_switch+0xbe sleepq_catch_signals+0xab sleepq_timedwait_sig+0xf _cv_timedwait_sig_sbt+0x= 19e seltdwait+0xa4 kern_select+0x8fa sys_select+0x54 amd64_syscall+0x321 Xfast_syscall+0xfb=20 where the important thread is TID 102066, with vnode_create_vobject. (kgdb) info threads ... 701 Thread 102066 (PID=3D1331: bacula-fd) sched_switch (td=3D0xfffff803ec5= 26960, newtd=3D0x0, flags=3D<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=3D0xfffff803ec526960, newtd=3D0x0, flags=3D<value optimized out>) at /usr/src/sys/kern/sched_ule.c:1945 1945 cpuid =3D PCPU_GET(cpuid); (kgdb) bt #0 sched_switch (td=3D0xfffff803ec526960, newtd=3D0x0, flags=3D<value opti= mized out>) at /usr/src/sys/kern/sched_ule.c:1945 #1 0xffffffff80580d4e in mi_switch (flags=3D260, newtd=3D0x0) at /usr/src/sys/kern/kern_synch.c:491 #2 0xffffffff805c155a in sleepq_wait (wchan=3D0x0, pri=3D0) at /usr/src/sys/kern/subr_sleepqueue.c:618 #3 0xffffffff80580837 in _sleep (ident=3D<value optimized out>, lock=3D<va= lue optimized out>, priority=3D<value optimized out>, wmesg=3D<value optimized = out>, sbt=3D<value optimized out>, pr=3D<value optimized out>, flags=3D<value opt= imized out>) at /usr/src/sys/kern/kern_synch.c:255 #4 0xffffffff80766e60 in vnode_create_vobject (vp=3D0xfffff816fe4f3588, isize=3D512, td=3D0xfffff803ec526960) at /usr/src/sys/vm/vnode_pager.c:120 #5 0xffffffff8072fe80 in ufs_lookup_ino (vdp=3D0xfffff816fe4f3588, vpp=3D0xfffffe17f2e63858, cnp=3D0xfffffe17f2e63880, dd_ino=3D0x0) at /usr/src/sys/ufs/ufs/ufs_lookup.c:259 #6 0xffffffff807f897a in VOP_CACHEDLOOKUP_APV (vop=3D<value optimized out>, a=3D<value optimized out>) at vnode_if.c:197 #7 0xffffffff806092e6 in vfs_cache_lookup (ap=3D<value optimized out>) at vnode_if.h:80 #8 0xffffffff807f883a in VOP_LOOKUP_APV (vop=3D<value optimized out>, a=3D= <value optimized out>) at vnode_if.c:129 #9 0xffffffff806111f1 in lookup (ndp=3D0xfffffe17f2e637f8) at vnode_if.h:54 #10 0xffffffff80610a04 in namei (ndp=3D0xfffffe17f2e637f8) at /usr/src/sys/kern/vfs_lookup.c:302 #11 0xffffffff8062631e in kern_statat_vnhook (td=3D0xfffff803ec526960, flag=3D<value optimized out>, fd=3D-100, path=3D0x43c18128 <Error reading a= ddress 0x43c18128: Bad address>, pathseg=3DUIO_USERSPACE, sbp=3D0xfffffe17f2e63910, hook=3D0) at /usr/src/sys/kern/vfs_syscalls.c:2300 #12 0xffffffff80626420 in sys_lstat (td=3D0x0, uap=3D0xfffffe17f2e63a40) at /usr/src/sys/kern/vfs_syscalls.c:2280 #13 0xffffffff8078acd1 in amd64_syscall (td=3D0xfffff803ec526960, traced=3D= 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=3D0xfffff816fe4f3588, isize=3D512, td=3D0xfffff803ec526960) at /usr/src/sys/vm/vnode_pager.c:120 120 VM_OBJECT_SLEEP(object, object, PDROP | PVM, "vodea= d", 0); (kgdb) p *vp $1 =3D {v_tag =3D 0xffffffff8085c651 "ufs", v_op =3D 0xffffffff80b0f950, v_= data =3D 0xfffff81488311160, v_mount =3D 0xfffff8019a27d000, v_nmntvnodes =3D {tqe_n= ext =3D 0xfffff816894dc3b0, tqe_prev =3D 0xfffff80b0d4991f8}, v_un =3D {vu_mount = =3D 0x0,=20 vu_socket =3D 0x0, vu_cdev =3D 0x0, vu_fifoinfo =3D 0x0}, v_hashlist = =3D {le_next =3D 0xfffff80824c363b0, le_prev =3D 0xfffff81742127b48}, v_cache_src =3D {lh_fi= rst =3D 0x0}, v_cache_dst =3D {tqh_first =3D 0xfffff80e5f6a5af0,=20 tqh_last =3D 0xfffff80e5f6a5b10}, v_cache_dd =3D 0xfffff80e5f6a5af0, v_= lock =3D {lock_object =3D {lo_name =3D 0xffffffff8085c651 "ufs", lo_flags =3D 117112= 832, lo_data =3D 0, lo_witness =3D 0x0}, lk_lock =3D 1, lk_exslpfail =3D 0, lk_t= imo =3D 51,=20 lk_pri =3D 96}, v_interlock =3D {lock_object =3D {lo_name =3D 0xfffffff= f80870687 "vnode interlock", lo_flags =3D 16973824, lo_data =3D 0, lo_witness =3D 0x0= }, mtx_lock =3D 4}, v_vnlock =3D 0xfffff816fe4f35f0, v_actfreelist =3D { tqe_next =3D 0xfffff80b0d4991d8, tqe_prev =3D 0xfffff816894dc470}, v_bu= fobj =3D {bo_lock =3D {lock_object =3D {lo_name =3D 0xffffffff80870697 "bufobj inter= lock", lo_flags =3D 86179840, lo_data =3D 0, lo_witness =3D 0x0}, rw_lock =3D 1},= =20 bo_ops =3D 0xffffffff80afc070, bo_object =3D 0xfffff802f8423d00, bo_syn= clist =3D {le_next =3D 0x0, le_prev =3D 0x0}, bo_private =3D 0xfffff816fe4f3588, __bo= _vnode =3D 0xfffff816fe4f3588, bo_clean =3D {bv_hd =3D {tqh_first =3D 0x0,=20 tqh_last =3D 0xfffff816fe4f36a8}, bv_root =3D {pt_root =3D 0}, bv_c= nt =3D 0}, bo_dirty =3D {bv_hd =3D {tqh_first =3D 0x0, tqh_last =3D 0xfffff816fe4f36c8= }, bv_root =3D {pt_root =3D 0}, bv_cnt =3D 0}, bo_numoutput =3D 0, bo_flag =3D 0, bo_bsize= =3D 32768},=20 v_pollinfo =3D 0x0, v_label =3D 0x0, v_lockf =3D 0x0, v_rl =3D {rl_waiter= s =3D {tqh_first =3D 0x0, tqh_last =3D 0xfffff816fe4f3710}, rl_currdep =3D 0x0}, = v_cstart =3D 0, v_lasta =3D 0, v_lastw =3D 0, v_clen =3D 0, v_holdcnt =3D 8, v_usecount = =3D 7,=20 v_iflag =3D 512, v_vflag =3D 0, v_writecount =3D 0, v_hash =3D 76467851, = v_type =3D VDIR} (kgdb) p *(vp->v_bufobj.bo_object) $2 =3D {lock =3D {lock_object =3D {lo_name =3D 0xffffffff8088aeb6 "vm objec= t", lo_flags =3D 90374144, lo_data =3D 0, lo_witness =3D 0x0}, rw_lock =3D 1}, object_li= st =3D {tqe_next =3D 0xfffff802f8423e00, tqe_prev =3D 0xfffff802f8423c20}, shadow_= head =3D { lh_first =3D 0x0}, shadow_list =3D {le_next =3D 0x0, le_prev =3D 0xfffff801744afa30}, memq =3D {tqh_first =3D 0xfffff8183ea423d0, tqh_last = =3D 0xfffff8183ea423e0}, rtree =3D {rt_root =3D 18446735381746688977, rt_flags = =3D 0 '\0'}, size =3D 1,=20 generation =3D 1, ref_count =3D 0, shadow_count =3D 0, memattr =3D 6 '\00= 6', type =3D 2 '\002', flags =3D 16392, pg_color =3D 1608, paging_in_progress =3D 0, resident_page_count =3D 1, backing_object =3D 0x0, backing_object_offset = =3D 0,=20 pager_object_list =3D {tqe_next =3D 0x0, tqe_prev =3D 0x0}, rvq =3D {lh_f= irst =3D 0x0}, cache =3D {rt_root =3D 0, rt_flags =3D 0 '\0'}, handle =3D 0xfffff816fe4f35= 88, un_pager =3D {vnp =3D {vnp_size =3D 512, writemappings =3D 0}, devp =3D {devp_pglist= =3D { tqh_first =3D 0x200, tqh_last =3D 0x0}, ops =3D 0x0, dev =3D 0x0}, = sgp =3D {sgp_pglist =3D {tqh_first =3D 0x200, tqh_last =3D 0x0}}, swp =3D {swp_tmpf= s =3D 0x200, swp_bcount =3D 0}}, cred =3D 0x0, charge =3D 0} (kgdb) p *td $3 =3D {td_lock =3D 0xffffffff80b9d4d0, td_proc =3D 0xfffff8025dd694f0, td_= plist =3D {tqe_next =3D 0xfffff801744ac4b0, tqe_prev =3D 0xfffff805374dd970}, td_runq= =3D {tqe_next =3D 0x0, tqe_prev =3D 0xffffffff80b728b0}, td_slpq =3D { tqe_next =3D 0xfffff80389d11960, tqe_prev =3D 0xfffff80223243e80}, td_l= ockq =3D {tqe_next =3D 0x0, tqe_prev =3D 0xfffffe00003849b8}, td_hash =3D {le_next = =3D 0x0, le_prev =3D 0xfffffe00007d7590}, td_cpuset =3D 0xfffff801100593a8,=20 td_sel =3D 0xfffff806ce36eb00, td_sleepqueue =3D 0x0, td_turnstile =3D 0xfffff80174d07e40, td_rlqe =3D 0xfffff8017477ba28, td_umtxq =3D 0xfffff803a5a44f00, td_tid =3D 102066, td_sigqueue =3D {sq_signals =3D {__b= its =3D {0, 0, 0, 0}}, sq_kill =3D { __bits =3D {0, 0, 0, 0}}, sq_list =3D {tqh_first =3D 0x0, tqh_last =3D 0xfffff803ec526a18}, sq_proc =3D 0xfffff8025dd694f0, sq_flags =3D 1}, td_lend_user_pri =3D 255 '=CB=99', td_flags =3D 4, td_inhibitors =3D 2, td_= pflags =3D 0, td_dupfd =3D 0,=20 td_sqqueue =3D 0, td_wchan =3D 0xfffff802f8423d00, td_wmesg =3D 0xfffffff= f8088be0a "vodead", td_lastcpu =3D 13 '\r', td_oncpu =3D 255 '=CB=99', td_owepreempt = =3D 0 '\0', td_tsqueue =3D 0 '\0', td_locks =3D 26721, td_rw_rlocks =3D 0, td_lk_slocks= =3D 0,=20 td_stopsched =3D 0, td_blocked =3D 0x0, td_lockname =3D 0x0, td_contested= =3D {lh_first =3D 0x0}, td_sleeplocks =3D 0x0, td_intr_nesting_level =3D 0, td_= pinned =3D 0, td_ucred =3D 0xfffff8017438e800, td_estcpu =3D 0, td_slptick =3D 1266348= 642,=20 td_blktick =3D 0, td_swvoltick =3D 1266348642, td_cow =3D 0, td_ru =3D {r= u_utime =3D {tv_sec =3D 0, tv_usec =3D 0}, ru_stime =3D {tv_sec =3D 0, tv_usec =3D 0}, = ru_maxrss =3D 7952, ru_ixrss =3D 21233268, ru_idrss =3D 1299996, ru_isrss =3D 13866624,=20 ru_minflt =3D 1, ru_majflt =3D 0, ru_nswap =3D 0, ru_inblock =3D 210560= 8, ru_oublock =3D 0, ru_msgsnd =3D 1531599, ru_msgrcv =3D 100, ru_nsignals =3D= 0, ru_nvcsw =3D 1685809, ru_nivcsw =3D 9633}, td_rux =3D {rux_runtime =3D 2226241352945= ,=20 rux_uticks =3D 46227, rux_sticks =3D 62106, rux_iticks =3D 0, rux_uu = =3D 365363300, rux_su =3D 490865795, rux_tu =3D 856229096}, td_incruntime =3D 0, td_runtim= e =3D 2226241352945, td_pticks =3D 0, td_sticks =3D 0, td_iticks =3D 0, td_uticks= =3D 0,=20 td_intrval =3D 0, td_oldsigmask =3D {__bits =3D {0, 0, 0, 0}}, td_generat= ion =3D 1695442, td_sigstk =3D {ss_sp =3D 0x0, ss_size =3D 0, ss_flags =3D 0}, td_x= sig =3D 0, td_profil_addr =3D 0, td_profil_ticks =3D 0,=20 td_name =3D "bacula-fd\000\000\000\000\000\000\000\000\000\000", td_fpop = =3D 0x0, td_dbgflags =3D 0, td_dbgksi =3D {ksi_link =3D {tqe_next =3D 0x0, tqe_prev = =3D 0x0}, ksi_info =3D {si_signo =3D 0, si_errno =3D 0, si_code =3D 0, si_pid =3D 0, = si_uid =3D 0,=20 si_status =3D 0, si_addr =3D 0x0, si_value =3D {sival_int =3D 0, siva= l_ptr =3D 0x0, sigval_int =3D 0, sigval_ptr =3D 0x0}, _reason =3D {_fault =3D {_trapno =3D= 0}, _timer =3D {_timerid =3D 0, _overrun =3D 0}, _mesgq =3D {_mqd =3D 0}, _poll =3D {_band= =3D 0},=20 __spare__ =3D {__spare1__ =3D 0, __spare2__ =3D {0, 0, 0, 0, 0, 0, = 0}}}}, ksi_flags =3D 0, ksi_sigq =3D 0x0}, td_ng_outbound =3D 0, td_osd =3D {osd_n= slots =3D 0, osd_slots =3D 0x0, osd_next =3D {le_next =3D 0x0, le_prev =3D 0x0}},=20 td_map_def_user =3D 0x0, td_dbg_forked =3D 0, td_vp_reserv =3D 0, td_no_s= leeping =3D 0, td_dom_rr_idx =3D 0, td_sigmask =3D {__bits =3D {0, 0, 0, 0}}, td_rqinde= x =3D 48 '0', td_base_pri =3D 152 '\230', td_priority =3D 152 '\230',=20 td_pri_class =3D 3 '\003', td_user_pri =3D 183 '=CB=87', td_base_user_pri= =3D 183 '=CB=87', td_pcb =3D 0xfffffe17f2e63b80, td_state =3D TDS_INHIBITED, td_retval =3D {0, 1084620448}, td_slpcallout =3D {c_links =3D {le =3D {le_next =3D 0x0,=20 le_prev =3D 0xfffffe0000ad9288}, sle =3D {sle_next =3D 0x0}, tqe = =3D {tqe_next =3D 0x0, tqe_prev =3D 0xfffffe0000ad9288}}, c_time =3D 5430875852315327, c_= precision =3D 26843, c_arg =3D 0xfffff803ec526960,=20 c_func =3D 0xffffffff805c1370 <sleepq_timeout>, c_lock =3D 0x0, c_flags= =3D 2, c_iflags =3D 272, c_cpu =3D 11}, td_frame =3D 0xfffffe17f2e63ac0, td_kstack= _obj =3D 0xfffff8076ec32a00, td_kstack =3D 18446741977545703424, td_kstack_pages =3D= 4,=20 td_critnest =3D 1, td_md =3D {md_spinlock_count =3D 1, md_saved_flags =3D= 582, md_spurflt_addr =3D 1131679744}, td_sched =3D 0xfffff803ec526de0, td_ar =3D= 0x0, td_lprof =3D {{lh_first =3D 0x0}, {lh_first =3D 0x0}}, td_dtrace =3D 0x0, t= d_errno =3D 0,=20 td_vnet =3D 0x0, td_vnet_lpush =3D 0x0, td_intr_frame =3D 0x0, td_rfppwai= t_p =3D 0xfffff80616f0a000, td_ma =3D 0x0, td_ma_cnt =3D 0, td_su =3D 0x0, td_dbg_s= c_code =3D 0, td_dbg_sc_narg =3D 0, td_emuldata =3D 0x0} (kgdb) p *object $4 =3D {lock =3D {lock_object =3D {lo_name =3D 0xffffffff8088aeb6 "vm objec= t", lo_flags =3D 90374144, lo_data =3D 0, lo_witness =3D 0x0}, rw_lock =3D 1}, object_li= st =3D {tqe_next =3D 0xfffff802f8423e00, tqe_prev =3D 0xfffff802f8423c20}, shadow_= head =3D { lh_first =3D 0x0}, shadow_list =3D {le_next =3D 0x0, le_prev =3D 0xfffff801744afa30}, memq =3D {tqh_first =3D 0xfffff8183ea423d0, tqh_last = =3D 0xfffff8183ea423e0}, rtree =3D {rt_root =3D 18446735381746688977, rt_flags = =3D 0 '\0'}, size =3D 1,=20 generation =3D 1, ref_count =3D 0, shadow_count =3D 0, memattr =3D 6 '\00= 6', type =3D 2 '\002', flags =3D 16392, pg_color =3D 1608, paging_in_progress =3D 0, resident_page_count =3D 1, backing_object =3D 0x0, backing_object_offset = =3D 0,=20 pager_object_list =3D {tqe_next =3D 0x0, tqe_prev =3D 0x0}, rvq =3D {lh_f= irst =3D 0x0}, cache =3D {rt_root =3D 0, rt_flags =3D 0 '\0'}, handle =3D 0xfffff816fe4f35= 88, un_pager =3D {vnp =3D {vnp_size =3D 512, writemappings =3D 0}, devp =3D {devp_pglist= =3D { tqh_first =3D 0x200, tqh_last =3D 0x0}, ops =3D 0x0, dev =3D 0x0}, = sgp =3D {sgp_pglist =3D {tqh_first =3D 0x200, tqh_last =3D 0x0}}, swp =3D {swp_tmpf= s =3D 0x200, swp_bcount =3D 0}}, cred =3D 0x0, charge =3D 0} --=20 You are receiving this mail because: You are the assignee for the bug.=
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?bug-204764-3630-HviiTroe8W>