Skip to content
This repository has been archived by the owner on Jan 12, 2024. It is now read-only.

Bug: JRuby stacktraces with Java content can fail the reporting #47

Open
wants to merge 13 commits into
base: master
Choose a base branch
from

Conversation

olleolleolle
Copy link
Contributor

@olleolleolle olleolleolle commented Feb 20, 2017

JRuby stacktraces can contain lines that do not conform to the BACKTRACE_REGEX pattern, which then returns nil instead of matches. Selection on these bad matches will fail with a NoMethodError for #start_with? on nil.

  • JRuby: Disable sqlite3 in Gemfile.base and tests that rely on it
  • Spec: Add a JRuby-only spec for stacktraces of Java Exceptions
  • Spec file: Rubocop autocorrect (this changed a line number in a test)
  • Implementation change: if strip_load_path gets a nil it returns "" (Controversial? I don't know enough to know.)

(Update): This is an Issue which was upgraded to a PR after the fact.

Update 2: This is not finished.

Current behavior

See error_message/stacktrace.rb for the code that fails.

Here's the current behavior: Opbeat throws a stacktrace and a "NoMethodError on nil".

rake aborted!
NoMethodError: undefined method `start_with?' for nil:NilClass
/home/ecraft/my-gems/jruby/2.3.0/gems/opbeat-3.0.9/lib/opbeat/error_message/stacktrace.rb:50:in `block in strip_load_path'
/home/ecraft/my-gems/jruby/2.3.0/gems/opbeat-3.0.9/lib/opbeat/error_message/stacktrace.rb:48:in `strip_load_path'
/home/ecraft/my-gems/jruby/2.3.0/gems/opbeat-3.0.9/lib/opbeat/error_message/stacktrace.rb:34:in `from_line'
/home/ecraft/my-gems/jruby/2.3.0/gems/opbeat-3.0.9/lib/opbeat/error_message/stacktrace.rb:15:in `block in from'
/home/ecraft/my-gems/jruby/2.3.0/gems/opbeat-3.0.9/lib/opbeat/error_message/stacktrace.rb:14:in `from'
/home/ecraft/my-gems/jruby/2.3.0/gems/opbeat-3.0.9/lib/opbeat/error_message.rb:54:in `block in from_exception'
/home/ecraft/my-gems/jruby/2.3.0/gems/opbeat-3.0.9/lib/opbeat/error_message.rb:26:in `initialize'
/home/ecraft/my-gems/jruby/2.3.0/gems/opbeat-3.0.9/lib/opbeat/error_message.rb:51:in `from_exception'
/home/ecraft/my-gems/jruby/2.3.0/gems/opbeat-3.0.9/lib/opbeat/client.rb:196:in `report'
/home/ecraft/my-gems/jruby/2.3.0/gems/opbeat-3.0.9/lib/opbeat.rb:114:in `report'
/dist/rails-app/Rakefile:24:in `execute'
/home/ecraft/my-gems/jruby/2.3.0/gems/rake-12.0.0/exe/rake:27:in `<main>'

Background

Update: The script below as a runnable file: https://gist.github.com/olleolleolle/2a9ba37a0fe774bd484929c0e0f155bb

Here is a way to make a Java exception in JRuby:

def make_java_exception
  require 'java'
  java_import 'java.lang.ClassNotFoundException'
  java::lang::Class.forName("foo.Bar")
rescue ClassNotFoundException => e
  e
end

Having cut and pasted the strip_load_path and BACKTRACE_REGEX into my irb, I could reproduce the issue with a standard Java error:

jruby-9.1.7.0 :022 > ex = make_java_exception
jruby-9.1.7.0 :022 > ex.backtrace.reverse.map {|line|
  _, abs_path, lineno, function = line.match(BACKTRACE_REGEX).to_a
 filename = strip_load_path(abs_path)
}

NoMethodError: undefined method `start_with?' for nil:NilClass
	from (irb):4:in `block in strip_load_path'
	from org/jruby/RubyArray.java:2564:in `select'
	from (irb):2:in `strip_load_path'
	from (irb):22:in `block in evaluate'
	from org/jruby/RubyArray.java:2485:in `map'
	from (irb):22:in `<eval>'
	from org/jruby/RubyKernel.java:1000:in `eval'
	from org/jruby/RubyKernel.java:1298:in `loop'
	from org/jruby/RubyKernel.java:1120:in `catch'
	from org/jruby/RubyKernel.java:1120:in `catch'
	from /Users/olle/.rvm/rubies/jruby-9.1.7.0/bin/irb:13:in `<main>'

Example of the stacktrace generated above:

java.lang.Class.forName0(Native Method)
java.lang.Class.forName(java/lang/Class.java:264)
java.lang.reflect.Method.invoke(java/lang/reflect/Method.java:498)
org.jruby.javasupport.JavaMethod.invokeDirectWithExceptionHandling(org/jruby/javasupport/JavaMethod.java:453)
org.jruby.javasupport.JavaMethod.invokeStaticDirect(org/jruby/javasupport/JavaMethod.java:365)
RUBY.make_java_exception((irb):26)
RUBY.<eval>((irb):30)
org.jruby.RubyKernel.evalCommon(org/jruby/RubyKernel.java:1033)
org.jruby.RubyKernel.eval(org/jruby/RubyKernel.java:1000)
org.jruby.RubyKernel$INVOKER$s$0$3$eval19.call(org/jruby/RubyKernel$INVOKER$s$0$3$eval19.gen)
RUBY.evaluate(/Users/olle/.rvm/rubies/jruby-9.1.7.0/lib/ruby/stdlib/irb/workspace.rb:87)
RUBY.evaluate(/Users/olle/.rvm/rubies/jruby-9.1.7.0/lib/ruby/stdlib/irb/context.rb:380)
RUBY.block in eval_input(/Users/olle/.rvm/rubies/jruby-9.1.7.0/lib/ruby/stdlib/irb.rb:489)
RUBY.signal_status(/Users/olle/.rvm/rubies/jruby-9.1.7.0/lib/ruby/stdlib/irb.rb:623)
RUBY.block in eval_input(/Users/olle/.rvm/rubies/jruby-9.1.7.0/lib/ruby/stdlib/irb.rb:486)
RUBY.block in each_top_level_statement(/Users/olle/.rvm/rubies/jruby-9.1.7.0/lib/ruby/stdlib/irb/ruby-lex.rb:246)
org.jruby.RubyKernel.loop(org/jruby/RubyKernel.java:1298)
org.jruby.RubyKernel$INVOKER$s$0$0$loop.call(org/jruby/RubyKernel$INVOKER$s$0$0$loop.gen)
RUBY.block in each_top_level_statement(/Users/olle/.rvm/rubies/jruby-9.1.7.0/lib/ruby/stdlib/irb/ruby-lex.rb:232)
org.jruby.RubyContinuation.enter(org/jruby/RubyContinuation.java:107)
org.jruby.RubyKernel.rbCatch19Common(org/jruby/RubyKernel.java:1127)
org.jruby.RubyKernel.catch(org/jruby/RubyKernel.java:1120)
org.jruby.RubyKernel$INVOKER$s$rbCatch19.call(org/jruby/RubyKernel$INVOKER$s$rbCatch19.gen)
RUBY.each_top_level_statement(/Users/olle/.rvm/rubies/jruby-9.1.7.0/lib/ruby/stdlib/irb/ruby-lex.rb:231)
RUBY.eval_input(/Users/olle/.rvm/rubies/jruby-9.1.7.0/lib/ruby/stdlib/irb.rb:485)
RUBY.block in start(/Users/olle/.rvm/rubies/jruby-9.1.7.0/lib/ruby/stdlib/irb.rb:395)
org.jruby.RubyContinuation.enter(org/jruby/RubyContinuation.java:107)
org.jruby.RubyKernel.rbCatch19Common(org/jruby/RubyKernel.java:1127)
org.jruby.RubyKernel.catch(org/jruby/RubyKernel.java:1120)
org.jruby.RubyKernel$INVOKER$s$rbCatch19.call(org/jruby/RubyKernel$INVOKER$s$rbCatch19.gen)
RUBY.start(/Users/olle/.rvm/rubies/jruby-9.1.7.0/lib/ruby/stdlib/irb.rb:394)
Users.olle.$_dot_rvm.rubies.jruby_minus_9_dot_1_dot_7_dot_0.bin.irb.invokeOther3:start(Users/olle/$_dot_rvm/rubies/jruby_minus_9_dot_1_dot_7_dot_0/bin//Users/olle/.rvm/rubies/jruby-9.1.7.0/bin/irb:13)
Users.olle.$_dot_rvm.rubies.jruby_minus_9_dot_1_dot_7_dot_0.bin.irb.<main>(/Users/olle/.rvm/rubies/jruby-9.1.7.0/bin/irb:13)
java.lang.invoke.MethodHandle.invokeWithArguments(java/lang/invoke/MethodHandle.java:627)
org.jruby.Ruby.runScript(org/jruby/Ruby.java:823)
org.jruby.Ruby.runNormally(org/jruby/Ruby.java:742)
org.jruby.Ruby.runNormally(org/jruby/Ruby.java:760)
org.jruby.Ruby.runFromMain(org/jruby/Ruby.java:573)
org.jruby.Main.doRunFromMain(org/jruby/Main.java:417)
org.jruby.Main.internalRun(org/jruby/Main.java:305)
org.jruby.Main.run(org/jruby/Main.java:232)
org.jruby.Main.main(org/jruby/Main.java:204)

Solution inspiration

@olleolleolle
Copy link
Contributor Author

In my case, it was just a regular old LoadError which triggered this sad issue.

@olleolleolle olleolleolle changed the title Bug: JRuby stacktraces with nil paths can fail the reporting Bug: JRuby stacktraces with Java content can fail the reporting Feb 20, 2017
@mikker
Copy link
Collaborator

mikker commented Feb 20, 2017

Thanks! A PR would be greatly appreciated 👍

@olleolleolle
Copy link
Contributor Author

@mikker I have questions on desired behavior. I don't quite know how things behave with returned lists of Frame objects.

If I add something like this"

diff --git a/lib/opbeat/error_message/stacktrace.rb b/lib/opbeat/error_message/stacktrace.rb
index 6133f6f..0bb8704 100644
--- a/lib/opbeat/error_message/stacktrace.rb
+++ b/lib/opbeat/error_message/stacktrace.rb
@@ -27,9 +27,19 @@ module Opbeat
 
         BACKTRACE_REGEX = /^(.+?):(\d+)(?::in `(.+?)')?$/.freeze
 
+        # regexp (optional leading X: on windows, or JRuby9000 class-prefix)
+        RUBY_INPUT_FORMAT = /
+          ^ \s* (?: [a-zA-Z]: | uri:classloader: )? ([^:]+ | <.*>):
+          (\d+)
+          (?: :in \s `([^']+)')?$
+        /x
+
+        # org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:170)
+        JAVA_INPUT_FORMAT = /^(.+)\.([^\.]+)\(([^\:]+)\:(\d+)\)$/
+
         class << self
           def from_line config, line
-            _, abs_path, lineno, function = line.match(BACKTRACE_REGEX).to_a
+            abs_path, lineno, function, _module_name = parse_line(line)
             lineno = lineno.to_i
             filename = strip_load_path(abs_path)
 
@@ -44,7 +54,21 @@ module Opbeat
 
           private
 
+          def parse_line(unparsed_line)
+            ruby_match = unparsed_line.match(RUBY_INPUT_FORMAT)
+            if ruby_match
+              _, file, number, method = ruby_match.to_a
+              file.sub!(/\.class$/, '.rb')
+              module_name = nil
+            else
+              java_match = unparsed_line.match(JAVA_INPUT_FORMAT)
+              _, module_name, method, file, number = java_match.to_a
+            end
+            [file, number, method, module_name]
+          end
+
           def strip_load_path path
+            return '' unless path
             prefix = $:
               .map(&:to_s)
               .select { |s| path.start_with?(s) }

Then the errors get quenched at least, but the new module_name parsed Java metadata remains unused.

@olleolleolle
Copy link
Contributor Author

olleolleolle commented Feb 20, 2017

@mikker The older Rubies run first. Isn't that a little irritating? Or is it best?

@olleolleolle
Copy link
Contributor Author

olleolleolle commented Feb 20, 2017

@mikker I need to push a JRuby test into the Travis matrix. I'll try to get just a single one in there.

(And, I added it last, too. Ugh.)

@mikker
Copy link
Collaborator

mikker commented Jun 15, 2017

Apparently Sidekiq 5 can't do Ruby < 2.2.

@olleolleolle
Copy link
Contributor Author

@mikker: (Hi! Yes, this got me going on this path. 2.1 is EOL'd. Can we stop supporting < 2.2?)

@mikker
Copy link
Collaborator

mikker commented Jun 15, 2017

We probably could. Can we get away with just freezing Sidekiq to be <5 in ruby 2.2 Gemfiles?

@olleolleolle
Copy link
Contributor Author

@mikker Sure can start there.

gem 'sidekiq', require: false
# Freeze Sidekiq to < 5 in Ruby 2.2 Gemfiles
if RUBY_VERSION >= '2'
gem 'sidekiq', (RUBY_VERSION >= '2.2.2' ? '~> 5' : '~> 4'), require: false
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

A beautiful line of code 😆 👍🏼

Copy link
Contributor Author

@olleolleolle olleolleolle Jun 15, 2017

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Reminds us of the game "inte nudda golvet", "gulv brænder" etc.

Avoiiiiid the warnings.

@olleolleolle
Copy link
Contributor Author

@mikker In any event, whether or not this JRuby stacktrace feature can be implemented, the build improvements in this PR could be extracted to their own PR.

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Projects
None yet
Development

Successfully merging this pull request may close these issues.

2 participants