Fork me on GitHub

【java8】为java8的foreach正名

  首先为自己没有经过严格测试得出的错误结论感到抱歉,原博文,测试完感觉自己发现了一个新bug,后来思前想后觉得不应该是这样的,如果效率差的这么多,jdk的开发人员会不去优化它吗,但是怎么重复测试任然得到一样的结果,非常疑惑。

  我觉得应该是测试方法出问题了,可是怎么也想不到原因,后来了解到jmh,深入研究了一番,觉得jmh的测试值得借鉴,jmh在测试的时候都会先经过预热几遍要测试的代码,示例如下:

public static void main(String[] args) throws RunnerException {
    Options opt = new OptionsBuilder()
            .include(JMHSample_02_BenchmarkModes.class.getSimpleName())
            .warmupIterations(5)
            .measurementIterations(5)
            .forks(1)
            .build();

    new Runner(opt).run();
}

  我觉得这是有必要的,而我的测试恰恰缺少了这个步骤,随后我在测试中应用了预热处理(均是3次预热,5次运行取平均值),得出的以下结论。

  首先是上个测试中被冤枉的java8的foreach循环,测试代码:

package yiwangzhibujian.jmh.test;

import org.openjdk.jmh.annotations.*;
import org.openjdk.jmh.runner.Runner;
import org.openjdk.jmh.runner.RunnerException;
import org.openjdk.jmh.runner.options.Options;
import org.openjdk.jmh.runner.options.OptionsBuilder;

import java.util.ArrayList;
import java.util.HashMap;
import java.util.List;
import java.util.Map;
import java.util.concurrent.TimeUnit;

@State(Scope.Thread)
@BenchmarkMode(Mode.SingleShotTime)
@OutputTimeUnit(TimeUnit.MILLISECONDS)
public class J8Loop {
  public static Map<Integer,List<Dog>> dogMap=new HashMap<>();
  static {
    dogMap.put(10, getDogs(10));
    dogMap.put(100, getDogs(100));
    dogMap.put(1000, getDogs(1000));
    dogMap.put(10000, getDogs(10000));
    dogMap.put(100000, getDogs(100000));
    dogMap.put(1000000, getDogs(1000000));
  }
  
  private static List<Dog> getDogs(int num) {
    List<Dog> dogs=new ArrayList<>();
    for(int i=0;i<num;i++){
      dogs.add(new Dog(i,"dog"+i));
    }
    return dogs;
  }
  
  private void loop(List<Dog> list) {
    list.forEach(dog->{
      dog.hashCode();
    });
  }

  @Benchmark
  @OperationsPerInvocation(10)
  public void measureWrong_10() {
    List<Dog> list = dogMap.get(10);
    loop(list);
  }

  @Benchmark
  @OperationsPerInvocation(100)
  public void measureWrong_100() {
    List<Dog> list = dogMap.get(100);
    loop(list);
  }

  @Benchmark
  @OperationsPerInvocation(1000)
  public void measureWrong_1000() {
    List<Dog> list = dogMap.get(1000);
    loop(list);
  }

  @Benchmark
  @OperationsPerInvocation(10000)
  public void measureWrong_10000() {
    List<Dog> list = dogMap.get(10000);
    loop(list);
  }

  @Benchmark
  @OperationsPerInvocation(100000)
  public void measureWrong_100000() {
    List<Dog> list = dogMap.get(100000);
    loop(list);
  }
  
  @Benchmark
  @OperationsPerInvocation(1000000)
  public void measureWrong_1000000() {
    List<Dog> list = dogMap.get(1000000);
    loop(list);
  }

  /*
   * ============================== HOW TO RUN THIS TEST:
   * ====================================
   *
   * You might notice the larger the repetitions count, the lower the
   * "perceived" cost of the operation being measured. Up to the point we do
   * each addition with 1/20 ns, well beyond what hardware can actually do.
   *
   * This happens because the loop is heavily unrolled/pipelined, and the
   * operation to be measured is hoisted from the loop. Morale: don't overuse
   * loops, rely on JMH to get the measurement right.
   *
   * You can run this test:
   *
   * a) Via the command line: $ mvn clean install $ java -jar
   * target/benchmarks.jar JMHSample_11 -wi 5 -i 5 -f 1 (we requested 5
   * warmup/measurement iterations, single fork)
   *
   * b) Via the Java API: (see the JMH homepage for possible caveats when
   * running from IDE: http://openjdk.java.net/projects/code-tools/jmh/)
   */

  public static void main(String[] args) throws RunnerException {
    Options opt = new OptionsBuilder()
        .include(J8Loop.class.getSimpleName())
        .warmupIterations(2)
        .measurementIterations(2).forks(1).build();

    new Runner(opt).run();
  }

}
class Dog{
  private int age;
  private String name;
  public Dog(int age, String name) {
    super();
    this.age = age;
    this.name = name;
  }
  public int getAge() {
    return age;
  }
  public void setAge(int age) {
    this.age = age;
  }
  public String getName() {
    return name;
  }
  public void setName(String name) {
    this.name = name;
  }
  @Override
  public String toString() {
    return "Dog [age=" + age + ", name=" + name + "]";
  }
}
View Code

  测试结果:

