From owner-freebsd-java Fri Dec 1 10: 9:24 2000 Delivered-To: freebsd-java@freebsd.org Received: from heinz.jollem.com (c104187.upc-c.chello.nl [212.187.104.187]) by hub.freebsd.org (Postfix) with ESMTP id B42BD37B401 for ; Fri, 1 Dec 2000 10:09:17 -0800 (PST) Received: (from ernst@localhost) by heinz.jollem.com (8.11.1/8.9.3) id eB1I8Rn59521; Fri, 1 Dec 2000 19:08:27 +0100 (CET) (envelope-from ernst) Date: Fri, 1 Dec 2000 19:08:27 +0100 From: Ernst de Haan To: "Koster, K.J." Cc: FreeBSD Java mailing list Subject: Re: Performance hint for JDK on FreeBSD Message-ID: <20001201190827.A59487@c187104187.telekabel.chello.nl> References: <59063B5B4D98D311BC0D0001FA7E4522026D7A7D@l04.research.kpn.com> <20001201174923.A57144@c187104187.telekabel.chello.nl> <20001201185031.A58178@c187104187.telekabel.chello.nl> Mime-Version: 1.0 Content-Type: multipart/mixed; boundary="PNTmBPCT7hxwcZjr" Content-Disposition: inline User-Agent: Mutt/1.2i In-Reply-To: <20001201185031.A58178@c187104187.telekabel.chello.nl>; from ernst@jollem.com on Fri, Dec 01, 2000 at 06:50:31PM +0100 Sender: owner-freebsd-java@FreeBSD.ORG Precedence: bulk X-Loop: FreeBSD.org --PNTmBPCT7hxwcZjr Content-Type: text/plain; charset=us-ascii Content-Disposition: inline Ok, the votes are counted, the results are in :) I've written a small Java program I wrote to produce new test results that should be reproducable on other (FreeBSD) systems too. I've included the .java file in an attachment, and, for your convenience, the AWTTest.class file. In the program I do 2 things. First I attempt to load the class java.awt.Toolkit. Then I invoke the class function getDefaultToolkit(), which apparently initializes AWT. Here are the results (I did only one run): Original Applied suggested modifications -------- ------------------------------- Class load: 155 ms. 154 ms. AWT startup: 2454 ms. 437 ms. That's quite a difference, isn't it? :) Could anyone confirm these results for his/her system? Ernst Ernst de Haan wrote: > Heya Kees-Jan and all, > > > > > I never knew that it is a 400% performance boost, which does sound a little > > > strange. I'm really curious why that is. > > > > Well, I turned on profiling, and found that most of the time is spent in X11 > > specific Java code. I will re-run the tests after I temporarily disabled your > > suggested modifications. > > Okay, I did a little profiling (using -Xrunhprof:cpu=times). This is the top > 10 when I dont have the modified font.properties file: > > CPU TIME (ms) BEGIN (total = 29358) Fri Dec 1 17:55:12 2000 > rank self accum count trace method > 1 24.71% 24.71% 253952 1304 sun/io/CharToByteSingleByte.getNative > 2 16.04% 40.76% 8188 1399 sun/io/CharToByteSingleByte.convert > 3 12.93% 53.69% 253952 182 java/lang/String.charAt > 4 2.25% 55.94% 8184 620 java/lang/Throwable.fillInStackTrace > 5 1.44% 57.38% 8258 938 java/lang/String. > 6 1.33% 58.71% 1 1275 sun/awt/font/NativeFontWrapper.registerFonts > 7 1.21% 59.93% 8184 867 java/lang/Throwable. > 8 1.08% 61.01% 10958 153 java/io/StreamTokenizer.read > 9 1.07% 62.08% 10958 623 java/io/BufferedInputStream.read > 10 0.91% 62.99% 318 123 java/util/Properties.loadConvert > > The traces for the top 3 are: > > TRACE 1304: > sun/io/CharToByteSingleByte.getNative > sun/io/CharToByteSingleByte.convert > sun/awt/font/NativeFontWrapper.registerFonts > sun/awt/X11GraphicsEnvironment.registerNativeFonts > > TRACE 1399: > sun/io/CharToByteSingleByte.convert > sun/awt/font/NativeFontWrapper.registerFonts > sun/awt/X11GraphicsEnvironment.registerNativeFonts > sun/java2d/SunGraphicsEnvironment$2.run > > TRACE 182: > java/lang/String.charAt > sun/io/CharToByteSingleByte.getNative > sun/io/CharToByteSingleByte.convert > sun/awt/font/NativeFontWrapper.registerFonts > > Here are the startup times for AWT: > > Original: w/modifications: > ---------------- ------------------------------ > run 1: 2607 ms 608 ms > run 2: 2579 ms 573 ms > run 3: 2583 ms 601 ms > run 4: 2713 ms 599 ms > > Note: The only modifications performed are adding the URW fonts to my > XF86Config and using the font.properties from Kees-Jan's site instead of the > original one! > > Here is the top 10 of CPU time eaters for my application with the > modifications applied: > > CPU TIME (ms) BEGIN (total = 9169) Fri Dec 1 17:46:56 2000 > rank self accum count trace method > 1 2.91% 2.91% 318 110 java/util/Properties.loadConvert > 2 2.75% 5.66% 252 109 java/util/Properties.loadConvert > 3 2.25% 7.91% 5 158 java/util/Properties.load > 4 1.98% 9.89% 6356 987 java/lang/String.indexOf > 5 1.73% 11.63% 5479 584 java/io/BufferedInputStream.read > 6 1.73% 13.36% 5479 142 java/io/StreamTokenizer.read > 7 1.49% 14.85% 8590 203 java/lang/StringBuffer.append > 8 1.42% 16.27% 8590 675 java/lang/String.charAt > 9 1.41% 17.68% 8133 946 java/lang/StringBuffer.append > 10 1.36% 19.04% 8133 207 java/lang/String.charAt > > Now all of a sudden my application code comes on top. And that's the way I > like it! :) > > IMHO these results are quite amazing! > > Next thing I'll do is write a small program that will do nothing but starting > AWT and displaying the startup times, as the current results are obtained by > looking at the log output of my own Swing application. > > > Ernst > > > To Unsubscribe: send mail to majordomo@FreeBSD.org > with "unsubscribe freebsd-java" in the body of the message > --PNTmBPCT7hxwcZjr Content-Type: text/plain; charset=us-ascii Content-Disposition: attachment; filename="AWTTest.java" public class AWTTest { public static void main(String[] args) throws Exception { // Load the Toolkit class from the AWT package long beforeClassLoad = System.currentTimeMillis(); Class c = Class.forName("java.awt.Toolkit"); long afterClassLoad = System.currentTimeMillis(); // Get the getDefaultToolkit() class function java.lang.reflect.Method m = c.getMethod("getDefaultToolkit", null); // Invoke the class function long beforeInvoke = System.currentTimeMillis(); m.invoke(null, null); long afterInvoke = System.currentTimeMillis(); long t1 = afterClassLoad - beforeClassLoad; long t2 = afterInvoke - beforeInvoke; System.out.println("Class load took: " + t1 + " ms."); System.out.println("AWT startup took: " + t2 + " ms."); System.exit(0); } } --PNTmBPCT7hxwcZjr Content-Type: application/octet-stream Content-Disposition: attachment; filename="AWTTest.class" Content-Transfer-Encoding: base64 yv66vgADAC0ATgcAAgEAB0FXVFRlc3QHAAQBABBqYXZhL2xhbmcvT2JqZWN0AQAEbWFpbgEA FihbTGphdmEvbGFuZy9TdHJpbmc7KVYBAApFeGNlcHRpb25zBwAJAQATamF2YS9sYW5nL0V4 Y2VwdGlvbgEABENvZGUBAA9MaW5lTnVtYmVyVGFibGUMAA0ADgEAEWN1cnJlbnRUaW1lTWls bGlzAQADKClKCgAQAAwHABEBABBqYXZhL2xhbmcvU3lzdGVtCAATAQAQamF2YS5hd3QuVG9v bGtpdAwAFQAWAQAHZm9yTmFtZQEAJShMamF2YS9sYW5nL1N0cmluZzspTGphdmEvbGFuZy9D bGFzczsKABgAFAcAGQEAD2phdmEvbGFuZy9DbGFzcwgAGwEAEWdldERlZmF1bHRUb29sa2l0 DAAdAB4BAAlnZXRNZXRob2QBAEAoTGphdmEvbGFuZy9TdHJpbmc7W0xqYXZhL2xhbmcvQ2xh c3M7KUxqYXZhL2xhbmcvcmVmbGVjdC9NZXRob2Q7CgAYABwMACEAIgEABmludm9rZQEAOShM amF2YS9sYW5nL09iamVjdDtbTGphdmEvbGFuZy9PYmplY3Q7KUxqYXZhL2xhbmcvT2JqZWN0 OwoAJAAgBwAlAQAYamF2YS9sYW5nL3JlZmxlY3QvTWV0aG9kDAAnACgBAANvdXQBABVMamF2 YS9pby9QcmludFN0cmVhbTsJABAAJgcAKwEAFmphdmEvbGFuZy9TdHJpbmdCdWZmZXIMAC0A LgEABjxpbml0PgEAAygpVgoAKgAsCAAxAQASQ2xhc3MgbG9hZCB0b29rOiAgDAAzADQBAAZh cHBlbmQBACwoTGphdmEvbGFuZy9TdHJpbmc7KUxqYXZhL2xhbmcvU3RyaW5nQnVmZmVyOwoA KgAyDAAzADcBABsoSilMamF2YS9sYW5nL1N0cmluZ0J1ZmZlcjsKACoANggAOgEABCBtcy4M ADwAPQEACHRvU3RyaW5nAQAUKClMamF2YS9sYW5nL1N0cmluZzsKACoAOwwAQABBAQAHcHJp bnRsbgEAFShMamF2YS9sYW5nL1N0cmluZzspVgoAQwA/BwBEAQATamF2YS9pby9QcmludFN0 cmVhbQgARgEAEkFXVCBzdGFydHVwIHRvb2s6IAwASABJAQAEZXhpdAEABChJKVYKABAARwoA AwAsAQAKU291cmNlRmlsZQEADEFXVFRlc3QuamF2YQAhAAEAAwAAAAAAAgAJAAUABgACAAcA AAAEAAEACAAKAAAAwgAEAA8AAAB6uAAPQBISuAAXTrgADzcELRIaAbYAHzoGuAAPNwcZBgEB tgAjV7gADzcJFgQfZTcLFgkWB2U3DbIAKbsAKlm3AC8SMLYANRYLtgA4Ejm2ADW2AD62AEKy ACm7ACpZtwAvEkW2ADUWDbYAOBI5tgA1tgA+tgBCA7gASrEAAAABAAsAAAA2AA0AAAAGAAQA BwAKAAgADwALABgADgAdAA8AJQAQACoAEgAwABMANwAVAFYAFgB1ABcAeQAYAAEALQAuAAEA CgAAACEAAQABAAAABSq3AEuxAAAAAQALAAAACgACAAAAAQAEAAEAAQBMAAAAAgBN --PNTmBPCT7hxwcZjr-- To Unsubscribe: send mail to majordomo@FreeBSD.org with "unsubscribe freebsd-java" in the body of the message