<div dir="ltr"><div>I got some log from client side</div><div><br></div><div><br></div><div><b>PARTI</b></div><div>[2015-02-10 08:23:01.613646] D [MSGID: 0] [dht-common.c:2183:dht_lookup] 0-r2dr3-dht: Calling fresh lookup for /1w_test00/721ea549-8e2b-4770-9c52-2cc0c4ef872d on r2dr3-replicate-0</div><div>[2015-02-10 08:23:01.613947] D [afr-lk-common.c:447:transaction_lk_op] 0-r2dr3-replicate-1: lk op is for a transaction</div><div>[2015-02-10 08:23:01.614417] D [MSGID: 0] [dht-common.c:1819:dht_lookup_cbk] 0-r2dr3-dht: fresh_lookup returned for /1w_test00/721ea549-8e2b-4770-9c52-2cc0c4ef872d with op_ret -1 and op_errno 2</div><div>[2015-02-10 08:23:01.614444] D [MSGID: 0] [dht-common.c:1823:dht_lookup_cbk] 0-r2dr3-dht: Entry /1w_test00/721ea549-8e2b-4770-9c52-2cc0c4ef872d missing on subvol r2dr3-replicate-0</div><div>[2015-02-10 08:23:01.614463] D [MSGID: 0] [dht-common.c:1608:dht_lookup_everywhere] 0-r2dr3-dht: winding lookup call to 2 subvols</div><div>[2015-02-10 08:23:01.615067] D [MSGID: 0] [dht-common.c:1414:dht_lookup_everywhere_cbk] 0-r2dr3-dht: returned with op_ret -1 and op_errno 2 (/1w_test00/721ea549-8e2b-4770-9c52-2cc0c4ef872d) from subvol r2dr3-replicate-1</div><div>[2015-02-10 08:23:01.615117] D [MSGID: 0] [dht-common.c:1414:dht_lookup_everywhere_cbk] 0-r2dr3-dht: returned with op_ret -1 and op_errno 2 (/1w_test00/721ea549-8e2b-4770-9c52-2cc0c4ef872d) from subvol r2dr3-replicate-0</div><div>[2015-02-10 08:23:01.615139] D [MSGID: 0] [dht-common.c:1086:dht_lookup_everywhere_done] 0-r2dr3-dht: STATUS: hashed_subvol r2dr3-replicate-0 cached_subvol null</div><div>[2015-02-10 08:23:01.615158] D [MSGID: 0] [dht-common.c:1147:dht_lookup_everywhere_done] 0-r2dr3-dht: There was no cached file and unlink on hashed is not skipped /1w_test00/721ea549-8e2b-4770-9c52-2cc0c4ef872d</div><div>[2015-02-10 08:23:01.615761] D [afr-transaction.c:1177:afr_post_nonblocking_entrylk_cbk] 0-r2dr3-replicate-0: Non blocking entrylks done. Proceeding to FOP</div><div>[2015-02-10 08:23:01.616450] D [afr-lk-common.c:447:transaction_lk_op] 0-r2dr3-replicate-0: lk op is for a transaction</div><div>[2015-02-10 08:23:01.617153] D [afr-transaction.c:1127:afr_post_nonblocking_inodelk_cbk] 0-r2dr3-replicate-0: Non blocking inodelks done. Proceeding to FOP</div><div>[2015-02-10 08:23:01.618365] D [MSGID: 0] [dht-common.c:2183:dht_lookup] 0-r2dr3-dht: Calling fresh lookup for /1w_test00/70e8e730-0442-47c3-94c6-e2d13506427f on r2dr3-replicate-0</div><div>[2015-02-10 08:23:01.618670] D [afr-lk-common.c:447:transaction_lk_op] 0-r2dr3-replicate-0: lk op is for a transaction</div><div>[2015-02-10 08:23:01.619054] D [MSGID: 0] [dht-common.c:1819:dht_lookup_cbk] 0-r2dr3-dht: fresh_lookup returned for /1w_test00/70e8e730-0442-47c3-94c6-e2d13506427f with op_ret -1 and op_errno 2</div><div>[2015-02-10 08:23:01.619077] D [MSGID: 0] [dht-common.c:1823:dht_lookup_cbk] 0-r2dr3-dht: Entry /1w_test00/70e8e730-0442-47c3-94c6-e2d13506427f missing on subvol r2dr3-replicate-0</div><div>[2015-02-10 08:23:01.619096] D [MSGID: 0] [dht-common.c:1608:dht_lookup_everywhere] 0-r2dr3-dht: winding lookup call to 2 subvols</div><div>[2015-02-10 08:23:01.619812] D [MSGID: 0] [dht-common.c:1414:dht_lookup_everywhere_cbk] 0-r2dr3-dht: returned with op_ret -1 and op_errno 2 (/1w_test00/70e8e730-0442-47c3-94c6-e2d13506427f) from subvol r2dr3-replicate-1</div><div>[2015-02-10 08:23:01.619910] D [MSGID: 0] [dht-common.c:1414:dht_lookup_everywhere_cbk] 0-r2dr3-dht: returned with op_ret -1 and op_errno 2 (/1w_test00/70e8e730-0442-47c3-94c6-e2d13506427f) from subvol r2dr3-replicate-0</div><div>[2015-02-10 08:23:01.619953] D [MSGID: 0] [dht-common.c:1086:dht_lookup_everywhere_done] 0-r2dr3-dht: STATUS: hashed_subvol r2dr3-replicate-0 cached_subvol null</div><div>[2015-02-10 08:23:01.619971] D [MSGID: 0] [dht-common.c:1147:dht_lookup_everywhere_done] 0-r2dr3-dht: There was no cached file and unlink on hashed is not skipped /1w_test00/70e8e730-0442-47c3-94c6-e2d13506427f</div><div>[2015-02-10 08:23:01.620542] D [afr-transaction.c:1177:afr_post_nonblocking_entrylk_cbk] 0-r2dr3-replicate-0: Non blocking entrylks done. Proceeding to FOP</div><div>[2015-02-10 08:23:01.621220] D [afr-lk-common.c:447:transaction_lk_op] 0-r2dr3-replicate-0: lk op is for a transaction</div><div>[2015-02-10 08:23:01.621946] D [afr-transaction.c:1127:afr_post_nonblocking_inodelk_cbk] 0-r2dr3-replicate-0: Non blocking inodelks done. Proceeding to FOP</div><div>[2015-02-10 08:23:01.623192] D [MSGID: 0] [dht-common.c:2183:dht_lookup] 0-r2dr3-dht: Calling fresh lookup for /1w_test00/65dc668b-4b42-45e8-942d-dcb283c206a0 on r2dr3-replicate-1</div><div>[2015-02-10 08:23:01.623540] D [afr-lk-common.c:447:transaction_lk_op] 0-r2dr3-replicate-0: lk op is for a transaction</div><div>[2015-02-10 08:23:01.623948] D [MSGID: 0] [dht-common.c:1819:dht_lookup_cbk] 0-r2dr3-dht: fresh_lookup returned for /1w_test00/65dc668b-4b42-45e8-942d-dcb283c206a0 with op_ret -1 and op_errno 2</div><div>[2015-02-10 08:23:01.623975] D [MSGID: 0] [dht-common.c:1823:dht_lookup_cbk] 0-r2dr3-dht: Entry /1w_test00/65dc668b-4b42-45e8-942d-dcb283c206a0 missing on subvol r2dr3-replicate-1</div><div>[2015-02-10 08:23:01.623997] D [MSGID: 0] [dht-common.c:1608:dht_lookup_everywhere] 0-r2dr3-dht: winding lookup call to 2 subvols</div><div>[2015-02-10 08:23:01.624645] D [MSGID: 0] [dht-common.c:1414:dht_lookup_everywhere_cbk] 0-r2dr3-dht: returned with op_ret -1 and op_errno 2 (/1w_test00/65dc668b-4b42-45e8-942d-dcb283c206a0) from subvol r2dr3-replicate-1</div><div>[2015-02-10 08:23:01.624746] D [MSGID: 0] [dht-common.c:1414:dht_lookup_everywhere_cbk] 0-r2dr3-dht: returned with op_ret -1 and op_errno 2 (/1w_test00/65dc668b-4b42-45e8-942d-dcb283c206a0) from subvol r2dr3-replicate-0</div><div>[2015-02-10 08:23:01.624773] D [MSGID: 0] [dht-common.c:1086:dht_lookup_everywhere_done] 0-r2dr3-dht: STATUS: hashed_subvol r2dr3-replicate-1 cached_subvol null</div><div>[2015-02-10 08:23:01.624792] D [MSGID: 0] [dht-common.c:1147:dht_lookup_everywhere_done] 0-r2dr3-dht: There was no cached file and unlink on hashed is not skipped /1w_test00/65dc668b-4b42-45e8-942d-dcb283c206a0</div><div>[2015-02-10 08:23:01.625299] D [afr-transaction.c:1177:afr_post_nonblocking_entrylk_cbk] 0-r2dr3-replicate-1: Non blocking entrylks done. Proceeding to FOP</div><div>[2015-02-10 08:23:01.625971] D [afr-lk-common.c:447:transaction_lk_op] 0-r2dr3-replicate-1: lk op is for a transaction</div><div>[2015-02-10 08:23:01.626690] D [afr-transaction.c:1127:afr_post_nonblocking_inodelk_cbk] 0-r2dr3-replicate-1: Non blocking inodelks done. Proceeding to FOP</div><div><br></div><div class="gmail_extra"><br></div><div class="gmail_extra"><b>PARTII</b><br></div><div class="gmail_extra"><div class="gmail_extra">[2015-02-10 08:48:30.396145] D [rpc-clnt-ping.c:255:rpc_clnt_start_ping] 0-r2dr3-client-1: returning as transport is already disconnected OR there are no frames (0 || 0)</div><div class="gmail_extra">[2015-02-10 08:48:37.396576] D [rpc-clnt-ping.c:255:rpc_clnt_start_ping] 0-r2dr3-client-3: returning as transport is already disconnected OR there are no frames (0 || 0)</div><div class="gmail_extra">[2015-02-10 08:48:38.396684] D [rpc-clnt-ping.c:255:rpc_clnt_start_ping] 0-r2dr3-client-2: returning as transport is already disconnected OR there are no frames (0 || 0)</div><div class="gmail_extra">[2015-02-10 08:49:13.398692] D [rpc-clnt-ping.c:255:rpc_clnt_start_ping] 0-r2dr3-client-0: returning as transport is already disconnected OR there are no frames (0 || 0)</div><div class="gmail_extra">[2015-02-10 08:49:13.398751] D [rpc-clnt-ping.c:255:rpc_clnt_start_ping] 0-r2dr3-client-1: returning as transport is already disconnected OR there are no frames (0 || 0)</div><div class="gmail_extra">[2015-02-10 08:49:20.399164] D [rpc-clnt-ping.c:255:rpc_clnt_start_ping] 0-r2dr3-client-3: returning as transport is already disconnected OR there are no frames (0 || 0)</div><div><br></div></div><div class="gmail_extra"><br></div><div class="gmail_extra"><b>Volume INFO</b></div><div class="gmail_extra"><div>Volume Name: r2dr3</div><div>Type: Distributed-Replicate</div><div>Volume ID: b30ffc1a-9a6c-45e7-a847-97efd9d864d2</div><div>Status: Started</div><div>Number of Bricks: 2 x 2 = 4</div><div>Transport-type: tcp</div><div>Bricks:</div><div>Brick1: node1:/gfs_data/r2dr3</div><div>Brick2: node2:/gfs_data/r2dr3</div><div>Brick3: node3:/gfs_data/r2dr3</div><div>Brick4: node4:/gfs_data/r2dr3</div><div>Options Reconfigured:</div><div>diagnostics.count-fop-hits: on</div><div>diagnostics.latency-measurement: on</div><div>diagnostics.brick-log-level: DEBUG</div><div>diagnostics.client-log-level: DEBUG</div></div><div class="gmail_extra"><br></div><div class="gmail_extra"><br><div class="gmail_quote">2015-02-06 18:32 GMT+08:00 Ason Hu <span dir="ltr"><<a href="mailto:tobechihiro@gmail.com" target="_blank">tobechihiro@gmail.com</a>></span>:<br><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left-width:1px;border-left-color:rgb(204,204,204);border-left-style:solid;padding-left:1ex"><div dir="ltr">Hi Pranith,<div><br></div><div><br></div><div><div>Gluster Version :</div><div>glusterfs 3.6.2 built on Jan 22 2015 12:58:10</div></div><div><ul><li>100,000 file test in XFS directly<br></li></ul></div><blockquote style="margin:0px 0px 0px 40px;border:none;padding:0px"><div>[root@glusterfs-node1 gfs_data]# java FileCreationAndSearchtest 10w_test 100000</div><div><div>Creation finished!! Time: <b>8961(ms)</b></div></div><div><div>File Search Finished!! 33223 searches, time: 124ms, misses:0</div></div><div><div>NIO Search Finished!! 33223 searches, time: 367ms, misses:0</div></div></blockquote><div><br></div><div><ul><li>100,000 file test from client (Distributed Replicated)<br></li></ul></div><blockquote style="margin:0px 0px 0px 40px;border:none;padding:0px"><div><div>[root@glusterfs-client01 drvol]# java FileCreationAndSearchtest 10w_test01 100000</div></div><div><div>Start!!</div></div><div><div>Creation finished!! Time: <b>265713(ms)</b></div></div><div><div>File Search Finished!! 33453 searches, time: 18403(ms), misses:0</div></div><div><div>NIO Search Finished!! 33453 searches, time: 17827(ms), misses:0</div></div></blockquote><div><br></div><div><br></div><div>after many small file created (<span style="color:rgb(84,84,84);line-height:18.2000007629395px">≒</span>200 million), it cost more than 1000000(ms) to finish 100,000 file test</div><div><br></div><div>I've flushed all volumes and create new one to reproduce the condition again.</div><div><div><div><br></div><div><br></div><div><div class="gmail_extra"><br><div class="gmail_quote">2015-02-05 19:19 GMT+08:00 Pranith Kumar Karampuri <span dir="ltr"><<a href="mailto:pkarampu@redhat.com" target="_blank">pkarampu@redhat.com</a>></span>:<br><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left-width:1px;border-left-color:rgb(204,204,204);border-left-style:solid;padding-left:1ex">
<div text="#000000" bgcolor="#FFFFFF"><span>
<br>
<div>On 02/02/2015 02:42 PM, Ason Hu wrote:<br>
</div>
<blockquote type="cite">
<div dir="ltr">Hi,
<div><br>
</div>
<div>In my small file test, 3 types of volume are created in
same GlusterFS Cluster (4 nodes)</div>
<div>
<ul>
<li>Distritubed<br>
</li>
<li>Distributed Replicated<br>
</li>
<li>Distributed Striped</li>
</ul>
<br>
10 million small files (8 byte) create and search each test
cycle life <br>
<table style="border-spacing:0px;color:rgb(119,119,119);font-size:13px">
<tbody>
</tbody>
</table>
<div><br>
</div>
<div><br>
</div>
<div>
<div>Nodes info : </div>
<div>
<ul>
<li>OS : CentOS 6.6 64bit</li>
<li>RAM : 64GB<br>
</li>
<li>HDD : 4TB, 7200RPM, SAS *6 RAID 0<br>
</li>
<li>FileSystem : XFS, BS=4K</li>
</ul>
</div>
</div>
<div><br>
</div>
<div><br>
</div>
<div>Problem :</div>
<div><br>
</div>
<div>It occur when file reach <span style="color:rgb(84,84,84);line-height:18.2000007629395px">≒</span>200
million (sum of 3 volumes)</div>
</div>
<div>files created speed drop from <span style="color:rgb(84,84,84);line-height:18.2000007629395px"> </span><span style="color:rgb(84,84,84);line-height:18.2000007629395px">≒</span>1500
to <span style="color:rgb(84,84,84);line-height:18.2000007629395px"> </span><span style="color:rgb(84,84,84);line-height:18.2000007629395px">≒</span>100</div>
</div>
</blockquote></span>
If you do this test directly on the XFS partition, what is the kind
of performance difference you see?<br>
<br>
Pranith<span><br>
<blockquote type="cite">
<div dir="ltr">
<div><br>
</div>
<div>Though the speed of creation become slow but search speed
and throughput still good </div>
<div>Seems each types of volume have same problem, I don't know
what cause this problem..<br>
</div>
<div><br>
</div>
<div><br>
</div>
<div>Workaround :</div>
<div><br>
</div>
<div>I try to create new volume ( Distributed |
Distributed Replicated | Distributed Striped ), mount it, </div>
<div>problem solved!</div>
<div>But the old volume write speed still sad..</div>
<div><br>
</div>
<div><br>
</div>
<div><br>
</div>
<div>I'd try to increase below volume setting, but don't work
at all</div>
<div>
<ul>
<li>performance.cache-size <br>
</li>
<li>performance.io-thread-count</li>
</ul>
</div>
<div>
<div><br>
</div>
<div>I didn't enable the volume qouta option.</div>
<div>Does glusterfs volume have some kind of limitation of
file creation? <br>
</div>
</div>
</div>
</blockquote>
</span><blockquote type="cite">
<div dir="ltr">
<div><br>
</div>
<div><br>
</div>
<div>Regards</div>
<div>Nosa Hu,</div>
<div><br>
</div>
<div><br>
</div>
</div>
<br>
<fieldset></fieldset>
<br>
<pre>_______________________________________________
Gluster-users mailing list
<a href="mailto:Gluster-users@gluster.org" target="_blank">Gluster-users@gluster.org</a>
<a href="http://www.gluster.org/mailman/listinfo/gluster-users" target="_blank">http://www.gluster.org/mailman/listinfo/gluster-users</a></pre>
</blockquote>
<br>
</div>
</blockquote></div><br></div></div></div></div></div>
</blockquote></div><br></div></div>