0

When I debugged my application, I located the problem at last. I can reproduce it, but I have no idea why it happens. Here's the entire code:

public static MappedByteBuffer map(File file, long length) throws IOException {
    RandomAccessFile raf = new RandomAccessFile(file, "rw");
    try {
        if (length > 0) {
            raf.setLength(length);
        }
        try {
            return raf.getChannel().map(FileChannel.MapMode.READ_WRITE, 0, file.length());
        } catch (IOException e) {
            System.gc();
            System.runFinalization();
            return raf.getChannel().map(FileChannel.MapMode.READ_WRITE, 0, file.length());
        }
    } finally {
        raf.close();
    }
}

public static void main(String[] args) throws IOException, InterruptedException {
    long t = System.currentTimeMillis();
    MappedByteBuffer mbb = map(new File("temp.mmp"), 1024L * 1024 * 1024);

    System.out.println("load " + (System.currentTimeMillis() - t));//*
    for (int i = 0; i < 2014L * 1024 * 1024; i++) {}//*
    int d = 0;
    for (int j = 0; j < 10; j++) {
        t = System.currentTimeMillis();
        mbb.position(0);
        mbb.limit(mbb.capacity());

        for (int i = 0; i < mbb.capacity(); i++) {
            d += mbb.get();
        }
        System.out.println(j + " " + (System.currentTimeMillis() - t));
    }
    System.out.println(d);
}

The output is:

load 3
0 3429
1 3443
2 3203
3 3197
4 3203
5 3194
6 3247
7 3216
8 3211
9 3201
-1073741824

After commenting out the two lines marked with //*, The output is:

0 782
1 804
2 539
3 557
4 545
5 558
6 546
7 546
8 545
9 557
-1073741824

I've tested under JDK 6/7/8 and Windows7 64 OS, there's no difference. But under linux/CentOS the problem is gone. Is it a Java bug? Or something I do wrong. Thanks for help.

After further study, I learned that this is a thing about JIT. But I can not tell why still.

A new test code:

public static void main(String args[]) {
    System.out.println("a");//1
    for (int i = 0; i <   1073741824; i++) {}//2
    {
        long d = 0;
        long t = System.currentTimeMillis();
        for (int j = 0; j < 40; j++) {
            for (int x = 0; x < 1073741824; x++) {
                d += 1;
            }
        }
        System.out.println(d + " " + (System.currentTimeMillis() - t));
    }
    {
        long d = 0;
        long t = System.currentTimeMillis();
        for (int j = 0; j < 40; j++) {
            for (int x = 0; x < 1073741824; x++) {
                d += 1;
            }
        }
        System.out.println(d + " " + (System.currentTimeMillis() - t));
    }
}

output is:

a
42949672960 792
42949672960 1563

To comment/uncomment the lines of //1 or //2 will affect results. Strange things.

  • 3
    Excuse me, what is wrong? What is your problem? – Thomas Uhrig Jun 19 '14 at 06:32
  • 1
    Ah OK, I think I got it: If you remove the two line you marked with `//*` the execution is much faster, although the two lines are not inside the code you measure. – Thomas Uhrig Jun 19 '14 at 06:36
  • 1
    So, I cannot reproduce your problem. I'm on a Win 7 (64 bit) laptop with Java 8 and it all works fine. I can advice you 2 things: (1) remove the empty for-loop, it's useless and (2) be very careful with micro benchmarking. As you see, your first iteration take much long as your last iterations (3429 to 3201 and 804 to 557). That's a difference of 30%! The JVM optimize code, has an own startup-time and is super complex. Read more at http://stackoverflow.com/questions/504103/how-do-i-write-a-correct-micro-benchmark-in-java and repeat you test with a real benchmark tool. – Thomas Uhrig Jun 19 '14 at 06:48
  • no obvious difference after commented it. – BlackJoker Jun 19 '14 at 08:44
  • @ThomasUhrig Yes you got it. Sorry I don't speak English well. – kobevaliant Jun 19 '14 at 08:58
  • I think I find a clue. When use eclipse(jdt) to compile there's no difference. So it's javac bug? – kobevaliant Jun 19 '14 at 10:10

0 Answers0