Bug 812924 - poor write performance using gluster-plugin
poor write performance using gluster-plugin
Status: CLOSED UPSTREAM
Product: GlusterFS
Classification: Community
Component: gluster-hadoop (Show other bugs)
mainline
Unspecified Linux
medium Severity low
: ---
: ---
Assigned To: Jay Vyas
hcfs-gluster-bugs
: Reopened, Triaged
Depends On:
Blocks: 1057253
  Show dependency treegraph
 
Reported: 2012-04-16 11:09 EDT by Tim Wilkinson
Modified: 2014-05-13 10:09 EDT (History)
10 users (show)

See Also:
Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
Environment:
Last Closed: 2014-05-13 10:09:06 EDT
Type: Bug
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: ---
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---


Attachments (Terms of Use)

  None (edit)
Description Tim Wilkinson 2012-04-16 11:09:48 EDT
Description of problem:
----------------------
We are using 'grep' to read and teragen to write to a gluster volume using the gluster-plugin. Throughput shows reads performing as expected while writes are moving much (100x) slower. 



Component Version-Release:
-------------------------
kernel 2.6.32-131.0.15.el6.x86_64
glusterfs-fuse-3.3.0qa32.1 x86_64
glusterfs-server-3.3.0qa32.1 x86_64
glusterfs-3.3.0qa32.1 x86_64
glusterfs-geo-replication-3.3.0qa32.1 x86_64
glusterfs-rdma-3.3.0qa32.1 x86_64



How reproducible:
----------------
Consistent



Steps to Reproduce:
------------------
1. Configure hadoop environment with gluster-plugin. Create gluster
   volume using XFS underlying storage.
2. Use hadoop to copy in fixed size file for grep.
3. Use hadoop grep to measure read throughput
   (filesize[MB] / runtime[sec])
4. Use teragen to generate a fixed amount of terasort data to measure
   write throughput.



Actual results:
--------------
While reads perform @40-50 MB/s, writes hover in the area of 4-7 MB/s.



Expected results:
----------------
Writes more comparable to the read performance.



Additional info:
---------------
We've tested distributed gluster volumes as well as with replication at 2 with no difference in results.

strace confirms the writes are tiny. 

top shows a glusterfsd thread maxed out in CPU usage.
 
straced reads (using PID of maxed glusterfsd thread):
> [root@perf64 hadoop]# strace -c -p 28250
> % time     seconds  usecs/call     calls    errors syscall
> ------ ----------- ----------- --------- --------- ----------------
>  83.53    0.288506          25     11612           readv
>  11.33    0.039145           3     14575           writev
>   3.17    0.010965           1     11586           read
>   0.88    0.003046           0     11586           munmap
>   0.40    0.001387           0     11586           open
>   0.21    0.000728           0     11586           close
>   0.21    0.000719           0     11586           fstat
>   0.14    0.000497           0     11586           mmap
>   0.11    0.000379           0      1026       139 futex
> ------ ----------- ----------- --------- --------- ----------------
> 100.00    0.345372                 96729       139 total



> [root@perf64 hadoop]# strace -ttT -p 28250 -o strace.out
>   ...
> 10:19:02.861685 open("/proc/25343/status", O_RDONLY) = 4 <0.000054>
> 10:19:02.861768 fstat(4, {st_mode=S_IFREG|0444, st_size=0, ...}) = 0 <0.000024>
> 10:19:02.861862 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fcd41dfe000 <0.000053>
> 10:19:02.861958 read(4, "Name:\tjava\nState:\tS (sleeping)\nT"..., 1024) = 902 <0.000072>
> 10:19:02.862056 close(4)                = 0 <0.000009>
> 10:19:02.862083 munmap(0x7fcd41dfe000, 4096) = 0 <0.000084>
> 10:19:02.862208 writev(7, [{"\200\0\0\350", 4}, {"\2\5n\210\0\0\0\0\0\0\0\2\0\23\320\5\0\0\1J\0\0\0\33\0\0\0\6\0\0\0008"..., 96}, {"\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\1"..., 136}], 3) = 236 <0.000016>
> 10:19:02.862267 writev(9, [{"\200\0\0\350", 4}, {"\0T?\306\0\0\0\0\0\0\0\2\0\23\320\5\0\0\1J\0\0\0\33\0\0\0\6\0\0\0008"..., 96}, {"\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\1"..., 136}], 3) = 236 <0.000011>
> 10:19:02.862314 readv(5, [{"3\0\0\0\1\0\0\0\16\334R\5\0\0\0\0P\214&I\315\177\0\0\0\0\0\0\0\0\0\0"..., 80}, {"special pinto beans. furiously r"..., 131072}], 2) = 51 <0.000493>
>    ...




