Hmm. JRuby -S rake jamming

Ruby JRuby
1

Ok.
I have a rake task that does a lot of file and numeric calculations.
(A lot == Tb’s)

I’ve tried numerous command line options such as:

jruby -J-Xmn512m -J-Xms2048m -J-Xmx2048m -J-server -S rake --trace
[namespace]:[task]

But despite my efforts the task jams dead after about 20 minutes of
running.
ps shows this:

java -client -Djruby.memory.max=2048m -Djruby.stack.max=1024k -Xmx2048m
-Xss1024k
-Djffi.boot.library.path=/opt/jruby-1.5.0/lib/native/i386-Linux:/opt/jruby-1.5.0/lib/native/ppc-Linux:/opt/jruby-1.5.0/lib/native/x86_64-Linux
-Xmn512m -Xms2048m -server
-Xbootclasspath/a:/opt/jruby-1.5.0/lib/jruby.jar -classpath
/opt/jruby-1.5.0/lib/profile.jar: -Djruby.home=/opt/jruby-1.5.0
-Djruby.lib=/opt/jruby-1.5.0/lib -Djruby.script=jruby
-Djruby.shell=/bin/sh org.jruby.Main -S rake --trace [namespace]:[task]

There’s nothing particularly gnarly about the task.
It just runs through 100’s of Gb of files (mp3s, xml, jpgs) doing
calculations.

Plain ruby/rake (1.8.7) doesn’t jam.
FYI I have tasks that take 2-3+ days to run to completion and 1.8.7 rake
has no issues with this.

OS is ubuntu 2.6.31-20-server #57-Ubuntu SMP Mon Feb 8 09:59:59 UTC 2010
x86_64.
Java:
java version “1.6.0_0”
OpenJDK Runtime Environment (IcedTea6 1.6.1) (6b16-1.6.1-3ubuntu1)
OpenJDK 64-Bit Server VM (build 14.0-b16, mixed mode)

Considering using plain Sun runtime to see if it’s an OpenJDK issue.
Will report back.

Kimbo.

To unsubscribe from this list, please visit:

http://xircles.codehaus.org/manage_email
2

Try grabbing a thread dump by sending “kill -QUIT” to the process and
share that with us if you can.

/Nick

On Thu, May 13, 2010 at 7:31 AM, Kimberley Scott
[email protected] wrote:

java version “1.6.0_0”

To unsubscribe from this list, please visit:

http://xircles.codehaus.org/manage_email

To unsubscribe from this list, please visit:

http://xircles.codehaus.org/manage_email
3

Running the script now.
For reference purposes its ~11pm Australia (Gold Coast) time.

My testbed is 4 x 16 quad core servers and they’re almost completely
disk and network bound to a NAS at present.
A tad busy I fear.
So it’ll take a while.
Don’t hold your breath or you’ll pass out. :slight_smile:

Kimbo

On 13/05/2010, at 10:36 PM, Nick S. wrote:

It just runs through 100’s of Gb of files (mp3s, xml, jpgs) doing calculations.
Considering using plain Sun runtime to see if it’s an OpenJDK issue.

To unsubscribe from this list, please visit:

http://xircles.codehaus.org/manage_email

To unsubscribe from this list, please visit:

http://xircles.codehaus.org/manage_email
4

FYI I installed the Sun jdk as well, so I’m running the script under:

  1. plain ruby (ruby-enterprise-1.8.7-2010.01) 1.8.7
  2. jruby using Sun’s jdk
  3. jruby using OpenJDK
    Will report back when I get some detail.

For reference, jruby is much faster than plain 1.8.7 even when disk
bound over nfs to a NAS.

Kimbo

On 13/05/2010, at 10:47 PM, Kimberley Scott wrote:

I have a rake task that does a lot of file and numeric calculations.

OpenJDK 64-Bit Server VM (build 14.0-b16, mixed mode)

To unsubscribe from this list, please visit:

http://xircles.codehaus.org/manage_email

To unsubscribe from this list, please visit:

http://xircles.codehaus.org/manage_email
5

Looks like the “pumper” threads are still working. The next thing to
confirm would be whether the find process is still actually running or
if it’s gone away. It’s possible we’ve “missed” it dying or are
preventing it from dying in some way and it’s actually done.

The backtick/system logic has always been a little tweaky, but if it’s
consistently freezing for this command we might have a good clue how
to proceed. I’d say you should file a bug now so we can track it
there.

On Thu, May 13, 2010 at 1:25 PM, Kimberley Scott
[email protected] wrote:

Perhaps it’s a timeout threading issue in ShellLauncher?
“Thread-47” daemon prio=10 tid=0x00007fa8b84bb000 nid=0x49d in Object.wait() [0x00007fa8bd952000]

 java.lang.Thread.State: RUNNABLE
    at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:118)

    at org.jruby.internal.runtime.methods.JavaMethod$JavaMethodOne.call(JavaMethod.java:924)
    at org.jruby.RubyClass.finvoke(RubyClass.java:663)
    at org.jruby.runtime.InterpretedBlock.evalBlockBody(InterpretedBlock.java:373)
    at org.jruby.ast.NewlineNode.interpret(NewlineNode.java:104)
    at org.jruby.runtime.callsite.CachingCallSite.cacheAndCall(CachingCallSite.java:329)
    at org.jruby.RubyArray.each(RubyArray.java:1637)
    at org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:148)
    at org.jruby.ast.EnsureNode.interpret(EnsureNode.java:96)
    at org.jruby.ast.NewlineNode.interpret(NewlineNode.java:104)
    at org.jruby.runtime.callsite.CachingCallSite.cacheAndCall(CachingCallSite.java:289)
    at org.jruby.runtime.InterpretedBlock.evalBlockBody(InterpretedBlock.java:373)
    at org.jruby.ast.NewlineNode.interpret(NewlineNode.java:104)
    at org.jruby.ast.RescueNode.interpretWithJavaExceptions(RescueNode.java:118)
    at org.jruby.internal.runtime.methods.InterpretedMethod.call(InterpretedMethod.java:139)
    at org.jruby.ast.ZYieldNode.interpret(ZYieldNode.java:25)
    at org.jruby.runtime.callsite.CachingCallSite.callIter(CachingCallSite.java:132)
    at org.jruby.Ruby.loadFile(Ruby.java:2539)
    at opt.jruby_minus_1_dot_5_dot_0.bin.rake.load(rake)

“GC task thread#6 (ParallelGC)” prio=10 tid=0x00000000402df800 nid=0x32a runnable

 to  space 65536K, 0% used [0x00007fa93def0000,0x00007fa93def0000,0x00007fa941ef0000)

  1. plain ruby (ruby-enterprise-1.8.7-2010.01) 1.8.7

Running the script now.
On 13/05/2010, at 10:36 PM, Nick S. wrote:

(A lot == Tb’s)
There’s nothing particularly gnarly about the task.

 http://xircles.codehaus.org/manage_email

To unsubscribe from this list, please visit:

To unsubscribe from this list, please visit:

http://xircles.codehaus.org/manage_email
6

After being apparently “jammed” for about 10-15 minutes did a -QUIT.
Sun JDK.

Odd.
Seems to be jammed on a backtick operation.
Possibly this:
n = find #{base}/#{day} -name "*_XXX.mp3" -print | wc -l 2>&1.to_i
Tres odd.
Hmm.
I’ve noticed that “find” is taking inordinately long times to respond
due to the nature of the folder/file structure.
Perhaps it’s a timeout threading issue in ShellLauncher?
(Note: no threads in script - plain sequential operations)

I’ll leave it running for a few more hours to see if it gets anywhere…
(Mainly because it’s 11:20pm and I’m a tad tired after starting work at
6am…)

Thread Dump:

^T2010-05-13 06:35:16
Full thread dump Java HotSpot™ 64-Bit Server VM (16.3-b01 mixed
mode):

“Thread-47” daemon prio=10 tid=0x00007fa8b84bb000 nid=0x49d in
Object.wait() [0x00007fa8bd952000]
java.lang.Thread.State: TIMED_WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
at
org.jruby.util.ShellLauncher$StreamPumper.run(ShellLauncher.java:1149)
- locked <0x00007fa92675b8a8> (a java.lang.Object)

“Thread-46” daemon prio=10 tid=0x00007fa8b82a2000 nid=0x49c runnable
[0x00007fa8bd750000]
java.lang.Thread.State: RUNNABLE
at java.io.FileInputStream.readBytes(Native Method)
at java.io.FileInputStream.read(FileInputStream.java:177)
at
org.jruby.util.ShellLauncher$StreamPumper.run(ShellLauncher.java:1157)

“Thread-45” daemon prio=10 tid=0x00007fa8b89ff800 nid=0x49a runnable
[0x00007fa8bd851000]
java.lang.Thread.State: RUNNABLE
at java.io.FileInputStream.readBytes(Native Method)
at java.io.FileInputStream.read(FileInputStream.java:199)
at
java.io.BufferedInputStream.fill(BufferedInputStream.java:218)
at
java.io.BufferedInputStream.read1(BufferedInputStream.java:258)
at
java.io.BufferedInputStream.read(BufferedInputStream.java:317)
- locked <0x00007fa92df2ca10> (a java.io.BufferedInputStream)
at java.io.FilterInputStream.read(FilterInputStream.java:90)
at
org.jruby.util.ShellLauncher$StreamPumper.run(ShellLauncher.java:1157)

“process reaper” daemon prio=10 tid=0x00007fa8b89fe800 nid=0x497
runnable [0x00007fa8bda53000]
java.lang.Thread.State: RUNNABLE
at java.lang.UNIXProcess.waitForProcessExit(Native Method)
at java.lang.UNIXProcess.access$900(UNIXProcess.java:20)
at java.lang.UNIXProcess$1$1.run(UNIXProcess.java:132)

“Low Memory Detector” daemon prio=10 tid=0x00007fa8b8070800 nid=0x337
runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE

“CompilerThread1” daemon prio=10 tid=0x00007fa8b806e000 nid=0x336
waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE

“CompilerThread0” daemon prio=10 tid=0x00007fa8b806b000 nid=0x335
waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE

“Signal Dispatcher” daemon prio=10 tid=0x00007fa8b8069000 nid=0x334
waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE

“Finalizer” daemon prio=10 tid=0x00007fa8b8049800 nid=0x333 in
Object.wait() [0x00007fa8be48b000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:118)
- locked <0x00007fa9423384f8> (a
java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:134)
at
java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:159)

“Reference Handler” daemon prio=10 tid=0x00007fa8b8047800 nid=0x332 in
Object.wait() [0x00007fa8be58c000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
at java.lang.Object.wait(Object.java:485)
at
java.lang.ref.Reference$ReferenceHandler.run(Reference.java:116)
- locked <0x00007fa9423381a0> (a java.lang.ref.Reference$Lock)

“main” prio=10 tid=0x00000000402c1800 nid=0x322 in Object.wait()
[0x00007fa949e91000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
at java.lang.Thread.join(Thread.java:1143)
- locked <0x00007fa926758c28> (a
org.jruby.util.ShellLauncher$StreamPumper)
at java.lang.Thread.join(Thread.java:1196)
at
org.jruby.util.ShellLauncher.handleStreams(ShellLauncher.java:1255)
at
org.jruby.util.ShellLauncher.runAndWait(ShellLauncher.java:391)
at org.jruby.RubyKernel.backquote(RubyKernel.java:1377)
at
org.jruby.RubyKernel$s_method_1_0$RUBYINVOKER$backquote.call(org/jruby/RubyKernel$s_method_1_0$RUBYINVOKER$backquote.gen:65535)
at
org.jruby.internal.runtime.methods.JavaMethod$JavaMethodOne.call(JavaMethod.java:924)
at
org.jruby.internal.runtime.methods.JavaMethod$JavaMethodN.call(JavaMethod.java:642)
at
org.jruby.runtime.callsite.SuperCallSite.callBlock(SuperCallSite.java:62)
at
org.jruby.runtime.callsite.SuperCallSite.call(SuperCallSite.java:69)
at org.jruby.ast.ZSuperNode.interpret(ZSuperNode.java:100)
at org.jruby.ast.NewlineNode.interpret(NewlineNode.java:104)
at org.jruby.ast.RescueNode.executeBody(RescueNode.java:199)
at
org.jruby.ast.RescueNode.interpretWithJavaExceptions(RescueNode.java:118)
at org.jruby.ast.RescueNode.interpret(RescueNode.java:110)
at
org.jruby.internal.runtime.methods.InterpretedMethod.call(InterpretedMethod.java:180)
at
org.jruby.internal.runtime.methods.DefaultMethod.call(DefaultMethod.java:172)
at org.jruby.RubyClass.finvoke(RubyClass.java:663)
at
org.jruby.javasupport.util.RuntimeHelpers.invoke(RuntimeHelpers.java:452)
at
org.jruby.RubyBasicObject.callMethod(RubyBasicObject.java:332)
at org.jruby.ast.DXStrNode.interpret(DXStrNode.java:74)
at org.jruby.ast.CallNoArgNode.interpret(CallNoArgNode.java:61)
at org.jruby.ast.DAsgnNode.interpret(DAsgnNode.java:110)
at org.jruby.ast.NewlineNode.interpret(NewlineNode.java:104)
at org.jruby.ast.BlockNode.interpret(BlockNode.java:71)
at org.jruby.ast.IfNode.interpret(IfNode.java:117)
at org.jruby.ast.NewlineNode.interpret(NewlineNode.java:104)
at org.jruby.ast.BlockNode.interpret(BlockNode.java:71)
at
org.jruby.runtime.InterpretedBlock.evalBlockBody(InterpretedBlock.java:373)
at
org.jruby.runtime.InterpretedBlock.yield(InterpretedBlock.java:346)
at
org.jruby.runtime.InterpretedBlock.yield(InterpretedBlock.java:303)
at org.jruby.runtime.Block.yield(Block.java:194)
at org.jruby.RubyArray.eachCommon(RubyArray.java:1630)
at org.jruby.RubyArray.each(RubyArray.java:1637)
at
org.jruby.RubyArray$i_method_0_0$RUBYFRAMEDINVOKER$each.call(org/jruby/RubyArray$i_method_0_0$RUBYFRAMEDINVOKER$each.gen:65535)
at
org.jruby.runtime.callsite.CachingCallSite.cacheAndCall(CachingCallSite.java:299)
at
org.jruby.runtime.callsite.CachingCallSite.callBlock(CachingCallSite.java:117)
at
org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:122)
at
org.jruby.ast.CallNoArgBlockNode.interpret(CallNoArgBlockNode.java:64)
at org.jruby.ast.NewlineNode.interpret(NewlineNode.java:104)
at org.jruby.ast.BlockNode.interpret(BlockNode.java:71)
at
org.jruby.runtime.InterpretedBlock.evalBlockBody(InterpretedBlock.java:373)
at
org.jruby.runtime.InterpretedBlock.yield(InterpretedBlock.java:327)
at org.jruby.runtime.BlockBody.call(BlockBody.java:78)
at org.jruby.runtime.Block.call(Block.java:89)
at org.jruby.RubyProc.call(RubyProc.java:224)
at org.jruby.RubyProc.call(RubyProc.java:203)
at
org.jruby.RubyProc$i_method_0_0$RUBYFRAMEDINVOKER$call.call(org/jruby/RubyProc$i_method_0_0$RUBYFRAMEDINVOKER$call.gen:65535)
at
org.jruby.internal.runtime.methods.DynamicMethod.call(DynamicMethod.java:198)
at
org.jruby.internal.runtime.methods.DynamicMethod.call(DynamicMethod.java:194)
at
org.jruby.runtime.callsite.CachingCallSite.cacheAndCall(CachingCallSite.java:329)
at
org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:188)
at
org.jruby.ast.CallTwoArgNode.interpret(CallTwoArgNode.java:59)
at org.jruby.ast.NewlineNode.interpret(NewlineNode.java:104)
at org.jruby.ast.CaseNode.interpret(CaseNode.java:138)
at org.jruby.ast.NewlineNode.interpret(NewlineNode.java:104)
at
org.jruby.runtime.InterpretedBlock.evalBlockBody(InterpretedBlock.java:373)
at
org.jruby.runtime.InterpretedBlock.yield(InterpretedBlock.java:346)
at
org.jruby.runtime.InterpretedBlock.yield(InterpretedBlock.java:303)
at org.jruby.runtime.Block.yield(Block.java:194)
at org.jruby.RubyArray.eachCommon(RubyArray.java:1630)
at org.jruby.RubyArray.each(RubyArray.java:1637)
at
org.jruby.RubyArray$i_method_0_0$RUBYFRAMEDINVOKER$each.call(org/jruby/RubyArray$i_method_0_0$RUBYFRAMEDINVOKER$each.gen:65535)
at
org.jruby.runtime.callsite.CachingCallSite.cacheAndCall(CachingCallSite.java:299)
at
org.jruby.runtime.callsite.CachingCallSite.callBlock(CachingCallSite.java:117)
at
org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:122)
at
org.jruby.ast.CallNoArgBlockNode.interpret(CallNoArgBlockNode.java:64)
at org.jruby.ast.NewlineNode.interpret(NewlineNode.java:104)
at org.jruby.ast.BlockNode.interpret(BlockNode.java:71)
at
org.jruby.internal.runtime.methods.InterpretedMethod.call(InterpretedMethod.java:180)
at
org.jruby.internal.runtime.methods.DefaultMethod.call(DefaultMethod.java:172)
at
org.jruby.runtime.callsite.CachingCallSite.cacheAndCall(CachingCallSite.java:309)
at
org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:148)
at
org.jruby.ast.FCallOneArgNode.interpret(FCallOneArgNode.java:36)
at org.jruby.ast.IfNode.interpret(IfNode.java:117)
at org.jruby.ast.NewlineNode.interpret(NewlineNode.java:104)
at org.jruby.ast.BlockNode.interpret(BlockNode.java:71)
at
org.jruby.runtime.InterpretedBlock.evalBlockBody(InterpretedBlock.java:373)
at
org.jruby.runtime.InterpretedBlock.yield(InterpretedBlock.java:294)
at
org.jruby.runtime.InterpretedBlock.yieldSpecific(InterpretedBlock.java:228)
at org.jruby.runtime.Block.yieldSpecific(Block.java:99)
at org.jruby.ast.ZYieldNode.interpret(ZYieldNode.java:25)
at org.jruby.ast.NewlineNode.interpret(NewlineNode.java:104)
at org.jruby.ast.EnsureNode.interpret(EnsureNode.java:96)
at org.jruby.ast.BeginNode.interpret(BeginNode.java:83)
at org.jruby.ast.NewlineNode.interpret(NewlineNode.java:104)
at org.jruby.ast.BlockNode.interpret(BlockNode.java:71)
at
org.jruby.internal.runtime.methods.InterpretedMethod.call(InterpretedMethod.java:160)
at
org.jruby.internal.runtime.methods.DefaultMethod.call(DefaultMethod.java:164)
at
org.jruby.internal.runtime.methods.AliasMethod.call(AliasMethod.java:81)
at
org.jruby.runtime.callsite.CachingCallSite.cacheAndCall(CachingCallSite.java:299)
at
org.jruby.runtime.callsite.CachingCallSite.callBlock(CachingCallSite.java:117)
at
org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:122)
at
org.jruby.ast.CallNoArgBlockNode.interpret(CallNoArgBlockNode.java:64)
at org.jruby.ast.NewlineNode.interpret(NewlineNode.java:104)
at org.jruby.ast.BlockNode.interpret(BlockNode.java:71)
at
org.jruby.internal.runtime.methods.InterpretedMethod.call(InterpretedMethod.java:221)
at
org.jruby.internal.runtime.methods.DefaultMethod.call(DefaultMethod.java:188)
at
org.jruby.runtime.callsite.CachingCallSite.cacheAndCall(CachingCallSite.java:329)
at
org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:188)
at
org.jruby.ast.FCallTwoArgNode.interpret(FCallTwoArgNode.java:38)
at org.jruby.ast.NewlineNode.interpret(NewlineNode.java:104)
at org.jruby.ast.BlockNode.interpret(BlockNode.java:71)
at
org.jruby.internal.runtime.methods.InterpretedMethod.call(InterpretedMethod.java:139)
at
org.jruby.internal.runtime.methods.DefaultMethod.call(DefaultMethod.java:156)
at
org.jruby.runtime.callsite.CachingCallSite.cacheAndCall(CachingCallSite.java:289)
at
org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:108)
at
org.jruby.ast.CallSpecialArgNode.interpret(CallSpecialArgNode.java:65)
at org.jruby.ast.NewlineNode.interpret(NewlineNode.java:104)
at org.jruby.ast.BlockNode.interpret(BlockNode.java:71)
at
org.jruby.internal.runtime.methods.InterpretedMethod.call(InterpretedMethod.java:180)
at
org.jruby.internal.runtime.methods.DefaultMethod.call(DefaultMethod.java:172)
at
org.jruby.runtime.callsite.CachingCallSite.cacheAndCall(CachingCallSite.java:309)
at
org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:148)
at
org.jruby.ast.FCallOneArgNode.interpret(FCallOneArgNode.java:36)
at org.jruby.ast.NewlineNode.interpret(NewlineNode.java:104)
at
org.jruby.runtime.InterpretedBlock.evalBlockBody(InterpretedBlock.java:373)
at
org.jruby.runtime.InterpretedBlock.yield(InterpretedBlock.java:346)
at
org.jruby.runtime.InterpretedBlock.yield(InterpretedBlock.java:303)
at org.jruby.runtime.Block.yield(Block.java:194)
at org.jruby.RubyArray.eachCommon(RubyArray.java:1630)
at org.jruby.RubyArray.each(RubyArray.java:1637)
at
org.jruby.RubyArray$i_method_0_0$RUBYFRAMEDINVOKER$each.call(org/jruby/RubyArray$i_method_0_0$RUBYFRAMEDINVOKER$each.gen:65535)
at
org.jruby.runtime.callsite.CachingCallSite.cacheAndCall(CachingCallSite.java:299)
at
org.jruby.runtime.callsite.CachingCallSite.callBlock(CachingCallSite.java:117)
at
org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:122)
at
org.jruby.ast.CallNoArgBlockNode.interpret(CallNoArgBlockNode.java:64)
at org.jruby.ast.NewlineNode.interpret(NewlineNode.java:104)
at org.jruby.ast.IfNode.interpret(IfNode.java:119)
at org.jruby.ast.IfNode.interpret(IfNode.java:119)
at org.jruby.ast.NewlineNode.interpret(NewlineNode.java:104)
at
org.jruby.runtime.InterpretedBlock.evalBlockBody(InterpretedBlock.java:373)
at
org.jruby.runtime.InterpretedBlock.yield(InterpretedBlock.java:294)
at
org.jruby.runtime.InterpretedBlock.yieldSpecific(InterpretedBlock.java:228)
at org.jruby.runtime.Block.yieldSpecific(Block.java:99)
at org.jruby.ast.ZYieldNode.interpret(ZYieldNode.java:25)
at org.jruby.ast.NewlineNode.interpret(NewlineNode.java:104)
at org.jruby.ast.RescueNode.executeBody(RescueNode.java:199)
at
org.jruby.ast.RescueNode.interpretWithJavaExceptions(RescueNode.java:118)
at org.jruby.ast.RescueNode.interpret(RescueNode.java:110)
at org.jruby.ast.BeginNode.interpret(BeginNode.java:83)
at org.jruby.ast.NewlineNode.interpret(NewlineNode.java:104)
at
org.jruby.internal.runtime.methods.InterpretedMethod.call(InterpretedMethod.java:160)
at
org.jruby.internal.runtime.methods.DefaultMethod.call(DefaultMethod.java:164)
at
org.jruby.runtime.callsite.CachingCallSite.cacheAndCall(CachingCallSite.java:299)
at
org.jruby.runtime.callsite.CachingCallSite.callBlock(CachingCallSite.java:117)
at
org.jruby.runtime.callsite.CachingCallSite.callIter(CachingCallSite.java:132)
at
org.jruby.ast.FCallNoArgBlockNode.interpret(FCallNoArgBlockNode.java:32)
at org.jruby.ast.NewlineNode.interpret(NewlineNode.java:104)
at
org.jruby.internal.runtime.methods.InterpretedMethod.call(InterpretedMethod.java:139)
at
org.jruby.internal.runtime.methods.DefaultMethod.call(DefaultMethod.java:156)
at
org.jruby.runtime.callsite.CachingCallSite.cacheAndCall(CachingCallSite.java:289)
at
org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:108)
at org.jruby.ast.VCallNode.interpret(VCallNode.java:85)
at org.jruby.ast.NewlineNode.interpret(NewlineNode.java:104)
at org.jruby.ast.BlockNode.interpret(BlockNode.java:71)
at
org.jruby.runtime.InterpretedBlock.evalBlockBody(InterpretedBlock.java:373)
at
org.jruby.runtime.InterpretedBlock.yield(InterpretedBlock.java:294)
at
org.jruby.runtime.InterpretedBlock.yieldSpecific(InterpretedBlock.java:228)
at org.jruby.runtime.Block.yieldSpecific(Block.java:99)
at org.jruby.ast.ZYieldNode.interpret(ZYieldNode.java:25)
at org.jruby.ast.NewlineNode.interpret(NewlineNode.java:104)
at org.jruby.ast.RescueNode.executeBody(RescueNode.java:199)
at
org.jruby.ast.RescueNode.interpretWithJavaExceptions(RescueNode.java:118)
at org.jruby.ast.RescueNode.interpret(RescueNode.java:110)
at org.jruby.ast.BeginNode.interpret(BeginNode.java:83)
at org.jruby.ast.NewlineNode.interpret(NewlineNode.java:104)
at
org.jruby.internal.runtime.methods.InterpretedMethod.call(InterpretedMethod.java:160)
at
org.jruby.internal.runtime.methods.DefaultMethod.call(DefaultMethod.java:164)
at
org.jruby.runtime.callsite.CachingCallSite.cacheAndCall(CachingCallSite.java:299)
at
org.jruby.runtime.callsite.CachingCallSite.callBlock(CachingCallSite.java:117)
at
org.jruby.runtime.callsite.CachingCallSite.callIter(CachingCallSite.java:132)
at
org.jruby.ast.FCallNoArgBlockNode.interpret(FCallNoArgBlockNode.java:32)
at org.jruby.ast.NewlineNode.interpret(NewlineNode.java:104)
at
org.jruby.internal.runtime.methods.InterpretedMethod.call(InterpretedMethod.java:139)
at
org.jruby.internal.runtime.methods.DefaultMethod.call(DefaultMethod.java:156)
at
org.jruby.runtime.callsite.CachingCallSite.cacheAndCall(CachingCallSite.java:289)
at
org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:108)
at org.jruby.ast.CallNoArgNode.interpret(CallNoArgNode.java:61)
at org.jruby.ast.NewlineNode.interpret(NewlineNode.java:104)
at org.jruby.ast.BlockNode.interpret(BlockNode.java:71)
at org.jruby.ast.RootNode.interpret(RootNode.java:129)
at org.jruby.Ruby.loadFile(Ruby.java:2539)
at
org.jruby.runtime.load.ExternalScript.load(ExternalScript.java:61)
at org.jruby.runtime.load.LoadService.load(LoadService.java:255)
at org.jruby.RubyKernel.loadCommon(RubyKernel.java:1010)
at org.jruby.RubyKernel.load(RubyKernel.java:992)
at
org.jruby.RubyKernel$s_method_0_1$RUBYFRAMEDINVOKER$load.call(org/jruby/RubyKernel$s_method_0_1$RUBYFRAMEDINVOKER$load.gen:65535)
at
org.jruby.internal.runtime.methods.DynamicMethod.call(DynamicMethod.java:190)
at
org.jruby.internal.runtime.methods.DynamicMethod.call(DynamicMethod.java:186)
at
org.jruby.runtime.callsite.CachingCallSite.cacheAndCall(CachingCallSite.java:309)
at
org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:148)
at opt.jruby_minus_1_dot_5_dot_0.bin.rake.file(rake:19)
at opt.jruby_minus_1_dot_5_dot_0.bin.rake.load(rake)
at org.jruby.Ruby.runScript(Ruby.java:684)
at org.jruby.Ruby.runNormally(Ruby.java:567)
at org.jruby.Ruby.runFromMain(Ruby.java:413)
at org.jruby.Main.run(Main.java:286)
at org.jruby.Main.run(Main.java:128)
at org.jruby.Main.main(Main.java:97)

