slowdown of zfs (tx->tx)

[Nicolas Rachinsky]

* Nicolas Rachinsky <fbsd-mas-0 at ml.turing-complete.org> [2013-01-10 20:39 +0100]:
> after replacing one of the controllers, all problems seem to have
> disappeared. Thank you very much for your advice!

Now the problem is back.

After changing the controller, there were no more timeouts logged.

No UDMA_CRC_Error_Count changed.

While the problem exists, top almost all the time shows:

last pid: 46322;  load averages:  0.90,  1.03,  0.98   up 0+11:07:55  08:28:41
39 processes:  1 running, 38 sleeping
CPU:  0.0% user,  0.0% nice, 50.1% system,  0.0% interrupt, 49.9% idle
Mem: 10M Active, 33M Inact, 7612M Wired, 23M Cache, 827M Buf, 234M Free
Swap: 16G Total, 13M Used, 16G Free

  PID USERNAME   THR PRI NICE   SIZE    RES STATE   C   TIME   WCPU COMMAND
  926 root         1  44    0 28020K  2404K select  1   2:23  0.29% snmpd
41642 user1        1  44    0  5828K   204K tx->tx  0  20:53  0.00% rsync
41641 user1        1  44    0 29952K  3976K select  1  13:39  0.00% ssh
41640 user1        1  44    0  5828K   140K select  1   0:20  0.00% rsync
90399 user2        1  44    0 14020K   872K tx->tx  0   0:16  0.00% rsync
  956 root         1  44    0 11808K   708K select  1   0:02  0.00% ntpd
 1051 root         1  44    0  8356K   640K kqread  0   0:00  0.00% master
25713 root         1  44    0 38108K  3596K select  1   0:00  0.00% sshd
  875 root         1  44    0  6920K   572K select  1   0:00  0.00% syslogd
 1066 root         1  44    0  7976K   564K nanslp  1   0:00  0.00% cron
 1058 postfix      1  44    0  8356K   792K kqread  1   0:00  0.00% qmgr
  705 root         1  44    0  5248K   120K select  1   0:00  0.00% devd
25715 root         1  44    0 10248K  2828K pause   1   0:00  0.00% csh
 1062 root         1  44    0 26176K   952K select  1   0:00  0.00% sshd
90401 user2        1  44    0 14020K   768K select  1   0:00  0.00% rsync
90400 user2        1  44    0 23808K   892K select  1   0:00  0.00% ssh
90372 user2        1  59    0  8344K   124K wait    0   0:00  0.00% sh
41619 user1        1  76    0  8344K    40K wait    1   0:00  0.00% sh
46322 root         1  44    0  9372K  1800K CPU1    1   0:00  0.00% top
89384 root         1  44    0  8344K   712K wait    0   0:00  0.00% sh
37854 root         1  45    0  8360K   472K piperd  1   0:00  0.00% sendmail
45382 postfix      1  44    0  8360K  1324K kqread  1   0:00  0.00% pickup
41608 root         1  76    0  8344K   440K wait    0   0:00  0.00% sh
25768 root         1  52    0 13440K  1716K nanslp  0   0:00  0.00% smartd
33599 root         1  50    0  8344K   452K wait    1   0:00  0.00% sh
33597 root         1  52    0  8344K   440K wait    1   0:00  0.00% sh
37855 root         1  44    0  8360K   468K piperd  0   0:00  0.00% postdrop
33591 root         1  44    0  7976K   524K piperd  1   0:00  0.00% cron
33595 root         1  46    0  8344K   436K wait    1   0:00  0.00% sh
33594 root         1  44    0  8344K   436K wait    1   0:00  0.00% sh
33592 root         1  45    0  7976K   524K piperd  1   0:00  0.00% cron
 1106 root         1  76    0  6916K   352K ttyin   1   0:00  0.00% getty
 1111 root         1  76    0  6916K   352K ttyin   1   0:00  0.00% getty
 1107 root         1  76    0  6916K   352K ttyin   0   0:00  0.00% getty
 1108 root         1  76    0  6916K   352K ttyin   0   0:00  0.00% getty
 1112 root         1  76    0  6916K   352K ttyin   0   0:00  0.00% getty
 1109 root         1  76    0  6916K   352K ttyin   1   0:00  0.00% getty
 1113 root         1  76    0  6916K   352K ttyin   0   0:00  0.00% getty
 1110 root         1  76    0  6916K   352K ttyin   0   0:00  0.00% getty

The result of
sh -c "while :;do gstat -I 5s -b ;done" > gstat.txt & iostat -d -x -w 5 > iostat.txt & zpool iostat -v 5 > zpool.txt &
is available via
http://flummi.dauerreden.de/20130111/zpool.txt
http://flummi.dauerreden.de/20130111/gstat.txt
http://flummi.dauerreden.de/20130111/iostat.txt

Thanks in advance!

Nicolas
-- 
http://www.rachinsky.de/nicolas