search

brandonhilkert / sucker_punch

Sucker Punch is a Ruby asynchronous processing library using concurrent-ruby, heavily influenced by Sidekiq and girl_friday.
MIT License
2.64k stars 114 forks source link

Testing (rspec) SuckerPunch with GlobalID in Rails 4.2 #98

Closed carmi closed 9 years ago

carmi commented 9 years ago

Not quite sure easiest way to report this error. But I just upgraded to Rails 4.2 which introduced GlobalID and in my test suite (rspec) I am getting errors when I use SuckerPunch as my ActiveJob backend in test environment.

When I do the following:

UserMailer.confirm(user).deliver_later

I got an error.

I've been using the SuckerPunch inline adapter require 'sucker_punch/testing/inline' but I still get the following error. When I switch to the Rails inline adapter, with no other change in my code:

 config.active_job.queue_adapter = :inline

the error goes away.

Let me know if I can provide more information.

Failures:

  1) UsersController GET show assigns the requested user as @user
     Failure/Error: let!(:user) { FactoryGirl.create(:user) }
     ActiveJob::DeserializationError:
       Error while trying to deserialize arguments: Couldn't find User with 'id'=1
     # ./.gems/ruby/2.1.0/gems/activerecord-4.2.0/lib/active_record/core.rb:154:in `find'
     # ./.gems/ruby/2.1.0/gems/globalid-0.3.0ctive_job/arguments.rb:38:in `deserialize'
    /Users/ehc/code/easyform/.gems/ruby/2.1.0/gems/activejob-4.2.0/lib/active_job/core.rb:85:in `deserialize_arguments'
    /Users/ehc/code/easyform/.gems/ruby/2.1.0/gems/activejob-4.2.0/lib/active_job/core.rb:75:in `deserialize_arguments_if_needed'
    /Users/ehc/code/easyform/.gems/ruby/2.1.0/gems/activejob-4.2.0/lib/active_job/execution.rb:30:in `perform_now'
    /Users/ehc/code/easyform/.gems/ruby/2.1.0/gems/activejob-4.2.0/lib/active_job/execution.rb:21:in `execute'
    /Use/lib/global_id/locator.rb:77:in `locate'
     # ./.gems/ruby/2.1.0rs/ehc/code/easyform/.gems/ruby/2.1.0/gems/activejob-4.2.0/lib/active_job/queue_adapters/sucker_punch_adapter.rb:35:in `perform'
    /Users/ehc/code/easyform/.gems/ruby/2.1.0/gems/celluloid-0.16.0/lib/celluloid/calls.rb:26:in `public_send'
    /Users/ehc/code/easyform/.gems/ruby/2.1.0/gems/celluloid-0.16.0/lib/celluloid/calls.rb:26:in `dispatch'
    /Users/ehc/code/easyform/.gems/ruby/2.1.0/gems/celluloid-0.16.0/lib/celluloid/calls.rb:63:in `dispatch'
    /Users/ehc/code/easyform/.gems/ruby/2.1.0/gems/celluloid-0.16.0//gems/globalid-0.3.0/lib/global_id/locator.rb:14:in `locate'
     # ./.gems/ruby/2.1.0/gems/activejob-4.2.0/lib/active_job/arguments.rb:88:in `deserialize_global_id'
     # ./.gems/ruby/2.1.0/gems/activejob-4.2.0/lib/active_job/arguments.rb:74:in `deserialize_argument'
     # ./.gems/ruby/2.1.0/gems/activejob-4.2.0/lib/active_job/arguments.rb:38:in `block in deserialize'
     # ./.gems/ruby/2.1.0/gems/activejob-4.2.0/lib/active_job/arguments.rb:38:in `map'
  lib/celluloid/cell.rb:60:in `block in invoke'
    /Users/ehc/code/easyform/.gems/ruby/2.1.0/gems/celluloid-0.16.0/lib/celluloid/cell.rb:71:in `block in task'
    /Users/ehc/code/easyform/.gems/ruby/2.1.0/gems/celluloid-0.16.0/lib/celluloid/actor.rb:357:in `block in task'
    /Users/ehc/code/easyform/.gems/ruby/2.1.0/gems/celluloid-0.16.0/lib/celluloid/tasks.rb:57:in `block in initialize'
    /Users/ehc/code/easyform/.gems/ruby/2.1.0/gems/celluloid-0.16.0/lib/celluloid/tasks/task_fiber.rb:15:in `block in create'
   # ./.gems/ruby/2.1.0/gems/activejob-4.2.0/lib/active_job/arguments.rb:38:in `deserialize'
     # ./.gems/ruby/2.1.0/gems/activejob-4.2.0/lib/active_job/core.rb:85:in `deserialize_arguments'
     # ./.gems/ruby/2.1.0/gems/activejob-4.2.0/lib/active_job/core.rb:75:in `deserialize_arguments_if_needed'
     # ./.gems/ruby/2.1.0/gems/activejob-4.2.0/lib/active_job/execution.rb:30:in `perform_now'
     # ./.gems/ruby/2.1.0/gems/activejob-4.2.0/lib/active_job/execution.rb:21:in `execute'
     # ./.gems/ruby/2.1.0/gems/activejob-4.2.0/lib/active_job/queue_adapters/sucker_punch_adapter.rb:35:in `perform'
     # ./.gems/ruby/2.1.0/gems/celluloid-0.16.0/lib/celluloid/calls.rb:26:in `public_send'
     # ./.gems/ruby/2.1.0/gems/celluloid-0.16.0/lib/celluloid/calls.rb:26:in `dispatch'
     # ./.gems/ruby/2.1.0/gems/celluloid-0.16.0/lib/celluloid/calls.rb:63:in `dispatch'
     # ./.gems/ruby/2.1.0/gems/celluloid-0.16.0/lib/celluloid/cell.rb:60:in `block in invoke'
     # ./.gems/ruby/2.1.0/gems/celluloid-0.16.0/lib/celluloid/cell.rb:71:in `block in task'
     # ./.gems/ruby/2.1.0/gems/celluloid-0.16.0/lib/celluloid/actor.rb:357:in `block in task'
     # ./.gems/ruby/2.1.0/gems/celluloid-0.16.0/lib/celluloid/tasks.rb:57:in `block in initialize'
     # ./.gems/ruby/2.1.0/gems/celluloid-0.16.0/lib/celluloid/tasks/task_fiber.rb:15:in `block in create'
     # (celluloid):0:in `remote procedure call'
     # ./.gems/ruby/2.1.0/gems/celluloid-0.16.0/lib/celluloid/calls.rb:92:in `value'
     # ./.gems/ruby/2.1.0/gems/celluloid-0.16.0/lib/celluloid/proxies/sync_proxy.rb:33:in `method_missing'
     # ./.gems/ruby/2.1.0/gems/celluloid-0.16.0/lib/celluloid/proxies/cell_proxy.rb:17:in `_send_'
     # ./.gems/ruby/2.1.0/gems/celluloid-0.16.0/lib/celluloid/pool_manager.rb:41:in `_send_'
     # ./.gems/ruby/2.1.0/gems/celluloid-0.16.0/lib/celluloid/pool_manager.rb:140:in `method_missing'
     # ./.gems/ruby/2.1.0/gems/celluloid-0.16.0/lib/celluloid/calls.rb:26:in `public_send'
     # ./.gems/ruby/2.1.0/gems/celluloid-0.16.0/lib/celluloid/calls.rb:26:in `dispatch'
     # ./.gems/ruby/2.1.0/gems/celluloid-0.16.0/lib/celluloid/calls.rb:63:in `dispatch'
     # ./.gems/ruby/2.1.0/gems/celluloid-0.16.0/lib/celluloid/cell.rb:60:in `block in invoke'
     # ./.gems/ruby/2.1.0/gems/celluloid-0.16.0/lib/celluloid/cell.rb:71:in `block in task'
     # ./.gems/ruby/2.1.0/gems/celluloid-0.16.0/lib/celluloid/actor.rb:357:in `block in task'
     # ./.gems/ruby/2.1.0/gems/celluloid-0.16.0/lib/celluloid/tasks.rb:57:in `block in initialize'
     # ./.gems/ruby/2.1.0/gems/celluloid-0.16.0/lib/celluloid/tasks/task_fiber.rb:15:in `block in create'
     # (celluloid):0:in `remote procedure call'
     # ./.gems/ruby/2.1.0/gems/celluloid-0.16.0/lib/celluloid/calls.rb:92:in `value'
     # ./.gems/ruby/2.1.0/gems/celluloid-0.16.0/lib/celluloid/proxies/sync_proxy.rb:33:in `method_missing'
     # ./.gems/ruby/2.1.0/gems/activejob-4.2.0/lib/active_job/queue_adapters/sucker_punch_adapter.rb:23:in `enqueue'
     # ./.gems/ruby/2.1.0/gems/activejob-4.2.0/lib/active_job/enqueuing.rb:71:in `block in enqueue'
     # ./.gems/ruby/2.1.0/gems/activesupport-4.2.0/lib/active_support/callbacks.rb:117:in `call'
     # ./.gems/ruby/2.1.0/gems/activesupport-4.2.0/lib/active_support/callbacks.rb:117:in `call'
     # ./.gems/ruby/2.1.0/gems/activesupport-4.2.0/lib/active_support/callbacks.rb:190:in `block in simple'
     # ./.gems/ruby/2.1.0/gems/activesupport-4.2.0/lib/active_support/callbacks.rb:338:in `call'
     # ./.gems/ruby/2.1.0/gems/activesupport-4.2.0/lib/active_support/callbacks.rb:338:in `block (2 levels) in simple'
     # ./.gems/ruby/2.1.0/gems/activejob-4.2.0/lib/active_job/logging.rb:14:in `call'
     # ./.gems/ruby/2.1.0/gems/activejob-4.2.0/lib/active_job/logging.rb:14:in `block (3 levels) in <module:Logging>'
     # ./.gems/ruby/2.1.0/gems/activejob-4.2.0/lib/active_job/logging.rb:43:in `block in tag_logger'
     # ./.gems/ruby/2.1.0/gems/activesupport-4.2.0/lib/active_support/tagged_logging.rb:68:in `block in tagged'
     # ./.gems/ruby/2.1.0/gems/activesupport-4.2.0/lib/active_support/tagged_logging.rb:26:in `tagged'
     # ./.gems/ruby/2.1.0/gems/activesupport-4.2.0/lib/active_support/tagged_logging.rb:68:in `tagged'
     # ./.gems/ruby/2.1.0/gems/activejob-4.2.0/lib/active_job/logging.rb:43:in `tag_logger'
     # ./.gems/ruby/2.1.0/gems/activejob-4.2.0/lib/active_job/logging.rb:13:in `block (2 levels) in <module:Logging>'
     # ./.gems/ruby/2.1.0/gems/activesupport-4.2.0/lib/active_support/callbacks.rb:436:in `instance_exec'
     # ./.gems/ruby/2.1.0/gems/activesupport-4.2.0/lib/active_support/callbacks.rb:436:in `block in make_lambda'
     # ./.gems/ruby/2.1.0/gems/activesupport-4.2.0/lib/active_support/callbacks.rb:337:in `call'
     # ./.gems/ruby/2.1.0/gems/activesupport-4.2.0/lib/active_support/callbacks.rb:337:in `block in simple'
     # ./.gems/ruby/2.1.0/gems/activesupport-4.2.0/lib/active_support/callbacks.rb:92:in `call'
     # ./.gems/ruby/2.1.0/gems/activesupport-4.2.0/lib/active_support/callbacks.rb:92:in `_run_callbacks'
     # ./.gems/ruby/2.1.0/gems/activesupport-4.2.0/lib/active_support/callbacks.rb:734:in `_run_enqueue_callbacks'
     # ./.gems/ruby/2.1.0/gems/activesupport-4.2.0/lib/active_support/callbacks.rb:81:in `run_callbacks'
     # ./.gems/ruby/2.1.0/gems/activejob-4.2.0/lib/active_job/enqueuing.rb:67:in `enqueue'
     # ./.gems/ruby/2.1.0/gems/activejob-4.2.0/lib/active_job/configured_job.rb:13:in `perform_later'
     # ./.gems/ruby/2.1.0/gems/actionmailer-4.2.0/lib/action_mailer/message_delivery.rb:112:in `enqueue_delivery'
     # ./.gems/ruby/2.1.0/gems/actionmailer-4.2.0/lib/action_mailer/message_delivery.rb:68:in `deliver_later'
     # ./app/models/user.rb:23:in `confirm_email'
     # ./.gems/ruby/2.1.0/gems/activesupport-4.2.0/lib/active_support/callbacks.rb:427:in `block in make_lambda'
     # ./.gems/ruby/2.1.0/gems/activesupport-4.2.0/lib/active_support/callbacks.rb:225:in `call'
     # ./.gems/ruby/2.1.0/gems/activesupport-4.2.0/lib/active_support/callbacks.rb:225:in `block in halting_and_conditional'
     # ./.gems/ruby/2.1.0/gems/activesupport-4.2.0/lib/active_support/callbacks.rb:92:in `call'
     # ./.gems/ruby/2.1.0/gems/activesupport-4.2.0/lib/active_support/callbacks.rb:92:in `_run_callbacks'
     # ./.gems/ruby/2.1.0/gems/activesupport-4.2.0/lib/active_support/callbacks.rb:734:in `_run_create_callbacks'
     # ./.gems/ruby/2.1.0/gems/activerecord-4.2.0/lib/active_record/callbacks.rb:306:in `_create_record'
     # ./.gems/ruby/2.1.0/gems/activerecord-4.2.0/lib/active_record/timestamp.rb:57:in `_create_record'
     # ./.gems/ruby/2.1.0/gems/activerecord-4.2.0/lib/active_record/persistence.rb:501:in `create_or_update'
     # ./.gems/ruby/2.1.0/gems/activerecord-4.2.0/lib/active_record/callbacks.rb:302:in `block in create_or_update'
     # ./.gems/ruby/2.1.0/gems/activesupport-4.2.0/lib/active_support/callbacks.rb:88:in `call'
     # ./.gems/ruby/2.1.0/gems/activesupport-4.2.0/lib/active_support/callbacks.rb:88:in `_run_callbacks'
     # ./.gems/ruby/2.1.0/gems/activesupport-4.2.0/lib/active_support/callbacks.rb:734:in `_run_save_callbacks'
     # ./.gems/ruby/2.1.0/gems/activerecord-4.2.0/lib/active_record/callbacks.rb:302:in `create_or_update'
     # ./.gems/ruby/2.1.0/gems/activerecord-4.2.0/lib/active_record/persistence.rb:142:in `save!'
     # ./.gems/ruby/2.1.0/gems/activerecord-4.2.0/lib/active_record/validations.rb:43:in `save!'
     # ./.gems/ruby/2.1.0/gems/activerecord-4.2.0/lib/active_record/attribute_methods/dirty.rb:29:in `save!'
     # ./.gems/ruby/2.1.0/gems/activerecord-4.2.0/lib/active_record/transactions.rb:291:in `block in save!'
     # ./.gems/ruby/2.1.0/gems/activerecord-4.2.0/lib/active_record/transactions.rb:347:in `block in with_transaction_returning_status'
     # ./.gems/ruby/2.1.0/gems/activerecord-4.2.0/lib/active_record/connection_adapters/abstract/database_statements.rb:213:in `block in transaction'
     # ./.gems/ruby/2.1.0/gems/activerecord-4.2.0/lib/active_record/connection_adapters/abstract/transaction.rb:188:in `within_new_transaction'
     # ./.gems/ruby/2.1.0/gems/activerecord-4.2.0/lib/active_record/connection_adapters/abstract/database_statements.rb:213:in `transaction'
     # ./.gems/ruby/2.1.0/gems/activerecord-4.2.0/lib/active_record/transactions.rb:220:in `transaction'
     # ./.gems/ruby/2.1.0/gems/activerecord-4.2.0/lib/active_record/transactions.rb:344:in `with_transaction_returning_status'
     # ./.gems/ruby/2.1.0/gems/activerecord-4.2.0/lib/active_record/transactions.rb:291:in `save!'
