Posible compilation issue #2954

pitr-ch · 2015-05-18T12:13:24Z

I've recently hit very strange JRuby behavior when developing new synchronization layer in concurrent-ruby in PR ruby-concurrency/concurrent-ruby#273 (comment).

The code seems to be working fine until it's compiled then it breaks. When while true is replaced with loop do it starts to work.

Following change is enough to break it, see pitr-ch/concurrent-ruby@c306a67 It fails on JRuby 1.7.19,20

Steps to reproduce:

pull pitr-ch/concurrent-ruby@c306a67
bundle update
bundle exec rspec spec/concurrent/atomic/cyclic_barrier_spec.rb
JRUBY_OPTS="-J-Djruby.jit.threshold=1 -J-Djruby.compile.mode=JIT" bundle exec rspec spec/concurrent/atomic/cyclic_barrier_spec.rb fails
JRUBY_OPTS="-J-Djruby.compile.mode=OFF" bundle exec rspec spec/concurrent/atomic/cyclic_barrier_spec.rb works

It looks like the body of the CyclicBarrier#wait method is skipped breaking the internal state of CyclicBarrier.

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

headius · 2015-05-28T22:57:18Z

Nice, it sounds like an obvious JIT issue. Can you check if it's fixed on master?

pitr-ch · 2015-06-01T09:01:29Z

Yeah it works in master (e29bc9a).

headius · 2015-08-17T18:41:31Z

Looking into this now.

headius · 2015-08-17T19:11:54Z

Well I was not able to reproduce so far. I get a different error regardless of command-line params:

NotImplementedError: NotImplementedError
  ensure_ivar_visibility! at /Users/headius/projects/concurrent-ruby/lib/concurrent/synchronization/abstract_object.rb:144
               initialize at /Users/headius/projects/concurrent-ruby/lib/concurrent/utility/monotonic_time.rb:9
               Concurrent at /Users/headius/projects/concurrent-ruby/lib/concurrent/utility/monotonic_time.rb:42
                   (root) at /Users/headius/projects/concurrent-ruby/lib/concurrent/utility/monotonic_time.rb:3
                  require at org/jruby/RubyKernel.java:1040
                   (root) at /Users/headius/projects/concurrent-ruby/lib/concurrent/atomic/condition.rb:1
                  require at org/jruby/RubyKernel.java:1040
                   (root) at /Users/headius/projects/concurrent-ruby/lib/concurrent/atomic/condition.rb:1
                  require at org/jruby/RubyKernel.java:1040
                   (root) at /Users/headius/projects/concurrent-ruby/lib/concurrent/atomics.rb:1
                  require at org/jruby/RubyKernel.java:1040
                   (root) at /Users/headius/projects/concurrent-ruby/lib/concurrent/atomics.rb:43
                  require at org/jruby/RubyKernel.java:1040
                   (root) at /Users/headius/projects/concurrent-ruby/lib/concurrent/configuration.rb:1
                  require at org/jruby/RubyKernel.java:1040
                   (root) at /Users/headius/projects/concurrent-ruby/lib/concurrent/configuration.rb:2
                     each at org/jruby/RubyArray.java:1613
                   (root) at /Users/headius/projects/concurrent-ruby/lib/concurrent.rb:1
                   (root) at /Users/headius/projects/concurrent-ruby/lib/concurrent.rb:6
                     each at org/jruby/RubyArray.java:1613
                   (root) at /Users/headius/projects/concurrent-ruby/spec/spec_helper.rb:1
                   (root) at /Users/headius/projects/concurrent-ruby/spec/spec_helper.rb:23
                   (root) at /Users/headius/projects/jruby-1.7/lib/ruby/gems/shared/gems/rspec-core-3.2.3/lib/rspec/core/configuration.rb:1
                requires= at /Users/headius/projects/jruby-1.7/lib/ruby/gems/shared/gems/rspec-core-3.2.3/lib/rspec/core/configuration.rb:1181
                requires= at /Users/headius/projects/jruby-1.7/lib/ruby/gems/shared/gems/rspec-core-3.2.3/lib/rspec/core/configuration.rb:1181
     process_options_into at /Users/headius/projects/jruby-1.7/lib/ruby/gems/shared/gems/rspec-core-3.2.3/lib/rspec/core/configuration_options.rb:110
     process_options_into at /Users/headius/projects/jruby-1.7/lib/ruby/gems/shared/gems/rspec-core-3.2.3/lib/rspec/core/configuration_options.rb:109
                     load at org/jruby/RubyKernel.java:1059
                   (root) at /Users/headius/projects/jruby-1.7/bin/rspec:23

I did not see anything obviously wrong by reading the bytecode, but I'm also not quite sure what I'm looking for.

You say that it appears that the body of the CyclicBarrier#wait method does not appear to be called. Do you mean the ns_wait call after the early return? In other words, is the early return always firing? That would indicate a problem in how we compile that return logic.

I need your assistance to reproduce this on 1.7. Very much want to fix.

pitr-ch · 2015-08-19T17:25:15Z

@headius Ah sorry I forgot to add step bundle exec rake compile after bundle update. It's missing compiled jar. After this fix I still get the error.

pitr-ch · 2015-08-19T17:35:08Z

