BUG - No immediate exit when pipeing ra output

[elof2 at sentor.se]

Hi Carter!

It seems that the bugfix to detect closure of the pipe still have issues.

In ra v2.x I was used to having the ra command terminate in 0.004s.
With the new ra 3.0.5.8, it won't terminate as swiftly.

ra v3.0.5.8:
time ra -nr argus.log - > /dev/null
real    0m4.499s
user    0m4.288s
sys     0m0.212s
Time to parse through 100% of this test-file is apparently ~4.5s.


Now lets see the time when grep or head terminates directly on the first 
line:
time ra -nr argus.log - | grep -q "."
real    0m4.562s
user    0m4.392s
sys     0m0.176s
time ra -nr argus.log - | head -1
real    0m4.588s
user    0m4.428s
sys     0m0.168s

Both commands take the full 4.5s (plus a little more) to finish.

If I add another (or the same) logfile, it will double the execution time:
time ra -nr argus.log argus.log - | head -1
real    0m9.002s
user    0m8.617s
sys     0m0.392s

Conclusion:
ra 3.0.5.8 don't immediately terminate upon pipe closure.



Speaking of latency and execution times...

Even when using the builtin -N1 option, ra v2 is way faster than v3:
ra v2.x:
time ra -N1 -nr argus.log -
real    0m0.003s
user    0m0.000s
sys     0m0.000s

ra 3.0.5.8:
real    0m0.024s
user    0m0.000s
sys     0m0.021s

v3 is 8 times slower than v2 when it comes to swift termination.
Can this be improved?


Also, no matter how many files I add to ra v2, it still terminates after 
0.003 seconds where as ra v3 will increase its 0.024s by approx 0.002 per 
file:
ra v2.x:
time ra -N1 -nr argus.log argus.log argus.log argus.log argus.log argus.log argus.log argus.log argus.log argus.log -
real    0m0.003s  <-  still 0.003s
user    0m0.000s
sys     0m0.002s

ra 3.0.5.8:
real    0m0.032s  <-  increases more and more for every file added
user    0m0.007s
sys     0m0.024s

If you have 288 argus files in a log dir and use ra -nr argus*.log to do 
some simple processing, you will always have a noticeable lag just for 
the sake of the 288 files, even if you use -N1. Can this be improved to 
be as swift as v2?
(288 files á 5 minutes = 24 hours)

/Elof


On Fri, 29 Apr 2011, Carter Bullard wrote:

> Hey Elof,
> I have the closed piped issue fixed now.  Its a small fix in every client, so you should wait to get a new client release.

> Carter



>>>> Two examples using the old ra v2.x :
>>>>
>>>> 1)
>>>> time ra -Zb -nr argus.log - ip | head -1
>>>> 04-27-11 23:54:00.925018  s        tcp             10.10.10.10.46382 ->   20.20.20.20.1503   5467  5550  967561   2559850     PA_PA
>>>>
>>>> real    0m0.004s
>>>> user    0m0.000s
>>>> sys     0m0.000s
>>>>
>>>>
>>>> 2)
>>>> time ra -Zb -nr argus-20110428.log - ip | grep -q "PA_PA$"
>>>>
>>>> real    0m0.004s
>>>> user    0m0.000s
>>>> sys     0m0.000s
>>>>
>>>>
>>>> Both examples only take 0.004s to execute.
>>>> Good!
>>>>
>>>>
>>>>
>>>> Now I try the same using ra v3 :
>>>>
>>>> 1)
>>>> time ra -Zb -nr argus.log - ip | head -1
>>>> 04-27-11 23:54:00.925018  s        tcp             30.30.30.30.32451 ->   40.40.40.40.25    52  97  1151   12274     PA_PA
>>>>
>>>> real    0m50.043s
>>>> user    0m48.171s
>>>> sys     0m1.892s
>>>>
>>>>
>>>> 2)
>>>> time ra -Zb -nr argus-20110429.13.log - ip | grep -q "PA_PA$"
>>>>
>>>> real    0m50.161s
>>>> user    0m48.103s
>>>> sys     0m2.068s
>>>>
>>>>
>>>> The commands take 50 seconds (!!!) to complete when they should have taken approx 0.004 seconds.
>>>>
>>>> The argus.log file is 96 MB and hold 828 372 rows of data.
>>>> (The larger the file, the longer I have to wait until the command terminates. If I have an old argus.log holding 24 hours of data, it will take ~30 minutes to parse it (even longer if it is bzipped))
>>>>
>>>>
>>>> It takes 50 seconds just to parse through 100% of the file:
>>>> time ra -nr argus.log - ip > /dev/null
>>>>
>>>> real    0m50.257s
>>>> user    0m48.599s
>>>> sys     0m1.596s