title: Multithreading with Java nanoTime
body: <p>I am currently programming a multithreaded program with Java. At some points different threads log their actions and I'm using <a href="http://docs.oracle.com/javase/7/docs/api/java/lang/System.html#nanoTime%28%29" rel="nofollow"><code>nanoTime</code></a> for this. Every thread has it's own log file and at the end I merge them and sort them based on their time (<code>nanoTime</code>) to see what happened. The thing is that I have erroneous behaviour similar to this where <code>x</code> is a <strong><code>volatile</code></strong> variable:</p>
  
  <pre><code>// logged by thead1
  x = true // done at time 0000, time computed &amp; logged after x = true was done
  
  // no events in between
  
  // logged by thread2
  read x // reads false while time before reading is 0001
  </code></pre>
  
  <p>So it seems to me that <code>nanoTime</code> doesn't really time things correctly.
  In <code>nanoTime</code> documentation it's written: </p>
  
  <blockquote>
    <p>The values returned by this method become meaningful only when the
    difference between two such values, obtained within the same instance
    of a Java virtual machine, is computed.</p>
  </blockquote>
  
  <p>Is it perhaps possible for threads created by the same process to be executed in different JVMs? This would explain the erroneous behaviour of <code>nanoTime</code> but still it doesn't make too much sense. Any ideas?</p>