straced writes:
> % time     seconds  usecs/call     calls    errors syscall
> ------ ----------- ----------- --------- --------- ----------------
>  38.54    0.067876           1    131318           read
>  29.07    0.051198           0    393836           writev
>  11.52    0.020283           0    131318           munmap
>   7.90    0.013918           0    262635           readv
>   5.00    0.008797           0    131317           open
>   3.03    0.005329           0    131318           mmap
>   2.95    0.005200           0    131318           close
>   1.80    0.003173           0    131318           fstat
>   0.19    0.000334           0     11490      2981 futex
> ------ ----------- ----------- --------- --------- ----------------
> 100.00    0.176108               1455868      2981 total
> 
> 
>   ...
> 09:56:57.668238 open("/proc/18812/status", O_RDONLY) = 4 <0.000010>
> 09:56:57.668268 fstat(4, {st_mode=S_IFREG|0444, st_size=0, ...}) = 0 <0.000006>
> 09:56:57.668303 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fcd501bb000 <0.000008>
> 09:56:57.668329 read(4, "Name:\tjava\nState:\tS (sleeping)\nT"..., 1024) = 904 <0.000022>
> 09:56:57.668373 close(4)                = 0 <0.000007>
> 09:56:57.668398 munmap(0x7fcd501bb000, 4096) = 0 <0.000011>
> 09:56:57.668437 writev(5, [{"\30\0\0\0\0\0\0\0\270\210\225\4\0\0\0\0", 16}, {"\2\0\0\0\0\0\0\0", 8}], 2) = 24 <0.000030>
> 09:56:57.668508 writev(7, [{"\200\0\0\216", 4}, {"\1\324\3165\0\0\0\0\0\0\0\2\0\23\320\5\0\0\1J\0\0\0\r\0\0\0\6\0\0\0008"..., 96}, {"\220c\252\267\243+E>\275\204\246\313\274\277t+\0\0\0\0\0\0\0\1\0\0\0\0\0\t\276\352"..., 44}, {"\r\n", 2}], 4) = 146 <0.000016>
> 09:56:57.668567 readv(5, [{"D\0\0\0\26\0\0\0\271\210\225\4\0\0\0\0\0\212&I\315\177\0\0\0\0\0\0\0\0\0\0"..., 80}, {"|j?^=gw2w`OOOOOOOOOOPPPPPPPPPPQQ"..., 131072}], 2) = 68 <0.000008>
> 09:56:57.668606 writev(5, [{"\20\0\0\0\303\377\377\377\271\210\225\4\0\0\0\0", 16}], 1) = 16 <0.000008>
> 09:56:57.668638 readv(5, [{"D\0\0\0\26\0\0\0\272\210\225\4\0\0\0\0\364\205&I\315\177\0\0\0\0\0\0\0\0\0\0"..., 80}, {"|j?^=gw2w`OOOOOOOOOOPPPPPPPPPPQQ"..., 131072}], 2) = 68 <0.000007>
> 09:56:57.668676 writev(5, [{"\20\0\0\0\303\377\377\377\272\210\225\4\0\0\0\0", 16}], 1) = 16 <0.000009>
> 09:56:57.668710 readv(5, [{"\250\0\0\0\20\0\0\0\273\210\225\4\0\0\0\0\0\212&I\315\177\0\0\0\0\0\0\0\0\0\0"..., 80}, {"    516145WWWWWWWWWWXXXXXXXXXXYY"..., 131072}], 2) = 168 <0.000008>
>   ...
Comment 1 Tim Wilkinson 2012-04-17 10:07:11 EDT
Note that changing the gluster volume from replication 2 to 'distributed' had no impact on the throughput.
Comment 3 RHEL Product and Program Management 2012-07-20 02:56:03 EDT
Development Management has reviewed and declined this request.
You may appeal this decision by reopening this request.
Comment 5 Jay Vyas 2013-02-15 15:41:48 EST
I've just finished running strace during a unit test.  

I've run this in virtualbox/fedora running in a VM with a mapreduce job running in localmode against glusterfs.  I DO NOT see any calls to "writev", but rather, to "write".  

To investigate further, I found this http://linux.die.net/man/2/writev, and it seems the writev call is different then the "write" system call.  

