Java-Gaming.org    
Featured games (79)
games approved by the League of Dukes
Games in Showcase (475)
Games in Android Showcase (106)
games submitted by our members
Games in WIP (530)
games currently in development
News: Read the Java Gaming Resources, or peek at the official Java tutorials
 
    Home     Help   Search   Login   Register   
Pages: [1]
  ignore  |  Print  
  JVM reports timer taking longer than it should...  (Read 2047 times)
0 Members and 1 Guest are viewing this topic.
Offline westloar

Junior Member





« Posted 2011-04-19 19:22:35 »

I posted not too long ago with code for a timer (that counts to 25s) which was broken, I fixed the issues, but now the JVM reports it taking longer (1 second longer) than it should run for, although the code prints out the time taken, which reports that it works fine, here's the code:

1  
2  
3  
4  
5  
6  
7  
8  
9  
10  
11  
12  
13  
14  
15  
16  
17  
18  
19  
20  
21  
22  
23  
24  
25  
26  
27  
28  
29  
30  
31  
32  
33  
34  
35  
36  
37  
38  
39  
40  
41  
42  
43  
44  
45  
46  
 
public static void main(String[] args) {
        Runnable ticker = new Timer();
        Thread t = new Thread(ticker);
        t.start();
    }

}

class Timer implements Runnable {
    long oneClock;
    long twoClock;
    int gameLength = 26; //+1 of required time (zeroth degree)
   long diff;
    long beforeTime;
    long afterTime;
    long realTime;
    boolean loop = false;

   public void run () {
        beforeTime = System.nanoTime()/1000000000;
        while (gameLength > 0){
            oneClock = System.nanoTime()/1000000000;
            loop = true;
           
            while (loop) {

                try {
                Thread.sleep(10); } catch (InterruptedException ex) {ex.printStackTrace(); }
                twoClock = System.nanoTime()/1000000000;

                diff = twoClock - oneClock;
                if (diff >= 1) {
                gameLength -= diff;
                System.out.println (this.gameLength) ;
                loop = false;
                } //second while close
           }
       } // 1st while close

        afterTime = System.nanoTime()/1000000000;
        realTime = afterTime - beforeTime;
        System.out.println("The end of the clock");
        System.out.println("The clock took" + realTime + "seconds to finish");
    }
}


the result is:
1  
2  
3  
4  
5  
6  
7  
8  
9  
10  
11  
12  
13  
14  
15  
16  
17  
18  
19  
20  
21  
22  
23  
24  
25  
26  
27  
28  
29  
30  
run:
25
24
23
22
21
20
19
18
17
16
15
14
13
12
11
10
9
8
7
6
5
4
3
2
1
0
The end of the clock
The clock took26seconds to finish
BUILD SUCCESSFUL (total time: 26 seconds)


if you can point out the obvious mistake I'll give you a virtual sticker, especially because it's not obvious to me Smiley
Offline Captain Awesome

Junior Member


Medals: 2


Hi


« Reply #1 - Posted 2011-04-19 20:29:00 »

I have read your code and if I'm correct, every second gameLength is subtracted by one and then sent to System.out.println().
The gameLength has been outputted 26 times which means that is has taken 26 seconds to complete. Why isn't gameLength starting at 25 like it should?
Offline westloar

Junior Member





« Reply #2 - Posted 2011-04-19 23:38:11 »

changing the gamelength to 25 confusingly means the program runs for 24 seconds :|
Games published by our own members! Check 'em out!
Legends of Yore - The Casual Retro Roguelike
Offline Captain Awesome

Junior Member


Medals: 2


Hi


« Reply #3 - Posted 2011-04-20 02:42:05 »

Huh, that's kinda weird. I'll try to run the code and see what happens
Offline philfrei
« Reply #4 - Posted 2011-04-20 06:01:58 »

?!

One second is consumed before 25 is printed, yes?
And 1 second before 1 is printed (after 2), yes?

So, all the way from 25 to 1 is 25 seconds (one second per number). Then you spend another second progressing down to 0.

Classic "off by one" error?

"Greetings my friends! We are all interested in the future, for that is where you and I are going to spend the rest of our lives!" -- The Amazing Criswell
Offline westloar

Junior Member





« Reply #5 - Posted 2011-04-20 14:04:51 »

after reading your posts I just wanted to double check that changing the gameLength didn't priduce the right results, it doesn't.

Changing it to 25 makes the clock run for 24 seconds.

Changing it to 26 makes it run for 26.

Can someone please tell me what's going on here!?
Online Riven
« League of Dukes »

JGO Overlord


Medals: 742
Projects: 4
Exp: 16 years


Hand over your head.


« Reply #6 - Posted 2011-04-20 15:16:59 »

Rounding way too soon...
oneClock = System.nanoTime()/1000000000;
twoClock = System.nanoTime()/1000000000;

You should never round it, until you print and even then you might want to round to millis, not seconds.

Hi, appreciate more people! Σ ♥ = ¾
Learn how to award medals... and work your way up the social rankings
Offline westloar

Junior Member





« Reply #7 - Posted 2011-04-20 15:21:49 »

