History | Log In     View a printable version of the current page.  
Issue Details (XML | Word | Printable)

Key: JRUBY-1437
Type: Bug Bug
Status: Closed Closed
Resolution: Cannot Reproduce
Priority: Critical Critical
Assignee: Charles Oliver Nutter
Reporter: Eric Armstrong
Votes: 1
Watchers: 2
Operations

If you were logged in you would be able to see more operations.
JRuby

Heap overflow on attempted gem install

Created: 15/Oct/07 04:34 PM   Updated: Friday 11:46 AM
Component/s: None
Affects Version/s: JRuby 1.0.0, JRuby 1.0.1
Fix Version/s: JRuby 1.1b1, JRuby 1.0.2

Time Tracking:
Not Specified

Environment:
Server: Big honkin' Enterprise 450 w/ton o'memory)
O/S: Solaris 2.9
JDK: 1.6.0 fcs b105
JDK: 6u5


 Description  « Hide
% head <jruby_install>/bin/gem
#!/usr/bin/env jruby -J-Xms128M -J-Xmx1024M

(This are the memory settings we use when generating javadocs for
the javase platform.)

% gem install optiflag
Bulk updating Gem source index for: http://gems.rubyforge.org
Exception in thread "main" java.lang.OutOfMemoryError: Java heap space
at java.util.LinkedList.addBefore(LinkedList.java:778)
at java.util.LinkedList.add(LinkedList.java:344)
at org.jvyamlb.ParserImpl$11.produce(ParserImpl.java:320)
at org.jvyamlb.ParserImpl.parseStreamNext(ParserImpl.java:823)
at org.jvyamlb.ParserImpl.peekEvent(ParserImpl.java:774)
at org.jvyamlb.ComposerImpl.composeNode(ComposerImpl.java:111)
at org.jvyamlb.ComposerImpl.composeNode(ComposerImpl.java:167)
at org.jvyamlb.ComposerImpl.composeNode(ComposerImpl.java:167)
at org.jvyamlb.ComposerImpl.composeNode(ComposerImpl.java:167)
at org.jvyamlb.ComposerImpl.composeDocument(ComposerImpl.java:100)
at org.jvyamlb.ComposerImpl.getNode(ComposerImpl.java:76)
at org.jvyamlb.BaseConstructorImpl.getData(BaseConstructorImpl.java:97)
at org.jruby.RubyYAML.load(RubyYAML.java:221)
at org.jruby.RubyYAMLInvokerSload1.call(Unknown Source)
at org.jruby.runtime.callback.FastInvocationCallback.execute(FastInvocationCallback.java:49)
at org.jruby.internal.runtime.methods.SimpleCallbackMethod.call(SimpleCallbackMethod.java:81)
at org.jruby.evaluator.EvaluationState.callNode(EvaluationState.java:568)
at org.jruby.evaluator.EvaluationState.evalInternal(EvaluationState.java:207)
at org.jruby.evaluator.EvaluationState.orNode(EvaluationState.java:1459)
at org.jruby.evaluator.EvaluationState.evalInternal(EvaluationState.java:339)
at org.jruby.evaluator.EvaluationState.eval(EvaluationState.java:164)
at org.jruby.internal.runtime.methods.DefaultMethod.internalCall(DefaultMethod.java:135)
at org.jruby.internal.runtime.methods.DynamicMethod.call(DynamicMethod.java:79)
at org.jruby.evaluator.EvaluationState.fCallNode(EvaluationState.java:1023)
at org.jruby.evaluator.EvaluationState.evalInternal(EvaluationState.java:253)
at org.jruby.evaluator.EvaluationState.blockNode(EvaluationState.java:531)
at org.jruby.evaluator.EvaluationState.evalInternal(EvaluationState.java:201)
at org.jruby.evaluator.EvaluationState.eval(EvaluationState.java:164)
at org.jruby.internal.runtime.methods.DefaultMethod.internalCall(DefaultMethod.java:135)
at org.jruby.internal.runtime.methods.DynamicMethod.call(DynamicMethod.java:79)
at org.jruby.evaluator.EvaluationState.fCallNode(EvaluationState.java:1023)
at org.jruby.evaluator.EvaluationState.evalInternal(EvaluationState.java:253)



 All   Comments   Work Log   Change History      Sort Order: Ascending order - Click to sort in descending order
Pat Cheng - 18/Oct/07 11:09 AM
I have similar problem running on Windows XP, running jvm 1.6.0_02