brandonhilkert commented 9 years ago

Couldn't find User with 'id'=1 is an application error. Sidekiq covers it a little bit here: https://github.com/mperham/sidekiq/wiki/FAQ#why-am-i-seeing-a-lot-of-cant-find-modelname-with-id12345-errors-with-sidekiq

Because sucker punch is always running workers, it means that the worker is attempting to run your job before the application code has created the user. Trying adding sleep to the worker to prove the theory.

You might also consider using the inline testing feature of sucker_punch https://github.com/brandonhilkert/sucker_punch#testing. This will make everything synchronous so you don't have to worry about this.

carmi commented 9 years ago

Yeah, I was using the inline adapter for sucker punch by requiring require 'sucker_punch/testing/inline' and I still got the error. Additionally, I put a binding in the invocation, so I could be sure that the database records existed before the error occured, and after. So that made me think it was a GlobalID issue or something with SuckerPunch.

brandonhilkert commented 9 years ago

Do you get the error when you use Sucker Punch outside of ActiveJob?

galulex commented 9 years ago

I have added to spec/rails_helper.rb Rails.application.config.active_job.queue_adapter = :inline and it helped

dbalexandre commented 9 years ago

I'm getting this error too, meanwhile I'm using this:

# config/initializers/acive_job.rb

Rails.application.configure do
  if Rails.env.test?
    config.active_job.queue_adapter = :inline
  else
    config.active_job.queue_adapter = :sucker_punch
  end
