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

PERF: Recover marshaling dump/load performance #31827

Merged
merged 2 commits into from Feb 1, 2018

Conversation

Projects
None yet
7 participants
@kamipo
Member

kamipo commented Jan 30, 2018

This performance regression which is described in #30680 was caused by
f0ddf87 due to force materialized LazyAttributeHash.

Since 95b86e5, default proc has been removed in the class, so it is no
longer needed that force materialized.

Avoiding force materialized will recover marshaling dump/load
performance.

Benchmark:

https://gist.github.com/blimmer/1360ea51cd3147bae8aeb7c6d09bff17

Before:

it took 0.6248569069430232 seconds to unmarshal the objects

Total allocated: 38681544 bytes (530060 objects)

allocated memory by class
-----------------------------------
  12138848  Hash
  10542384  String
   7920000  ActiveModel::Attribute::Uninitialized
   5600000  ActiveModel::Attribute::FromDatabase
   1200000  Foo
    880000  ActiveModel::LazyAttributeHash
    400000  ActiveModel::AttributeSet
        80  Integer
        72  ActiveRecord::ConnectionAdapters::SQLite3Adapter::SQLite3Integer
        40  ActiveModel::Type::String
        40  ActiveRecord::Type::DateTime
        40  Object
        40  Range

allocated objects by class
-----------------------------------
    250052  String
    110000  ActiveModel::Attribute::Uninitialized
     70001  Hash
     70000  ActiveModel::Attribute::FromDatabase
     10000  ActiveModel::AttributeSet
     10000  ActiveModel::LazyAttributeHash
     10000  Foo
         2  Integer
         1  ActiveModel::Type::String
         1  ActiveRecord::ConnectionAdapters::SQLite3Adapter::SQLite3Integer
         1  ActiveRecord::Type::DateTime
         1  Object
         1  Range

After:

it took 0.1660824950085953 seconds to unmarshal the objects

Total allocated: 13883811 bytes (220090 objects)

allocated memory by class
-----------------------------------
   5743371  String
   4940008  Hash
   1200000  Foo
    880000  ActiveModel::LazyAttributeHash
    720000  Array
    400000  ActiveModel::AttributeSet
        80  ActiveModel::Attribute::FromDatabase
        80  Integer
        72  ActiveRecord::ConnectionAdapters::SQLite3Adapter::SQLite3Integer
        40  ActiveModel::Type::String
        40  ActiveModel::Type::Value
        40  ActiveRecord::Type::DateTime
        40  Object
        40  Range

allocated objects by class
-----------------------------------
    130077  String
     50004  Hash
     10000  ActiveModel::AttributeSet
     10000  ActiveModel::LazyAttributeHash
     10000  Array
     10000  Foo
         2  Integer
         1  ActiveModel::Attribute::FromDatabase
         1  ActiveModel::Type::String
         1  ActiveModel::Type::Value
         1  ActiveRecord::ConnectionAdapters::SQLite3Adapter::SQLite3Integer
         1  ActiveRecord::Type::DateTime
         1  Object
         1  Range

Fixes #30680.

PERF: Recover marshaling dump/load performance
This performance regression which is described in #30680 was caused by
f0ddf87 due to force materialized `LazyAttributeHash`.

Since 95b86e5, default proc has been removed in the class, so it is no
longer needed that force materialized.

Avoiding force materialized will recover marshaling dump/load
performance.

Benchmark:

https://gist.github.com/blimmer/1360ea51cd3147bae8aeb7c6d09bff17

Before:

```
it took 0.6248569069430232 seconds to unmarshal the objects

Total allocated: 38681544 bytes (530060 objects)

allocated memory by class
-----------------------------------
  12138848  Hash
  10542384  String
   7920000  ActiveModel::Attribute::Uninitialized
   5600000  ActiveModel::Attribute::FromDatabase
   1200000  Foo
    880000  ActiveModel::LazyAttributeHash
    400000  ActiveModel::AttributeSet
        80  Integer
        72  ActiveRecord::ConnectionAdapters::SQLite3Adapter::SQLite3Integer
        40  ActiveModel::Type::String
        40  ActiveRecord::Type::DateTime
        40  Object
        40  Range

allocated objects by class
-----------------------------------
    250052  String
    110000  ActiveModel::Attribute::Uninitialized
     70001  Hash
     70000  ActiveModel::Attribute::FromDatabase
     10000  ActiveModel::AttributeSet
     10000  ActiveModel::LazyAttributeHash
     10000  Foo
         2  Integer
         1  ActiveModel::Type::String
         1  ActiveRecord::ConnectionAdapters::SQLite3Adapter::SQLite3Integer
         1  ActiveRecord::Type::DateTime
         1  Object
         1  Range
```

After:

```
it took 0.1660824950085953 seconds to unmarshal the objects

Total allocated: 13883811 bytes (220090 objects)

allocated memory by class
-----------------------------------
   5743371  String
   4940008  Hash
   1200000  Foo
    880000  ActiveModel::LazyAttributeHash
    720000  Array
    400000  ActiveModel::AttributeSet
        80  ActiveModel::Attribute::FromDatabase
        80  Integer
        72  ActiveRecord::ConnectionAdapters::SQLite3Adapter::SQLite3Integer
        40  ActiveModel::Type::String
        40  ActiveModel::Type::Value
        40  ActiveRecord::Type::DateTime
        40  Object
        40  Range

allocated objects by class
-----------------------------------
    130077  String
     50004  Hash
     10000  ActiveModel::AttributeSet
     10000  ActiveModel::LazyAttributeHash
     10000  Array
     10000  Foo
         2  Integer
         1  ActiveModel::Attribute::FromDatabase
         1  ActiveModel::Type::String
         1  ActiveModel::Type::Value
         1  ActiveRecord::ConnectionAdapters::SQLite3Adapter::SQLite3Integer
         1  ActiveRecord::Type::DateTime
         1  Object
         1  Range
```

Fixes #30680.

@kamipo kamipo added the activerecord label Jan 30, 2018

@kaspth

kaspth approved these changes Jan 30, 2018

Lets backport to 5.1 too 👍

@rafaelfranca

@sgrif are you fine with this approach?

@sgrif

sgrif approved these changes Jan 30, 2018

if @materialized
materialize
else
[@types, @values, @additional_types, @default_attributes]

This comment has been minimized.

@sgrif

sgrif Jan 30, 2018

Member

This will lose any mutations that have been made to the record. Can we just stick @delegate_hash in here and lose the materialized branch entirely?

@@ -76,15 +76,17 @@ def ==(other)
end
def marshal_dump
materialize
[@types, @values, @additional_types, @default_attributes, @delegate_hash]

This comment has been minimized.

@kamipo

kamipo Feb 1, 2018

Member

This will lose any mutations that have been made to the record. Can we just stick @delegate_hash in here and lose the materialized branch entirely?

Good point... I've fixed in 7c7e7b7.

@values = {}
@additional_types = {}
empty_hash = {}.freeze
initialize(empty_hash, empty_hash, empty_hash, empty_hash, values)
@materialized = true
else

This comment has been minimized.

@sgrif

sgrif Feb 1, 2018

Member

It seems like we only need the else branch here, don't we?

This comment has been minimized.

@sgrif

sgrif Feb 1, 2018

Member

Ah I see -- compatibility with old marshaled values.

@sgrif

sgrif approved these changes Feb 1, 2018

@kamipo kamipo merged commit 8f2bb58 into rails:master Feb 1, 2018

1 of 2 checks passed

continuous-integration/travis-ci/pr The Travis CI build failed
Details
codeclimate All good!
Details

@kamipo kamipo deleted the kamipo:recover_marshaling_performance branch Feb 1, 2018

