Timing method causing code to run slow

Question

I'm working on optimizing a little java program I made for Christmas. I was testing the amount of time it takes to run the methods and one of them, Snow_AI, is taking 1234567 nano seconds to run.

The issues is with the counter method:

public boolean Count() {
    if (CreateCnt > CreateTime) {
        CreateCnt = 0;
        return true;
    } else {
        CreateCnt = CreateCnt + 1;
    }
    return false;
}

This is how I'm making the calls:

MethTmr1 = System.nanoTime();
    if (Snw.Count()) {
        MethTmr = System.nanoTime();
        Snw.Snow_AI();
        MethTPS = 1000000000 / (System.nanoTime() - MethTmr);
    }
    try{
        MethTPS1 = 1000000000 / (System.nanoTime() - MethTmr1);
    }catch(Exception e){}

when I move the timing calls inside the If statement it changed the time to run to less than 5000. Anyone know why the counter method is causing this to happen?

care to share how you measure that? Please show both ways you measured that. — Jan, Dec 22 '15 at 08:23
`Tmr = System.nanoTime();` before the method call and `TPS = 1000000000 / (System.nanoTime() - Tmr);` After the call. its what i use to measure frame rate and Ticks per second — Kyle Burns, Dec 22 '15 at 18:14
Where do you measure time to run? I only see code like 1/time which would get lower with greater time...? — Jan, Dec 22 '15 at 18:23
in the TPS variable: `TPS = 1000000000 / (System.nanoTime() - Tmr);` it works, i have used it before on a course project testing. — Kyle Burns, Dec 22 '15 at 18:37
But thats **inversed** time. Bigger is shorter. How does your code look if you include the if? — Jan, Dec 22 '15 at 18:39
you mean the if that seams to cause the issues? that's the last section of code in the question. — Kyle Burns, Dec 22 '15 at 18:41
Can you add your output please? I'm confused what you measure where. MethTPS1 will include the whole messurement-code for MethTPS so it's counting **way more** than the if. — Jan, Dec 22 '15 at 18:45
i can give you a file to down load if that will help? https://drive.google.com/file/d/0B_OnW-7IrSM9UjlYY3cyU2k1QU0/view?usp=sharing — Kyle Burns, Dec 22 '15 at 18:49
just to clarify I did do the measuring separately, i just put the code like that so you could see how i measured them both :) — Kyle Burns, Dec 22 '15 at 18:54

score 1 · Accepted Answer · edited May 23 '17 at 11:50

1

Your measurement is flawed.

Check this: Why is System.nanoTime() way slower (in performance) than System.currentTimeMillis()?

And then look at your code:

MethTmr1 = System.nanoTime();
if (Snw.Count()) {
    //expensive! Added to outer time
    MethTmr = System.nanoTime();
    Snw.Snow_AI();
     //expensive! Added to outer time
    MethTPS = 1000000000 / (System.nanoTime() - MethTmr);
}
try{
    MethTPS1 = 1000000000 / (System.nanoTime() - MethTmr1);
}catch(Exception e){}

Baseline. Your MethTPS1 includes your (fast) getCount(), your Snow_AI() and two tcalls to System.nanoTime()

Try it this way once:

MethTmr1 = System.nanoTime();
if (Snw.Count()) {
    //expensive! Added to outer time
    //MethTmr = System.nanoTime();
    Snw.Snow_AI();
     //expensive! Added to outer time
    //MethTPS = 1000000000 / (System.nanoTime() - MethTmr);
}
try{
    MethTPS1 = 1000000000 / (System.nanoTime() - MethTmr1);
}catch(Exception e){}

edited May 23 '17 at 11:50

Community

1
1

answered Dec 22 '15 at 18:58

Jan

13,738
3
30
55

i did do the 2 timers on separate runs, i just did the code like that to show the way i'm testing :) – Kyle Burns Dec 22 '15 at 19:03
also the code is only there for testing and will be removed once the issues has been fixed. – Kyle Burns Dec 22 '15 at 19:12
I can only work with what I see - please then share what you really measure. how many iterations do you do for your test? – Jan Dec 22 '15 at 20:29
you right in what you said about the testing. it's not my AI method that is causing the slow down. when i do the testing i put the `system.nanotime()` around the method to test and then run the program for 500 to 5000 iterations and then i move onto the next method and do the same. in this one i did the same but forgot to remove the 1000000000 / so like you said it was inverses. – Kyle Burns Dec 22 '15 at 20:34
the AI method actually runs at 240 nanoseconds and its my Snow_move method that's causing the issue. I'm not sure there is much i can do for it though because it has to move 20,000 flakes :) thanks for the help. even if i was a bit blinded :) – Kyle Burns Dec 22 '15 at 20:37
1

Watching snowflakes all day would make you snow blind ;-) Merry Christmas ;-) – Jan Dec 22 '15 at 20:43
merry Christmas to you too :) – Kyle Burns Dec 22 '15 at 21:23

Timing method causing code to run slow

1 Answers1