“VM Thread” prio=10 tid=0x00007fa8b8043000 nid=0x331 runnable

“GC task thread#0 (ParallelGC)” prio=10 tid=0x00000000402d4800 nid=0x323
runnable

“GC task thread#1 (ParallelGC)” prio=10 tid=0x00000000402d6800 nid=0x324
runnable

“GC task thread#2 (ParallelGC)” prio=10 tid=0x00000000402d8000 nid=0x325
runnable

“GC task thread#3 (ParallelGC)” prio=10 tid=0x00000000402da000 nid=0x326
runnable

“GC task thread#4 (ParallelGC)” prio=10 tid=0x00000000402dc000 nid=0x327
runnable

“GC task thread#5 (ParallelGC)” prio=10 tid=0x00000000402dd800 nid=0x328
runnable

“GC task thread#6 (ParallelGC)” prio=10 tid=0x00000000402df800 nid=0x32a
runnable

“GC task thread#7 (ParallelGC)” prio=10 tid=0x00000000402e1800 nid=0x32b
runnable

“GC task thread#8 (ParallelGC)” prio=10 tid=0x00000000402e3000 nid=0x32c
runnable

“GC task thread#9 (ParallelGC)” prio=10 tid=0x00000000402e5000 nid=0x32d
runnable

“GC task thread#10 (ParallelGC)” prio=10 tid=0x00000000402e7000
nid=0x32e runnable

