Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

JRuby 9.0.5.0+ OOM errors under CentOS #3941

Closed
etehtsea opened this issue May 30, 2016 · 7 comments
Closed

JRuby 9.0.5.0+ OOM errors under CentOS #3941

etehtsea opened this issue May 30, 2016 · 7 comments

Comments

@etehtsea
Copy link
Contributor

etehtsea commented May 30, 2016

This issue also reproduced on production app after ~2 days of running under new jruby version. At some point we started to get OOM errors in our error-catcher and rpm on this node decreased relatively to other nodes which ran under 9.0.4.0. After switching to ubuntu based container this issue disappeared.

Results matrix:
JRuby 9.0.4.0 (Centos): 👍
JRuby 9.0.5.0+ (Centos): 👎
JRuby 9.0.5.0+ (Ubuntu): 👍

Images used below available on docker hub:

P.S. Notice that bundler 1.12.0+ has another perf issue (rubygems/bundler#4478) so I pinned bundler version to 1.11.2.

Gemfile used:

source 'https://rubygems.org'; gem 'rack'

JRuby 9.0.4.0 (CentOS)

/tmp  ⚡ \time -p docker run --rm -it -v /tmp/Gemfile:/Gemfile -w / etehtsea/jruby-centos:9.0.4.0 jruby -v -S bundle install --verbose --full-index 
jruby 9.0.4.0 (2.2.2) 2015-11-12 b9fb7aa OpenJDK 64-Bit Server VM 25.91-b14 on 1.8.0_91-b14 +jit [linux-amd64]
Don't run Bundler as root. Bundler can ask for sudo if it is needed, and
installing your bundle as root will break this application for all non-root
users on this machine.
Fetching source index from https://rubygems.org/
Need to query more than 500 gems. Downloading full index instead...
HTTP GET https://rubygems.org/quick/Marshal.4.8/rack-0.1.0.gemspec.rz
<..>
HTTP GET https://rubygems.global.ssl.fastly.net/quick/Marshal.4.8/rack-2.0.0.rc1.gemspec.rz
HTTP 200 OK
Resolving dependencies....
Installing rack 1.6.4
0:  rack (1.6.4) from /opt/jruby/lib/ruby/gems/shared/specifications/rack-1.6.4.gemspec
Using bundler 1.11.2
0:  bundler (1.11.2) from /opt/jruby/lib/ruby/gems/shared/specifications/bundler-1.11.2.gemspec
Bundle complete! 1 Gemfile dependency, 2 gems now installed.
Use `bundle show [gemname]` to see where a bundled gem is installed.
real        57.19
user         0.01
sys          0.02

JRuby 9.0.5.0 (CentOS)

/tmp  ⚡ \time -p docker run --rm -it -v /tmp/Gemfile:/Gemfile -w / etehtsea/jruby-centos:9.0.5.0 jruby -v -S bundle install --verbose --full-index   
jruby 9.0.5.0 (2.2.3) 2016-01-26 7bee00d OpenJDK 64-Bit Server VM 25.91-b14 on 1.8.0_91-b14 +jit [linux-amd64]
Don't run Bundler as root. Bundler can ask for sudo if it is needed, and
installing your bundle as root will break this application for all non-root
users on this machine.
Fetching source index from https://rubygems.org/
--- ERROR REPORT TEMPLATE -------------------------------------------------------
- What did you do?

  I ran the command `/opt/jruby/bin/bundle install --verbose --full-index`

- What did you expect to happen?

  I expected Bundler to...

- What happened instead?

  Instead, what actually happened was...


Error details

    Java::JavaLang::OutOfMemoryError: GC overhead limit exceeded
      org.jruby.RubyString.cat19(RubyString.java:1295)
      org.jruby.RubyString.cat19(RubyString.java:1285)
      org.jruby.RubyString.append19(RubyString.java:2068)
      opt.jruby.lib.ruby.gems.shared.gems.bundler_minus_1_dot_11_dot_2.lib.bundler.index.RUBY$method$\=\^\^$0(/opt/jruby/lib/ruby/gems/shared/gems/bundler-1.11.2/lib/bundler/index.rb:91)
      java.lang.invoke.LambdaForm$DMH/106297322.invokeStatic_L7_L(LambdaForm$DMH)
      java.lang.invoke.LambdaForm$MH/55331187.invokeExact_MT(LambdaForm$MH)
      org.jruby.internal.runtime.methods.CompiledIRMethod.call(CompiledIRMethod.java:131)
      org.jruby.internal.runtime.methods.MixedModeIRMethod.call(MixedModeIRMethod.java:194)
      org.jruby.internal.runtime.methods.DynamicMethod.call(DynamicMethod.java:197)
      org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:161)
      org.jruby.runtime.callsite.ShiftLeftCallSite.call(ShiftLeftCallSite.java:24)
      org.jruby.ir.interpreter.InterpreterEngine.processCall(InterpreterEngine.java:316)
      org.jruby.ir.interpreter.StartupInterpreterEngine.interpret(StartupInterpreterEngine.java:77)
      org.jruby.ir.interpreter.Interpreter.INTERPRET_BLOCK(Interpreter.java:132)
      org.jruby.runtime.MixedModeIRBlockBody.commonYieldPath(MixedModeIRBlockBody.java:148)
      org.jruby.runtime.IRBlockBody.doYield(IRBlockBody.java:179)
      org.jruby.runtime.BlockBody.yield(BlockBody.java:96)
      org.jruby.runtime.Block.yield(Block.java:166)
      org.jruby.RubyArray.each(RubyArray.java:1560)
      org.jruby.RubyArray$INVOKER$i$0$0$each.call(RubyArray$INVOKER$i$0$0$each.gen)
      org.jruby.internal.runtime.methods.JavaMethod$JavaMethodZeroBlock.call(JavaMethod.java:494)
      org.jruby.runtime.callsite.CachingCallSite.cacheAndCall(CachingCallSite.java:273)
      org.jruby.runtime.callsite.CachingCallSite.callBlock(CachingCallSite.java:79)
      org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:83)
      org.jruby.ir.instructions.CallBase.interpret(CallBase.java:414)
      org.jruby.ir.interpreter.InterpreterEngine.processCall(InterpreterEngine.java:348)
      org.jruby.ir.interpreter.StartupInterpreterEngine.interpret(StartupInterpreterEngine.java:77)
      org.jruby.internal.runtime.methods.MixedModeIRMethod.INTERPRET_METHOD(MixedModeIRMethod.java:140)
      org.jruby.internal.runtime.methods.MixedModeIRMethod.call(MixedModeIRMethod.java:126)
      org.jruby.runtime.callsite.CachingCallSite.cacheAndCall(CachingCallSite.java:273)
      org.jruby.runtime.callsite.CachingCallSite.callBlock(CachingCallSite.java:79)
      org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:83)

