How to test retries and failures in resque-retry and Rails 4?

Question

I am trying to write a spec that tests the retry functionality of resque-retry and I can not seem to get the tests to hit the binding.pry's correctly. Is there a way to test this functionality using rspec 3 so I can verify they are functioning as intended?

This is a request spec and I am trying to simulate a live request via fixtures, but no matter what I try I can't seem to get the job to retry.

gem 'resque', require: 'resque/server'
gem 'resque-web', require: 'resque_web'
gem 'resque-scheduler'
gem 'resque-retry'
gem 'resque-lock-timeout'

I am using resque_rspec, and trying this testing strategy.

Partial Spec

it 'retries it' do
  stub_request(:any, /.*api.bigcartel.*/).to_return(body: '{}', status: 200)
  @order_shipped_json['order']['originator_id'] = @provider_order
  post "/hook/shops/#{@shop.id}", @order_shipped_json.to_json, format: :json
  ResqueSpec.perform_all(queue_name)
  ???
end

Queue Job

class QueueHook
  extend Resque::Plugins::LockTimeout
  extend Resque::Plugins::Retry
  extend QueueLock
  extend QueueLogger

  @queue = AppSettings.queues[:hook_queue_name].to_sym
  @lock_timeout = 600
  @retry_exceptions = [QueueError::LockFailed]
  @retry_limit = 600
  @retry_delay = 1

  class << self
    def perform(web_hook_payload_id, _whiplash_customer_id)
      ActiveRecord::Base.clear_active_connections!
      @web_hook_payload = WebHookPayload.find(web_hook_payload_id)
      klass_constructor
      @hook.process_event
    end

    def identifier(_web_hook_payload_id, whiplash_customer_id)
      "lock:integration_hook:#{whiplash_customer_id}"
    end

    def after_perform_delete_webhook(_web_hook_payload_id, _whiplash_customer_id)
      @web_hook_payload.destroy
    end

    private

    ...
  end
end

Queue Job Modules

module QueueLogger
  def before_perform_log_job(*args)
    Rails.logger.info "[Resque][#{self}] running with #{args.inspect}..."
  end

  def on_failure_log_job(*args)
    message = "[Resque][#{self}] failed with #{args.inspect}..."
    run_counters
    Rails.logger.info message_builder(message)
  end

  private

  def run_counters
    @num_attempts += retry_attempt
    @all_attempts += retry_limit
  end

  def message_builder(message)
    return message unless @num_attempts
    return message += " Retrying (attempt ##{@num_attempts + 1})" if @num_attempts < @all_attempts
    message += ' Giving up.'
    message
  end
end

module QueueLock
  def loner_enqueue_failed(*args)
    Rails.logger.info "[Resque][#{self}] is already enqueued: #{args.inspect}..."
  end

  def lock_failed(*)
    raise QueueError::LockFailed
  end
end

Answer 1

A few notes-

1) As mentioned by others, you probably want to separate the resque callbacks from their functionality. That is, test that the retries are firing, but also separately test that they function as expected. You may want to separate those into two separate tests.

2) For checking that they are firing, I think you are looking for class doubles in RSpec 3.

You will need to instatiate the double and then raise an exception (docs). This will allow you to see if your retries are being called, and how many times they have been called (docs).

So, for example,

it "retries on exception n number of times" do
  queue_hook = class_double("QueueHook")
  expect(queue_hook).to have_received(:on_failure_log_job).exactly(n).times
  allow(queue_hook).to receive(:perform).and_raise(ExceptionClass, "Exception message")
  queue_hook.perform(payload_id, customer_id)
end

There's a fair bit going on, so I can't implement locally, but hopefully this can help you get going in the right direction.

Answer 2

So the specific failure you want to test retries for comes from this hook you implemented.

def lock_failed(*)
  raise QueueError::LockFailed
end

We need to trigger this. Here is where it gets used in the plugin. Since you're using a lock timeout it looks like we want to stub .acquire_lock_algorithm!. This is dangerous since this method is part of the plugin's internal api. Keep it in mind when you upgrade the plugin.

it 'retries it' do
  stub_request(:any, /.*api.bigcartel.*/).to_return(body: '{}', status: 200)

  allow(QueueHook).to receive(:acquire_lock_algorithm!).and_return(false, true)

  @order_shipped_json['order']['originator_id'] = @provider_order
  post "/hook/shops/#{@shop.id}", @order_shipped_json.to_json, format: :json

  ResqueSpec.perform_all(queue_name)
end

This spec should now be failing with Failure/Error: raise QueueError::LockFailed. Since that's expected we can set an expectation.

it 'retries it' do
  stub_request(:any, /.*api.bigcartel.*/).to_return(body: '{}', status: 200)

  allow(QueueHook).to receive(:acquire_lock_algorithm!).and_return(false, true)

  @order_shipped_json['order']['originator_id'] = @provider_order
  post "/hook/shops/#{@shop.id}", @order_shipped_json.to_json, format: :json

  expect {
    ResqueSpec.perform_all(queue_name)
  }.to raise_error(QueueError::LockFailed)
end

The spec should now be passing unless you have set ResqueSpec.inline = true. If you have then set it to false for this spec. It will be easier to follow.

If resque-retry is working then the job's failure should have resulted in the job being re-enqueued to ResqueSpec. We can add an expectation for that. expect(ResqueSpec.queues[queue_name]).to be_present. Not we can run the jobs again. We mocked the second return value of acquire_lock_algorithm! to be true so the job should succeed this time.

Since we want to test the counters lets add readers for them

module QueueLogger
  attr_reader :all_attempts, :num_attempts
end

And then finish up the spec...

it 'retries it' do
  stub_request(:any, /.*api.bigcartel.*/).to_return(body: '{}', status: 200)

  allow(QueueHook).to receive(:acquire_lock_algorithm!).and_return(false, true)

  @order_shipped_json['order']['originator_id'] = @provider_order
  post "/hook/shops/#{@shop.id}", @order_shipped_json.to_json, format: :json

  # Failing
  expect {
    ResqueSpec.perform_all(queue_name)
  }.to raise_error(QueueError::LockFailed)
  expect(ResqueSpec.queues[queue_name]).to be_present

  # Retrying
  ResqueSpec.perform_all(queue_name)
  expect(QueueHook.num_attempts).to eq(2)
  ... # Whatever else you want to test.
end

If you want to test the logging specifically you stub them and set expectations regarding what they are called with. That should do it, I have a simplified version running on my own machine. If not we might have to get into the details of your test and Resque configs.