What is the best practice to determine the executi

问题:

The test execution time which is displayed in eclipse->junit-view depends on the whole test case execution which includes:

• Testdata preperation
• Executing businesslogic
• assert results

I need a more detailed statement about the execution time of my businesslogic and only my businesslogic. That is what I have done inside my testcase:

Date lNow = new Date();
List<Geo> lAllBasisGeo = mGeoEvaluator.evaluateAllGeo(lGeoFixture.getGeo(), lAllGeo);
Date lStop = new Date();
System.out.println("Time of execution in seconds:"+((lStop.getTime()-lNow.getTime())/1000));

Well... I think I determine the time in a realy awkward way. Furthermore I dont think that it is necessary to declare two Date variables.

I need advice writing that code more efficiently...

回答1:

in a unit test I would prefer to add a timeout to the Test with a JUnit 4 annotation, to determine whether the test passes (fast enough) or not:

@Test(timeout=100)//let the test fail after 100 MilliSeconds
public void infinity() {
  while(true);
}

To determine the exact Runtime of your business logic I would add the Time statements right before and after your critical Codepath like you did, repeat it several times to get scholastically correct results, and remove the statements again, so slim the code.

long start = System.currentTimeMillis();
//execute logic in between
long end = System.currentTimeMillis();
System.out.println("DEBUG: Logic A took " + (end - start) + " MilliSeconds");

回答2:

JUnit 4.12 introduced the Stopwatch @Rule. It is quite straigthforward to use and should become the de facto way of verifying time spent during tests. Here's a sample class showcasing its functionalities:

public static class StopwatchTest {
     private static final Logger logger = Logger.getLogger("");

     private static void logInfo(Description description, String status, long nanos) {
         String testName = description.getMethodName();
         logger.info(String.format("Test %s %s, spent %d microseconds",
                                   testName, status, TimeUnit.NANOSECONDS.toMicros(nanos)));
     }

     @Rule
     public Stopwatch stopwatch = new Stopwatch() {
         @Override
         protected void succeeded(long nanos, Description description) {
             logInfo(description, "succeeded", nanos);
         }

         @Override
         protected void failed(long nanos, Throwable e, Description description) {
             logInfo(description, "failed", nanos);
         }

         @Override
         protected void skipped(long nanos, AssumptionViolatedException e, Description description) {
             logInfo(description, "skipped", nanos);
         }

         @Override
         protected void finished(long nanos, Description description) {
             logInfo(description, "finished", nanos);
         }
     };

     @Test
     public void succeeds() {
     }

     @Test
     public void fails() {
         fail();
     }

     @Test
     public void skips() {
         assumeTrue(false);
     }

     @Test
     public void performanceTest() throws InterruptedException {
         // An example to assert runtime:
         long delta = 30;
         Thread.sleep(300L);
         assertEquals(300d, stopwatch.runtime(MILLISECONDS), delta);
         Thread.sleep(500L);
         assertEquals(800d, stopwatch.runtime(MILLISECONDS), delta);
     }
}

回答3:

There is a very useful utility for this in the Guava library - Stopwatch.
This would allow you to write the following

import com.google.common.base.Stopwatch;

final Stopwatch stopwatch = Stopwatch.createStarted();
//dostuff
System.out.println("Time of execution in seconds:" + stopwatch.stop().elapsed(TimeUnit.SECONDS));