Re-raising the cause of a Java exception can result in leaked memory and IllegalStateExceptions #4699
Description
Environment
$ jruby -v
jruby 9.1.12.0 (2.3.3) 2017-06-15 33c6439 Java HotSpot(TM) 64-Bit Server VM 25.121-b13 on 1.8.0_121-b13 +jit [darwin-x86_64]
$ uname -a
Darwin marshall-work-lappy.local 15.6.0 Darwin Kernel Version 15.6.0: Tue Apr 11 16:00:51 PDT 2017; root:xnu-3248.60.11.5.3~1/RELEASE_X86_64 x86_64
I only reproduced this using Guava, but I believe it is not a Guava specific bug. If you'd like me to reproduce without an external dependency I'm willing to try, but it was easier to just use Gauva.
Expected Behavior
Re-raising the cause of a Java exception should work without error or leaked memory.
This script reproduces part of the issue. It runs successfully on 1.7.27 but fails on 9.1.12.0.
To run, download the Guava jar https://repo1.maven.org/maven2/com/google/guava/guava/22.0/guava-22.0.jar, and place it this script:
#!/usr/bin/env jruby
NUM_THREADS = 5
puts RUBY_DESCRIPTION
require_relative 'guava-22.0.jar'
class CustomError < StandardError; end
class CacheLoader < com.google.common.cache.CacheLoader
def load(key)
raise CustomError
end
end
class LoadingCache
def initialize
@cache = com.google.common.cache.CacheBuilder.newBuilder.build(CacheLoader.new)
end
def get(key)
begin
begin
@cache.get(key)
rescue com.google.common.util.concurrent.UncheckedExecutionException => e
raise e.cause
end
rescue CustomError
nil
end
end
end
shared_cache = LoadingCache.new
puts "Starting #{NUM_THREADS} threads"
threads = NUM_THREADS.times.map do
Thread.new do
begin
10_000.times do
shared_cache.get('asdf')
end
puts "#{Thread.current} finished successfully!\n"
rescue => e
puts "#{Thread.current} failed"
puts "#{e.class}: #{e}\n\t#{e.backtrace.join("\n\t")}\n"
end
end
end
puts "Waiting for all threads to finish"
threads.map(&:join)
puts "DONE"
Actual Behavior
IllegalStateExceptions
Running the above script on 9.1.12.0 results in all threads except for one dying from IllegalStateExceptions. It does not fail if NUM_THREADS = 1.
$ jruby java_cause_bug.rb
jruby 9.1.12.0 (2.3.3) 2017-06-15 33c6439 Java HotSpot(TM) 64-Bit Server VM 25.121-b13 on 1.8.0_121-b13 +jit [darwin-x86_64]
Starting 5 threads
Waiting for all threads to finish
#<Thread:0x7648d86d> failed
Java::JavaLang::IllegalStateException: Can't overwrite cause with com.google.common.util.concurrent.UncheckedExecutionException: org.jruby.exceptions.RaiseException: (CustomError) CustomError
java.lang.Throwable.initCause(Throwable.java:457)
org.jruby.RubyKernel.maybeRaiseJavaException(RubyKernel.java:908)
org.jruby.RubyKernel.raise(RubyKernel.java:841)
org.jruby.RubyKernel$INVOKER$s$0$3$raise.call(RubyKernel$INVOKER$s$0$3$raise.gen)
org.jruby.internal.runtime.methods.DynamicMethod.call(DynamicMethod.java:204)
org.jruby.internal.runtime.methods.DynamicMethod.call(DynamicMethod.java:200)
org.jruby.runtime.callsite.CachingCallSite.cacheAndCall(CachingCallSite.java:338)
org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:163)
java_cause_bug.invokeOther52:raise(java_cause_bug.rb:28)
java_cause_bug.RUBY$method$get$8(java_cause_bug.rb:28)
org.jruby.internal.runtime.methods.CompiledIRMethod.call(CompiledIRMethod.java:168)
org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:161)
java_cause_bug.invokeOther1:get(java_cause_bug.rb:43)
java_cause_bug.RUBY$block$\=java_cause_bug\,rb$2(java_cause_bug.rb:43)
org.jruby.runtime.CompiledIRBlockBody.yieldDirect(CompiledIRBlockBody.java:156)
org.jruby.runtime.IRBlockBody.yieldSpecific(IRBlockBody.java:80)
org.jruby.runtime.Block.yieldSpecific(Block.java:134)
org.jruby.RubyFixnum.times(RubyFixnum.java:299)
org.jruby.RubyFixnum$INVOKER$i$0$0$times.call(RubyFixnum$INVOKER$i$0$0$times.gen)
org.jruby.runtime.callsite.CachingCallSite.callBlock(CachingCallSite.java:139)
org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:145)
java_cause_bug.invokeOther4:times(java_cause_bug.rb:42)
java_cause_bug.RUBY$block$\=java_cause_bug\,rb$1(java_cause_bug.rb:42)
org.jruby.runtime.CompiledIRBlockBody.callDirect(CompiledIRBlockBody.java:145)
org.jruby.runtime.IRBlockBody.call(IRBlockBody.java:71)
org.jruby.runtime.Block.call(Block.java:124)
org.jruby.RubyProc.call(RubyProc.java:289)
org.jruby.RubyProc.call(RubyProc.java:246)
org.jruby.internal.runtime.RubyRunnable.run(RubyRunnable.java:104)
java.lang.Thread.run(Thread.java:745)
#<Thread:0xcdfc808> failed
[... removed stack since it's the same as above ...]
#<Thread:0x2b046212> failed
[... removed stack since it's the same as above ...]
#<Thread:0x552f9d5a> failed
[... removed stack since it's the same as above ...]
#<Thread:0x1275b47c> finished successfully!
DONE
Memory leaks
Regarding the memory leak, I have not yet been able to reproduce outside of production but running code similar to what is above resulted in several threads that each had a single 1.1GB RubyArrayOne object
that contained many ConcreteJavaProxys that wrapped the exception being thrown:
I changed our prod code from
begin
foo
rescue com.google.common.util.concurrent.UncheckedExecutionException => e
raise e.cause
end
to
begin
return foo
rescue com.google.common.util.concurrent.UncheckedExecutionException => e
end
raise e
and the memory leak went away. So I believe that re-raising a cause from inside the rescue in cases like this can also result in circular dependencies that leak memory.
The memory leak occurred on Linux with JRuby 9.1.7.0:
$ uname -a
Linux someserver 2.6.32-696.3.1.el6.x86_64 #1 SMP Tue May 30 19:52:55 UTC 2017 x86_64 x86_64 x86_64 GNU/Linux
$ ruby -v
jruby 9.1.7.0 (2.3.1) 2017-01-11 68056ae OpenJDK 64-Bit Server VM 25.131-b11 on 1.8.0_131-b11 +jit [linux-x86_64]
Let me know if there is any more useful detail that I should add!