Maybe ben or shak's team can comment on what this might mean....


   24111 0.000035 write(49, "ass=\"source\">yulisdayariel<br></"..., 8192) = 8192
    24111 0.000033 write(49, "le) {\n return; // Silently exit "..., 8192) = 8192
    24111 0.000033 write(49, "sh('/trunk/wepattack1.java');\n c"..., 8192) = 8192
    24111 0.000033 write(49, " type=\"text/javascript\" src=\"htt"..., 8192) = 8192
    24111 0.000032 write(49, " the Hippocrene (\"horse spring\")"..., 8192) = 8192
    24111 0.000033 write(49, "ld Capulet, and Montague,\nHave t"..., 8192) = 8192
    24111 0.000041 write(49, " in reckoning none,\nCome, go wit"..., 8192) = 8192
    24111 0.000069 write(49, "street.\n\t[Enter ROMEO, MERCUTIO,"..., 8192 <unfinished ...>
    24111 0.000030 <... write resumed> ) = 8192
    24111 0.000115 write(49, "our foe,\nA villain that is hithe"..., 8192) = 8192
    24111 0.006770 write(49, "nger be a Capulet.\nROMEO \t[Aside"..., 8192) = 8192
    24111 0.000073 write(49, "e, being misapplied;\nAnd vice so"..., 8192) = 8192
    24111 0.000088 write(49, "dy hand of the\ndial is now upon "..., 8192) = 8192
    24111 0.000055 write(49, "AURENCE \tSo smile the heavens up"..., 8192 <unfinished ...>
    24111 0.000036 <... write resumed> ) = 8192
    24111 0.000027 write(49, "ortune's fool!\nBENVOLIO \tWhy dos"..., 8192 <unfinished ...>
    24111 0.003526 <... write resumed> ) = 8192
    24111 0.000058 write(49, "h other griefs,\nWhy follow'd not"..., 8192) = 8192
    24111 0.006771 write(49, "ince, and call thee back\nWith tw"..., 8192) = 8192
    24111 0.000066 write(49, "e a joyful bride.\nI wonder at th"..., 8192) = 8192
    24111 0.003868 write(49, " prevent it:\nIf, in thy wisdom, "..., 8192) = 8192
    24111 0.000059 write(49, "'s point: stay, Tybalt, stay!\nRo"..., 8192 <unfinished ...>
    24111 0.000034 <... write resumed> ) = 8192
    24111 0.000061 write(49, "r the\nmourners, and stay dinner."..., 8192) = 8192
    24111 0.000099 write(49, "st die.\nROMEO \tI must indeed; an"..., 8192) = 8192
    24111 0.000058 write(49, "nd, both to impeach and purge\nMy"..., 8192) = 8192
    24111 0.000068 write(49, "\nA segmented HTML version of thi"..., 8192) = 8192
    24111 0.000061 write(49, "TAGUE \tO, where is Romeo? saw yo"..., 8192) = 8192
    24111 0.000104 write(49, "ormented and--God-den, good fell"..., 8192) = 8192
    24111 0.000052 write(49, " too rough,\nToo rude, too boiste"..., 8192) = 8192
    24111 0.000082 write(49, "t, cheerly, my hearts!\nTYBALT \tP"..., 8192) = 8192
    24111 0.006833 write(49, "high and hard to climb,\nAnd the "..., 8192) = 8192
    24111 0.000052 write(49, "y good son: but where hast thou "..., 8192) = 8192
    24111 0.000033 write(49, "NVOLIO]\nNurse \tMarry, farewell! "..., 8192) = 8192
    24111 0.000033 write(49, ", and let rich music's tongue\nUn"..., 8192) = 8192
    24111 0.000033 write(49, "io's breast,\nWho all as hot, tur"..., 8192) = 8192
    24111 0.000032 write(49, "\nScene III Friar Laurence's cell"..., 8192) = 8192
    24111 0.000032 write(49, "ove our daughter:\nLook you, she "..., 8192) = 8192
    24111 0.000033 write(49, "? doth she not count her blest,\n"..., 8192) = 8192
    24111 0.000033 write(49, "lk in thievish ways; or bid me l"..., 8192) = 8192
    24111 0.000033 write(49, "ead, sir, that will find out log"..., 8192) = 8192
    24111 0.000042 write(49, "et me ink and paper,\nAnd hire po"..., 8192) = 8192
    24111 0.000052 write(49, "or here lies Juliet, and her bea"..., 8192 <unfinished ...>
    24111 0.000279 <... write resumed> ) = 8192
    24111 0.000087 write(49, "ixed hour of her waking,\nCame I "..., 8192) = 8192
    24111 0.016648 write(49, "oung nobleman, kinsman to the pr"..., 8192) = 8192
    24111 0.000101 write(49, " nor can learn of him.\nBENVOLIO "..., 8192) = 8192
    24111 0.006838 write(49, " the admired beauties of Verona:"..., 8192) = 8192
    24111 0.000053 write(49, "\nROMEO \tWell, what was yours?\nME"..., 8192 <unfinished ...>
    24111 0.000022 <... write resumed> ) = 8192
    24111 0.000090 write(49, "What is her mother?\nNurse \tMarry"..., 8192) = 8192
    24111 0.000118 write(49, "at I have spoke: but farewell co"..., 8192) = 8192
    24111 0.000078 write(49, "groans ring yet in my ancient ea"..., 8192) = 8192
    24111 0.000057 write(49, "it were an ill thing to be offer"..., 8192 <unfinished ...>
    24111 0.006649 <... write resumed> ) = 8192
    24111 0.000049 write(49, "\nBENVOLIO \tAnd what to?\nMERCUTIO"..., 8192) = 8192
    24111 0.000047 write(49, "alt.\nPRINCE \tAnd for that offenc"..., 8192) = 8192
    24111 0.000069 write(49, "fault our law calls death; but t"..., 8192) = 8192
    24111 0.000110 write(49, "rsday?\nPARIS \tMy lord, I would t"..., 8192) = 8192
    24111 0.000046 write(49, "ss her!\nYou are to blame, my lor"..., 8192) = 8192
    24111 0.000133 write(49, "rty hours,\nAnd then awake as fro"..., 8192) = 8192
    24111 0.000068 write(49, "as, alas! Help, help! my lady's "..., 8192) = 8192
    24111 0.000057 write(49, "f wretch would sell it him.'\nO, "..., 8192) = 8192
    24111 0.003624 write(49, "d flesh. Eyes, look your last!\nA"..., 8192) = 8192
    24111 0.000093 write(49, "e came with flowers to strew his"..., 8192) = 8192
    24111 0.000047 write(49, "d makes civil hands unclean.\nFro"..., 8192) = 8192
    24111 0.000065 write(49, " and rough in proof!\nROMEO \tAlas"..., 8192 <unfinished ...>
    24111 0.000225 <... write resumed> ) = 8192
    24111 0.007662 write(49, "your will?\nLADY CAPULET \tThis is"..., 8192) = 8192
    24111 0.000083 write(49, "s o'er a courtier's nose,\nAnd th"..., 8192) = 8192
    24111 0.000045 write(49, "ly seen unknown, and known too l"..., 8192) = 8192
    24111 0.000056 write(49, "eve thee.\nROMEO \tIf my heart's d"..., 8192) = 8192
    24111 0.000055 write(49, " \tAh, that same pale hard-hearte"..., 8192) = 8192
    24111 0.000046 write(49, "nt thee, my man's as true as ste"..., 8192) = 8192
    24111 0.000054 write(49, "ERCUTIO \tAnd but one word with o"..., 8192) = 8192
    24111 0.000046 write(49, "ck mantle; till strange love, gr"..., 8192) = 8192
    24111 0.000046 write(49, " hear me but speak a word.\nROMEO"..., 8192) = 8192
    24111 0.000046 write(49, "wilt have it so.\nI'll say yon gr"..., 8192) = 8192
    24111 0.000033 write(49, "thee,\nNor what is mine shall nev"..., 8192) = 8192
    24111 0.000032 write(49, "ir; for I'll try if they\ncan lic"..., 8192) = 8192
    24111 0.000032 write(49, "he lies,\nFlower as she was, defl"..., 8192) = 8192
    24111 0.000032 write(49, "f; and, if you had the strength\n"..., 8192) = 8192
    24111 0.000039 write(49, "ath,\nIf I did stay to look on hi"..., 8192) = 8192
    24111 0.000032 write(49, "ings;\nSome shall be pardon'd, an"..., 8192) = 8192
    24111 0.000031 write(49, "GORY \tThat shows thee a weak sla"..., 8192) = 8192
    24111 0.000031 write(49, "f you leave me so, you do me wro"..., 8192) = 8192
    24111 0.000031 write(49, " it tetchy and fall out with the"..., 8192) = 8192
    24111 0.000031 write(49, "This wind, you talk of, blows us"..., 8192) = 8192
    24111 0.000031 write(49, " and MERCUTIO]\nBENVOLIO \tRomeo! "..., 8192) = 8192
    24111 0.000031 write(49, "eing in night, all this is but a"..., 8192) = 8192
    24111 0.000031 write(49, "u,\na very good blade! a very tal"..., 8192) = 8192
    24111 0.000031 write(49, "s,\nDriving back shadows over lou"..., 8192) = 8192
    24111 0.000031 write(49, "in am I none;\nTherefore farewell"..., 8192) = 8192
    24111 0.000031 write(49, "n heaven be so envious?\nNurse \tR"..., 8192) = 8192
    24111 0.000031 write(49, "y and by! God's will,\nWhat simpl"..., 8192) = 8192
    24111 0.000041 write(49, "om thee every day in the hour,\nF"..., 8192) = 8192
    24111 0.000031 write(49, " so quick, so fair an eye\nAs Par"..., 8192) = 8192
    24111 0.000035 write(49, "say, and fetch him hither.\nNow, "..., 8192) = 8192
    24111 0.000034 write(49, "URENCE \tPeace, ho, for shame! co"..., 8192) = 8192
    24111 0.000033 write(49, "hey of infection.\nFRIAR LAURENCE"..., 8192) = 8192
    24111 0.000059 write(49, "er stay.\nJULIET \tGo, get thee he"..., 8192) = 8192
    24111 0.000051 write(49, "ed him up in the sky.\n\nHypothese"..., 8192) = 8192
    24111 0.000067 write(49, "y thumb at them;\nwhich is a disg"..., 8192 <unfinished ...>
    24111 0.000038 <... write resumed> ) = 8192
    24111 0.000051 write(49, "air,\nTo merit bliss by making me"..., 8192) = 8192
    24111 0.000105 write(49, "too, I pray thee, nurse, say I.\n"..., 8192) = 8192
    24111 0.000088 write(49, "brisk awhile, and the longer liv"..., 8192) = 8192
    24111 0.000088 write(49, "conjure only but to raise up him"..., 8192) = 8192
    24111 0.000087 write(49, " \tIt is my soul that calls upon "..., 8192) = 8192
    24111 0.000063 write(49, "rt'sy.\nMERCUTIO \tThou hast most "..., 8192) = 8192
    24111 0.000047 write(49, "breath\nTo say to me that thou ar"..., 8192) = 8192
    24111 0.000047 write(49, "and flies\nwith his followers]\nME"..., 8192) = 8192
    24111 0.000062 write(49, "en, dreadful trumpet, sound the "..., 8192) = 8192
    24111 0.000055 write(49, ",\nAnd then down falls again.\nROM"..., 8192) = 8192
    24111 0.000056 write(49, "t, wilt thou wash him from his g"..., 8192) = 8192
    24111 0.000056 write(49, "o not know the lady's mind:\nUnev"..., 8192) = 8192
    24111 0.000064 write(49, "ho? need you my help?\nJULIET \tNo"..., 8192) = 8192
    24111 0.000055 write(49, "th him;\nAnd go, Sir Paris; every"..., 8192) = 8192
    24111 0.000033 write(49, " in the churchyard; yet I will a"..., 8192) = 8192
    24111 0.000054 write(49, "ALTHASAR]\nSecond Watchman \tHere'"..., 8192) = 8192
    24111 0.006925 write(49, "Popular culture\n 8 See also\n "..., 8192) = 8192
    24111 0.000060 write(49, "\t[Enter, several of both houses,"..., 8192) = 8192
    24111 0.000056 write(49, " not seen the change of fourteen"..., 8192 <unfinished ...>
    24111 0.000175 <... write resumed> ) = 8192
    24111 0.000111 write(49, "ent\nAnd what obscured in this fa"..., 8192) = 8192
    24111 0.003685 write(49, "nd Capulet \t'Tis more, 'tis more"..., 8192) = 8192
    24111 0.000067 write(49, " says nothing: what of that?\nHer"..., 8192) = 8192
    24111 0.000034 write(49, "\nHis help to crave, and my dear "..., 8192) = 8192
    24111 0.000033 write(49, "at word 'broad;' which added\nto "..., 8192) = 8192
    24111 0.000033 write(49, "dsome, and, I\nwarrant, a virtuou"..., 8192) = 8192
    24111 0.000033 write(49, "t,\nThy beauty hath made me effem"..., 8192) = 8192
    24111 0.000033 write(49, "onarch of the universal earth.\nO"..., 8192) = 8192
    24111 0.000033 write(49, "ollow perjury,\nKilling that love"..., 8192) = 8192
    24111 0.000033 write(49, "ll be satisfied\nWith Romeo, till"..., 8192) = 8192
    24111 0.000032 write(49, "abused with tears.\nJULIET \tThe t"..., 8192) = 8192
    24111 0.000033 write(49, " not, then, be stifled in the va"..., 8192) = 8192
    24111 0.000033 write(49, "?\nFirst Musician \tAn you re us a"..., 8192) = 8192
    24111 0.000034 write(49, "e joint by joint\nAnd strew this "..., 8192) = 8192
    24111 0.000033 write(49, "er hath mista'en--for, lo, his h"..., 8192) = 8192
    24111 0.000034 write(49, "elling with rapture at the song "..., 8192) = 8192
    24111 0.000037 read(48, "ns out\nWhose names are written t"..., 4096) = 4096
    24111 0.000033 write(49, "seeming ornaments,\nTo wield old "..., 8192) = 8192
    24111 0.000033 write(49, "ns out\nWhose names are written t"..., 8192) = 8192
    24111 0.000034 write(49, "poke for our excuse?\nOr shall we"..., 8192) = 8192
    24111 0.000034 write(49, " that villain Romeo.\nCAPULET \tCo"..., 8192) = 8192
    24111 0.000033 write(49, " thyself, though not a Montague."..., 8192) = 8192
    24111 0.000034 write(49, "medicine power:\nFor this, being "..., 8192) = 8192
    24111 0.000033 write(49, "made for himself to\nmar.\nNurse \t"..., 8192) = 8192
    24111 0.000033 write(49, "w can,\nIt cannot countervail the"..., 8192) = 8192
    24111 0.000042 write(49, "io?\nTybalt, that murderer, which"..., 8192) = 8192
    24111 0.000037 write(49, " might have moved?\nBut with a re"..., 8192) = 8192
    24111 0.000033 write(49, "end me to thy lady;\nAnd bid her "..., 8192) = 8192
    24111 0.000033 write(49, "d father, madam,\nI will not marr"..., 8192) = 8192
    24111 0.000032 write(49, "ently.\nGod join'd my heart and R"..., 8192) = 8192
    24111 0.000032 write(49, "in Capulet's house.\n\t[Enter LADY"..., 8192) = 8192
    24111 0.000032 write(49, "h of sleep,\nMy dreams presage so"..., 8192) = 8192
    24111 0.000033 write(49, "hink upon these gone;\nLet them a"..., 8192) = 8192
    24111 0.000033 write(49, "ENCE \tI will be brief, for my sh"..., 8192) = 8192
    24111 0.000033 write(49, " Scene I Verona. A public p"..., 8192) = 8192
    24111 0.000034 write(49, "'d sun\nPeer'd forth the golden w"..., 8192) = 8192
    24111 0.000034 write(49, "Servant \tPerhaps you have learne"..., 8192) = 8192
    24111 0.000033 write(49, " for pricking, and you beat love"..., 8192) = 8192
    24111 0.000034 write(49, "ill withdraw: but this intrusion"..., 8192) = 8192
    24111 0.000033 write(49, "t wings did I o'er-perch these w"..., 8192) = 8192
    24111 0.000033 write(49, "Where on a sudden one hath wound"..., 8192) = 8192
    24111 0.000042 write(49, "nurse, that loves to hear himsel"..., 8192) = 8192
    24111 0.000034 write(49, "re rich in matter than in words,"..., 8192) = 8192
    24111 0.000033 write(49, " the other sends\nIt back to Tyba"..., 8192) = 8192
    24111 0.000034 write(49, "on is enamour'd of thy parts,\nAn"..., 8192) = 8192
    24111 0.000034 write(49, "ot come down to-night:\nI promise"..., 8192) = 8192
    24111 0.000033 write(49, "oud, you have; but thankful, tha"..., 8192) = 8192
    24111 0.000033 write(49, "ver'd quite with dead men's ratt"..., 8192) = 8192
    24111 0.000033 write(49, "ha!\nThou shalt be logger-head. G"..., 8192) = 8192
    24111 0.000034 write(49, "ale and wild, and do import\nSome"..., 8192) = 8192
    24111 0.000033 write(49, "'d.\n\t[Laying PARIS in the tomb]\n"..., 8192) = 8192
    24111 0.000034 write(49, "ould send to Romeo:\nBut when I c"..., 8192) = 8192
    24111 0.000033 write(49, " to Capulet. (Second Capulet:)\nR"..., 8192) = 8192
    24111 0.000033 write(49, " own affections' counsellor,\nIs "..., 8192) = 8192
    24111 0.000032 write(49, "ke thee think thy swan a crow.\nR"..., 8192) = 8192
    24111 0.000033 write(49, ", then, I see Queen Mab hath bee"..., 8192) = 8192
    24111 0.000033 write(49, "her daughter, that you talk'd wi"..., 8192) = 8192
    24111 0.000032 write(49, "'st,\nThou mayst prove false; at "..., 8192) = 8192
    24111 0.000032 write(49, "hou wast thyself and these woes "..., 8192) = 8192
    24111 0.000035 write(49, "protest unto thee--\nNurse \tGood "..., 8192) = 8192
    24111 0.000032 write(49, ",\nthou wilt quarrel with a man t"..., 8192) = 8192
    24111 0.000032 write(49, "r rude brawls doth lie a-bleedin"..., 8192) = 8192
    24111 0.000033 write(49, "ishment:\nThis is dear mercy, and"..., 8192) = 8192
    24111 0.000034 write(49, "ere you go to bed,\nPrepare her, "..., 8192 <unfinished ...>
    24111 0.000095 <... write resumed> ) = 8192
    24111 0.000033 write(49, "your gossips, go.\nNurse \tI speak"..., 8192) = 8192
    24111 0.000032 write(49, " art thou dead:\nThen, as the man"..., 8192) = 8192
    24111 0.000033 write(49, "LET]\nLADY CAPULET \tWhat noise is"..., 8192) = 8192
    24111 0.000032 write(49, "this should be the house.\nBeing "..., 8192) = 8192
    24111 0.000033 write(49, "eless bargain to engrossing deat"..., 8192) = 8192
    24111 0.000033 write(49, " by and by my master drew on him"..., 8192) = 8192
    24111 0.000032 write(49, "dventured piteous overthrows\nDo "..., 8192) = 8192
    24111 0.000032 write(49, "ll we dine? O me! What fray was "..., 8192) = 8192
    24111 0.000033 write(49, "ember'd me, thou's hear our coun"..., 8192) = 8192
    24111 0.000033 write(49, "on's nose as a' lies asleep,\nThe"..., 8192) = 8192
    24111 0.000032 write(49, "at's this?\nJULIET \tA rhyme I lea"..., 8192) = 8192
    24111 0.000033 write(49, "ght:\nIt is too rash, too unadvis"..., 8192) = 8192
    24111 0.000033 write(49, "f old Capulet,\nHath sent a lette"..., 8192) = 8192
    24111 0.000032 write(49, "ng:--O, there\nis a nobleman in t"..., 8192) = 8192
    24111 0.000032 write(49, " to that, sir, an you\nwill give "..., 8192) = 8192
    24111 0.000032 write(49, "For thou wilt lie upon the wings"..., 8192) = 8192
    24111 0.000033 write(49, "rd:\nAdversity's sweet milk, phil"..., 8192) = 8192
    24111 0.000032 write(49, "whose notes do beat\nThe vaulty h"..., 8192) = 8192
    24111 0.000032 write(49, "tting in the clouds,\nThat sees i"..., 8192) = 8192
    24111 0.000040 write(49, "that cannot lick his\nown fingers"..., 8192) = 8192
    24111 0.000033 write(49, "d leave him all; life, living, a"..., 8192) = 8192
    24111 0.000036 write(49, "s,\nDoing more murders in this lo"..., 8192) = 8192
    24111 0.000033 write(49, "nlucky thing.\nBALTHASAR \tAs I di"..., 8192) = 8192
    24111 0.000033 write(49, "omatically converted by James Fa"..., 8192) = 8192
    24111 0.000032 write(49, "\nare ever thrust to the wall: th"..., 8192) = 8192
    24111 0.000068 write(49, "IO \tTell me in sadness, who is t"..., 8192) = 8192
    24111 0.000068 write(49, "s eleven years;\nFor then she cou"..., 8192) = 8192
    24111 0.000063 write(49, "misgives\nSome consequence yet ha"..., 8192) = 8192
    24111 0.000069 write(49, "n this way, and leap'd this orch"..., 8192) = 8192
    24111 0.000068 write(49, " Romeo, and good night indeed.\nI"..., 8192) = 8192
    24111 0.000057 write(49, "fflicted with\nthese strange flie"..., 8192) = 8192
    24111 0.000014 write(49, "ings.\nNow is the sun upon the hi"..., 8192) = 8192
    24111 0.000061 write(49, "; therefore turn and draw.\nROMEO"..., 8192) = 8192
    24111 0.000059 write(49, " devil art thou, that dost torme"..., 8192) = 8192
    24111 0.006669 write(49, "Nurse \t[Within] Let me come in, "..., 8192 <unfinished ...>
    24111 0.007033 <... write resumed> ) = 8192
    24111 0.006792 write(49, " Romeo!\nROMEO \tFarewell!\nI will "..., 8192) = 8192
    24111 0.000046 write(49, "t: or if it did not,\nYour first "..., 8192) = 8192
    24111 0.000014 write(49, "o with me into my closet,\nTo hel"..., 8192 <unfinished ...>
    24111 0.010187 <... write resumed> ) = 8192
    24111 0.000083 write(49, "eaven hath all,\nAnd all the bett"..., 8192) = 8192
    24111 0.006699 write(49, "d the neglecting it\nMay do much "..., 8192) = 8192
    24111 0.000076 write(49, "?\nPoison, I see, hath been his t"..., 8192) = 8192
    24111 0.000076 write(49, "ollo, and the hero Perseus.\n\nThe"..., 8192) = 8192
    24111 0.000009 write(49, ", sir?\nSAMPSON \tI do bite my thu"..., 8192) = 8192
    24111 0.000033 write(49, "LIO \tBe ruled by me, forget to t"..., 8192) = 8192
    24111 0.000034 write(49, "sed:\nAn I might live to see thee"..., 8192) = 8192
    24111 0.000033 write(49, "CAPULET \tWelcome, gentlemen! lad"..., 8192) = 8192
    24111 0.000033 write(49, "lind is his love and best befits"..., 8192) = 8192
    24111 0.000033 write(49, "IET \tRomeo!\nROMEO \tMy dear?\nJULI"..., 8192) = 8192
    24111 0.000033 write(49, "OMEO \tPink for flower.\nMERCUTIO "..., 8192) = 8192
    24111 0.000033 write(49, "use.\nIs thy news good, or bad? a"..., 8192) = 8192
    24111 0.000041 write(49, "\tWhat, art thou hurt?\nMERCUTIO \t"..., 8192) = 8192
    24111 0.000032 write(49, "Romeo that kill'd him, he is ban"..., 8192) = 8192
    24111 0.000032 write(49, "d\nMurder'd her kinsman. O, tell "..., 8192) = 8192
    24111 0.000033 write(49, "ef shows much of love;\nBut much "..., 8192) = 8192
    24111 0.000032 write(49, "ve I little talk'd of love;\nFor "..., 8192) = 8192
    24111 0.000032 write(49, "et me now be left alone,\nAnd let"..., 8192) = 8192
    24111 0.000033 write(49, "ove them no more by crossing the"..., 8192) = 8192
    24111 0.000044 write(49, "is dust and stones;--\nWhich with"..., 8192) = 8192
    24111 0.000032 write(49, "come hither.\n\t[Re-enter others o"..., 8192) = 8192
    24111 0.000033 write(49, "ellenic Museum, 1991\n\nThe poet H"..., 8192) = 8192
    24111 0.000032 write(49, "rike! beat them down!\nDown with "..., 8192) = 8192
    24111 0.000040 write(49, "\tYounger than she are happy moth"..., 8192) = 8192
    24111 0.000033 write(49, "ver,\nTo beautify him, only lacks"..., 8192) = 8192
    24111 0.000032 write(49, "two years ago.\nROMEO \t[To a Serv"..., 8192) = 8192
    24111 0.000032 write(49, "rs in all the heaven,\nHaving som"..., 8192) = 8192
    24111 0.000032 write(49, "LAURENCE \tThe grey-eyed morn smi"..., 8192) = 8192
    24111 0.000033 write(49, "ing for love?\nnow art thou socia"..., 8192) = 8192
    24111 0.000033 write(49, "oddly thou repliest!\n'Your love "..., 8192) = 8192
    24111 0.000038 write(49, "e Mercutio's dead!\nThat gallant "..., 8192) = 8192
    24111 0.000034 write(49, "LIET \tShall I speak ill of him t"..., 8192) = 8192
    24111 0.000033 write(49, "ct of them both,\nLike powder in "..., 8192) = 8192
    24111 0.000033 write(49, "To bear a poison, I would temper"..., 8192) = 8192
    24111 0.000033 write(49, " it, more than tears, with that "..., 8192) = 8192
    24111 0.000033 write(49, "\nOr, if I live, is it not very l"..., 8192) = 8192
    24111 0.000033 write(49, "Then have at you with my wit! I "..., 8192) = 8192
    24111 0.000032 write(49, "xorable far\nThan empty tigers or"..., 8192) = 8192
    24111 0.000032 write(49, "O me! this sight of death is as "..., 8192) = 8192
    24111 0.000032 write(49, "spring when the hero Bellerophon"..., 8192) = 8192
    24111 0.000041 write(49, "r streets again,\nYour lives shal"..., 8192) = 8192
    24111 0.000033 write(49, "vant \tFind them out whose names "..., 8192) = 8192
    24111 0.000033 write(49, "with a scarf,\nBearing a Tartar's"..., 8192) = 8192
    24111 0.000033 write(49, "ona brags of him\nTo be a virtuou"..., 8192) = 8192
    24111 0.000033 write(49, "n. O, be some other name!\nWhat's"..., 8192) = 8192
    24111 0.000033 write(49, "osed kings encamp them still\nIn "..., 8192) = 8192
    24111 0.000033 write(49, "re I\nmay find the young Romeo?\nR"..., 8192) = 8192
    24111 0.000033 write(49, " words,\nThen love-devouring deat"..., 8192) = 8192
    24111 0.000033 write(49, " the princes name, obey.\n\t[Enter"..., 8192) = 8192
    24111 0.000034 write(49, "t, Romeo, Juliet,\nAll slain, all"..., 8192) = 8192
    24111 0.000043 write(49, ", I could have stay'd here all t"..., 8192) = 8192
    24111 0.000033 write(49, "re news indeed!\nLADY CAPULET \tHe"..., 8192) = 8192
    24111 0.000034 write(49, "eed,\nOr my true heart with treac"..., 8192) = 8192
    24111 0.000032 write(49, "call for dates and quinces in th"..., 8192) = 8192
    24111 0.000033 write(49, "d spirit\nLifts me above the grou"..., 8192) = 8192
    24111 0.000035 write(49, "gone!\nBy heaven, I love thee bet"..., 8192) = 8192
    24111 0.000033 write(49, "et;\nAnd she, there dead, that Ro"..., 8192) = 8192
    24111 0.000032 write(49, "reet.\n Scene V A hall in "..., 8192) = 8192
    24111 0.000033 write(49, "\nThat westward rooteth from the "..., 8192) = 8192
    24111 0.000032 write(49, "d the language.\nServant \tYe say "..., 8192) = 8192
    24111 0.000033 write(49, "uote deformities?\nHere are the b"..., 8192) = 8192
    24111 0.000041 write(49, "worthiest hand\nThis holy shrine,"..., 8192) = 8192
    24111 0.000033 write(49, "e thy kinsmen are no let to me.\n"..., 8192) = 8192
    24111 0.000033 write(49, "ed, blessed man, for, lo,\nMy int"..., 8192) = 8192
    24111 0.000033 write(49, "ing against me, I'll take him\ndo"..., 8192) = 8192
    24111 0.000052 write(49, "rue love is grown to such excess"..., 8192) = 8192
    24111 0.000035 write(49, " than\nhis tongue,\nHis agile arm "..., 8192) = 8192
    24111 0.000034 write(49, "What sorrow craves acquaintance "..., 8192) = 8192
    24111 0.000034 write(49, "o time to woo.\nMadam, good night"..., 8192) = 8192
    24111 0.000033 write(49, "PULET \tHow now, how now, chop-lo"..., 8192) = 8192
    24111 0.000032 write(49, "de me with a dead man in his shr"..., 8192) = 8192
