Occasional ArrayIndexOutOfBoundsException from a line of Ruby that isn't doing array lookups #3729

hakanai · 2016-03-14T05:26:35Z

Environment

JRuby: JRuby 9.0.5.0
OS: OSX 10.11.1

We don't set JRUBY_OPTS. For a change we're running this using the command-line instead of embedding it. We're basically firing up rspec as part of functional testing. None of our command-line options are for changing behaviour in JRuby, other than deliberately setting file.encoding=UTF-8 for the benefit of Windows, which is not relevant for this run here as I'm on OSX.

Gems: rspec-core, rspec-mocks, ci-reporter.

Other environment variables of Ruby relevance:

RBENV_ROOT=/Users/tester/DevEnv/rbenv
RBENV_SHELL=bash

rbenv is indeed present, although we are not using it when running the tests - the tests run by <java classname="org.jruby.Main"> from an Ant task.

Expected Behaviour

I have a spec written as follows:

it 'notifies the callback of each result' do
  callback = double(:callback)
  expect(callback).to receive(:found).exactly(24).times
  @thing.search('mime-type:message/rfc822', callback)
end

Of note, this Thing#search method internally performs work in a thread pool, so the callback gets called from multiple threads, possibly all simultaneously. So the issue I'm about to describe could be a thread safety bug.

Of course I expect this test to pass. ;)

(But due to other circumstances, the test fails about half the time, because this search method ultimately calls the callback on multiple threads and rspec-mocks is not thread-safe. That's another issue and not what I'm reporting here.)

Actual Behaviour