“GC task thread#11 (ParallelGC)” prio=10 tid=0x00000000402e8800
nid=0x32f runnable

“GC task thread#12 (ParallelGC)” prio=10 tid=0x00000000402ea800
nid=0x330 runnable

“VM Periodic Task Thread” prio=10 tid=0x00007fa8b8073800 nid=0x338
waiting on condition

JNI global references: 760

Heap
PSYoungGen total 458752K, used 197712K [0x00007fa925ef0000,
0x00007fa945ef0000, 0x00007fa945ef0000)
eden space 393216K, 41% used
[0x00007fa925ef0000,0x00007fa92fde5138,0x00007fa93def0000)
from space 65536K, 53% used
[0x00007fa941ef0000,0x00007fa94410f138,0x00007fa945ef0000)
to space 65536K, 0% used
[0x00007fa93def0000,0x00007fa93def0000,0x00007fa941ef0000)
PSOldGen total 1572864K, used 0K [0x00007fa8c5ef0000,
0x00007fa925ef0000, 0x00007fa925ef0000)
object space 1572864K, 0% used
[0x00007fa8c5ef0000,0x00007fa8c5ef0000,0x00007fa925ef0000)
PSPermGen total 27584K, used 27536K [0x00007fa8c0af0000,
0x00007fa8c25e0000, 0x00007fa8c5ef0000)
object space 27584K, 99% used
[0x00007fa8c0af0000,0x00007fa8c25d4028,0x00007fa8c25e0000)

