Name: nt126004 Date: 01/28/2002


FULL PRODUCT VERSION :
java version "1.4.0-rc"
Java(TM) 2 Runtime Environment, Standard Edition (build 1.4.0-rc-b91)
Java HotSpot(TM) Client VM (build 1.4.0-rc-b91, mixed mode)

FULL OPERATING SYSTEM VERSION :
Windows NT Workstation 4.0 sp 5


EXTRA RELEVANT SYSTEM CONFIGURATION :
Pentium II 266

A DESCRIPTION OF THE PROBLEM :
java.nio.MappedByteBuffer takes over 100 ms to fill a 32K
byte array on my system. The problem appears to be related
to the length of the array and not to any need to access
the disk. The file, which is small, should be fully cached.
Also filling an array of half the size takes half the time.

Benchmark code is pasted below. Here's the output:

Elapsed: 121405 ms. Cost per iteration: 121.405 ms

It's possible this is an NT problem. I ran the benchmark on
a low-end Pentium II 266. Still, the difference in speed
between calling MappedByteBuffer.get() and copying an array
is at least four orders of magnitude.

STEPS TO FOLLOW TO REPRODUCE THE PROBLEM :
1. Run the provided benchmark on an NT box.
2.
3.

This bug can be reproduced always.

---------- BEGIN SOURCE ----------
import java.nio.*;
import java.nio.channels.*;
import java.io.*;

public class NIOBench {
        public static void main(String[] args) {
                NIOBench n = new NIOBench();
                try {
                        n.benchmarkMBB();
                } catch (Exception e) { e.printStackTrace(); }
        }
        private void benchmarkMBB() throws Exception {
        final int ITERATIONS = 1000;
        final int FILE_SIZE = 2 * 1024 * 1024; // 2 meg
        final int BYTES_TO_FETCH = 32 * 1024; // 32 k

        RandomAccessFile randFile = new RandomAccessFile("test.tst", "rw");
        randFile.setLength(FILE_SIZE);
        MappedByteBuffer mbb = randFile.getChannel().map(FileChannel.MapMode.R
EAD_WRITE, 0L, FILE_SIZE);
        mbb.force();

        byte [] receiveBuf = new byte [BYTES_TO_FETCH];

        System.out.println("MappedByteBuffer benchmark");
        long start = System.currentTimeMillis();
        for (int i = 0; i < ITERATIONS; i++) {
                mbb.position(0);
                mbb.get(receiveBuf); // this is the slow line
        }
        long end = System.currentTimeMillis();
        long elapsed = end - start;
        System.out.println("Elapsed: " + elapsed + " ms. Cost per iteration: "
+ ((double)elapsed / (double)ITERATIONS) + " ms");


        receiveBuf = new byte [BYTES_TO_FETCH];
        byte [] copyBuf = new byte [BYTES_TO_FETCH];

System.out.println("arraycopy benchmark");
        start = System.currentTimeMillis();
        for (int i = 0; i < ITERATIONS; i++) {
            System.arraycopy(copyBuf, 0, receiveBuf, 0, copyBuf.length);
        }
        end = System.currentTimeMillis();
        elapsed = end - start;
        System.out.println("Elapsed: " + elapsed + " ms. Cost per iteration: "
+ ((double)elapsed / (double)ITERATIONS) + " ms");
        }
}
---------- END SOURCE ----------
(Review ID: 138244)
======================================================================

Name: nt126004 Date: 02/06/2002


FULL PRODUCT VERSION :
java version "1.4.0-rc"
Java(TM) 2 Runtime Environment, Standard Edition (build 1.4.0-rc-b91)
Java HotSpot(TM) Client VM (build 1.4.0-rc-b91, mixed mode)


FULL OPERATING SYSTEM VERSION :
NT SP6 in a 450mhz system, 256 mb ram



A DESCRIPTION OF THE PROBLEM :
[Summary: this is a "performance" bug report -> something
that should be faster is slower....]

I'm sure there's something I don't understand, but the new
memory-mapped i/o in jdk 1.4 is slower than the old style
buffered i/o - which makes no sense
as far as I can tell, as the whole point of memory
mapped i/o [well part of the point] is to save a buffer
copy by letting the user directly use a "kernel" buffer
instead of copying data from kernel to user space [note: I
may be using unix terminology circa the 90's...]. I've only
run this on NT - if people think it's relevant I can run on
win2k and Sun boxes.

In various attempts at benchmarks the memory mapped stuff
is slower - thus there's no point and it might as well be
taken out of the jdk as there's no advantage.

Of course I may be misusing the new stuff so carefully
proofread mmap.java below.

I'm using NT SP6 in a 450mhz system, 256 mb ram.

version:

java version "1.4.0-rc"
Java(TM) 2 Runtime Environment, Standard Edition (build
1.4.0-rc-b91)
Java HotSpot(TM) Client VM (build 1.4.0-rc-b91, mixed mode)

javadoc:

http://java.sun.com/j2se/1.4/docs/api/java/nio/channels/File
Channel.html#map(java.nio.channels.FileChannel.MapMode,%
20long,%20long)
http://java.sun.com/j2se/1.4/docs/guide/nio/index.html

possible relevant bugs:

http://developer.java.sun.com/developer/bugParade/bugs/44919
14.html
http://developer.java.sun.com/developer/bugParade/bugs/44952
99.html

source code, 3 files to follow.

big.java - forms a "big" file, 50MB, "big.dat".
bufio.java - old style buffered i/o
mmap.java - trying to use the new memory mapped i/o - but
maybe I'm doing something wrong?

to repro: run "java big" [assuming "." is in classpath]
to form a 50mb file. then "java bufio" [should run it
several times in a row to be "fair"]. Then "java mmap"
[again, several times]. My results are 700ms for bufio
and 4400ms for mmap, thus old i/o is much faster.


-- big.java --import java.io.*;public class big{
public static void main( String[] args)
throws Throwable { long goal =
50 * 1024 * 1024; byte[] ar =
new byte[ 4096]; FileOutputStream fos = new
FileOutputStream( "big.dat");
BufferedOutputStream baos = new BufferedOutputStream
( fos); while ( goal &gt; 0) {
int want = (int) Math.min( goal, ar.length);
baos.write( ar, 0, want);
goal -= want; } }}--
bufio.java --import java.io.*;import java.util.*;import
java.nio.channels.*;import java.nio.*;public class bufio{
public static void main( String[] args)
throws Throwable { long t1 =
System.currentTimeMillis(); File f = new File
( "big.dat"); FileInputStream fis = new
FileInputStream( f); BufferedInputStream bis =
new BufferedInputStream( fis); byte[] ar= new byte
[ 4096]; long tot = 0; int nr;
while ( (nr = bis.read( ar)) &gt;= 0)
tot += nr; long dt =
System.currentTimeMillis() - t1; o.println
( "Old, buffered I/O done after: "+ dt);
} private static final PrintStream o =
System.out;}-- mmap.java --import java.io.*;import
java.util.*;import java.nio.channels.*;import
java.nio.*;public class mmap{ public static void main(
String[] args) throws Throwable {
long t1 = System.currentTimeMillis();
File f = new File( "big.dat");
FileInputStream fis = new FileInputStream( f);
FileChannel fc = fis.getChannel();
MappedByteBuffer mbb = fc.map(
FileChannel.MapMode.READ_ONLY,
0, f.length());
/* boolean lo = mbb.isLoaded();
if ( ! lo) {
o.print( "Loading..."); o.flush();
mbb.load(); o.print( "now " +
mbb.isLoaded() + " after " +
(System.currentTimeMillis() - t1));
} else
o.print( "Already loaded"); */
o.print( " direct? " + mbb.isDirect());
o.flush(); long remain
= f.length(); byte[] ar =new byte[ 4096];
while( remain &gt; 0) {
int want = Math.min( (int) remain, ar.length);
mbb.get( ar, 0, want);
remain -= want; } long dt =
System.currentTimeMillis() - t1; o.println
( " Done after: "+ dt); } private static final
PrintStream o = System.out;}


STEPS TO FOLLOW TO REPRODUCE THE PROBLEM :

to repro:

[1] compile code.
[2] run "java big" [assuming "." is in classpath]
to form a 50mb file.

[3] then "java bufio" [should run it several times in a row
to be "fair"].

[4] Then "java mmap" [again, several times]. My results are
700ms for bufio
and 4400ms for mmap, thus old i/o is much faster.


EXPECTED VERSUS ACTUAL BEHAVIOR :
Actual: 700ms for 'bufio', 4400ms for 'mmap'

Expected: Well memory mapped i/o has no point if it's
slower, so one would expect that code mmap
prints a *small* number than bufio.

This bug can be reproduced always.

---------- BEGIN SOURCE ----------
I'm having trouble cutting and pasting the code in a form that
preserved line endings correctly - I posted the code
in a forum posting which noone has commented on.

http://forum.java.sun.com/thread.jsp?forum=4&thread=213312
---------- END SOURCE ----------

CUSTOMER WORKAROUND :
Just use old buffered i/o circa jdk1.02.
(Review ID: 139080)
======================================================================