You are viewing a plain text version of this content. The canonical link for it is here.
Posted to notifications@jakarta.apache.org by se...@apache.org on 2010/11/23 00:18:06 UTC

svn commit: r1037933 - in /jakarta/jmeter/trunk: bin/ src/core/org/apache/jmeter/control/ src/core/org/apache/jmeter/samplers/ test/src/org/apache/jmeter/samplers/ xdocs/

Author: sebb
Date: Mon Nov 22 23:18:05 2010
New Revision: 1037933

URL: http://svn.apache.org/viewvc?rev=1037933&view=rev
Log:
System.nanoTime() tends to drift relative to System.currentTimeMillis().
Change SampleResult to recalculate offset each time.
Also enable reversion to using System.currentTimeMillis() only.

Modified:
    jakarta/jmeter/trunk/bin/jmeter.properties
    jakarta/jmeter/trunk/src/core/org/apache/jmeter/control/TransactionSampler.java
    jakarta/jmeter/trunk/src/core/org/apache/jmeter/samplers/SampleResult.java
    jakarta/jmeter/trunk/test/src/org/apache/jmeter/samplers/TestSampleResult.java
    jakarta/jmeter/trunk/xdocs/changes.xml

Modified: jakarta/jmeter/trunk/bin/jmeter.properties
URL: http://svn.apache.org/viewvc/jakarta/jmeter/trunk/bin/jmeter.properties?rev=1037933&r1=1037932&r2=1037933&view=diff
==============================================================================
--- jakarta/jmeter/trunk/bin/jmeter.properties (original)
+++ jakarta/jmeter/trunk/bin/jmeter.properties Mon Nov 22 23:18:05 2010
@@ -375,6 +375,9 @@ log_level.jorphan=INFO
 # This also affects the timestamp stored in result files
 sampleresult.timestamp.start=true
 
+# Whether to use System.nanoTime() - otherwise only use System.currentTimeMillis()
+#sampleresult.useNanoTime=true
+
 #---------------------------------------------------------------------------
 # Upgrade property
 #---------------------------------------------------------------------------

