Results 1 to 7 of 7
  1. #1
    Kobe is offline Member
    Join Date
    Aug 2011
    Posts
    4
    Rep Power
    0

    Default Time lost during time measuring

    Hi there

    I'd like to measure some times and during encountered a problem: Somehow some time is out of my measurement and I don't know where it has gone to. Maybe you know where?

    Java Code:
    public class TestClass {
    
        static long timer1 = 0;
    
        static long timer2 = 0;
    
        static long timer3 = 0;
    
        public static void main(String[] args) {
            int max = 1;
            for (int i = 0; i < 31; i++) {
                doTimerTest(max);
                timer1 = timer2 = timer3 = 0;
                max = max << 1;
            }
        }
    
        private static void doTimerTest(int max) {
            for (int j = 0; j < max; j++) {
                myTime();
            }
            System.out.println(max + " : " + timer1 + " + " + timer2 + " ~= " + timer3);
        }
    
        static void myTime() {
            long start1 = System.currentTimeMillis();
            timer1 += System.currentTimeMillis() - start1;
            long start2 = System.currentTimeMillis();
            timer2 += System.currentTimeMillis() - start2;
            timer3 += System.currentTimeMillis() - start1;
        }
    
    }
    The ouput is
    1 : 0 + 0 ~= 0
    2 : 0 + 0 ~= 0
    4 : 0 + 0 ~= 0
    8 : 0 + 0 ~= 0
    16 : 0 + 0 ~= 0
    32 : 1 + 0 ~= 1
    64 : 0 + 0 ~= 0
    128 : 0 + 0 ~= 0
    256 : 0 + 0 ~= 0
    512 : 0 + 1 ~= 1
    1024 : 1 + 0 ~= 2
    2048 : 1 + 3 ~= 5
    4096 : 5 + 2 ~= 11
    8192 : 5 + 2 ~= 15
    16384 : 8 + 6 ~= 32
    32768 : 12 + 16 ~= 72
    65536 : 40 + 38 ~= 143
    131072 : 83 + 57 ~= 271
    262144 : 151 + 159 ~= 550
    524288 : 275 + 264 ~= 1086
    1048576 : 581 + 555 ~= 2250
    2097152 : 1159 + 1191 ~= 4599
    4194304 : 2241 + 2297 ~= 9151
    8388608 : 4553 + 4568 ~= 18147
    16777216 : 9035 + 9079 ~= 36263
    33554432 : 18265 + 18519 ~= 73520
    67108864 : 36313 + 36788 ~= 146318
    ...
    You can see each time increases in (about) the factor 2. But actually the summands must be (almost) equal to the sum, don't they??

    The lost time is even more if I use System.nanoTime().

    Regards
    Kobe

  2. #2
    Tolls is offline Moderator
    Join Date
    Apr 2009
    Posts
    11,945
    Rep Power
    19

    Default

    What are you expecting here?

  3. #3
    Kobe is offline Member
    Join Date
    Aug 2011
    Posts
    4
    Rep Power
    0

    Default

    I expect timer1+timer2 ~= timer3 but it is timer1 + timer2 ~= timer3/2

  4. #4
    Tolls is offline Moderator
    Join Date
    Apr 2009
    Posts
    11,945
    Rep Power
    19

    Default

    Because of the resolution of the call to getTimeInMillis means that the timer3 result includes any missing ticks inbetween these two lines:
    Java Code:
            timer1 += System.currentTimeMillis() - start1;
            long start2 = System.currentTimeMillis();
    and also these two:
    Java Code:
            timer2 += System.currentTimeMillis() - start2;
            timer3 += System.currentTimeMillis() - start1;

  5. #5
    Kobe is offline Member
    Join Date
    Aug 2011
    Posts
    4
    Rep Power
    0

    Default

    So that means System.currentTimeMillis() has taken my lost time. But what does happen in this method that takes so long?

  6. #6
    Tolls is offline Moderator
    Join Date
    Apr 2009
    Posts
    11,945
    Rep Power
    19

    Default

    Not just that method call (though that will be part of it), but after the second System.currentTimeMillis() call there are 2 commands before the items are subtracted, at any one of which the millisecond count could tick over. Then there are a couple more prior to the next call to System.currentTimeMillis() (for start2). And so on.

    Look at the byte code to see what I mean.

    There is almost as much going on after the attempt to calculate the time as there is during it.

    Here's a sample:
    Java Code:
    invokestatic (System.currentTimeMillis())
    lstore_0
    getstatic (timer1)
    invokestatic (System.currentTimeMillis()) // this is your timing point but ...
    lload_0
    lsub // You don't subtract until here  then...
    ladd
    putstatic (timer1) // You do the above and this bit before ...
    invokestatic (System.currentTimeMillis())    // getting the next time stamp
    .. and so on.

  7. #7
    Kobe is offline Member
    Join Date
    Aug 2011
    Posts
    4
    Rep Power
    0

Similar Threads

  1. Replies: 3
    Last Post: 08-23-2011, 12:46 PM
  2. calculate time diff for particular time period
    By baktha.thalapathy in forum New To Java
    Replies: 2
    Last Post: 05-24-2010, 04:10 PM
  3. Class Time - represents time of day
    By verbazon in forum New To Java
    Replies: 1
    Last Post: 04-13-2009, 01:06 AM
  4. measuring time in nano seconds
    By Java Tip in forum Java Tip
    Replies: 0
    Last Post: 11-06-2007, 12:11 PM
  5. measuring time in millsecond
    By Java Tip in forum Java Tip
    Replies: 0
    Last Post: 11-06-2007, 12:05 PM

Posting Permissions

  • You may not post new threads
  • You may not post replies
  • You may not post attachments
  • You may not edit your posts
  •