Skip to content

Commit 0c7adc8

Browse files
jukzijukzi
committed
tests: use nanoTime for measurements
* System.currentTimeMillis() is not guaranteed to be monotonic * removed some related dead code * added missing volatile modifier
1 parent 0364a48 commit 0c7adc8

File tree

29 files changed

+163
-250
lines changed

29 files changed

+163
-250
lines changed

‎org.eclipse.jdt.apt.pluggable.tests/src/org/eclipse/jdt/apt/pluggable/tests/PerformanceTests.java‎

Lines changed: 24 additions & 62 deletions
Original file line numberDiff line numberDiff line change
@@ -153,43 +153,32 @@ public void testBoringFiles() throws Exception
153153

154154
Runtime run = Runtime.getRuntime();
155155

156-
long start;
156+
long startNanos;
157157

158158
if (INCLUDE_APT_DISABLED) {
159159
AptConfig.setEnabled(jproj, false);
160-
start = System.currentTimeMillis();
160+
startNanos = System.nanoTime();
161161
run.exec(CMD_START_CPU_PROFILING).waitFor();
162162
fullBuild( project.getFullPath() );
163-
if (VERBOSE)
164-
System.out.println("APT disabled: full build took " + ((System.currentTimeMillis() - start)/1000L) + " sec");
163+
if (VERBOSE) {
164+
System.out
165+
.println("APT disabled: full build took " + ((System.nanoTime() - startNanos) / 1_000_000L) + " ms");
166+
}
165167
run.exec(CMD_PERF_SNAPSHOT).waitFor();
166168
run.exec(CMD_STOP_CPU_PROFILING).waitFor();
167169
expectingNoProblems();
168-
169-
// System.gc();
170-
// Thread.sleep(1000);
171-
//
172-
// AptConfig.setEnabled(jproj, false);
173-
// start = System.currentTimeMillis();
174-
// fullBuild( project.getFullPath() );
175-
// if (VERBOSE) {
176-
// System.out.println("full build took " + ((System.currentTimeMillis() - start)/1000L) + " sec");
177-
// System.out.println("Taking heap snapshot");
178-
// }
179-
// run.exec(CMD_HEAP_SNAPSHOT).waitFor();
180-
// expectingNoProblems();
181170
}
182171

183172
System.gc();
184173
Thread.sleep(1000);
185174

186175
AptConfig.setEnabled(jproj, true);
187-
start = System.currentTimeMillis();
176+
startNanos = System.nanoTime();
188177
if (VERBOSE)
189178
System.out.println("APT enabled: starting full build");
190179
fullBuild( project.getFullPath() );
191180
if (VERBOSE) {
192-
System.out.println("full build took " + ((System.currentTimeMillis() - start)/1000L) + " sec");
181+
System.out.println("full build took " + ((System.nanoTime() - startNanos) / 1_000_000L) + " ms");
193182
System.out.println("Taking heap snapshot");
194183
}
195184
run.exec(CMD_HEAP_SNAPSHOT).waitFor();
@@ -199,13 +188,14 @@ public void testBoringFiles() throws Exception
199188
Thread.sleep(1000);
200189

201190
AptConfig.setEnabled(jproj, true);
202-
start = System.currentTimeMillis();
191+
startNanos = System.nanoTime();
203192
if (VERBOSE)
204193
System.out.println("APT enabled: starting full build");
205194
run.exec(CMD_START_CPU_PROFILING).waitFor();
206195
fullBuild( project.getFullPath() );
207-
if (VERBOSE)
208-
System.out.println("full build took " + ((System.currentTimeMillis() - start)/1000L) + " sec");
196+
if (VERBOSE) {
197+
System.out.println("full build took " + ((System.nanoTime() - startNanos) / 1_000_000L) + " ms");
198+
}
209199
run.exec(CMD_PERF_SNAPSHOT).waitFor();
210200
run.exec(CMD_STOP_CPU_PROFILING).waitFor();
211201
expectingNoProblems();
@@ -214,13 +204,14 @@ public void testBoringFiles() throws Exception
214204
Thread.sleep(1000);
215205