Environment

    Bundler   1.11.2
    Rubygems  2.4.8
    Ruby      2.2.3p0 (2016-01-26 revision 51636) [java]
    GEM_HOME  /opt/jruby/lib/ruby/gems/shared
    GEM_PATH  /opt/jruby/lib/ruby/gems/shared:/root/.gem/jruby/2.2.0
    Git       not installed
--- TEMPLATE END ----------------------------------------------------------------

Unfortunately, an unexpected error occurred, and Bundler cannot continue.

First, try this link to see if there are any existing issue reports for this error:
https://github.com/bundler/bundler/search?q=GC+overhead+limit+exceeded&type=Issues

If there aren't any reports for this error yet, please create copy and paste the report template above into a new issue. Don't forget to anonymize any private data! The new issue form is located at:
https://github.com/bundler/bundler/issues/new
real        63.02
user         0.01
sys          0.02

JRuby 9.1.2.0 (CentOS)

/tmp  ⚡ \time -p docker run --rm -it -v /tmp/Gemfile:/Gemfile -w / etehtsea/jruby-centos:9.1.2.0 jruby -v -S bundle install --verbose --full-index  
jruby 9.1.2.0 (2.3.0) 2016-05-26 7357c8f OpenJDK 64-Bit Server VM 25.91-b14 on 1.8.0_91-b14 +jit [linux-x86_64]
Don't run Bundler as root. Bundler can ask for sudo if it is needed, and
installing your bundle as root will break this application for all non-root
users on this machine.
Fetching source index from https://rubygems.org/
--- ERROR REPORT TEMPLATE -------------------------------------------------------
- What did you do?

  I ran the command `/opt/jruby/bin/bundle install --verbose --full-index`

- What did you expect to happen?

  I expected Bundler to...

- What happened instead?

  Instead, what actually happened was...


