[#108552] [Ruby master Bug#18782] Race conditions in autoload when loading the same feature with multiple threads. — "ioquatix (Samuel Williams)" <noreply@...>
Issue #18782 has been reported by ioquatix (Samuel Williams).
11 messages
2022/05/14
[ruby-core:108562] [Ruby master Bug#18782] Race conditions in autoload when loading the same feature with multiple threads.
From:
"ioquatix (Samuel Williams)" <noreply@...>
Date:
2022-05-15 23:36:16 UTC
List:
ruby-core #108562
Issue #18782 has been updated by ioquatix (Samuel Williams).
Okay, so I suspected some issue with `autoload_delete` and finally found how to reproduce it.
```c
static void
autoload_delete(VALUE mod, ID id)
{
RB_VM_LOCK_ENTER();
st_data_t val, load = 0, n = id;
if (st_lookup(RCLASS_IV_TBL(mod), (st_data_t)autoload, &val)) {
struct st_table *tbl = check_autoload_table((VALUE)val);
struct autoload_data *ele;
struct autoload_const *ac;
st_delete(tbl, &n, &load);
/* Qfalse can indicate already deleted */
if (load != Qfalse) {
ele = get_autoload_data((VALUE)load, &ac);
VM_ASSERT(ele);
/*
* we must delete here to avoid "already initialized" warnings
* with parallel autoload. Using list_del_init here so list_del
* works in autoload_c_free
*/
ccan_list_del_init(&ac->cnode);
if (tbl->num_entries == 0) {
n = autoload;
st_delete(RCLASS_IV_TBL(mod), &n, &val);
}
}
}
RB_VM_LOCK_LEAVE();
rb_thread_schedule(); // add this to create odd behaviour (eventually).
}
```
Test case:
```ruby
module MyModule; end
file = "autoload_does_not_exist.rb"
190.times do
puts "."
start = false
threads = Array.new(10) do
Thread.new do
Thread.pass until start
begin
MyModule.autoload :FileDoesNotExist, file
Thread.pass
MyModule::FileDoesNotExist
rescue LoadError => e
e
ensure
Thread.pass
end
end
end
start = true
threads.each { |t|
raise "Failed" unless t.value.is_a?(LoadError)
}
end
```
Failure example:
```
..
#<Thread:0x00007fafd3665c08 ../test.rb:35 run> terminated with exception (report_on_exception is true):
../test.rb:40:in `block (3 levels) in <main>': uninitialized constant MyModule::FileDoesNotExist (NameError)
../test.rb:40:in `block (3 levels) in <main>': uninitialized constant MyModule::FileDoesNotExist (NameError)
make: *** [uncommon.mk:1250: runruby] Error 1
```
----------------------------------------
Bug #18782: Race conditions in autoload when loading the same feature with multiple threads.
https://bugs.ruby-lang.org/issues/18782#change-97601
* Author: ioquatix (Samuel Williams)
* Status: Open
* Priority: Normal
* Backport: 2.7: UNKNOWN, 3.0: UNKNOWN, 3.1: UNKNOWN
----------------------------------------
I have identified several race conditions in the autoload code.
1. It's possible to race on adding and then deleting items in `autoload_featuremap`. When this happens, two threads will try to load the same file with different autoload data and deadlock.
2. When finishing autoload, it's necessary to clear `ele->state` before setting constants. If this is not synchronised, a thread can see the cleared `ele->state` before seeing the constants and assume the constant is not being autoloaded and then fail with `NameError`.
This test case can reproduce both cases:
```
# test.rb
autoload_path = File.join(__dir__, "foobar.rb")
File.write(autoload_path, 'module Foo; end; module Bar; end')
100_000.times do
$stderr.puts "--------------------"
autoload :Foo, autoload_path
autoload :Bar, autoload_path
t1 = Thread.new {Foo}
t2 = Thread.new {Bar}
t1.join
t2.join
Object.send(:remove_const, :Foo)
Object.send(:remove_const, :Bar)
$LOADED_FEATURES.delete(autoload_path)
end
```
Example failure of case (1):
```
-------------------- (success)
autoload_by_someone_else ele=0x55f33b806a30 ele->state=(nil)
autoload_by_someone_else ele=0x55f33b806a30 ele->state=(nil)
check_autoload_required 2
autoload_by_someone_else ele=0x55f33b806a30 ele->state=0x7fdd678be780
check_autoload_required 4
autoload_by_someone_else ele=0x55f33b806a30 ele->state=0x7fdd678be780
check_autoload_required 4
ele=0x55f33b806a30 ele->state=0x7fdd678be780 = NULL
check_autoload_required 4
-------------------- (failure)
autoload_by_someone_else ele=0x55f33b806a30 ele->state=(nil)
autoload_by_someone_else ele=0x55f33b6e8f40 ele->state=(nil)
check_autoload_required 2
check_autoload_required 3
autoload_by_someone_else ele=0x55f33b806a30 ele->state=0x7fdd6779d780
check_autoload_required 1
autoload_by_someone_else ele=0x55f33b806a30 ele->state=0x7fdd6779d780
check_autoload_required 1
ele=0x55f33b806a30 ele->state=0x7fdd6779d780 = NULL
ele=0x55f33b6e8f40 ele->state=0x7fdd678be780 = NULL
../test.rb:12:in `join': No live threads left. Deadlock? (fatal)
3 threads, 3 sleeps current:0x000055f33b771250 main thread:0x000055f33b66e090
* #<Thread:0x00007fdd6a2cb0b0 sleep_forever>
rb_thread_t:0x000055f33b66e090 native:0x00007fdd6a71c3c0 int:0
* #<Thread:0x00007fdd676e0090 ../test.rb:9 sleep_forever>
rb_thread_t:0x000055f33b770ff0 native:0x00007fdd6789e640 int:1 mutex:0x000055f33b7c5100 cond:1
depended by: tb_thread_id:0x000055f33b66e090
* #<Thread:0x00007fdd676e1238 ../test.rb:10 sleep_forever>
rb_thread_t:0x000055f33b771250 native:0x00007fdd679bf640 int:0
from ../test.rb:12:in `block in <main>'
from ../test.rb:4:in `times'
from ../test.rb:4:in `<main>'
make: *** [uncommon.mk:1250: runruby] Error 1
```
Example failure of case (2):
```
[0x7f175fe5b0c8] rb_autoload_str mod=Object id=Foo file="/home/samuel/Projects/ioquatix/ruby/foobar.rb"
[0x7f175fe5b0c8] rb_autoload_str const_set mod=Object id=Foo file="/home/samuel/Projects/ioquatix/ruby/foobar.rb"
[0x7f175fe5b0c8] rb_autoload_str mod=Object id=Bar file="/home/samuel/Projects/ioquatix/ruby/foobar.rb"
[0x7f175fe5b0c8] rb_autoload_str const_set mod=Object id=Bar file="/home/samuel/Projects/ioquatix/ruby/foobar.rb"
[0x7f175fe61d88] rb_const_search_from value == Qundef -> autoloading
[0x7f175fe61e78] rb_const_search_from value == Qundef -> autoloading
[0x7f175fe61e78] Assigning constants...
[0x7f175fe61d88] rb_const_search_from value == Qundef -> autoloading
[0x7f175fe61e78] autoload_const_set name=:Foo value=Foo
[0x7f175fe61e78] autoload_const_set name=:Bar value=Bar
#<Thread:0x00007f175fe61d88 ../test.rb:11 run> terminated with exception (report_on_exception is true):
../test.rb:11:in `block (2 levels) in <main>': uninitialized constant Bar (NameError)
../test.rb:11:in `block (2 levels) in <main>': uninitialized constant Bar (NameError)
make: *** [uncommon.mk:1250: runruby] Error 1
```
These failures are very uncommon but it does impact Ruby as far back as 2.7, and probably earlier.
---Files--------------------------------
0001-Add-RUBY_VM_CRITICAL_SECTION-for-detecting-unexpecte.patch (2.07 KB)
0002-Prevent-race-between-GC-mark-and-autoload-setup.patch (1.01 KB)
0003-Protect-race-on-autoload-state.patch (10.6 KB)
0004-Increase-timeout-for-debug-tests.patch (910 Bytes)
0005-Revert-removal-of-non-conditional-xfree.patch (691 Bytes)
--
https://bugs.ruby-lang.org/
Unsubscribe: <mailto:ruby-core-request@ruby-lang.org?subject=unsubscribe>
<http://lists.ruby-lang.org/cgi-bin/mailman/options/ruby-core>