Comment 6 Ben England 2013-02-16 09:40:28 EST
Jay, 

It doesn't matter whether it's write or writev, the strace command was just an example.  The point is that the transfer size is tiny.  

You didn't need to post the entire Shakespeare play -- Shakespeare is great but bugzilla is not where Shakespeare would want to see his play performed, I'm sure! ;-)  strace -c would just provide the counters, for example.

Let's put this in perspective.  The BAGL servers are routinely configured with XFS storage bricks that can come close to 1 GB/s transfer rates.  When your RAID6 storage array can write at 1 GB/sec ~= 1 KB/microsec, then an 8-KB write is 8 microsec worth of data.  The FUSE context switching alone takes that long.  Can't BufferedFileWriter be configured with a buffer that is 128 KB = 1/8 millisecond worth of data? FUSE can only accept data in 128-KB chunks in RHEL6.

Let's test this enhancement on BAGL and write enough data that you can get repeatable results that show a significant difference. I'd suggest at least 1 GB of data, which should only be a few seconds worth if the optimization works.
Comment 7 Jay Vyas 2013-04-22 20:51:33 EDT
** Update on the Small Writes issue **

Some good progress and news on this: 

Diane has tested this and confirmed that by adding a Buffer wrapper to the stream, there is a major increase in performance... details to come.  But in general. 