I tried different -Xms and -Xmx values, didn't seem to help.
C:\workspace\jruby_trunk\bin>gem install optiflag
Bulk updating Gem source index for: http://gems.rubyforge.org
Exception in thread "main" java.lang.OutOfMemoryError: Java heap space
at org.jruby.util.ByteList.grow(ByteList.java:537)
at org.jruby.util.ByteList.append(ByteList.java:116)
at org.jruby.util.ByteList.append(ByteList.java:122)
at org.jvyamlb.ScannerImpl.update(ScannerImpl.java:330)
at org.jvyamlb.ScannerImpl.ensure(ScannerImpl.java:350)
at org.jvyamlb.ScannerImpl.scanLineBreak(ScannerImpl.java:581)
at org.jvyamlb.ScannerImpl.scanToNextToken(ScannerImpl.java:562)
at org.jvyamlb.ScannerImpl.fetchMoreTokens(ScannerImpl.java:488)
at org.jvyamlb.ScannerImpl.peekToken(ScannerImpl.java:411)
at org.jvyamlb.ParserImpl$ProductionEnvironment.produce(ParserImpl.java:355)
at org.jvyamlb.ParserImpl.parseStreamNext(ParserImpl.java:730)
at org.jvyamlb.ParserImpl.peekEvent(ParserImpl.java:681)
at org.jvyamlb.ComposerImpl.composeNode(ComposerImpl.java:161)
at org.jvyamlb.ComposerImpl.composeNode(ComposerImpl.java:167)
at org.jvyamlb.ComposerImpl.composeNode(ComposerImpl.java:167)
at org.jvyamlb.ComposerImpl.composeDocument(ComposerImpl.java:100)
at org.jvyamlb.ComposerImpl.getNode(ComposerImpl.java:76)
at org.jvyamlb.BaseConstructorImpl.getData(BaseConstructorImpl.java:97)
at org.jruby.RubyYAML.load(RubyYAML.java:223)
at org.jruby.RubyYAMLInvoker$load_FS1.call(Unknown Source)
at org.jruby.runtime.callback.FastInvocationCallback.execute(FastInvocationCallback.java:49)
at org.jruby.internal.runtime.methods.SimpleCallbackMethod.call(SimpleCallbackMethod.java:70)
at org.jruby.runtime.CallAdapter$DefaultCallAdapter.call(CallAdapter.java:167)
at org.jruby.runtime.CallAdapter$DefaultCallAdapter.call(CallAdapter.java:108)
at org.jruby.evaluator.ASTInterpreter.callNode(ASTInterpreter.java:561)
at org.jruby.evaluator.ASTInterpreter.evalInternal(ASTInterpreter.java:208)
at org.jruby.evaluator.ASTInterpreter.orNode(ASTInterpreter.java:1335)
at org.jruby.evaluator.ASTInterpreter.evalInternal(ASTInterpreter.java:338)
at org.jruby.evaluator.ASTInterpreter.eval(ASTInterpreter.java:165)
at org.jruby.internal.runtime.methods.DefaultMethod.call(DefaultMethod.java:144)
at org.jruby.runtime.CallAdapter$DefaultCallAdapter.call(CallAdapter.java:167)
at org.jruby.runtime.CallAdapter$DefaultCallAdapter.call(CallAdapter.java:108)


Charles Oliver Nutter - 19/Oct/07 05:09 PM
This looks like a bug in jvyamlb. Assigning to Ola.

Ola Bini - 20/Oct/07 08:26 AM
This is strange - I can't reproduce the issue at all:
Orpheus:~/workspace/jruby> head bin/gem
#!/usr/bin/env jruby -J-Xmx384M
#--
# Copyright 2006 by Chad Fowler, Rich Kilmer, Jim Weirich and others.
# All rights reserved.
# See LICENSE.txt for permissions.
#++


require 'rubygems'
Gem.manage_gems
Orpheus:~/workspace/jruby> bin/gem install optiflag
Bulk updating Gem source index for: http://gems.rubyforge.org
Successfully installed optiflag-0.6.5
Installing ri documentation for optiflag-0.6.5...
Installing RDoc documentation for optiflag-0.6.5...

The above memory settings are the default in our gem script. As far as I can see, there is nothing bad in the YAML spec for optiflag, since I can install it just fine. Could you try again with the default settings?


Eric Armstrong - 23/Oct/07 05:03 PM
I just now found your comment. For some reason, the email notification escaped me.
I just duplicated the error with the default settings and a different command (gem query):

