1.7.19 -- invoking UndefinedMethod.call; report at http://bugs.jruby.org

[the-michael-toy]

Going through exception logs and found this, and it says to file a bug, so I am filing a bug. Don't know how to reproduce this so I have no idea how to tell if this would be fixed in a future version. Sorry if this is a waste of your time, but I feel like you asked me to file a bug so I am trying to be helpful

jruby -v: jruby 1.7.19 (1.9.3p551) 2015-01-29 20786bd on Java HotSpot(TM) 64-Bit Server VM 1.8.0_92-b14 [darwin-x86_64]

JRUBY_OPTS: -Xss2048k -XX:+UseG1GC -XX:+UseCompressedOops -XX:+UseCompressedClassPointers -XX:MaxGCPauseMillis=1000 -XX:MaxMetaspaceSize=512m -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/tmp/ -Xms256m -Xmx1024m -Dapple.awt.UIElement=true -Djava.awt.headless=true -Djruby.cli.encoding.external=UTF-8 -Dapple.awt.UIElement=true -XX:+TieredCompilation -XX:TieredStopAtLevel=1 -Djruby.compile.mode=OFF -Djruby.compile.invokedynamic=false org/jruby/Main

The failing method looks like this:

    def self.all
      features.map{|h| new(h) }.select{|feature| feature.enabled_via_license }
    end

[the-michael-toy]

( here's the stack trace from that line ... )

Java::JavaLang::UnsupportedOperationException: BUG: invoking UndefinedMethod.call; report at http://bugs.jruby.org
  from UndefinedMethod.java:59:in `call'
  from DynamicMethod.java:210:in `call'
  from DynamicMethod.java:206:in `call'
  from CachingCallSite.java:168:in `call'
  from RespondToCallSite.java:47:in `call'
  from /tmp/jruby3829850646626032269extract/jruby-stdlib-1.7.19.jar!/META-INF/jruby.home/lib/ruby/1.9/ostruct.rb:156:in `__file__'
  from JittedMethod.java:181:in `call'
  from CachingCallSite.java:326:in `cacheAndCall'
  from CachingCallSite.java:170:in `call'
  from /tmp/jruby3829850646626032269extract/jruby-stdlib-1.7.19.jar!/META-INF/jruby.home/lib/ruby/1.9/ostruct.rb:91:in `block_0$RUBY$__for__'
  from CompiledBlock.java:112:in `yield'
  from CompiledBlock.java:95:in `yield'
  from Block.java:142:in `yield'
  from RubyHash.java:1354:in `visit'
  from RubyHash.java:648:in `visitLimited'
  from RubyHash.java:634:in `visitAll'
  from RubyHash.java:1305:in `iteratorVisitAll'
  from RubyHash.java:1350:in `each_pairCommon'
  from RubyHash.java:1341:in `each19'
  from CachingCallSite.java:143:in `callBlock'
  from CachingCallSite.java:154:in `callIter'
  from /tmp/jruby3829850646626032269extract/jruby-stdlib-1.7.19.jar!/META-INF/jruby.home/lib/ruby/1.9/ostruct.rb:89:in `__file__'
  from AbstractScript.java:42:in `__file__'
  from JittedMethod.java:201:in `call'
  from CachingCallSite.java:177:in `callBlock'
  from CachingCallSite.java:183:in `call'
  from RubyClass.java:856:in `newInstance'
  from JavaMethod.java:297:in `call'
  from CachingCallSite.java:168:in `call'
  from lib/helltool/models/legacy_feature.rb:89:in `block_4$RUBY$all'
  from CompiledBlock19.java:135:in `yield'
  from Block.java:142:in `yield'
  from RubyArray.java:2399:in `collect'
  from RubyArray.java:2412:in `map19'
  from CachingCallSite.java:143:in `callBlock'
  from CachingCallSite.java:154:in `callIter'
  from lib/helltool/models/legacy_feature.rb:89:in `method__3$RUBY$all'

[headius]

Thanks for reporting this! Are you able to try JRuby 1.7.25 and see if it still comes up? I understand you can't reproduce it easily, but a lot of fixes happened between 1.7.19 and 1.7.29.

We are also hoping to do a 1.7.26 release next week, so if there's a bug here we really want to fix it.

[headius]

Marking for 1.7.26 but if we can't reproduce easily it will get bumped.

[the-michael-toy]

This has happened 18 times, on our hundreds of running instances, between May 2016 and now, so it is rare. We will be rolling JRuby forwards at some point soon, maybe if we roll forward and the incidents vanish we could guess it was fixed, but I don't exactly know what sequence of operations causes this. I could bracket this code with a rescue for this error and try to capture more of that state.

Looking at the 18 incidents to see if there is anything I can glean ...

... I see it happens on both Java 7 and Java 8.

... We've been running 1.7.19 since may of 2015 (except for one month in early 2016 1.7.23 got rolled out and then back, don't know why).

I'll let you know if I find anything else out. Sorry I can't be more helpful.

[headius]

I will see what I can figured out on my end too. Your trace does say it happens in ostruct.rb, so perhaps I can see if there's a problem just by staring at the code.

[headius]

Hmm...so far no luck. There's very few ways this could happen, and I'm not seeing any of them that seems likely.

[headius]

@the-michael-toy The only determination I've come to is that we might need a better piece of code for RespondToCallSite. I still cannot reproduce or find an explanation for why you see these errors.

If any of the incidents you have see comes with a different backtrace, please provide that. I had hope I'd see something obvious by digging around in ostruct.rb but unfortunately I did not.

If possible, you should try 1.7.25 as well. It may be that the bug you're seeing was fixed through other means.

[the-michael-toy]

I tried 1.7.25, but something weird happens that also happened with 1.7.23 which is why we are still running 1.7.19. (something odd with File.stat on a jar path which is a directory, believing the object is a file). So I can't deploy a 1.7.25 version and the error is infrequent enough that I won't see it unless I deploy it.

Rather than attempt to work around the 1.7.25 problem, because I was realizing it was going to be a fair bit of work to get 1.7.25 running, I decided it was smarter to put that fair bit of work towards moving to 9K instead especially in light of #4112.

All that to say, I think we are moving on, and unlikely to have more info on this bug. At this point the 9K version works, and doesn't have the weird file path issue. It doesn't work well enough to deploy yet, so no clue if our use of OpenStruct is still problematic for 9K.

[headius]

something odd with File.stat on a jar path which is a directory, believing the object is a file

Usually our special jar/classpath/classloader URLs get special-cased in the various File methods. This may just be a missed case. If you can report something we can reproduce, it would be super great :-)

I decided it was smarter to put that fair bit of work towards moving to 9K

Good to hear that 9k is working like you expected 1.7.25 to work for these cases!

Given the road map for 1.7 I will close this as Won't Fix for now, since we can't reproduce and 9k does not have the same issue.

Please keep us posted on your progress getting 9k up and running. We are standing by to support folks trying to migrate and deal with issues that come up.