Date: Tue, 15 Jan 2013 23:45:56 +0100 From: Nicolas Rachinsky <fbsd-mas-0@ml.turing-complete.org> To: Artem Belevich <art@freebsd.org> Cc: freebsd-fs <freebsd-fs@freebsd.org> Subject: Re: slowdown of zfs (tx->tx) Message-ID: <20130115224556.GA41774@mid.pc5.i.0x5.de> In-Reply-To: <CAFqOu6jKX-Ks6C1RK5GwZ51ZVUSnGSe7S99_EfK%2BfwLPjAFFYw@mail.gmail.com> References: <CAFqOu6jrng=v8eVyhqV-PBqJM_dYy%2BU7X4%2B=ahBeoxvK4mxcSA@mail.gmail.com> <20130110193949.GA10023@mid.pc5.i.0x5.de> <20130111073417.GA95100@mid.pc5.i.0x5.de> <CAFqOu6gWpMsWN0pTBiv10WfwyGWMfO9GzMLWTtcVxHixr-_i3Q@mail.gmail.com> <20130114094010.GA75529@mid.pc5.i.0x5.de> <CAFqOu6hxfGt_M6Jo9qWeifDz9YnNc_Bd9H-GEe4RYtutaPvH5w@mail.gmail.com> <20130114195148.GA20540@mid.pc5.i.0x5.de> <CAFqOu6jwJ4qhbOovN_NhzusdQJvrbvUC3g93sziR=Uw99SGenw@mail.gmail.com> <20130114214652.GA76779@mid.pc5.i.0x5.de> <CAFqOu6jKX-Ks6C1RK5GwZ51ZVUSnGSe7S99_EfK%2BfwLPjAFFYw@mail.gmail.com>
next in thread | previous in thread | raw e-mail | index | archive | help
* Artem Belevich <art@freebsd.org> [2013-01-14 17:37 -0800]: > OK. threads responsible for transaction sync seem to be stuck in zio_wait. > zio_wait is in turn waiting for some task thread to be done with its work. > Now you need to figure out what are those task threads doing. > > 'procstat -kk 0' will dump few hundreds of taskq threads. Most of them > would be zfs related. On an idle box (8.3/amd64 in my case) most of > them would have the same stack trace looking like this (modulo > offsets): > > mi_switch+0x196 sleepq_wait+0x42 _sleep+0x3c0 > taskqueue_thread_loop+0xbe fork_exit+0x11f fork_trampoline+0xe > > Look for stack traces that don't match that pattern. There are some of these. root@bolte ~# sh -c 'for i in `jot 1000`; do procstat -kk 0 ; sleep 0.1 ; done' | sort | uniq -c | grep -v -F 'mi_switch+0x176 sleepq_wait+0x42 _sleep+0x317 taskqueue_thread_loop+0xbe fork_exit+0x11f fork_trampoline+0xe' | sort -n 1 0 100098 kernel zio_write_issue_ mi_switch+0x176 sleepq_wait+0x42 _cv_wait+0x129 space_map_load_wait+0x20 metaslab_activate+0x73 metaslab_alloc+0x7b2 zio_dva_allocate+0x9a zio_execute+0xc3 zio_ready+0x17d zio_execute+0xc3 zio_ready+0x17d zio_execute+0xc3 zio_ready+0x17d zio_execute+0xc3 zio_ready+0x17d zio_execute+0xc3 zio_ready+0x17d zio_execute+0xc3 1 0 100098 kernel zio_write_issue_ mi_switch+0x176 sleepq_wait+0x42 _cv_wait+0x129 zio_wait+0x61 dmu_buf_hold_array_by_dnode+0x22b dmu_read+0x89 space_map_load+0x108 metaslab_activate+0xdc metaslab_alloc+0x7b2 zio_dva_allocate+0x1aa zio_execute+0xc3 zio_ready+0x17d zio_execute+0xc3 zio_ready+0x17d zio_execute+0xc3 taskqueue_run_locked+0x85 taskqueue_thread_loop+0x4e fork_exit+0x11f 1 0 100098 kernel zio_write_issue_ mi_switch+0x176 sleepq_wait+0x42 _sx_xlock_hard+0x305 _sx_xlock+0x4e metaslab_alloc+0x77b zio_dva_allocate+0x1aa zio_execute+0xc3 taskqueue_run_locked+0x85 taskqueue_thread_loop+0x4e fork_exit+0x11f fork_trampoline+0xe 1 0 100098 kernel zio_write_issue_ mi_switch+0x176 sleepq_wait+0x42 _sx_xlock_hard+0x305 _sx_xlock+0x4e metaslab_alloc+0x77b zio_dva_allocate+0x1aa zio_execute+0xc3 zio_ready+0x17d zio_execute+0xc3 taskqueue_run_locked+0x85 taskqueue_thread_loop+0x4e fork_exit+0x11f fork_trampoline+0xe 1 0 100098 kernel zio_write_issue_ mi_switch+0x176 turnstile_wait+0x1cb _mtx_lock_sleep+0xb0 taskqueue_member+0xe8 zio_execute+0x10c taskqueue_run_locked+0x85 taskqueue_thread_loop+0x4e fork_exit+0x11f fork_trampoline+0xe 1 0 100099 kernel zio_write_issue_ mi_switch+0x176 critical_exit+0xa5 intr_event_handle+0xb3 intr_execute_handlers+0x5f lapic_handle_intr+0x37 Xapic_isr1+0xa5 space_map_remove+0x81 space_map_load+0x1a4 metaslab_activate+0xdc metaslab_alloc+0x7b2 zio_dva_allocate+0x9a zio_execute+0xc3 taskqueue_run_locked+0x85 taskqueue_thread_loop+0x4e fork_exit+0x11f fork_trampoline+0xe 1 0 100099 kernel zio_write_issue_ mi_switch+0x176 sleepq_wait+0x42 _cv_wait+0x129 space_map_load_wait+0x20 metaslab_activate+0x73 metaslab_alloc+0x7b2 zio_dva_allocate+0x1aa zio_execute+0xc3 zio_ready+0x17d zio_execute+0xc3 taskqueue_run_locked+0x85 taskqueue_thread_loop+0x4e fork_exit+0x11f fork_trampoline+0xe 1 0 100099 kernel zio_write_issue_ mi_switch+0x176 sleepq_wait+0x42 _sx_xlock_hard+0x305 _sx_xlock+0x4e metaslab_alloc+0x77b zio_dva_allocate+0x1aa zio_execute+0xc3 taskqueue_run_locked+0x85 taskqueue_thread_loop+0x4e fork_exit+0x11f fork_trampoline+0xe 1 0 100106 kernel zio_write_intr_1 <running> 1 0 100108 kernel zio_write_intr_3 <running> 1 0 100109 kernel zio_write_intr_4 <running> 1 0 100109 kernel zio_write_intr_4 mi_switch+0x176 turnstile_wait+0x1cb _mtx_lock_sleep+0xb0 _sleep+0x251 taskqueue_thread_loop+0xbe fork_exit+0x11f fork_trampoline+0xe 1 0 100110 kernel zio_write_intr_5 mi_switch+0x176 turnstile_wait+0x1cb _mtx_lock_sleep+0xb0 _sleep+0x251 taskqueue_thread_loop+0xbe fork_exit+0x11f fork_trampoline+0xe 2 0 100040 kernel nfe0 taskq <running> 2 0 100096 kernel zio_read_intr_0 <running> 2 0 100098 kernel zio_write_issue_ mi_switch+0x176 sleepq_wait+0x42 _cv_wait+0x129 space_map_load_wait+0x20 metaslab_activate+0x73 metaslab_alloc+0x7b2 zio_dva_allocate+0x1aa zio_execute+0xc3 zio_ready+0x17d zio_execute+0xc3 zio_ready+0x17d zio_execute+0xc3 zio_ready+0x17d zio_execute+0xc3 zio_ready+0x17d zio_execute+0xc3 zio_ready+0x17d zio_execute+0xc3 2 0 100099 kernel zio_write_issue_ mi_switch+0x176 sleepq_wait+0x42 _cv_wait+0x129 space_map_load_wait+0x20 metaslab_activate+0x73 metaslab_alloc+0x7b2 zio_dva_allocate+0x9a zio_execute+0xc3 zio_ready+0x17d zio_execute+0xc3 zio_ready+0x17d zio_execute+0xc3 zio_ready+0x17d zio_execute+0xc3 zio_ready+0x17d zio_execute+0xc3 zio_ready+0x17d zio_execute+0xc3 2 0 100099 kernel zio_write_issue_ mi_switch+0x176 sleepq_wait+0x42 _cv_wait+0x129 zio_wait+0x61 dbuf_read+0x5e5 dbuf_findbp+0x107 dbuf_prefetch+0x8f dmu_prefetch+0x1bb space_map_load+0x289 metaslab_activate+0xdc metaslab_alloc+0x7b2 zio_dva_allocate+0x1aa zio_execute+0xc3 taskqueue_run_locked+0x85 taskqueue_thread_loop+0x4e fork_exit+0x11f fork_trampoline+0xe 2 0 100099 kernel zio_write_issue_ mi_switch+0x176 sleepq_wait+0x42 _sx_xlock_hard+0x305 _sx_xlock+0x4e metaslab_alloc+0x77b zio_dva_allocate+0x9a zio_execute+0xc3 taskqueue_run_locked+0x85 taskqueue_thread_loop+0x4e fork_exit+0x11f fork_trampoline+0xe 3 0 100098 kernel zio_write_issue_ mi_switch+0x176 sleepq_wait+0x42 _cv_wait+0x129 space_map_load_wait+0x20 metaslab_activate+0x73 metaslab_alloc+0x7b2 zio_dva_allocate+0x9a zio_execute+0xc3 zio_ready+0x17d zio_execute+0xc3 zio_ready+0x17d zio_execute+0xc3 zio_ready+0x17d zio_execute+0xc3 zio_ready+0x17d zio_execute+0xc3 taskqueue_run_locked+0x85 taskqueue_thread_loop+0x4e 3 0 100099 kernel zio_write_issue_ mi_switch+0x176 sleepq_wait+0x42 _cv_wait+0x129 space_map_load_wait+0x20 metaslab_activate+0x73 metaslab_alloc+0x7b2 zio_dva_allocate+0x1aa zio_execute+0xc3 zio_ready+0x17d zio_execute+0xc3 zio_ready+0x17d zio_execute+0xc3 zio_ready+0x17d zio_execute+0xc3 zio_ready+0x17d zio_execute+0xc3 taskqueue_run_locked+0x85 taskqueue_thread_loop+0x4e 3 0 100099 kernel zio_write_issue_ mi_switch+0x176 sleepq_wait+0x42 _cv_wait+0x129 zio_wait+0x61 dmu_buf_hold_array_by_dnode+0x22b dmu_read+0x89 space_map_load+0x108 metaslab_activate+0xdc metaslab_alloc+0x7b2 zio_dva_allocate+0x1aa zio_execute+0xc3 taskqueue_run_locked+0x85 taskqueue_thread_loop+0x4e fork_exit+0x11f fork_trampoline+0xe 4 0 100098 kernel zio_write_issue_ mi_switch+0x176 sleepq_wait+0x42 _cv_wait+0x129 space_map_load_wait+0x20 metaslab_activate+0x73 metaslab_alloc+0x7b2 zio_dva_allocate+0x1aa zio_execute+0xc3 zio_ready+0x17d zio_execute+0xc3 taskqueue_run_locked+0x85 taskqueue_thread_loop+0x4e fork_exit+0x11f fork_trampoline+0xe 6 0 100098 kernel zio_write_issue_ mi_switch+0x176 sleepq_wait+0x42 _cv_wait+0x129 space_map_load_wait+0x20 metaslab_activate+0x73 metaslab_alloc+0x7b2 zio_dva_allocate+0x1aa zio_execute+0xc3 zio_ready+0x17d zio_execute+0xc3 zio_ready+0x17d zio_execute+0xc3 zio_ready+0x17d zio_execute+0xc3 taskqueue_run_locked+0x85 taskqueue_thread_loop+0x4e fork_exit+0x11f fork_trampoline+0xe 7 0 100098 kernel zio_write_issue_ mi_switch+0x176 sleepq_wait+0x42 _cv_wait+0x129 space_map_load_wait+0x20 metaslab_activate+0x73 metaslab_alloc+0x7b2 zio_dva_allocate+0x9a zio_execute+0xc3 zio_ready+0x17d zio_execute+0xc3 zio_ready+0x17d zio_execute+0xc3 zio_ready+0x17d zio_execute+0xc3 taskqueue_run_locked+0x85 taskqueue_thread_loop+0x4e fork_exit+0x11f fork_trampoline+0xe 7 0 100099 kernel zio_write_issue_ mi_switch+0x176 sleepq_wait+0x42 _cv_wait+0x129 space_map_load_wait+0x20 metaslab_activate+0x73 metaslab_alloc+0x7b2 zio_dva_allocate+0x9a zio_execute+0xc3 zio_ready+0x17d zio_execute+0xc3 zio_ready+0x17d zio_execute+0xc3 zio_ready+0x17d zio_execute+0xc3 taskqueue_run_locked+0x85 taskqueue_thread_loop+0x4e fork_exit+0x11f fork_trampoline+0xe 12 0 100099 kernel zio_write_issue_ mi_switch+0x176 sleepq_wait+0x42 _cv_wait+0x129 space_map_load_wait+0x20 metaslab_activate+0x73 metaslab_alloc+0x7b2 zio_dva_allocate+0x9a zio_execute+0xc3 zio_ready+0x17d zio_execute+0xc3 zio_ready+0x17d zio_execute+0xc3 taskqueue_run_locked+0x85 taskqueue_thread_loop+0x4e fork_exit+0x11f fork_trampoline+0xe 14 0 100099 kernel zio_write_issue_ mi_switch+0x176 sleepq_wait+0x42 _cv_wait+0x129 zio_wait+0x61 dmu_buf_hold_array_by_dnode+0x22b dmu_read+0x89 space_map_load+0x108 metaslab_activate+0xdc metaslab_alloc+0x7b2 zio_dva_allocate+0x9a zio_execute+0xc3 taskqueue_run_locked+0x85 taskqueue_thread_loop+0x4e fork_exit+0x11f fork_trampoline+0xe 18 0 100098 kernel zio_write_issue_ mi_switch+0x176 sleepq_wait+0x42 _cv_wait+0x129 space_map_load_wait+0x20 metaslab_activate+0x73 metaslab_alloc+0x7b2 zio_dva_allocate+0x9a zio_execute+0xc3 zio_ready+0x17d zio_execute+0xc3 zio_ready+0x17d zio_execute+0xc3 taskqueue_run_locked+0x85 taskqueue_thread_loop+0x4e fork_exit+0x11f fork_trampoline+0xe 23 0 100098 kernel zio_write_issue_ mi_switch+0x176 sleepq_wait+0x42 _cv_wait+0x129 space_map_load_wait+0x20 metaslab_activate+0x73 metaslab_alloc+0x7b2 zio_dva_allocate+0x9a zio_execute+0xc3 zio_ready+0x17d zio_execute+0xc3 taskqueue_run_locked+0x85 taskqueue_thread_loop+0x4e fork_exit+0x11f fork_trampoline+0xe 26 0 100099 kernel zio_write_issue_ mi_switch+0x176 sleepq_wait+0x42 _cv_wait+0x129 space_map_load_wait+0x20 metaslab_activate+0x73 metaslab_alloc+0x7b2 zio_dva_allocate+0x9a zio_execute+0xc3 zio_ready+0x17d zio_execute+0xc3 taskqueue_run_locked+0x85 taskqueue_thread_loop+0x4e fork_exit+0x11f fork_trampoline+0xe 31 0 100098 kernel zio_write_issue_ mi_switch+0x176 sleepq_wait+0x42 _cv_wait+0x129 space_map_load_wait+0x20 metaslab_activate+0x73 metaslab_alloc+0x7b2 zio_dva_allocate+0x1aa zio_execute+0xc3 zio_ready+0x17d zio_execute+0xc3 zio_ready+0x17d zio_execute+0xc3 taskqueue_run_locked+0x85 taskqueue_thread_loop+0x4e fork_exit+0x11f fork_trampoline+0xe 37 0 100099 kernel zio_write_issue_ mi_switch+0x176 sleepq_wait+0x42 _cv_wait+0x129 space_map_load_wait+0x20 metaslab_activate+0x73 metaslab_alloc+0x7b2 zio_dva_allocate+0x1aa zio_execute+0xc3 zio_ready+0x17d zio_execute+0xc3 zio_ready+0x17d zio_execute+0xc3 taskqueue_run_locked+0x85 taskqueue_thread_loop+0x4e fork_exit+0x11f fork_trampoline+0xe 84 0 100098 kernel zio_write_issue_ mi_switch+0x176 sleepq_wait+0x42 _cv_wait+0x129 space_map_load_wait+0x20 metaslab_activate+0x73 metaslab_alloc+0x7b2 zio_dva_allocate+0x1aa zio_execute+0xc3 taskqueue_run_locked+0x85 taskqueue_thread_loop+0x4e fork_exit+0x11f fork_trampoline+0xe 89 0 100099 kernel zio_write_issue_ mi_switch+0x176 sleepq_wait+0x42 _cv_wait+0x129 space_map_load_wait+0x20 metaslab_activate+0x73 metaslab_alloc+0x7b2 zio_dva_allocate+0x1aa zio_execute+0xc3 taskqueue_run_locked+0x85 taskqueue_thread_loop+0x4e fork_exit+0x11f fork_trampoline+0xe 145 0 100099 kernel zio_write_issue_ mi_switch+0x176 sleepq_wait+0x42 _cv_wait+0x129 space_map_load_wait+0x20 metaslab_activate+0x73 metaslab_alloc+0x7b2 zio_dva_allocate+0x9a zio_execute+0xc3 taskqueue_run_locked+0x85 taskqueue_thread_loop+0x4e fork_exit+0x11f fork_trampoline+0xe 147 0 100098 kernel zio_write_issue_ mi_switch+0x176 sleepq_wait+0x42 _cv_wait+0x129 space_map_load_wait+0x20 metaslab_activate+0x73 metaslab_alloc+0x7b2 zio_dva_allocate+0x9a zio_execute+0xc3 taskqueue_run_locked+0x85 taskqueue_thread_loop+0x4e fork_exit+0x11f fork_trampoline+0xe 313 0 100099 kernel zio_write_issue_ <running> 329 0 100098 kernel zio_write_issue_ <running> 998 0 100040 kernel nfe0 taskq mi_switch+0x176 sleepq_wait+0x42 msleep_spin+0x1a2 taskqueue_thread_loop+0x71 fork_exit+0x11f fork_trampoline+0xe 1000 0 100000 kernel swapper mi_switch+0x176 sleepq_timedwait+0x42 _sleep+0x301 scheduler+0x357 mi_startup+0x77 btext+0x2c 1000 0 100017 kernel acpi_task_0 mi_switch+0x176 sleepq_wait+0x42 msleep_spin+0x1a2 taskqueue_thread_loop+0x71 fork_exit+0x11f fork_trampoline+0xe 1000 0 100018 kernel acpi_task_1 mi_switch+0x176 sleepq_wait+0x42 msleep_spin+0x1a2 taskqueue_thread_loop+0x71 fork_exit+0x11f fork_trampoline+0xe 1000 0 100019 kernel acpi_task_2 mi_switch+0x176 sleepq_wait+0x42 msleep_spin+0x1a2 taskqueue_thread_loop+0x71 fork_exit+0x11f fork_trampoline+0xe 1000 0 100041 kernel nfe1 taskq mi_switch+0x176 sleepq_wait+0x42 msleep_spin+0x1a2 taskqueue_thread_loop+0x71 fork_exit+0x11f fork_trampoline+0xe 1000 PID TID COMM TDNAME KSTACK Thank you very much Nicolas -- http://www.rachinsky.de/nicolas
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?20130115224556.GA41774>