New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Bundler fails under +indy (claims gems listed more than once) #3950

Closed
billdueber opened this Issue Jun 2, 2016 · 7 comments

Comments

Projects
None yet
4 participants
@billdueber

billdueber commented Jun 2, 2016

Environment

  • jruby 9.1.2.0 (2.3.0) 2016-05-26 7357c8f OpenJDK 64-Bit Server VM 25.91-b14 on 1.8.0_91-8u91-b14-1~bpo8+1-b14 +indy +jit [linux-x86_64]
  • SMP Debian 3.16.7-ckt25-2 (2016-04-08) x86_64 GNU/Linux

Expected Behavior

To work identically to the (not at all problematic) behavior without +indy

Actual Behavior

Dumps the following:

/htsolr/catalog-dev/bin/ht_traject (s6)> export JRUBY_OPTS='-Xcompile.invokedynamic=true'
/htsolr/catalog-dev/bin/ht_traject (s6)> bundle install
Your Gemfile lists the gem rake (>= 0) more than once.
You should probably keep only one of them.
While it's not a problem now, it could cause errors if you change the version of just one of them later.
Your Gemfile lists the gem bundler (>= 0) more than once.
You should probably keep only one of them.
While it's not a problem now, it could cause errors if you change the version of just one of them later.
Fetching gem metadata from https://rubygems.org/
Fetching version metadata from https://rubygems.org/
Fetching version metadata from https://rubygems.org/--- ERROR REPORT TEMPLATE -------------------------------------------------------
- What did you do?

  I ran the command `/htsolr/catalog-dev/bin/jruby/bin/bundle install`

- What did you expect to happen?

  I expected Bundler to...

- What happened instead?

  Instead, what actually happened was...