216206
AptConfig.setEnabled(jproj, true);
217-
start = System.currentTimeMillis();
207+
startNanos = System.nanoTime();
218208
if (VERBOSE)
219209
System.out.println("APT enabled: starting full build");
220210
run.exec(CMD_START_CPU_PROFILING).waitFor();
221211
fullBuild( project.getFullPath() );
222-
if (VERBOSE)
223-
System.out.println("full build took " + ((System.currentTimeMillis() - start)/1000L) + " sec");
212+
if (VERBOSE) {
213+
System.out.println("full build took " + ((System.nanoTime() - startNanos) / 1_000_000L) + " ms");
214+
}
224215
run.exec(CMD_PERF_SNAPSHOT).waitFor();
225216
run.exec(CMD_STOP_CPU_PROFILING).waitFor();
226217
expectingNoProblems();
@@ -247,63 +238,34 @@ public void _testInterestingFilesWithJ6() throws Exception
247238

248239
Runtime run = Runtime.getRuntime();
249240

250-
long start;
251-
252241
if (INCLUDE_APT_DISABLED) {
253242
AptConfig.setEnabled(jproj, false);
254-
start = System.currentTimeMillis();
243+
long startNanos = System.nanoTime();
255244
run.exec(CMD_START_CPU_PROFILING).waitFor();
256245
fullBuild( project.getFullPath() );
257246
if (VERBOSE)
258-
System.out.println("APT disabled: full build took " + ((System.currentTimeMillis() - start)/1000L) + " sec");
247+
System.out.println(
248+
"APT disabled: full build took " + ((System.nanoTime() - startNanos) / 1_000_000L) + " ms");
259249
run.exec(CMD_PERF_SNAPSHOT).waitFor();
260250
run.exec(CMD_STOP_CPU_PROFILING).waitFor();
261251
expectingNoProblems();
262-
263-
// System.gc();
264-
// Thread.sleep(1000);
265-
//
266-
// AptConfig.setEnabled(jproj, false);
267-
// start = System.currentTimeMillis();
268-
// run.exec(CMD_START_CPU_PROFILING).waitFor();
269-
// fullBuild( project.getFullPath() );
270-
// if (VERBOSE)
271-
// System.out.println("APT disabled: full build took " + ((System.currentTimeMillis() - start)/1000L) + " sec");
272-
// run.exec(CMD_PERF_SNAPSHOT).waitFor();
273-
// run.exec(CMD_STOP_CPU_PROFILING).waitFor();
274-
// expectingNoProblems();
275252
}
276253

277254
System.gc();
278255
Thread.sleep(1000);
279256

280257
AptConfig.setEnabled(jproj, true);
281-
start = System.currentTimeMillis();
258+
long startNanos = System.nanoTime();
282259
if (VERBOSE)
283260
System.out.println("APT enabled: starting full build");
284261
run.exec(CMD_START_CPU_PROFILING).waitFor();
285262
fullBuild( project.getFullPath() );
286263
if (VERBOSE)
287-
System.out.println("full build took " + ((System.currentTimeMillis() - start)/1000L) + " sec");
264+
System.out.println("full build took " + ((System.nanoTime() - startNanos) / 1_000_000L) + " ms");
288265
run.exec(CMD_PERF_SNAPSHOT).waitFor();
289266
run.exec(CMD_STOP_CPU_PROFILING).waitFor();
290267
expectingNoProblems();
291268

292-
// System.gc();
293-
// Thread.sleep(1000);
294-
//
295-
// AptConfig.setEnabled(jproj, true);
296-
// start = System.currentTimeMillis();
297-
// if (VERBOSE)
298-
// System.out.println("APT enabled: starting full build");
299-
// run.exec(CMD_START_CPU_PROFILING).waitFor();
300-
// fullBuild( project.getFullPath() );
301-
// if (VERBOSE)
302-
// System.out.println("full build took " + ((System.currentTimeMillis() - start)/1000L) + " sec");
303-
// run.exec(CMD_PERF_SNAPSHOT).waitFor();
304-
// run.exec(CMD_STOP_CPU_PROFILING).waitFor();
305-
// expectingNoProblems();
306-
307269
// Now delete the project!
308270
if (VERBOSE)
309271
System.out.println("Deleting workspace");
@@ -329,10 +291,10 @@ public void _testGeneratingLotsOfFiles() throws Exception
329291
// Set some per-project preferences
330292
AptConfig.setEnabled(jproj, true);
331293

