On 2013-04-16 00:45:19, Artella Coding wrote:
> Hi Felix,
>
> Thanks for your response. That is an interest observation you made about
> the println functon.
>
> Upon playing with the code a bit more, I noticed that the strange behaviour
> seems to be limited to the function "second". The distinguishing feature of
> this function is that it involves a nested function.
>
> I have rewritten the codes to only involve a single function in each source
> file (in order to illustrate this better) & the source and results are
> below (to call the functions twice just uncomment the last few lines I have
> commented out in each program) :
>
> firstAndFirst.rs
> 1)Call "first" once : 4.5s
> 2)Call "first" twice : 9.4s
>
> secondAndSecond.rs (nested function call_
> 1)Call "second" once : 9.5s
> 2)Call "second" twice : 43.8s (--> I would have expected this to be 19s <--)
>
> *********************************************************************************
> *********************************************************************************
> //firstAndFirst.rs
> static g_r: float = 3.569956;
> static g_x0:float = 0.53;
>
> fn first(n: i64, x0 : float, r: float) -> float {
> let mut x = x0;
> let mut i = 0i64;
> loop {
> x = r*x*(1.-x);
> i += 1;
> if i == n { break }
> }
> x
> }
>
> fn main(){
> let l = 400000000i64;
>
> let result = first(l,g_x0,g_r);
> io::println(float::to_str(result));
>
> //let result2 = first(l,g_x0,g_r);
> //io::println(float::to_str(result2));
> }
> *********************************************************************************
> *********************************************************************************
> //secondAndSecond.rs
> static g_r: float = 3.569956;
> static g_x0:float = 0.53;
>
> fn second(n: i64, x0 : float, r: float) -> float {
>
> fn calc(x : float, r: float) -> float {
> let mut xm = x;
> xm = r*xm*(1.-xm);
> xm
> }
>
> let mut x = x0;
> let mut i = 0i64;
> loop {
> x = calc(x,r);
> i += 1;
> if i == n { break }
> }
> x
>
> }
>
> fn main(){
> let l = 400000000i64;
>
> let result = second(l,g_x0,g_r);
> io::println(float::to_str(result));
>
> //let result2 = second(l,g_x0,g_r);
> //io::println(float::to_str(result2));
> }
> *********************************************************************************
> *********************************************************************************
Hi Artella,
I was curious about this and did some investigation. There are a few things
that are
causing the issues you are seeing.
rustc doesn't produce particularly good LLVM IR. There is nothing technically
wrong
with it, it is just very bloated. This is fine because the LLVM optimizer is
pretty good
at taking that code down to a reasonable level.
I did some tests compiling with all 4 levels of optimization:
Level 0: (default)
Time: 10.0s
Binary Size: 118k
LLVM IR Size: 16512 lines
Level 1:
Time: 1.38s
Binary Size: 62k
LLVM IR Size: 6902 lines
Level 2: (default level with -O)
Time: 1.37s
Binary Size: 22k
LLVM IR Size: 1949 lines
Level 3:
Time: 1.37s
Binary Size: 22k
LLVM IR Size: 1949 lines
The jump from 0 to 1 is the biggest. In fact calling second twice produces a
difference of
50s vs 2.7 for level 0 vs level 1 optimization.
As to why it produces so much code, well for one, all the intrinsics and a few
other
things are included, even at opt-level 1 they are removed as being unused. That
doesn't
explain the speed of the code though. That is likely to do with the fact that
the call to
the inner function isn't inlined, and therefore you are paying for that
function call.
While normally function calls are fast, when you are calling it 400,000,000
times, it adds
up.
As for the exponetial slow-down, it's related to the fact that io is
asynchronous and
handled by the scheduler task, but tasks are scheduled co-operative meaning
a CPU-intensive task can block other tasks in the same thread. I haven't yet
figured out
the specific reasons, but wrapping each call to `second` in it's own task
causes the time
to drop from ~1 minute to 7 seconds. If you account for parallelism from
running in
multiple threads, then `time` reports ~15 seconds. Which is double.
Again, I am unclear on the exact reason why this happens, but it is fairly
clear that it
is the IO that is causing the issue. Fortunately there is a new scheduler on
the way that
will hopefully sort some of these issues.
--
James Miller
_______________________________________________
Rust-dev mailing list
[email protected]
https://mail.mozilla.org/listinfo/rust-dev
