Wednesday, October 13, 2010

Java ain't got no rhythm, but can it keep time?

I need sub-millisecond timing in Java; I want to measure events in the low microsecond range. What to do? My options seem to be:

  1. Use System.currentTimeMillis() and average over long numbers of runs; many problems here.
  2. Use System.nanoTime() and time individual events. Great, but the Javadoc is very scary for multi-threaded code.
  3. Try out sun.misc.Perf.highResCounter() (many non-official references for this.)
  4. Write our own JNI call for gettimeofday().

After months of hitting my head I wised up and looked into the JDK6 C++ source code. Surprise!

The C++ source

Drilling down points me to os::javaTimeNanos() (nanoTime), os::elapsed_counter() (highResCounter), and os::javaTimeMillis() (currentTimeMillis). On Linux these are:

System.currentTimeMillis()

jlong os::javaTimeMillis() {
  timeval time;
  int status = gettimeofday(&time, NULL);
  assert(status != -1, "linux error");
  return jlong(time.tv_sec) * 1000  +  jlong(time.tv_usec / 1000);
}

System.nanoTime()

jlong os::javaTimeNanos() {
  if (Linux::supports_monotonic_clock()) {
    struct timespec tp;
    int status = Linux::clock_gettime(CLOCK_MONOTONIC, &tp);
    assert(status == 0, "gettime error");
    jlong result = jlong(tp.tv_sec) * (1000 * 1000 * 1000) + jlong(tp.tv_nsec);
    return result;
  } else {
    timeval time;
    int status = gettimeofday(&time, NULL);
    assert(status != -1, "linux error");
    jlong usecs = jlong(time.tv_sec) * (1000 * 1000) + jlong(time.tv_usec);
    return 1000 * usecs;
  }
}

sun.misc.Perf.highResCounter()

jlong os::elapsed_counter() {
  timeval time;
  int status = gettimeofday(&time, NULL);
  return jlong(time.tv_sec) * 1000 * 1000 + jlong(time.tv_usec) - initial_time_count;
}

And:

void os::init(void) {
  char dummy;   /* used to get a guess on initial stack address */
//  first_hrtime = gethrtime();

  // With LinuxThreads the JavaMain thread pid (primordial thread)
  // is different than the pid of the java launcher thread.
  // So, on Linux, the launcher thread pid is passed to the VM
  // via the sun.java.launcher.pid property.
  // Use this property instead of getpid() if it was correctly passed.
  // See bug 6351349.
  pid_t java_launcher_pid = (pid_t) Arguments::sun_java_launcher_pid();

  _initial_pid = (java_launcher_pid > 0) ? java_launcher_pid : getpid();

  clock_tics_per_sec = sysconf(_SC_CLK_TCK);

  init_random(1234567);

  ThreadCritical::initialize();

  Linux::set_page_size(sysconf(_SC_PAGESIZE));
  if (Linux::page_size() == -1) {
    fatal1("os_linux.cpp: os::init: sysconf failed (%s)", strerror(errno));
  }
  init_page_sizes((size_t) Linux::page_size());

  Linux::initialize_system_info();

  // main_thread points to the aboriginal thread
  Linux::_main_thread = pthread_self();

  Linux::clock_init();
  initial_time_count = os::elapsed_counter();
  pthread_mutex_init(&dl_mutex, NULL);
}

(The net effect is to normalize to 0-time at JVM boot rather than the epoch.)

The solution

Just use System.nanoTime() and stop worrying so much. It is fine for microsecond timing—even across threads—just RTFM and ignore javadoc.

1 comment:

Ryan said...

The difference between a good developer and an ok developer is that the good developer knows to take the time to understand what's really going on.