* [ruby-core:107715] [Ruby master Bug#18599] `vm->loaded_features_snapshot` became very inefficient in Ruby 3.1
@ 2022-02-22 17:37 byroot (Jean Boussier)
2022-02-23 16:09 ` [ruby-core:107733] " byroot (Jean Boussier)
` (4 more replies)
0 siblings, 5 replies; 6+ messages in thread
From: byroot (Jean Boussier) @ 2022-02-22 17:37 UTC (permalink / raw)
To: ruby-core
Issue #18599 has been reported by byroot (Jean Boussier).
----------------------------------------
Bug #18599: `vm->loaded_features_snapshot` became very inefficient in Ruby 3.1
https://bugs.ruby-lang.org/issues/18599
* Author: byroot (Jean Boussier)
* Status: Open
* Priority: Normal
* ruby -v: ruby 3.1.1p18 (2022-02-18 revision 53f5fc4236) [x86_64-darwin20]
* Backport: 2.6: DONTNEED, 2.7: DONTNEED, 3.0: DONTNEED, 3.1: UNKNOWN
----------------------------------------
A change in how shared arrays behave has caused a fairly major performance regression in `Kernel.require`. In short on every single call, a full copy of `$LOADED_FEATURES` is made.
In our app this causes over 6GiB worth of useless allocations.
### Reproduction
```ruby
# frozen_string_literal: true
require "objspace"
files = 5.times.map { |i| "/tmp/foo-#{i}.rb" }
files.each { |f| File.write(f, "") }
require files.shift
4.times { GC.start }
generation = GC.count
ObjectSpace.trace_object_allocations do
files.each { |f| require f }
end
ObjectSpace.dump_all(output: File.open("/tmp/allocated.heap", "w+"), since: generation)
ObjectSpace.dump_all(output: File.open("/tmp/full.heap", "w+"))
```
If you inspect the `allocated.heap`, you'll notice 4 array, each increasingly bigger.
```
$ grep ARRAY /tmp/allocated.heap
{"address":"0x10fe2b3b8", "type":"ARRAY", "frozen":true, "length":92, "references":["0x10fcd3da8", "0x10fcca2a8", "0x10fcc21c0", ...], "file":"<internal:/opt/rubies/3.1.0/lib/ruby/3.1.0/rubygems/core_ext/kernel_require.rb>", "line":85, "method":"require", "generation":13, "memsize":776, "flags":{"wb_protected":true}}
...
{"address":"0x10fe2b688", "type":"ARRAY", "frozen":true, "length":91, "references":["0x10fcd3da8", "0x10fcca2a8", "0x10fcc21c0", ...], "file":"<internal:/opt/rubies/3.1.0/lib/ruby/3.1.0/rubygems/core_ext/kernel_require.rb>", "line":85, "method":"require", "generation":13, "memsize":768, "flags":{"wb_protected":true}}
...
{"address":"0x10fe2b958", "type":"ARRAY", "frozen":true, "length":89, "references":["0x10fcd3da8", "0x10fcca2a8", "0x10fcc21c0", ...], "file":"<internal:/opt/rubies/3.1.0/lib/ruby/3.1.0/rubygems/core_ext/kernel_require.rb>", "line":85, "method":"require", "generation":13, "memsize":752, "flags":{"wb_protected":true}}
...
{"address":"0x10fe2bc28", "type":"ARRAY", "frozen":true, "length":88, "references":["0x10fcd3da8", "0x10fcca2a8", "0x10fcc21c0", ...], "file":"<internal:/opt/rubies/3.1.0/lib/ruby/3.1.0/rubygems/core_ext/kernel_require.rb>", "line":85, "method":"require", "generation":13, "memsize":744, "flags":{"wb_protected":true}}
...
```
And if you lookup the addresses in `full.heap`, it makes no doubt that it's `$LOADED_FEATURES`.
Note however how the array is `"frozen":true`, so it's not `$LOADED_FEATURES` directly, but the shared array that backs `vm->loaded_features` and `vm->loaded_features_snapshot`.
### More scoped reproduction
If we scope on shared arrays behavior specifically, we can get a much smaller reproduction:
```ruby
array = 10.times.to_a
copy = array.dup
before = GC.stat(:total_allocated_objects)
copy << 1
p GC.stat(:total_allocated_objects) - before # 1 on Ruby 3.1, 0 on 3.0 and older
```
In short, back in 3.0 and older, appending to a shared array wouldn't "unshare" the array, but starting in 3.1 it now does.
The problem being that `Kernel.require` heavily assumed this implementation detail:
```c
static void
reset_loaded_features_snapshot(rb_vm_t *vm)
{
rb_ary_replace(vm->loaded_features_snapshot, vm->loaded_features);
}
rb_provide_feature(rb_vm_t *vm, VALUE feature)
{
//...
get_loaded_features_index(vm);
rb_ary_push(features, rb_fstring(feature));
features_index_add(vm, feature, INT2FIX(RARRAY_LEN(features)-1));
reset_loaded_features_snapshot(vm);
}
```
`rb_provide_feature` first append to `$LOADED_FEATURES` and then resets `vm->loaded_features_snapshot` to be a shared copy of `$LOADED_FEATURES`.
--
https://bugs.ruby-lang.org/
^ permalink raw reply [flat|nested] 6+ messages in thread
* [ruby-core:107733] [Ruby master Bug#18599] `vm->loaded_features_snapshot` became very inefficient in Ruby 3.1
2022-02-22 17:37 [ruby-core:107715] [Ruby master Bug#18599] `vm->loaded_features_snapshot` became very inefficient in Ruby 3.1 byroot (Jean Boussier)
@ 2022-02-23 16:09 ` byroot (Jean Boussier)
2022-02-23 17:05 ` [ruby-core:107734] " byroot (Jean Boussier)
` (3 subsequent siblings)
4 siblings, 0 replies; 6+ messages in thread
From: byroot (Jean Boussier) @ 2022-02-23 16:09 UTC (permalink / raw)
To: ruby-core
Issue #18599 has been updated by byroot (Jean Boussier).
Backport changed from 2.6: DONTNEED, 2.7: DONTNEED, 3.0: DONTNEED, 3.1: UNKNOWN to 2.6: DONTNEED, 2.7: UNKNOWN, 3.0: UNKNOWN, 3.1: UNKNOWN
Ok, so my assessment about shared arrays wasn't quite correct. What caused the difference between 3.0 and 3.1 here is http://github.com/ruby/ruby/commit/aeae6e2842e1702dfb89b8ae69b48c4f5f64c662
Previously the shared array would be force recycled immediately, which was hiding the problem, but it was already there.
With the help of @peterzhu2118, we figured a fairly simple patch for this: https://github.com/ruby/ruby/pull/5593
----------------------------------------
Bug #18599: `vm->loaded_features_snapshot` became very inefficient in Ruby 3.1
https://bugs.ruby-lang.org/issues/18599#change-96656
* Author: byroot (Jean Boussier)
* Status: Open
* Priority: Normal
* ruby -v: ruby 3.1.1p18 (2022-02-18 revision 53f5fc4236) [x86_64-darwin20]
* Backport: 2.6: DONTNEED, 2.7: UNKNOWN, 3.0: UNKNOWN, 3.1: UNKNOWN
----------------------------------------
A change in how shared arrays behave has caused a fairly major performance regression in `Kernel.require`. In short on every single call, a full copy of `$LOADED_FEATURES` is made.
In our app this causes over 6GiB worth of useless allocations.
### Reproduction
```ruby
# frozen_string_literal: true
require "objspace"
files = 5.times.map { |i| "/tmp/foo-#{i}.rb" }
files.each { |f| File.write(f, "") }
require files.shift
4.times { GC.start }
generation = GC.count
ObjectSpace.trace_object_allocations do
files.each { |f| require f }
end
ObjectSpace.dump_all(output: File.open("/tmp/allocated.heap", "w+"), since: generation)
ObjectSpace.dump_all(output: File.open("/tmp/full.heap", "w+"))
```
If you inspect the `allocated.heap`, you'll notice 4 array, each increasingly bigger.
```
$ grep ARRAY /tmp/allocated.heap
{"address":"0x10fe2b3b8", "type":"ARRAY", "frozen":true, "length":92, "references":["0x10fcd3da8", "0x10fcca2a8", "0x10fcc21c0", ...], "file":"<internal:/opt/rubies/3.1.0/lib/ruby/3.1.0/rubygems/core_ext/kernel_require.rb>", "line":85, "method":"require", "generation":13, "memsize":776, "flags":{"wb_protected":true}}
...
{"address":"0x10fe2b688", "type":"ARRAY", "frozen":true, "length":91, "references":["0x10fcd3da8", "0x10fcca2a8", "0x10fcc21c0", ...], "file":"<internal:/opt/rubies/3.1.0/lib/ruby/3.1.0/rubygems/core_ext/kernel_require.rb>", "line":85, "method":"require", "generation":13, "memsize":768, "flags":{"wb_protected":true}}
...
{"address":"0x10fe2b958", "type":"ARRAY", "frozen":true, "length":89, "references":["0x10fcd3da8", "0x10fcca2a8", "0x10fcc21c0", ...], "file":"<internal:/opt/rubies/3.1.0/lib/ruby/3.1.0/rubygems/core_ext/kernel_require.rb>", "line":85, "method":"require", "generation":13, "memsize":752, "flags":{"wb_protected":true}}
...
{"address":"0x10fe2bc28", "type":"ARRAY", "frozen":true, "length":88, "references":["0x10fcd3da8", "0x10fcca2a8", "0x10fcc21c0", ...], "file":"<internal:/opt/rubies/3.1.0/lib/ruby/3.1.0/rubygems/core_ext/kernel_require.rb>", "line":85, "method":"require", "generation":13, "memsize":744, "flags":{"wb_protected":true}}
...
```
And if you lookup the addresses in `full.heap`, it makes no doubt that it's `$LOADED_FEATURES`.
Note however how the array is `"frozen":true`, so it's not `$LOADED_FEATURES` directly, but the shared array that backs `vm->loaded_features` and `vm->loaded_features_snapshot`.
### More scoped reproduction
If we scope on shared arrays behavior specifically, we can get a much smaller reproduction:
```ruby
array = 10.times.to_a
copy = array.dup
before = GC.stat(:total_allocated_objects)
copy << 1
p GC.stat(:total_allocated_objects) - before # 1 on Ruby 3.1, 0 on 3.0 and older
```
In short, back in 3.0 and older, appending to a shared array wouldn't "unshare" the array, but starting in 3.1 it now does.
The problem being that `Kernel.require` heavily assumed this implementation detail:
```c
static void
reset_loaded_features_snapshot(rb_vm_t *vm)
{
rb_ary_replace(vm->loaded_features_snapshot, vm->loaded_features);
}
rb_provide_feature(rb_vm_t *vm, VALUE feature)
{
//...
get_loaded_features_index(vm);
rb_ary_push(features, rb_fstring(feature));
features_index_add(vm, feature, INT2FIX(RARRAY_LEN(features)-1));
reset_loaded_features_snapshot(vm);
}
```
`rb_provide_feature` first append to `$LOADED_FEATURES` and then resets `vm->loaded_features_snapshot` to be a shared copy of `$LOADED_FEATURES`.
--
https://bugs.ruby-lang.org/
^ permalink raw reply [flat|nested] 6+ messages in thread
* [ruby-core:107734] [Ruby master Bug#18599] `vm->loaded_features_snapshot` became very inefficient in Ruby 3.1
2022-02-22 17:37 [ruby-core:107715] [Ruby master Bug#18599] `vm->loaded_features_snapshot` became very inefficient in Ruby 3.1 byroot (Jean Boussier)
2022-02-23 16:09 ` [ruby-core:107733] " byroot (Jean Boussier)
@ 2022-02-23 17:05 ` byroot (Jean Boussier)
2022-11-11 15:32 ` [ruby-core:110706] " thomthom (Thomas Thomassen)
` (2 subsequent siblings)
4 siblings, 0 replies; 6+ messages in thread
From: byroot (Jean Boussier) @ 2022-02-23 17:05 UTC (permalink / raw)
To: ruby-core
Issue #18599 has been updated by byroot (Jean Boussier).
I tested the patch against our app, it does solve the problem perfectly, and the time spent in GC during boot is noticeably reduced (`~40% -> ~28%`).
----------------------------------------
Bug #18599: `vm->loaded_features_snapshot` became very inefficient in Ruby 3.1
https://bugs.ruby-lang.org/issues/18599#change-96657
* Author: byroot (Jean Boussier)
* Status: Open
* Priority: Normal
* ruby -v: ruby 3.1.1p18 (2022-02-18 revision 53f5fc4236) [x86_64-darwin20]
* Backport: 2.6: DONTNEED, 2.7: UNKNOWN, 3.0: UNKNOWN, 3.1: UNKNOWN
----------------------------------------
A change in how shared arrays behave has caused a fairly major performance regression in `Kernel.require`. In short on every single call, a full copy of `$LOADED_FEATURES` is made.
In our app this causes over 6GiB worth of useless allocations.
### Reproduction
```ruby
# frozen_string_literal: true
require "objspace"
files = 5.times.map { |i| "/tmp/foo-#{i}.rb" }
files.each { |f| File.write(f, "") }
require files.shift
4.times { GC.start }
generation = GC.count
ObjectSpace.trace_object_allocations do
files.each { |f| require f }
end
ObjectSpace.dump_all(output: File.open("/tmp/allocated.heap", "w+"), since: generation)
ObjectSpace.dump_all(output: File.open("/tmp/full.heap", "w+"))
```
If you inspect the `allocated.heap`, you'll notice 4 array, each increasingly bigger.
```
$ grep ARRAY /tmp/allocated.heap
{"address":"0x10fe2b3b8", "type":"ARRAY", "frozen":true, "length":92, "references":["0x10fcd3da8", "0x10fcca2a8", "0x10fcc21c0", ...], "file":"<internal:/opt/rubies/3.1.0/lib/ruby/3.1.0/rubygems/core_ext/kernel_require.rb>", "line":85, "method":"require", "generation":13, "memsize":776, "flags":{"wb_protected":true}}
...
{"address":"0x10fe2b688", "type":"ARRAY", "frozen":true, "length":91, "references":["0x10fcd3da8", "0x10fcca2a8", "0x10fcc21c0", ...], "file":"<internal:/opt/rubies/3.1.0/lib/ruby/3.1.0/rubygems/core_ext/kernel_require.rb>", "line":85, "method":"require", "generation":13, "memsize":768, "flags":{"wb_protected":true}}
...
{"address":"0x10fe2b958", "type":"ARRAY", "frozen":true, "length":89, "references":["0x10fcd3da8", "0x10fcca2a8", "0x10fcc21c0", ...], "file":"<internal:/opt/rubies/3.1.0/lib/ruby/3.1.0/rubygems/core_ext/kernel_require.rb>", "line":85, "method":"require", "generation":13, "memsize":752, "flags":{"wb_protected":true}}
...
{"address":"0x10fe2bc28", "type":"ARRAY", "frozen":true, "length":88, "references":["0x10fcd3da8", "0x10fcca2a8", "0x10fcc21c0", ...], "file":"<internal:/opt/rubies/3.1.0/lib/ruby/3.1.0/rubygems/core_ext/kernel_require.rb>", "line":85, "method":"require", "generation":13, "memsize":744, "flags":{"wb_protected":true}}
...
```
And if you lookup the addresses in `full.heap`, it makes no doubt that it's `$LOADED_FEATURES`.
Note however how the array is `"frozen":true`, so it's not `$LOADED_FEATURES` directly, but the shared array that backs `vm->loaded_features` and `vm->loaded_features_snapshot`.
### More scoped reproduction
If we scope on shared arrays behavior specifically, we can get a much smaller reproduction:
```ruby
array = 10.times.to_a
copy = array.dup
before = GC.stat(:total_allocated_objects)
copy << 1
p GC.stat(:total_allocated_objects) - before # 1 on Ruby 3.1, 0 on 3.0 and older
```
In short, back in 3.0 and older, appending to a shared array wouldn't "unshare" the array, but starting in 3.1 it now does.
The problem being that `Kernel.require` heavily assumed this implementation detail:
```c
static void
reset_loaded_features_snapshot(rb_vm_t *vm)
{
rb_ary_replace(vm->loaded_features_snapshot, vm->loaded_features);
}
rb_provide_feature(rb_vm_t *vm, VALUE feature)
{
//...
get_loaded_features_index(vm);
rb_ary_push(features, rb_fstring(feature));
features_index_add(vm, feature, INT2FIX(RARRAY_LEN(features)-1));
reset_loaded_features_snapshot(vm);
}
```
`rb_provide_feature` first append to `$LOADED_FEATURES` and then resets `vm->loaded_features_snapshot` to be a shared copy of `$LOADED_FEATURES`.
--
https://bugs.ruby-lang.org/
^ permalink raw reply [flat|nested] 6+ messages in thread
* [ruby-core:110706] [Ruby master Bug#18599] `vm->loaded_features_snapshot` became very inefficient in Ruby 3.1
2022-02-22 17:37 [ruby-core:107715] [Ruby master Bug#18599] `vm->loaded_features_snapshot` became very inefficient in Ruby 3.1 byroot (Jean Boussier)
2022-02-23 16:09 ` [ruby-core:107733] " byroot (Jean Boussier)
2022-02-23 17:05 ` [ruby-core:107734] " byroot (Jean Boussier)
@ 2022-11-11 15:32 ` thomthom (Thomas Thomassen)
2022-11-11 23:38 ` [ruby-core:110713] " byroot (Jean Boussier)
2022-11-13 8:08 ` [ruby-core:110735] " nagachika (Tomoyuki Chikanaga)
4 siblings, 0 replies; 6+ messages in thread
From: thomthom (Thomas Thomassen) @ 2022-11-11 15:32 UTC (permalink / raw)
To: ruby-core
Issue #18599 has been updated by thomthom (Thomas Thomassen).
Is this targeted to be ported to Ruby 3.1? I see it's not included in 3.1.2 nor in the ruby_3_1 branch.
----------------------------------------
Bug #18599: `vm->loaded_features_snapshot` became very inefficient in Ruby 3.1
https://bugs.ruby-lang.org/issues/18599#change-100047
* Author: byroot (Jean Boussier)
* Status: Closed
* Priority: Normal
* ruby -v: ruby 3.1.1p18 (2022-02-18 revision 53f5fc4236) [x86_64-darwin20]
* Backport: 2.6: WONTFIX, 2.7: REQUIRED, 3.0: REQUIRED, 3.1: REQUIRED
----------------------------------------
A change in how shared arrays behave has caused a fairly major performance regression in `Kernel.require`. In short on every single call, a full copy of `$LOADED_FEATURES` is made.
In our app this causes over 6GiB worth of useless allocations.
### Reproduction
```ruby
# frozen_string_literal: true
require "objspace"
files = 5.times.map { |i| "/tmp/foo-#{i}.rb" }
files.each { |f| File.write(f, "") }
require files.shift
4.times { GC.start }
generation = GC.count
ObjectSpace.trace_object_allocations do
files.each { |f| require f }
end
ObjectSpace.dump_all(output: File.open("/tmp/allocated.heap", "w+"), since: generation)
ObjectSpace.dump_all(output: File.open("/tmp/full.heap", "w+"))
```
If you inspect the `allocated.heap`, you'll notice 4 array, each increasingly bigger.
```
$ grep ARRAY /tmp/allocated.heap
{"address":"0x10fe2b3b8", "type":"ARRAY", "frozen":true, "length":92, "references":["0x10fcd3da8", "0x10fcca2a8", "0x10fcc21c0", ...], "file":"<internal:/opt/rubies/3.1.0/lib/ruby/3.1.0/rubygems/core_ext/kernel_require.rb>", "line":85, "method":"require", "generation":13, "memsize":776, "flags":{"wb_protected":true}}
...
{"address":"0x10fe2b688", "type":"ARRAY", "frozen":true, "length":91, "references":["0x10fcd3da8", "0x10fcca2a8", "0x10fcc21c0", ...], "file":"<internal:/opt/rubies/3.1.0/lib/ruby/3.1.0/rubygems/core_ext/kernel_require.rb>", "line":85, "method":"require", "generation":13, "memsize":768, "flags":{"wb_protected":true}}
...
{"address":"0x10fe2b958", "type":"ARRAY", "frozen":true, "length":89, "references":["0x10fcd3da8", "0x10fcca2a8", "0x10fcc21c0", ...], "file":"<internal:/opt/rubies/3.1.0/lib/ruby/3.1.0/rubygems/core_ext/kernel_require.rb>", "line":85, "method":"require", "generation":13, "memsize":752, "flags":{"wb_protected":true}}
...
{"address":"0x10fe2bc28", "type":"ARRAY", "frozen":true, "length":88, "references":["0x10fcd3da8", "0x10fcca2a8", "0x10fcc21c0", ...], "file":"<internal:/opt/rubies/3.1.0/lib/ruby/3.1.0/rubygems/core_ext/kernel_require.rb>", "line":85, "method":"require", "generation":13, "memsize":744, "flags":{"wb_protected":true}}
...
```
And if you lookup the addresses in `full.heap`, it makes no doubt that it's `$LOADED_FEATURES`.
Note however how the array is `"frozen":true`, so it's not `$LOADED_FEATURES` directly, but the shared array that backs `vm->loaded_features` and `vm->loaded_features_snapshot`.
### More scoped reproduction
If we scope on shared arrays behavior specifically, we can get a much smaller reproduction:
```ruby
array = 10.times.to_a
copy = array.dup
before = GC.stat(:total_allocated_objects)
copy << 1
p GC.stat(:total_allocated_objects) - before # 1 on Ruby 3.1, 0 on 3.0 and older
```
In short, back in 3.0 and older, appending to a shared array wouldn't "unshare" the array, but starting in 3.1 it now does.
The problem being that `Kernel.require` heavily assumed this implementation detail:
```c
static void
reset_loaded_features_snapshot(rb_vm_t *vm)
{
rb_ary_replace(vm->loaded_features_snapshot, vm->loaded_features);
}
rb_provide_feature(rb_vm_t *vm, VALUE feature)
{
//...
get_loaded_features_index(vm);
rb_ary_push(features, rb_fstring(feature));
features_index_add(vm, feature, INT2FIX(RARRAY_LEN(features)-1));
reset_loaded_features_snapshot(vm);
}
```
`rb_provide_feature` first append to `$LOADED_FEATURES` and then resets `vm->loaded_features_snapshot` to be a shared copy of `$LOADED_FEATURES`.
--
https://bugs.ruby-lang.org/
^ permalink raw reply [flat|nested] 6+ messages in thread
* [ruby-core:110713] [Ruby master Bug#18599] `vm->loaded_features_snapshot` became very inefficient in Ruby 3.1
2022-02-22 17:37 [ruby-core:107715] [Ruby master Bug#18599] `vm->loaded_features_snapshot` became very inefficient in Ruby 3.1 byroot (Jean Boussier)
` (2 preceding siblings ...)
2022-11-11 15:32 ` [ruby-core:110706] " thomthom (Thomas Thomassen)
@ 2022-11-11 23:38 ` byroot (Jean Boussier)
2022-11-13 8:08 ` [ruby-core:110735] " nagachika (Tomoyuki Chikanaga)
4 siblings, 0 replies; 6+ messages in thread
From: byroot (Jean Boussier) @ 2022-11-11 23:38 UTC (permalink / raw)
To: ruby-core
Issue #18599 has been updated by byroot (Jean Boussier).
> Is this targeted to be ported to Ruby 3.1?
Yes.
----------------------------------------
Bug #18599: `vm->loaded_features_snapshot` became very inefficient in Ruby 3.1
https://bugs.ruby-lang.org/issues/18599#change-100054
* Author: byroot (Jean Boussier)
* Status: Closed
* Priority: Normal
* ruby -v: ruby 3.1.1p18 (2022-02-18 revision 53f5fc4236) [x86_64-darwin20]
* Backport: 2.6: WONTFIX, 2.7: REQUIRED, 3.0: REQUIRED, 3.1: REQUIRED
----------------------------------------
A change in how shared arrays behave has caused a fairly major performance regression in `Kernel.require`. In short on every single call, a full copy of `$LOADED_FEATURES` is made.
In our app this causes over 6GiB worth of useless allocations.
### Reproduction
```ruby
# frozen_string_literal: true
require "objspace"
files = 5.times.map { |i| "/tmp/foo-#{i}.rb" }
files.each { |f| File.write(f, "") }
require files.shift
4.times { GC.start }
generation = GC.count
ObjectSpace.trace_object_allocations do
files.each { |f| require f }
end
ObjectSpace.dump_all(output: File.open("/tmp/allocated.heap", "w+"), since: generation)
ObjectSpace.dump_all(output: File.open("/tmp/full.heap", "w+"))
```
If you inspect the `allocated.heap`, you'll notice 4 array, each increasingly bigger.
```
$ grep ARRAY /tmp/allocated.heap
{"address":"0x10fe2b3b8", "type":"ARRAY", "frozen":true, "length":92, "references":["0x10fcd3da8", "0x10fcca2a8", "0x10fcc21c0", ...], "file":"<internal:/opt/rubies/3.1.0/lib/ruby/3.1.0/rubygems/core_ext/kernel_require.rb>", "line":85, "method":"require", "generation":13, "memsize":776, "flags":{"wb_protected":true}}
...
{"address":"0x10fe2b688", "type":"ARRAY", "frozen":true, "length":91, "references":["0x10fcd3da8", "0x10fcca2a8", "0x10fcc21c0", ...], "file":"<internal:/opt/rubies/3.1.0/lib/ruby/3.1.0/rubygems/core_ext/kernel_require.rb>", "line":85, "method":"require", "generation":13, "memsize":768, "flags":{"wb_protected":true}}
...
{"address":"0x10fe2b958", "type":"ARRAY", "frozen":true, "length":89, "references":["0x10fcd3da8", "0x10fcca2a8", "0x10fcc21c0", ...], "file":"<internal:/opt/rubies/3.1.0/lib/ruby/3.1.0/rubygems/core_ext/kernel_require.rb>", "line":85, "method":"require", "generation":13, "memsize":752, "flags":{"wb_protected":true}}
...
{"address":"0x10fe2bc28", "type":"ARRAY", "frozen":true, "length":88, "references":["0x10fcd3da8", "0x10fcca2a8", "0x10fcc21c0", ...], "file":"<internal:/opt/rubies/3.1.0/lib/ruby/3.1.0/rubygems/core_ext/kernel_require.rb>", "line":85, "method":"require", "generation":13, "memsize":744, "flags":{"wb_protected":true}}
...
```
And if you lookup the addresses in `full.heap`, it makes no doubt that it's `$LOADED_FEATURES`.
Note however how the array is `"frozen":true`, so it's not `$LOADED_FEATURES` directly, but the shared array that backs `vm->loaded_features` and `vm->loaded_features_snapshot`.
### More scoped reproduction
If we scope on shared arrays behavior specifically, we can get a much smaller reproduction:
```ruby
array = 10.times.to_a
copy = array.dup
before = GC.stat(:total_allocated_objects)
copy << 1
p GC.stat(:total_allocated_objects) - before # 1 on Ruby 3.1, 0 on 3.0 and older
```
In short, back in 3.0 and older, appending to a shared array wouldn't "unshare" the array, but starting in 3.1 it now does.
The problem being that `Kernel.require` heavily assumed this implementation detail:
```c
static void
reset_loaded_features_snapshot(rb_vm_t *vm)
{
rb_ary_replace(vm->loaded_features_snapshot, vm->loaded_features);
}
rb_provide_feature(rb_vm_t *vm, VALUE feature)
{
//...
get_loaded_features_index(vm);
rb_ary_push(features, rb_fstring(feature));
features_index_add(vm, feature, INT2FIX(RARRAY_LEN(features)-1));
reset_loaded_features_snapshot(vm);
}
```
`rb_provide_feature` first append to `$LOADED_FEATURES` and then resets `vm->loaded_features_snapshot` to be a shared copy of `$LOADED_FEATURES`.
--
https://bugs.ruby-lang.org/
^ permalink raw reply [flat|nested] 6+ messages in thread
* [ruby-core:110735] [Ruby master Bug#18599] `vm->loaded_features_snapshot` became very inefficient in Ruby 3.1
2022-02-22 17:37 [ruby-core:107715] [Ruby master Bug#18599] `vm->loaded_features_snapshot` became very inefficient in Ruby 3.1 byroot (Jean Boussier)
` (3 preceding siblings ...)
2022-11-11 23:38 ` [ruby-core:110713] " byroot (Jean Boussier)
@ 2022-11-13 8:08 ` nagachika (Tomoyuki Chikanaga)
4 siblings, 0 replies; 6+ messages in thread
From: nagachika (Tomoyuki Chikanaga) @ 2022-11-13 8:08 UTC (permalink / raw)
To: ruby-core
Issue #18599 has been updated by nagachika (Tomoyuki Chikanaga).
Backport changed from 2.6: WONTFIX, 2.7: REQUIRED, 3.0: REQUIRED, 3.1: REQUIRED to 2.6: WONTFIX, 2.7: REQUIRED, 3.0: REQUIRED, 3.1: DONE
ruby_3_1 012015d762d000966a33fcea5f3069decd9d4007 merged revision(s) b8f0dc59d52266d9fbfc039e2f4b0f727c62baa0.
----------------------------------------
Bug #18599: `vm->loaded_features_snapshot` became very inefficient in Ruby 3.1
https://bugs.ruby-lang.org/issues/18599#change-100072
* Author: byroot (Jean Boussier)
* Status: Closed
* Priority: Normal
* ruby -v: ruby 3.1.1p18 (2022-02-18 revision 53f5fc4236) [x86_64-darwin20]
* Backport: 2.6: WONTFIX, 2.7: REQUIRED, 3.0: REQUIRED, 3.1: DONE
----------------------------------------
A change in how shared arrays behave has caused a fairly major performance regression in `Kernel.require`. In short on every single call, a full copy of `$LOADED_FEATURES` is made.
In our app this causes over 6GiB worth of useless allocations.
### Reproduction
```ruby
# frozen_string_literal: true
require "objspace"
files = 5.times.map { |i| "/tmp/foo-#{i}.rb" }
files.each { |f| File.write(f, "") }
require files.shift
4.times { GC.start }
generation = GC.count
ObjectSpace.trace_object_allocations do
files.each { |f| require f }
end
ObjectSpace.dump_all(output: File.open("/tmp/allocated.heap", "w+"), since: generation)
ObjectSpace.dump_all(output: File.open("/tmp/full.heap", "w+"))
```
If you inspect the `allocated.heap`, you'll notice 4 array, each increasingly bigger.
```
$ grep ARRAY /tmp/allocated.heap
{"address":"0x10fe2b3b8", "type":"ARRAY", "frozen":true, "length":92, "references":["0x10fcd3da8", "0x10fcca2a8", "0x10fcc21c0", ...], "file":"<internal:/opt/rubies/3.1.0/lib/ruby/3.1.0/rubygems/core_ext/kernel_require.rb>", "line":85, "method":"require", "generation":13, "memsize":776, "flags":{"wb_protected":true}}
...
{"address":"0x10fe2b688", "type":"ARRAY", "frozen":true, "length":91, "references":["0x10fcd3da8", "0x10fcca2a8", "0x10fcc21c0", ...], "file":"<internal:/opt/rubies/3.1.0/lib/ruby/3.1.0/rubygems/core_ext/kernel_require.rb>", "line":85, "method":"require", "generation":13, "memsize":768, "flags":{"wb_protected":true}}
...
{"address":"0x10fe2b958", "type":"ARRAY", "frozen":true, "length":89, "references":["0x10fcd3da8", "0x10fcca2a8", "0x10fcc21c0", ...], "file":"<internal:/opt/rubies/3.1.0/lib/ruby/3.1.0/rubygems/core_ext/kernel_require.rb>", "line":85, "method":"require", "generation":13, "memsize":752, "flags":{"wb_protected":true}}
...
{"address":"0x10fe2bc28", "type":"ARRAY", "frozen":true, "length":88, "references":["0x10fcd3da8", "0x10fcca2a8", "0x10fcc21c0", ...], "file":"<internal:/opt/rubies/3.1.0/lib/ruby/3.1.0/rubygems/core_ext/kernel_require.rb>", "line":85, "method":"require", "generation":13, "memsize":744, "flags":{"wb_protected":true}}
...
```
And if you lookup the addresses in `full.heap`, it makes no doubt that it's `$LOADED_FEATURES`.
Note however how the array is `"frozen":true`, so it's not `$LOADED_FEATURES` directly, but the shared array that backs `vm->loaded_features` and `vm->loaded_features_snapshot`.
### More scoped reproduction
If we scope on shared arrays behavior specifically, we can get a much smaller reproduction:
```ruby
array = 10.times.to_a
copy = array.dup
before = GC.stat(:total_allocated_objects)
copy << 1
p GC.stat(:total_allocated_objects) - before # 1 on Ruby 3.1, 0 on 3.0 and older
```
In short, back in 3.0 and older, appending to a shared array wouldn't "unshare" the array, but starting in 3.1 it now does.
The problem being that `Kernel.require` heavily assumed this implementation detail:
```c
static void
reset_loaded_features_snapshot(rb_vm_t *vm)
{
rb_ary_replace(vm->loaded_features_snapshot, vm->loaded_features);
}
rb_provide_feature(rb_vm_t *vm, VALUE feature)
{
//...
get_loaded_features_index(vm);
rb_ary_push(features, rb_fstring(feature));
features_index_add(vm, feature, INT2FIX(RARRAY_LEN(features)-1));
reset_loaded_features_snapshot(vm);
}
```
`rb_provide_feature` first append to `$LOADED_FEATURES` and then resets `vm->loaded_features_snapshot` to be a shared copy of `$LOADED_FEATURES`.
--
https://bugs.ruby-lang.org/
^ permalink raw reply [flat|nested] 6+ messages in thread
end of thread, other threads:[~2022-11-13 8:08 UTC | newest]
Thread overview: 6+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2022-02-22 17:37 [ruby-core:107715] [Ruby master Bug#18599] `vm->loaded_features_snapshot` became very inefficient in Ruby 3.1 byroot (Jean Boussier)
2022-02-23 16:09 ` [ruby-core:107733] " byroot (Jean Boussier)
2022-02-23 17:05 ` [ruby-core:107734] " byroot (Jean Boussier)
2022-11-11 15:32 ` [ruby-core:110706] " thomthom (Thomas Thomassen)
2022-11-11 23:38 ` [ruby-core:110713] " byroot (Jean Boussier)
2022-11-13 8:08 ` [ruby-core:110735] " nagachika (Tomoyuki Chikanaga)
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for read-only IMAP folder(s) and NNTP newsgroup(s).