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

Rails 5 ActiveRecord::Attribute stack level too deep error on save #26122

Closed
johnathanludwig opened this Issue Aug 11, 2016 · 8 comments

Comments

Projects
None yet
7 participants
@johnathanludwig
Copy link

johnathanludwig commented Aug 11, 2016

If you make a lot of assignments to an ActiveRecord object, you will get a a SystemStackError during save. In our case we are calculating some stats on reports we generate by incrementing various counters. In some cases we have large reports where one field could be incremented more than 10k times.

Steps to reproduce

  1. Make an assignment on the same attribute of an object at least 10,050 times.
  2. Attempt to save the object.

Expected behavior

The object should be saved.

Actual behavior

A stack level too deep error is raised. Here is the trace:

SystemStackError: stack level too deep
activerecord-5.0.0/lib/active_record/attribute.rb:44:in `original_value'
activerecord-5.0.0/lib/active_record/attribute.rb:44:in `original_value'
... 10027 levels...
activerecord-5.0.0/lib/active_record/attribute.rb:44:in `original_value'
activerecord-5.0.0/lib/active_record/attribute.rb:123:in `changed_from_assignment?'
activerecord-5.0.0/lib/active_record/attribute.rb:55:in `changed?'
activerecord-5.0.0/lib/active_record/attribute_mutation_tracker.rb:25:in `changed?'
activerecord-5.0.0/lib/active_record/attribute_mutation_tracker.rb:9:in `block in changed_values'
activerecord-5.0.0/lib/active_record/attribute_mutation_tracker.rb:8:in `each'
activerecord-5.0.0/lib/active_record/attribute_mutation_tracker.rb:8:in `each_with_object'
activerecord-5.0.0/lib/active_record/attribute_mutation_tracker.rb:8:in `changed_values'
activerecord-5.0.0/lib/active_record/attribute_methods/dirty.rb:83:in `changed_attributes'
activemodel-5.0.0/lib/active_model/dirty.rb:146:in `changed'
activerecord-5.0.0/lib/active_record/attribute_methods/dirty.rb:127:in `keys_for_partial_write'
activerecord-5.0.0/lib/active_record/attribute_methods/dirty.rb:123:in `_create_record'
activerecord-5.0.0/lib/active_record/callbacks.rb:302:in `block in _create_record'
activesupport-5.0.0/lib/active_support/callbacks.rb:126:in `call'
activesupport-5.0.0/lib/active_support/callbacks.rb:126:in `call'
activesupport-5.0.0/lib/active_support/callbacks.rb:506:in `block (2 levels) in compile'
activesupport-5.0.0/lib/active_support/callbacks.rb:455:in `call'
activesupport-5.0.0/lib/active_support/callbacks.rb:455:in `call'
activesupport-5.0.0/lib/active_support/callbacks.rb:101:in `__run_callbacks__'
activesupport-5.0.0/lib/active_support/callbacks.rb:750:in `_run_create_callbacks'
activerecord-5.0.0/lib/active_record/callbacks.rb:302:in `_create_record'
activerecord-5.0.0/lib/active_record/timestamp.rb:68:in `_create_record'
activerecord-5.0.0/lib/active_record/persistence.rb:534:in `create_or_update'
activerecord-5.0.0/lib/active_record/callbacks.rb:298:in `block in create_or_update'
activesupport-5.0.0/lib/active_support/callbacks.rb:126:in `call'
activesupport-5.0.0/lib/active_support/callbacks.rb:126:in `call'
activesupport-5.0.0/lib/active_support/callbacks.rb:506:in `block (2 levels) in compile'
activesupport-5.0.0/lib/active_support/callbacks.rb:455:in `call'
activesupport-5.0.0/lib/active_support/callbacks.rb:455:in `call'
activesupport-5.0.0/lib/active_support/callbacks.rb:101:in `__run_callbacks__'
activesupport-5.0.0/lib/active_support/callbacks.rb:750:in `_run_save_callbacks'
activerecord-5.0.0/lib/active_record/callbacks.rb:298:in `create_or_update'
activerecord-5.0.0/lib/active_record/persistence.rb:125:in `save'
activerecord-5.0.0/lib/active_record/validations.rb:44:in `save'
activerecord-5.0.0/lib/active_record/attribute_methods/dirty.rb:22:in `save'
activerecord-5.0.0/lib/active_record/transactions.rb:319:in `block (2 levels) in save'
activerecord-5.0.0/lib/active_record/transactions.rb:395:in `block in with_transaction_returning_status'
activerecord-5.0.0/lib/active_record/connection_adapters/abstract/database_statements.rb:232:in `block in transaction'
activerecord-5.0.0/lib/active_record/connection_adapters/abstract/transaction.rb:189:in `within_new_transaction'
activerecord-5.0.0/lib/active_record/connection_adapters/abstract/database_statements.rb:232:in `transaction'
activerecord-5.0.0/lib/active_record/transactions.rb:211:in `transaction'
activerecord-5.0.0/lib/active_record/transactions.rb:392:in `with_transaction_returning_status'
activerecord-5.0.0/lib/active_record/transactions.rb:319:in `block in save'
activerecord-5.0.0/lib/active_record/transactions.rb:334:in `rollback_active_record_state!'
activerecord-5.0.0/lib/active_record/transactions.rb:318:in `save'
activerecord-5.0.0/lib/active_record/suppressor.rb:41:in `save'

