JEP 230: 微基准测试套件

值得注意的是，JEP 230：微基准测试套件是一个OpenJDK项目，旨在：

向 JDK 源代码添加一组基本的微基准测试，并使开发人员能够轻松运行现有的微基准测试和创建新的测试。

这个功能已经在Java 12中实现。

Java 微基准测试工具（JMH）

对于早期版本的 Java，请查看Java 微基准测试工具（JMH）项目，JEP 230 是基于它实现的。

如果您不使用工具并想计时执行时间较短的方法：多次执行，每次将执行次数加倍，直到达到一秒左右。因此，System.nanoTime的调用时间等以及System.nanoTime的准确性并不会对结果产生太大影响。

    int runs = 0, runsPerRound = 10;
    long begin = System.nanoTime(), end;
    do {
        for (int i=0; i<runsPerRound; ++i) timedMethod();
        end = System.nanoTime();
        runs += runsPerRound;
        runsPerRound *= 2;
    } while (runs < Integer.MAX_VALUE / 2 && 1000000000L > end - begin);
    System.out.println("Time for timedMethod() is " + 
        0.000000001 * (end-begin) / runs + " seconds");

当然，关于使用墙钟的注意事项也适用：JIT编译、多个线程/进程的影响等。因此，您首先需要执行该方法“很多次”，以便JIT编译器完成其工作，然后多次重复此测试并记录最短的执行时间。

public @interface Trace {
  boolean showParameters();
}

@Aspect
public class TraceAspect {
  [...]
  @Around("tracePointcut() && @annotation(trace) && !within(TraceAspect)")
  public Object traceAdvice ( ProceedingJintPoint jP, Trace trace ) {

    Object result;
    // initilize timer

    try { 
      result = jp.procced();
    } finally { 
      // calculate execution time 
    }

    return result;
  }
  [...]
}

非常优秀的代码。

http://www.rgagnon.com/javadetails/java-0585.html

import java.util.concurrent.TimeUnit;

long startTime = System.currentTimeMillis();
........
........
........
long finishTime = System.currentTimeMillis();

String diff = millisToShortDHMS(finishTime - startTime);


  /**
   * converts time (in milliseconds) to human-readable format
   *  "<dd:>hh:mm:ss"
   */
  public static String millisToShortDHMS(long duration) {
    String res = "";
    long days  = TimeUnit.MILLISECONDS.toDays(duration);
    long hours = TimeUnit.MILLISECONDS.toHours(duration)
                   - TimeUnit.DAYS.toHours(TimeUnit.MILLISECONDS.toDays(duration));
    long minutes = TimeUnit.MILLISECONDS.toMinutes(duration)
                     - TimeUnit.HOURS.toMinutes(TimeUnit.MILLISECONDS.toHours(duration));
    long seconds = TimeUnit.MILLISECONDS.toSeconds(duration)
                   - TimeUnit.MINUTES.toSeconds(TimeUnit.MILLISECONDS.toMinutes(duration));
    if (days == 0) {
      res = String.format("%02d:%02d:%02d", hours, minutes, seconds);
    }
    else {
      res = String.format("%dd%02d:%02d:%02d", days, hours, minutes, seconds);
    }
    return res;
  }

Spring提供了一个实用类org.springframework.util.StopWatch，根据JavaDoc：

Simple stop watch, allowing for timing of a number of tasks, exposing total running time and running time for each named task.

用法：

StopWatch stopWatch = new StopWatch("Performance Test Result");

stopWatch.start("Method 1");
doSomething1();//method to test
stopWatch.stop();

stopWatch.start("Method 2");
doSomething2();//method to test
stopWatch.stop();

System.out.println(stopWatch.prettyPrint());

输出：

StopWatch 'Performance Test Result': running time (millis) = 12829
-----------------------------------------
ms     %     Task name
-----------------------------------------
11907  036%  Method 1
00922  064%  Method 2

有关方面：

@Around("execution(* my.package..*.*(..))")
public Object logTime(ProceedingJoinPoint joinPoint) throws Throwable {
    StopWatch stopWatch = new StopWatch();
    stopWatch.start();
    Object retVal = joinPoint.proceed();
    stopWatch.stop();
    log.info(" execution time: " + stopWatch.getTotalTimeMillis() + " ms");
    return retVal;
}

我编写了一种方法，可以以更易读的形式打印方法的执行时间。例如，计算100万的阶乘大约需要9分钟。因此，执行时间将被打印为：

Execution Time: 9 Minutes, 36 Seconds, 237 MicroSeconds, 806193 NanoSeconds

代码在这里：

public class series
{
    public static void main(String[] args)
    {
        long startTime = System.nanoTime();

        long n = 10_00_000;
        printFactorial(n);

        long endTime = System.nanoTime();
        printExecutionTime(startTime, endTime);

    }

    public static void printExecutionTime(long startTime, long endTime)
    {
        long time_ns = endTime - startTime;
        long time_ms = TimeUnit.NANOSECONDS.toMillis(time_ns);
        long time_sec = TimeUnit.NANOSECONDS.toSeconds(time_ns);
        long time_min = TimeUnit.NANOSECONDS.toMinutes(time_ns);
        long time_hour = TimeUnit.NANOSECONDS.toHours(time_ns);

        System.out.print("\nExecution Time: ");
        if(time_hour > 0)
            System.out.print(time_hour + " Hours, ");
        if(time_min > 0)
            System.out.print(time_min % 60 + " Minutes, ");
        if(time_sec > 0)
            System.out.print(time_sec % 60 + " Seconds, ");
        if(time_ms > 0)
            System.out.print(time_ms % 1E+3 + " MicroSeconds, ");
        if(time_ns > 0)
            System.out.print(time_ns % 1E+6 + " NanoSeconds");
    }
}

你可以使用Perf4j，这是一个非常酷的工具。使用起来很简单。

String watchTag = "target.SomeMethod";
StopWatch stopWatch = new LoggingStopWatch(watchTag);
Result result = null; // Result is a type of a return value of a method
try {
    result = target.SomeMethod();
    stopWatch.stop(watchTag + ".success");
} catch (Exception e) {
    stopWatch.stop(watchTag + ".fail", "Exception was " + e);
    throw e; 
}

详细信息可在开发者指南中找到。

编辑：项目似乎已经停滞不前

在Spring框架中，我们有一个称为StopWatch（org.springframework.util.StopWatch）的调用。

//measuring elapsed time using Spring StopWatch
        StopWatch watch = new StopWatch();
        watch.start();
        for(int i=0; i< 1000; i++){
            Object obj = new Object();
        }
        watch.stop();
        System.out.println("Total execution time to create 1000 objects in Java using StopWatch in millis: "
                + watch.getTotalTimeMillis());

<dependencies>
    <dependency>
        <groupId>io.dropwizard.metrics</groupId>
        <artifactId>metrics-core</artifactId>
        <version>${metrics.version}</version>
    </dependency>
</dependencies>

@Timed
public void exampleMethod(){
    // some code
}

或者包含 Timer 的代码片段：

final Timer timer = metricsRegistry.timer("some_name");
final Timer.Context context = timer.time();
// timed code
context.stop();

com.example.ExampleService.exampleMethod
             count = 2
         mean rate = 3.11 calls/minute
     1-minute rate = 0.96 calls/minute
     5-minute rate = 0.20 calls/minute
    15-minute rate = 0.07 calls/minute
               min = 17.01 milliseconds
               max = 1006.68 milliseconds
              mean = 511.84 milliseconds
            stddev = 699.80 milliseconds
            median = 511.84 milliseconds
              75% <= 1006.68 milliseconds
              95% <= 1006.68 milliseconds
              98% <= 1006.68 milliseconds
              99% <= 1006.68 milliseconds
            99.9% <= 1006.68 milliseconds

通过使用AOP/AspectJ和@Loggable注解，以及jcabi-aspects库，您可以轻松简洁地完成它：

@Loggable(Loggable.DEBUG)
public String getSomeResult() {
  // return some value
}