<br><br><div class="gmail_quote">On Sat, Feb 16, 2013 at 12:57 AM, Hynek Vychodil <span dir="ltr"><<a href="mailto:vychodil.hynek@gmail.com" target="_blank">vychodil.hynek@gmail.com</a>></span> wrote:<br><blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex">
It works like charm. I have patched R15B03 ad with 1MB read ahead it<br>
is unbelievable fast<br>
<br>
20> timer:tc(line_read_test,read_std,["test.txt"]).<br>
{30732,2408}<br>
<br>
It is even four times faster than port version<br>
<br>
24> timer:tc(line_read_test,read_port,["test.txt"]).<br>
{135676,2408}<br>
<br>
It is also faster without async threads. Measurements above was with<br>
+A 10. Without async threads:<br>
<br>
2> timer:tc(line_read_test,read_std,["test.txt"]).<br>
{19322,2408}<br>
<br>
I was expected time around 100ms but current behavior is far beyond<br>
expectation. I hope this patch will find way into upcoming R16. It<br>
seems to speed up line oriented io for "normal" files two times also.<br>
<br>
Thanks a lot<br>
Hynek Vychodil<br></blockquote><div><br></div><div>And thanks to you - if we don't know it's broken we can't fix it - so all observations of</div><div>weird behaviour are worthy of note.</div><div><br></div>
<div>Cheers</div><div><br></div><div>/Joe</div><div><br></div><div><br></div><div><br></div><div> </div><blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex">
<br>
On Fri, Feb 15, 2013 at 4:58 PM, Lukas Larsson<br>
<div class="HOEnZb"><div class="h5"><<a href="mailto:lukas@erlang-solutions.com">lukas@erlang-solutions.com</a>> wrote:<br>
> Oh, and here are the benchmarks for me now:<br>
><br>
> R15B03:<br>
><br>
> 1> timer:tc(line_read_test,read_std,["test.txt"]).<br>
> {21307874,14448}<br>
><br>
> R16B with patch:<br>
><br>
> 1> timer:tc(line_read_test,read_std,["test.txt"]).<br>
> {91885,14448}<br>
><br>
> It's not every day you find a two line change which increases speed by a<br>
> factor of 232!<br>
><br>
> Lukas<br>
><br>
><br>
> On Fri, Feb 15, 2013 at 4:42 PM, Lukas Larsson <<a href="mailto:lukas@erlang-solutions.com">lukas@erlang-solutions.com</a>><br>
> wrote:<br>
>><br>
>> aha, you needed to have very long lines in the file to provoke the<br>
>> behaviour. The file I was experimenting on had the same line length all the<br>
>> time.<br>
>><br>
>> I think I've found the culprit. Aparently the read_ahead option was<br>
>> ignored after the first buffer had been consumed. Try the patch below and<br>
>> see if it works for you:<br>
>><br>
>> From 0884480691e047801cef117b19151a7d34c9e438 Mon Sep 17 00:00:00 2001<br>
>> From: Lukas Larsson <<a href="mailto:lukas@erlang-solutions.com">lukas@erlang-solutions.com</a>><br>
>> Date: Fri, 15 Feb 2013 16:37:52 +0100<br>
>> Subject: [PATCH] invoke_read_line now remembers read_ahead settings<br>
>><br>
>> ---<br>
>> erts/emulator/drivers/common/efile_drv.c | 2 ++<br>
>> 1 file changed, 2 insertions(+)<br>
>><br>
>> diff --git a/erts/emulator/drivers/common/efile_drv.c<br>
>> b/erts/emulator/drivers/common/efile_drv.c<br>
>> index 2279fec..d81f116 100644<br>
>> --- a/erts/emulator/drivers/common/efile_drv.c<br>
>> +++ b/erts/emulator/drivers/common/efile_drv.c<br>
>> @@ -1160,6 +1160,8 @@ static void invoke_read_line(void *data)<br>
>> /* Need more place */<br>
>> ErlDrvSizeT need = (d->c.read_line.read_size >=<br>
>> DEFAULT_LINEBUF_SIZE) ?<br>
>> d->c.read_line.read_size + DEFAULT_LINEBUF_SIZE :<br>
>> DEFAULT_LINEBUF_SIZE;<br>
>> + if (need < (d->c.read_line.binp)->orig_size)<br>
>> + need = (d->c.read_line.binp)->orig_size;<br>
>> ErlDrvBinary *newbin = driver_alloc_binary(need);<br>
>> if (newbin == NULL) {<br>
>> d->result_ok = 0;<br>
>> --<br>
>> 1.7.10.4<br>
>><br>
>><br>
>><br>
>><br>
>> On Fri, Feb 15, 2013 at 1:29 AM, Hynek Vychodil <<a href="mailto:vychodil.hynek@gmail.com">vychodil.hynek@gmail.com</a>><br>
>> wrote:<br>
>>><br>
>>> Using async thread drops time down to 4.6s which is still 20 times<br>
>>> slower than mine simple wrapper.<br>
>>><br>
>>> On Thu, Feb 14, 2013 at 4:25 PM, Lukas Larsson <<a href="mailto:lukas@erlang.org">lukas@erlang.org</a>> wrote:<br>
>>> > Hello!<br>
>>> ><br>
>>> > If you start erlang with an async thread (erl +A 1) you will see<br>
>>> > radically<br>
>>> > different behaviour. For me the time it takes to use read_line drops<br>
>>> > from<br>
>>> > 58s to 2s. When doing file i/o you should always have some async<br>
>>> > threads to<br>
>>> > help you do the work, this is why in R16B we changed the default from 0<br>
>>> > to<br>
>>> > 10 async threads.<br>
>>> ><br>
>>> > Lukas<br>
>>> ><br>
>>> ><br>
>>> > On Thu, Feb 14, 2013 at 3:46 PM, Hynek Vychodil<br>
>>> > <<a href="mailto:vychodil.hynek@gmail.com">vychodil.hynek@gmail.com</a>><br>
>>> > wrote:<br>
>>> >><br>
>>> >> Hello,<br>
>>> >> I know it was been already discussed here in list and it is also<br>
>>> >> recurring<br>
>>> >> topic for at least five years. But anyway I have been bitten by it<br>
>>> >> again<br>
>>> >> and<br>
>>> >> also found pretty pathological case. I have 30MB text file and it has<br>
>>> >> a<br>
>>> >> few<br>
>>> >> near to 1MB lines there. (I can provide file with same line lengths if<br>
>>> >> somebody interested.) What I have been observed is that reading this<br>
>>> >> file<br>
>>> >> using raw file:read_line/1 takes 51s! For comparison I have tried some<br>
>>> >> different approaches and what I got (line_read_test:read_std/1 is<br>
>>> >> using<br>
>>> >> file:read_line/1):<br>
>>> >><br>
>>> >> 1> timer:tc(line_read_test,read_std,["test.txt"]).<br>
>>> >> {51028105,2408}<br>
>>> >> 2> timer:tc(line_read_test,read,["test.txt"]).<br>
>>> >> {226220,2408}<br>
>>> >> 3> timer:tc(line_read_test,read_port,["test.txt"]).<br>
>>> >> {139388,2408}<br>
>>> >><br>
>>> >> $time perl -nE'$i++}{say $i' test.txt<br>
>>> >> 2408<br>
>>> >><br>
>>> >> real 0m0.053s<br>
>>> >> user 0m0.044s<br>
>>> >> sys 0m0.008s<br>
>>> >><br>
>>> >> $ time wc -l test.txt<br>
>>> >> 2408 test.txt<br>
>>> >><br>
>>> >> real 0m0.013s<br>
>>> >> user 0m0.004s<br>
>>> >> sys 0m0.008s<br>
>>> >><br>
>>> >> $ time ./a.out test.txt<br>
>>> >> 2408<br>
>>> >><br>
>>> >> real 0m0.020s<br>
>>> >> user 0m0.012s<br>
>>> >> sys 0m0.008s<br>
>>> >><br>
>>> >> It means erlang should be at least 225 times faster<br>
>>> >> (line_read_test:read/1<br>
>>> >> which has flow control). Erlang can be 350 times faster<br>
>>> >> (line_read_test:read_port/1 without flow control). Another high level<br>
>>> >> language (perl) is almost thousand times faster. Special C program is<br>
>>> >> almost<br>
>>> >> four thousands times faster and old good glibc is two and half<br>
>>> >> thousands<br>
>>> >> times faster. Come on guys it is not even fun when simple (and wrong)<br>
>>> >> erlang<br>
>>> >> wrapper around standard module is more than two order of magnitude<br>
>>> >> faster.<br>
>>> >> From mine experience when there is something two orders of magnitude<br>
>>> >> slower<br>
>>> >> it tells me there is something damn wrong. I have looked into<br>
>>> >> efile_drv.c<br>
>>> >> and<br>
>>> >> ti is unfortunately far beyond mine C skill but if simple buffering<br>
>>> >> and<br>
>>> >> binary:match/2 can outperform it 225 times there has to be something<br>
>>> >> rotten<br>
>>> >> in this code.<br>
>>> >><br>
>>> >> I have also experimented with read_ahead option in file:open and<br>
>>> >> changing<br>
>>> >> to<br>
>>> >> less value makes thing worse.<br>
>>> >><br>
>>> >> Just to make grasp how bad it is, in same time I'm able sort 150<br>
>>> >> million<br>
>>> >> 64bit values (1.2GB of data) three times (one CPU core same HW). It is<br>
>>> >> not<br>
>>> >> in<br>
>>> >> flow control, mine simple wrapper does flow control too. It can't make<br>
>>> >> current code less intrusive, if it consumes 100% CPU for 51s instead<br>
>>> >> of<br>
>>> >> 226ms<br>
>>> >> then it will definitely affect whole server. It is not in concurrent<br>
>>> >> access,<br>
>>> >> mine code allows concurrent access too. Admitting there is something<br>
>>> >> broken<br>
>>> >> is first step to fixing it. I hope I helped at least in this way.<br>
>>> >><br>
>>> >> With best regards<br>
>>> >> Hynek Vychodil<br>
>>> >><br>
>>> >> _______________________________________________<br>
>>> >> erlang-questions mailing list<br>
>>> >> <a href="mailto:erlang-questions@erlang.org">erlang-questions@erlang.org</a><br>
>>> >> <a href="http://erlang.org/mailman/listinfo/erlang-questions" target="_blank">http://erlang.org/mailman/listinfo/erlang-questions</a><br>
>>> >><br>
>>> ><br>
>>> _______________________________________________<br>
>>> erlang-questions mailing list<br>
>>> <a href="mailto:erlang-questions@erlang.org">erlang-questions@erlang.org</a><br>
>>> <a href="http://erlang.org/mailman/listinfo/erlang-questions" target="_blank">http://erlang.org/mailman/listinfo/erlang-questions</a><br>
>><br>
>><br>
><br>
_______________________________________________<br>
erlang-questions mailing list<br>
<a href="mailto:erlang-questions@erlang.org">erlang-questions@erlang.org</a><br>
<a href="http://erlang.org/mailman/listinfo/erlang-questions" target="_blank">http://erlang.org/mailman/listinfo/erlang-questions</a><br>
</div></div></blockquote></div><br>