332-
long start = System.currentTimeMillis();
333-
fullBuild( project.getFullPath() );
294+
long startNanos = System.nanoTime();
295+
fullBuild(project.getFullPath());
334296
if (VERBOSE)
335-
System.out.println("Done with build after " + ((System.currentTimeMillis() - start)/1000L) + " sec");
297+
System.out.println("Done with build after " + ((System.nanoTime() - startNanos) / 1_000_000L) + " ms");
336298

337299
expectingNoProblems();
338300

‎org.eclipse.jdt.apt.pluggable.tests/src/org/eclipse/jdt/apt/pluggable/tests/ScalingTests.java‎

Lines changed: 5 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -85,10 +85,12 @@ public void testGeneratingLotsOfFiles() throws Exception
8585
// Set some per-project preferences
8686
AptConfig.setEnabled(jproj, true);
8787

88-
long start = System.currentTimeMillis();
88+
long startNanos = System.nanoTime();
8989
fullBuild( project.getFullPath() );
90-
if (VERBOSE)
91-
System.out.println("Done with build after " + ((System.currentTimeMillis() - start)/1000L) + " sec");
90+
if (VERBOSE) {
91+
System.out.println(
92+
"Done with build after " + ((System.nanoTime() - startNanos) / 1_000_000L) + " ms");
93+
}
9294

9395
expectingNoProblems();
9496

‎org.eclipse.jdt.apt.tests/src-annotations/org/eclipse/jdt/apt/tests/annotations/pause/PauseAnnotationProcessor.java‎

Lines changed: 6 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -44,14 +44,13 @@ public void process() {
4444
Collection<Declaration> annotatedDecls = _env.getDeclarationsAnnotatedWith(_annotationDecl);
4545
for (Declaration decl : annotatedDecls) {
4646
Pause a = decl.getAnnotation(Pause.class);
47-
int pause = a.value();
48-
System.out.println(phase + " pausing for " + pause + " to process " + decl.getSimpleName() + "...");
47+
int pauseMs = a.value();
48+
System.out.println(phase + " pausing for " + pauseMs + " to process " + decl.getSimpleName() + "...");
4949
// busy sleep
50-
long end = System.currentTimeMillis() + pause;
51-
while (System.currentTimeMillis() < end)
52-
for (int i = 0; i < 100000; ++i) {
53-
/* pausing */
54-
}
50+
long timeoutNanos = System.nanoTime() + pauseMs * 1_000_000L;
51+
while (System.nanoTime() < timeoutNanos) {
52+
Thread.onSpinWait();
53+
}
5554
System.out.println(phase + " finished pausing");
5655
}
5756
}

‎org.eclipse.jdt.apt.tests/src/org/eclipse/jdt/apt/tests/APTTestBase.java‎

Lines changed: 0 additions & 18 deletions
Original file line numberDiff line numberDiff line change
@@ -365,22 +365,4 @@ protected void expectingSpecificProblemsFor(IPath root, ExpectedProblem[] proble
365365
protected void expectingOnlySpecificProblemFor(IPath root, ExpectedProblem problem) {
366366
expectingOnlySpecificProblemsFor(root, new ExpectedProblem[] { problem });
367367
}
368-
369-
protected static void sleep( long millis )
370-
{
371-
long end = System.currentTimeMillis() + millis;
372-
while ( millis > 0 )
373-
{
374-
try
375-
{
376-
Thread.sleep( millis );
377-
}
378-
catch ( InterruptedException ie )
379-
{}
380-
millis = end - System.currentTimeMillis();
381-
}
382-
}
383-
384-
385-
386368
}