When it enters ns_wait_until method here https://github.com/pitr-ch/concurrent-ruby/blob/bug/lib/concurrent/atomic/cyclic_barrier.rb#L56-56, the return inside this method (wrapped by while true) is not returning on linked line but from the CyclicBarrier#wait method. After it's compiled the error happens consistently. I hope it helps. (Sorry for response delay.)

headius · 2016-01-16T00:10:27Z

Reproduced finally.

headius · 2016-01-16T02:06:08Z

I believe I have a trivial reproduction:

def foo(&a)
  while true
    return 1
  end
end
p foo

This will not output anything because the return triggers a return "jump exception and bubbles all the way out of the script.

This behavior is triggered by having a while loop and a block capture argument (the &a). For reasons I have not determined, I set up the compiler to deoptimize while loops in the presence of a captured block to always use a "safe" form that rescues nonlocal jumps like breaks and next. Unfortunately, that safe version does not appear to be handling the return jump properly.

I think this may have been a mistake about nonlocal flow control in the past; specifically, I think I may have believed at the time that if the block contained a "break" or "next", those should jump based on the the loop within which the block was called. This is not the case.

$ ruby23 -e "def foo(&a); while true; a.call; p 1; end; p 2; end; foo { break }; p 3"
3

Here we see that the non-local break inside the foo call does not break ou tof the while loop, but actually breaks all the way out of the foo method. This does not require any special handling in the while loop.

I will try removing this behavior, run some tests, and also try to figure out if I had any other reason for doing this.

headius · 2016-01-16T02:34:07Z

Well the only case I could find that breaks when I change this is a test case that never actually tested what we thought it did:

[] ~/projects/jruby-1.7 $ rvm ruby-1.8.7-p374 do ruby -e "def foo(&b); while true; b.call; p 1; end; p 2; end; p foo { eval 'break 3' }"
3

[] ~/projects/jruby-1.7 $ jruby -e "def foo(&b); while true; b.call; p 1; end; p 2; end; p foo { eval 'break 3' }"
LocalJumpError: unexpected break
    eval at org/jruby/RubyKernel.java:1079
  (root) at -e:1
    call at org/jruby/RubyProc.java:281
     foo at -e:1
  (root) at -e:1

[] ~/projects/jruby-1.7 $ ruby23 -e "def foo(&b); while true; b.call; end; end; foo { eval 'break 3' }"
-e:1:in `eval': (eval):1: Can't escape from eval with break (SyntaxError)

In 1.8.7, the break from the eval bubbles out and eventually breaks from the foo call; not from the while. In Ruby 1.9+, eval no longer is allowed to contain loose breaks like this, and with my change both 1.8 and 1.9 modes raise this error.

If I leave the code as is, we still don't behave like 1.8.7, and the break breaks out of the loop instead of out of foo:

$ jruby --1.8 -e "def foo(&b); while true; b.call; p 1; end; p 2; end; p foo { eval 'break 3' }"
2
nil

Since doing a loose break in an eval has never really been approved behavior, and it is officially an error in 1.9.3+, I'm going to remove this logic.

Fixes #2954. See discussion for details on this change.

headius · 2016-01-16T02:44:12Z

Ok, this is fixed, and the specs run fine with jit.threshold=0.

@enebo I know you may be concerned about this change, so we'll talk about whether we want to roll it into a 1.7.25 after we see how travis looks. Unfortunately 1.7 travis does not run a lot of JIT tests, but I feel pretty good about this change, especially given that it was very broken before.

headius added jit JRuby 1.7.x labels May 28, 2015

headius added this to the JRuby 1.7.21 milestone May 28, 2015

enebo modified the milestones: JRuby 1.7.21, JRuby 1.7.22 Jul 7, 2015

headius added the feedback needed label Aug 17, 2015

enebo modified the milestones: JRuby 1.7.22, JRuby 1.7.23 Aug 20, 2015

enebo modified the milestones: JRuby 1.7.23, JRuby 1.7.24 Nov 24, 2015

kares removed the feedback needed label Dec 18, 2015

headius added a commit that referenced this issue Jan 16, 2016

Don't deoptimize while loops just because of a block arg.

c40bfa8

Fixes #2954. See discussion for details on this change.

headius closed this as completed Jan 16, 2016

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Posible compilation issue #2954

Posible compilation issue #2954

pitr-ch commented May 18, 2015

headius commented May 28, 2015

pitr-ch commented Jun 1, 2015

headius commented Aug 17, 2015

headius commented Aug 17, 2015

pitr-ch commented Aug 19, 2015

pitr-ch commented Aug 19, 2015

headius commented Jan 16, 2016

headius commented Jan 16, 2016

headius commented Jan 16, 2016

headius commented Jan 16, 2016

Posible compilation issue #2954

Posible compilation issue #2954

Comments

pitr-ch commented May 18, 2015

headius commented May 28, 2015

pitr-ch commented Jun 1, 2015

headius commented Aug 17, 2015

headius commented Aug 17, 2015

pitr-ch commented Aug 19, 2015

pitr-ch commented Aug 19, 2015

headius commented Jan 16, 2016

headius commented Jan 16, 2016

headius commented Jan 16, 2016

headius commented Jan 16, 2016