Description of problem: While creating nested directory and file on a 3*3 volume the performance of creation degrades on 100+ iterations. Version-Release number of selected component (if applicable): How reproducible:2/2 Attaching sosoreports at qe.eng.blr.redhat.com:/var/www/html/sosreports/<bug> Steps to Reproduce: 1. create a volume 3*3 with arbiter as the third brick. (VolumeName-GUESS) 2. Mount a fuse mount on the client side and use the following script on client to start the IO. The IO's are of 50Kb each 1 for ((i=0;i<=100000;i++)) 2 3 do 4 #rm -rvf folder$i 5 mkdir f$i 6 cd f$i 7 dd if=/dev/urandom of=d$i count=5 bs=10k 8 #cd .. 9 done 3. When the directory creation reaches 107+ the creation slows down to 1 file(s) per 40 seconds. Actual results: creation taking 40+ seconds for a single 50KB file. Expected results: Creation shouldn't take less than a second for a 50Kb file. Additional info: ************************************************************************ [root@dhcp43-157 ~]# gluster volume status Status of volume: guess Gluster process TCP Port RDMA Port Online Pid ------------------------------------------------------------------------------ Brick dhcp43-157.lab.eng.blr.redhat.com:/rh s/brick1/guess 49154 0 Y 18242 Brick dhcp43-192.lab.eng.blr.redhat.com:/rh s/brick1/guess 49154 0 Y 15486 Brick dhcp43-153.lab.eng.blr.redhat.com:/rh s/brick1/guess 49154 0 Y 2084 Brick dhcp43-157.lab.eng.blr.redhat.com:/rh s/brick2/guess 49155 0 Y 16136 Brick dhcp43-192.lab.eng.blr.redhat.com:/rh s/brick2/guess 49155 0 Y 23306 Brick dhcp43-153.lab.eng.blr.redhat.com:/rh s/brick2/guess 49155 0 Y 2093 Brick dhcp43-157.lab.eng.blr.redhat.com:/rh s/brick3/guess 49156 0 Y 23608 Brick dhcp43-192.lab.eng.blr.redhat.com:/rh s/brick3/guess 49156 0 Y 23325 Brick dhcp43-153.lab.eng.blr.redhat.com:/rh s/brick3/guess 49156 0 Y 10888 Self-heal Daemon on localhost N/A N/A Y 18262 Self-heal Daemon on dhcp43-153.lab.eng.blr. redhat.com N/A N/A Y 12868 Self-heal Daemon on dhcp43-192.lab.eng.blr. redhat.com N/A N/A Y 17389 Task Status of Volume guess ------------------------------------------------------------------------------ There are no active volume tasks ************************************************************************ [root@dhcp43-157 ~]# gluster volume info Volume Name: guess Type: Distributed-Replicate Volume ID: 6f64fde7-d697-4d67-bdca-4adff1902f45 Status: Started Number of Bricks: 3 x (2 + 1) = 9 Transport-type: tcp Bricks: Brick1: dhcp43-157.lab.eng.blr.redhat.com:/rhs/brick1/guess Brick2: dhcp43-192.lab.eng.blr.redhat.com:/rhs/brick1/guess Brick3: dhcp43-153.lab.eng.blr.redhat.com:/rhs/brick1/guess (arbiter) Brick4: dhcp43-157.lab.eng.blr.redhat.com:/rhs/brick2/guess Brick5: dhcp43-192.lab.eng.blr.redhat.com:/rhs/brick2/guess Brick6: dhcp43-153.lab.eng.blr.redhat.com:/rhs/brick2/guess (arbiter) Brick7: dhcp43-157.lab.eng.blr.redhat.com:/rhs/brick3/guess Brick8: dhcp43-192.lab.eng.blr.redhat.com:/rhs/brick3/guess Brick9: dhcp43-153.lab.eng.blr.redhat.com:/rhs/brick3/guess (arbiter) Options Reconfigured: cluster.post-op-delay-secs: 0 diagnostics.count-fop-hits: on diagnostics.latency-measurement: on transport.address-family: inet performance.readdir-ahead: on nfs.disable: on ************************************************************************** OUTPUT OF gluster volume PROFILING:- [root@dhcp43-157 ~]# cat profile.out Brick: dhcp43-157.lab.eng.blr.redhat.com:/rhs/brick2/guess ---------------------------------------------------------- Cumulative Stats: Block Size: 8192b+ 16384b+ 32768b+ No. of Reads: 0 0 0 No. of Writes: 2597 68 59 %-latency Avg-latency Min-Latency Max-Latency No. of calls Fop --------- ----------- ----------- ----------- ------------ ---- 0.00 0.00 us 0.00 us 0.00 us 902 FORGET 0.00 0.00 us 0.00 us 0.00 us 607 RELEASE 0.00 0.00 us 0.00 us 0.00 us 3121 RELEASEDIR 0.00 89.00 us 19.00 us 180.00 us 4 GETXATTR 0.01 1248.50 us 1175.00 us 1311.00 us 4 READDIR 0.01 70.26 us 30.00 us 201.00 us 74 STATFS 0.03 88.79 us 50.00 us 159.00 us 170 REMOVEXATTR 0.03 101.59 us 54.00 us 206.00 us 170 OPEN 0.04 114.21 us 62.00 us 206.00 us 170 FSTAT 0.05 51.17 us 16.00 us 178.00 us 550 FLUSH 0.06 174.92 us 107.00 us 349.00 us 170 TRUNCATE 0.07 48.16 us 17.00 us 158.00 us 720 FINODELK 0.11 170.20 us 86.00 us 362.00 us 340 XATTROP 0.16 167.91 us 30.00 us 1648.00 us 509 STAT 0.16 119.88 us 71.00 us 261.00 us 720 FXATTROP 0.20 574.37 us 141.00 us 1528.00 us 190 CREATE 0.24 518.02 us 131.00 us 3835.00 us 246 UNLINK 0.27 260.43 us 52.00 us 1172.00 us 558 SETXATTR 0.27 83.93 us 41.00 us 516.00 us 1738 WRITE 0.57 435.42 us 83.00 us 1973.00 us 702 RMDIR 0.58 64.36 us 17.00 us 6277.00 us 4832 INODELK 0.67 74.08 us 16.00 us 1831.00 us 4796 ENTRYLK 0.78 749.21 us 166.00 us 24603.00 us 558 MKDIR 1.25 234.88 us 3.00 us 8322.00 us 2838 OPENDIR 34.04 5020.08 us 30.00 us 28323.00 us 3614 READDIRP 60.39 610.81 us 49.00 us 8257.00 us 52686 LOOKUP Duration: 9581 seconds Data Read: 0 bytes Data Written: 31027200 bytes Interval 3 Stats: Block Size: 8192b+ 16384b+ No. of Reads: 0 0 No. of Writes: 98 1 %-latency Avg-latency Min-Latency Max-Latency No. of calls Fop --------- ----------- ----------- ----------- ------------ ---- 0.00 0.00 us 0.00 us 0.00 us 20 RELEASE 0.01 55.88 us 20.00 us 178.00 us 40 FLUSH 0.01 59.10 us 21.00 us 122.00 us 40 FINODELK 0.01 189.14 us 111.00 us 348.00 us 14 STAT 0.01 64.93 us 30.00 us 152.00 us 41 STATFS 0.03 141.62 us 71.00 us 236.00 us 40 FXATTROP 0.05 100.03 us 48.00 us 246.00 us 99 WRITE 0.05 57.37 us 22.00 us 253.00 us 178 ENTRYLK 0.09 72.72 us 24.00 us 414.00 us 230 INODELK 0.11 1094.60 us 894.00 us 1528.00 us 20 CREATE 0.16 460.26 us 320.00 us 1172.00 us 69 SETXATTR 0.46 1282.45 us 997.00 us 2183.00 us 69 MKDIR 99.00 674.29 us 82.00 us 3797.00 us 28536 LOOKUP Duration: 56 seconds Data Read: 0 bytes Data Written: 1024000 bytes Brick: dhcp43-157.lab.eng.blr.redhat.com:/rhs/brick1/guess ---------------------------------------------------------- Cumulative Stats: Block Size: 1b+ 4b+ 8b+ No. of Reads: 0 0 0 No. of Writes: 2 490 1 Block Size: 16b+ 32b+ 64b+ No. of Reads: 0 0 2 No. of Writes: 1777 2232 99995 Block Size: 128b+ 4096b+ 8192b+ No. of Reads: 0 0 15 No. of Writes: 4 20 2848 Block Size: 16384b+ 32768b+ 131072b+ No. of Reads: 51 272 892 No. of Writes: 59 3 0 %-latency Avg-latency Min-Latency Max-Latency No. of calls Fop --------- ----------- ----------- ----------- ------------ ---- 0.00 0.00 us 0.00 us 0.00 us 964 FORGET 0.00 0.00 us 0.00 us 0.00 us 101986 RELEASE 0.00 0.00 us 0.00 us 0.00 us 448787 RELEASEDIR 0.00 106.25 us 63.00 us 193.00 us 4 GETXATTR 0.01 884.75 us 799.00 us 1042.00 us 4 READDIR 0.01 86.61 us 31.00 us 223.00 us 74 STATFS 0.03 95.22 us 52.00 us 269.00 us 165 REMOVEXATTR 0.04 88.48 us 33.00 us 528.00 us 236 READ 0.05 184.33 us 108.00 us 320.00 us 165 TRUNCATE 0.06 91.12 us 21.00 us 585.00 us 397 FSTAT 0.09 167.50 us 89.00 us 532.00 us 330 XATTROP 0.10 112.75 us 44.00 us 3557.00 us 501 OPEN 0.17 154.76 us 33.00 us 1372.00 us 629 STAT 0.22 670.23 us 133.00 us 19669.00 us 189 CREATE 0.24 562.08 us 127.00 us 5467.00 us 246 UNLINK 0.26 274.23 us 61.00 us 864.00 us 558 SETXATTR 0.34 53.14 us 17.00 us 769.00 us 3778 FINODELK 0.44 50.83 us 14.00 us 9472.00 us 5067 FLUSH 0.55 455.41 us 93.00 us 10218.00 us 702 RMDIR 0.57 70.19 us 17.00 us 7490.00 us 4695 INODELK 0.69 84.41 us 14.00 us 3164.00 us 4794 ENTRYLK 0.70 727.11 us 153.00 us 2151.00 us 558 MKDIR 0.70 84.74 us 34.00 us 15899.00 us 4789 WRITE 0.92 141.32 us 64.00 us 15192.00 us 3780 FXATTROP 1.30 267.57 us 3.00 us 9871.00 us 2838 OPENDIR 33.16 5275.17 us 29.00 us 28659.00 us 3663 READDIRP 59.36 657.12 us 53.00 us 4460.00 us 52644 LOOKUP Duration: 338646 seconds Data Read: 129295635 bytes Data Written: 38085936 bytes Interval 3 Stats: Block Size: 16b+ 32b+ 8192b+ No. of Reads: 0 0 0 No. of Writes: 69 69 115 Block Size: 32768b+ No. of Reads: 68 No. of Writes: 0 %-latency Avg-latency Min-Latency Max-Latency No. of calls Fop --------- ----------- ----------- ----------- ------------ ---- 0.00 0.00 us 0.00 us 0.00 us 160 RELEASE 0.02 86.44 us 31.00 us 200.00 us 41 STATFS 0.02 70.23 us 22.00 us 585.00 us 66 FSTAT 0.02 77.32 us 34.00 us 228.00 us 68 READ 0.03 109.12 us 34.00 us 214.00 us 49 STAT 0.05 62.05 us 20.00 us 416.00 us 184 FINODELK 0.06 64.36 us 21.00 us 232.00 us 184 ENTRYLK 0.06 100.14 us 46.00 us 570.00 us 137 OPEN 0.10 85.94 us 34.00 us 204.00 us 253 WRITE 0.10 74.88 us 22.00 us 464.00 us 296 INODELK 0.12 1098.43 us 903.00 us 1331.00 us 23 CREATE 0.12 140.61 us 67.00 us 420.00 us 184 FXATTROP 0.13 58.73 us 15.00 us 641.00 us 459 FLUSH 0.15 473.49 us 324.00 us 864.00 us 69 SETXATTR 0.44 1345.03 us 1035.00 us 2151.00 us 69 MKDIR 98.56 727.85 us 78.00 us 3240.00 us 28609 LOOKUP Duration: 56 seconds Data Read: 2873819 bytes Data Written: 1183255 bytes Brick: dhcp43-157.lab.eng.blr.redhat.com:/rhs/brick3/guess ---------------------------------------------------------- Cumulative Stats: Block Size: 8192b+ 16384b+ 32768b+ No. of Reads: 0 0 0 No. of Writes: 168491 756 62 Block Size: 131072b+ No. of Reads: 0 No. of Writes: 271200 %-latency Avg-latency Min-Latency Max-Latency No. of calls Fop --------- ----------- ----------- ----------- ------------ ---- 0.00 0.00 us 0.00 us 0.00 us 137515 FORGET 0.00 0.00 us 0.00 us 0.00 us 36056 RELEASE 0.00 0.00 us 0.00 us 0.00 us 315720 RELEASEDIR 0.00 78.00 us 36.00 us 187.00 us 4 GETXATTR 0.01 909.25 us 782.00 us 984.00 us 4 READDIR 0.01 59.88 us 26.00 us 127.00 us 74 STATFS 0.03 91.11 us 51.00 us 205.00 us 154 REMOVEXATTR 0.03 102.58 us 54.00 us 224.00 us 154 OPEN 0.03 113.26 us 65.00 us 217.00 us 154 FSTAT 0.05 50.48 us 16.00 us 164.00 us 512 FLUSH 0.05 168.78 us 113.00 us 246.00 us 154 TRUNCATE 0.06 47.90 us 19.00 us 209.00 us 666 FINODELK 0.10 166.18 us 89.00 us 370.00 us 308 XATTROP 0.15 153.64 us 24.00 us 620.00 us 509 STAT 0.15 117.98 us 67.00 us 225.00 us 666 FXATTROP 0.24 608.92 us 133.00 us 26920.00 us 211 UNLINK 0.26 84.72 us 39.00 us 216.00 us 1608 WRITE 0.26 250.63 us 47.00 us 781.00 us 558 SETXATTR 0.53 60.13 us 18.00 us 3692.00 us 4696 INODELK 0.58 439.85 us 85.00 us 2414.00 us 702 RMDIR 0.61 68.69 us 15.00 us 1755.00 us 4704 ENTRYLK 0.75 714.48 us 144.00 us 2431.00 us 558 MKDIR 1.08 3192.51 us 139.00 us 461575.00 us 179 CREATE 1.17 218.55 us 3.00 us 7153.00 us 2838 OPENDIR 33.19 4984.17 us 28.00 us 27260.00 us 3538 READDIRP 60.68 612.66 us 28.00 us 3608.00 us 52627 LOOKUP Duration: 358519 seconds Data Read: 0 bytes Data Written: 37290956800 bytes Interval 3 Stats: Block Size: 8192b+ No. of Reads: 0 No. of Writes: 130 %-latency Avg-latency Min-Latency Max-Latency No. of calls Fop --------- ----------- ----------- ----------- ------------ ---- 0.00 0.00 us 0.00 us 0.00 us 26 RELEASE 0.01 160.93 us 116.00 us 257.00 us 14 STAT 0.01 58.02 us 28.00 us 127.00 us 41 STATFS 0.01 51.10 us 19.00 us 98.00 us 52 FLUSH 0.01 54.65 us 22.00 us 120.00 us 52 FINODELK 0.03 129.79 us 73.00 us 204.00 us 52 FXATTROP 0.05 50.53 us 19.00 us 250.00 us 190 ENTRYLK 0.06 96.47 us 44.00 us 204.00 us 130 WRITE 0.07 62.28 us 20.00 us 454.00 us 234 INODELK 0.15 1130.04 us 926.00 us 1505.00 us 26 CREATE 0.15 441.46 us 317.00 us 781.00 us 69 SETXATTR 0.46 1322.30 us 1013.00 us 2431.00 us 69 MKDIR 98.96 682.87 us 81.00 us 3128.00 us 28544 LOOKUP Duration: 56 seconds Data Read: 0 bytes Data Written: 1331200 bytes Brick: dhcp43-153.lab.eng.blr.redhat.com:/rhs/brick2/guess ---------------------------------------------------------- Cumulative Stats: Block Size: 1b+ No. of Reads: 0 No. of Writes: 2929 %-latency Avg-latency Min-Latency Max-Latency No. of calls Fop --------- ----------- ----------- ----------- ------------ ---- 0.00 0.00 us 0.00 us 0.00 us 948 FORGET 0.00 0.00 us 0.00 us 0.00 us 2038 RELEASE 0.00 0.00 us 0.00 us 0.00 us 355258 RELEASEDIR 0.00 78.75 us 38.00 us 159.00 us 4 GETXATTR 0.01 1117.75 us 1074.00 us 1215.00 us 4 READDIR 0.05 90.13 us 51.00 us 151.00 us 170 REMOVEXATTR 0.05 97.77 us 51.00 us 297.00 us 170 TRUNCATE 0.05 104.42 us 51.00 us 222.00 us 170 OPEN 0.06 117.39 us 64.00 us 239.00 us 170 FSTAT 0.09 55.69 us 17.00 us 231.00 us 550 FLUSH 0.11 51.45 us 18.00 us 469.00 us 720 FINODELK 0.19 177.96 us 89.00 us 635.00 us 340 XATTROP 0.27 122.49 us 69.00 us 801.00 us 720 FXATTROP 0.30 518.86 us 119.00 us 1195.00 us 190 CREATE 0.31 409.07 us 99.00 us 1075.00 us 246 UNLINK 0.32 59.06 us 23.00 us 296.00 us 1738 WRITE 0.41 237.07 us 46.00 us 770.00 us 558 SETXATTR 0.87 58.40 us 19.00 us 1008.00 us 4832 INODELK 0.92 422.91 us 88.00 us 1584.00 us 702 RMDIR 0.97 65.25 us 15.00 us 1356.00 us 4796 ENTRYLK 1.12 650.05 us 148.00 us 1999.00 us 558 MKDIR 1.79 204.99 us 3.00 us 1429.00 us 2838 OPENDIR 92.10 566.67 us 35.00 us 3837.00 us 52689 LOOKUP Duration: 241951 seconds Data Read: 0 bytes Data Written: 2929 bytes Interval 3 Stats: Block Size: 1b+ No. of Reads: 0 No. of Writes: 99 %-latency Avg-latency Min-Latency Max-Latency No. of calls Fop --------- ----------- ----------- ----------- ------------ ---- 0.00 0.00 us 0.00 us 0.00 us 20 RELEASE 0.01 55.75 us 19.00 us 105.00 us 40 FLUSH 0.01 57.95 us 20.00 us 147.00 us 40 FINODELK 0.03 141.35 us 70.00 us 201.00 us 40 FXATTROP 0.04 72.11 us 27.00 us 161.00 us 99 WRITE 0.06 55.16 us 20.00 us 216.00 us 178 ENTRYLK 0.09 68.20 us 21.00 us 349.00 us 230 INODELK 0.10 889.15 us 796.00 us 1195.00 us 20 CREATE 0.15 377.48 us 275.00 us 597.00 us 69 SETXATTR 0.43 1109.26 us 848.00 us 1999.00 us 69 MKDIR 99.08 616.46 us 85.00 us 2650.00 us 28528 LOOKUP Duration: 56 seconds Data Read: 0 bytes Data Written: 99 bytes Brick: dhcp43-153.lab.eng.blr.redhat.com:/rhs/brick1/guess ---------------------------------------------------------- Cumulative Stats: Block Size: 1b+ No. of Reads: 0 No. of Writes: 76282 %-latency Avg-latency Min-Latency Max-Latency No. of calls Fop --------- ----------- ----------- ----------- ------------ ---- 0.00 0.00 us 0.00 us 0.00 us 966 FORGET 0.00 0.00 us 0.00 us 0.00 us 71386 RELEASE 0.00 0.00 us 0.00 us 0.00 us 355083 RELEASEDIR 0.00 98.00 us 38.00 us 186.00 us 4 GETXATTR 0.01 1129.25 us 1061.00 us 1220.00 us 4 READDIR 0.04 94.73 us 52.00 us 183.00 us 165 REMOVEXATTR 0.04 95.32 us 49.00 us 168.00 us 165 TRUNCATE 0.06 121.47 us 67.00 us 891.00 us 165 FSTAT 0.14 99.66 us 44.00 us 466.00 us 501 OPEN 0.16 169.71 us 90.00 us 347.00 us 330 XATTROP 0.28 517.40 us 118.00 us 1538.00 us 189 CREATE 0.31 441.18 us 124.00 us 2105.00 us 246 UNLINK 0.40 253.01 us 49.00 us 814.00 us 558 SETXATTR 0.57 53.23 us 16.00 us 806.00 us 3778 FINODELK 0.70 48.53 us 13.00 us 886.00 us 5067 FLUSH 0.81 60.93 us 18.00 us 397.00 us 4695 INODELK 0.81 59.87 us 24.00 us 425.00 us 4789 WRITE 0.84 423.24 us 99.00 us 2645.00 us 702 RMDIR 0.93 68.29 us 15.00 us 605.00 us 4794 ENTRYLK 1.03 649.54 us 147.00 us 2450.00 us 558 MKDIR 1.37 127.33 us 63.00 us 10001.00 us 3780 FXATTROP 1.71 212.39 us 3.00 us 1372.00 us 2838 OPENDIR 89.78 600.48 us 35.00 us 3787.00 us 52646 LOOKUP Duration: 241951 seconds Data Read: 0 bytes Data Written: 76282 bytes Interval 3 Stats: Block Size: 1b+ No. of Reads: 0 No. of Writes: 253 %-latency Avg-latency Min-Latency Max-Latency No. of calls Fop --------- ----------- ----------- ----------- ------------ ---- 0.00 0.00 us 0.00 us 0.00 us 160 RELEASE 0.06 58.08 us 19.00 us 806.00 us 184 FINODELK 0.06 58.57 us 21.00 us 289.00 us 184 ENTRYLK 0.07 97.12 us 45.00 us 448.00 us 137 OPEN 0.08 63.30 us 25.00 us 425.00 us 253 WRITE 0.11 72.72 us 22.00 us 397.00 us 296 INODELK 0.11 939.65 us 771.00 us 1538.00 us 23 CREATE 0.14 57.24 us 14.00 us 880.00 us 459 FLUSH 0.15 415.52 us 279.00 us 758.00 us 69 SETXATTR 0.19 190.53 us 67.00 us 10001.00 us 184 FXATTROP 0.40 1099.13 us 859.00 us 2450.00 us 69 MKDIR 98.63 652.12 us 81.00 us 3089.00 us 28600 LOOKUP Duration: 56 seconds Data Read: 0 bytes Data Written: 253 bytes Brick: dhcp43-153.lab.eng.blr.redhat.com:/rhs/brick3/guess ---------------------------------------------------------- Cumulative Stats: Block Size: 1b+ No. of Reads: 0 No. of Writes: 2390 %-latency Avg-latency Min-Latency Max-Latency No. of calls Fop --------- ----------- ----------- ----------- ------------ ---- 0.00 0.00 us 0.00 us 0.00 us 913 FORGET 0.00 0.00 us 0.00 us 0.00 us 545 RELEASE 0.00 0.00 us 0.00 us 0.00 us 3055 RELEASEDIR 0.00 229.00 us 20.00 us 438.00 us 4 GETXATTR 0.01 1130.25 us 994.00 us 1295.00 us 4 READDIR 0.04 91.89 us 55.00 us 165.00 us 154 REMOVEXATTR 0.05 106.35 us 53.00 us 221.00 us 154 OPEN 0.05 113.28 us 53.00 us 366.00 us 154 TRUNCATE 0.06 122.51 us 67.00 us 1053.00 us 154 FSTAT 0.09 57.48 us 17.00 us 246.00 us 512 FLUSH 0.11 53.09 us 19.00 us 215.00 us 666 FINODELK 0.17 176.80 us 89.00 us 371.00 us 308 XATTROP 0.25 123.48 us 69.00 us 259.00 us 666 FXATTROP 0.26 404.11 us 101.00 us 1199.00 us 211 UNLINK 0.31 559.80 us 145.00 us 1194.00 us 179 CREATE 0.31 62.63 us 24.00 us 1336.00 us 1608 WRITE 0.41 236.71 us 63.00 us 897.00 us 558 SETXATTR 0.85 58.23 us 18.00 us 471.00 us 4696 INODELK 0.95 434.99 us 86.00 us 1564.00 us 702 RMDIR 0.95 65.41 us 14.00 us 1000.00 us 4704 ENTRYLK 1.11 643.74 us 158.00 us 1950.00 us 558 MKDIR 1.71 195.04 us 3.00 us 1249.00 us 2838 OPENDIR 92.29 566.25 us 20.00 us 4704.00 us 52630 LOOKUP Duration: 9580 seconds Data Read: 0 bytes Data Written: 2390 bytes Interval 3 Stats: Block Size: 1b+ No. of Reads: 0 No. of Writes: 130 %-latency Avg-latency Min-Latency Max-Latency No. of calls Fop --------- ----------- ----------- ----------- ------------ ---- 0.00 0.00 us 0.00 us 0.00 us 26 RELEASE 0.02 63.12 us 21.00 us 231.00 us 52 FLUSH 0.02 66.33 us 23.00 us 215.00 us 52 FINODELK 0.04 142.27 us 69.00 us 259.00 us 52 FXATTROP 0.05 75.08 us 28.00 us 188.00 us 130 WRITE 0.06 56.68 us 21.00 us 215.00 us 190 ENTRYLK 0.09 66.12 us 24.00 us 471.00 us 234 INODELK 0.13 905.15 us 804.00 us 1049.00 us 26 CREATE 0.14 363.78 us 277.00 us 626.00 us 69 SETXATTR 0.42 1105.45 us 873.00 us 1950.00 us 69 MKDIR 99.03 623.91 us 86.00 us 2695.00 us 28538 LOOKUP Duration: 56 seconds Data Read: 0 bytes Data Written: 130 bytes Brick: dhcp43-192.lab.eng.blr.redhat.com:/rhs/brick3/guess ---------------------------------------------------------- Cumulative Stats: Block Size: 8192b+ 16384b+ 32768b+ No. of Reads: 0 0 0 No. of Writes: 168491 756 62 Block Size: 131072b+ No. of Reads: 0 No. of Writes: 271200 %-latency Avg-latency Min-Latency Max-Latency No. of calls Fop --------- ----------- ----------- ----------- ------------ ---- 0.00 0.00 us 0.00 us 0.00 us 137523 FORGET 0.00 0.00 us 0.00 us 0.00 us 36056 RELEASE 0.00 0.00 us 0.00 us 0.00 us 315714 RELEASEDIR 0.00 79.75 us 28.00 us 163.00 us 4 GETXATTR 0.01 61.41 us 22.00 us 166.00 us 74 STATFS 0.01 1205.75 us 1130.00 us 1275.00 us 4 READDIR 0.03 82.16 us 48.00 us 196.00 us 154 REMOVEXATTR 0.04 108.65 us 63.00 us 222.00 us 154 FSTAT 0.04 108.74 us 50.00 us 1749.00 us 154 OPEN 0.06 51.30 us 16.00 us 181.00 us 512 FLUSH 0.06 170.58 us 104.00 us 292.00 us 154 TRUNCATE 0.08 48.60 us 18.00 us 174.00 us 666 FINODELK 0.09 135.67 us 37.00 us 621.00 us 273 STAT 0.12 163.04 us 88.00 us 322.00 us 308 XATTROP 0.19 116.95 us 67.00 us 266.00 us 666 FXATTROP 0.25 578.89 us 120.00 us 1398.00 us 179 CREATE 0.26 516.23 us 115.00 us 18482.00 us 211 UNLINK 0.32 83.35 us 43.00 us 245.00 us 1608 WRITE 0.32 244.34 us 48.00 us 911.00 us 558 SETXATTR 0.62 55.35 us 15.00 us 5793.00 us 4696 INODELK 0.64 383.17 us 68.00 us 1447.00 us 702 RMDIR 0.72 64.63 us 14.00 us 2197.00 us 4704 ENTRYLK 0.88 660.31 us 141.00 us 1775.00 us 558 MKDIR 1.28 189.48 us 3.00 us 4096.00 us 2838 OPENDIR 22.30 4790.40 us 27.00 us 26629.00 us 1958 READDIRP 71.69 573.07 us 30.00 us 3543.00 us 52629 LOOKUP Duration: 358518 seconds Data Read: 0 bytes Data Written: 37290956800 bytes Interval 3 Stats: Block Size: 8192b+ No. of Reads: 0 No. of Writes: 130 %-latency Avg-latency Min-Latency Max-Latency No. of calls Fop --------- ----------- ----------- ----------- ------------ ---- 0.00 0.00 us 0.00 us 0.00 us 26 RELEASE 0.00 118.33 us 109.00 us 125.00 us 3 STAT 0.01 59.34 us 27.00 us 154.00 us 41 STATFS 0.02 55.13 us 19.00 us 119.00 us 52 FINODELK 0.02 55.81 us 19.00 us 152.00 us 52 FLUSH 0.04 134.17 us 71.00 us 236.00 us 52 FXATTROP 0.06 54.18 us 19.00 us 233.00 us 190 ENTRYLK 0.07 94.39 us 46.00 us 213.00 us 130 WRITE 0.08 61.41 us 22.00 us 331.00 us 234 INODELK 0.14 971.50 us 803.00 us 1398.00 us 26 CREATE 0.15 390.77 us 289.00 us 756.00 us 69 SETXATTR 0.43 1147.78 us 931.00 us 1651.00 us 69 MKDIR 99.00 636.09 us 79.00 us 2806.00 us 28536 LOOKUP Duration: 56 seconds Data Read: 0 bytes Data Written: 1331200 bytes Brick: dhcp43-192.lab.eng.blr.redhat.com:/rhs/brick2/guess ---------------------------------------------------------- Cumulative Stats: Block Size: 8192b+ 16384b+ 32768b+ No. of Reads: 0 0 57 No. of Writes: 168554 724 71 Block Size: 131072b+ No. of Reads: 0 No. of Writes: 250800 %-latency Avg-latency Min-Latency Max-Latency No. of calls Fop --------- ----------- ----------- ----------- ------------ ---- 0.00 0.00 us 0.00 us 0.00 us 137446 FORGET 0.00 0.00 us 0.00 us 0.00 us 36143 RELEASE 0.00 0.00 us 0.00 us 0.00 us 456805 RELEASEDIR 0.00 89.25 us 56.00 us 159.00 us 4 GETXATTR 0.01 1234.25 us 1124.00 us 1335.00 us 4 READDIR 0.01 69.27 us 24.00 us 164.00 us 74 STATFS 0.04 96.12 us 52.00 us 871.00 us 170 REMOVEXATTR 0.04 100.70 us 52.00 us 243.00 us 170 OPEN 0.04 113.22 us 64.00 us 196.00 us 170 FSTAT 0.07 52.72 us 16.00 us 202.00 us 550 FLUSH 0.07 178.20 us 105.00 us 401.00 us 170 TRUNCATE 0.08 49.58 us 19.00 us 674.00 us 720 FINODELK 0.09 147.17 us 31.00 us 637.00 us 273 STAT 0.13 168.88 us 83.00 us 509.00 us 340 XATTROP 0.20 119.63 us 67.00 us 237.00 us 720 FXATTROP 0.24 537.25 us 119.00 us 1504.00 us 190 CREATE 0.26 455.61 us 121.00 us 1155.00 us 246 UNLINK 0.32 243.35 us 49.00 us 933.00 us 558 SETXATTR 0.35 85.65 us 41.00 us 683.00 us 1738 WRITE 0.65 394.90 us 78.00 us 1517.00 us 702 RMDIR 0.66 58.71 us 18.00 us 5428.00 us 4832 INODELK 0.76 68.20 us 16.00 us 3848.00 us 4796 ENTRYLK 1.14 870.43 us 146.00 us 125918.00 us 558 MKDIR 1.33 200.14 us 2.00 us 3655.00 us 2838 OPENDIR 22.15 4676.92 us 28.00 us 25278.00 us 2026 READDIRP 71.35 579.26 us 55.00 us 3111.00 us 52689 LOOKUP Duration: 358518 seconds Data Read: 2918400 bytes Data Written: 34617395200 bytes Interval 3 Stats: Block Size: 8192b+ 16384b+ No. of Reads: 0 0 No. of Writes: 98 1 %-latency Avg-latency Min-Latency Max-Latency No. of calls Fop --------- ----------- ----------- ----------- ------------ ---- 0.00 0.00 us 0.00 us 0.00 us 20 RELEASE 0.00 135.67 us 113.00 us 157.00 us 3 STAT 0.01 45.67 us 18.00 us 80.00 us 40 FLUSH 0.01 51.42 us 20.00 us 120.00 us 40 FINODELK 0.02 69.85 us 27.00 us 131.00 us 41 STATFS 0.03 128.12 us 74.00 us 237.00 us 40 FXATTROP 0.05 92.72 us 43.00 us 170.00 us 99 WRITE 0.05 54.63 us 19.00 us 158.00 us 178 ENTRYLK 0.08 65.92 us 21.00 us 317.00 us 230 INODELK 0.11 987.65 us 821.00 us 1504.00 us 20 CREATE 0.15 399.80 us 292.00 us 855.00 us 69 SETXATTR 0.43 1147.51 us 895.00 us 1888.00 us 69 MKDIR 99.06 635.35 us 79.00 us 2613.00 us 28530 LOOKUP Duration: 56 seconds Data Read: 0 bytes Data Written: 1024000 bytes Brick: dhcp43-192.lab.eng.blr.redhat.com:/rhs/brick1/guess ---------------------------------------------------------- Cumulative Stats: Block Size: 1b+ 4b+ 8b+ No. of Reads: 0 0 0 No. of Writes: 2 490 1 Block Size: 16b+ 32b+ 64b+ No. of Reads: 0 0 0 No. of Writes: 1599 2068 1 Block Size: 8192b+ 16384b+ 32768b+ No. of Reads: 0 0 101 No. of Writes: 2616 50 54 Block Size: 131072b+ No. of Reads: 879 No. of Writes: 0 %-latency Avg-latency Min-Latency Max-Latency No. of calls Fop --------- ----------- ----------- ----------- ------------ ---- 0.00 0.00 us 0.00 us 0.00 us 945 FORGET 0.00 0.00 us 0.00 us 0.00 us 1091 RELEASE 0.00 0.00 us 0.00 us 0.00 us 3073 RELEASEDIR 0.00 65.50 us 34.00 us 94.00 us 4 GETXATTR 0.01 71.91 us 30.00 us 145.00 us 74 STATFS 0.01 1381.50 us 829.00 us 1926.00 us 4 READDIR 0.03 94.30 us 54.00 us 180.00 us 165 REMOVEXATTR 0.04 124.93 us 65.00 us 2508.00 us 165 FSTAT 0.07 185.30 us 111.00 us 1031.00 us 165 TRUNCATE 0.09 146.57 us 31.00 us 601.00 us 273 STAT 0.11 104.01 us 46.00 us 688.00 us 501 OPEN 0.12 169.95 us 88.00 us 381.00 us 330 XATTROP 0.22 534.54 us 153.00 us 1090.00 us 189 CREATE 0.27 514.28 us 127.00 us 4955.00 us 246 UNLINK 0.31 258.21 us 75.00 us 699.00 us 558 SETXATTR 0.44 54.05 us 19.00 us 2180.00 us 3778 FINODELK 0.55 49.62 us 14.00 us 767.00 us 5067 FLUSH 0.59 387.96 us 76.00 us 1237.00 us 702 RMDIR 0.66 64.51 us 18.00 us 2374.00 us 4695 INODELK 0.78 75.17 us 17.00 us 1321.00 us 4794 ENTRYLK 0.85 81.34 us 33.00 us 319.00 us 4789 WRITE 1.05 127.35 us 64.00 us 506.00 us 3780 FXATTROP 1.09 901.69 us 171.00 us 129800.00 us 558 MKDIR 1.35 218.71 us 2.00 us 4637.00 us 2838 OPENDIR 21.34 4914.06 us 29.00 us 21935.00 us 1999 READDIRP 70.00 611.93 us 20.00 us 3858.00 us 52646 LOOKUP Duration: 9580 seconds Data Read: 120932505 bytes Data Written: 30741776 bytes Interval 3 Stats: Block Size: 16b+ 32b+ 8192b+ No. of Reads: 0 0 0 No. of Writes: 69 69 115 %-latency Avg-latency Min-Latency Max-Latency No. of calls Fop --------- ----------- ----------- ----------- ------------ ---- 0.00 0.00 us 0.00 us 0.00 us 160 RELEASE 0.00 131.00 us 121.00 us 148.00 us 3 STAT 0.01 69.22 us 32.00 us 142.00 us 41 STATFS 0.05 54.27 us 19.00 us 210.00 us 184 FINODELK 0.06 64.51 us 20.00 us 240.00 us 184 ENTRYLK 0.07 95.32 us 46.00 us 688.00 us 137 OPEN 0.11 74.15 us 22.00 us 459.00 us 296 INODELK 0.11 964.83 us 853.00 us 1090.00 us 23 CREATE 0.11 88.30 us 36.00 us 207.00 us 253 WRITE 0.13 140.49 us 69.00 us 325.00 us 184 FXATTROP 0.13 56.97 us 14.00 us 643.00 us 459 FLUSH 0.15 416.45 us 313.00 us 617.00 us 69 SETXATTR 1.06 3033.91 us 892.00 us 129800.00 us 69 MKDIR 98.00 675.30 us 82.00 us 2505.00 us 28601 LOOKUP Duration: 56 seconds Data Read: 0 bytes Data Written: 1183255 bytes [root@dhcp43-157 ~]#
The same test was reproduced in 1) Plain distribute volume 2) Single brick volume
**correction** it was not reproducible in Single brick volume
We have noticed that backend brick performance matters (and amplifies the performance issues) a lot for how gluster performs. Considering in this test, we are ending up creating fragments in backend filesystem, I see that this may be expected behavior. I recommend running the tests with latest glusterfs-6.x releases, and checking what is the behavior. If not happening, close it as WORKSFORME.
Based on profile information, the problem seems related to the number of lookups processed by bricks (they take 99% of the time). Kernel sends a lookup for each path component before every operation. Given that this tests creates a nested directory structure, the number of lookups grows linearly as the depth is greater. The total number of lookups is quadratic on the depth of the directory. I see two possible issues here: 1. md-stat should prevent most of the lookup requests to reach the bricks. 2. There are many more lookups than expected (even considering a quadratic growth). I'll run a test with latest version and see if any of the previous problems persist.
I've just repeated the test with version 7.0 and I've got much better performance. I still see a small slowdown when on depth 300, but it's less than a second. The number of lookups have been drastrically reduced. With depth 300, I only see 3710 lookups. So it seems that caching is doing its job. Based on these results I'll close the bug.