end
brandonhilkert commented 9 years ago

Quick question for everyone that has experienced this, are you using transactions? And if so, have you read this: https://github.com/brandonhilkert/sucker_punch#cleaning-test-data-transactions ?

dbalexandre commented 9 years ago

@brandonhilkert yes, I'm using transactions.

# spec/support/database_cleaner.rb

RSpec.configure do |config|
  config.before(:suite) do
    DatabaseCleaner.clean_with(:truncation)
  end

  config.before(:each) do
    DatabaseCleaner.strategy = :transaction
  end

  config.before(:each, type: :feature) do
    DatabaseCleaner.strategy = :truncation
  end

  config.before(:each, job: true) do
    DatabaseCleaner.strategy = :truncation
  end

  config.before(:each) do
    DatabaseCleaner.start
  end

  config.after(:each) do
    DatabaseCleaner.clean
  end
end

# spec/rails_helper.rb

RSpec.configure do |config|
  ...
  config.use_transactional_fixtures = false
  ...
end

Using `config.active_job.queue_adapter = :inline`:

```ruby
$ bin/rspec spec

Finished in 2 seconds (files took 5.34 seconds to load)
106 examples, 0 failures

Requiring sucker_punch/testing/inline in spec/rails_helper.rb with config.active_job.queue_adapter = :sucker_punch:

$ bin/rspec spec

......................................
  An error occurred in an after hook
    ActiveJob::DeserializationError: Error while trying to deserialize arguments: Couldn't find User with 'id'=4
    occurred at /home/vagrant/.gem/ruby/2.2.0/gems/activerecord-4.2.0/lib/active_record/core.rb:154:in `find'

