Skip site navigation (1)Skip section navigation (2)
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>