Sidekiq is too fast?

One of the Rails apps I work on uses the awesome Sidekiq to handle background tasks. It's the tool of choice at reinteractive due to its speed and simplicity.

I was having a weird problem on this code base where jobs were failing, seemingly randomly, the solution was non intuitive enough that I thought I would share it.

So the code was this:

class GraphImport < ActiveRecord::Base
  #...

  after_create :queue
  def queue
    GraphImportWorker.perform(self.id)
  end

  #...
end

This seems simple enough. Once the record has been created, queue up a background worker to go about doing the heavy lifting (in this case parsing a CSV and creating record from it) which allows our controller action to return feedback to the user instantly.

The problem was that I was occasionally getting the following error:

ActiveRecord::RecordNotFound - Couldn't find GraphImport with 'id'=64

WAT?!? How could the ID not be found? It must be in the database because otherwise the record couldn't be saved and the queue method wouldn't have an ID to pass to the GraphImportWorker class. How could the GraphImportWorker class possibly not be able to find the row in the database?

What was even more confusing is that after getting that error, looking at the database gave the following:

[1] pry(main)> GraphImport.find(64)
  GraphImport Load (17.0ms)  SELECT  "graph_imports".* FROM "graph_imports"  WHERE "graph_imports"."id" = $1 LIMIT 1  [["id", 64]]
=> #<GraphImport id: 64, organisation_id: 3, data: "Name,Frequency,Symbol,Inverte...", separator: nil, creator_id: 1, created_at: "2015-02-06 02:31:58", updated_at: "2015-02-06 02:31:58", completed_at: nil, failed_at: nil, filename: "test.csv">

Which showed the record was there. Hmmm....

This stumped me for a bit, until I remembered that Rails wraps actions inside of SQL transactions. So the after_create method would be executing from within the transaction, meaning it had access to the SQL row that has been inserted but not committed to the graph_imports table until the end of the ActiveRecord callbacks. When the queue method was called, Sidekiq was so fast that it tried to do the find by ID action BEFORE the transaction had time to complete, so the record wasn't there yet!

However, sometimes Sidekiq was busy with something else, so it didn't queue up this action for a couple of milliseconds, which was enough to allow the ActiveRecord transaction to complete and so the record got found and executed successfully.

The solution?

Well, I've found out there are two simple solutions:

1) The author of Sidekiq already talks about this in his Problems and Troubshooting page

2) Move the queuing call to where it belongs:

Instead of having the queue as an after_create action, move it into the controller like so:

def create
  #...
  if @graph_import.save
    @graph_import.queue
    #...
end

This ensured that the ActiveRecord SQL transaction would always complete before we tried to queue the action.

So the real problem? Sidekiq is too fast :)

Now, the fun thing here is that at reinteractive, we consider Active Record callbacks a code smell in any case, and had we just not used a call back like this, we would have never hit the error. Funny how that works.