Occasionally (1 per 20 runs or so, based on today's runs), I get this failure instead:

 [java] Failures:
 [java] 
 [java]   1) Thing#search when a callback is provided notifies the callback of each result
 [java]      Failure/Error: Unable to find org.jruby.RubyArray.map(org/jruby/RubyArray.java to read failed line
 [java] 
 [java]      Java::JavaLang::ArrayIndexOutOfBoundsException:
 [java]        7
 [java]      # org.jruby.RubyArray.map(org/jruby/RubyArray.java:2300)
 [java]      # RUBY.(root)(/path/to/project/functional-tests/src/test/rspec/lib/case/search_unsorted_spec.rb:42)
 [java]      # RUBY.run(uri:classloader:/gems/rspec-core-3.4.3/lib/rspec/core/example.rb:236)
 [java]      # RUBY.with_around_and_singleton_context_hooks(uri:classloader:/gems/rspec-core-3.4.3/lib/rspec/core/example.rb:478)
 [java]      # RUBY.block in with_around_example_hooks(uri:classloader:/gems/rspec-core-3.4.3/lib/rspec/core/example.rb:435)
  ...

Line 42 is this one:

      @thing.search('mime-type:message/rfc822', callback)

No call to Array#map on that line, no array lookups either, no idea what is going on.

The text was updated successfully, but these errors were encountered:

kares · 2016-03-14T07:19:32Z

its likely to be at thread-safety issue - this kind of failures (usually) happens when an array instance is being accessed concurrently.

jmettraux · 2016-12-22T11:55:56Z

I'm facing the same intermittent issue. It would be nice if the actual point in the Ruby (not Java) code would be indicated. That would help fix the issue in your code.

Here's what JRuby tells me: https://gist.github.com/jmettraux/91e04143828e22259aa06390ad7a1d28 not a single pointer to my code.

Context:

$ java -Xmx32m -version
java version "1.7.0_76"
Java(TM) SE Runtime Environment (build 1.7.0_76-b13)
Java HotSpot(TM) 64-Bit Server VM (build 24.76-b04, mixed mode)
$ javac -J-Xmx32m -version
javac 1.7.0_76
$ ruby --version
jruby 1.7.19 (1.9.3p551) 2015-02-05 32f5af0 on Java HotSpot(TM) 64-Bit Server VM 1.7.0_76-b13 +jit [linux-amd64]

Thanks for JRuby.

kares · 2016-12-23T05:13:59Z

@jmettraux haven't looked, but could you please confirm its there in the latest of JRuby 1.7 (1.7.26 atm)

jmettraux · 2016-12-23T05:22:31Z

@kares OK, give me some time to gather the info.

jmettraux · 2016-12-23T06:02:22Z

@kares I made a testbed at https://github.com/jmettraux/jruby-gh3729

It happens on the main thread.

When happening in another thread, there is a useful indication like:

Exception in thread "Ruby-0-Thread-15: test.rb:10" 200Exception in thread "Ruby-0-Thread-17: test.rb:10"

No such info when on the main thread (see below).

The code looks like ( https://github.com/jmettraux/jruby-gh3729/blob/master/test.rb ):

a = []

Thread.new do
  loop do
    a << Time.now.to_f
  end
end

1000.times do
  p a.collect { |f| f.to_i }.size
end

sample output ( https://github.com/jmettraux/jruby-gh3729/blob/master/sample-output.txt ):

jruby --dev -G test.rb

jruby 1.7.26 (1.9.3p551) 2016-08-26 69763b8 on Java HotSpot(TM) 64-Bit Server VM 1.8.0_60-b27 [darwin-x86_64]

java version "1.8.0_60"
Java(TM) SE Runtime Environment (build 1.8.0_60-b27)
Java HotSpot(TM) 64-Bit Server VM (build 25.60-b23, mixed mode)

0
0
0
0
0
0
0
RubyArray.java:2400:in `collect': java.lang.ArrayIndexOutOfBoundsException: 2
	from RubyArray.java:2409:in `collect19'
	from RubyArray$INVOKER$i$0$0$collect19.gen:-1:in `call'
	from CachingCallSite.java:143:in `callBlock'
	from CachingCallSite.java:154:in `callIter'
	from CallNoArgBlockNode.java:64:in `interpret'
	from CallNoArgNode.java:60:in `interpret'
	from FCallOneArgNode.java:36:in `interpret'
	from NewlineNode.java:105:in `interpret'
	from ASTInterpreter.java:112:in `INTERPRET_BLOCK'
	from Interpreted19Block.java:206:in `evalBlockBody'
	from Interpreted19Block.java:157:in `yield'
	from Interpreted19Block.java:130:in `yieldSpecific'
	from Block.java:111:in `yieldSpecific'
	from RubyFixnum.java:275:in `times'
	from RubyFixnum$INVOKER$i$0$0$times.gen:-1:in `call'
	from CachingCallSite.java:316:in `cacheAndCall'
	from CachingCallSite.java:145:in `callBlock'
	from CachingCallSite.java:154:in `callIter'
	from CallNoArgBlockNode.java:64:in `interpret'
	from NewlineNode.java:105:in `interpret'
	from BlockNode.java:71:in `interpret'
	from RootNode.java:129:in `interpret'
	from ASTInterpreter.java:121:in `INTERPRET_ROOT'
	from Ruby.java:884:in `runInterpreter'
	from Ruby.java:892:in `runInterpreter'
	from Ruby.java:733:in `runNormally'
	from Ruby.java:578:in `runFromMain'
	from Main.java:393:in `doRunFromMain'
	from Main.java:288:in `internalRun'
	from Main.java:217:in `run'
	from Main.java:197:in `main'
make: *** [test] Error 1

Seen on JRuby 1.7.19 and 1.7.26

kares · 2016-12-23T09:13:34Z

@jmettraux aah so its the same concurrency issue -> JRuby's Array should raise ConcurrencyError here
-> just like it does elsewhere. but that won't indicate the problematic .rb line (from the other thread)

but collect should get improved, thanks for the reminder (not sure it will happen on 1.7.x due EOL)

jmettraux · 2016-12-23T09:14:35Z

Keep up the great work guys!

see jruby#3729

see #3729

hakanai mentioned this issue Mar 14, 2016

"could not coerce Fixnum to interface java.util.Set" from code that isn't dealing with sets #3730

Closed

kares added concurrency JRuby 1.7.x JRuby 9000 labels Dec 23, 2016

kares added a commit to kares/jruby that referenced this issue Dec 30, 2016

raise ConcurrencyError on thread-safety issue from Array#collect

1d2f3d8

see jruby#3729

kares added a commit that referenced this issue Dec 30, 2016

[test] concurrency test-case for Array#collect (resolving #3729)

70fdee6

kares closed this as completed Dec 30, 2016

kares added this to the JRuby 9.1.7.0 milestone Dec 30, 2016

kares added a commit to kares/jruby that referenced this issue Dec 30, 2016

raise ConcurrencyError on thread-safety issue from Array#collect

b6b31e8

see jruby#3729

kares added a commit that referenced this issue Dec 30, 2016

raise ConcurrencyError on thread-safety issue from Array#collect

bfa5cad

see #3729

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Occasional ArrayIndexOutOfBoundsException from a line of Ruby that isn't doing array lookups #3729

Occasional ArrayIndexOutOfBoundsException from a line of Ruby that isn't doing array lookups #3729

hakanai commented Mar 14, 2016

kares commented Mar 14, 2016

jmettraux commented Dec 22, 2016

kares commented Dec 23, 2016

jmettraux commented Dec 23, 2016

jmettraux commented Dec 23, 2016

kares commented Dec 23, 2016

jmettraux commented Dec 23, 2016

Occasional ArrayIndexOutOfBoundsException from a line of Ruby that isn't doing array lookups #3729

Occasional ArrayIndexOutOfBoundsException from a line of Ruby that isn't doing array lookups #3729

Comments

hakanai commented Mar 14, 2016

Environment

Expected Behaviour

Actual Behaviour

kares commented Mar 14, 2016

jmettraux commented Dec 22, 2016

kares commented Dec 23, 2016

jmettraux commented Dec 23, 2016

jmettraux commented Dec 23, 2016

kares commented Dec 23, 2016

jmettraux commented Dec 23, 2016