On 13/05/2010, at 10:55 PM, Kimberley Scott wrote:

On 13/05/2010, at 10:47 PM, Kimberley Scott wrote:

Ok.
java -client -Djruby.memory.max=2048m -Djruby.stack.max=1024k -Xmx2048m -Xss1024k -Djffi.boot.library.path=/opt/jruby-1.5.0/lib/native/i386-Linux:/opt/jruby-1.5.0/lib/native/ppc-Linux:/opt/jruby-1.5.0/lib/native/x86_64-Linux -Xmn512m -Xms2048m -server -Xbootclasspath/a:/opt/jruby-1.5.0/lib/jruby.jar -classpath /opt/jruby-1.5.0/lib/profile.jar: -Djruby.home=/opt/jruby-1.5.0 -Djruby.lib=/opt/jruby-1.5.0/lib -Djruby.script=jruby -Djruby.shell=/bin/sh org.jruby.Main -S rake --trace [namespace]:[task]
OpenJDK Runtime Environment (IcedTea6 1.6.1) (6b16-1.6.1-3ubuntu1)
To unsubscribe from this list, please visit:

To unsubscribe from this list, please visit:

http://xircles.codehaus.org/manage_email

To unsubscribe from this list, please visit:

http://xircles.codehaus.org/manage_email
7