Finished in 22.41 seconds (files took 6.53 seconds to load)
106 examples, 1 failure

Let me know if I can help you to investigate this issue.

andypike commented 9 years ago

Just for further confirmation I am also seeing this behaviour on this project https://github.com/andypike/ruby_videos. I'm happy to help if you need further information :smile:

brandonhilkert commented 9 years ago

@andypike This project uses transactional fixtures without database cleaner, which as mentioned above won't work b/c the thread is running separately from the transaction.

@dbalexandre Can you put a public sample app for me to check out?

andypike commented 9 years ago

Sure, I tried using database_cleaner and truncation for specs that use sucker_punch and had the above behaviour. I reverted back to using the inline active_job adapter for the test environment to get my specs passing.

I can make these changes again for you and leave it in a branch as a test app that recreates the issue above. Will update this issue with the details shortly.

Thanks for the fast reply and awesome gem :heart:

andypike commented 9 years ago

Hi @brandonhilkert,

Here is a branch that recreates the issue: https://github.com/andypike/ruby_videos/tree/sucker_punch_spec_errors

To recap, it's a Rails 4.2 app using ActiveJob to send async emails via sucker_punch.

In this branch I do not use transactional fixtures and instead use database_cleaner with truncation. I've included sucker_punch/testing/inline in rails_helper.rb and specified the ActiveJob adapter as :sucker_punch for all environments.