Error details

    Java::JavaLang::OutOfMemoryError: GC overhead limit exceeded
      org.jruby.ir.instructions.SearchConstInstr.cache(SearchConstInstr.java:99)
      org.jruby.ir.interpreter.StartupInterpreterEngine.processOtherOp(StartupInterpreterEngine.java:173)
      org.jruby.ir.interpreter.StartupInterpreterEngine.interpret(StartupInterpreterEngine.java:115)
      org.jruby.ir.interpreter.InterpreterEngine.interpret(InterpreterEngine.java:86)
      org.jruby.internal.runtime.methods.MixedModeIRMethod.INTERPRET_METHOD(MixedModeIRMethod.java:179)
      org.jruby.internal.runtime.methods.MixedModeIRMethod.call(MixedModeIRMethod.java:165)
      org.jruby.RubyClass.invoke(RubyClass.java:553)
      org.jruby.runtime.Helpers.invoke(Helpers.java:424)
      org.jruby.ir.instructions.specialized.OneArgOperandAttrAssignInstr.interpret(OneArgOperandAttrAssignInstr.java:27)
      org.jruby.ir.interpreter.InterpreterEngine.processCall(InterpreterEngine.java:348)
      org.jruby.ir.interpreter.StartupInterpreterEngine.interpret(StartupInterpreterEngine.java:77)
      org.jruby.internal.runtime.methods.MixedModeIRMethod.INTERPRET_METHOD(MixedModeIRMethod.java:109)
      org.jruby.internal.runtime.methods.MixedModeIRMethod.call(MixedModeIRMethod.java:95)
      org.jruby.runtime.callsite.CachingCallSite.cacheAndCall(CachingCallSite.java:273)
      org.jruby.runtime.callsite.CachingCallSite.callBlock(CachingCallSite.java:79)
      org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:83)
      org.jruby.ir.instructions.CallBase.interpret(CallBase.java:423)
      org.jruby.ir.interpreter.InterpreterEngine.processCall(InterpreterEngine.java:348)
      org.jruby.ir.interpreter.StartupInterpreterEngine.interpret(StartupInterpreterEngine.java:77)
      org.jruby.ir.interpreter.Interpreter.INTERPRET_BLOCK(Interpreter.java:132)
      org.jruby.runtime.MixedModeIRBlockBody.commonYieldPath(MixedModeIRBlockBody.java:148)
      org.jruby.runtime.IRBlockBody.call(IRBlockBody.java:66)
      org.jruby.runtime.Block.call(Block.java:126)
      org.jruby.RubyProc.call(RubyProc.java:342)
      org.jruby.RubyProc.call19(RubyProc.java:326)
      org.jruby.RubyProc$INVOKER$i$0$0$call19.call(RubyProc$INVOKER$i$0$0$call19.gen)
      org.jruby.internal.runtime.methods.DynamicMethod.call(DynamicMethod.java:193)
      org.jruby.internal.runtime.methods.DynamicMethod.call(DynamicMethod.java:189)
      org.jruby.runtime.callsite.CachingCallSite.cacheAndCall(CachingCallSite.java:293)
      org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:131)
      org.jruby.ir.interpreter.InterpreterEngine.processCall(InterpreterEngine.java:332)
      org.jruby.ir.interpreter.StartupInterpreterEngine.interpret(StartupInterpreterEngine.java:77)

Environment

    Bundler   1.11.2
    Rubygems  2.6.4
    Ruby      2.3.0p0 (2016-05-26 revision 52539) [java]
    GEM_HOME  /opt/jruby/lib/ruby/gems/shared
    GEM_PATH  /opt/jruby/lib/ruby/gems/shared:/root/.gem/jruby/2.3.0
    Git       not installed
--- TEMPLATE END ----------------------------------------------------------------

Unfortunately, an unexpected error occurred, and Bundler cannot continue.

First, try this link to see if there are any existing issue reports for this error:
https://github.com/bundler/bundler/search?q=GC+overhead+limit+exceeded&type=Issues

If there aren't any reports for this error yet, please create copy and paste the report template above into a new issue. Don't forget to anonymize any private data! The new issue form is located at:
https://github.com/bundler/bundler/issues/new
real        62.68
user         0.00
sys          0.00

JRuby 9.0.5.0 (Ubuntu)

