<html>
<head>
<meta http-equiv="Content-Type" content="text/html; charset=Windows-1252">
<style type="text/css" style="display:none"><!-- p { margin-top: 0px; margin-bottom: 0px; }--></style>
</head>
<body dir="ltr" style="font-size:12pt;color:#000000;background-color:#FFFFFF;font-family:Calibri,Arial,Helvetica,sans-serif;">
<p>Thanks, that was helpful reading although I'm not 100% sure where to start.<br>
</p>
<p><br>
</p>
<p>I did a bit of testing with the scripts and running IOmeter on a VM residing on a vSphere host connected to my ZFS box with 8Gbit Fibre channel.<br>
</p>
<p><br>
</p>
<p>I noticed that txg commits rarely took over 1 second.<br>
</p>
<p><br>
</p>
<div>root@zfs10:/tmp# dtrace -s duration.d pool01</div>
<div>dtrace: script 'duration.d' matched 2 probes</div>
<div>CPU ID FUNCTION:NAME</div>
<div> 7 17407 txg_sync_thread:txg-synced sync took 0.68 seconds</div>
<div> 8 17407 txg_sync_thread:txg-synced sync took 0.71 seconds</div>
<div> 12 17407 txg_sync_thread:txg-synced sync took 0.52 seconds</div>
<div> 7 17407 txg_sync_thread:txg-synced sync took 0.29 seconds</div>
<div> 22 17407 txg_sync_thread:txg-synced sync took 0.64 seconds</div>
<div> 1 17407 txg_sync_thread:txg-synced sync took 0.34 seconds</div>
<div> 5 17407 txg_sync_thread:txg-synced sync took 0.93 seconds</div>
<div> 0 17407 txg_sync_thread:txg-synced sync took 0.46 seconds</div>
<div> 9 17407 txg_sync_thread:txg-synced sync took 2.59 seconds</div>
<div> 0 17407 txg_sync_thread:txg-synced sync took 0.29 seconds</div>
<div> 7 17407 txg_sync_thread:txg-synced sync took 1.31 seconds</div>
<div> 8 17407 txg_sync_thread:txg-synced sync took 0.71 seconds</div>
<div> 10 17407 txg_sync_thread:txg-synced sync took 0.67 seconds</div>
<div> 8 17407 txg_sync_thread:txg-synced sync took 0.29 seconds</div>
<div> 12 17407 txg_sync_thread:txg-synced sync took 0.58 seconds</div>
<div> 1 17407 txg_sync_thread:txg-synced sync took 0.46 seconds</div>
<div><br>
also I noticed that the default allocation of 4GB on the slog device was never used, the peak I saw was just over 1GB, most of the time half that.<br>
</div>
<div><br>
</div>
<div>
<div> 0 17408 txg_sync_thread:txg-syncing 1179MB of 4096MB used</div>
<div> 9 17408 txg_sync_thread:txg-syncing 482MB of 4096MB used</div>
<div> 20 17408 txg_sync_thread:txg-syncing 686MB of 4096MB used</div>
<div> 0 17408 txg_sync_thread:txg-syncing 429MB of 4096MB used</div>
<div> 14 17408 txg_sync_thread:txg-syncing 328MB of 4096MB used</div>
<div> 10 17408 txg_sync_thread:txg-syncing 374MB of 4096MB used</div>
<div> 8 17408 txg_sync_thread:txg-syncing 510MB of 4096MB used</div>
<div> 12 17408 txg_sync_thread:txg-syncing 210MB of 4096MB used</div>
<div> 1 17408 txg_sync_thread:txg-syncing 268MB of 4096MB used</div>
<div> 0 17408 txg_sync_thread:txg-syncing 432MB of 4096MB used</div>
<div> 16 17408 txg_sync_thread:txg-syncing 236MB of 4096MB used</div>
<div> 18 17408 txg_sync_thread:txg-syncing 341MB of 4096MB used</div>
<div> 9 17408 txg_sync_thread:txg-syncing 361MB of 4096MB used</div>
<div> 14 17408 txg_sync_thread:txg-syncing 597MB of 4096MB used</div>
<div> 10 17408 txg_sync_thread:txg-syncing 357MB of 4096MB used</div>
<div> 21 17408 txg_sync_thread:txg-syncing 437MB of 4096MB used</div>
<div> 18 17408 txg_sync_thread:txg-syncing 637MB of 4096MB used</div>
<div><br>
I did not see any significant write latency, but I did see a high read latency which is odd since it doesn't reflect what I experience on the VM or the vSphere host.<br>
</div>
<div><br>
</div>
<div>
<div>root@zfs10:/tmp# dtrace -s rw.d -c 'sleep 60'</div>
<div><br>
</div>
<div> write</div>
<div> value ------------- Distribution ------------- count</div>
<div> 8 | 0</div>
<div> 16 | 27</div>
<div> 32 |@ 11222</div>
<div> 64 |@@@@@@@ 106215</div>
<div> 128 |@@@@@@@@@@@@@@@@@@@@@@ 327807</div>
<div> 256 |@@@@@@ 94605</div>
<div> 512 |@ 20467</div>
<div> 1024 | 6067</div>
<div> 2048 |@ 7968</div>
<div> 4096 |@ 10076</div>
<div> 8192 | 3380</div>
<div> 16384 | 249</div>
<div> 32768 | 214</div>
<div> 65536 | 219</div>
<div> 131072 | 77</div>
<div> 262144 | 1</div>
<div> 524288 | 0</div>
<div><br>
</div>
<div> read</div>
<div> value ------------- Distribution ------------- count</div>
<div> 4 | 0</div>
<div> 8 | 18</div>
<div> 16 | 58</div>
<div> 32 | 174</div>
<div> 64 |@@@@@@ 4322</div>
<div> 128 |@@@@@@@@@ 6278</div>
<div> 256 |@@@ 2545</div>
<div> 512 |@ 892</div>
<div> 1024 |@ 1074</div>
<div> 2048 |@@ 1171</div>
<div> 4096 |@@@ 2222</div>
<div> 8192 |@@@@@@ 4103</div>
<div> 16384 |@@@ 2400</div>
<div> 32768 |@@ 1401</div>
<div> 65536 |@@ 1504</div>
<div> 131072 |@ 897</div>
<div> 262144 |@ 427</div>
<div> 524288 | 39</div>
<div> 1048576 | 1</div>
<div> 2097152 | 0</div>
<div><br>
</div>
<div> avg latency stddev iops throughput</div>
<div>write 496us 3136us 9809/s 450773k/s</div>
<div>read 22633us 59917us 492/s 17405k/s</div>
<div><br>
I also happen to monitor how busy each disk is and I don't see any significant load there either... here is an example<br>
</div>
<div><br>
</div>
<div><img name="null" title="pastedImage.png" originalwidth="973" originalheight="337" width="480.8" height="166.5257965056526" src="cid:391d20a6-a7e7-4ec1-850c-2153d4eb4f64"><br>
</div>
<div><br>
</div>
<div>so I'm a bit lost as what to do next, I don't see any stress on the system in terms of writes but I still cannot max out the 8gbit FC... reads however are doing fairly good, getting just over 700MB/sec which is acceptable over 8Gbit FC. Writes tend to
be between 350 and 450 MB/sec... they should get up to 700MB/sec as well.<br>
</div>
<div><br>
</div>
<div>Any ideas where to start? <br>
</div>
<div><br>
</div>
<div>br,<br>
</div>
<div>Rune<br>
</div>
<br>
</div>
<br>
</div>
<div><br>
</div>
<p><br>
</p>
<div style="color: rgb(33, 33, 33);">
<hr tabindex="-1" style="display:inline-block; width:98%">
<div id="divRplyFwdMsg" dir="ltr"><font face="Calibri, sans-serif" color="#000000" style="font-size:11pt"><b>From:</b> Schweiss, Chip <chip@innovates.com><br>
<b>Sent:</b> Wednesday, October 14, 2015 2:44 PM<br>
<b>To:</b> Rune Tipsmark<br>
<b>Cc:</b> omnios-discuss@lists.omniti.com<br>
<b>Subject:</b> Re: [OmniOS-discuss] ZIL TXG commits happen very frequently - why?</font>
<div> </div>
</div>
<div>
<div dir="ltr">
<div>It all has to do with the write throttle and buffers filling. Here's a great blog post on how it works and how it's tuned:<br>
<br>
<a href="http://dtrace.org/blogs/ahl/2014/02/10/the-openzfs-write-throttle/">http://dtrace.org/blogs/ahl/2014/02/10/the-openzfs-write-throttle/</a><br>
<br>
<a href="http://dtrace.org/blogs/ahl/2014/08/31/openzfs-tuning/">http://dtrace.org/blogs/ahl/2014/08/31/openzfs-tuning/</a><br>
<br>
</div>
-Chip<br>
<div><br>
</div>
</div>
<div class="gmail_extra"><br>
<div class="gmail_quote">On Wed, Oct 14, 2015 at 12:45 AM, Rune Tipsmark <span dir="ltr">
<<a href="mailto:rt@steait.net" target="_blank">rt@steait.net</a>></span> wrote:<br>
<blockquote class="gmail_quote" style="margin:0 0 0 .8ex; border-left:1px #ccc solid; padding-left:1ex">
<div lang="EN-US">
<div>
<p class="MsoNormal">Hi all.<u></u><u></u></p>
<p class="MsoNormal"><u></u> <u></u></p>
<p class="MsoNormal">Wondering if anyone could shed some light on why my ZFS pool would perform TXG commits up to 5 times per second. It’s set to the default 5 second interval and occasionally it does wait 5 seconds between commits, but only when nearly idle.<u></u><u></u></p>
<p class="MsoNormal"><u></u> <u></u></p>
<p class="MsoNormal">I’m not sure if this impacts my performance but I would suspect it doesn’t improve it. I force sync on all data.<u></u><u></u></p>
<p class="MsoNormal"><u></u> <u></u></p>
<p class="MsoNormal">I got 11 mirrors (7200rpm sas disks) two SLOG devices and two L2 ARC devices and a pair of spare disks.<u></u><u></u></p>
<p class="MsoNormal"><u></u> <u></u></p>
<p class="MsoNormal">Each log device can hold 150GB of data so plenty for 2 TXG commits. The system has 384GB memory.<u></u><u></u></p>
<p class="MsoNormal">
<u></u><u></u></p>
<p class="MsoNormal">Below is a bit of output from zilstat during a near idle time this morning so you wont see 4-5 commits per second, but during load later today it will happen..<u></u><u></u></p>
<p class="MsoNormal"><u></u> <u></u></p>
<p class="MsoNormal">root@zfs10:/tmp# ./zilstat.ksh -M -t -p pool01 txg<u></u><u></u></p>
<p class="MsoNormal">waiting for txg commit...<u></u><u></u></p>
<p class="MsoNormal">TIME txg N-MB N-MB/s N-Max-Rate B-MB B-MB/s B-Max-Rate ops <=4kB 4-32kB >=32kB<u></u><u></u></p>
<p class="MsoNormal">2015 Oct 14 06:21:19 10872771 3 3 0 21 21 2 234 14 19 201<u></u><u></u></p>
<p class="MsoNormal">2015 Oct 14 06:21:22 10872772 10 3 3 70 23 24 806 0 84 725<u></u><u></u></p>
<p class="MsoNormal">2015 Oct 14 06:21:24 10872773 12 6 5 56 28 26 682 17 107 558<u></u><u></u></p>
<p class="MsoNormal">2015 Oct 14 06:21:25 10872774 13 13 2 75 75 14 651 0 10 641<u></u><u></u></p>
<p class="MsoNormal">2015 Oct 14 06:21:25 10872775 0 0 0 0 0 0 1 0 0 1<u></u><u></u></p>
<p class="MsoNormal">2015 Oct 14 06:21:26 10872776 11 11 6 53 53 29 645 2 136 507<u></u><u></u></p>
<p class="MsoNormal">2015 Oct 14 06:21:30 10872777 11 2 4 81 20 32 873 11 60 804<u></u><u></u></p>
<p class="MsoNormal">2015 Oct 14 06:21:30 10872778 0 0 0 0 0 0 1 0 1 0<u></u><u></u></p>
<p class="MsoNormal">2015 Oct 14 06:21:31 10872779 12 12 11 56 56 52 631 0 8 623<u></u><u></u></p>
<p class="MsoNormal">2015 Oct 14 06:21:33 10872780 11 5 4 74 37 27 858 0 44 814<u></u><u></u></p>
<p class="MsoNormal">2015 Oct 14 06:21:36 10872781 14 4 6 79 26 30 977 12 82 883<u></u><u></u></p>
<p class="MsoNormal">2015 Oct 14 06:21:39 10872782 11 3 4 78 26 25 957 18 55 884<u></u><u></u></p>
<p class="MsoNormal">2015 Oct 14 06:21:43 10872783 13 3 4 80 20 24 930 0 135 795<u></u><u></u></p>
<p class="MsoNormal">2015 Oct 14 06:21:46 10872784 13 4 4 81 27 29 965 13 95 857<u></u><u></u></p>
<p class="MsoNormal">2015 Oct 14 06:21:49 10872785 11 3 6 80 26 41 1077 12 215 850<u></u><u></u></p>
<p class="MsoNormal">2015 Oct 14 06:21:53 10872786 9 3 2 67 22 18 870 1 74 796<u></u><u></u></p>
<p class="MsoNormal">2015 Oct 14 06:21:56 10872787 12 3 5 72 18 26 909 17 163 729<u></u><u></u></p>
<p class="MsoNormal">2015 Oct 14 06:21:58 10872788 12 6 3 53 26 21 530 0 33 497<u></u><u></u></p>
<p class="MsoNormal">2015 Oct 14 06:21:59 10872789 26 26 24 72 72 62 882 12 60 810<u></u><u></u></p>
<p class="MsoNormal">2015 Oct 14 06:22:02 10872790 9 3 5 57 19 28 777 0 70 708<u></u><u></u></p>
<p class="MsoNormal">2015 Oct 14 06:22:07 10872791 11 2 3 96 24 22 1044 12 46 986<u></u><u></u></p>
<p class="MsoNormal">2015 Oct 14 06:22:10 10872792 13 3 4 78 19 22 911 12 38 862<u></u><u></u></p>
<p class="MsoNormal">2015 Oct 14 06:22:14 10872793 11 2 4 79 19 26 930 10 94 826<u></u><u></u></p>
<p class="MsoNormal">2015 Oct 14 06:22:17 10872794 11 3 5 73 24 26 1054 17 151 886<u></u><u></u></p>
<p class="MsoNormal">2015 Oct 14 06:22:17 10872795 0 0 0 0 0 0 2 0 0 2<u></u><u></u></p>
<p class="MsoNormal">2015 Oct 14 06:22:18 10872796 40 40 38 78 78 60 707 0 28 680<u></u><u></u></p>
<p class="MsoNormal">2015 Oct 14 06:22:22 10872797 10 3 3 66 22 21 937 14 164 759<u></u><u></u></p>
<p class="MsoNormal">2015 Oct 14 06:22:25 10872798 9 2 2 66 16 21 821 11 92 718<u></u><u></u></p>
<p class="MsoNormal">2015 Oct 14 06:22:28 10872799 24 12 14 80 40 43 750 0 23 727<u></u><u></u></p>
<p class="MsoNormal">2015 Oct 14 06:22:28 10872800 0 0 0 0 0 0 2 0 0 2<u></u><u></u></p>
<p class="MsoNormal">2015 Oct 14 06:22:29 10872801 15 7 9 49 24 24 526 11 25 490<u></u><u></u></p>
<p class="MsoNormal">2015 Oct 14 06:22:33 10872802 10 2 3 79 19 24 939 0 63 876<u></u><u></u></p>
<p class="MsoNormal">2015 Oct 14 06:22:36 10872803 10 5 3 59 29 18 756 11 65 682<u></u><u></u></p>
<p class="MsoNormal">2015 Oct 14 06:22:36 10872804 0 0 0 0 0 0 0 0 0 0<u></u><u></u></p>
<p class="MsoNormal">2015 Oct 14 06:22:36 10872805 13 13 2 58 58 9 500 0 29 471<u></u><u></u></p>
<p class="MsoNormal"><u></u> <u></u></p>
<p class="MsoNormal">--<u></u><u></u></p>
<p class="MsoNormal"><u></u> <u></u></p>
<p class="MsoNormal">root@zfs10:/tmp# zpool status pool01<u></u><u></u></p>
<p class="MsoNormal"> pool: pool01<u></u><u></u></p>
<p class="MsoNormal">state: ONLINE<u></u><u></u></p>
<p class="MsoNormal"> scan: scrub repaired 0 in 7h53m with 0 errors on Sat Oct 3 06:53:43 2015<u></u><u></u></p>
<p class="MsoNormal">config:<u></u><u></u></p>
<p class="MsoNormal"><u></u> <u></u></p>
<p class="MsoNormal"> NAME STATE READ WRITE CKSUM<u></u><u></u></p>
<p class="MsoNormal"> <span lang="DE">pool01 ONLINE 0 0 0<u></u><u></u></span></p>
<p class="MsoNormal"><span lang="DE"> mirror-0 ONLINE 0 0 0<u></u><u></u></span></p>
<p class="MsoNormal"><span lang="DE"> c4t5000C50055FC9533d0 ONLINE 0 0 0<u></u><u></u></span></p>
<p class="MsoNormal"><span lang="DE"> c4t5000C50055FE6A63d0 ONLINE 0 0 0<u></u><u></u></span></p>
<p class="MsoNormal"><span lang="DE"> mirror-1 ONLINE 0 0 0<u></u><u></u></span></p>
<p class="MsoNormal"><span lang="DE"> c4t5000C5005708296Fd0 ONLINE 0 0 0<u></u><u></u></span></p>
<p class="MsoNormal"><span lang="DE"> c4t5000C5005708351Bd0 ONLINE 0 0 0<u></u><u></u></span></p>
<p class="MsoNormal"><span lang="DE"> mirror-2 ONLINE 0 0 0<u></u><u></u></span></p>
<p class="MsoNormal"><span lang="DE"> c4t5000C500570858EFd0 ONLINE 0 0 0<u></u><u></u></span></p>
<p class="MsoNormal"><span lang="DE"> c4t5000C50057085A6Bd0 ONLINE 0 0 0<u></u><u></u></span></p>
<p class="MsoNormal"><span lang="DE"> mirror-3 ONLINE 0 0 0<u></u><u></u></span></p>
<p class="MsoNormal"><span lang="DE"> c4t5000C50057086307d0 ONLINE 0 0 0<u></u><u></u></span></p>
<p class="MsoNormal"><span lang="DE"> c4t5000C50057086B67d0 ONLINE 0 0 0<u></u><u></u></span></p>
<p class="MsoNormal"><span lang="DE"> mirror-4 ONLINE 0 0 0<u></u><u></u></span></p>
<p class="MsoNormal"><span lang="DE"> c4t5000C500570870D3d0 ONLINE 0 0 0<u></u><u></u></span></p>
<p class="MsoNormal"><span lang="DE"> c4t5000C50057089753d0 ONLINE 0 0 0<u></u><u></u></span></p>
<p class="MsoNormal"><span lang="DE"> mirror-5 ONLINE 0 0 0<u></u><u></u></span></p>
<p class="MsoNormal"><span lang="DE"> c4t5000C500625B7EA7d0 ONLINE 0 0 0<u></u><u></u></span></p>
<p class="MsoNormal"><span lang="DE"> c4t5000C500625B8137d0 ONLINE 0 0 0<u></u><u></u></span></p>
<p class="MsoNormal"><span lang="DE"> mirror-6 ONLINE 0 0 0<u></u><u></u></span></p>
<p class="MsoNormal"><span lang="DE"> c4t5000C500625B8427d0 ONLINE 0 0 0<u></u><u></u></span></p>
<p class="MsoNormal"><span lang="DE"> c4t5000C500625B86E3d0 ONLINE 0 0 0<u></u><u></u></span></p>
<p class="MsoNormal"><span lang="DE"> mirror-7 ONLINE 0 0 0<u></u><u></u></span></p>
<p class="MsoNormal"><span lang="DE"> c4t5000C500625B886Fd0 ONLINE 0 0 0<u></u><u></u></span></p>
<p class="MsoNormal"><span lang="DE"> c4t5000C500625BB773d0 ONLINE 0 0 0<u></u><u></u></span></p>
<p class="MsoNormal"><span lang="DE"> mirror-8 ONLINE 0 0 0<u></u><u></u></span></p>
<p class="MsoNormal"><span lang="DE"> c4t5000C500625BC2C3d0 ONLINE 0 0 0<u></u><u></u></span></p>
<p class="MsoNormal"><span lang="DE"> c4t5000C500625BD3EBd0 ONLINE 0 0 0<u></u><u></u></span></p>
<p class="MsoNormal"><span lang="DE"> mirror-9 ONLINE 0 0 0<u></u><u></u></span></p>
<p class="MsoNormal"><span lang="DE"> c4t5000C50062878C0Bd0 ONLINE 0 0 0<u></u><u></u></span></p>
<p class="MsoNormal"><span lang="DE"> c4t5000C50062878C43d0 ONLINE 0 0 0<u></u><u></u></span></p>
<p class="MsoNormal"><span lang="DE"> mirror-10 ONLINE 0 0 0<u></u><u></u></span></p>
<p class="MsoNormal"><span lang="DE"> c4t5000C50062879687d0 ONLINE 0 0 0<u></u><u></u></span></p>
<p class="MsoNormal"><span lang="DE"> c4t5000C50062879707d0 ONLINE 0 0 0<u></u><u></u></span></p>
<p class="MsoNormal"><span lang="DE"> </span>logs<u></u><u></u></p>
<p class="MsoNormal"> c11d0 ONLINE 0 0 0<u></u><u></u></p>
<p class="MsoNormal"> c10d0 ONLINE 0 0 0<u></u><u></u></p>
<p class="MsoNormal"> cache<u></u><u></u></p>
<p class="MsoNormal"> c14d0 ONLINE 0 0 0<u></u><u></u></p>
<p class="MsoNormal"> c15d0 ONLINE 0 0 0<u></u><u></u></p>
<p class="MsoNormal"> spares<u></u><u></u></p>
<p class="MsoNormal"> c4t5000C50062879723d0 AVAIL<u></u><u></u></p>
<p class="MsoNormal"> c4t5000C50062879787d0 AVAIL<u></u><u></u></p>
<p class="MsoNormal"><u></u> <u></u></p>
<p class="MsoNormal">errors: No known data errors<u></u><u></u></p>
<p class="MsoNormal"><u></u> <u></u></p>
<p class="MsoNormal"><u></u> <u></u></p>
<p class="MsoNormal"><span style="font-size:10.0pt; color:#878787">Br,<u></u><u></u></span></p>
<p class="MsoNormal"><span style="font-size:10.0pt; color:#878787">Rune</span><u></u><u></u></p>
</div>
</div>
<br>
_______________________________________________<br>
OmniOS-discuss mailing list<br>
<a href="mailto:OmniOS-discuss@lists.omniti.com">OmniOS-discuss@lists.omniti.com</a><br>
<a href="http://lists.omniti.com/mailman/listinfo/omnios-discuss" rel="noreferrer" target="_blank">http://lists.omniti.com/mailman/listinfo/omnios-discuss</a><br>
<br>
</blockquote>
</div>
<br>
</div>
</div>
</div>
</body>
</html>