java - 奇怪的方法调用优化问题

Question

我一直在测试 DataInputStream.readByte() 方法运行太慢的问题，发现有趣但难以理解的问题。我正在使用 jdk1.7.0_40，Windows 7 64 位。

假设我们有一些巨大的字节数组并从中读取数据。让我们比较 4 种从这个数组中逐字节读取的方法:

1. 通过简单的循环阅读
2. 通过 ByteArrayInputStream 读取 -> DataInputStream
3. 通过 ByteArrayInputStream 读取 -> 我们自己的 DataInputStream 实现 (MyDataInputStream)
4. 通过 ByteArrayInputStream 读取并从 DataInputStream 复制方法 readByte()。

我发现了以下结果(经过长时间的测试循环迭代):

• 循环大约花费了。 312446094 纳秒
• DataInputStream 取了 apox。 2555898090 纳秒
• MyDataInputStream 花费了大约。 2630664298 纳秒
• 通过方法 readByte() 复制耗时 309265568 ns

换句话说，我们遇到了奇怪的优化问题:通过对象方法调用的相同操作比通过“ native ”实现花费的时间长 10 倍。

问题:为什么？。

信息:

@Test
public void testBytes1() throws IOException {
    byte[] bytes = new byte[1_000_000_000];
    Random r = new Random();
    for (int i = 0; i < bytes.length; i++)
        bytes[i] = (byte) r.nextInt();

    do {
        System.out.println();

        bytes[r.nextInt(1_000_000_000)] = (byte) r.nextInt();

        testLoop(bytes);
        testDis(bytes);
        testMyDis(bytes);
        testViaMethod(bytes);
    } while (true);
}

private void testDis(byte[] bytes) throws IOException {
    long time1 = System.nanoTime();
    long c = 0;
    try (ByteArrayInputStream bais = new ByteArrayInputStream(bytes);
         DataInputStream dis = new DataInputStream(bais)) {
        for (int i = 0; i < bytes.length; i++) {
            c += dis.readByte();
        }
    }
    long time2 = System.nanoTime();
    System.out.println("Dis: \t\t\t\t" + (time2 - time1) + "\t\t\t\t" + c);
}

private void testMyDis(byte[] bytes) throws IOException {
    long time1 = System.nanoTime();
    long c = 0;
    try (ByteArrayInputStream bais = new ByteArrayInputStream(bytes);
         MyDataInputStream dis = new MyDataInputStream(bais)) {
        for (int i = 0; i < bytes.length; i++) {
            c += dis.readByte();
        }
    }
    long time2 = System.nanoTime();
    System.out.println("My Dis: \t\t\t" + (time2 - time1) + "\t\t\t\t" + c);
}

private void testViaMethod(byte[] bytes) throws IOException {
    long time1 = System.nanoTime();
    long c = 0;
    try (ByteArrayInputStream bais = new ByteArrayInputStream(bytes)
    ) {
        for (int i = 0; i < bytes.length; i++) {
            c += readByte(bais);
        }
    }
    long time2 = System.nanoTime();
    System.out.println("Via method: \t\t" + (time2 - time1) + "\t\t\t\t" + c);
}

private void testLoop(byte[] bytes) {
    long time1 = System.nanoTime();
    long c = 0;
    for (int i = 0; i < bytes.length; i++) {
        c += bytes[i];
    }
    long time2 = System.nanoTime();
    System.out.println("Loop: \t\t\t\t" + (time2 - time1) + "\t\t\t\t" + c);
}

public final byte readByte(InputStream in) throws IOException {
    int ch = in.read();
    if (ch < 0)
        throw new EOFException();
    return (byte)(ch);
}

static class MyDataInputStream implements Closeable {

    InputStream in;

    MyDataInputStream(InputStream in) {
        this.in = in;
    }

    public final byte readByte() throws IOException {
        int ch = in.read();
        if (ch < 0)
            throw new EOFException();
        return (byte)(ch);
    }

    @Override
    public void close() throws IOException {
        in.close();
    }
}

附言更新 对于那些对我的结果有疑问的人，这是打印输出，使用 -XX:+PrintCompilation -verbose:gc -XX:CICompilerCount=1

     37    1             java.lang.String::hashCode (55 bytes)
     41    2             java.lang.String::charAt (29 bytes)
     43    3             java.lang.String::indexOf (70 bytes)
     49    4             java.lang.AbstractStringBuilder::ensureCapacityInternal (16 bytes)
     52    5             java.lang.AbstractStringBuilder::append (29 bytes)
    237    6             java.util.Random::nextInt (7 bytes)
    237    9     n       sun.misc.Unsafe::compareAndSwapLong (native)   
    238    7             java.util.concurrent.atomic.AtomicLong::get (5 bytes)
    238    8             java.util.concurrent.atomic.AtomicLong::compareAndSet (13 bytes)
    239   10             java.util.Random::next (47 bytes)
    239   11 %           fias.TestArrays::testBytes1 @ 15 (77 bytes)
   9645   11 %           fias.TestArrays::testBytes1 @ -2 (77 bytes)   made not entrant

   9646   12 %           fias.TestArrays::testLoop @ 10 (77 bytes)
   9964   12 %           fias.TestArrays::testLoop @ -2 (77 bytes)   made not entrant
Loop:               318726397               -500090432
   9965   13             java.io.DataInputStream::readByte (23 bytes)
   9966   14  s          java.io.ByteArrayInputStream::read (36 bytes)
   9967   15 % !         fias.TestArrays::testDis @ 37 (279 bytes)
Dis:                2684374258              -500090432
  12651   16             fias.TestArrays$MyDataInputStream::readByte (23 bytes)
  12652   17 % !         fias.TestArrays::testMyDis @ 37 (279 bytes)
My Dis:             2675570541              -500090432
  15327   18             fias.TestArrays::readByte (20 bytes)
  15328   19 % !         fias.TestArrays::testViaMethod @ 23 (179 bytes)
Via method:         2367507141              -500090432

  17694   20             fias.TestArrays::testLoop (77 bytes)
  17699   21 %           fias.TestArrays::testLoop @ 10 (77 bytes)
Loop:               374525891               -500090567
  18069   22   !         fias.TestArrays::testDis (279 bytes)
Dis:                2674626125              -500090567
  20745   23   !         fias.TestArrays::testMyDis (279 bytes)
My Dis:             2671418683              -500090567
  23417   24   !         fias.TestArrays::testViaMethod (179 bytes)
Via method:         2359181776              -500090567

Loop:               315081855               -500090663
Dis:                2558738649              -500090663
My Dis:             2627056034              -500090663
Via method:         311692727               -500090663

Loop:               317813286               -500090778
Dis:                2565161726              -500090778
My Dis:             2630665760              -500090778
Via method:         314594434               -500090778

Loop:               313695660               -500090797
Dis:                2568251556              -500090797
My Dis:             2635236578              -500090797
Via method:         311882312               -500090797

Loop:               316781686               -500090929
Dis:                2563535623              -500090929
My Dis:             2638487613              -500090929
Via method:         313170789               -500090929

UPD-2:这是benchmark和 results @maaartinus 友情赠送。

Answer 1

令人惊讶的是，原因是 MyDataInputStream/DataInputStream 上的 try-with-resources 语句

如果我们将初始化移动到 try block 中，性能将类似于循环/方法调用

private void testMyDis(byte[] bytes) throws IOException {
    final long time1 = System.nanoTime();
    long c = 0;
    try (ByteArrayInputStream bais = new ByteArrayInputStream(bytes)) {
        final MyDataInputStream dis = new MyDataInputStream(bais);
        for (int i = 0; i < bytes.length; i++) {
            c += dis.readByte();
        }
    }
    final long time2 = System.nanoTime();
    System.out.println("My Dis: \t\t\t" + (time2 - time1) + "\t\t\t\t" + c);
}

我认为 JIT 不能使用那些不必要的资源 Range Check Elimination