slowdown of zfs (tx->tx)
Nicolas Rachinsky
fbsd-mas-0 at ml.turing-complete.org
Tue Jan 15 22:46:05 UTC 2013
* Artem Belevich <art at 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 at 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
More information about the freebsd-fs
mailing list