Error details

    NoMethodError: undefined method `map' for nil:NilClass
      /htsolr/catalog-dev/bin/jruby-9.1.2.0/lib/ruby/gems/shared/gems/bundler-1.12.5/lib/bundler/index.rb:112:in `block in dependency_names'
      org/jruby/RubyArray.java:1593:in `each'
      /htsolr/catalog-dev/bin/jruby-9.1.2.0/lib/ruby/gems/shared/gems/bundler-1.12.5/lib/bundler/index.rb:99:in `block in each'
      org/jruby/RubyArray.java:1593:in `each'
      /htsolr/catalog-dev/bin/jruby-9.1.2.0/lib/ruby/gems/shared/gems/bundler-1.12.5/lib/bundler/index.rb:98:in `each'
      /htsolr/catalog-dev/bin/jruby-9.1.2.0/lib/ruby/gems/shared/gems/bundler-1.12.5/lib/bundler/index.rb:112:in `dependency_names'
      /htsolr/catalog-dev/bin/jruby-9.1.2.0/lib/ruby/gems/shared/gems/bundler-1.12.5/lib/bundler/source/rubygems.rb:367:in `block in remote_specs'
      org/jruby/RubyArray.java:1593:in `each'
      /htsolr/catalog-dev/bin/jruby-9.1.2.0/lib/ruby/gems/shared/gems/bundler-1.12.5/lib/bundler/source/rubygems.rb:365:in `block in remote_specs'
      org/jruby/RubyKernel.java:1290:in `loop'
      /htsolr/catalog-dev/bin/jruby-9.1.2.0/lib/ruby/gems/shared/gems/bundler-1.12.5/lib/bundler/source/rubygems.rb:363:in `block in remote_specs'
      /htsolr/catalog-dev/bin/jruby-9.1.2.0/lib/ruby/gems/shared/gems/bundler-1.12.5/lib/bundler/index.rb:10:in `build'
      /htsolr/catalog-dev/bin/jruby-9.1.2.0/lib/ruby/gems/shared/gems/bundler-1.12.5/lib/bundler/source/rubygems.rb:335:in `remote_specs'
      /htsolr/catalog-dev/bin/jruby-9.1.2.0/lib/ruby/gems/shared/gems/bundler-1.12.5/lib/bundler/source/rubygems.rb:82:in `specs'
      /htsolr/catalog-dev/bin/jruby-9.1.2.0/lib/ruby/gems/shared/gems/bundler-1.12.5/lib/bundler/definition.rb:211:in `block in index'
      org/jruby/RubyArray.java:1593:in `each'
      /htsolr/catalog-dev/bin/jruby-9.1.2.0/lib/ruby/gems/shared/gems/bundler-1.12.5/lib/bundler/definition.rb:209:in `block in index'
      /htsolr/catalog-dev/bin/jruby-9.1.2.0/lib/ruby/gems/shared/gems/bundler-1.12.5/lib/bundler/index.rb:10:in `build'
      /htsolr/catalog-dev/bin/jruby-9.1.2.0/lib/ruby/gems/shared/gems/bundler-1.12.5/lib/bundler/definition.rb:206:in `index'
      /htsolr/catalog-dev/bin/jruby-9.1.2.0/lib/ruby/gems/shared/gems/bundler-1.12.5/lib/bundler/definition.rb:200:in `resolve'
      /htsolr/catalog-dev/bin/jruby-9.1.2.0/lib/ruby/gems/shared/gems/bundler-1.12.5/lib/bundler/definition.rb:140:in `specs'
      /htsolr/catalog-dev/bin/jruby-9.1.2.0/lib/ruby/gems/shared/gems/bundler-1.12.5/lib/bundler/definition.rb:129:in `resolve_remotely!'
      /htsolr/catalog-dev/bin/jruby-9.1.2.0/lib/ruby/gems/shared/gems/bundler-1.12.5/lib/bundler/installer.rb:195:in `resolve_if_need'
      /htsolr/catalog-dev/bin/jruby-9.1.2.0/lib/ruby/gems/shared/gems/bundler-1.12.5/lib/bundler/installer.rb:70:in `run'
      /htsolr/catalog-dev/bin/jruby-9.1.2.0/lib/ruby/gems/shared/gems/bundler-1.12.5/lib/bundler/installer.rb:22:in `install'
      /htsolr/catalog-dev/bin/jruby-9.1.2.0/lib/ruby/gems/shared/gems/bundler-1.12.5/lib/bundler/cli/install.rb:102:in `run'
      /htsolr/catalog-dev/bin/jruby-9.1.2.0/lib/ruby/gems/shared/gems/bundler-1.12.5/lib/bundler/cli.rb:175:in `install'
      /htsolr/catalog-dev/bin/jruby-9.1.2.0/lib/ruby/gems/shared/gems/bundler-1.12.5/lib/bundler/vendor/thor/lib/thor/command.rb:27:in `run'
      /htsolr/catalog-dev/bin/jruby-9.1.2.0/lib/ruby/gems/shared/gems/bundler-1.12.5/lib/bundler/vendor/thor/lib/thor/invocation.rb:126:in `invoke_command'
      /htsolr/catalog-dev/bin/jruby-9.1.2.0/lib/ruby/gems/shared/gems/bundler-1.12.5/lib/bundler/vendor/thor/lib/thor.rb:359:in `dispatch'
      /htsolr/catalog-dev/bin/jruby-9.1.2.0/lib/ruby/gems/shared/gems/bundler-1.12.5/lib/bundler/vendor/thor/lib/thor/base.rb:440:in `start'
      /htsolr/catalog-dev/bin/jruby-9.1.2.0/lib/ruby/gems/shared/gems/bundler-1.12.5/lib/bundler/cli.rb:11:in `start'
      /htsolr/catalog-dev/bin/jruby-9.1.2.0/lib/ruby/gems/shared/gems/bundler-1.12.5/exe/bundle:27:in `block in (root)'
      /htsolr/catalog-dev/bin/jruby-9.1.2.0/lib/ruby/gems/shared/gems/bundler-1.12.5/lib/bundler/friendly_errors.rb:98:in `with_friendly_errors'
      /htsolr/catalog-dev/bin/jruby-9.1.2.0/lib/ruby/gems/shared/gems/bundler-1.12.5/exe/bundle:19:in `<top>'
      org/jruby/RubyKernel.java:962:in `load'
      /htsolr/catalog-dev/bin/jruby/bin/bundle:22:in `<top>'

