delayed_job with handle_asynchronously

[artempankov]

Hi

I have Tranfer model
method is import_1c

module SpreeExchange
  class Transfer < ActiveRecord::Base
  #...
  def process_pending_files
      method = %{#{EXCHANGE_TYPES[exchange_type]}_#{PARSE_METHODS[parse_method]}}
      processor = send method if self.respond_to? method
      if processor.is_a?(Delayed::Backend::ActiveRecord::Job)
        self.jobs << processor
        save
      end
  end
  def import_1c
      #...
  end
  handle_asynchronously :import_1c, :queue => 'import',  :run_at => Proc.new { Time.now.end_of_day - 7200 + Time.now.hour*60 + Time.now.min }  
  #...
  end
end

When i have no airbrake gem in Gemfile, everything is working, i have new job in delayed_jobs table after calling process_pending_files:

2.1.5 :001 > t = SpreeExchange::Transfer.all.first
 => #<SpreeExchange::Transfer id: 484, endtime: nil, message: "", state: 0, created_at: "2015-10-07 10:34:32", updated_at: "2015-10-08 09:07:40", exchange_type: 1, parse_method: 1, cookie_name: "877ddcf61a8c68f8208e6ba1de302fb9", cookie_value: "98e0bc27873e2bcd9d4fb8cc05e37f2b", request_type: "catalog", store_id: 1, uuid: nil, stock_location_id: nil, exception_backtrace: nil>
2.1.5 :002 > t.process_pending_files
 => true

But after just installing airbrake, i get:

2.1.5 :001 > t = SpreeExchange::Transfer.all.first
 => #<SpreeExchange::Transfer id: 484, endtime: nil, message: "", state: 0, created_at: "2015-10-07 10:34:32", updated_at: "2015-10-08 09:07:40", exchange_type: 1, parse_method: 1, cookie_name: "877ddcf61a8c68f8208e6ba1de302fb9", cookie_value: "98e0bc27873e2bcd9d4fb8cc05e37f2b", request_type: "catalog", store_id: 1, uuid: nil, stock_location_id: nil, exception_backtrace: nil>
2.1.5 :002 > t.process_pending_files
 => nil

I can't even create record with .delay method:

2.1.5 :017 >   t = SpreeExchange::Transfer.all.first
 => #<SpreeExchange::Transfer id: 484, endtime: nil, message: "", state: 0, created_at: "2015-10-07 10:34:32", updated_at: "2015-10-08 09:07:40", exchange_type: 1, parse_method: 1, cookie_name: "877ddcf61a8c68f8208e6ba1de302fb9", cookie_value: "98e0bc27873e2bcd9d4fb8cc05e37f2b", request_type: "catalog", store_id: 1, uuid: nil, stock_location_id: nil, exception_backtrace: nil>
2.1.5 :018 > t.delay.import_1c
 => "6f486a6878e7e3b8367fe7b3"

There is nothing in delayed_jobs table

Any ideas?

[kyrylo]

Hello! I slightly edited formatting in your original post, because some return values were not showing up because of the < character.

What are your Airbrake, DelayedJob and Rails versions?
What is your Airbrake config?

[artempankov]

rails (4.1.9)
delayed_job (4.1.1) delayed_job_active_record (4.1.0) (updated today, was 4.0.3)
airbrake (4.3.1)

Airbrake.configure do |config|
config.api_key = 'e7f0c8730bbe9f34452def12b0328bfd'
end

[kyrylo]

Judging by your examples, it's hard for me to see how Airbrake breaks DelayedJob for you. I tested it locally with simple examples and it works for me, with or without Airbrake.

It looks like in your second example from IRB t.process_pending_files returns nil because the class of processor is not Delayed::Backend::ActiveRecord::Job (that is, is_a? returns false). I have a suspicion that processor is equal to nil, because self.respond_to? method returns false.

FWIW, from what I know, if you define handle_asynchronously :import_1c, you don't need to call delay anymore (you have t.delay.import_1c, and it should be just t.import_1c).

I would suggest to run DelayedJob with rake jobs:work to debug this better.

[artempankov]

i called delay from console just for testing purpose

but class of processor can only be Delayed::Backend::ActiveRecord::Job if handle_asynchronously works. but u r actually right, with code

    def process_pending_files
      method = %{#{EXCHANGE_TYPES[exchange_type]}_#{PARSE_METHODS[parse_method]}}
      logger.info "method: #{method}"
      processor = self.send method if self.respond_to? method
      logger.info "processor: #{processor} #{processor.class.to_s} #{processor.class}"
      if processor.is_a?(Delayed::Backend::ActiveRecord::Job)
        self.jobs << processor
        save
      end
    end  

i get:

2.1.5 :002 > t.process_pending_files
method: import_1c
processor: 67b83644ce6b8b2c04e3b768 String String

So aith Airbrake enabled, import_1c is recognized as a string, not as method

[kyrylo]

What's the source code of import_1c?

[artempankov]

    def import_1c
      unless self.state == SpreeExchange::Transfer.state_code(:failure) or self.state == SpreeExchange::Transfer.state_code(:processed)
        if self.state == SpreeExchange::Transfer.state_code(:pending)
          self.state = SpreeExchange::Transfer.state_code :progress
          save
        end
        Sunspot.session = Sunspot::Rails::StubSessionProxy.new(Sunspot.session)

        something_processed = false

        transfer_attachments.where(state: SpreeExchange::TransferAttachment.state_code(:pending)).where("file_file_name LIKE '%.xml'").order(:id).each do |attachment|
          unless attachment.nil?
            attachment.state = SpreeExchange::TransferAttachment.state_code(:progress)
            attachment.save

            base_filename = attachment.file_file_name.sub /\.xml$/i, ''
            if STATES.values.include?(base_filename.to_sym)
              self.state = SpreeExchange::Transfer.state_code base_filename.to_sym
              save
            end
            node_set = Nokogiri::XML File.open attachment.file.path
            begin
              Spree::Product.import_1c node_set, transfer_attachments
              attachment.state = SpreeExchange::TransferAttachment.state_code(:success)
              attachment.save
              if transfer_attachments.where("file_file_name LIKE '%.xml'").where.not(state: SpreeExchange::TransferAttachment.state_code(:success)).count == 0
                self.state = SpreeExchange::Transfer.state_code :success
                save
              end

              something_processed = true

            rescue
              attachment.state = SpreeExchange::TransferAttachment.state_code :failure
              attachment.save
              self.message = $!.message
              self.exception_backtrace = $1.backtrace
              self.state = SpreeExchange::Transfer.state_code :failure
              save
            end
          end
        end

        Sunspot.session = Sunspot.session.original_session
        Spree::Product.reindex_updated_after(created_at)

        if something_processed and Delayed::Job.where('handler LIKE ?', '%update_yandex_market%').count < 2
          self.update_yandex_market
        end
      end
    end

[kyrylo]

This method can return 2 values: nil or the return value of self.update_yandex_market.

• When the unless self.state == SpreeExchange::Transfer.state_code(:failure) or self.state == SpreeExchange::Transfer.state_code(:processed) condition is not met, it returns nil.
• When the if something_processed and Delayed::Job.where('handler LIKE ?', '%update_yandex_market%').count < 2 is not met, it also returns nil
• When the previous condition is met, it returns what self.update_yandex_market returns (which apparently is a String).

Sorry, but I fail to see how it can return a processor, which is a Delayed::Backend::ActiveRecord::Job instance, and I don't see any clues why it breaks the Airbrake library.

[artempankov]

i wrote:

  def import_1c
      #...
  end
  handle_asynchronously :import_1c, :queue => 'import',  :run_at => Proc.new { Time.now.end_of_day - 7200 + Time.now.hour*60 + Time.now.min }  
  #...

So when you executing method specified in handle_asynchronously, it doesn't actually executed, and Delayed::Backend::ActiveRecord::Job instance returned.
And now method actually return String instance, not Delayed::Backend::ActiveRecord::Job
handle_asynchronously doesn't works as designed in my application with airbrake enabled

[artempankov]

i've made some research.
downgrading airbrake version to 4.0.0 fixes this issue. And 4.1.0 brakes delayed_job again.

[kyrylo]

Thanks, that's a very useful information! I'll investigate this later today.

[kyrylo]

OK, I looked through commits between 4.1.0 and 4.0.0 and couldn't find anything relevant.

How do you integrate Delayed Job with Airbrake? Could you show your Gemfile.lock?

[kyrylo]

A gentle ping.