Tricky JRuby Issue with Java Exceptions
Wednesday, August 1st, 2012Yesterday I spent a good deal of time tracking down something that appears now to be an error in JRuby 1.6.7, which is what we're using on this code. The problem was a little nasty in that the code was generating a java exception and depending on the code we were using, it was either getting swallowed completely, or only showing the message of the exception - and not the complete stack trace as you'd expect in a Java exception.
But let's set the stage, and in doing so expose the error that led to this horrible problem. The code starts out with a seemingly innocent ruby module:
module Bun private def wrap(dog) puts "wrapping up #{dog}" end def box(dogs) puts "boxing up #{dogs.join(', ')}" end end
The idea is that the Bun is a module the has a few methods that we'll need in some other classes, and similar to an ObjC Category, it's placed here and just re-used in the classes with the 'include' directive.
Next comes a class that uses the Bun module - just as you'd expect.
require 'bun' class Fixer include Bun def fix(count) count.times wrap('beef dog') end end
Nothing fancy here.
The next class was intended to use this module when it had more functionality, but refactoring took that functionality out of the module and into the first class. Still, the refactoring didn't catch the difference, and so the code of the second class looks like this:
require 'bun' class Shipper include Bun def ship(count) fix(10) end end
Technically, the following code should not work:
require 'shipper' s = Shipper.new s.ship(1)
and in truth, it doesn't. But in the larger context of the app where there are many more things happening, it passed the compile and run tests only to find that there was a stack crash exception. So far, this was annoying, but that's not where it stopped.
The real code we had looked more like this:
require 'java' require 'java.util.concurrent.Executors' require 'java.util.concurrent.TimeUnit' require 'shipper' executor = Executors.new_fixed_thread_pool(4) 10.times do executor.execute do begin s = Shipper.new s.ship(1) rescue => e puts "caught: #{e.to_s}" end end end
So we have a multi-threaded app, using the Java Executors to help things out, and we got an exception that didn't get caught by the rescue clause. Very odd. Even worse, if we changed the call to use the submit method:
10.times do executor.submit do begin s = Shipper.new s.ship(1) rescue => e puts "caught: #{e.to_s}" end end end
we got NOTHING. The exception was thrown, but completely swallowed up by the Executor's submit call.
After a bunch of reading, the latter at least makes sense in the context of the JVM. All exceptions will get swallowed up in the submit call, and it's up to you to keep the future, and interrogate it. So that was explained. What wasn't explained was this: When I took out the Executor, I got the message and the stack trace!
OK, to summarize: Use the Executors and you get the exception message - Don't use it and you get the message and the stack trace.
I've tried to make a simple test case, the one above, but it's properly seen as not being able to find the method on the object. But in our more complex code, that's not the case. When I talked to a friend about this, I ended up getting this tweet in response:
As I've seen this guy today on the JRuby bug tracker, I think he really knows what he's talking about. Sadly, I can't easily reproduce the problem, and it's often these complex ones that are the really tough ones to reproduce. However, it's fixed, and we have a work-around (simply comment out the Executor block) so we're able to proceed. Also, I trust that it's fixed in JRuby 1.7, so when we want to go there, that'll be waiting for us.
In retrospect, this has been a lot of work, but a real insight into ruby, JRuby, and the support community. It's been a real enlightening experience.