See : https://github.com/gluster/hadoop-glusterfs/blob/bb19cb4094a1f10c5dcbda0793f94e84b3df3745/src/main/java/org/apache/hadoop/fs/glusterfs/GlusterFUSEOutputStream.java for the implementation (the only main change here is the single line which adds the Buffer around the FileOutputStream).


** Some notes on the DFSOutputStream - relevant but eventually these will be part of a new ticket do make our Glsuter output stream more sophisticated, and optimal .  ** 

Now we are comparing this with the DFSOutputStream in hadoop.  DFSOutputStream is highly sophisticated, it is akin to what we might do if we decided to talk to LibGFAPI for writes - with direct connections to Data nodes, a "streamer" which reads from an ack queue, and also, some buffering logic.  Also, there is direct cross talking to data nodes.   

1) there is sophisticated buffering logic : both direct (BufferedOujtputStream) and indirect (data queue and streamer) in the DFSOutputStream. I think the DataStreamer serves as a buffer to.   

2) there is a unresolved JIRA filed that sais the buffering doesnt work properly. 

3) There are debates in hadoop community about value of java buffering vs letting OS do the buffering. 

4) my opinion: overall i think micro-optimizing HDFS absolute streaming write time with direct buffers is not the biggest priority in hadoop community - they focus more on making the distributed writes faster, speeding up the spill process, and compressing network traffic.
Comment 8 Jay Vyas 2013-04-26 14:32:56 EDT
The patch has now gone in and has necessary unit tests, as well as production test to deem this fixed.  

https://github.com/gluster/hadoop-glusterfs/pull/26/commitshttps://github.com/gluster/hadoop-glusterfs/pull/26/commits
Comment 9 Jay Vyas 2013-04-26 14:33:58 EDT
https://github.com/gluster/hadoop-glusterfs/pull/26/commits <-- fixed link

Note You need to log in before you can comment on or make changes to this bug.