Modified: jakarta/jmeter/trunk/src/core/org/apache/jmeter/control/TransactionSampler.java
URL: http://svn.apache.org/viewvc/jakarta/jmeter/trunk/src/core/org/apache/jmeter/control/TransactionSampler.java?rev=1037933&r1=1037932&r2=1037933&view=diff
==============================================================================
--- jakarta/jmeter/trunk/src/core/org/apache/jmeter/control/TransactionSampler.java (original)
+++ jakarta/jmeter/trunk/src/core/org/apache/jmeter/control/TransactionSampler.java Mon Nov 22 23:18:05 2010
@@ -117,7 +117,7 @@ public class TransactionSampler extends 
         }
         // Bug 50080 (not include pause time when generate parent)
         if (!transactionController.isIncludeTimers()) {
-            long end = SampleResult.currentTimeInMs();
+            long end = transactionSampleResult.currentTimeInMillis();
             transactionSampleResult.setIdleTime(end
                     - transactionSampleResult.getStartTime() - totalTime);
             transactionSampleResult.setEndTime(end);

Modified: jakarta/jmeter/trunk/src/core/org/apache/jmeter/samplers/SampleResult.java
URL: http://svn.apache.org/viewvc/jakarta/jmeter/trunk/src/core/org/apache/jmeter/samplers/SampleResult.java?rev=1037933&r1=1037932&r2=1037933&view=diff
==============================================================================
--- jakarta/jmeter/trunk/src/core/org/apache/jmeter/samplers/SampleResult.java (original)
+++ jakarta/jmeter/trunk/src/core/org/apache/jmeter/samplers/SampleResult.java Mon Nov 22 23:18:05 2010
@@ -160,12 +160,6 @@ public class SampleResult implements Ser
     private String dataEncoding;// (is this really the character set?) e.g.
                                 // ISO-8895-1, UTF-8
 
-    // a reference time from the nanosecond clock
-    private static final long referenceTimeNsClock = sampleNsClockInMs();
-
-    // a reference time from the millisecond clock
-    private static final long referenceTimeMsClock = System.currentTimeMillis();
-
     /** elapsed time */
     private long time = 0;
 
@@ -199,6 +193,9 @@ public class SampleResult implements Ser
     private static final boolean startTimeStamp
         = JMeterUtils.getPropDefault("sampleresult.timestamp.start", false);  // $NON-NLS-1$
 
+    private static final boolean useNanoTime
+    = JMeterUtils.getPropDefault("sampleresult.useNanoTime", true);  // $NON-NLS-1$
+
     static {
         if (startTimeStamp) {
             log.info("Note: Sample TimeStamps are START times");
@@ -206,10 +203,21 @@ public class SampleResult implements Ser
             log.info("Note: Sample TimeStamps are END times");
         }
         log.info("sampleresult.default.encoding is set to " + DEFAULT_ENCODING);
+        log.info("sampleresult.useNanoTime="+useNanoTime);
     }
 
+    private transient final long nanoTimeOffset;
+
+    private long initOffset(){
+        if (useNanoTime){
+            return System.currentTimeMillis() - sampleNsClockInMs();
+        } else {
+            return Long.MIN_VALUE;
+        }
+    }
     public SampleResult() {
         time = 0;
+        nanoTimeOffset = initOffset();
     }
 
     /**
@@ -218,6 +226,7 @@ public class SampleResult implements Ser
      * @param res existing sample result
      */
     public SampleResult(SampleResult res) {
+        nanoTimeOffset = initOffset();
         allThreads = res.allThreads;//OK
         assertionResults = res.assertionResults;// TODO ??
         bytes = res.bytes;
@@ -270,7 +279,8 @@ public class SampleResult implements Ser
      *            create the sample finishing now, else starting now
      */
     protected SampleResult(long elapsed, boolean atend) {
-        long now = currentTimeInMs();
+        nanoTimeOffset = initOffset();
+        long now = currentTimeInMillis();
         if (atend) {
             setTimes(now - elapsed, now);
         } else {
@@ -304,7 +314,7 @@ public class SampleResult implements Ser
      *            desired elapsed time
      */
     public static SampleResult createTestSample(long elapsed) {
-        long now = currentTimeInMs();
+        long now = System.currentTimeMillis();
         return createTestSample(now, now + elapsed);
     }
 
@@ -319,6 +329,7 @@ public class SampleResult implements Ser
      * @param elapsed
      */
     public SampleResult(long stamp, long elapsed) {
+        nanoTimeOffset = initOffset();
         stampAndTime(stamp, elapsed);
     }
 
@@ -327,9 +338,14 @@ public class SampleResult implements Ser
     }
 
     // Helper method to get 1 ms resolution timing.
-    public static long currentTimeInMs() {
-        long elapsedInMs = sampleNsClockInMs() - referenceTimeNsClock;
-        return referenceTimeMsClock + elapsedInMs;
+    public long currentTimeInMillis() {
+        if (useNanoTime){
+            if (nanoTimeOffset == Long.MIN_VALUE){
+                throw new RuntimeException("Invalid call; nanoTimeOffset as not been set");
+            }
+            return sampleNsClockInMs() + nanoTimeOffset;            
+        }
+        return System.currentTimeMillis();
     }
 
     // Helper method to maintain timestamp relationships
@@ -923,7 +939,7 @@ public class SampleResult implements Ser
      */
     public void sampleStart() {
         if (startTime == 0) {
-            setStartTime(currentTimeInMs());
+            setStartTime(currentTimeInMillis());
         } else {
             log.error("sampleStart called twice", new Throwable("Invalid call sequence"));
         }
@@ -935,7 +951,7 @@ public class SampleResult implements Ser
      */
     public void sampleEnd() {
         if (endTime == 0) {
-            setEndTime(currentTimeInMs());
+            setEndTime(currentTimeInMillis());
         } else {
             log.error("sampleEnd called twice", new Throwable("Invalid call sequence"));
         }
@@ -949,7 +965,7 @@ public class SampleResult implements Ser
         if (pauseTime != 0) {
             log.error("samplePause called twice", new Throwable("Invalid call sequence"));
         }
-        pauseTime = currentTimeInMs();
+        pauseTime = currentTimeInMillis();
     }
 
     /**
@@ -960,7 +976,7 @@ public class SampleResult implements Ser
         if (pauseTime == 0) {
             log.error("sampleResume without samplePause", new Throwable("Invalid call sequence"));
         }
-        idleTime += currentTimeInMs() - pauseTime;
+        idleTime += currentTimeInMillis() - pauseTime;
         pauseTime = 0;
     }
 
@@ -1063,7 +1079,7 @@ public class SampleResult implements Ser
      *
      */
     public void latencyEnd() {
-        latency = currentTimeInMs() - startTime - idleTime;
+        latency = currentTimeInMillis() - startTime - idleTime;
     }
 
     /**

Modified: jakarta/jmeter/trunk/test/src/org/apache/jmeter/samplers/TestSampleResult.java
URL: http://svn.apache.org/viewvc/jakarta/jmeter/trunk/test/src/org/apache/jmeter/samplers/TestSampleResult.java?rev=1037933&r1=1037932&r2=1037933&view=diff
==============================================================================
--- jakarta/jmeter/trunk/test/src/org/apache/jmeter/samplers/TestSampleResult.java (original)
+++ jakarta/jmeter/trunk/test/src/org/apache/jmeter/samplers/TestSampleResult.java Mon Nov 22 23:18:05 2010
@@ -99,7 +99,7 @@ public class TestSampleResult extends Te
         }
 
         private static long sampleClock() {
-            return SampleResult.currentTimeInMs();
+            return System.currentTimeMillis();
         }
 
         public void testSubResults() throws Exception {

Modified: jakarta/jmeter/trunk/xdocs/changes.xml
URL: http://svn.apache.org/viewvc/jakarta/jmeter/trunk/xdocs/changes.xml?rev=1037933&r1=1037932&r2=1037933&view=diff
==============================================================================
--- jakarta/jmeter/trunk/xdocs/changes.xml (original)
+++ jakarta/jmeter/trunk/xdocs/changes.xml Mon Nov 22 23:18:05 2010
@@ -62,6 +62,8 @@ To override the default local language f
 <h2>Incompatible changes</h2>
 
 <p>
+Removed method public static long currentTimeInMs().
+This has been replaced by the instance method public long currentTimeInMillis().
 </p>
 
 <h2>Bug fixes</h2>
@@ -108,6 +110,11 @@ To override the default local language f
 <li>Bug 50203 Cannot set property "jmeter.save.saveservice.default_delimiter=\t"</li>
 <li>mirror-server.sh - fix classpath to use : separator (not ;)</li>
 <li>Bug 50286 - URL Re-writing Modifier: extracted jsessionid value is incorrect when is between XML tags</li>
+<li>
+System.nanoTime() tends to drift relative to System.currentTimeMillis().
+Change SampleResult to recalculate offset each time.
+Also enable reversion to using System.currentTimeMillis() only.
+</li>
 </ul>
 
 <!-- ==================================================== -->



---------------------------------------------------------------------
To unsubscribe, e-mail: notifications-unsubscribe@jakarta.apache.org
For additional commands, e-mail: notifications-help@jakarta.apache.org