Environment

  Bundler   1.12.5
  Rubygems  2.6.4
  Ruby      2.3.0p0 (2016-05-26 revision 52539) [java]
  GEM_HOME  /htsolr/catalog-dev/bin/jruby-9.1.2.0/lib/ruby/gems/shared
  GEM_PATH  /htsolr/catalog-dev/bin/jruby-9.1.2.0/lib/ruby/gems/shared:/afs/umich.edu/user/d/u/dueberb/.gem/jruby/2.3.0
  Git       2.1.4

      Bundler settings

  orig_path
    Set via BUNDLE_ORIG_PATH: "/usr/lib/jvm/java-8-openjdk-amd64/bin:/htsolr/catalog-dev/bin/jruby/bin:/htapps/dueberb.babel/mdp-tools/scripts:/htsolr/catalog/bin/jruby/bin:/datamart/bin:/l/local/fits:/l/local/bin:/usr/kerberos/bin:/l/local/java/bin:/usr/java/bin:/l/local/rbenv/shims:/l/local/rbenv/bin:/l/local/rbenv/shims:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games:/afs/umich.edu/user/d/u/dueberb/bin:/l/local/git/bin"
--- TEMPLATE END ----------------------------------------------------------------

Unfortunately, an unexpected error occurred, and Bundler cannot continue.

First, try this link to see if there are any existing issue reports for this error:
https://github.com/bundler/bundler/search?q=undefined+method+%60map%27+for+nil%3ANilClass&type=Issues

If there aren't any reports for this error yet, please create copy and paste the report template above into a new issue. Don't forget to anonymize any private data! The new issue form is located at:
https://github.com/bundler/bundler/issues/new

@enebo enebo added this to the JRuby 9.1.3.0 milestone Jun 2, 2016

@abiacco

This comment has been minimized.

Show comment
Hide comment
@abiacco

abiacco Jun 18, 2016

This is likely the same issue I posted to bundler about a month ago
bundler/bundler#4587

abiacco commented Jun 18, 2016

This is likely the same issue I posted to bundler about a month ago
bundler/bundler#4587

@headius

This comment has been minimized.

Show comment
Hide comment
@headius

headius Aug 12, 2016

Member

Success! I have reproduced this on my machine.

Member

headius commented Aug 12, 2016

Success! I have reproduced this on my machine.

@headius

This comment has been minimized.

Show comment
Hide comment
@headius

headius Aug 12, 2016

Member

It seems like under indy, there's a bogus specification in Bundler:

"rails-3.2.5"=>#<Bundler::EndpointSpecification:0xbe2 rails-3.2.5>, "-"=>#<Bundler::EndpointSpecification:0xbe4 ->

I'm trying to figure out where these are constructed.

Member

headius commented Aug 12, 2016

It seems like under indy, there's a bogus specification in Bundler:

"rails-3.2.5"=>#<Bundler::EndpointSpecification:0xbe2 rails-3.2.5>, "-"=>#<Bundler::EndpointSpecification:0xbe4 ->

I'm trying to figure out where these are constructed.

@headius

This comment has been minimized.

Show comment
Hide comment
@headius

headius Aug 12, 2016

Member