Fantastic news :slight_smile: FWIW, if you do run into threading-like issues with
backtick or system, you can always fall back on popen and driving the
process yourself. It’s a bit less hacky internally.

Keep us posted on your progress and any other issues you run into.

On Fri, May 14, 2010 at 6:15 AM, Kimberley Scott
[email protected] wrote:

if it’s gone away. It’s possible we’ve “missed” it dying or are

After being apparently “jammed” for about 10-15 minutes did a -QUIT.
to the nature of the folder/file structure.
Full thread dump Java HotSpot™ 64-Bit Server VM (16.3-b01 mixed mode):
[0x00007fa8bd750000]
   at java.io.FileInputStream.read(FileInputStream.java:199)
 java.lang.Thread.State: RUNNABLE
 java.lang.Thread.State: RUNNABLE
Object.wait() [0x00007fa8be48b000]
   at java.lang.Object.wait(Native Method)
org.jruby.util.ShellLauncher$StreamPumper)
org.jruby.internal.runtime.methods.JavaMethod$JavaMethodN.call(JavaMethod.java:642)
   at
   at org.jruby.ast.NewlineNode.interpret(NewlineNode.java:104)
   at org.jruby.runtime.Block.yield(Block.java:194)
   at
   at org.jruby.RubyProc.call(RubyProc.java:203)
   at org.jruby.ast.CallTwoArgNode.interpret(CallTwoArgNode.java:59)
   at org.jruby.RubyArray.eachCommon(RubyArray.java:1630)
org.jruby.ast.CallNoArgBlockNode.interpret(CallNoArgBlockNode.java:64)
   at org.jruby.ast.FCallOneArgNode.interpret(FCallOneArgNode.java:36)
   at org.jruby.ast.ZYieldNode.interpret(ZYieldNode.java:25)
org.jruby.internal.runtime.methods.AliasMethod.call(AliasMethod.java:81)
   at
   at
   at org.jruby.ast.BlockNode.interpret(BlockNode.java:71)
   at
   at
   at org.jruby.ast.NewlineNode.interpret(NewlineNode.java:104)
   at
   at
   at
   at
   at
