Duplicate :
|
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 > 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)) >= 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 > 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) ======================================================================