ruby-core@ruby-lang.org archive (unofficial mirror)
 help / color / mirror / Atom feed
* [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).