# JMH version: 1.19
# VM version: JDK 1.8.0_51, VM 25.51-b03
# VM invoker: D:\soft\java\java8\jre\bin\java.exe
# VM options: -Dfile.encoding=UTF-8
# Warmup: 3 iterations, single-shot each
# Measurement: 5 iterations, single-shot each
# Timeout: 10 min per iteration
# Threads: 1 thread
# Benchmark mode: Single shot invocation time
# Benchmark: yiwangzhibujian.jmh.test.J8Loop.measureWrong_10

# Run progress: 0.00% complete, ETA 00:00:00
# Fork: 1 of 1
# Warmup Iteration   1: 85.205 ms/op
# Warmup Iteration   2: 0.013 ms/op
# Warmup Iteration   3: 0.012 ms/op
Iteration   1: 0.010 ms/op
Iteration   2: 0.013 ms/op
Iteration   3: 0.009 ms/op
Iteration   4: 0.010 ms/op
Iteration   5: 0.011 ms/op


Result "yiwangzhibujian.jmh.test.J8Loop.measureWrong_10":
  N = 5
  mean =      0.010 ±(99.9%) 0.006 ms/op

  Histogram, ms/op:
    [0.008, 0.009) = 0 
    [0.009, 0.009) = 1 
    [0.009, 0.010) = 0 
    [0.010, 0.010) = 2 
    [0.010, 0.011) = 0 
    [0.011, 0.011) = 1 
    [0.011, 0.012) = 0 
    [0.012, 0.012) = 0 
    [0.012, 0.013) = 0 
    [0.013, 0.013) = 0 
    [0.013, 0.014) = 1 

  Percentiles, ms/op:
      p(0.0000) =      0.009 ms/op
     p(50.0000) =      0.010 ms/op
     p(90.0000) =      0.013 ms/op
     p(95.0000) =      0.013 ms/op
     p(99.0000) =      0.013 ms/op
     p(99.9000) =      0.013 ms/op
     p(99.9900) =      0.013 ms/op
     p(99.9990) =      0.013 ms/op
     p(99.9999) =      0.013 ms/op
    p(100.0000) =      0.013 ms/op


# JMH version: 1.19
# VM version: JDK 1.8.0_51, VM 25.51-b03
# VM invoker: D:\soft\java\java8\jre\bin\java.exe
# VM options: -Dfile.encoding=UTF-8
# Warmup: 3 iterations, single-shot each
# Measurement: 5 iterations, single-shot each
# Timeout: 10 min per iteration
# Threads: 1 thread
# Benchmark mode: Single shot invocation time
# Benchmark: yiwangzhibujian.jmh.test.J8Loop.measureWrong_100

# Run progress: 16.67% complete, ETA 00:00:10
# Fork: 1 of 1
# Warmup Iteration   1: 81.395 ms/op
# Warmup Iteration   2: 0.046 ms/op
# Warmup Iteration   3: 0.070 ms/op
Iteration   1: 0.040 ms/op
Iteration   2: 0.065 ms/op
Iteration   3: 0.023 ms/op
Iteration   4: 0.025 ms/op
Iteration   5: 0.024 ms/op


Result "yiwangzhibujian.jmh.test.J8Loop.measureWrong_100":
  N = 5
  mean =      0.035 ±(99.9%) 0.069 ms/op

  Histogram, ms/op:
    [0.020, 0.025) = 3 
    [0.025, 0.030) = 0 
    [0.030, 0.035) = 0 
    [0.035, 0.040) = 1 
    [0.040, 0.045) = 0 
    [0.045, 0.050) = 0 
    [0.050, 0.055) = 0 
    [0.055, 0.060) = 0 
    [0.060, 0.065) = 1 

  Percentiles, ms/op:
      p(0.0000) =      0.023 ms/op
     p(50.0000) =      0.025 ms/op
     p(90.0000) =      0.065 ms/op
     p(95.0000) =      0.065 ms/op
     p(99.0000) =      0.065 ms/op
     p(99.9000) =      0.065 ms/op
     p(99.9900) =      0.065 ms/op
     p(99.9990) =      0.065 ms/op
     p(99.9999) =      0.065 ms/op
    p(100.0000) =      0.065 ms/op


# JMH version: 1.19
# VM version: JDK 1.8.0_51, VM 25.51-b03
# VM invoker: D:\soft\java\java8\jre\bin\java.exe
# VM options: -Dfile.encoding=UTF-8
# Warmup: 3 iterations, single-shot each
# Measurement: 5 iterations, single-shot each
# Timeout: 10 min per iteration
# Threads: 1 thread
# Benchmark mode: Single shot invocation time
# Benchmark: yiwangzhibujian.jmh.test.J8Loop.measureWrong_1000

