Return-Path: Delivered-To: apmail-db-derby-dev-archive@www.apache.org Received: (qmail 95868 invoked from network); 4 Sep 2004 11:15:49 -0000 Received: from hermes.apache.org (HELO mail.apache.org) (209.237.227.199) by minotaur-2.apache.org with SMTP; 4 Sep 2004 11:15:49 -0000 Received: (qmail 57321 invoked by uid 500); 4 Sep 2004 11:15:48 -0000 Delivered-To: apmail-db-derby-dev-archive@db.apache.org Received: (qmail 57294 invoked by uid 500); 4 Sep 2004 11:15:47 -0000 Mailing-List: contact derby-dev-help@db.apache.org; run by ezmlm Precedence: bulk list-help: list-unsubscribe: list-post: List-Id: "Derby Development" Reply-To: "Derby Development" Delivered-To: mailing list derby-dev@db.apache.org Received: (qmail 57280 invoked by uid 99); 4 Sep 2004 11:15:47 -0000 X-ASF-Spam-Status: No, hits=0.0 required=10.0 tests= X-Spam-Check-By: apache.org Received-SPF: neutral (hermes.apache.org: local policy) Received: from [62.24.64.34] (HELO smtp.dkm.cz) (62.24.64.34) by apache.org (qpsmtpd/0.28) with SMTP; Sat, 04 Sep 2004 04:15:46 -0700 Received: (qmail 40455 invoked by uid 0); 4 Sep 2004 11:15:42 -0000 Received: from lin.code.cz (HELO ?192.168.0.2?) (62.245.69.249) by smtp.dkm.cz with SMTP; 4 Sep 2004 11:15:41 -0000 Message-ID: <4139A433.4010106@code.cz> Date: Sat, 04 Sep 2004 13:17:07 +0200 From: =?ISO-8859-1?Q?Jan_Hlavat=FD?= User-Agent: Mozilla Thunderbird 0.7.3 (Windows/20040803) X-Accept-Language: en-us, en MIME-Version: 1.0 To: Derby Development Subject: Re: java1.4.2 "rws" mode - log write performance References: <6A8D4356-FBDD-11D8-A91C-000D93ADDBD4@serv.net> <4136691B.7030204@Source-Zone.org> <41368CD7.3060700@code.cz> <41374DA0.4040309@sbcglobal.net> In-Reply-To: <41374DA0.4040309@sbcglobal.net> X-Enigmail-Version: 0.85.0.0 X-Enigmail-Supports: pgp-inline, pgp-mime Content-Type: multipart/signed; micalg=pgp-sha1; protocol="application/pgp-signature"; boundary="------------enig859E9A4227CF025546A80FA4" X-Virus-Checked: Checked X-Spam-Rating: minotaur-2.apache.org 1.6.2 0/1000/N This is an OpenPGP/MIME signed message (RFC 2440 and 3156) --------------enig859E9A4227CF025546A80FA4 Content-Type: multipart/mixed; boundary="------------060804070609070108070406" This is a multi-part message in MIME format. --------------060804070609070108070406 Content-Type: text/plain; charset=us-ascii Content-Transfer-Encoding: 7bit As this seems crucial for log performance, I made a test to see for myself what's really the best way to write a log. It tests various forced sequential write methods, with growing and preallocated file. Using direct buffers doesn't seem to have any effect over plain RandomAccessFile.write(byte[]). Following results are from my Athlon XP 1700+ Windows XP Professional machine, with IDE disk that can dish out unsynced writes at 40MB/s, running JDK1.5 RC. It proves Mike's point about "rws" being best on preallocated files on Windows. That is, it can write 10MB/s in 4228 byte chunks, that is about 2490 chunks per sec. So if you want to get 10000 transactions/sec, you will have to combine logs and write them in one chunk. I think that's exactly what Derby does. So we're all good ;) It also shows that sync() / force() are thing to avoid at all costs on Windows ;) Can anyone run the test on another OS? I've attached the source file for the tests. (warning: 10000 records test ran for 30minutes ;-) You can decrease the chunk count) --------------------------------------------- 1. System info: --------------------------------------------- OS Platform: Windows XP/x86/5.1 Java spec: Java Platform API Specification version 1.5 from Sun Microsystems Inc. Java VM: Java HotSpot(TM) Client VM version 1.5.0-rc-b63 from Sun Microsystems Inc. Java home: C:\java\jdk1.5.0\jre Test file: C:\Documents and Settings\hlavac\iotest\test.bin Test file exists, deleting... --------------------------------------------------------------------- 2. Testing growing file using RandomAccessFile "rw" + .getFD().sync() --------------------------------------------------------------------- Chunk size: 4228 bytes Count: 10000 Total time: 283527 ms Writes per second: 35.27 writes/s Time per chunk: 28.353 ms Write bandwidth: 144.0KB/s --------------------------------------------------------------------------- 3. Testing preallocated file using RandomAccessFile "rw" + .getFD().sync() --------------------------------------------------------------------------- Chunk size: 4228 bytes Count: 10000 Total time: 276988 ms Writes per second: 36.103 writes/s Time per chunk: 27.699 ms Write bandwidth: 148.0KB/s --------------------------------------------------------------------- 4. Testing growing file using RandomAccessFile "rws" --------------------------------------------------------------------- Chunk size: 4228 bytes Count: 10000 Total time: 9173 ms Writes per second: 1090.156 writes/s Time per chunk: 0.917 ms Write bandwidth: 4.0MB/s --------------------------------------------------------------------- 5. Testing preallocated file using RandomAccessFile "rws" --------------------------------------------------------------------- Chunk size: 4228 bytes Count: 10000 Total time: 4016 ms Writes per second: 2490.04 writes/s Time per chunk: 0.402 ms Write bandwidth: 10.0MB/s --------------------------------------------------------------------- 6. Testing growing file using RandomAccessFile "rwd" --------------------------------------------------------------------- Chunk size: 4228 bytes Count: 10000 Total time: 10264 ms Writes per second: 974.279 writes/s Time per chunk: 1.026 ms Write bandwidth: 3.0MB/s --------------------------------------------------------------------- 7. Testing preallocated file using RandomAccessFile "rwd" --------------------------------------------------------------------- Chunk size: 4228 bytes Count: 10000 Total time: 5598 ms Writes per second: 1786.352 writes/s Time per chunk: 0.56 ms Write bandwidth: 7.0MB/s ------------------------------------------------------------------------------ 8. Testing growing file using direct buffer + FileChannel "rw" + force(true) ------------------------------------------------------------------------------ Chunk size: 4228 bytes Count: 10000 Total time: 281445 ms Writes per second: 35.531 writes/s Time per chunk: 28.144 ms Write bandwidth: 144.0KB/s ----------------------------------------------------------------------------------- 9. Testing preallocated file using direct buffer + FileChannel "rw" + force(true) ----------------------------------------------------------------------------------- Chunk size: 4228 bytes Count: 10000 Total time: 276638 ms Writes per second: 36.148 writes/s Time per chunk: 27.664 ms Write bandwidth: 148.0KB/s ------------------------------------------------------------------------------ 10. Testing growing file using direct buffer + FileChannel "rw" + force(false) ------------------------------------------------------------------------------ Chunk size: 4228 bytes Count: 10000 Total time: 283908 ms Writes per second: 35.223 writes/s Time per chunk: 28.391 ms Write bandwidth: 144.0KB/s ------------------------------------------------------------------------------ 11. Testing preallocated file using direct buffer + FileChannel "rw" + force(false) ------------------------------------------------------------------------------ Chunk size: 4228 bytes Count: 10000 Total time: 277960 ms Writes per second: 35.976 writes/s Time per chunk: 27.796 ms Write bandwidth: 144.0KB/s ------------------------------------------------------------------------------ 12. Testing growing file using direct buffer + FileChannel "rws" ------------------------------------------------------------------------------ Chunk size: 4228 bytes Count: 10000 Total time: 8733 ms Writes per second: 1145.082 writes/s Time per chunk: 0.873 ms Write bandwidth: 4.0MB/s ------------------------------------------------------------------------------ 13. Testing preallocated file using direct buffer + FileChannel "rws" ------------------------------------------------------------------------------ Chunk size: 4228 bytes Count: 10000 Total time: 3805 ms Writes per second: 2628.121 writes/s Time per chunk: 0.381 ms Write bandwidth: 10.0MB/s ------------------------------------------------------------------------------ 14. Testing growing file using direct buffer + FileChannel "rwd" ------------------------------------------------------------------------------ Chunk size: 4228 bytes Count: 10000 Total time: 10595 ms Writes per second: 943.841 writes/s Time per chunk: 1.06 ms Write bandwidth: 3.0MB/s ------------------------------------------------------------------------------ 15. Testing preallocated file using direct buffer + FileChannel "rwd" ------------------------------------------------------------------------------ Chunk size: 4228 bytes Count: 10000 Total time: 5508 ms Writes per second: 1815.541 writes/s Time per chunk: 0.551 ms Write bandwidth: 7.0MB/s --------------060804070609070108070406 Content-Type: text/plain; name="Main.java" Content-Transfer-Encoding: 8bit Content-Disposition: inline; filename="Main.java" /* * Main.java * * Created on 4. z��� 2004, 10:13 */ package iotest; import java.io.*; import java.nio.*; import java.nio.channels.*; /** * * @author hlavac */ public class Main { public static void main(String[] args) { // change these to play with chunk size/file length int chunksize = 4228; int chunks = 10000; // ~ 40MB try { File testfile = new File("test.bin").getCanonicalFile(); System.out.println("\n---------------------------------------------\n1. System info:\n---------------------------------------------\n"); System.out.println("OS Platform: "+System.getProperty("os.name","unknown")+"/"+System.getProperty("os.arch","unknown")+"/"+System.getProperty("os.version","unknown")); System.out.println(" Java spec: "+System.getProperty("java.specification.name","unknown")+" version "+System.getProperty("java.specification.version","unknown")+" from "+System.getProperty("java.specification.vendor","unknown")); System.out.println(" Java VM: "+System.getProperty("java.vm.name","unknown")+" version "+System.getProperty("java.vm.version","unknown")+" from "+System.getProperty("java.vm.vendor","unknown")); System.out.println(" Java home: "+System.getProperty("java.home","unknown")); System.out.println(" Test file: "+testfile); if (testfile.exists()) { System.out.println("\nTest file exists, deleting..."); testfile.delete(); } long toalsize = chunksize*chunks; byte[] buffer = new byte[chunksize]; buffer[0]='<'; buffer[chunksize-1]='>'; for (int j=1;j'); try { System.out.println( "\n------------------------------------------------------------------------------"+ "\n8. Testing growing file using direct buffer + FileChannel \"rw\" + force(true)" + "\n------------------------------------------------------------------------------"); RandomAccessFile raf = new RandomAccessFile(testfile,"rw"); try { FileChannel fch = raf.getChannel(); try { fch.position(0L); long starttime = System.currentTimeMillis(); for (int i=0; i= GIGA) { return ""+round3(bytes/GIGA)+"G"; } else if (bytes >= MEGA) { return ""+round3(bytes/MEGA)+"M"; } else if (bytes >= KILO) { return ""+round3(bytes/KILO)+"K"; } else { return ""+bytes; } } } --------------060804070609070108070406-- --------------enig859E9A4227CF025546A80FA4 Content-Type: application/pgp-signature; name="signature.asc" Content-Description: OpenPGP digital signature Content-Disposition: attachment; filename="signature.asc" -----BEGIN PGP SIGNATURE----- Version: GnuPG v1.2.4 (MingW32) Comment: Using GnuPG with Thunderbird - http://enigmail.mozdev.org iQEVAwUBQTmkN3FDePgyse5HAQIYSAf9Gl9o9SlcCmo0iwJb8mROK31IktuJ0w3b ECTZ4WmmFjCoWojGhyDnsIgKFmLKXPF9nyEdR2AE+5NmMts3wXI0EN+kKfLOUB7H SqJTSwJUR+cgS7ZYj7Bq0/u5CvssfM+GRsbe1uvRovaSOYUJ08paV5JuS4uiRwl3 9TXpy35IMu4wJl1QPuf0L6z5XU+U5rUCW6bgjkRiQWxyaSA9e7FPQdG/r6b8FG2b 5BYVOfZgLwuPzAYWrnMcDD29kTaRdvVFGWEQJEJ9awZUnGxBwqpUTd7rDFh/pr83 OZQrCHG7+WVLbu2z2E/GPUdERtP746Q46pKZ5MWFK+OKhvokw68pZQ== =VM8l -----END PGP SIGNATURE----- --------------enig859E9A4227CF025546A80FA4--