gem query --remote

      • REMOTE GEMS ***
        BBulk updating Gem source index for: http://gems.rubyforge.org
        Exception in thread "main" java.lang.OutOfMemoryError: GC overhead limit exceeded
        at org.jvyamlb.ParserImpl$25.produce(ParserImpl.java:488)
        at org.jvyamlb.ParserImpl.parseStreamNext(ParserImpl.java:823)
        at org.jvyamlb.ParserImpl.peekEvent(ParserImpl.java:774)
        at org.jvyamlb.ComposerImpl.composeNode(ComposerImpl.java:147)
        at org.jvyamlb.ComposerImpl.composeNode(ComposerImpl.java:167)
        at org.jvyamlb.ComposerImpl.composeNode(ComposerImpl.java:167)
        at org.jvyamlb.ComposerImpl.composeNode(ComposerImpl.java:167)
        at org.jvyamlb.ComposerImpl.composeDocument(ComposerImpl.java:100)
        at org.jvyamlb.ComposerImpl.getNode(ComposerImpl.java:76)
        at org.jvyamlb.BaseConstructorImpl.getData(BaseConstructorImpl.java:97)
        at org.jruby.RubyYAML.load(RubyYAML.java:221)
        at org.jruby.RubyYAMLInvokerSload1.call(Unknown Source)

I'm willing to believe that I have an environment anomaly, but I wonder what the
heck it could be? I'm glad that Pat Cheng observed the same problem. That
suggests that there is some difference between the modules or permissions
on a developer's system, as opposed to a "user's" system. Maybe you could try
it with a clean install of jruby binaries, rather than from a development environment?

Another highly likely suspect is an old Java class that somehow sneaked into the
binaries, so that your development classes are going to the wrong offsets in the
release versions. (I've seen that sort of thing before, although one would like to
imagine that it doesn't happen with interpreted classess...)


Pat Cheng - 23/Oct/07 05:58 PM
It's not specific on the gems. Originally, I had problem installing rails with my jruby_trunk, and I have the same problem with optiflag.

I just tried it again with a more recent trunk, and it works for me.


Ola Bini - 24/Oct/07 03:41 AM
Yeah, Eric, could you try with trunk JRuby and see if that works?

The version of JvYAML shipped in 1.0 takes much more memory, and I'm not sure it will be possible to backport those changes to the 1.0-branch.


Charles Oliver Nutter - 30/Oct/07 02:56 AM
Resolving as can't reproduce.

Eric Armstrong - 31/Oct/07 02:21 PM
a. Weird. This resolution message doesn't appear under
the bug-created thread.

b. I question the resolution.

The resolution is given as "unable to reproduce". Yet
Pat Cheng saw the same problem with the release version, and
as far as I can tell, everyone else who tried to reproduce
it was using the trunk, rather than the release.

To my mind, the inability to browse and load gems qualifies
as a "showstopper" bug. Version 1.0 shouldn't have gone out
with that problem, and a 1.0.x patch is needed to make it
into something usable. But Ola suggests that a back port to
the 1.0 branch isn't likely to be possible, which means that
branch is dead.

I thought about downloading the trunk, but I saw a ton of
bugs, and that gave me pause. So it seems that a stable
1.1 release is quite a ways off--which is a problem, because
I would be inclined to label it as an unresolved "Blocker"
in 1.0 and 1.0.1, and declare it "resolved in 1.1".


Thomas E Enebo - 31/Oct/07 02:53 PM
I did not notice that this was originally reported against Solaris, but we can now run this on 1.0.2 pre-build on both Windows and MacOS with no troubles. On windows there were some minor tweakage to make sure all .bat files had the upp'd -Xmx values. I also tried doing this by wiping out the source_cache which should be a worse case scenario.

Eric, can you reproduce this?


Charles Oliver Nutter - 31/Oct/07 02:56 PM
I was not able to reproduce this on Solaris 10 x86 or Mac OS 10.4 x86, but I did manage to get OOM on a Linux x64 box running Java 5. However, the -Xmx flag to bump it up (-J-Xmx512M in my case) allowed it to "Bulk update" just fine and proceed to the optiflag install.

Hence, "cannot reproduce". Eric, if you could try again against the 1.0 branch (ASAP, we're cutting a release within hours) and try to run this again, we would appreciate it. At the moment, it seems to work fine, albeit requiring a memory bump on one or two platforms.


Thomas E Enebo - 31/Oct/07 03:18 PM
Bumped max heap up to 512M since this worked for Charlie on 64 bit system. Commit 4837.

Joni Niemi - 10/Oct/08 01:04 AM
The reason seems to be that gem install process is a memory hog, at least in Windows platform. The process takes > 750 megabytes of memory in Windows XP.

Charles Oliver Nutter - 10/Oct/08 11:46 AM
Joni: I believe this should be entirely solved now that we've moved to RubyGems 1.2+. It no longer consumes so much memory, as part of design changes in RubyGems.