surely it doesn't matter when I round it as the variable remains the same until the next iteration of the loop? So rounding it at the beggining or the end of the loop wouldn't make a difference?
Offline philfrei
« Reply #8 - Posted 2011-04-20 21:42:44 »

I ran your code with 25 and it takes 26.
I ran your code with 24 and it takes 25.

Copying the code to Eclipse was a little messy as it did not cut-and-paste into my system cleanly. I moved a few things around a bit but I think I did so accurately, didn't change the way the code functions. You can check my listing and output.

1  
2  
3  
4  
5  
6  
7  
8  
9  
10  
11  
12  
13  
14  
15  
16  
17  
18  
19  
20  
21  
22  
23  
24  
25  
26  
27  
28  
29  
30  
31  
32  
33  
34  
35  
36  
37  
38  
39  
40  
41  
42  
43  
44  
45  
46  
47  
48  
49  
50  
51  
52  
package westloar;

public class Timer implements Runnable
{
    long oneClock;
    long twoClock;
    int gameLength = 25; //+1 of required time (zeroth degree)    
   long diff;    
    long beforeTime;    
    long afterTime;    
    long realTime;    
    boolean loop = false;  
 
    public static void main(String[] args)
    {
   Runnable ticker = new Timer();
   Thread t = new Thread(ticker);
   t.start();  
    }
   
    public void run ()
    {
       beforeTime = System.nanoTime()/1000000000;
       while (gameLength > 0)
       {
          oneClock = System.nanoTime()/1000000000;
          loop = true;
          while (loop)
          {
             try
             {
                Thread.sleep(10);
             }
             catch (InterruptedException ex) {
                ex.printStackTrace();
             }
             twoClock = System.nanoTime()/1000000000;
             diff = twoClock - oneClock;
             if (diff >= 1)
             {
                gameLength -= diff;
                System.out.println (this.gameLength) ;
                loop = false;
             } //second while close                  
         } // 1st while close        
      }
   afterTime = System.nanoTime()/1000000000;
   realTime = afterTime - beforeTime;
   System.out.println("The end of the clock");        
   System.out.println("The clock took" + realTime + "seconds to finish");    
    }
}


Quote
24
23
22
21
20
19
18
17
16
15
14
13
12
11
10
9
8
7
6
5
4
3
2
1
0
The end of the clock
The clock took25seconds to finish

"Greetings my friends! We are all interested in the future, for that is where you and I are going to spend the rest of our lives!" -- The Amazing Criswell
Offline philfrei
« Reply #9 - Posted 2011-04-20 22:06:45 »

I just wanted to add, (and the previous post was getting rather long) that if there is some sort of timing creep, I think it must be happening with the setting of the variable oneClock.

Potentially, each time you set it, it might have slipped as much as 10msec (timer increment) plus any residual time that the timer might consume. I've seen some places where a timer is set to X but the actual value comes out to X+4msec, give or take a little. Also, the time taken to execute the loop will be part of the slip.

So let's see, 25 x 15 msecs gives 375 msecs, yes? That's not quite enough for a full second's slippage, but maybe that is a good start in trying to find it. (Other comments about rounding & such may also be relevent.)

In any case, I think you should tie your timer tests to the first "beforeTime" rather than "oneClock". Thus, instead of "diff = twoClock - oneClock;" do this sort of thing:

1  
2  
3  
4  
5  
6  
7  
8  
9  
10  
11  
12  
13  
14  
int i;
while (loop)
    {
        try
        {
            Thread.sleep(10);
        }
        catch (InterruptedException ex)
        {
            ex.printStackTrace();
        }
        twoClock = System.nanoTime()/1000000000;
        diff = twoClock - ( beforeTime +  i++ );;
        if (diff >= 1)


This way, if there is slippage, at least it won't "accumulate".
Hope that helps!

"Greetings my friends! We are all interested in the future, for that is where you and I are going to spend the rest of our lives!" -- The Amazing Criswell
Games published by our own members! Check 'em out!
Legends of Yore - The Casual Retro Roguelike
Offline philfrei
« Reply #10 - Posted 2011-04-20 22:37:40 »

Back again after testing my fix.  Sad

For the code to work, the declaration of int i = 1; has to happen right with the setting of "beforeTime" and only be incremented as part of the outer while loop.

But the principle remains the same. Tie you testing to a single moment in time.

details... Tongue

"Greetings my friends! We are all interested in the future, for that is where you and I are going to spend the rest of our lives!" -- The Amazing Criswell
Offline Roquen
« Reply #11 - Posted 2011-04-21 07:57:59 »

Rounding way too soon...

That's generous.  I'd call it tossing way most of the significant information.  Smiley
Offline westloar

Junior Member





« Reply #12 - Posted 2011-04-21 20:47:59 »

cheers Philfrei, that's really helpful and makes a lot of sense to compare it to a static point in time
Rounding way too soon...

That's generous.  I'd call it tossing way most of the significant information.  Smiley

losing information isn't a problem if you're not using it and in a larger application has memory advantages...
Offline westloar

Junior Member





« Reply #13 - Posted 2011-04-22 00:43:33 »

ok so using a static time to test with works, but setting gameLength to 25 still produces 26 secs whereas setting it to 24 actually produces 25 now Smiley

but still,doesn't work properly, I'm using netbeans IDE, any known problems with that?
Offline philfrei
« Reply #14 - Posted 2011-04-22 03:13:13 »

On you first output, you printed 25..0. That's 26 numbers. Each one took a second, because you print numbers after sleeping.

Classic "off by one" error. I have a special fondness for them. They always remind me of the wedding card we got from my father: "Happy 0th Anniversary!"

"Greetings my friends! We are all interested in the future, for that is where you and I are going to spend the rest of our lives!" -- The Amazing Criswell
Offline loom_weaver

JGO Coder


Medals: 17



« Reply #15 - Posted 2011-04-22 06:59:25 »

cheers Philfrei, that's really helpful and makes a lot of sense to compare it to a static point in time
Rounding way too soon...

That's generous.  I'd call it tossing way most of the significant information.  Smiley

losing information isn't a problem if you're not using it and in a larger application has memory advantages...

Heh, but it does matter if you want your program to calculate correct results.  When it comes to numbers, precision, etc. Roquen may be terse but he knows his stuff.

To the original poster, don't do any of the dividing until you're ready to calculate your final result and definitely don't divide any values you intend to accumulate.
Offline Roquen
« Reply #16 - Posted 2011-04-22 14:43:17 »

I frequently make posts when I'm in a rush (heavy round-off error).  I hope that someone will read my mind and translate what I'm saying...and sometimes it works!  For those who wish to test their mind reading skills what I (and Riven) meant was:

Digitial clocks are (effectively) square waves.  Their associated counters track how many transistions (a stairstep function WRT time) that have occured (taking into account any overflow) since it was last reset.  So when you pretend that a given counter measures realtime, you have to remember that your result has an error bound of twice (+/-1) of the resolution.  By dividing first, you effectively divide the clock frequency, so if you divide down to one second resoultion, then the error WRT to realtime is +/- 1 second.  That's what I meant by:  "tossing way most of the significant information"  Using two of these as timestamps compounds the error of the two samples.

Example of the error range (using milliseconds for shortness)
1  
2  
3  
4  
5  
6  
7  
8  
9  
    int t0= 999;
    int t1=1000;
    int t2=1999;
    int a0 = t0/1000;
    int a1 = t1/1000;
    int a2 = t2/1000;
   
    System.out.printf("%d %d %d\n", a1, a1-a0, (t1-t0+500)/1000);
    System.out.printf("%d %d %d\n", a2, a2-a1, (t2-t1+500)/1000);


Dividing early gives more importance to the exact values of the low bits that your throwing away.
Offline westloar

Junior Member





« Reply #17 - Posted 2011-06-05 23:31:34 »

sorry for the late reply Roquen, haven't been back to this site for a while, joys of being a father Smiley

thanks for that explanation, that makes a lot of sense and I wasn't aware of that so cheers Smiley
Offline cylab

JGO Ninja


Medals: 38



« Reply #18 - Posted 2011-06-06 08:57:41 »

sorry for the late reply Roquen, haven't been back to this site for a while, joys of being a father Smiley

Smiley Have a good time! We celebrated the first birthday of my daughter yesterday.  Cheesy

Mathias - I Know What [you] Did Last Summer!
Pages: [1]
  ignore  |  Print  
 
 
You cannot reply to this message, because it is very, very old.

 

Add your game by posting it in the WIP section,
or publish it in Showcase.

The first screenshot will be displayed as a thumbnail.

ctomni231 (33 views)
2014-07-18 06:55:21

Zero Volt (29 views)
2014-07-17 23:47:54

danieldean (24 views)
2014-07-17 23:41:23

MustardPeter (26 views)
2014-07-16 23:30:00

Cero (41 views)
2014-07-16 00:42:17

Riven (43 views)
2014-07-14 18:02:53

OpenGLShaders (31 views)
2014-07-14 16:23:47

Riven (30 views)
2014-07-14 11:51:35

quew8 (29 views)
2014-07-13 13:57:52

SHC (65 views)
2014-07-12 17:50:04
HotSpot Options
by dleskov
2014-07-08 03:59:08

Java and Game Development Tutorials
by SwordsMiner
2014-06-14 00:58:24

Java and Game Development Tutorials
by SwordsMiner
2014-06-14 00:47:22

How do I start Java Game Development?
by ra4king
2014-05-17 11:13:37

HotSpot Options
by Roquen
2014-05-15 09:59:54

HotSpot Options
by Roquen
2014-05-06 15:03:10

Escape Analysis
by Roquen
2014-04-29 22:16:43

Experimental Toys
by Roquen
2014-04-28 13:24:22
java-gaming.org is not responsible for the content posted by its members, including references to external websites, and other references that may or may not have a relation with our primarily gaming and game production oriented community. inquiries and complaints can be sent via email to the info‑account of the company managing the website of java‑gaming.org
Powered by MySQL Powered by PHP Powered by SMF 1.1.18 | SMF © 2013, Simple Machines | Managed by Enhanced Four Valid XHTML 1.0! Valid CSS!