‎org.eclipse.jdt.apt.tests/src/org/eclipse/jdt/apt/tests/AptBuilderTests.java‎

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -502,7 +502,7 @@ public void testDeletedParentFile() throws Exception
502502
TestUtil.deleteFile(p1a1Path);
503503

504504
// sleep to let the resource-change event fire
505-
sleep( 1000 );
505+
Util.waitAtLeast(1000);
506506

507507
incrementalBuild( project.getFullPath() );
508508

@@ -513,7 +513,7 @@ public void testDeletedParentFile() throws Exception
513513

514514
// sleep to let the resource-change event fire
515515
// TODO: Is there a more reliable, consistent, and efficient way to wait?
516-
sleep( 1000 );
516+
Util.waitAtLeast(1000);
517517

518518
incrementalBuild( project.getFullPath() );
519519
expectingOnlyProblemsFor( p1bPath );

‎org.eclipse.jdt.apt.tests/src/org/eclipse/jdt/apt/tests/PerfTests.java‎

Lines changed: 4 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -142,9 +142,9 @@ public void testBuilding() throws Throwable {
142142
assertNoUnexpectedProblems();
143143

144144
System.out.println("Performing full build without apt...");
145-
long start = System.currentTimeMillis();
145+
long startNanos = System.nanoTime();
146146
proj.build(IncrementalProjectBuilder.FULL_BUILD, null);
147-
long totalWithoutAPT = System.currentTimeMillis() - start;
147+
long totalWithoutAPT = (System.nanoTime() - startNanos) / 1_000_000L;
148148
System.out.println("Completed full build without APT in " + totalWithoutAPT + "ms.");
149149

150150
assertNoUnexpectedProblems();
@@ -156,9 +156,9 @@ public void testBuilding() throws Throwable {
156156
assertNoUnexpectedProblems();
157157

158158
System.out.println("Performing full build with apt...");
159-
start = System.currentTimeMillis();
159+
startNanos = System.nanoTime();
160160
proj.build(IncrementalProjectBuilder.FULL_BUILD, null);
161-
long totalWithAPT = System.currentTimeMillis() - start;
161+
long totalWithAPT = (System.nanoTime() - startNanos) / 1_000_000L;
162162
System.out.println("Completed full build with APT in " + totalWithAPT + "ms.");
163163

164164
assertNoUnexpectedProblems();

‎org.eclipse.jdt.apt.tests/src/org/eclipse/jdt/apt/tests/ScalingTests.java‎

Lines changed: 4 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -98,11 +98,11 @@ public void testGeneratingLotsOfFiles() throws Exception
9898
IJavaProject jproj = env.getJavaProject( projName );
9999
AptConfig.setEnabled(jproj, true);
100100

101-
long start = System.currentTimeMillis();
101+
long startNanos = System.nanoTime();
102102
fullBuild( project.getFullPath() );
103-
if (VERBOSE)
104-
System.out.println("Done with build after " + ((System.currentTimeMillis() - start)/1000L) + " sec");
105-
103+
if (VERBOSE) {
104+
System.out.println("Done with build after " + ((System.nanoTime() - startNanos) / 1_000_000L) + " ms");
105+
}
106106
expectingNoProblems();
107107

108108
IPath projPath = jproj.getProject().getLocation();

‎org.eclipse.jdt.apt.tests/src/org/eclipse/jdt/apt/tests/StarProcessorTests.java‎

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -500,7 +500,7 @@ public void testDeletedParentFile() throws Exception
500500
TestUtil.deleteFile(p1a1Path);
501501

502502
// sleep to let the resource-change event fire
503-
sleep( 1000 );
503+
Util.waitAtLeast(1000);
504504

505505
incrementalBuild( project.getFullPath() );
506506

@@ -511,7 +511,7 @@ public void testDeletedParentFile() throws Exception
511511

512512
// sleep to let the resource-change event fire
513513
// TODO: Is there a more reliable, consistent, and efficient way to wait?
514-
sleep( 1000 );
514+
Util.waitAtLeast(1000);
515515

516516
incrementalBuild( project.getFullPath() );
517517
expectingOnlyProblemsFor( p1bPath );

‎org.eclipse.jdt.core.tests.compiler/src/org/eclipse/jdt/core/tests/compiler/regression/NullReferenceImplTests.java‎

Lines changed: 3 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -643,9 +643,9 @@ public void test2062_mergedWith() {
643643

644644
public void test2400_state_consistency() {
645645
int failures = 0;
646-
long start;
646+
long startNanos;
647647
if (MEASURE_PERFORMANCES) {
648-
start = System.currentTimeMillis();
648+
startNanos = System.nanoTime();
649649
}
650650
String header = "state consistency failures: ";
651651
for (int l = 0; l < COMBINATION_TESTS_LOOP_NB ; l++) {
@@ -721,7 +721,7 @@ public void test2400_state_consistency() {
721721
}
722722
if (MEASURE_PERFORMANCES) {
723723
System.out.println("mergedWith\t\t\t" + COMBINATION_TESTS_LOOP_NB + "\t" +
724-
(System.currentTimeMillis() - start));
724+
(System.nanoTime() - startNanos) / 1_000_000L);
725725
}
726726
for (int i = 0; i < State.states.length; i++) {
727727
if (State.states[i].symbolic) {

‎org.eclipse.jdt.core.tests.compiler/src/org/eclipse/jdt/core/tests/compiler/regression/NullReferenceImplTransformations.java‎

Lines changed: 7 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -2765,9 +2765,9 @@ int test(int combinationTestsLoopsNb, boolean skipHighOrderBits) {
27652765
Map.Entry transition, transitionsSet;
27662766
this.failuresNb = 0; // reset
27672767
this.failuresNb = 0; // reset
2768-
long start = 0;
2768+
long startNanos = 0;
27692769
if (combinationTestsLoopsNb > 1) {
2770-
start = System.currentTimeMillis();
2770+
startNanos = System.nanoTime();
27712771
}
27722772
for (int l = 0; l < combinationTestsLoopsNb ; l++) {
27732773
transitionsSetsIterator = this.initializedTransitions.entrySet().iterator();
@@ -2795,8 +2795,8 @@ int test(int combinationTestsLoopsNb, boolean skipHighOrderBits) {
27952795
}
27962796
}
27972797
if (combinationTestsLoopsNb > 1) {
2798-
System.out.println(this.name + "...\t\t" + combinationTestsLoopsNb + "\t" +
2799-
(System.currentTimeMillis() - start));
2798+
System.out.println(
2799+
this.name + "...\t\t" + combinationTestsLoopsNb + "\t" + (System.nanoTime() - startNanos) / 1_000_000L);
28002800
}
28012801
// PREMATURE optimize test (extraneous allocations and copies)
28022802
// PREMATURE optimize test (extraneous iterations - undup)
@@ -3117,9 +3117,9 @@ int test(int combinationTestsLoopsNb, boolean skipHighOrderBits) {
31173117
Map.Entry transition, transitionsSet;
31183118
this.failuresNb = 0; // reset
31193119
this.failuresNb = 0; // reset
3120-
long start = 0;
3120+
long startNanos = 0;
31213121
if (combinationTestsLoopsNb > 1) {
3122-
start = System.currentTimeMillis();
3122+
startNanos = System.nanoTime();
31233123
}
31243124
for (int l = 0; l < combinationTestsLoopsNb ; l++) {
31253125
transitionsSetsIterator = this.initializedTransitions.entrySet().iterator();
@@ -3159,7 +3159,7 @@ int test(int combinationTestsLoopsNb, boolean skipHighOrderBits) {
31593159
}
31603160
if (combinationTestsLoopsNb > 1) {
31613161
System.out.println(this.name + "...\t\t" + combinationTestsLoopsNb + "\t" +
3162-
(System.currentTimeMillis() - start));
3162+
(System.nanoTime() - startNanos) / 1_000_000L);
31633163
}
31643164
// PREMATURE optimize test (extraneous allocations and copies)
31653165
// PREMATURE optimize test (extraneous iterations - undup)

0 commit comments

Comments
 (0)