Whew, finally got it. Seems to be a problem with reified instance variables. For some reason, the attr_accessor-defined variables in Gem::Specification are not getting set or read properly. If you pass -Xreify.variables=false to JRuby it should work ok (so there's your workaround for the moment).

I'll get it patched up for 9.1.3.0.

Member

headius commented Aug 12, 2016

Whew, finally got it. Seems to be a problem with reified instance variables. For some reason, the attr_accessor-defined variables in Gem::Specification are not getting set or read properly. If you pass -Xreify.variables=false to JRuby it should work ok (so there's your workaround for the moment).

I'll get it patched up for 9.1.3.0.

@headius

This comment has been minimized.

Show comment
Hide comment
@headius

headius Aug 12, 2016

Member

Ok, I figured out the problem.

As of 9.1.0.0 we started "reifying" up to ten instance variables per Ruby class, allocating specialized objects with up to ten fields. This reduces memory size for objects with under ten variables, since they no longer need a separate growable array to hold values.

The bug is that when a parent class reifies its variables, the child class should do so as well. In this case, Gem::Specification gets constructed and reified first. Later on, Bundler::EndpointSpecification extends it and redefines some of its attributes. Because we had no longer to also reify the child, they both end up using the 10-field object. The parent methods that access that instance variable see one offset, and the child methods see another.

This manifests when building up the EndpointSpecification objects needed by Bundler. Partway through bundling, JRuby's JIT fires. From then on, methods that access variables attempt to go directly at them, bypassing the normal dispatch mechanism. Unfortunately this means that the parent's methods accessing fields like "name" and "version" look in one place, and the child looks in another...and as a result, both end up nil, we start building bogus specifications for a gem called "-", and those bogus specifications fail to produce an array of dependencies that can be maped.

I have a fix I am testing locally that detects whether a parent class was itself reifiable, and if so it sets the child to also be reifiable. This allows all classes in the system to have their own layout of instance variables without stepping on super or subclasses.

This bug is good justification for us to finally get JIT + indy runs into CI.

Member

headius commented Aug 12, 2016

Ok, I figured out the problem.

As of 9.1.0.0 we started "reifying" up to ten instance variables per Ruby class, allocating specialized objects with up to ten fields. This reduces memory size for objects with under ten variables, since they no longer need a separate growable array to hold values.

The bug is that when a parent class reifies its variables, the child class should do so as well. In this case, Gem::Specification gets constructed and reified first. Later on, Bundler::EndpointSpecification extends it and redefines some of its attributes. Because we had no longer to also reify the child, they both end up using the 10-field object. The parent methods that access that instance variable see one offset, and the child methods see another.

This manifests when building up the EndpointSpecification objects needed by Bundler. Partway through bundling, JRuby's JIT fires. From then on, methods that access variables attempt to go directly at them, bypassing the normal dispatch mechanism. Unfortunately this means that the parent's methods accessing fields like "name" and "version" look in one place, and the child looks in another...and as a result, both end up nil, we start building bogus specifications for a gem called "-", and those bogus specifications fail to produce an array of dependencies that can be maped.

I have a fix I am testing locally that detects whether a parent class was itself reifiable, and if so it sets the child to also be reifiable. This allows all classes in the system to have their own layout of instance variables without stepping on super or subclasses.

This bug is good justification for us to finally get JIT + indy runs into CI.

@headius

This comment has been minimized.

Show comment
Hide comment
@headius

headius Aug 12, 2016

Member

I have a reproduction, finally!

class Foo
  attr_accessor :name

  def initialize(name)
    self.name = name
  end


  def full_name
    name.to_s + 'baz'
  end

end

4.times {
  p Foo.new('foo').full_name
}

puts

class Bar < Foo
  def initialize(name)
    @name = name
  end
end

4.times {
  p Bar.new('foo').full_name
}

The output follows:

[-Xcompile.invokedynamic] ~/projects/jruby $ jruby variable_repro.rb 
"foobaz"
"foobaz"
"foobaz"
"foobaz"

"foobaz"
"foobaz"
"baz"
"baz"

The Foo objects work properly every time, setting and getting the name value.

The Bar objects, on the other hand, start out ok and then starts to fail. I haven't worked out the sequence here, but in most cases the first encounter with a variable or call site will use the slow logic, and subsequent encounters will use fast logic. In this case it seems to take a couple iterations for everything to get bound to the fast logic.

I will try to turn this into a test along with my fix.

Member

headius commented Aug 12, 2016

I have a reproduction, finally!

class Foo
  attr_accessor :name

  def initialize(name)
    self.name = name
  end


  def full_name
    name.to_s + 'baz'
  end

end

4.times {
  p Foo.new('foo').full_name
}

puts

class Bar < Foo
  def initialize(name)
    @name = name
  end
end

4.times {
  p Bar.new('foo').full_name
}

The output follows:

[-Xcompile.invokedynamic] ~/projects/jruby $ jruby variable_repro.rb 
"foobaz"
"foobaz"
"foobaz"
"foobaz"

"foobaz"
"foobaz"
"baz"
"baz"

The Foo objects work properly every time, setting and getting the name value.

The Bar objects, on the other hand, start out ok and then starts to fail. I haven't worked out the sequence here, but in most cases the first encounter with a variable or call site will use the slow logic, and subsequent encounters will use fast logic. In this case it seems to take a couple iterations for everything to get bound to the fast logic.

I will try to turn this into a test along with my fix.

@headius headius closed this in e2355a3 Aug 12, 2016

@headius

This comment has been minimized.

Show comment
Hide comment
@headius

headius Aug 12, 2016

Member

I've pushed my fix and test to master, but we still need to get test:jruby:jit running with invokedynamic to really exercise this.

Member

headius commented Aug 12, 2016

I've pushed my fix and test to master, but we still need to get test:jruby:jit running with invokedynamic to really exercise this.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment