Bug #7530

Concurrent loads fail with mutex errors

Added by Charles Nutter over 2 years ago. Updated 28 days ago.

[ruby-core:50645]
Status:Closed
Priority:Normal
Assignee:Masaki Matsushita
ruby -v:ruby 2.0.0dev (2012-12-01 trunk 38126) [x86_64-darwin11.4.2] Backport:

Description

I have no idea what's going on here.

jruby-1.7.0 ~/projects/vts-jruby $ cat bench_load_path.rb 
require 'benchmark'

FAKE_PATHS = ARGV[0].to_i || 100
THREADS = 8
ITERATIONS_PER_THREAD = 1000

FAKE_PATHS.times do |i|
  $:.unshift "foo#{i}"
end

$: << '.'

system 'touch __load_path_bench_script__.rb'
puts Benchmark.measure {
  @threads = THREADS.times.map do
    Thread.new {
      ITERATIONS_PER_THREAD.times do
        require '__load_path_bench_script__'
        $".pop
      end
    }
  end
  @threads.each { |t| t.join }
}
system 'rm __load_path_bench_script__.rb'

jruby-1.7.0 ~/projects/vts-jruby $ ruby-2.0.0 -rubygems bench_load_path.rb 100
/usr/local/lib/ruby/2.0.0/rubygems/custom_require.rb:36:in `require': wrong argument type false (expected mutex) (TypeError)
    from /usr/local/lib/ruby/2.0.0/rubygems/custom_require.rb:36:in `require'
    from bench_load_path.rb:18:in `block (4 levels) in <main>'
    from bench_load_path.rb:17:in `times'
    from bench_load_path.rb:17:in `block (3 levels) in <main>'

jruby-1.7.0 ~/projects/vts-jruby $ ruby-2.0.0 --disable-gems bench_load_path.rb 100
bench_load_path.rb:18:in `require': wrong argument type false (expected mutex) (TypeError)
    from bench_load_path.rb:18:in `block (4 levels) in <main>'
    from bench_load_path.rb:17:in `times'
    from bench_load_path.rb:17:in `block (3 levels) in <main>'

With verbose on, I get this error and a bunch of circular require warnings, even though I'm not doing any circular requires here.

ruby-2.0.0-preview2 ~/projects/vts-jruby $ ruby -v bench_load_path.rb 
ruby 2.0.0dev (2012-12-01 trunk 38126) [x86_64-darwin11.4.2]
/Users/headius/.rvm/rubies/ruby-2.0.0-preview2/lib/ruby/site_ruby/2.0.0/rubygems/custom_require.rb:36: warning: loading in progress, circular require considered harmful - /Users/headius/projects/vts-jruby/__load_path_bench_script__.rb
    from bench_load_path.rb:17:in `block (3 levels) in <main>'
    from bench_load_path.rb:17:in `times'
    from bench_load_path.rb:18:in `block (4 levels) in <main>'
    from /Users/headius/.rvm/rubies/ruby-2.0.0-preview2/lib/ruby/site_ruby/2.0.0/rubygems/custom_require.rb:36:in `require'
    from /Users/headius/.rvm/rubies/ruby-2.0.0-preview2/lib/ruby/site_ruby/2.0.0/rubygems/custom_require.rb:36:in `require'
/Users/headius/.rvm/rubies/ruby-2.0.0-preview2/lib/ruby/site_ruby/2.0.0/rubygems/custom_require.rb:36: warning: loading in progress, circular require considered harmful - /Users/headius/projects/vts-jruby/__load_path_bench_script__.rb
    from bench_load_path.rb:17:in `block (3 levels) in <main>'
    from bench_load_path.rb:17:in `times'
    from bench_load_path.rb:18:in `block (4 levels) in <main>'
    from /Users/headius/.rvm/rubies/ruby-2.0.0-preview2/lib/ruby/site_ruby/2.0.0/rubygems/custom_require.rb:36:in `require'
    from /Users/headius/.rvm/rubies/ruby-2.0.0-preview2/lib/ruby/site_ruby/2.0.0/rubygems/custom_require.rb:36:in `require'
/Users/headius/.rvm/rubies/ruby-2.0.0-preview2/lib/ruby/site_ruby/2.0.0/rubygems/custom_require.rb:36: warning: loading in progress, circular require considered harmful - /Users/headius/projects/vts-jruby/__load_path_bench_script__.rb
    from bench_load_path.rb:17:in `block (3 levels) in <main>'
    from bench_load_path.rb:17:in `times'
    from bench_load_path.rb:18:in `block (4 levels) in <main>'
    from /Users/headius/.rvm/rubies/ruby-2.0.0-preview2/lib/ruby/site_ruby/2.0.0/rubygems/custom_require.rb:36:in `require'
    from /Users/headius/.rvm/rubies/ruby-2.0.0-preview2/lib/ruby/site_ruby/2.0.0/rubygems/custom_require.rb:36:in `require'
/Users/headius/.rvm/rubies/ruby-2.0.0-preview2/lib/ruby/site_ruby/2.0.0/rubygems/custom_require.rb:36: warning: loading in progress, circular require considered harmful - /Users/headius/projects/vts-jruby/__load_path_bench_script__.rb
    from bench_load_path.rb:17:in `block (3 levels) in <main>'
    from bench_load_path.rb:17:in `times'
    from bench_load_path.rb:18:in `block (4 levels) in <main>'
    from /Users/headius/.rvm/rubies/ruby-2.0.0-preview2/lib/ruby/site_ruby/2.0.0/rubygems/custom_require.rb:36:in `require'
    from /Users/headius/.rvm/rubies/ruby-2.0.0-preview2/lib/ruby/site_ruby/2.0.0/rubygems/custom_require.rb:36:in `require'
/Users/headius/.rvm/rubies/ruby-2.0.0-preview2/lib/ruby/site_ruby/2.0.0/rubygems/custom_require.rb:36: warning: loading in progress, circular require considered harmful - /Users/headius/projects/vts-jruby/__load_path_bench_script__.rb
    from bench_load_path.rb:17:in `block (3 levels) in <main>'
    from bench_load_path.rb:17:in `times'
    from bench_load_path.rb:18:in `block (4 levels) in <main>'
    from /Users/headius/.rvm/rubies/ruby-2.0.0-preview2/lib/ruby/site_ruby/2.0.0/rubygems/custom_require.rb:36:in `require'
    from /Users/headius/.rvm/rubies/ruby-2.0.0-preview2/lib/ruby/site_ruby/2.0.0/rubygems/custom_require.rb:36:in `require'
/Users/headius/.rvm/rubies/ruby-2.0.0-preview2/lib/ruby/site_ruby/2.0.0/rubygems/custom_require.rb:36: warning: loading in progress, circular require considered harmful - /Users/headius/projects/vts-jruby/__load_path_bench_script__.rb
    from bench_load_path.rb:17:in `block (3 levels) in <main>'
    from bench_load_path.rb:17:in `times'
    from bench_load_path.rb:18:in `block (4 levels) in <main>'
    from /Users/headius/.rvm/rubies/ruby-2.0.0-preview2/lib/ruby/site_ruby/2.0.0/rubygems/custom_require.rb:36:in `require'
    from /Users/headius/.rvm/rubies/ruby-2.0.0-preview2/lib/ruby/site_ruby/2.0.0/rubygems/custom_require.rb:36:in `require'
/Users/headius/.rvm/rubies/ruby-2.0.0-preview2/lib/ruby/site_ruby/2.0.0/rubygems/custom_require.rb:36: warning: loading in progress, circular require considered harmful - /Users/headius/projects/vts-jruby/__load_path_bench_script__.rb
    from bench_load_path.rb:17:in `block (3 levels) in <main>'
    from bench_load_path.rb:17:in `times'
    from bench_load_path.rb:18:in `block (4 levels) in <main>'
    from /Users/headius/.rvm/rubies/ruby-2.0.0-preview2/lib/ruby/site_ruby/2.0.0/rubygems/custom_require.rb:36:in `require'
    from /Users/headius/.rvm/rubies/ruby-2.0.0-preview2/lib/ruby/site_ruby/2.0.0/rubygems/custom_require.rb:36:in `require'
/Users/headius/.rvm/rubies/ruby-2.0.0-preview2/lib/ruby/site_ruby/2.0.0/rubygems/custom_require.rb:36: warning: loading in progress, circular require considered harmful - /Users/headius/projects/vts-jruby/__load_path_bench_script__.rb
    from bench_load_path.rb:17:in `block (3 levels) in <main>'
    from bench_load_path.rb:17:in `times'
    from bench_load_path.rb:18:in `block (4 levels) in <main>'
    from /Users/headius/.rvm/rubies/ruby-2.0.0-preview2/lib/ruby/site_ruby/2.0.0/rubygems/custom_require.rb:36:in `require'
    from /Users/headius/.rvm/rubies/ruby-2.0.0-preview2/lib/ruby/site_ruby/2.0.0/rubygems/custom_require.rb:36:in `require'
/Users/headius/.rvm/rubies/ruby-2.0.0-preview2/lib/ruby/site_ruby/2.0.0/rubygems/custom_require.rb:36: warning: loading in progress, circular require considered harmful - /Users/headius/projects/vts-jruby/__load_path_bench_script__.rb
    from bench_load_path.rb:17:in `block (3 levels) in <main>'
    from bench_load_path.rb:17:in `times'
    from bench_load_path.rb:18:in `block (4 levels) in <main>'
    from /Users/headius/.rvm/rubies/ruby-2.0.0-preview2/lib/ruby/site_ruby/2.0.0/rubygems/custom_require.rb:36:in `require'
    from /Users/headius/.rvm/rubies/ruby-2.0.0-preview2/lib/ruby/site_ruby/2.0.0/rubygems/custom_require.rb:36:in `require'
/Users/headius/.rvm/rubies/ruby-2.0.0-preview2/lib/ruby/site_ruby/2.0.0/rubygems/custom_require.rb:36: warning: loading in progress, circular require considered harmful - /Users/headius/projects/vts-jruby/__load_path_bench_script__.rb
    from bench_load_path.rb:17:in `block (3 levels) in <main>'
    from bench_load_path.rb:17:in `times'
    from bench_load_path.rb:18:in `block (4 levels) in <main>'
    from /Users/headius/.rvm/rubies/ruby-2.0.0-preview2/lib/ruby/site_ruby/2.0.0/rubygems/custom_require.rb:36:in `require'
    from /Users/headius/.rvm/rubies/ruby-2.0.0-preview2/lib/ruby/site_ruby/2.0.0/rubygems/custom_require.rb:36:in `require'
/Users/headius/.rvm/rubies/ruby-2.0.0-preview2/lib/ruby/site_ruby/2.0.0/rubygems/custom_require.rb:36:in `require': Attempt to unlock a mutex which is locked by another thread (ThreadError)
    from /Users/headius/.rvm/rubies/ruby-2.0.0-preview2/lib/ruby/site_ruby/2.0.0/rubygems/custom_require.rb:36:in `require'
    from bench_load_path.rb:18:in `block (4 levels) in <main>'
    from bench_load_path.rb:17:in `times'
    from bench_load_path.rb:17:in `block (3 levels) in <main>'

Related issues

Related to Ruby trunk - Bug #10892: Deadlock in autoload Open

Associated revisions

Revision 38744
Added by glass over 2 years ago

  • load.c (load_lock): fix not to delete thread shield twice.
    it may break the shield locked by another thread.
    [Bug #7530]

  • test/ruby/test_require.rb: a test for above.

Revision 38744
Added by glass over 2 years ago

  • load.c (load_lock): fix not to delete thread shield twice.
    it may break the shield locked by another thread.
    [Bug #7530]

  • test/ruby/test_require.rb: a test for above.

Revision 38750
Added by glass over 2 years ago

  • load.c (load_lock): if thread shield is destroyed and there is no waiting thread, insert new thread shield into load_table. [Bug #7530]

Revision 38750
Added by glass over 2 years ago

  • load.c (load_lock): if thread shield is destroyed and there is no waiting thread, insert new thread shield into load_table. [Bug #7530]

History

#1 Updated by Usaku NAKAMURA over 2 years ago

  • Target version set to 2.0.0
  • Category set to core
  • Status changed from Open to Assigned
  • Assignee set to Motohiro KOSAKI

#2 Updated by Motohiro KOSAKI over 2 years ago

  • Assignee changed from Motohiro KOSAKI to Nobuyoshi Nakada

When removing $".pop likes following, this issue never happen.
So, I suspect this is require and threadshield issue.


require 'benchmark'

FAKE_PATHS = ARGV[0].to_i || 100
THREADS = 2
ITERATIONS_PER_THREAD = 1000

FAKE_PATHS.times do |i|
  $:.unshift "foo#{i}"
end

$: << '.'

ITERATIONS_PER_THREAD.times {|i|
  system "touch __load_path_bench_script__#{i}.rb"
}

puts Benchmark.measure {
  @threads = THREADS.times.map do
    Thread.new {
      ITERATIONS_PER_THREAD.times do |i|
        require "__load_path_bench_script__#{i}"
      end
    }
  end
  @threads.each { |t| t.join }
}

ITERATIONS_PER_THREAD.times {|i|
  system "rm __load_path_bench_script__#{i}.rb"
}


#3 Updated by Nobuyoshi Nakada over 2 years ago

  • Priority changed from Normal to 5

#4 Updated by Masaki Matsushita over 2 years ago

Here is the minimal code:

THREADS = 2
ITERATIONS_PER_THREAD = 1000

system 'touch __load_path_bench_script__.rb'
THREADS.times.map {
  Thread.new do
    ITERATIONS_PER_THREAD.times do
      require_relative '__load_path_bench_script__'
      $".pop
    end
  end
}.each(&:join)
system 'rm __load_path_bench_script__.rb'

#5 Updated by Masaki Matsushita over 2 years ago

  • Assignee changed from Nobuyoshi Nakada to Masaki Matsushita

#6 Updated by Anonymous over 2 years ago

  • % Done changed from 0 to 100
  • Status changed from Assigned to Closed

This issue was solved with changeset r38744.
Charles, thank you for reporting this issue.
Your contribution to Ruby is greatly appreciated.
May Ruby be with you.


  • load.c (load_lock): fix not to delete thread shield twice.
    it may break the shield locked by another thread.
    [Bug #7530]

  • test/ruby/test_require.rb: a test for above.

#7 Updated by Nobuyoshi Nakada 28 days ago

  • Related to Bug #10892: Deadlock in autoload added

#8 Updated by Nobuyoshi Nakada 28 days ago

  • Description updated (diff)

Also available in: Atom PDF