Re: [JMeter] JUnit sampler sample time changes
That reminds me -
Tests I've done on Windows show that nanoTime() drifts considerably
when compared with currentTimeMillis(), i.e. its clock does not appear
to run at the same rate.
Here's a simple test you can run:
public class NanoDrift {
public static void main(String[] args) throws InterruptedException {
long systemTime = System.currentTimeMillis();
long nanoTime = System.nanoTime() / 100;
long count=0;
while(true){
long systemDiff = System.currentTimeMillis() - systemTime;
long nanoDiff = System.nanoTime() / 100 - nanoTime;
long absdiff = Math.abs(systemDiff-nanoDiff);
if (absdiff 100 || (count % 60 == 0)) {
System.out.println(@:+count+ |S-N|:+absdiff+
S:+systemDiff + N: + nanoDiff);
}
Thread.sleep(1000);
count++;
}
}
}
Behaviour may depend on the JVM used; on
java version 1.6.0_24
Java(TM) SE Runtime Environment (build 1.6.0_24-b07)
Java HotSpot(TM) Client VM (build 19.1-b02, mixed mode, sharing)
I just got
@:0 |S-N|:0 S:0 N:0
@:60 |S-N|:0 S:60032 N:60032
@:120 |S-N|:1 S:120032 N:120033
@:180 |S-N|:2 S:180032 N:180034
@:240 |S-N|:6 S:240032 N:240038
@:300 |S-N|:7 S:300032 N:300039
@:360 |S-N|:13 S:360032 N:360045
@:420 |S-N|:14 S:420032 N:420046
@:480 |S-N|:15 S:480032 N:480047
@:540 |S-N|:16 S:540032 N:540048
@:600 |S-N|:17 S:600032 N:600049
@:660 |S-N|:18 S:660032 N:660050
@:720 |S-N|:19 S:720032 N:720051
@:780 |S-N|:20 S:780032 N:780052
@:840 |S-N|:21 S:840032 N:840053
@:900 |S-N|:22 S:900032 N:900054
@:960 |S-N|:23 S:960032 N:960055
@:1020 |S-N|:24 S:1020032 N:1020056
@:1080 |S-N|:21 S:1080063 N:1080084
@:1140 |S-N|:22 S:1140063 N:1140085
@:1200 |S-N|:23 S:1200063 N:1200086
@:1260 |S-N|:24 S:1260063 N:1260087
@:1320 |S-N|:21 S:1320172 N:1320193
@:1380 |S-N|:36 S:1380172 N:1380208
@:1440 |S-N|:37 S:1440172 N:1440209
@:1500 |S-N|:38 S:1500172 N:1500210
@:1560 |S-N|:40 S:1560172 N:1560212
@:1620 |S-N|:41 S:1620172 N:1620213
@:1680 |S-N|:42 S:1680172 N:1680214
@:1740 |S-N|:29 S:1740188 N:1740217
@:1800 |S-N|:30 S:1800188 N:1800218
@:1860 |S-N|:31 S:1860188 N:1860219
@:1920 |S-N|:31 S:1920188 N:1920219
@:1980 |S-N|:32 S:1980188 N:1980220
@:2040 |S-N|:33 S:2040188 N:2040221
@:2100 |S-N|:34 S:2100188 N:2100222
@:2160 |S-N|:35 S:2160188 N:2160223
@:2220 |S-N|:36 S:2220188 N:2220224
@:2280 |S-N|:37 S:2280188 N:2280225
@:2340 |S-N|:38 S:2340188 N:2340226
@:2400 |S-N|:39 S:2400188 N:2400227
@:2460 |S-N|:40 S:2460188 N:2460228
@:2520 |S-N|:41 S:2520188 N:2520229
However, on a FreeBSD system using
java version 1.6.0_03-p4
Java(TM) SE Runtime Environment (build 1.6.0_03-p4-root_17_dec_2010_05_08-b00)
Java HotSpot(TM) 64-Bit Server VM (build
1.6.0_03-p4-root_17_dec_2010_05_08-b00, mixed mode)
I see no drift:
@:0 |S-N|:0 S:0 N:0
@:60 |S-N|:0 S:60118 N:60118
@:120 |S-N|:0 S:120239 N:120239
@:180 |S-N|:1 S:180357 N:180358
@:240 |S-N|:0 S:240476 N:240476
@:300 |S-N|:0 S:300594 N:300594
@:360 |S-N|:0 S:360713 N:360713
@:420 |S-N|:0 S:420830 N:420830
@:480 |S-N|:1 S:480948 N:480949
@:540 |S-N|:0 S:541066 N:541066
@:600 |S-N|:0 S:601184 N:601184
@:660 |S-N|:0 S:661302 N:661302
@:720 |S-N|:0 S:721419 N:721419
@:780 |S-N|:0 S:781537 N:781537
@:840 |S-N|:0 S:841655 N:841655
@:900 |S-N|:0 S:901773 N:901773
@:960 |S-N|:1 S:961890 N:961891
@:1020 |S-N|:0 S:1022008 N:1022008
@:1080 |S-N|:0 S:1082126 N:1082126
@:1140 |S-N|:0 S:1142244 N:1142244
@:1200 |S-N|:1 S:1202361 N:1202362
@:1260 |S-N|:1 S:1262479 N:1262480
@:1320 |S-N|:0 S:1322600 N:1322600
@:1380 |S-N|:1 S:1382748 N:1382749
@:1440 |S-N|:0 S:1442879 N:1442879
@:1500 |S-N|:1 S:1502997 N:1502998
@:1560 |S-N|:0 S:1563115 N:1563115
@:1620 |S-N|:0 S:1623233 N:1623233
@:1680 |S-N|:0 S:1683351 N:1683351
@:1740 |S-N|:0 S:1743468 N:1743468
@:1800 |S-N|:0 S:1803586 N:1803586
@:1860 |S-N|:0 S:1863704 N:1863704
@:1920 |S-N|:1 S:1923838 N:1923839
@:1980 |S-N|:0 S:1983959 N:1983959
@:2040 |S-N|:1 S:2044077 N:2044078
@:2100 |S-N|:0 S:2104195 N:2104195
@:2160 |S-N|:0 S:2164313 N:2164313
@:2220 |S-N|:1 S:2224430 N:2224431
@:2280 |S-N|:1 S:2284548 N:2284549
@:2340 |S-N|:0 S:2344666 N:2344666
@:2400 |S-N|:1 S:2404784 N:2404785
@:2460 |S-N|:0 S:2464903 N:2464903
@:2520 |S-N|:0 S:2525020 N:2525020
@:2580 |S-N|:0 S:2585138 N:2585138
@:2640 |S-N|:0 S:2645256 N:2645256
On 3 April 2011 13:50, Peter Lin wool...@gmail.com wrote:
Another important thing to consider is that nano time costs a lot more
than System.currentTimeMillis().
I've done some benchmarking in the past and nano time costs 30% on
windows. On linux, the cost is higher due to differences in how it's
implemented.
On Sun, Apr 3, 2011 at 5:28 AM, sebb seb...@gmail.com wrote:
On 3 April 2011 08:32, Ben Cuthbert ben_cuthb...@yahoo.co.uk wrote:
I see the nanotime. But the time in the sampler results is reported in ms.
So when you have you data
it just says 0. I would like it to go one further and report a low level.
Sorry, that's not possible currently.
Re: [JMeter] JUnit sampler sample time changes
I've talked with BEA's JRockit team in the past regarding the
differences in Nano time on different platforms.
Given these issues, using nano time in JMeter is difficult at best.
From what I am told by Henrik stahl, making nano time reliable and
performant isn't trivial, so using it to measure performance isn't
really recommended. As far as I know, the only way to get reliable
high performance nano time is if the OS provides it.
On Sun, Apr 3, 2011 at 9:45 AM, sebb seb...@gmail.com wrote:
That reminds me -
Tests I've done on Windows show that nanoTime() drifts considerably
when compared with currentTimeMillis(), i.e. its clock does not appear
to run at the same rate.
Here's a simple test you can run:
public class NanoDrift {
public static void main(String[] args) throws InterruptedException {
long systemTime = System.currentTimeMillis();
long nanoTime = System.nanoTime() / 100;
long count=0;
while(true){
long systemDiff = System.currentTimeMillis() - systemTime;
long nanoDiff = System.nanoTime() / 100 - nanoTime;
long absdiff = Math.abs(systemDiff-nanoDiff);
if (absdiff 100 || (count % 60 == 0)) {
System.out.println(@:+count+ |S-N|:+absdiff+
S:+systemDiff + N: + nanoDiff);
}
Thread.sleep(1000);
count++;
}
}
}
Behaviour may depend on the JVM used; on
java version 1.6.0_24
Java(TM) SE Runtime Environment (build 1.6.0_24-b07)
Java HotSpot(TM) Client VM (build 19.1-b02, mixed mode, sharing)
I just got
@:0 |S-N|:0 S:0 N:0
@:60 |S-N|:0 S:60032 N:60032
@:120 |S-N|:1 S:120032 N:120033
@:180 |S-N|:2 S:180032 N:180034
@:240 |S-N|:6 S:240032 N:240038
@:300 |S-N|:7 S:300032 N:300039
@:360 |S-N|:13 S:360032 N:360045
@:420 |S-N|:14 S:420032 N:420046
@:480 |S-N|:15 S:480032 N:480047
@:540 |S-N|:16 S:540032 N:540048
@:600 |S-N|:17 S:600032 N:600049
@:660 |S-N|:18 S:660032 N:660050
@:720 |S-N|:19 S:720032 N:720051
@:780 |S-N|:20 S:780032 N:780052
@:840 |S-N|:21 S:840032 N:840053
@:900 |S-N|:22 S:900032 N:900054
@:960 |S-N|:23 S:960032 N:960055
@:1020 |S-N|:24 S:1020032 N:1020056
@:1080 |S-N|:21 S:1080063 N:1080084
@:1140 |S-N|:22 S:1140063 N:1140085
@:1200 |S-N|:23 S:1200063 N:1200086
@:1260 |S-N|:24 S:1260063 N:1260087
@:1320 |S-N|:21 S:1320172 N:1320193
@:1380 |S-N|:36 S:1380172 N:1380208
@:1440 |S-N|:37 S:1440172 N:1440209
@:1500 |S-N|:38 S:1500172 N:1500210
@:1560 |S-N|:40 S:1560172 N:1560212
@:1620 |S-N|:41 S:1620172 N:1620213
@:1680 |S-N|:42 S:1680172 N:1680214
@:1740 |S-N|:29 S:1740188 N:1740217
@:1800 |S-N|:30 S:1800188 N:1800218
@:1860 |S-N|:31 S:1860188 N:1860219
@:1920 |S-N|:31 S:1920188 N:1920219
@:1980 |S-N|:32 S:1980188 N:1980220
@:2040 |S-N|:33 S:2040188 N:2040221
@:2100 |S-N|:34 S:2100188 N:2100222
@:2160 |S-N|:35 S:2160188 N:2160223
@:2220 |S-N|:36 S:2220188 N:2220224
@:2280 |S-N|:37 S:2280188 N:2280225
@:2340 |S-N|:38 S:2340188 N:2340226
@:2400 |S-N|:39 S:2400188 N:2400227
@:2460 |S-N|:40 S:2460188 N:2460228
@:2520 |S-N|:41 S:2520188 N:2520229
However, on a FreeBSD system using
java version 1.6.0_03-p4
Java(TM) SE Runtime Environment (build 1.6.0_03-p4-root_17_dec_2010_05_08-b00)
Java HotSpot(TM) 64-Bit Server VM (build
1.6.0_03-p4-root_17_dec_2010_05_08-b00, mixed mode)
I see no drift:
@:0 |S-N|:0 S:0 N:0
@:60 |S-N|:0 S:60118 N:60118
@:120 |S-N|:0 S:120239 N:120239
@:180 |S-N|:1 S:180357 N:180358
@:240 |S-N|:0 S:240476 N:240476
@:300 |S-N|:0 S:300594 N:300594
@:360 |S-N|:0 S:360713 N:360713
@:420 |S-N|:0 S:420830 N:420830
@:480 |S-N|:1 S:480948 N:480949
@:540 |S-N|:0 S:541066 N:541066
@:600 |S-N|:0 S:601184 N:601184
@:660 |S-N|:0 S:661302 N:661302
@:720 |S-N|:0 S:721419 N:721419
@:780 |S-N|:0 S:781537 N:781537
@:840 |S-N|:0 S:841655 N:841655
@:900 |S-N|:0 S:901773 N:901773
@:960 |S-N|:1 S:961890 N:961891
@:1020 |S-N|:0 S:1022008 N:1022008
@:1080 |S-N|:0 S:1082126 N:1082126
@:1140 |S-N|:0 S:1142244 N:1142244
@:1200 |S-N|:1 S:1202361 N:1202362
@:1260 |S-N|:1 S:1262479 N:1262480
@:1320 |S-N|:0 S:1322600 N:1322600
@:1380 |S-N|:1 S:1382748 N:1382749
@:1440 |S-N|:0 S:1442879 N:1442879
@:1500 |S-N|:1 S:1502997 N:1502998
@:1560 |S-N|:0 S:1563115 N:1563115
@:1620 |S-N|:0 S:1623233 N:1623233
@:1680 |S-N|:0 S:1683351 N:1683351
@:1740 |S-N|:0 S:1743468 N:1743468
@:1800 |S-N|:0 S:1803586 N:1803586
@:1860 |S-N|:0 S:1863704 N:1863704
@:1920 |S-N|:1 S:1923838 N:1923839
@:1980 |S-N|:0 S:1983959 N:1983959
@:2040 |S-N|:1 S:2044077 N:2044078
@:2100 |S-N|:0 S:2104195 N:2104195
@:2160 |S-N|:0 S:2164313 N:2164313
@:2220 |S-N|:1 S:2224430 N:2224431
@:2280 |S-N|:1 S:2284548 N:2284549
@:2340 |S-N|:0 S:2344666 N:2344666
@:2400 |S-N|:1 S:2404784 N:2404785
@:2460 |S-N|:0 S:2464903 N:2464903
@:2520 |S-N|:0 S:2525020 N:2525020
@:2580 |S-N|:0 S:2585138 N:2585138
@:2640 |S-N|:0 S:2645256 N:2645256
On 3 April 2011 13:50, Peter Lin wool...@gmail.com wrote:
Re: [JMeter] JUnit sampler sample time changes
On 31 March 2011 19:41, Ben Cuthbert ben_cuthb...@yahoo.co.uk wrote: All I have been looking over the code in the JUnitSampler code under the jmeter source. I would like to make a change to use nanoTime() rather than milliseconds. Why? I can see in the AnnotatedTestCase there is an elapsed time. But I can't see how it is returned to a results table. Any ideas? The time in AnnotatedTestCase is only used for reporting timeout errors. The actual sample time is calculated using SampleResult.sampleStart() and sampleEnd() which already use nanoTime(). - To unsubscribe, e-mail: dev-unsubscr...@jakarta.apache.org For additional commands, e-mail: dev-h...@jakarta.apache.org
[JMeter] JUnit sampler sample time changes
All I have been looking over the code in the JUnitSampler code under the jmeter source. I would like to make a change to use nanoTime() rather than milliseconds. I can see in the AnnotatedTestCase there is an elapsed time. But I can't see how it is returned to a results table. Any ideas?
