[Gluster-users] GlusterFS (3.3.1) - performance issues - large number of LOOKUP calls & high CPU usage
Charles Cooke
charles at coupa.com
Thu Jun 6 12:23:46 UTC 2013
On Mon, May 27, 2013 at 5:20 PM, Charles Cooke <charles at coupa.com> wrote:
> Hi,
>
> We are currently attempting to use GlusterFS but are encountering
> significant performance issues in our environment. The symptoms we are
> seeing are that read/write performance degrades and the glusterfsd
> eventually takes up to 100% of the CPU.
>
> We currently run in a simple 1x2 replicated configuration. The I/O
> primarily consists of write operations, with a smaller amount of reads.
>
> What we see consistently on profiling is that the LOOKUP calls are
> consistently taking the majority of the time. I am not sure what this
> represents - but the ordinality seems to be out of whack - eg. when several
> dozen read/write operations are taking place, there will be several
> thousand LOOKUP calls.
>
> Following the discussion in the IRC Archives - there was some indication
> that our symptoms (large number of LOOKUP calls) were the result of
> self-heal checks and/or DHT misses as per:
> http://irclog.perlgeek.de/gluster/2012-11-28
> --> JoeJulian Well, that's either self-heal checks and/or dht misses.
>
> So we've disabled the self-heal daemon and turned lookup-unhashed off.
> But this hasn't had an impact on the performance either way. The volume
> information is shown below along with volume profiling information.
>
> Volume Name: gluster
> Type: Replicate
> Volume ID: 08cb1e95-1f56-449c-b427-8f1921371d5a
> Status: Started
> Number of Bricks: 1 x 2 = 2
> Transport-type: tcp
> Bricks:
> Brick1: stg100mol1-int.coupahost.com:/mnt/gluster/export
> Brick2: stg100mol2-int.coupahost.com:/mnt/gluster/export
> Options Reconfigured:
> performance.cache-size: 2000000000
> performance.cache-refresh-timeout: 0
> geo-replication.indexing: off
> diagnostics.latency-measurement: on
> diagnostics.count-fop-hits: on
> cluster.self-heal-daemon: off
> cluster.lookup-unhashed: off
>
>
> Brick: stg100mol1-int.coupahost.com:/mnt/gluster/export
> -------------------------------------------------------
> Cumulative Stats:
> Block Size: 1b+ 2b+
> 4b+
> No. of Reads: 0 0
> 0
> No. of Writes: 98 8
> 69
>
> Block Size: 8b+ 16b+
> 32b+
> No. of Reads: 0 0
> 0
> No. of Writes: 125 43
> 7
>
> Block Size: 64b+ 128b+
> 256b+
> No. of Reads: 3 0
> 18
> No. of Writes: 154 620
> 262
>
> Block Size: 512b+ 1024b+
> 2048b+
> No. of Reads: 27 68
> 14
> No. of Writes: 373 86
> 60
>
> Block Size: 4096b+ 8192b+
> 16384b+
> No. of Reads: 0 6
> 14
> No. of Writes: 11957 2398
> 6
>
> Block Size: 32768b+ 65536b+
> 131072b+
> No. of Reads: 17 65
> 149
> No. of Writes: 7 0
> 0
>
> %-latency Avg-latency Min-Latency Max-Latency No. of calls
> Fop
> --------- ----------- ----------- ----------- ------------
> ----
> 0.00 0.00 us 0.00 us 0.00 us 712
> FORGET
> 0.00 0.00 us 0.00 us 0.00 us 5789
> RELEASE
> 0.00 0.00 us 0.00 us 0.00 us 5896
> RELEASEDIR
> 0.00 86.33 us 52.00 us 137.00 us 3
> GETXATTR
> 0.00 1045.00 us 1045.00 us 1045.00 us 1
> RMDIR
> 0.00 156.98 us 32.00 us 1272.00 us 41
> FTRUNCATE
> 0.00 572.24 us 212.00 us 3865.00 us 49
> MKDIR
> 0.01 135.47 us 36.00 us 6126.00 us 471
> TRUNCATE
> 0.01 160.58 us 14.00 us 5641.00 us 470
> STAT
> 0.03 517.82 us 38.00 us 163774.00 us 471
> SETATTR
> 0.07 1445.84 us 25.00 us 97172.00 us 396
> READ
> 0.07 401.11 us 13.00 us 33647.00 us 1449
> READDIR
> 0.10 3617.81 us 111.00 us 237368.00 us 221
> STATFS
> 0.10 8252.17 us 14.00 us 406281.00 us 99
> LK
> 0.10 1161.94 us 162.00 us 263151.00 us 709
> CREATE
> 0.12 2204.37 us 79.00 us 175090.00 us 457
> RENAME
> 0.13 1084.25 us 84.00 us 487294.00 us 942
> XATTROP
> 0.24 336.51 us 23.00 us 753796.00 us 5896
> OPENDIR
> 0.25 343.05 us 25.00 us 267306.00 us 5951
> OPEN
> 0.26 763.13 us 12.00 us 498524.00 us 2729
> INODELK
> 0.26 518.81 us 11.00 us 574717.00 us 4100
> ENTRYLK
> 0.27 5757.93 us 65.00 us 266003.00 us 377
> UNLINK
> 0.28 141.80 us 25.00 us 33487.00 us 16273
> WRITE
> 0.38 303.52 us 12.00 us 905949.00 us 10244
> FSTAT
> 0.88 14109.27 us 1733.00 us 574868.00 us 505
> FSYNC
> 2.17 1793.98 us 7.00 us 1341172.00 us 9841
> FLUSH
> 3.17 788.24 us 66.00 us 925523.00 us 32627
> FXATTROP
> 13.92 7132.57 us 55.00 us 735763.00 us 15853
> READDIRP
> 18.04 2726.17 us 7.00 us 1337047.00 us 53762
> FINODELK
> 59.14 630.92 us 29.00 us 1358867.00 us 761500
> LOOKUP
>
> Duration: 2281 seconds
> Data Read: 27416867 bytes
> Data Written: 115562427 bytes
>
> Interval 47 Stats:
> Block Size: 4096b+ 8192b+
> No. of Reads: 0 0
> No. of Writes: 104 21
> %-latency Avg-latency Min-Latency Max-Latency No. of calls
> Fop
> --------- ----------- ----------- ----------- ------------
> ----
> 0.00 0.00 us 0.00 us 0.00 us 7
> RELEASE
> 0.00 0.00 us 0.00 us 0.00 us 21
> RELEASEDIR
> 0.00 18.86 us 13.00 us 36.00 us 7
> FLUSH
> 0.00 38.00 us 15.00 us 67.00 us 4
> ENTRYLK
> 0.00 230.00 us 230.00 us 230.00 us 1
> MKDIR
> 0.00 251.00 us 251.00 us 251.00 us 1
> CREATE
> 0.01 116.50 us 33.00 us 455.00 us 6
> OPEN
> 0.01 133.83 us 23.00 us 260.00 us 6
> STAT
> 0.02 827.50 us 139.00 us 1516.00 us 2
> STATFS
> 0.03 103.95 us 31.00 us 284.00 us 21
> OPENDIR
> 0.07 339.07 us 66.00 us 907.00 us 14
> READDIRP
> 0.08 89.11 us 20.00 us 750.00 us 64
> FSTAT
> 0.23 123.34 us 48.00 us 901.00 us 125
> WRITE
> 0.41 105.09 us 16.00 us 2021.00 us 263
> FINODELK
> 0.86 234.20 us 73.00 us 8309.00 us 249
> FXATTROP
> 98.27 794.98 us 32.00 us 372846.00 us 8420
> LOOKUP
>
> Duration: 11 seconds
> Data Read: 0 bytes
> Data Written: 993600 bytes
>
> Brick: stg100mol2-int.coupahost.com:/mnt/gluster/export
> -------------------------------------------------------
> Cumulative Stats:
> Block Size: 1b+ 2b+
> 4b+
> No. of Reads: 0 0
> 0
> No. of Writes: 98 8
> 69
>
> Block Size: 8b+ 16b+
> 32b+
> No. of Reads: 0 0
> 0
> No. of Writes: 125 43
> 7
>
> Block Size: 64b+ 128b+
> 256b+
> No. of Reads: 0 3
> 13
> No. of Writes: 154 620
> 262
>
> Block Size: 512b+ 1024b+
> 2048b+
> No. of Reads: 32 58
> 15
> No. of Writes: 373 86
> 60
>
> Block Size: 4096b+ 8192b+
> 16384b+
> No. of Reads: 0 6
> 16
> No. of Writes: 11957 2398
> 6
>
> Block Size: 32768b+ 65536b+
> 131072b+
> No. of Reads: 19 46
> 163
> No. of Writes: 7 0
> 0
>
> %-latency Avg-latency Min-Latency Max-Latency No. of calls
> Fop
> --------- ----------- ----------- ----------- ------------
> ----
> 0.00 0.00 us 0.00 us 0.00 us 712
> FORGET
> 0.00 0.00 us 0.00 us 0.00 us 5789
> RELEASE
> 0.00 0.00 us 0.00 us 0.00 us 5896
> RELEASEDIR
> 0.00 131.00 us 131.00 us 131.00 us 1
> RMDIR
> 0.00 87.00 us 61.00 us 113.00 us 2
> GETXATTR
> 0.00 197.12 us 32.00 us 2304.00 us 41
> FTRUNCATE
> 0.01 602.80 us 214.00 us 11089.00 us 49
> MKDIR
> 0.01 105.21 us 38.00 us 4226.00 us 471
> TRUNCATE
> 0.01 514.50 us 17.00 us 44276.00 us 98
> LK
> 0.03 369.86 us 14.00 us 35614.00 us 322
> STAT
> 0.07 618.82 us 38.00 us 230853.00 us 471
> SETATTR
> 0.07 427.43 us 172.00 us 21070.00 us 709
> CREATE
> 0.13 589.38 us 107.00 us 47276.00 us 942
> XATTROP
> 0.15 3001.27 us 111.00 us 600028.00 us 221
> STATFS
> 0.18 284.42 us 11.00 us 230739.00 us 2725
> INODELK
> 0.24 2732.04 us 23.00 us 85370.00 us 385
> READ
> 0.27 2572.42 us 75.00 us 256620.00 us 457
> RENAME
> 0.33 239.45 us 24.00 us 625901.00 us 5951
> OPEN
> 0.37 169.74 us 15.00 us 433133.00 us 9356
> FSTAT
> 0.39 1164.77 us 14.00 us 468495.00 us 1449
> READDIR
> 0.44 5045.44 us 121.00 us 89320.00 us 377
> UNLINK
> 0.46 339.88 us 21.00 us 632652.00 us 5896
> OPENDIR
> 0.55 145.86 us 25.00 us 123050.00 us 16273
> WRITE
> 0.76 803.77 us 11.00 us 857743.00 us 4100
> ENTRYLK
> 1.69 14534.79 us 1493.00 us 464961.00 us 505
> FSYNC
> 4.71 2078.22 us 6.00 us 818633.00 us 9841
> FLUSH
> 5.05 2310.54 us 56.00 us 615643.00 us 9497
> READDIRP
> 5.95 791.32 us 63.00 us 608936.00 us 32628
> FXATTROP
> 6.97 563.13 us 6.00 us 1103183.00 us 53723
> FINODELK
> 71.18 405.92 us 8.00 us 1216554.00 us 761502
> LOOKUP
>
> Duration: 2250 seconds
> Data Read: 27138474 bytes
> Data Written: 115562427 bytes
>
> Interval 47 Stats:
> Block Size: 4096b+ 8192b+
> No. of Reads: 0 0
> No. of Writes: 104 21
> %-latency Avg-latency Min-Latency Max-Latency No. of calls
> Fop
> --------- ----------- ----------- ----------- ------------
> ----
> 0.00 0.00 us 0.00 us 0.00 us 7
> RELEASE
> 0.00 0.00 us 0.00 us 0.00 us 21
> RELEASEDIR
> 0.00 26.00 us 26.00 us 26.00 us 1
> STAT
> 0.00 195.00 us 195.00 us 195.00 us 1
> CREATE
> 0.00 53.25 us 27.00 us 86.00 us 4
> ENTRYLK
> 0.00 249.00 us 249.00 us 249.00 us 1
> MKDIR
> 0.00 159.00 us 125.00 us 193.00 us 2
> STATFS
> 0.01 52.00 us 18.00 us 143.00 us 7
> FLUSH
> 0.01 65.67 us 33.00 us 136.00 us 6
> OPEN
> 0.03 98.14 us 25.00 us 405.00 us 21
> OPENDIR
> 0.04 50.35 us 18.00 us 202.00 us 57
> FSTAT
> 0.17 381.32 us 77.00 us 926.00 us 28
> READDIRP
> 0.26 134.29 us 50.00 us 1403.00 us 125
> WRITE
> 0.93 240.55 us 71.00 us 10168.00 us 250
> FXATTROP
> 0.98 240.87 us 15.00 us 34353.00 us 264
> FINODELK
> 97.56 749.24 us 28.00 us 296964.00 us 8417
> LOOKUP
>
> Duration: 11 seconds
> Data Read: 0 bytes
> Data Written: 993600 bytes
>
>
>
>
>
Hello,
As a followup for anyone experiencing similar issues - switching to an NFS
mount from a Gluster Native resolved the issue.
The giveaway was the large number of context switches happening in the
kernel during some heavy operations (vmstat or dstat) - neither the I/O,
network interface, or CPU was the bottleneck - but the context switching
was causing significant impact on the performance of our Java application.
The application has a large volume of writes on many small files, which is
not ideal for the FUSE client. Switching to NFS brought the times down an
order of magnitude.
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://supercolony.gluster.org/pipermail/gluster-users/attachments/20130606/ba5be1d9/attachment.html>
More information about the Gluster-users
mailing list