In this branch I get 8 failing specs, all with the Error while trying to deserialize arguments: Couldn't find Video with 'id'=47 (with varying ids).

Contrast this branch with master where I just use the inline ActiveJob adapter for the test environment (without user database_cleaner etc).

I hope this helps. If you need anything further I'd be more than happy to help.

Andy

andypike commented 9 years ago

Right, ignore all that!

I forgot to add the :job => true to the specs that send async emails and now it's working fine. Will commit these to the branch so others can see a working example.

Andy

andypike commented 9 years ago

Interestingly, I changed the tag from :job to :async, ran my specs and it failed as described above (that's the tag I used originally). Then putting it back to :job worked again. But then I put it back to use the :async tag again and it worked fine.

I've since run the specs about 20 times now using the :async tag and it always passes. So not sure what to add here, may totally be user error on my part but I'm pretty sure the error did happen when everything was configured correctly.

I'll update the issue if I can get a repeatable setup.

brandonhilkert commented 9 years ago

@andypike Thanks for the update. Would be happy to dig in to an example that doesn't work. But as long as it doesn't have the truncation stuff, it won't work. I have a hard time keeping with all the changes with Rspec and syntax for database_cleaner so it wouldn't surprise me if, at some point, the meta data starts working differently.

jpaulomotta commented 9 years ago

@brandonhilkert Hello. I'm having the same issue here. I'm using minitest engine instead of rspec. No problems running it on development, but in test it doesn't work.

I'm using

Database cleaner is set to truncation on every test. The only thing that makes rails find my model is: use_transactional_fixtures = false

But this breaks lots of my other tests.

Is there anyway to test Sucker Punch without disabling transaction_fixtures? Right now I'm skipping the tests using ActiveJob inline. Thanks for your help. JP

brandonhilkert commented 9 years ago

@jpaulomotta Keep transactional fixtures on defeats the purpose of using truncation. Unfortunately, if data is created in a transaction, it won't be available for the other thread that sucker punch is running in.