System configuration

Rails version: 5.0.0

Ruby version: 2.4.4

Test Case

begin
  require "bundler/inline"
rescue LoadError => e
  $stderr.puts "Bundler version 1.10 or later is required. Please update your Bundler"
  raise e
end

gemfile(true) do
  source "https://rubygems.org"
  gem "rails", github: "rails/rails"
  gem "sqlite3"
end

require "active_record"
require "minitest/autorun"
require "logger"

# This connection will do for database-independent bug reports.
ActiveRecord::Base.establish_connection(adapter: "sqlite3", database: ":memory:")
ActiveRecord::Base.logger = Logger.new(STDOUT)

ActiveRecord::Schema.define do
  create_table :stats, force: true do |t|
    t.integer :count, default: 0
  end
end

class Stat < ActiveRecord::Base
end

class BugTest < Minitest::Test
  def test_association_stuff
    stat = Stat.new

    10_050.times { stat.count += 1 }

    assert stat.save
  end
end
@prakashmurthy

This comment has been minimized.

Copy link
Contributor

prakashmurthy commented Aug 13, 2016

I am able to reproduce this behavior with the executable test case provided by @johnathanludwig in his comment above, with master branch. Though in my case, the error started happening after the counter was incremented 11_847 times.

The behavior does not happen with 4-2-stable.

From git bisect, it looks like the behavior was introduced by 07723c2 cc: @sgrif

@sgrif

This comment has been minimized.

Copy link
Member

sgrif commented Aug 14, 2016

So yes. This is a legitimate consequence of the current implementation. That said, I'm reasonably comfortable just saying: Don't assign the same attribute 10000+ times.

@sgrif sgrif closed this Aug 14, 2016

@olivierlacan

This comment has been minimized.

Copy link
Contributor

olivierlacan commented Aug 14, 2016

@sgrif Just because you haven't locked the issue yet and I have to ask, is this due to the whole tracking of changes made to attributes? 😈

Seems like a fairly reasonable caveat for such a crucial feature.

@tenderlove tenderlove reopened this Aug 14, 2016

tenderlove added a commit that referenced this issue Aug 14, 2016

@sgrif

This comment has been minimized.

Copy link
Member

sgrif commented Aug 14, 2016

I missed the proper use case in the original issue. Sorry for dismissing this.

@HollowerMan

This comment has been minimized.

Copy link

HollowerMan commented Feb 8, 2017

Just to mention that I also encountered the issue.

I solved it by saving the model regularly between attribue updates.

@sgrif

This comment has been minimized.

Copy link
Member

sgrif commented Feb 8, 2017

If you're still encountering this after 1317136 please open a new issue.

@johnathanludwig

This comment has been minimized.

Copy link
Author

johnathanludwig commented Feb 8, 2017

It wasn't in the patch notes, but 5.0.1 included @tenderlove's fix. It's working for me now.

@HollowerMan

This comment has been minimized.

Copy link

HollowerMan commented Feb 8, 2017

I can confirm this can not be reproduced with 5.0.1.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment