scenic-views / scenic

Versioned database views for Rails
https://thoughtbot.com/blog/announcing-scenic--versioned-database-views-for-rails
MIT License
3.41k stars 222 forks source link

Reverting breaks on Ruby 3 due to keyword changes, solution is relatively easy #331

Closed JoshCheek closed 2 years ago

JoshCheek commented 3 years ago

Hi 👋 so the way the command recorder methods record their result, cause the migrations to error when reverting a migration on Ruby 3. Eg here is a method that is incorrect:

https://github.com/scenic-views/scenic/blob/v1.5.4/lib/scenic/command_recorder.rb#L14-L16

module Scenic
  module CommandRecorder
    # ...
    def update_view(*args)
      record(:update_view, args)
    end
  end
end

After a lot of research (eg @eregon's blog here), I've come to the conclusion that the way to fix this across all the relevant Ruby versions is to conditionally use ruby2_keywords:

module Scenic
  module CommandRecorder
    # ...
    def update_view(*args)
      record(:update_view, args)
    end
+   ruby2_keywords : update_view if respond_to?(:ruby2_keywords, true)
  end
end

There's a lot of additional detail in (this) bug in ActiveRecord, where I initially reported it.

But you can run the test suite on 2.7 with env RUBYOPT=-W:deprecated rake and it will emit warnings where this error occurs. In Ruby 3 , each of those warnings actually explodes. It's pretty confusing to trace them back to Scenic's definition

env RUBYOPT=-W:deprecated rake

Or you can run it on Ruby 3, it will actually fail in those spots 😜

image
gsar commented 3 years ago

@JoshCheek thanks for that investigation! i'm also running into this problem with replace_view. i tried monkey-patching Scenic::CommandRecorder but it doesn't seem to help. is the problem actually in rails? the backtrace below would seem to suggest that the rails method_missing in lib/active_record/migration.rb is doing the forwarding.

$ rake --backtrace db:rollback
ruby/3.0.1 isn't supported by this pry-doc version
== 20210706002815 UpdateEtlViewProfilesToVersion2: reverting ==================
-- replace_view(:etl_view_profiles, {:version=>1})
rake aborted!
StandardError: An error has occurred, this and all later migrations canceled:

wrong number of arguments (given 2, expected 1)
/Users/gsar/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/scenic-1.5.4/lib/scenic/statements.rb:135:in `replace_view'
/Users/gsar/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/activerecord-6.1.3.2/lib/active_record/migration.rb:929:in `block in method_missing'
/Users/gsar/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/activerecord-6.1.3.2/lib/active_record/migration.rb:897:in `block in say_with_time'
/Users/gsar/.rbenv/versions/3.0.1/lib/ruby/3.0.0/benchmark.rb:293:in `measure'
/Users/gsar/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/activerecord-6.1.3.2/lib/active_record/migration.rb:897:in `say_with_time'
/Users/gsar/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/activerecord-6.1.3.2/lib/active_record/migration.rb:918:in `method_missing'
/Users/gsar/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/activerecord-6.1.3.2/lib/active_record/migration/command_recorder.rb:126:in `block in replay'
/Users/gsar/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/activerecord-6.1.3.2/lib/active_record/migration/command_recorder.rb:125:in `each'
/Users/gsar/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/activerecord-6.1.3.2/lib/active_record/migration/command_recorder.rb:125:in `replay'
/Users/gsar/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/activerecord-6.1.3.2/lib/active_record/migration.rb:741:in `revert'
/Users/gsar/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/activerecord-6.1.3.2/lib/active_record/migration.rb:865:in `exec_migration'
/Users/gsar/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/activerecord-6.1.3.2/lib/active_record/migration.rb:851:in `block (2 levels) in migrate'
/Users/gsar/.rbenv/versions/3.0.1/lib/ruby/3.0.0/benchmark.rb:293:in `measure'
/Users/gsar/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/activerecord-6.1.3.2/lib/active_record/migration.rb:850:in `block in migrate'
/Users/gsar/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/activerecord-6.1.3.2/lib/active_record/connection_adapters/abstract/connection_pool.rb:462:in `with_connection'
/Users/gsar/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/activerecord-6.1.3.2/lib/active_record/migration.rb:849:in `migrate'
/Users/gsar/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/activerecord-6.1.3.2/lib/active_record/migration.rb:1037:in `migrate'
/Users/gsar/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/activerecord-6.1.3.2/lib/active_record/migration.rb:1329:in `block in execute_migration_in_transaction'
/Users/gsar/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/activerecord-6.1.3.2/lib/active_record/migration.rb:1380:in `block in ddl_transaction'
/Users/gsar/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/activerecord-6.1.3.2/lib/active_record/connection_adapters/abstract/database_statements.rb:320:in `block in transaction'
/Users/gsar/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/activerecord-6.1.3.2/lib/active_record/connection_adapters/abstract/transaction.rb:310:in `block in within_new_transaction'
eregon commented 3 years ago

That method_missing uses ruby2_keywords in https://github.com/rails/rails/blob/d305be07428a8e86e2736b57f839680c9e970293/activerecord/lib/active_record/migration.rb#L917-L934, so on rails master it seems fine at least and not the cause.

JoshCheek commented 3 years ago

@JoshCheek thanks for that investigation! i'm also running into this problem with replace_view. i tried monkey-patching Scenic::CommandRecorder but it doesn't seem to help. is the problem actually in rails? the backtrace below would seem to suggest that the rails method_missing in lib/active_record/migration.rb is doing the forwarding.

$ rake --backtrace db:rollback
ruby/3.0.1 isn't supported by this pry-doc version
== 20210706002815 UpdateEtlViewProfilesToVersion2: reverting ==================
-- replace_view(:etl_view_profiles, {:version=>1})
rake aborted!
StandardError: An error has occurred, this and all later migrations canceled:

wrong number of arguments (given 2, expected 1)
/Users/gsar/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/scenic-1.5.4/lib/scenic/statements.rb:135:in `replace_view'
/Users/gsar/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/activerecord-6.1.3.2/lib/active_record/migration.rb:929:in `block in method_missing'
/Users/gsar/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/activerecord-6.1.3.2/lib/active_record/migration.rb:897:in `block in say_with_time'
/Users/gsar/.rbenv/versions/3.0.1/lib/ruby/3.0.0/benchmark.rb:293:in `measure'
/Users/gsar/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/activerecord-6.1.3.2/lib/active_record/migration.rb:897:in `say_with_time'
/Users/gsar/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/activerecord-6.1.3.2/lib/active_record/migration.rb:918:in `method_missing'
/Users/gsar/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/activerecord-6.1.3.2/lib/active_record/migration/command_recorder.rb:126:in `block in replay'
/Users/gsar/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/activerecord-6.1.3.2/lib/active_record/migration/command_recorder.rb:125:in `each'
/Users/gsar/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/activerecord-6.1.3.2/lib/active_record/migration/command_recorder.rb:125:in `replay'
/Users/gsar/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/activerecord-6.1.3.2/lib/active_record/migration.rb:741:in `revert'
/Users/gsar/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/activerecord-6.1.3.2/lib/active_record/migration.rb:865:in `exec_migration'
/Users/gsar/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/activerecord-6.1.3.2/lib/active_record/migration.rb:851:in `block (2 levels) in migrate'
/Users/gsar/.rbenv/versions/3.0.1/lib/ruby/3.0.0/benchmark.rb:293:in `measure'
/Users/gsar/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/activerecord-6.1.3.2/lib/active_record/migration.rb:850:in `block in migrate'
/Users/gsar/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/activerecord-6.1.3.2/lib/active_record/connection_adapters/abstract/connection_pool.rb:462:in `with_connection'
/Users/gsar/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/activerecord-6.1.3.2/lib/active_record/migration.rb:849:in `migrate'
/Users/gsar/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/activerecord-6.1.3.2/lib/active_record/migration.rb:1037:in `migrate'
/Users/gsar/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/activerecord-6.1.3.2/lib/active_record/migration.rb:1329:in `block in execute_migration_in_transaction'
/Users/gsar/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/activerecord-6.1.3.2/lib/active_record/migration.rb:1380:in `block in ddl_transaction'
/Users/gsar/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/activerecord-6.1.3.2/lib/active_record/connection_adapters/abstract/database_statements.rb:320:in `block in transaction'
/Users/gsar/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/activerecord-6.1.3.2/lib/active_record/connection_adapters/abstract/transaction.rb:310:in `block in within_new_transaction'

It's not in Rails, I thought the same thing and opened a bug report there, but that's not where it is. Based on that backtrace, and what I figured out, I'd expect the incorrect method definition is here.

In your migration, try adding ruby2_keywords to it:

module Scenic::CommandRecorder
  ruby2_keywords :replace_view if respond_to?(:ruby2_keywords, true)
end

class MyMigration < ActiveRecord::Migration[6.1]
  def change
    # ...
  end
end

If you try it, can you reply back with whether it works or not? It would be a good way to confirm what I expect.

gsar commented 3 years ago

@JoshCheek i can confirm that it still fails the rollback with this in the migration file:

module Scenic::CommandRecorder
  ruby2_keywords :update_view
end

class UpdateEtlViewUsersToVersion2 < ActiveRecord::Migration[6.1]
  def change
    update_view :etl_view_users, version: 2, revert_to_version: 1
  end
end
$ rake --backtrace db:migrate:up VERSION=20210706000231
== 20210706000231 UpdateEtlViewUsersToVersion2: migrating =====================
-- update_view(:etl_view_users, {:version=>2, :revert_to_version=>1})
   -> 0.0158s
== 20210706000231 UpdateEtlViewUsersToVersion2: migrated (0.0159s) ============

$ rake --backtrace db:migrate:down VERSION=20210706000231
== 20210706000231 UpdateEtlViewUsersToVersion2: reverting =====================
-- update_view(:etl_view_users, {:version=>1})
rake aborted!
StandardError: An error has occurred, this and all later migrations canceled:

wrong number of arguments (given 2, expected 1)
/Users/gsar/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/scenic-1.5.4/lib/scenic/statements.rb:91:in `update_view'
/Users/gsar/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/activerecord-6.1.3.2/lib/active_record/migration.rb:929:in `block in method_missing'
/Users/gsar/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/activerecord-6.1.3.2/lib/active_record/migration.rb:897:in `block in say_with_time'
/Users/gsar/.rbenv/versions/3.0.1/lib/ruby/3.0.0/benchmark.rb:293:in `measure'
/Users/gsar/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/activerecord-6.1.3.2/lib/active_record/migration.rb:897:in `say_with_time'
/Users/gsar/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/activerecord-6.1.3.2/lib/active_record/migration.rb:918:in `method_missing'
/Users/gsar/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/activerecord-6.1.3.2/lib/active_record/migration/command_recorder.rb:126:in `block in replay'
/Users/gsar/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/activerecord-6.1.3.2/lib/active_record/migration/command_recorder.rb:125:in `each'
/Users/gsar/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/activerecord-6.1.3.2/lib/active_record/migration/command_recorder.rb:125:in `replay'
/Users/gsar/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/activerecord-6.1.3.2/lib/active_record/migration.rb:741:in `revert'
/Users/gsar/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/activerecord-6.1.3.2/lib/active_record/migration.rb:865:in `exec_migration'
/Users/gsar/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/activerecord-6.1.3.2/lib/active_record/migration.rb:851:in `block (2 levels) in migrate'
/Users/gsar/.rbenv/versions/3.0.1/lib/ruby/3.0.0/benchmark.rb:293:in `measure'
/Users/gsar/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/activerecord-6.1.3.2/lib/active_record/migration.rb:850:in `block in migrate'
/Users/gsar/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/activerecord-6.1.3.2/lib/active_record/connection_adapters/abstract/connection_pool.rb:462:in `w
ith_connection'
/Users/gsar/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/activerecord-6.1.3.2/lib/active_record/migration.rb:849:in `migrate'
/Users/gsar/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/activerecord-6.1.3.2/lib/active_record/migration.rb:1037:in `migrate'

To work around the problem, it suffices to avoid the change migration and do an up/down instead (note this works even without ruby2_keywords), presumably because it doesn't have to infer the down migration?

class UpdateEtlViewUsersToVersion2 < ActiveRecord::Migration[6.1]
  def up
    update_view :etl_view_users, version: 2
  end

  def down
    update_view :etl_view_users, version: 1
  end
end
$ rake --backtrace db:migrate:up VERSION=20210706000231
== 20210706000231 UpdateEtlViewUsersToVersion2: migrating =====================
-- update_view(:etl_view_users, {:version=>2})
   -> 0.0157s
== 20210706000231 UpdateEtlViewUsersToVersion2: migrated (0.0159s) ============

$ rake --backtrace db:migrate:down VERSION=20210706000231
== 20210706000231 UpdateEtlViewUsersToVersion2: reverting =====================
-- update_view(:etl_view_users, {:version=>1})
   -> 0.0174s
== 20210706000231 UpdateEtlViewUsersToVersion2: reverted (0.0176s) ============
JoshCheek commented 3 years ago

Hmmm 🤔 well... perhaps I've misanalyzed it, then 😖

rdlugosz commented 2 years ago

UPDATE - I've determined the crash in my app was being caused by the zero_downtime_migrations gem, even though it looked like Scenic 1.5.5 was to blame based on the backtrace. There is a bug open over there about this, along with a PR.

--

Hi - it appears this should be fixed with v 1.5.5, yet I'm still seeing this error when trying to update a view. Ruby 3.0.3, Rails 6.1.4.4, Scenic 1.5.5

$ bin/rails db:migrate --backtrace
Running via Spring preloader in process 39688
== 20220113171405 UpdatePreciselyNeighborhoodsToVersion3: migrating ===========
-- update_view(:precisely_neighborhoods, {:version=>3, :revert_to_version=>2})
rake aborted!
StandardError: An error has occurred, this and all later migrations canceled:

wrong number of arguments (given 2, expected 1)
/Users/ryan/.rbenv/versions/3.0.3/lib/ruby/gems/3.0.0/gems/scenic-1.5.5/lib/scenic/statements.rb:91:in `update_view'
/Users/ryan/.rbenv/versions/3.0.3/lib/ruby/gems/3.0.0/gems/activerecord-6.1.4.4/lib/active_record/migration.rb:929:in `block in method_missing'
...

Migration:

class UpdatePreciselyNeighborhoodsToVersion3 < ActiveRecord::Migration[6.1]
  def change
    update_view :precisely_neighborhoods, version: 3, revert_to_version: 2
  end
end

Hopefully I'm not missing something obvious here, but this appears to be the same problem as described in this issue.

EDIT: Hm... well I created a new app with the same versions of ruby/rails/scenic and was able to successfully create and update a view. Tells me there's something going on with our app or one of the other gems we're using... but what?

JoshCheek commented 2 years ago

EDIT: Hm... well I created a new app with the same versions of ruby/rails/scenic and was able to successfully create and update a view. Tells me there's something going on with our app or one of the other gems we're using... but what?

Are you able to roll it back? IIRC, when going up, the commands are simply run, but when going down, the commands are recorded and inverted before playing them. I think it was that recording / inverting process that lost track of the keywordness of the arguments.

rdlugosz commented 2 years ago

Hey Josh, thx for the reply. Doing manual up/down didn’t change anything. I figured out that the bug is actually being caused by the zero_downtime_migrations gem (mentioned in an update to my earlier post).

These bugs are tricky to pinpoint- the backtrace really made it look like the error was in scenic; couldn’t find the real culprit until I made a blank project & added migration-related gems one by one until it broke.

On Fri, Jan 14, 2022 at 2:35 PM Josh Cheek @.***> wrote:

EDIT: Hm... well I created a new app with the same versions of ruby/rails/scenic and was able to successfully create and update a view. Tells me there's something going on with our app or one of the other gems we're using... but what?

Are you able to roll it back? IIRC, when going up, the commands are simply run, but when going down, the commands are recorded and inverted before playing them. I think it was that recording / inverting process that lost track of the keywordness of the arguments.

— Reply to this email directly, view it on GitHub https://github.com/scenic-views/scenic/issues/331#issuecomment-1013416444, or unsubscribe https://github.com/notifications/unsubscribe-auth/AADCHGDXHVIW4SKA67YR26LUWB3JPANCNFSM47ZXUB7Q . You are receiving this because you commented.Message ID: @.***>

derekprior commented 2 years ago

So are we saying we can probably revert this PR?

rdlugosz commented 2 years ago

So are we saying we can probably revert this PR?

No. I've verified that Scenic 1.5.4 crashes with the argument error when doing a rollback (seems to work on a migrate though). Scenic 1.5.5 does not crash on either migrate or rollback. The fix definitely needs to stay in place. See below:

[:~/workspace/scenic_test/lol] master(+5/-5)* ± rake db:rollback --backtrace
== 20220114221717 UpdateCurrentTimePgsToVersion5: reverting ===================
-- update_view(:current_time_pgs, {:version=>4})
rake aborted!
StandardError: An error has occurred, this and all later migrations canceled:

wrong number of arguments (given 2, expected 1)
/Users/ryan/.rbenv/versions/3.0.3/lib/ruby/gems/3.0.0/gems/scenic-1.5.4/lib/scenic/statements.rb:91:in `update_view'
/Users/ryan/.rbenv/versions/3.0.3/lib/ruby/gems/3.0.0/gems/activerecord-6.1.4.4/lib/active_record/migration.rb:929:in `block in method_missing'
...

When I stated "the bug was actually caused by..." I was referring to the issue I was having in my real application that led me to this thread in the first place. Sorry for any confusion!

JoshCheek commented 2 years ago

These bugs are tricky to pinpoint- the backtrace really made it look like the error was in scenic; couldn’t find the real culprit until I made a blank project & added migration-related gems one by one until it broke.

Aye, the backtraces are very misleading, b/c they don't break where the problem is introduced, they break where it eventually manifests, which is often in a completely different location. I first reported this as a bug on ActiveRecord for that same reason.