undefined method 'create' for Merit:Action:Class
psnider30 opened this issue · 12 comments
Also undefined method 'where' for Merit:Action:Class
Merit is not loading correctly in development. I routinely get these errors and then restart the server to get Merit working again. This issue is similar to (#45) but resurfaced in rails 6.
stack trace on error from MeritWorker which calls: Merit::Action.where(processed: false)
12:01:30 log.1 | ↳ app/middleware/ip_randomizer.rb:11:in `call'
12:01:30 worker.1 | 2020-02-06T20:01:30.148Z 74828 TID-owip0cpsk MeritWorker JID-f334db610c3b88f9f25b7e20 INFO: start
12:01:30 worker.1 | 2020-02-06T20:01:30.154Z 74828 TID-owip0cpsk MeritWorker JID-f334db610c3b88f9f25b7e20 INFO: fail: 0.006 sec
12:01:30 worker.1 | 2020-02-06T20:01:30.154Z 74828 TID-owip0cpsk MeritWorker JID-f334db610c3b88f9f25b7e20 INFO: delete_by_digest(enrolluniquejobs:26496cc4e7b0aa7b2bcb1db41d41a01f) completed in 0.0ms
12:01:30 worker.1 | 2020-02-06T20:01:30.155Z 74828 TID-owip0cpsk WARN: {"context":"Job raised exception","job":{"queue":"default","args":[],"class":"MeritWorker","retry":false,"lock":"until_and_while_executing","on_conflict":"reject","dead":false,"jid":"f334db610c3b88f9f25b7e20","created_at":1581019290.1411042,"lock_timeout":0,"lock_expiration":null,"unique_prefix":"enrolluniquejobs","unique_args":[],"unique_digest":"enrolluniquejobs:26496cc4e7b0aa7b2bcb1db41d41a01f:RUN","enqueued_at":1581019290.1473641},"jobstr":"{\"queue\":\"default\",\"args\":[],\"class\":\"MeritWorker\",\"retry\":false,\"lock\":\"until_and_while_executing\",\"on_conflict\":\"reject\",\"dead\":false,\"jid\":\"f334db610c3b88f9f25b7e20\",\"created_at\":1581019290.1411042,\"lock_timeout\":0,\"lock_expiration\":null,\"unique_prefix\":\"enrolluniquejobs\",\"unique_args\":[],\"unique_digest\":\"enrolluniquejobs:26496cc4e7b0aa7b2bcb1db41d41a01f\",\"enqueued_at\":1581019290.1473641}"}
12:01:30 worker.1 | 2020-02-06T20:01:30.156Z 74828 TID-owip0cpsk WARN: NoMethodError: undefined method `where' for Merit::Action:Class
12:01:30 worker.1 | Did you mean? when
12:01:30 worker.1 | 2020-02-06T20:01:30.156Z 74828 TID-owip0cpsk WARN: /Users/Paul/sites/enroll/app/workers/merit_worker.rb:7:in `perform'
12:01:30 worker.1 | /Users/Paul/.rbenv/versions/2.6.4/lib/ruby/gems/2.6.0/gems/sidekiq-5.2.7/lib/sidekiq/processor.rb:192:in `execute_job'
12:01:30 worker.1 | /Users/Paul/.rbenv/versions/2.6.4/lib/ruby/gems/2.6.0/gems/sidekiq-5.2.7/lib/sidekiq/processor.rb:165:in `block (2 levels) in process'
12:01:30 worker.1 | /Users/Paul/.rbenv/versions/2.6.4/lib/ruby/gems/2.6.0/gems/sidekiq-5.2.7/lib/sidekiq/middleware/chain.rb:128:in `block in invoke'
12:01:30 worker.1 | /Users/Paul/.rbenv/versions/2.6.4/lib/ruby/gems/2.6.0/gems/sidekiq-unique-jobs-6.0.15/lib/sidekiq_unique_jobs/server/middleware.rb:34:in `block (2 levels) in call'
12:01:30 worker.1 | /Users/Paul/.rbenv/versions/2.6.4/lib/ruby/gems/2.6.0/gems/sidekiq-unique-jobs-6.0.15/lib/sidekiq_unique_jobs/lock/until_and_while_executing.rb:22:in `block in execute'
12:01:30 worker.1 | /Users/Paul/.rbenv/versions/2.6.4/lib/ruby/gems/2.6.0/gems/sidekiq-unique-jobs-6.0.15/lib/sidekiq_unique_jobs/lock/while_executing.rb:38:in `execute'
12:01:30 worker.1 | /Users/Paul/.rbenv/versions/2.6.4/lib/ruby/gems/2.6.0/gems/sidekiq-unique-jobs-6.0.15/lib/sidekiq_unique_jobs/lock/until_and_while_executing.rb:22:in `execute'
12:01:30 worker.1 | /Users/Paul/.rbenv/versions/2.6.4/lib/ruby/gems/2.6.0/gems/sidekiq-unique-jobs-6.0.15/lib/sidekiq_unique_jobs/server/middleware.rb:33:in `block in call'
12:01:30 worker.1 | /Users/Paul/.rbenv/versions/2.6.4/lib/ruby/gems/2.6.0/gems/sidekiq-unique-jobs-6.0.15/lib/sidekiq_unique_jobs/sidekiq_unique_jobs.rb:43:in `block in with_context'
12:01:30 worker.1 | /Users/Paul/.rbenv/versions/2.6.4/lib/ruby/gems/2.6.0/gems/sidekiq-5.2.7/lib/sidekiq/logging.rb:48:in `with_context'
12:01:30 log.1 | ** [Honeybadger] Reporting error id=6ba813a9-2020-4e97-b823-99e7917b288b level=1 pid=74828
12:01:30 worker.1 | /Users/Paul/.rbenv/versions/2.6.4/lib/ruby/gems/2.6.0/gems/sidekiq-unique-jobs-6.0.15/lib/sidekiq_unique_jobs/sidekiq_unique_jobs.rb:43:in `with_context'
12:01:30 worker.1 | /Users/Paul/.rbenv/versions/2.6.4/lib/ruby/gems/2.6.0/gems/sidekiq-unique-jobs-6.0.15/lib/sidekiq_unique_jobs/server/middleware.rb:32:in `call'
12:01:30 worker.1 | /Users/Paul/.rbenv/versions/2.6.4/lib/ruby/gems/2.6.0/gems/sidekiq-5.2.7/lib/sidekiq/middleware/chain.rb:130:in `block in invoke'
12:01:30 worker.1 | /Users/Paul/.rbenv/versions/2.6.4/lib/ruby/gems/2.6.0/gems/honeybadger-4.5.2/lib/honeybadger/plugins/sidekiq.rb:10:in `call'
12:01:30 worker.1 | /Users/Paul/.rbenv/versions/2.6.4/lib/ruby/gems/2.6.0/gems/sidekiq-5.2.7/lib/sidekiq/middleware/chain.rb:130:in `block in invoke'
12:01:30 worker.1 | /Users/Paul/.rbenv/versions/2.6.4/lib/ruby/gems/2.6.0/gems/sidekiq-5.2.7/lib/sidekiq/middleware/chain.rb:133:in `invoke'
12:01:30 log.1 | ** [Honeybadger] Success ⚡ Development mode is enabled; this error will be reported if it occurs after you deploy your app. id=6ba813a9-2020-4e97-b823-99e7917b288b level=1 pid=74828
12:01:30 worker.1 | /Users/Paul/.rbenv/versions/2.6.4/lib/ruby/gems/2.6.0/gems/sidekiq-5.2.7/lib/sidekiq/processor.rb:164:in `block in process'
12:01:30 worker.1 | /Users/Paul/.rbenv/versions/2.6.4/lib/ruby/gems/2.6.0/gems/sidekiq-5.2.7/lib/sidekiq/processor.rb:137:in `block (6 levels) in dispatch'
12:01:30 worker.1 | /Users/Paul/.rbenv/versions/2.6.4/lib/ruby/gems/2.6.0/gems/sidekiq-5.2.7/lib/sidekiq/job_retry.rb:109:in `local'
12:01:30 worker.1 | /Users/Paul/.rbenv/versions/2.6.4/lib/ruby/gems/2.6.0/gems/sidekiq-5.2.7/lib/sidekiq/processor.rb:136:in `block (5 levels) in dispatch'
12:01:30 worker.1 | /Users/Paul/.rbenv/versions/2.6.4/lib/ruby/gems/2.6.0/gems/sidekiq-5.2.7/lib/sidekiq/rails.rb:43:in `block in call'
12:01:30 worker.1 | /Users/Paul/.rbenv/versions/2.6.4/lib/ruby/gems/2.6.0/gems/activesupport-6.0.0/lib/active_support/execution_wrapper.rb:88:in `wrap'
12:01:30 worker.1 | /Users/Paul/.rbenv/versions/2.6.4/lib/ruby/gems/2.6.0/gems/activesupport-6.0.0/lib/active_support/reloader.rb:72:in `block in wrap'
12:01:30 worker.1 | /Users/Paul/.rbenv/versions/2.6.4/lib/ruby/gems/2.6.0/gems/activesupport-6.0.0/lib/active_support/execution_wrapper.rb:88:in `wrap'
12:01:30 worker.1 | /Users/Paul/.rbenv/versions/2.6.4/lib/ruby/gems/2.6.0/gems/activesupport-6.0.0/lib/active_support/reloader.rb:71:in `wrap'
12:01:30 worker.1 | /Users/Paul/.rbenv/versions/2.6.4/lib/ruby/gems/2.6.0/gems/sidekiq-5.2.7/lib/sidekiq/rails.rb:42:in `call'
12:01:30 worker.1 | /Users/Paul/.rbenv/versions/2.6.4/lib/ruby/gems/2.6.0/gems/sidekiq-5.2.7/lib/sidekiq/processor.rb:132:in `block (4 levels) in dispatch'
12:01:30 worker.1 | /Users/Paul/.rbenv/versions/2.6.4/lib/ruby/gems/2.6.0/gems/sidekiq-5.2.7/lib/sidekiq/processor.rb:250:in `stats'
12:01:30 worker.1 | /Users/Paul/.rbenv/versions/2.6.4/lib/ruby/gems/2.6.0/gems/sidekiq-5.2.7/lib/sidekiq/processor.rb:127:in `block (3 levels) in dispatch'
12:01:30 worker.1 | /Users/Paul/.rbenv/versions/2.6.4/lib/ruby/gems/2.6.0/gems/sidekiq-5.2.7/lib/sidekiq/job_logger.rb:8:in `call'
12:01:30 worker.1 | /Users/Paul/.rbenv/versions/2.6.4/lib/ruby/gems/2.6.0/gems/sidekiq-5.2.7/lib/sidekiq/processor.rb:126:in `block (2 levels) in dispatch'
12:01:30 worker.1 | /Users/Paul/.rbenv/versions/2.6.4/lib/ruby/gems/2.6.0/gems/sidekiq-5.2.7/lib/sidekiq/job_retry.rb:74:in `global'
12:01:30 worker.1 | /Users/Paul/.rbenv/versions/2.6.4/lib/ruby/gems/2.6.0/gems/sidekiq-5.2.7/lib/sidekiq/processor.rb:125:in `block in dispatch'
12:01:30 worker.1 | /Users/Paul/.rbenv/versions/2.6.4/lib/ruby/gems/2.6.0/gems/sidekiq-5.2.7/lib/sidekiq/logging.rb:48:in `with_context'
12:01:30 worker.1 | /Users/Paul/.rbenv/versions/2.6.4/lib/ruby/gems/2.6.0/gems/sidekiq-5.2.7/lib/sidekiq/logging.rb:42:in `with_job_hash_context'
12:01:30 worker.1 | /Users/Paul/.rbenv/versions/2.6.4/lib/ruby/gems/2.6.0/gems/sidekiq-5.2.7/lib/sidekiq/processor.rb:124:in `dispatch'
12:01:30 worker.1 | /Users/Paul/.rbenv/versions/2.6.4/lib/ruby/gems/2.6.0/gems/sidekiq-5.2.7/lib/sidekiq/processor.rb:163:in `process'
12:01:30 worker.1 | /Users/Paul/.rbenv/versions/2.6.4/lib/ruby/gems/2.6.0/gems/sidekiq-5.2.7/lib/sidekiq/processor.rb:83:in `process_one'
12:01:30 worker.1 | /Users/Paul/.rbenv/versions/2.6.4/lib/ruby/gems/2.6.0/gems/sidekiq-5.2.7/lib/sidekiq/processor.rb:71:in `run'
12:01:30 worker.1 | /Users/Paul/.rbenv/versions/2.6.4/lib/ruby/gems/2.6.0/gems/sidekiq-5.2.7/lib/sidekiq/util.rb:16:in `watchdog'
12:01:30 worker.1 | /Users/Paul/.rbenv/versions/2.6.4/lib/ruby/gems/2.6.0/gems/sidekiq-5.2.7/lib/sidekiq/util.rb:25:in `block in safe_thread'
12:01:30 log.1 | Started GET "/admin/sidekiq/cron" for 127.0.0.1 at 2020-02-06 12:01:30 -0800
What version of merit are you using?
What does Merit.orm return in the environment where it fails?
Hi Tute,
It fails in development and return :active_record as expected.
huh, thank you. I assume it's latest versions of merit.
Could you come up with concrete steps to reliably replicate it? How can I replicate this myself? Thanks!
Hi,
I have the same issue and get this error message in console :
[Webpacker] Everything's up-to-date. Nothing to do [merit] Missing column: target_data. Run rails generate merit:upgradeandrake db:migrateto add it. Completed 500 Internal Server Error in 294ms (Views: 256.7ms | ActiveRecord: 30.0ms | Allocations: 123976) NoMethodError - undefined methodcreate' for Merit::Action:Class:`
I already have the column target_data in "merit_actions" table.
I'm working with ruby 2.6.5 and rails 6.0.2.1
Thank you. If it happens for you reliably, can you share the code somewhere I can get access to so we debug?
If I set config.autoloader = :classic in application.rb the problem goes away. This appears directly related to the use of Zeitwerk in Rails 6. I get this warning in the log:
DEPRECATION WARNING: Initialization autoloaded the constants Merit::Badge, Merit::BadgeRules and Merit::PointRules.
10:45:39 log.1 |
10:45:39 log.1 | Being able to do this is deprecated. Autoloading during initialization is going
10:45:39 log.1 | to be an error condition in future versions of Rails.
10:45:39 log.1 |
10:45:39 log.1 | Reloading does not reboot the application, and therefore code executed during
10:45:39 log.1 | initialization does not run again. So, if you reload Merit::Badge, for example,
10:45:39 log.1 | the expected changes won't be reflected in that stale Class object.
10:45:39 log.1 |
10:45:39 log.1 | These autoloaded constants have been unloaded.
10:45:39 log.1 |
10:45:39 log.1 | Please, check the "Autoloading and Reloading Constants" guide for solutions.
Merit version 3.0.3
To reproduce, add a validator to your model that has merit on it, make a request that loads that model, then remove the validator, then make another request without restarting the app. You should be able to reproduce that way.
Related: #331
Thanks for the pointer, @mrsweaters. I applied some fixes in master, and started a new PR to address this: #337. There are some commits that need more work, but it's off to a good start I think.
@psnider30 @Tioneb12 @mrsweaters thank you for your input on this issue. I think #337 is ready to test with Zeitwerk mode. Would you please try it in your apps to ensure it works well for you? Thank you.
I merged in zeitwerk into master, @psnider30 @Tioneb12 @mrsweaters. I don't want to release the new version of merit, though, until someone who was seeing the error sees this fix addressing it.
Please let me know how it goes when you try it! Thank you.
@tute Your master branch tested out well for us in development and staging. It's deployed in production now and I'll let you know if I see any errors. Thx for all your work!
That's great news, thanks for testing. Releasing v4 soon!