- Community Home
- >
- Servers and Operating Systems
- >
- Operating Systems
- >
- Operating System - OpenVMS
- >
- Re: Slow Java startup Alpha vs. I64: excessive dir...
Categories
Company
Local Language
Forums
Discussions
Forums
- Data Protection and Retention
- Entry Storage Systems
- Legacy
- Midrange and Enterprise Storage
- Storage Networking
- HPE Nimble Storage
Discussions
Discussions
Discussions
Forums
Discussions
Discussion Boards
Discussion Boards
Discussion Boards
Discussion Boards
- BladeSystem Infrastructure and Application Solutions
- Appliance Servers
- Alpha Servers
- BackOffice Products
- Internet Products
- HPE 9000 and HPE e3000 Servers
- Networking
- Netservers
- Secure OS Software for Linux
- Server Management (Insight Manager 7)
- Windows Server 2003
- Operating System - Tru64 Unix
- ProLiant Deployment and Provisioning
- Linux-Based Community / Regional
- Microsoft System Center Integration
Discussion Boards
Discussion Boards
Discussion Boards
Discussion Boards
Discussion Boards
Discussion Boards
Discussion Boards
Discussion Boards
Discussion Boards
Discussion Boards
Discussion Boards
Discussion Boards
Discussion Boards
Discussion Boards
Discussion Boards
Discussion Boards
Discussion Boards
Discussion Boards
Discussion Boards
Community
Resources
Forums
Blogs
- Subscribe to RSS Feed
- Mark Topic as New
- Mark Topic as Read
- Float this Topic for Current User
- Bookmark
- Subscribe
- Printer Friendly Page
- Mark as New
- Bookmark
- Subscribe
- Mute
- Subscribe to RSS Feed
- Permalink
- Report Inappropriate Content
02-10-2012 04:47 AM - edited 02-10-2012 04:58 AM
02-10-2012 04:47 AM - edited 02-10-2012 04:58 AM
We're trying to assess if running JRuby on Alpha is practical, and need answers for why resource usage just to start the application on Alpha is so much higher than Itanium for the same minimal test case.
Using a vanilla JRuby 1.6.0 from upstream unpacked at JRUBY_ROOT and defining the JRuby command as follows, I am seeing startup times on JRE 1.5 on Alpha that are way out of line with startup times on JRE 1.6 on Itanium. This reflects in a much higher BUFIO time as well. With SET WATCH enabled I see excessive directory scans for non-existent path components on Alpha that aren't happening on IA64. I have tried messing with classpath and bootclasspath (which are equivalent on both systems, i.e. CLASSPATH and JAVA$CLASSPATH are not defined, so it should be set to just what you see in my test command) to try to resolve the issue but so far have been unable to prevent the JRuby on Alpha from making so many useless directory scans. What am I missing? Why the big difference between architectures?
$ show sym jruby JRUBY== "$ SYS$COMMON:[JAVA$150.bin]java$java "-Djruby.home=/jruby_root" "-Djruby.lib=/jruby_root/lib" "-Djruby.script=jr uby" "-Djruby.memory.max=500m" "-Djruby.stack.max=1024k" "-Xmx500m" "-Xss1024k" "Xbootclasspath/a:/jruby_root/lib/jruby.jar" "org.jruby.Main" " $ show log jruby_root "JRUBY_ROOT" = "DYM$SYS_V:[DYMAX.JRUBY]" (LNM$PROCESS_TABLE) $ type hworld.rb puts "hello world" $ jruby hworld.rb
On IA64, using the above example code, typical resource usage is:
Dirio= 6383 Bufio= 1003 Kernel= 44 Exec= 5 User=126 Elapsed= 355
For the above example on Alpha, typical resource usage is:
Dirio= 5707 Bufio= 18473 Kernel=786 Exec=311 User=490 Elapsed= 3653
As for the count of failed directory scans on Itanium for the same example above:
search rtest_i64.log "directory scan","status: 00000000"/mat=and/stat/out=nl: Files searched: 1 Buffered I/O count: 8 Records searched: 6733 Direct I/O count: 418 Characters searched: 853299 Page faults: 26 Records matched: 404 Elapsed CPU time: 0 00:00:00.03 Lines printed: 404 Elapsed time: 0 00:00:00.03
And on Alpha:
search rtest_alp4.log "directory scan","status: 00000000"/mat=and/stat/out=nl: Files searched: 1 Buffered I/O count: 8 Records searched: 96908 Direct I/O count: 13541 Characters searched: 12760392 Page faults: 26 Records matched: 13338 Elapsed CPU time: 0 00:00:00.57 Lines printed: 13338 Elapsed time: 0 00:00:00.57
So, again, orders of magnitude difference.
Here are some example failed directory scans that appear on Alpha but not on Itanium:
%XQP, Thread #0, Directory scan for: MAIN.CLASS;0, Status: 00000000 %XQP, Thread #0, Directory scan for: MAIN_CLASS.DIR;1, Status: 00000000 %XQP, Thread #0, Directory scan for: MAIN_CLASS.;0, Status: 00000000 %XQP, Thread #0, Directory scan for: MAIN_CLASS.;0, Status: 00000000 %XQP, Thread #0, Directory scan for: MAIN_CLASS.DIR;0, Status: 00000000 %XQP, Thread #0, Directory scan for: MAIN$STATUS.CLASS;0, Status: 00000000 %XQP, Thread #0, Directory scan for: MAIN$STATUS_CLASS.DIR;1, Status: 00000000 %XQP, Thread #0, Directory scan for: MAIN$STATUS_CLASS.;0, Status: 00000000 %XQP, Thread #0, Directory scan for: MAIN$STATUS_CLASS.;0, Status: 00000000 %XQP, Thread #0, Directory scan for: MAIN$STATUS_CLASS.DIR;0, Status: 00000000 %XQP, Thread #0, Directory scan for: RUBYTHREAD$S$0$0$MAIN.CLASS;0, Status: 00000000 %XQP, Thread #0, Directory scan for: RUBYTHREAD$S$0$0$MAIN_CLASS.DIR;1, Status: 00000000 %XQP, Thread #0, Directory scan for: RUBYTHREAD$S$0$0$MAIN_CLASS.;0, Status: 00000000 %XQP, Thread #0, Directory scan for: RUBYTHREAD$S$0$0$MAIN_CLASS.;0, Status: 00000000 %XQP, Thread #0, Directory scan for: RUBYTHREAD$S$0$0$MAIN_CLASS.DIR;0, Status: 00000000 %XQP, Thread #0, Directory scan for: RUBYNUMERIC$I$1$0$REMAINDER.CLASS;0, Status: 00000000 %XQP, Thread #0, Directory scan for: RUBYNUMERIC$I$1$0$REMAINDER_CLASS.DIR;1, Status: 00000000 %XQP, Thread #0, Directory scan for: RUBYNUMERIC$I$1$0$REMAINDER_CLASS.;0, Status: 00000000 %XQP, Thread #0, Directory scan for: RUBYNUMERIC$I$1$0$REMAINDER_CLASS.;0, Status: 00000000 %XQP, Thread #0, Directory scan for: RUBYNUMERIC$I$1$0$REMAINDER_CLASS.DIR;0, Status: 00000000
We believe if we can get Java from looking all over hell and creation for stuff it's going to fail to find anyway, we could dramatically improve JRuby startup time on Alpha. Can someone who knows what's going on between the two Java implementations please help explain our results? Better yet, please point us in the right direction for resolving the issue.
Thanks,
Ben
p.s. I did a brief test with JRuby 1.6.5 and the numbers were not significantly different. so I have no reason to believe the latest release, 1.6.6, would be any better either.
p.p.s. In case it matters, my Java versions are:
java version "1.5.0" Java(TM) 2 Runtime Environment, Standard Edition Fast VM (build 1.5.0-6.p1, build J2SDK.v.1.5.0:11/16/2009-20:33, native threads, jit_150) java version "1.6.0" Java(TM) SE Runtime Environment Java HotSpot(TM) 64-Bit Server VM (build 14.3-b01, mixed mode)
Solved! Go to Solution.
- Tags:
- Java
- Mark as New
- Bookmark
- Subscribe
- Mute
- Subscribe to RSS Feed
- Permalink
- Report Inappropriate Content
02-10-2012 02:22 PM
02-10-2012 02:22 PM
Re: Slow Java startup Alpha vs. I64: excessive directory scans (vanilla upstream JRuby)
Well written problem description. Thank you!
What does the logical name DYM$SYS_V translate to on the Alpha, versus the Itanium.
As you drill down on that name, maybe one system has a much wider search list than the other?
If a search list is currently involved, can you retry with a simple logical name pointing directly to the right disk/directory?
Java/Ruby will have been installed on an ODS-5 disk.
But that DYM$SYS_V , is it pointing to volumes with the same file structure level (2 or 5) on Alpha versus Itanium?
Can you somehow make it find what it is looking for in a benign way? (by re-arranging the search lists if those are in play).
fwiw,
Hein.
- Mark as New
- Bookmark
- Subscribe
- Mute
- Subscribe to RSS Feed
- Permalink
- Report Inappropriate Content
02-11-2012 08:51 AM
02-11-2012 08:51 AM
Re: Slow Java startup Alpha vs. I64: excessive directory scans (vanilla upstream JRuby)
- Mark as New
- Bookmark
- Subscribe
- Mute
- Subscribe to RSS Feed
- Permalink
- Report Inappropriate Content
02-13-2012 02:08 AM
02-13-2012 02:08 AM
Re: Slow Java startup Alpha vs. I64: excessive directory scans (vanilla upstream JRuby)
DYM$SYS_V is the same on both systems:
"DYM$SYS_V" = "$2$DKC0:" (LNM$SYSTEM_TABLE)
This is an ODS-5 volume.
- Mark as New
- Bookmark
- Subscribe
- Mute
- Subscribe to RSS Feed
- Permalink
- Report Inappropriate Content
02-13-2012 02:56 AM - edited 02-13-2012 02:59 AM
02-13-2012 02:56 AM - edited 02-13-2012 02:59 AM
Re: Slow Java startup Alpha vs. I64: excessive directory scans (vanilla upstream JRuby)
There were indeed searches for "ORG_JRUBY_MAIN.". I only showed the paths matching the string "main" that were in the Alpha log but not in the Itanium log. However, on the Itanium those searches were for "org_jruby_Main.". That is due to these settings on Itanium that are not set on Alpha, particularly the case preserve setting:
(LNM$JOB_887817C0) "DECC$ARGV_PARSE_STYLE" = "ENABLE" "DECC$EFS_CASE_PRESERVE" = "ENABLE" "DECC$EFS_CHARSET" = "ENABLE"
That makes the Itanium scan for mixed case paths, but it doesn't change which paths are being scanned for. Nor does it influence the timings positively when set on the Alpha. Here is the common set of paths matching the string "main" that are scanned for unsuccessfully on both platforms in a new test with the above settings now applied to the Alpha as well:
%XQP, Thread #0, Directory scan for: org_jruby.Main.DIR;1, Status: 00000000 %XQP, Thread #0, Directory scan for: org_jruby.Main;0, Status: 00000000 %XQP, Thread #0, Directory scan for: org_jruby.Main;0, Status: 00000000 %XQP, Thread #0, Directory scan for: org_jruby_Main.DIR;1, Status: 00000000 %XQP, Thread #0, Directory scan for: org_jruby_Main.;0, Status: 00000000 %XQP, Thread #0, Directory scan for: org_jruby_Main.;0, Status: 00000000 %XQP, Thread #0, Directory scan for: org_jruby_Main.DIR;0, Status: 00000000
As for JAVA$FILENAME_CONTROLS, that is set to -1 on both systems.
There is nothing in either log matching "main" and "00000001". In fact, there is nothing at all matching the "main" other than the "Status: 00000000" entries shown above that are found in both logs and the now mixed-cased ones from which I showed you an excerpt in my original post (35 lines in all). And all that is consistent with your observation that the additional searches should only happen if "Main" can not be found in jruby.jar (and clearly it is, since the test program works on both systems). That's what I thought, too, so it's a real puzzler.
Here are the first several lines of my search for "main" with both SET WATCH and -verbose:class together on the Alpha:
%XQP, Thread #0, Directory scan for: org_jruby.Main.DIR;1, Status: 00000000 %XQP, Thread #0, Directory scan for: org_jruby.Main;0, Status: 00000000 %XQP, Thread #0, Directory scan for: org_jruby.Main;0, Status: 00000000 %XQP, Thread #0, Directory scan for: org_jruby_Main.DIR;1, Status: 00000000 %XQP, Thread #0, Directory scan for: org_jruby_Main.;0, Status: 00000000 %XQP, Thread #0, Directory scan for: org_jruby_Main.;0, Status: 00000000 %XQP, Thread #0, Directory scan for: org_jruby_Main.DIR;0, Status: 00000000 [Loaded java/security/ProtectionDomain.class from /SYS$COMMON/JAVA$150/JRE/lib/rt.jar] %XQP, Thread #0, Directory scan for: Main.class.DIR;1, Status: 00000000 %XQP, Thread #0, Directory scan for: Main.class;0, Status: 00000000 %XQP, Thread #0, Directory scan for: Main.class;0, Status: 00000000 %XQP, Thread #0, Directory scan for: Main_class.DIR;1, Status: 00000000 %XQP, Thread #0, Directory scan for: Main_class.;0, Status: 00000000 %XQP, Thread #0, Directory scan for: Main_class.;0, Status: 00000000 %XQP, Thread #0, Directory scan for: Main_class.DIR;0, Status: 00000000 [Loaded org/jruby/Main.class from /jruby_root/lib/jruby.jar]
Ben
- Mark as New
- Bookmark
- Subscribe
- Mute
- Subscribe to RSS Feed
- Permalink
- Report Inappropriate Content
02-13-2012 03:30 AM
02-13-2012 03:30 AM
Solution- Mark as New
- Bookmark
- Subscribe
- Mute
- Subscribe to RSS Feed
- Permalink
- Report Inappropriate Content
02-13-2012 03:55 AM
02-13-2012 03:55 AM
Re: Slow Java startup Alpha vs. I64: excessive directory scans (vanilla upstream JRuby)
As per my original post, I used /a ... Looking back at it, I don't know what happened to the "-" in front (maybe a mistake when I un-wrapped the lines by hand) but here is a fresh paste of the definition again:
JRUBY == "$ SYS$COMMON:[JAVA$150.bin]java$java "-Djruby.home=/jruby_root" "-Djruby.lib=/jruby_root/lib" "-Djruby.script=jruby" "-Djruby.memory.max=500m" "-Djruby.stack.max=1024k" "-Xmx500m" "-Xss1024k" "-Djruby.shell=/dyulib/sh.exe" "-Xbootclasspath/a:/jruby_root/lib/jruby.jar:/jna_root/jna.jar" -verbose:class "org.jruby.Main" "-I/dym$disk/dymax/pro/ruby/lib/site_ruby/dylib" "-I/dym$disk/dymax/pro/ruby/lib/site_ruby" "
All of this is patterned after what jruby looks like (from 'ps auxwww' output) on Linux:
java -client -Djruby.memory.max=-Xmx500m -Djruby.stack.max=-Xss1024k -Xmx500m -Xss1024k -Djffi.boot.library.path=/f/Development/Live/jruby-1.6.2/lib/native/i386-Linux:/f/Development/Live/jruby-1.6.2/lib/native/ppc-Linux:/f/Development/Live/jruby-1.6.2/lib/native/x86_64-Linux -Dfile.encoding=UTF-8 -Xbootclasspath/a:/f/Development/Live/jruby-1.6.2/lib/jruby.jar -classpath : -Djruby.home=/f/Development/Live/jruby-1.6.2 -Djruby.lib=/f/Development/Live/jruby-1.6.2/lib -Djruby.script=jruby -Djruby.shell=/bin/sh org.jruby.Main
We don't yet have a working jffi for VMS, so that part is missing from our definition. I tried also playing with -classpath : (maybe this nulls out the classpath, if set?) but this made no difference.
Ben
- Mark as New
- Bookmark
- Subscribe
- Mute
- Subscribe to RSS Feed
- Permalink
- Report Inappropriate Content
02-13-2012 04:15 AM
02-13-2012 04:15 AM
Re: Slow Java startup Alpha vs. I64: excessive directory scans (vanilla upstream JRuby)
I have now posted the complete log with "SET WATCH" and -verbose:class here: rtest_alp.bg
- Mark as New
- Bookmark
- Subscribe
- Mute
- Subscribe to RSS Feed
- Permalink
- Report Inappropriate Content
02-13-2012 04:47 AM
02-13-2012 04:47 AM
Re: Slow Java startup Alpha vs. I64: excessive directory scans (vanilla upstream JRuby)
Bingo! Prepending instead of appending makes a *huge* difference here:
!A:MEDIANET.HARDWARE!> @rtest J R U B Y Hello World test java version "1.5.0" Java(TM) 2 Runtime Environment, Standard Edition Fast VM (build 1.5.0-6.p1, build J2SDK.v.1.5.0:11/16/2009-20:33, native threads, jit_150) jruby 1.6.0 (ruby 1.8.7 patchlevel 330) (2011-03-15 f3b6154) (Fast VM 1.5.0) [OpenVMS-alpha-java] JRUBYT == "$ SYS$COMMON:[JAVA$150.bin]java$java "-Djruby.home=/jruby_root" "-Djruby.lib=/jruby_root/lib" "-Djruby.script=jruby" "-Djruby.memory.max=500m" "-Djruby.stack.max=1024k" "-Xmx500m" "-Xss1024k" "-Djruby.shell=/dyulib/sh.exe" "-Xbootclasspath/p:/jruby_root/lib/jruby.jar:/jna_root/jna.jar" -client "org.jruby.Main" "-I/dym$disk/dymax/pro/ruby/lib/site_ruby/dylib" "- I/dym$disk/dymax/pro/ruby/lib/site_ruby" " hello world Dirio= 2027 Bufio= 793 Kernel= 61 Exec= 11 User=370 Elapsed= 450
- Mark as New
- Bookmark
- Subscribe
- Mute
- Subscribe to RSS Feed
- Permalink
- Report Inappropriate Content
02-13-2012 09:30 AM
02-13-2012 09:30 AM
Re: Slow Java startup Alpha vs. I64: excessive directory scans (vanilla upstream JRuby)
I have filed this as an issue upstream, xreffing back to this thread:
http://jira.codehaus.org/browse/JRUBY-6448
Ben