# Run progress: 33.33% complete, ETA 00:00:08
# Fork: 1 of 1
# Warmup Iteration   1: 85.176 ms/op
# Warmup Iteration   2: 0.201 ms/op
# Warmup Iteration   3: 0.183 ms/op
Iteration   1: 0.195 ms/op
Iteration   2: 0.184 ms/op
Iteration   3: 0.566 ms/op
Iteration   4: 0.101 ms/op
Iteration   5: 0.091 ms/op


Result "yiwangzhibujian.jmh.test.J8Loop.measureWrong_1000":
  N = 5
  mean =      0.227 ±(99.9%) 0.751 ms/op

  Histogram, ms/op:
    [0.000, 0.050) = 0 
    [0.050, 0.100) = 1 
    [0.100, 0.150) = 1 
    [0.150, 0.200) = 2 
    [0.200, 0.250) = 0 
    [0.250, 0.300) = 0 
    [0.300, 0.350) = 0 
    [0.350, 0.400) = 0 
    [0.400, 0.450) = 0 
    [0.450, 0.500) = 0 
    [0.500, 0.550) = 0 
    [0.550, 0.600) = 1 

  Percentiles, ms/op:
      p(0.0000) =      0.091 ms/op
     p(50.0000) =      0.184 ms/op
     p(90.0000) =      0.566 ms/op
     p(95.0000) =      0.566 ms/op
     p(99.0000) =      0.566 ms/op
     p(99.9000) =      0.566 ms/op
     p(99.9900) =      0.566 ms/op
     p(99.9990) =      0.566 ms/op
     p(99.9999) =      0.566 ms/op
    p(100.0000) =      0.566 ms/op


# JMH version: 1.19
# VM version: JDK 1.8.0_51, VM 25.51-b03
# VM invoker: D:\soft\java\java8\jre\bin\java.exe
# VM options: -Dfile.encoding=UTF-8
# Warmup: 3 iterations, single-shot each
# Measurement: 5 iterations, single-shot each
# Timeout: 10 min per iteration
# Threads: 1 thread
# Benchmark mode: Single shot invocation time
# Benchmark: yiwangzhibujian.jmh.test.J8Loop.measureWrong_10000

# Run progress: 50.00% complete, ETA 00:00:06
# Fork: 1 of 1
# Warmup Iteration   1: 85.345 ms/op
# Warmup Iteration   2: 0.698 ms/op
# Warmup Iteration   3: 0.857 ms/op
Iteration   1: 0.866 ms/op
Iteration   2: 0.778 ms/op
Iteration   3: 0.871 ms/op
Iteration   4: 1.047 ms/op
Iteration   5: 0.306 ms/op


Result "yiwangzhibujian.jmh.test.J8Loop.measureWrong_10000":
  N = 5
  mean =      0.774 ±(99.9%) 1.074 ms/op

  Histogram, ms/op:
    [0.300, 0.350) = 1 
    [0.350, 0.400) = 0 
    [0.400, 0.450) = 0 
    [0.450, 0.500) = 0 
    [0.500, 0.550) = 0 
    [0.550, 0.600) = 0 
    [0.600, 0.650) = 0 
    [0.650, 0.700) = 0 
    [0.700, 0.750) = 0 
    [0.750, 0.800) = 1 
    [0.800, 0.850) = 0 
    [0.850, 0.900) = 2 
    [0.900, 0.950) = 0 
    [0.950, 1.000) = 0 
    [1.000, 1.050) = 1 

  Percentiles, ms/op:
      p(0.0000) =      0.306 ms/op
     p(50.0000) =      0.866 ms/op
     p(90.0000) =      1.047 ms/op
     p(95.0000) =      1.047 ms/op
     p(99.0000) =      1.047 ms/op
     p(99.9000) =      1.047 ms/op
     p(99.9900) =      1.047 ms/op
     p(99.9990) =      1.047 ms/op
     p(99.9999) =      1.047 ms/op
    p(100.0000) =      1.047 ms/op


# JMH version: 1.19
# VM version: JDK 1.8.0_51, VM 25.51-b03
# VM invoker: D:\soft\java\java8\jre\bin\java.exe
# VM options: -Dfile.encoding=UTF-8
# Warmup: 3 iterations, single-shot each
# Measurement: 5 iterations, single-shot each
# Timeout: 10 min per iteration
# Threads: 1 thread
# Benchmark mode: Single shot invocation time
# Benchmark: yiwangzhibujian.jmh.test.J8Loop.measureWrong_100000

# Run progress: 66.67% complete, ETA 00:00:04
# Fork: 1 of 1
# Warmup Iteration   1: 96.430 ms/op
# Warmup Iteration   2: 6.303 ms/op
# Warmup Iteration   3: 1.515 ms/op
Iteration   1: 1.337 ms/op
Iteration   2: 1.260 ms/op
Iteration   3: 1.279 ms/op
Iteration   4: 1.210 ms/op
Iteration   5: 1.107 ms/op


Result "yiwangzhibujian.jmh.test.J8Loop.measureWrong_100000":
  N = 5
  mean =      1.238 ±(99.9%) 0.334 ms/op

  Histogram, ms/op:
    [1.100, 1.125) = 1 
    [1.125, 1.150) = 0 
    [1.150, 1.175) = 0 
    [1.175, 1.200) = 0 
    [1.200, 1.225) = 1 
    [1.225, 1.250) = 0 
    [1.250, 1.275) = 1 
    [1.275, 1.300) = 1 
    [1.300, 1.325) = 0 
    [1.325, 1.350) = 1 
    [1.350, 1.375) = 0 
    [1.375, 1.400) = 0 

  Percentiles, ms/op:
      p(0.0000) =      1.107 ms/op
     p(50.0000) =      1.260 ms/op
     p(90.0000) =      1.337 ms/op
     p(95.0000) =      1.337 ms/op
     p(99.0000) =      1.337 ms/op
     p(99.9000) =      1.337 ms/op
     p(99.9900) =      1.337 ms/op
     p(99.9990) =      1.337 ms/op
     p(99.9999) =      1.337 ms/op
    p(100.0000) =      1.337 ms/op


# JMH version: 1.19
# VM version: JDK 1.8.0_51, VM 25.51-b03
# VM invoker: D:\soft\java\java8\jre\bin\java.exe
# VM options: -Dfile.encoding=UTF-8
# Warmup: 3 iterations, single-shot each
# Measurement: 5 iterations, single-shot each
# Timeout: 10 min per iteration
# Threads: 1 thread
# Benchmark mode: Single shot invocation time
# Benchmark: yiwangzhibujian.jmh.test.J8Loop.measureWrong_1000000

# Run progress: 83.33% complete, ETA 00:00:02
# Fork: 1 of 1
# Warmup Iteration   1: 155.436 ms/op
# Warmup Iteration   2: 16.059 ms/op
# Warmup Iteration   3: 10.600 ms/op
Iteration   1: 10.347 ms/op
Iteration   2: 10.207 ms/op
Iteration   3: 11.790 ms/op
Iteration   4: 10.717 ms/op
Iteration   5: 10.128 ms/op


Result "yiwangzhibujian.jmh.test.J8Loop.measureWrong_1000000":
  N = 5
  mean =     10.638 ±(99.9%) 2.628 ms/op

  Histogram, ms/op:
    [10.000, 10.125) = 0 
    [10.125, 10.250) = 2 
    [10.250, 10.375) = 1 
    [10.375, 10.500) = 0 
    [10.500, 10.625) = 0 
    [10.625, 10.750) = 1 
    [10.750, 10.875) = 0 
    [10.875, 11.000) = 0 
    [11.000, 11.125) = 0 
    [11.125, 11.250) = 0 
    [11.250, 11.375) = 0 
    [11.375, 11.500) = 0 
    [11.500, 11.625) = 0 
    [11.625, 11.750) = 0 
    [11.750, 11.875) = 1 

  Percentiles, ms/op:
      p(0.0000) =     10.128 ms/op
     p(50.0000) =     10.347 ms/op
     p(90.0000) =     11.790 ms/op
     p(95.0000) =     11.790 ms/op
     p(99.0000) =     11.790 ms/op
     p(99.9000) =     11.790 ms/op
     p(99.9900) =     11.790 ms/op
     p(99.9990) =     11.790 ms/op
     p(99.9999) =     11.790 ms/op
    p(100.0000) =     11.790 ms/op


# Run complete. Total time: 00:00:13

Benchmark                    Mode  Cnt   Score   Error  Units
J8Loop.measureWrong_10         ss    5   0.010 ± 0.006  ms/op
J8Loop.measureWrong_100        ss    5   0.035 ± 0.069  ms/op
J8Loop.measureWrong_1000       ss    5   0.227 ± 0.751  ms/op
J8Loop.measureWrong_10000      ss    5   0.774 ± 1.074  ms/op
J8Loop.measureWrong_100000     ss    5   1.238 ± 0.334  ms/op
J8Loop.measureWrong_1000000    ss    5  10.638 ± 2.628  ms/op
View Code

  其中最终的结论是:

Benchmark                    Mode  Cnt   Score   Error  Units
J8Loop.measureWrong_10         ss    5   0.010 ± 0.006  ms/op
J8Loop.measureWrong_100        ss    5   0.035 ± 0.069  ms/op
J8Loop.measureWrong_1000       ss    5   0.227 ± 0.751  ms/op
J8Loop.measureWrong_10000      ss    5   0.774 ± 1.074  ms/op
J8Loop.measureWrong_100000     ss    5   1.238 ± 0.334  ms/op
J8Loop.measureWrong_1000000    ss    5  10.638 ± 2.628  ms/op

  然后是表现最好的增强for循环,测试代码:

package yiwangzhibujian.jmh.test;

import org.openjdk.jmh.annotations.*;
import org.openjdk.jmh.runner.Runner;
import org.openjdk.jmh.runner.RunnerException;
import org.openjdk.jmh.runner.options.Options;
import org.openjdk.jmh.runner.options.OptionsBuilder;

import java.util.ArrayList;
import java.util.HashMap;
import java.util.List;
import java.util.Map;
import java.util.concurrent.TimeUnit;

@State(Scope.Thread)
@BenchmarkMode(Mode.SingleShotTime)
@OutputTimeUnit(TimeUnit.MILLISECONDS)
public class J8Loop {
  public static Map<Integer,List<Dog>> dogMap=new HashMap<>();
  static {
    dogMap.put(10, getDogs(10));
    dogMap.put(100, getDogs(100));
    dogMap.put(1000, getDogs(1000));
    dogMap.put(10000, getDogs(10000));
    dogMap.put(100000, getDogs(100000));
    dogMap.put(1000000, getDogs(1000000));
  }
  
  private static List<Dog> getDogs(int num) {
    List<Dog> dogs=new ArrayList<>();
    for(int i=0;i<num;i++){
      dogs.add(new Dog(i,"dog"+i));
    }
    return dogs;
  }
  
  private void loop(List<Dog> list) {
    for(Dog dog:list){
      dog.hashCode();
    }
  }

  @Benchmark
  @OperationsPerInvocation(10)
  public void measureWrong_10() {
    List<Dog> list = dogMap.get(10);
    loop(list);
  }

  @Benchmark
  @OperationsPerInvocation(100)
  public void measureWrong_100() {
    List<Dog> list = dogMap.get(100);
    loop(list);
  }

  @Benchmark
  @OperationsPerInvocation(1000)
  public void measureWrong_1000() {
    List<Dog> list = dogMap.get(1000);
    loop(list);
  }

  @Benchmark
  @OperationsPerInvocation(10000)
  public void measureWrong_10000() {
    List<Dog> list = dogMap.get(10000);
    loop(list);
  }

  @Benchmark
  @OperationsPerInvocation(100000)
  public void measureWrong_100000() {
    List<Dog> list = dogMap.get(100000);
    loop(list);
  }
  
  @Benchmark
  @OperationsPerInvocation(1000000)
  public void measureWrong_1000000() {
    List<Dog> list = dogMap.get(1000000);
    loop(list);
  }

  /*
   * ============================== HOW TO RUN THIS TEST:
   * ====================================
   *
   * You might notice the larger the repetitions count, the lower the
   * "perceived" cost of the operation being measured. Up to the point we do
   * each addition with 1/20 ns, well beyond what hardware can actually do.
   *
   * This happens because the loop is heavily unrolled/pipelined, and the
   * operation to be measured is hoisted from the loop. Morale: don't overuse
   * loops, rely on JMH to get the measurement right.
   *
   * You can run this test:
   *
   * a) Via the command line: $ mvn clean install $ java -jar
   * target/benchmarks.jar JMHSample_11 -wi 5 -i 5 -f 1 (we requested 5
   * warmup/measurement iterations, single fork)
   *
   * b) Via the Java API: (see the JMH homepage for possible caveats when
   * running from IDE: http://openjdk.java.net/projects/code-tools/jmh/)
   */

  public static void main(String[] args) throws RunnerException {
    Options opt = new OptionsBuilder()
        .include(J8Loop.class.getSimpleName())
        .warmupIterations(3)
        .measurementIterations(5).forks(1).build();

    new Runner(opt).run();
  }

}
class Dog{
  private int age;
  private String name;
  public Dog(int age, String name) {
    super();
    this.age = age;
    this.name = name;
  }
  public int getAge() {
    return age;
  }
  public void setAge(int age) {
    this.age = age;
  }
  public String getName() {
    return name;
  }
  public void setName(String name) {
    this.name = name;
  }
  @Override
  public String toString() {
    return "Dog [age=" + age + ", name=" + name + "]";
  }
}
View Code

  测试结果:

# JMH version: 1.19
# VM version: JDK 1.8.0_51, VM 25.51-b03
# VM invoker: D:\soft\java\java8\jre\bin\java.exe
# VM options: -Dfile.encoding=UTF-8
# Warmup: 3 iterations, single-shot each
# Measurement: 5 iterations, single-shot each
# Timeout: 10 min per iteration
# Threads: 1 thread
# Benchmark mode: Single shot invocation time
# Benchmark: yiwangzhibujian.jmh.test.J8Loop.measureWrong_10