/tmp  ⚡ \time -p docker run --rm -it -v /tmp/Gemfile:/Gemfile -w / etehtsea/jruby-ubuntu:9.0.5.0 jruby -v -S bundle install --verbose --full-index  
jruby 9.0.5.0 (2.2.3) 2016-01-26 7bee00d OpenJDK 64-Bit Server VM 25.91-b14 on 1.8.0_91-8u91-b14-1~bpo8+1-b14 +jit [linux-amd64]
Don't run Bundler as root. Bundler can ask for sudo if it is needed, and
installing your bundle as root will break this application for all non-root
users on this machine.
Fetching source index from https://rubygems.org/
Need to query more than 500 gems. Downloading full index instead...
HTTP GET https://rubygems.org/quick/Marshal.4.8/rack-0.1.0.gemspec.rz
HTTP 302 Moved Temporarily
HTTP GET https://rubygems.global.ssl.fastly.net/quick/Marshal.4.8/rack-0.1.0.gemspec.rz
<..>
HTTP GET https://rubygems.global.ssl.fastly.net/quick/Marshal.4.8/rack-2.0.0.rc1.gemspec.rz
HTTP 200 OK
Resolving dependencies....
Installing rack 1.6.4
/opt/jruby/lib/ruby/stdlib/jars/installer.rb:12: warning: Ambiguous first argument; make sure.
0:  rack (1.6.4) from /opt/jruby/lib/ruby/gems/shared/specifications/rack-1.6.4.gemspec
Using bundler 1.11.2
0:  bundler (1.11.2) from /opt/jruby/lib/ruby/gems/shared/specifications/bundler-1.11.2.gemspec
Bundle complete! 1 Gemfile dependency, 2 gems now installed.
Use `bundle show [gemname]` to see where a bundled gem is installed.
real        65.02
user         0.01
sys          0.01

JRuby 9.1.2.0 (Ubuntu)

