async-http icon indicating copy to clipboard operation
async-http copied to clipboard

Sidekiq process got stuck in busy queue

Open mohsinssi opened this issue 3 years ago • 19 comments

Sidekiq task got stuck sometimes in busy queue when using Async-http and perform multiple simultaneous requests to third party. Some methods i have tried is apply timeout to tasks and also on third party calling.

mohsinssi avatar Jan 03 '22 17:01 mohsinssi

Are you able to give some more details about the nature of the error/hang? Do you have any error logs?

ioquatix avatar Jan 03 '22 22:01 ioquatix

No errors occur however i tried to add custom logs to each function start and end but for some reason second task start log comes but not end log.

Async do
      results = []
      barrier = Async::Barrier.new
      semaphore = Async::Semaphore.new(2, parent: barrier)
      @params.each_slice(500) do |param|
        semaphore.async do
          response = fetch_articles(param)
          body = JSON.parse(response.body)
          results << body
        end
      end
      Rails.logger.debug { 'AsyncHttp#wait' }
      barrier.wait
      process_results(results)
    end

   def fetch_articles(param)
    Rails.logger.debug { "Requesting articles start at #{Time.current}" } // this comes on two times as our params count is more than 500 
    response =  HTTParty call with timeout 6
    Rails.logger.debug { "Requesting articles end at #{Time.current}" } // this comes only one time in logs
    response
  end

mohsinssi avatar Jan 04 '22 06:01 mohsinssi

HTTParty might not be compatible with Async on Ruby 2.x - try using Async::HTTP::Internet.

ioquatix avatar Jan 04 '22 20:01 ioquatix

@ioquatix i have tried that before also the behavior was same.

mohsinssi avatar Jan 05 '22 06:01 mohsinssi

Does it hang every single time or only occasionally?

ioquatix avatar Jan 05 '22 22:01 ioquatix

@ioquatix it hangs occasionally

mohsinssi avatar Jan 06 '22 05:01 mohsinssi

Okay let me see if I can reproduce it.

Can you tell me the exact versions of the gems you are using, e.g. your gem lock file, and specifically sidekiq, sidekiq pro, etc versions, your Ruby version, OS, and async / async-http versions.

ioquatix avatar Jan 06 '22 07:01 ioquatix

Sure sidekiq (6.2.2) sidekiq-cron (1.2.0) async-http (0.56.5) Ruby 3.0.2-alpine3.13 OS Linux

mohsinssi avatar Jan 06 '22 07:01 mohsinssi

Can you tell me Async version too please :)

ioquatix avatar Jan 06 '22 07:01 ioquatix

Are you able to try Ruby 3.0.3? There was a few bugs in 3.0.2.

ioquatix avatar Jan 06 '22 07:01 ioquatix

(Or try using Ruby 2.7.4 / 2.7.5 which is rock solid).

ioquatix avatar Jan 06 '22 07:01 ioquatix

async (1.30.1) Also not yet tried other ruby versions as i am unable to understand what's causing this issue

mohsinssi avatar Jan 06 '22 07:01 mohsinssi

Ruby 3.0.2 has a bug in IO wait, which can cause intermittent hang, which was fixed in Ruby 3.0.3. I'm not sure if it impacts Async 1.x but it's possible.

ioquatix avatar Jan 06 '22 08:01 ioquatix

ok i will try to upgrade to Ruby 3.0.3 and if issue still comes up i will notify here

mohsinssi avatar Jan 06 '22 10:01 mohsinssi

@ioquatix I upgraded to Ruby 3.0.3 (also tried 3.1.0) and now the issue changed. After couple of hours sidekiq process get stop and on logs i checked and it shows the same like i mentioned above the request got started but never ended and also cpu spikes up from 15% to 25% suddenly and may be thats the cause for sidekiq process stop.

mohsinssi avatar Feb 07 '22 15:02 mohsinssi

Here is the latest code

Async do |task|
  task.with_timeout(80) do
    results = []
    barrier = Async::Barrier.new
    semaphore = Async::Semaphore.new(2, parent: barrier)
    internet = Async::HTTP::Internet.new
    @params.each_slice(500) do |param|
      semaphore.async do |sem_task|
        sem_task.with_timeout(10) do
          response = fetch_articles(param, internet)
          body = JSON.parse(response.body)
          results << body
          response&.finish
        end
      end
    end
    Rails.logger.debug { 'AsyncHttp#wait' }
    barrier.wait  (Here it stucked)
    process_results(results)
  ensure
       internet&.close
  end
end

 def fetch_articles(param, internet)
  Rails.logger.debug { "Requesting articles start at #{Time.current}" } // this comes on logs two times as our params count is more than 500
  response =  request using Internet
  Rails.logger.debug { "Requesting articles end at #{Time.current}" }
  response
end

mohsinssi avatar Feb 07 '22 15:02 mohsinssi

Thanks I'll check it.

ioquatix avatar Feb 07 '22 18:02 ioquatix

Thanks I'll check it.

Yes let me know if you found the cause and how i can solve this

mohsinssi avatar Feb 07 '22 19:02 mohsinssi

Can you please try updating to the latest version of async - there was a bug in Async::Barrier that could lead to a hang in some situations.

ioquatix avatar May 05 '22 01:05 ioquatix

We also found a bug in Ruby's autoload, which can lead to deadlocks, it is fixed in Ruby 3.2. Please open a new issue if you still have issues on the latest release.

ioquatix avatar Oct 31 '22 04:10 ioquatix