@blimmer

This comment has been minimized.

blimmer commented Feb 1, 2018

Wow, thank you very much for this. Really appreciated.

@kaspth you mentioned that this will be backported to 5.1, but any chance of it getting backported to 5.0 as well since that's where the performance regression was introduced? The reason I ask is because we can pretty easily upgrade to 5.0.x with the existing work I had done on our application, but 5.1 takes a bit more work and the community usually recommends going up "one step at a time".

Thanks for the consideration and, again, thank you very much for taking the time to address this.

@kaspth

This comment has been minimized.

Member

kaspth commented Feb 4, 2018

@kamipo thoughts on 👆?

@kamipo

This comment has been minimized.

Member

kamipo commented Feb 5, 2018

Yeah, I'll backport this to 5-0-stable as well in this case since the performance regression was introduced by backporting #25949.

kamipo added a commit that referenced this pull request Feb 5, 2018

PERF: Recover marshaling dump/load performance (#31827)
* PERF: Recover marshaling dump/load performance

This performance regression which is described in #30680 was caused by
f0ddf87 due to force materialized `LazyAttributeHash`.

Since 95b86e5, default proc has been removed in the class, so it is no
longer needed that force materialized.

Avoiding force materialized will recover marshaling dump/load
performance.

Benchmark:

https://gist.github.com/blimmer/1360ea51cd3147bae8aeb7c6d09bff17

Before:

```
it took 0.6248569069430232 seconds to unmarshal the objects

Total allocated: 38681544 bytes (530060 objects)

allocated memory by class
-----------------------------------
  12138848  Hash
  10542384  String
   7920000  ActiveModel::Attribute::Uninitialized
   5600000  ActiveModel::Attribute::FromDatabase
   1200000  Foo
    880000  ActiveModel::LazyAttributeHash
    400000  ActiveModel::AttributeSet
        80  Integer
        72  ActiveRecord::ConnectionAdapters::SQLite3Adapter::SQLite3Integer
        40  ActiveModel::Type::String
        40  ActiveRecord::Type::DateTime
        40  Object
        40  Range

allocated objects by class
-----------------------------------
    250052  String
    110000  ActiveModel::Attribute::Uninitialized
     70001  Hash
     70000  ActiveModel::Attribute::FromDatabase
     10000  ActiveModel::AttributeSet
     10000  ActiveModel::LazyAttributeHash
     10000  Foo
         2  Integer
         1  ActiveModel::Type::String
         1  ActiveRecord::ConnectionAdapters::SQLite3Adapter::SQLite3Integer
         1  ActiveRecord::Type::DateTime
         1  Object
         1  Range
```

After:

```
it took 0.1660824950085953 seconds to unmarshal the objects

Total allocated: 13883811 bytes (220090 objects)

allocated memory by class
-----------------------------------
   5743371  String
   4940008  Hash
   1200000  Foo
    880000  ActiveModel::LazyAttributeHash
    720000  Array
    400000  ActiveModel::AttributeSet
        80  ActiveModel::Attribute::FromDatabase
        80  Integer
        72  ActiveRecord::ConnectionAdapters::SQLite3Adapter::SQLite3Integer
        40  ActiveModel::Type::String
        40  ActiveModel::Type::Value
        40  ActiveRecord::Type::DateTime
        40  Object
        40  Range

allocated objects by class
-----------------------------------
    130077  String
     50004  Hash
     10000  ActiveModel::AttributeSet
     10000  ActiveModel::LazyAttributeHash
     10000  Array
     10000  Foo
         2  Integer
         1  ActiveModel::Attribute::FromDatabase
         1  ActiveModel::Type::String
         1  ActiveModel::Type::Value
         1  ActiveRecord::ConnectionAdapters::SQLite3Adapter::SQLite3Integer
         1  ActiveRecord::Type::DateTime
         1  Object
         1  Range
```

Fixes #30680.

* Keep the `@delegate_hash` to avoid to lose any mutations that have been made to the record

kamipo added a commit to kamipo/rails that referenced this pull request Feb 5, 2018

PERF: Recover marshaling dump/load performance (rails#31827)
* PERF: Recover marshaling dump/load performance

This performance regression which is described in rails#30680 was caused by
f0ddf87 due to force materialized `LazyAttributeHash`.

Since 95b86e5, default proc has been removed in the class, so it is no
longer needed that force materialized.

Avoiding force materialized will recover marshaling dump/load
performance.

Benchmark:

https://gist.github.com/blimmer/1360ea51cd3147bae8aeb7c6d09bff17

Before:

```
it took 0.6248569069430232 seconds to unmarshal the objects

Total allocated: 38681544 bytes (530060 objects)

allocated memory by class
-----------------------------------
  12138848  Hash
  10542384  String
   7920000  ActiveModel::Attribute::Uninitialized
   5600000  ActiveModel::Attribute::FromDatabase
   1200000  Foo
    880000  ActiveModel::LazyAttributeHash
    400000  ActiveModel::AttributeSet
        80  Integer
        72  ActiveRecord::ConnectionAdapters::SQLite3Adapter::SQLite3Integer
        40  ActiveModel::Type::String
        40  ActiveRecord::Type::DateTime
        40  Object
        40  Range

allocated objects by class
-----------------------------------
    250052  String
    110000  ActiveModel::Attribute::Uninitialized
     70001  Hash
     70000  ActiveModel::Attribute::FromDatabase
     10000  ActiveModel::AttributeSet
     10000  ActiveModel::LazyAttributeHash
     10000  Foo
         2  Integer
         1  ActiveModel::Type::String
         1  ActiveRecord::ConnectionAdapters::SQLite3Adapter::SQLite3Integer
         1  ActiveRecord::Type::DateTime
         1  Object
         1  Range
```

After:

```
it took 0.1660824950085953 seconds to unmarshal the objects

Total allocated: 13883811 bytes (220090 objects)

allocated memory by class
-----------------------------------
   5743371  String
   4940008  Hash
   1200000  Foo
    880000  ActiveModel::LazyAttributeHash
    720000  Array
    400000  ActiveModel::AttributeSet
        80  ActiveModel::Attribute::FromDatabase
        80  Integer
        72  ActiveRecord::ConnectionAdapters::SQLite3Adapter::SQLite3Integer
        40  ActiveModel::Type::String
        40  ActiveModel::Type::Value
        40  ActiveRecord::Type::DateTime
        40  Object
        40  Range

allocated objects by class
-----------------------------------
    130077  String
     50004  Hash
     10000  ActiveModel::AttributeSet
     10000  ActiveModel::LazyAttributeHash
     10000  Array
     10000  Foo
         2  Integer
         1  ActiveModel::Attribute::FromDatabase
         1  ActiveModel::Type::String
         1  ActiveModel::Type::Value
         1  ActiveRecord::ConnectionAdapters::SQLite3Adapter::SQLite3Integer
         1  ActiveRecord::Type::DateTime
         1  Object
         1  Range
```

Fixes rails#30680.

* Keep the `@delegate_hash` to avoid to lose any mutations that have been made to the record
@sgrif

This comment has been minimized.

Member

sgrif commented Feb 6, 2018

I don't think we should be backporting to a version which is only supposed to receive security fixes.

@carlosantoniodasilva

This comment has been minimized.

Member

carlosantoniodasilva commented Feb 6, 2018

I wouldn't mind backporting this to 5.0, part of it being personal need from an app still running on it, and also because I think it's in theory still part of the bug fix maintenance window, at least until 5.2 final is released, isn't it?

Thanks for the fix @kamipo!

@matthewd

This comment has been minimized.

Member

matthewd commented Feb 6, 2018

@carlosantoniodasilva officially only one (most recent) release is supported for bug fixes... but if you're happy to deal with any [probably unlikely] follow-on problems/regressions, go for it 👍

@carlosantoniodasilva

This comment has been minimized.

Member

carlosantoniodasilva commented Feb 6, 2018

Thanks @matthewd, I was mistaken then to say that 5.0 was still on for bug fixes. I did check the branch for backport activity and it seems to receive commits here and there, and as a side note, even though our maintenance page says "only the latest release series", it mentions "currently included series: 5.0.Z", which was unfortunately just the bit that I checked before commenting earlier. Will see about updating that page then.

@blimmer

This comment has been minimized.

blimmer commented Feb 7, 2018

@carlosantoniodasilva just to clarify the thread above, do you plan to backport to 5.0? Or should I look into how to monkeypatch on a fork we use until we can get up to 5.1?

Thanks!

@rafaelfranca

This comment has been minimized.

Member

rafaelfranca commented Feb 7, 2018

5.0 is still supported (this is why it is in the page). I'm supporting it, but I was planing to the next release to be the last one. I'm fine with backporting this fix.

@rafaelfranca

This comment has been minimized.

Member

rafaelfranca commented Feb 7, 2018

@kamipo can you apply the patch to 5-0-stable please?

@kamipo

This comment has been minimized.

Member

kamipo commented Feb 9, 2018

Sure, I will do that.

@carlosantoniodasilva

This comment has been minimized.

Member

carlosantoniodasilva commented Feb 10, 2018

kamipo added a commit to kamipo/rails that referenced this pull request Feb 18, 2018

PERF: Recover marshaling dump/load performance (rails#31827)
* PERF: Recover marshaling dump/load performance

This performance regression which is described in rails#30680 was caused by
f0ddf87 due to force materialized `LazyAttributeHash`.

Since 95b86e5, default proc has been removed in the class, so it is no
longer needed that force materialized.

Avoiding force materialized will recover marshaling dump/load
performance.

Benchmark:

https://gist.github.com/blimmer/1360ea51cd3147bae8aeb7c6d09bff17

Before:

```
it took 0.6248569069430232 seconds to unmarshal the objects

Total allocated: 38681544 bytes (530060 objects)

allocated memory by class
-----------------------------------
  12138848  Hash
  10542384  String
   7920000  ActiveModel::Attribute::Uninitialized
   5600000  ActiveModel::Attribute::FromDatabase
   1200000  Foo
    880000  ActiveModel::LazyAttributeHash
    400000  ActiveModel::AttributeSet
        80  Integer
        72  ActiveRecord::ConnectionAdapters::SQLite3Adapter::SQLite3Integer
        40  ActiveModel::Type::String
        40  ActiveRecord::Type::DateTime
        40  Object
        40  Range

allocated objects by class
-----------------------------------
    250052  String
    110000  ActiveModel::Attribute::Uninitialized
     70001  Hash
     70000  ActiveModel::Attribute::FromDatabase
     10000  ActiveModel::AttributeSet
     10000  ActiveModel::LazyAttributeHash
     10000  Foo
         2  Integer
         1  ActiveModel::Type::String
         1  ActiveRecord::ConnectionAdapters::SQLite3Adapter::SQLite3Integer
         1  ActiveRecord::Type::DateTime
         1  Object
         1  Range
```

After:

```
it took 0.1660824950085953 seconds to unmarshal the objects

Total allocated: 13883811 bytes (220090 objects)

allocated memory by class
-----------------------------------
   5743371  String
   4940008  Hash
   1200000  Foo
    880000  ActiveModel::LazyAttributeHash
    720000  Array
    400000  ActiveModel::AttributeSet
        80  ActiveModel::Attribute::FromDatabase
        80  Integer
        72  ActiveRecord::ConnectionAdapters::SQLite3Adapter::SQLite3Integer
        40  ActiveModel::Type::String
        40  ActiveModel::Type::Value
        40  ActiveRecord::Type::DateTime
        40  Object
        40  Range

allocated objects by class
-----------------------------------
    130077  String
     50004  Hash
     10000  ActiveModel::AttributeSet
     10000  ActiveModel::LazyAttributeHash
     10000  Array
     10000  Foo
         2  Integer
         1  ActiveModel::Attribute::FromDatabase
         1  ActiveModel::Type::String
         1  ActiveModel::Type::Value
         1  ActiveRecord::ConnectionAdapters::SQLite3Adapter::SQLite3Integer
         1  ActiveRecord::Type::DateTime
         1  Object
         1  Range
```

Fixes rails#30680.

* Keep the `@delegate_hash` to avoid to lose any mutations that have been made to the record

jhocc pushed a commit to Casecommons/rails that referenced this pull request Mar 26, 2018

PERF: Recover marshaling dump/load performance (rails#31827)
* PERF: Recover marshaling dump/load performance

This performance regression which is described in rails#30680 was caused by
f0ddf87 due to force materialized `LazyAttributeHash`.

Since 95b86e5, default proc has been removed in the class, so it is no
longer needed that force materialized.

Avoiding force materialized will recover marshaling dump/load
performance.

Benchmark:

https://gist.github.com/blimmer/1360ea51cd3147bae8aeb7c6d09bff17

Before:

```
it took 0.6248569069430232 seconds to unmarshal the objects

Total allocated: 38681544 bytes (530060 objects)

allocated memory by class
-----------------------------------
  12138848  Hash
  10542384  String
   7920000  ActiveModel::Attribute::Uninitialized
   5600000  ActiveModel::Attribute::FromDatabase
   1200000  Foo
    880000  ActiveModel::LazyAttributeHash
    400000  ActiveModel::AttributeSet
        80  Integer
        72  ActiveRecord::ConnectionAdapters::SQLite3Adapter::SQLite3Integer
        40  ActiveModel::Type::String
        40  ActiveRecord::Type::DateTime
        40  Object
        40  Range

allocated objects by class
-----------------------------------
    250052  String
    110000  ActiveModel::Attribute::Uninitialized
     70001  Hash
     70000  ActiveModel::Attribute::FromDatabase
     10000  ActiveModel::AttributeSet
     10000  ActiveModel::LazyAttributeHash
     10000  Foo
         2  Integer
         1  ActiveModel::Type::String
         1  ActiveRecord::ConnectionAdapters::SQLite3Adapter::SQLite3Integer
         1  ActiveRecord::Type::DateTime
         1  Object
         1  Range
```

After:

```
it took 0.1660824950085953 seconds to unmarshal the objects

Total allocated: 13883811 bytes (220090 objects)

allocated memory by class
-----------------------------------
   5743371  String
   4940008  Hash
   1200000  Foo
    880000  ActiveModel::LazyAttributeHash
    720000  Array
    400000  ActiveModel::AttributeSet
        80  ActiveModel::Attribute::FromDatabase
        80  Integer
        72  ActiveRecord::ConnectionAdapters::SQLite3Adapter::SQLite3Integer
        40  ActiveModel::Type::String
        40  ActiveModel::Type::Value
        40  ActiveRecord::Type::DateTime
        40  Object
        40  Range

allocated objects by class
-----------------------------------
    130077  String
     50004  Hash
     10000  ActiveModel::AttributeSet
     10000  ActiveModel::LazyAttributeHash
     10000  Array
     10000  Foo
         2  Integer
         1  ActiveModel::Attribute::FromDatabase
         1  ActiveModel::Type::String
         1  ActiveModel::Type::Value
         1  ActiveRecord::ConnectionAdapters::SQLite3Adapter::SQLite3Integer
         1  ActiveRecord::Type::DateTime
         1  Object
         1  Range
```

Fixes rails#30680.

* Keep the `@delegate_hash` to avoid to lose any mutations that have been made to the record
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment