The Source for Java Technology Collaboration
User: Password:



Michael Nascimento Santos

Michael Nascimento Santos's Blog

Playing with the Tiger: Measuring nanos

Posted by mister__m on February 05, 2004 at 06:41 PM | Comments (10)

Ok, sorry for not blogging for so long, but I have to work, date etc. :-D

I hope this is the start of a series of small, but informative blog entries about new features available in Tiger, especially the ones a hundred people haven't mentioned before me :-D

To begin with, I'll show you how to use the new nanoTime() method in System. An important thing to notice is that nanoTime()'s return and currentTimeMillis's are not necessarily related to each other - meaning they don't have to use the same reference to zero. This example also uses the new static import feature. I am not saying I like it or not. That's what I expect you to say.

Here's the code:

import static java.lang.System.*;

public class Nano {
   public static void main(String[] args) {
      long time = 0;
      long newTime;
      long smaller = 9999999999999L;

      for (int i = 0; i < 100000; i++) {
         time = nanoTime();
         newTime = nanoTime();

         smaller = Math.min(smaller, newTime - time);
      }

      out.println("Smallest nano interval measured: " + smaller);
      out.println("Current time millis: " + currentTimeMillis());
      out.println("Nano time: " + nanoTime());
   }
}

Save it in Nano.java and compile it with:

javac -source 1.5 Nano.java

Then run it normally with:

java -cp . Nano

My results (P4, 1GB RAM, Windows 2000 Pro) are:

Smallest nano interval measured: 1116
Current time millis: 1076038988125
Nano time: 8736336585045

This method is intended to be used as a way to measure performance, for instance. Here, I just tried to get its precision in my current box configuration.

Please let me know if you get smallest nano intervals in your platform/configuration. See you soon ;-)


Bookmark blog post: del.icio.us del.icio.us Digg Digg DZone DZone Furl Furl Reddit Reddit
Comments
Comments are listed in date ascending order (oldest first) | Post Comment

  • Linux
    Here on Gentoo Linux, I get a smallest time of 1000 nanoseconds every time.

    I think when you use static import like you did, it looks bad, but I think if you static import specific methods of static utility classes like Math or SwingConstants, it can make the code look less cluttered. (I don't consider System a class whose static imports look nice.)

    Posted by: keithkml on February 05, 2004 at 09:28 PM

  • In the words of Mermaidman...
    EEEEEEvvvvviiiiilllll

    Posted by: robertx on February 06, 2004 at 06:52 AM

  • Behavior on My Linux Box
    The smallest nano second interval that I was able to measure was 1000 every time on my Linux box too. I'm using Red Hat 9.0.

    Also, I have mixed feelings about the static import. I do think it would be a mistake to statically import * from a class, too much chance for ambiguous method references. However, I like being able to statically import System.out so that shortens the calls to out.println(...). It does look like it could introduce more problems than it solves in terms of code maintainability.

    Warren

    Posted by: wthomp6984 on February 06, 2004 at 08:28 AM

  • static import is not for this.
    i thought static import should not be used like this. It looks "ok" only in constants and math libraries. Even then, i think statics are more evil than blessing..

    Posted by: ahmetaa on February 06, 2004 at 12:12 PM

  • Timer resolution?
    We don't have J2SE 1.5 on Mac OS X yet, so I wrote my own nanoTime() method (below) using Sun's performance measurement class.

    One thing I've noticed is that I obtain 2x better clock resolution when I compute elapsed CPU time directly from clock ticks because the conversion from ticks to nanoseconds requires one multiply and one divide (before the compiler optimizes my code).

    Could someone please test the program below under Java 1.5 and tell me how the resolution of my nanoTime() method compares with the new System.nanoTime() method? Set the BEST variable to false and change the 2 timer.nanoTime() calls in getResolution() to System.nanoTime().

    Currently, with BEST = true, I am getting a time resolution of 440 nanoseconds on Mac OS X (old 400 MHz G3 iMac).

    Thank you!
    Craig

    [code]
    // Test Sun's performance measurement clock

    import sun.misc.Perf;
    import java.text.DecimalFormat;

    public class TestTimer
    {
    HiResTimer timer;

    public TestTimer()
    {
    long before, after, cputime; // CPU timing variables

    DecimalFormat sci = new DecimalFormat("##0.###E0");

    timer = new HiResTimer();

    System.out.println("Counter frequency : " + sci.format(timer.getFrequency()) + " Hz (ticks/sec)");
    System.out.println("Time per clock tick : " + timer.getTickTime() + " nanoseconds");
    System.out.println("Counter resolution : " + timer.getCounterResolution() + " clock ticks");
    System.out.println("Avg. counter resolution: " + timer.getAvgCounterResolution() + " clock ticks");
    System.out.println("Time resolution : " + timer.getResolution() + " nanoseconds");

    System.out.println("Sleeping for 3 seconds . . .");
    before = System.currentTimeMillis(); // timer.milliTime();
    snooze();
    after = System.currentTimeMillis(); // timer.milliTime();
    cputime = after - before;
    System.out.println("Sleep time of 3 seconds measured as: " + cputime + " milliseconds");

    System.out.println("Sleeping again for 3 seconds . . .");
    before = timer.nanoTime(); // System.nanoTime();
    snooze();
    after = timer.nanoTime(); // System.nanoTime();
    cputime = after - before;
    System.out.println("Sleep time of 3 seconds measured as: " + cputime + " nanoseconds");

    System.out.println("Sleeping yet again for 3 seconds . . .");
    before = timer.getTicks();
    snooze();
    after = timer.getTicks();
    cputime = timer.nsFromTicks(after - before);
    System.out.println("Sleep time of 3 seconds measured as: " + cputime + " nanoseconds from ticks");
    }

    // Sleep 3 seconds
    private final void snooze()
    {
    try
    {
    Thread.sleep(3000);
    }
    catch ( Exception x )
    {
    x.printStackTrace();
    }
    }

    public static void main(String[] args)
    {
    new TestTimer();
    }

    // Inner class for high-rez timing measurements
    public class HiResTimer
    {
    private Perf hiResTimer;
    private long freq;

    private int LOOPS;
    private boolean BEST;

    public HiResTimer()
    {
    hiResTimer = Perf.getPerf();
    freq = hiResTimer.highResFrequency();

    LOOPS = 1000000;
    BEST = true; // Toggle for clock ticks ns
    }

    // return current time in milliseconds
    public long milliTime()
    {
    return (hiResTimer.highResCounter() * 1000L / freq);
    // return (hiResTimer.highResCounter() / ((freq + 500L) / 1000L));
    }

    // return current time in nanoseconds
    public long nanoTime()
    {
    return (hiResTimer.highResCounter() * 1000000000L / freq);
    }

    // return the current clock ticks
    public long getTicks()
    {
    return hiResTimer.highResCounter();
    }

    // return the number of clock ticks per second
    public long getFrequency()
    {
    return freq;
    }

    // return the number of nanoseconds per clock tick
    public long getTickTime()
    {
    return (1000000000L/freq);
    }

    // convert clock ticks to nanoseconds
    public long nsFromTicks(long ticks)
    {
    return (ticks * 1000000000L / freq);
    }

    // Error expected in measured elapsed time (in nanoseconds)
    public long getResolution()
    {
    long before = 0L;
    long after = 0L;
    long smallest = Long.MAX_VALUE;

    if (BEST)
    {
    // Compute using clock ticks
    for (int i=0; i ns
    }
    else
    {
    // Compute using nanoseconds
    for (int i=0; i<LOOPS; ++i)
    {
    before = nanoTime(); // System.nanoTime();
    after = nanoTime(); // System.nanoTime();
    smallest = Math.min(smallest, after - before);
    }
    return (smallest);
    }
    }

    public long getCounterResolution()
    {
    long before = 0L;
    long after = 0L;
    long smallest = Long.MAX_VALUE;

    for (int i=0; i<LOOPS; ++i)
    {
    before = hiResTimer.highResCounter();
    after = hiResTimer.highResCounter();

    smallest = Math.min(smallest, after - before);
    }
    return smallest;
    }

    // Avg error expected in measured elapsed time (in clock ticks)
    public long getAvgCounterResolution()
    {
    long before = 0L;
    long after = 0L;
    long dt = 0L;

    // Warm up JIT/HotSpot compiler
    // for (int i=0; i<LOOPS; ++i)
    // before = hiResTimer.highResCounter();

    for (int i=0; i<LOOPS; ++i)
    {
    // before = after = hiResTimer.highResCounter();
    // while (before == after)
    // after = hiResTimer.highResCounter();

    before = hiResTimer.highResCounter();
    after = hiResTimer.highResCounter();

    dt += (after - before);
    }
    return Math.round((double)dt/LOOPS);
    }
    } // End HiResTimer inner class

    } // End TestTimer class
    [/code]

    Posted by: mattocks on February 06, 2004 at 07:25 PM

  • Re: Timer resolution?
    Sorry, browser mangled part of the code. Try again:


    // Test Sun's performance measurement clock

    import sun.misc.Perf;
    import java.text.DecimalFormat;

    public class TestTimer
    {
    HiResTimer timer;

    public TestTimer()
    {
    long before, after, cputime; // CPU timing variables

    DecimalFormat sci = new DecimalFormat("##0.###E0");

    timer = new HiResTimer();

    System.out.println("Counter frequency : " + sci.format(timer.getFrequency()) + " Hz (ticks/sec)");
    System.out.println("Time per clock tick : " + timer.getTickTime() + " nanoseconds");
    System.out.println("Counter resolution : " + timer.getCounterResolution() + " clock ticks");
    System.out.println("Avg. counter resolution: " + timer.getAvgCounterResolution() + " clock ticks");
    System.out.println("Time resolution : " + timer.getResolution() + " nanoseconds");

    System.out.println("Sleeping for 3 seconds . . .");
    before = System.currentTimeMillis(); // timer.milliTime();
    snooze();
    after = System.currentTimeMillis(); // timer.milliTime();
    cputime = after - before;
    System.out.println("Sleep time of 3 seconds measured as: " + cputime + " milliseconds");

    System.out.println("Sleeping again for 3 seconds . . .");
    before = timer.nanoTime(); // System.nanoTime();
    snooze();
    after = timer.nanoTime(); // System.nanoTime();
    cputime = after - before;
    System.out.println("Sleep time of 3 seconds measured as: " + cputime + " nanoseconds");

    System.out.println("Sleeping yet again for 3 seconds . . .");
    before = timer.getTicks();
    snooze();
    after = timer.getTicks();
    cputime = timer.nsFromTicks(after - before);
    System.out.println("Sleep time of 3 seconds measured as: " + cputime + " nanoseconds from ticks");
    }

    // Sleep 3 seconds
    private final void snooze()
    {
    try
    {
    Thread.sleep(3000);
    }
    catch ( Exception x )
    {
    x.printStackTrace();
    }
    }

    public static void main(String[] args)
    {
    new TestTimer();
    }

    // Inner class for high-rez timing measurements
    public class HiResTimer
    {
    private Perf hiResTimer;
    private long freq;

    private int LOOPS;
    private boolean BEST;

    public HiResTimer()
    {
    hiResTimer = Perf.getPerf();
    freq = hiResTimer.highResFrequency();

    LOOPS = 1000000;
    BEST = true; // Toggle for clock ticks ns
    }

    // return current time in milliseconds
    public long milliTime()
    {
    return (hiResTimer.highResCounter() * 1000L / freq);
    // return (hiResTimer.highResCounter() / ((freq + 500L) / 1000L));
    }

    // return current time in nanoseconds
    public long nanoTime()
    {
    return (hiResTimer.highResCounter() * 1000000000L / freq);
    }

    // return the current clock ticks
    public long getTicks()
    {
    return hiResTimer.highResCounter();
    }

    // return the number of clock ticks per second
    public long getFrequency()
    {
    return freq;
    }

    // return the number of nanoseconds per clock tick
    public long getTickTime()
    {
    return (1000000000L/freq);
    }

    // convert clock ticks to nanoseconds
    public long nsFromTicks(long ticks)
    {
    return (ticks * 1000000000L / freq);
    }

    // Error expected in measured elapsed time (in nanoseconds)
    public long getResolution()
    {
    long before = 0L;
    long after = 0L;
    long smallest = Long.MAX_VALUE;

    if (BEST)
    {
    // Compute using clock ticks
    for (int i=0; i ns
    }
    else
    {
    // Compute using nanoseconds
    for (int i=0; i

    Posted by: mattocks on February 06, 2004 at 07:32 PM

  • Re: Measuring nanos
    I copied and pasted your code and ran it and I got 0 for the smallest interval. But the nanoTime() consitently returned a number with three zeros at the end. So like others I would say the smallest interval is 1000. I am running Redhat Fedora Core1 on a P4 2.4 Ghz.

    Posted by: dann on February 06, 2004 at 08:23 PM

  • Ew
    You've managed to find the worst possible way to use static import. Congratulations.

    Posted by: gafter on February 08, 2004 at 12:36 PM

  • Please have a minimum standard
    Guys,

    Please have a minimum standard while posting the content. You do not want to post "cheezy" stuff and lose name (both the Author and the website).

    When i looked at this post, I was expecting a through performance comparison between various versions of the Sun JDK over different platforms.

    I hope this "series" does not continue. Sorry if I am being rude, but this is outrageous.

    Dushy

    Posted by: dushy13 on February 08, 2004 at 05:06 PM

  • Re: Please have a minimum standard
    Have I ever said the code looked fine? No, I clearly said: I am not saying if it's good or not. And do you know why I wrote this code? I wanted to get reactions from Java developers about static import. Expect to see even more hideous uses of this new feature, because, as I say, everything that compiles eventually shows in source code.

    Sorry if you were looking for a performance comparison, but there's nothing nowhere that indicates that this post is about it.

    This series is about playing with the Tiger, exploring things other articles on the web don't - such as bad uses of static import. I am not here to say this code is good, as I said. This is something I expected you to say. However, as most of you got the impression I liked the way this code is written, let me make it clear: this code sucks. The nanoTime() stuff is cool, the static import is not. Not at all. It's ugly, smelly and would probably never hire someone who writes this code of code.

    Hope you get the intent better ;-) Keep on ranting - or not - about it.

    Posted by: mister__m on February 09, 2004 at 02:37 AM





Powered by
Movable Type 3.01D
 Feed java.net RSS Feeds