# Run progress: 0.00% complete, ETA 00:00:00
# Fork: 1 of 1
# Warmup Iteration   1: 0.047 ms/op
# Warmup Iteration   2: 0.010 ms/op
# Warmup Iteration   3: 0.009 ms/op
Iteration   1: 0.009 ms/op
Iteration   2: 0.011 ms/op
Iteration   3: 0.009 ms/op
Iteration   4: 0.009 ms/op
Iteration   5: 0.010 ms/op


Result "yiwangzhibujian.jmh.test.J8Loop.measureWrong_10":
  N = 5
  mean =      0.010 ±(99.9%) 0.003 ms/op

  Histogram, ms/op:
    [0.008, 0.008) = 0 
    [0.008, 0.009) = 0 
    [0.009, 0.009) = 0 
    [0.009, 0.009) = 2 
    [0.009, 0.009) = 0 
    [0.009, 0.010) = 1 
    [0.010, 0.010) = 0 
    [0.010, 0.010) = 1 
    [0.010, 0.010) = 0 
    [0.010, 0.011) = 0 
    [0.011, 0.011) = 1 

  Percentiles, ms/op:
      p(0.0000) =      0.009 ms/op
     p(50.0000) =      0.009 ms/op
     p(90.0000) =      0.011 ms/op
     p(95.0000) =      0.011 ms/op
     p(99.0000) =      0.011 ms/op
     p(99.9000) =      0.011 ms/op
     p(99.9900) =      0.011 ms/op
     p(99.9990) =      0.011 ms/op
     p(99.9999) =      0.011 ms/op
    p(100.0000) =      0.011 ms/op


# JMH version: 1.19
# VM version: JDK 1.8.0_51, VM 25.51-b03
# VM invoker: D:\soft\java\java8\jre\bin\java.exe
# VM options: -Dfile.encoding=UTF-8
# Warmup: 3 iterations, single-shot each
# Measurement: 5 iterations, single-shot each
# Timeout: 10 min per iteration
# Threads: 1 thread
# Benchmark mode: Single shot invocation time
# Benchmark: yiwangzhibujian.jmh.test.J8Loop.measureWrong_100

# Run progress: 16.67% complete, ETA 00:00:10
# Fork: 1 of 1
# Warmup Iteration   1: 0.068 ms/op
# Warmup Iteration   2: 0.038 ms/op
# Warmup Iteration   3: 0.038 ms/op
Iteration   1: 0.037 ms/op
Iteration   2: 0.025 ms/op
Iteration   3: 0.125 ms/op
Iteration   4: 0.038 ms/op
Iteration   5: 0.038 ms/op


Result "yiwangzhibujian.jmh.test.J8Loop.measureWrong_100":
  N = 5
  mean =      0.053 ±(99.9%) 0.158 ms/op

  Histogram, ms/op:
    [0.000, 0.013) = 0 
    [0.013, 0.025) = 0 
    [0.025, 0.038) = 2 
    [0.038, 0.050) = 2 
    [0.050, 0.063) = 0 
    [0.063, 0.075) = 0 
    [0.075, 0.088) = 0 
    [0.088, 0.100) = 0 
    [0.100, 0.113) = 0 
    [0.113, 0.125) = 0 
    [0.125, 0.138) = 1 
    [0.138, 0.150) = 0 
    [0.150, 0.163) = 0 
    [0.163, 0.175) = 0 
    [0.175, 0.188) = 0 

  Percentiles, ms/op:
      p(0.0000) =      0.025 ms/op
     p(50.0000) =      0.038 ms/op
     p(90.0000) =      0.125 ms/op
     p(95.0000) =      0.125 ms/op
     p(99.0000) =      0.125 ms/op
     p(99.9000) =      0.125 ms/op
     p(99.9900) =      0.125 ms/op
     p(99.9990) =      0.125 ms/op
     p(99.9999) =      0.125 ms/op
    p(100.0000) =      0.125 ms/op


# JMH version: 1.19
# VM version: JDK 1.8.0_51, VM 25.51-b03
# VM invoker: D:\soft\java\java8\jre\bin\java.exe
# VM options: -Dfile.encoding=UTF-8
# Warmup: 3 iterations, single-shot each
# Measurement: 5 iterations, single-shot each
# Timeout: 10 min per iteration
# Threads: 1 thread
# Benchmark mode: Single shot invocation time
# Benchmark: yiwangzhibujian.jmh.test.J8Loop.measureWrong_1000

# Run progress: 33.33% complete, ETA 00:00:08
# Fork: 1 of 1
# Warmup Iteration   1: 0.266 ms/op
# Warmup Iteration   2: 0.310 ms/op
# Warmup Iteration   3: 0.635 ms/op
Iteration   1: 0.297 ms/op
Iteration   2: 0.255 ms/op
Iteration   3: 0.425 ms/op
Iteration   4: 0.413 ms/op
Iteration   5: 0.317 ms/op


