jakarta-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From sebb <seb...@gmail.com>
Subject Re: [JMeter] JUnit sampler sample time changes
Date Sun, 03 Apr 2011 13:45:47 GMT
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() / 1000000;
        long count=0;
        while(true){
            long systemDiff = System.currentTimeMillis() - systemTime;
            long nanoDiff = System.nanoTime() / 1000000 - 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 <woolfel@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 <sebbaz@gmail.com> wrote:
>> On 3 April 2011 08:32, Ben Cuthbert <ben_cuthbert@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.
>>
>> Changing the elapsed time to nanoSecs would break compatibility, and
>> such a level of precision is illusory anyway for almost all of the
>> samplers.
>>
>> It might be possible to keep a separate field for nanoSeconds and
>> report that, but I'm not sure there's sufficient need to warrant the
>> change and additional data storage.
>>
>>> Regards
>>> On 2 Apr 2011, at 16:18, sebb wrote:
>>>
>>>> On 31 March 2011 19:41, Ben Cuthbert <ben_cuthbert@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-unsubscribe@jakarta.apache.org
>>>> For additional commands, e-mail: dev-help@jakarta.apache.org
>>>>
>>>
>>>
>>> ---------------------------------------------------------------------
>>> To unsubscribe, e-mail: dev-unsubscribe@jakarta.apache.org
>>> For additional commands, e-mail: dev-help@jakarta.apache.org
>>>
>>>
>>
>> ---------------------------------------------------------------------
>> To unsubscribe, e-mail: dev-unsubscribe@jakarta.apache.org
>> For additional commands, e-mail: dev-help@jakarta.apache.org
>>
>>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: dev-unsubscribe@jakarta.apache.org
> For additional commands, e-mail: dev-help@jakarta.apache.org
>
>

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


Mime
View raw message