/tmp  ⚡ \time -p docker run --rm -it -v /tmp/Gemfile:/Gemfile -w / etehtsea/jruby-ubuntu:9.1.2.0 jruby -v -S bundle install --verbose --full-index   
jruby 9.1.2.0 (2.3.0) 2016-05-26 7357c8f OpenJDK 64-Bit Server VM 25.91-b14 on 1.8.0_91-8u91-b14-1~bpo8+1-b14 +jit [linux-x86_64]
Don't run Bundler as root. Bundler can ask for sudo if it is needed, and
installing your bundle as root will break this application for all non-root
users on this machine.
Fetching source index from https://rubygems.org/
Need to query more than 500 gems. Downloading full index instead...
HTTP GET https://rubygems.org/quick/Marshal.4.8/rack-0.1.0.gemspec.rz
HTTP 302 Moved Temporarily
HTTP GET https://rubygems.global.ssl.fastly.net/quick/Marshal.4.8/rack-0.1.0.gemspec.rz
<..>
HTTP GET https://rubygems.global.ssl.fastly.net/quick/Marshal.4.8/rack-2.0.0.rc1.gemspec.rz
HTTP 200 OK
Resolving dependencies....
Installing rack 1.6.4
constructing an Installer object with a string is deprecated. Please use Gem::Installer.at (called from: /opt/jruby/lib/ruby/gems/shared/gems/bundler-1.11.2/lib/bundler/source/rubygems.rb:135:in `block in install')
0:  rack (1.6.4) from /opt/jruby/lib/ruby/gems/shared/specifications/rack-1.6.4.gemspec
Using bundler 1.11.2
0:  bundler (1.11.2) from /opt/jruby/lib/ruby/gems/shared/specifications/bundler-1.11.2.gemspec
Bundle complete! 1 Gemfile dependency, 2 gems now installed.
Use `bundle show [gemname]` to see where a bundled gem is installed.
real        64.21
user         0.01
sys          0.01
@headius
Copy link
Member

headius commented May 31, 2016

@etehtsea Thanks for the report! It's very strange to see such different behavior just moving to another Linux flavor. Thank you also for including the 9.0.5.0 output...it's helpful to know it it existed before JRuby 9.1.

Can you try to reproduce with this flag passed to JRuby, please: -J-XX:+HeapDumpOnOutOfMemoryError

That should produce a dump of your bundle install execution and we can see why there's so much memory being consumed. Attach it here or post it somewhere we can download it (it's likely text, so it should compress well).

@bbrowning
Copy link
Contributor

This may be related to jruby/jruby-openssl#94. Memory consumption from that issue is directly related to the X509 certificates installed on a machine. A heap dump will tell you for sure as classes related to X509 certificates will use up lots of memory if this is the same underlying cause.

@etehtsea
Copy link
Contributor Author

@headius
Copy link
Member

headius commented Jun 8, 2016

@etehtsea Thanks! I'll have a look at it today.

@headius
Copy link
Member

headius commented Jun 8, 2016

Ok, there appears to be a few things taking up a lot of memory. I used Eclipse Memory Analyzer to do a leak search and it found the following items:

  1. A single RubyHash for Bundler's Index appears to be retaining over 160MB all by itself. I dug into the Hash in question and see keys like "21-day-challenge-countdown", "3d-ribbon", "53cr-shoulda-generator". I'm not sure what all this is, but it's not likely to be the issue.
  2. The OpenSSL issue seems to be that org.jruby.ext.openssl.x509store.X509Object.Store has an array of X509Object with 165 entries, all x509Store.Certificate objects. These are consuming a bit over 400k each for a total of almost 67MB. This appears to be the issue @bbrowning mentioned; these certificates are each holding on to their own BouncyCastle provider. cc @kares and @mkristian. This problem shows up a few more times in the leak suspects report.
  3. A RubyArray instance used by RubyGems to hold all loaded gems appears to be retaining 64MB of memory. Most of the entries are themselves RubyArray instances, containing tuples of two strings and a Gem::Version object. It isn't too suprising to see this structure, so I wouldn't consider it a suspect, but it is a lot of memory just to hold gem versions. This is likely smaller under 9.1 since the Gem::Version object will be a more efficient structure internally

So of these, only (2) seems to be a regression. The others could be improved, but it may require working with RubyGems and Bundler folks. Since we already have jruby/jruby-openssl#94 I'm going to close this as a duplicate.

FWIW, here's the top 25-or-so dominators in your heap dump:

Class Name                                                       | Shallow Heap | Retained Heap | Percentage
-------------------------------------------------------------------------------------------------------------
org.jruby.RubyObject @ 0xe9e3ad20                                |           32 |   163,545,584 |     40.28%
org.jruby.RubyClass @ 0xe20485a8                                 |          200 |    66,928,032 |     16.48%
org.jruby.RubyObject @ 0xe6f3e1c8                                |           32 |    66,918,424 |     16.48%
org.jruby.RubyArray @ 0xec6ef228                                 |           48 |    64,108,672 |     15.79%
org.jruby.Ruby @ 0xe0d73ac0                                      |          880 |     2,130,496 |      0.52%
org.bouncycastle.jce.provider.BouncyCastleProvider @ 0xe2693728  |           96 |       664,888 |      0.16%
java.util.jar.JarFile @ 0xe1f1b940                               |           64 |       541,016 |      0.13%
class org.jruby.util.JarResource @ 0xe0c5ff40 System Class       |            8 |       469,416 |      0.12%
org.jruby.util.JRubyClassLoader @ 0xe0e8fdb8                     |           88 |       468,744 |      0.12%
org.jruby.RubyModule @ 0xe6b7e088                                |          136 |       407,840 |      0.10%
org.jruby.RubyClass @ 0xe12e6d70                                 |          200 |       348,120 |      0.09%
org.jruby.RubyModule @ 0xe113f060                                |          136 |       331,496 |      0.08%
org.jruby.runtime.load.LoadService @ 0xe0d73ee8                  |           64 |       227,760 |      0.06%
class sun.security.provider.X509Factory @ 0xe194e1e8 System Class|           24 |       223,144 |      0.05%
class org.jruby.parser.RubyParser @ 0xe0c01cd8 System Class      |          584 |       186,000 |      0.05%
org.jruby.RubyClass @ 0xe1aab038                                 |          200 |       184,520 |      0.05%
class sun.util.calendar.ZoneInfoFile @ 0xe0c5a738 System Class   |          120 |       159,936 |      0.04%
org.jruby.RubyClass @ 0xe12fecd0                                 |          200 |       135,232 |      0.03%
com.sun.crypto.provider.SunJCE @ 0xe2ad3b10                      |           96 |       123,152 |      0.03%
java.util.jar.JarFile @ 0xe1fbdcf0                               |           64 |       121,696 |      0.03%
sun.misc.Launcher$ExtClassLoader @ 0xe0d80af0                    |           80 |       121,272 |      0.03%
org.jruby.RubyClass @ 0xe18c1570                                 |          200 |       119,248 |      0.03%
-------------------------------------------------------------------------------------------------------------

@headius headius closed this as completed Jun 8, 2016
@headius headius added this to the Invalid or Duplicate milestone Jun 8, 2016
@headius
Copy link
Member

headius commented Jun 8, 2016

@etehtsea We are working on a fix that will go into a jruby-openssl release, but as a short term workaround can you try passing -Xopenssl.provider.register=true to JRuby or -Djruby.openssl.provider.register=true to the JVM? It should help.

@headius
Copy link
Member

headius commented Jun 8, 2016

@etehtsea Sorry, I guess that workaround won't work until we get next jruby-openssl release out, in which case we'll just fix it.

@headius headius mentioned this issue Jun 30, 2016
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

3 participants