Result "yiwangzhibujian.jmh.test.J8Loop.measureWrong_1000":
  N = 5
  mean =      0.341 ±(99.9%) 0.287 ms/op

  Histogram, ms/op:
    [0.200, 0.225) = 0 
    [0.225, 0.250) = 0 
    [0.250, 0.275) = 1 
    [0.275, 0.300) = 1 
    [0.300, 0.325) = 1 
    [0.325, 0.350) = 0 
    [0.350, 0.375) = 0 
    [0.375, 0.400) = 0 
    [0.400, 0.425) = 2 
    [0.425, 0.450) = 0 
    [0.450, 0.475) = 0 

  Percentiles, ms/op:
      p(0.0000) =      0.255 ms/op
     p(50.0000) =      0.317 ms/op
     p(90.0000) =      0.425 ms/op
     p(95.0000) =      0.425 ms/op
     p(99.0000) =      0.425 ms/op
     p(99.9000) =      0.425 ms/op
     p(99.9900) =      0.425 ms/op
     p(99.9990) =      0.425 ms/op
     p(99.9999) =      0.425 ms/op
    p(100.0000) =      0.425 ms/op


# JMH version: 1.19
# VM version: JDK 1.8.0_51, VM 25.51-b03
# VM invoker: D:\soft\java\java8\jre\bin\java.exe
# VM options: -Dfile.encoding=UTF-8
# Warmup: 3 iterations, single-shot each
# Measurement: 5 iterations, single-shot each
# Timeout: 10 min per iteration
# Threads: 1 thread
# Benchmark mode: Single shot invocation time
# Benchmark: yiwangzhibujian.jmh.test.J8Loop.measureWrong_10000

# Run progress: 50.00% complete, ETA 00:00:06
# Fork: 1 of 1
# Warmup Iteration   1: 2.482 ms/op
# Warmup Iteration   2: 2.617 ms/op
# Warmup Iteration   3: 2.814 ms/op
Iteration   1: 2.656 ms/op
Iteration   2: 2.848 ms/op
Iteration   3: 2.636 ms/op
Iteration   4: 1.800 ms/op
Iteration   5: 0.927 ms/op


Result "yiwangzhibujian.jmh.test.J8Loop.measureWrong_10000":
  N = 5
  mean =      2.173 ±(99.9%) 3.101 ms/op

  Histogram, ms/op:
    [0.000, 0.250) = 0 
    [0.250, 0.500) = 0 
    [0.500, 0.750) = 0 
    [0.750, 1.000) = 1 
    [1.000, 1.250) = 0 
    [1.250, 1.500) = 0 
    [1.500, 1.750) = 0 
    [1.750, 2.000) = 1 
    [2.000, 2.250) = 0 
    [2.250, 2.500) = 0 
    [2.500, 2.750) = 2 

  Percentiles, ms/op:
      p(0.0000) =      0.927 ms/op
     p(50.0000) =      2.636 ms/op
     p(90.0000) =      2.848 ms/op
     p(95.0000) =      2.848 ms/op
     p(99.0000) =      2.848 ms/op
     p(99.9000) =      2.848 ms/op
     p(99.9900) =      2.848 ms/op
     p(99.9990) =      2.848 ms/op
     p(99.9999) =      2.848 ms/op
    p(100.0000) =      2.848 ms/op


# JMH version: 1.19
# VM version: JDK 1.8.0_51, VM 25.51-b03
# VM invoker: D:\soft\java\java8\jre\bin\java.exe
# VM options: -Dfile.encoding=UTF-8
# Warmup: 3 iterations, single-shot each
# Measurement: 5 iterations, single-shot each
# Timeout: 10 min per iteration
# Threads: 1 thread
# Benchmark mode: Single shot invocation time
# Benchmark: yiwangzhibujian.jmh.test.J8Loop.measureWrong_100000

# Run progress: 66.67% complete, ETA 00:00:04
# Fork: 1 of 1
# Warmup Iteration   1: 17.857 ms/op
# Warmup Iteration   2: 7.360 ms/op
# Warmup Iteration   3: 2.186 ms/op
Iteration   1: 1.542 ms/op
Iteration   2: 1.419 ms/op
Iteration   3: 2.023 ms/op
Iteration   4: 1.382 ms/op
Iteration   5: 1.448 ms/op