org.jruby.ast.FCallNoArgBlockNode.interpret(FCallNoArgBlockNode.java:32)
   at org.jruby.ast.NewlineNode.interpret(NewlineNode.java:104)
   at
   at org.jruby.Ruby.runNormally(Ruby.java:567)
“GC task thread#1 (ParallelGC)” prio=10 tid=0x00000000402d6800 nid=0x324

runnable
“GC task thread#12 (ParallelGC)” prio=10 tid=0x00000000402ea800 nid=0x330
 eden space 393216K, 41% used
0x00007fa8c25e0000, 0x00007fa8c5ef0000)

  1. jruby using OpenJDK

For reference purposes its ~11pm Australia (Gold Coast) time.
On 13/05/2010, at 10:36 PM, Nick S. wrote:

I have a rake task that does a lot of file and numeric calculations.

calculations.
OpenJDK 64-Bit Server VM (build 14.0-b16, mixed mode)

 http://xircles.codehaus.org/manage_email

To unsubscribe from this list, please visit:

 http://xircles.codehaus.org/manage_email

To unsubscribe from this list, please visit:

http://xircles.codehaus.org/manage_email
8

Interesting.
Turns out it’s not a problem with jruby at all.
One of our sys admins was doing some “tuning” right across the time I
was doing my tests.
This involved the tuning the lookup() system call between small/large
files so it was NAS wide and was the cause of ‘find’ being painfully
slow.
The “tuning” has ceased and jruby rake works just peachy now.
Still slow, but that’s the “tuning” issue, and not jruby.

Sorry for the bother.

FYI I’m switching all my rake scripts over to JRuby 1.5.0 now and
thrash the sh… er… stuffing out of it.

Kimbo.

On 14/05/2010, at 3:43 PM, Charles Oliver N. wrote:

On Thu, May 13, 2010 at 1:25 PM, Kimberley Scott

Hmm.
Thread Dump:
$StreamPumper.run(ShellLauncher.java:1149)
“Thread-45” daemon prio=10 tid=0x00007fa8b89ff800 nid=0x49a
- locked <0x00007fa92df2ca10> (a java.io.BufferedInputStream)

java.lang.Thread.State: RUNNABLE
118)
at java.lang.Object.wait(Native Method)
- locked <0x00007fa926758c28> (a org.jruby.util.ShellLauncher
at org.jruby.internal.runtime.methods.JavaMethod
at org.jruby.ast.NewlineNode.interpret(NewlineNode.java:104)
.runtime.methods.InterpretedMethod.call(InterpretedMethod.java:180)
332)
org
$each.call(org/jruby/RubyArray$i_method_0_0$RUBYFRAMEDINVOKER
at
.jruby.runtime.InterpretedBlock.evalBlockBody(InterpretedBlock.java:
at
.runtime.callsite.CachingCallSite.cacheAndCall(CachingCallSite.java:
at
at org.jruby.RubyArray$i_method_0_0$RUBYFRAMEDINVOKER
.runtime.callsite.CachingCallSite.callBlock(CachingCallSite.java:117)
org
.runtime.callsite.CachingCallSite.cacheAndCall(CachingCallSite.java:
at
at org.jruby.ast.ZYieldNode.interpret(ZYieldNode.java:25)
at
299)
64)
.internal.runtime.methods.DefaultMethod.call(DefaultMethod.java:188)
org.jruby.ast.FCallTwoArgNode.interpret(FCallTwoArgNode.java:38)
.internal.runtime.methods.DefaultMethod.call(DefaultMethod.java:156)
org.jruby.ast.CallSpecialArgNode.interpret(CallSpecialArgNode.java:
.jruby
at
at org.jruby.runtime.Block.yield(Block.java:194)
at
at org.jruby.ast.NewlineNode.interpret(NewlineNode.java:104)
org
at org.jruby.ast.RescueNode.interpret(RescueNode.java:110)
.internal.runtime.methods.DefaultMethod.call(DefaultMethod.java:164)
org
.runtime.methods.InterpretedMethod.call(InterpretedMethod.java:139)
org
org.jruby.runtime.InterpretedBlock.yield(InterpretedBlock.java:294)
.jruby.ast.RescueNode.interpretWithJavaExceptions(RescueNode.java:
org
.runtime.callsite.CachingCallSite.callBlock(CachingCallSite.java:117)
.jruby
289)
at
.jruby
at
at org.jruby.Main.main(Main.java:97)
nid=0x325 runnable
“GC task thread#6 (ParallelGC)” prio=10 tid=0x00000000402df800

waiting on condition
to space 65536K, 0% used

For reference, jruby is much faster than plain 1.8.7 even when

completely disk and network bound to a NAS at present.

process and

Xmx2048m -Xss1024k -Djffi.boot.library.path=/opt/jruby-1.5.0/
doing calculations.
(6b16-1.6.1-3ubuntu1)

http://xircles.codehaus.org/manage_email

To unsubscribe from this list, please visit:

To unsubscribe from this list, please visit:

http://xircles.codehaus.org/manage_email