<div dir="ltr"><div>Oh, and here are the benchmarks for me now:<br><br></div>R15B03:<br>1> timer:tc(line_read_test,read_std,["test.txt"]).<br>{21307874,14448}<br><br><div><div>R16B with patch:<br>1> timer:tc(line_read_test,read_std,["test.txt"]).<br>
{91885,14448}<br><br></div><div>It's not every day you find a two line change which increases speed by a factor of 232!<br></div><div><br></div><div>Lukas<br></div></div></div><div class="gmail_extra"><br><br><div class="gmail_quote">
On Fri, Feb 15, 2013 at 4:42 PM, Lukas Larsson <span dir="ltr"><<a href="mailto:lukas@erlang-solutions.com" target="_blank">lukas@erlang-solutions.com</a>></span> wrote:<br><blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex">
<div dir="ltr">aha, you needed to have very long lines in the file to provoke the behaviour. The file I was experimenting on had the same line length all the time.<br><br>I think I've found the culprit. Aparently the read_ahead option was ignored after the first buffer had been consumed. Try the patch below and 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" target="_blank">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 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 >= DEFAULT_LINEBUF_SIZE) ?<br>                d->c.read_line.read_size + DEFAULT_LINEBUF_SIZE : 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;<span class="HOEnZb"><font color="#888888"><br>
-- <br>1.7.10.4<br>
<br><br></font></span></div><div class="HOEnZb"><div class="h5"><div class="gmail_extra"><br><br><div class="gmail_quote">On Fri, Feb 15, 2013 at 1:29 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">Using async thread drops time down to 4.6s which is still 20 times<br>
slower than mine simple wrapper.<br>
<div><div><br>
On Thu, Feb 14, 2013 at 4:25 PM, Lukas Larsson <<a href="mailto:lukas@erlang.org" target="_blank">lukas@erlang.org</a>> wrote:<br>
> Hello!<br>
><br>
> If you start erlang with an async thread (erl +A 1) you will see radically<br>
> different behaviour. For me the time it takes to use read_line drops from<br>
> 58s to 2s. When doing file i/o you should always have some async threads to<br>
> help you do the work, this is why in R16B we changed the default from 0 to<br>
> 10 async threads.<br>
><br>
> Lukas<br>
><br>
><br>
> On Thu, Feb 14, 2013 at 3:46 PM, Hynek Vychodil <<a href="mailto:vychodil.hynek@gmail.com" target="_blank">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 recurring<br>
>> topic for at least five years. But anyway I have been bitten by it again<br>
>> and<br>
>> also found pretty pathological case. I have 30MB text file and it has 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 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 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 (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 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 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 efile_drv.c<br>
>> and<br>
>> ti is unfortunately far beyond mine C skill but if simple buffering 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 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 million<br>
>> 64bit values (1.2GB of data) three times (one CPU core same HW). It is 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 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" target="_blank">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" target="_blank">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></div>
</div></div></blockquote></div><br></div>