Result "yiwangzhibujian.jmh.test.J8Loop.measureWrong_100000":
  N = 5
  mean =      1.563 ±(99.9%) 1.017 ms/op

  Histogram, ms/op:
    [1.300, 1.350) = 0 
    [1.350, 1.400) = 1 
    [1.400, 1.450) = 2 
    [1.450, 1.500) = 0 
    [1.500, 1.550) = 1 
    [1.550, 1.600) = 0 
    [1.600, 1.650) = 0 
    [1.650, 1.700) = 0 
    [1.700, 1.750) = 0 
    [1.750, 1.800) = 0 
    [1.800, 1.850) = 0 
    [1.850, 1.900) = 0 
    [1.900, 1.950) = 0 
    [1.950, 2.000) = 0 
    [2.000, 2.050) = 1 

  Percentiles, ms/op:
      p(0.0000) =      1.382 ms/op
     p(50.0000) =      1.448 ms/op
     p(90.0000) =      2.023 ms/op
     p(95.0000) =      2.023 ms/op
     p(99.0000) =      2.023 ms/op
     p(99.9000) =      2.023 ms/op
     p(99.9900) =      2.023 ms/op
     p(99.9990) =      2.023 ms/op
     p(99.9999) =      2.023 ms/op
    p(100.0000) =      2.023 ms/op


# JMH version: 1.19
# VM version: JDK 1.8.0_51, VM 25.51-b03
# VM invoker: D:\soft\java\java8\jre\bin\java.exe
# VM options: -Dfile.encoding=UTF-8
# Warmup: 3 iterations, single-shot each
# Measurement: 5 iterations, single-shot each
# Timeout: 10 min per iteration
# Threads: 1 thread
# Benchmark mode: Single shot invocation time
# Benchmark: yiwangzhibujian.jmh.test.J8Loop.measureWrong_1000000

# Run progress: 83.33% complete, ETA 00:00:02
# Fork: 1 of 1
# Warmup Iteration   1: 78.570 ms/op
# Warmup Iteration   2: 21.032 ms/op
# Warmup Iteration   3: 10.005 ms/op
Iteration   1: 12.503 ms/op
Iteration   2: 10.849 ms/op
Iteration   3: 12.988 ms/op
Iteration   4: 12.030 ms/op
Iteration   5: 11.531 ms/op


Result "yiwangzhibujian.jmh.test.J8Loop.measureWrong_1000000":
  N = 5
  mean =     11.980 ±(99.9%) 3.206 ms/op

  Histogram, ms/op:
    [10.000, 10.250) = 0 
    [10.250, 10.500) = 0 
    [10.500, 10.750) = 0 
    [10.750, 11.000) = 1 
    [11.000, 11.250) = 0 
    [11.250, 11.500) = 0 
    [11.500, 11.750) = 1 
    [11.750, 12.000) = 0 
    [12.000, 12.250) = 1 
    [12.250, 12.500) = 0 
    [12.500, 12.750) = 1 

  Percentiles, ms/op:
      p(0.0000) =     10.849 ms/op
     p(50.0000) =     12.030 ms/op
     p(90.0000) =     12.988 ms/op
     p(95.0000) =     12.988 ms/op
     p(99.0000) =     12.988 ms/op
     p(99.9000) =     12.988 ms/op
     p(99.9900) =     12.988 ms/op
     p(99.9990) =     12.988 ms/op
     p(99.9999) =     12.988 ms/op
    p(100.0000) =     12.988 ms/op


# Run complete. Total time: 00:00:12

Benchmark                    Mode  Cnt   Score   Error  Units
J8Loop.measureWrong_10         ss    5   0.010 ± 0.003  ms/op
J8Loop.measureWrong_100        ss    5   0.053 ± 0.158  ms/op
J8Loop.measureWrong_1000       ss    5   0.341 ± 0.287  ms/op
J8Loop.measureWrong_10000      ss    5   2.173 ± 3.101  ms/op
J8Loop.measureWrong_100000     ss    5   1.563 ± 1.017  ms/op
J8Loop.measureWrong_1000000    ss    5  11.980 ± 3.206  ms/op
View Code

  其中最终的结论是:

Benchmark                    Mode  Cnt   Score   Error  Units
J8Loop.measureWrong_10         ss    5   0.010 ± 0.003  ms/op
J8Loop.measureWrong_100        ss    5   0.053 ± 0.158  ms/op
J8Loop.measureWrong_1000       ss    5   0.341 ± 0.287  ms/op
J8Loop.measureWrong_10000      ss    5   2.173 ± 3.101  ms/op
J8Loop.measureWrong_100000     ss    5   1.563 ± 1.017  ms/op
J8Loop.measureWrong_1000000    ss    5  11.980 ± 3.206  ms/op

  如果用折线图对比的话:

  会发现java8的foreach循环效率会更高一筹,真是冤枉了它。

  其他几种循环就没必要测试了,用这两种我觉得就差不多了,如果你写代码思维不够清晰,需要经常debug,建议使用增强for循环,方便调试。

 

  然后说一下有可能让人困惑的预热,我自己也做过测试,这个java8的foreach预热是jvm级别的,只要预热一次,以后速度都是这样的,至于深层次的原因我后续会做研究的。

 

posted @ 2017-06-08 22:30  已往之不谏  阅读(15346)  评论(8编辑  收藏  举报