CODEWITHSUNDEEP
ruby-on-railssidekiq
Fei Qu
Fei Qu

Reputation: 141

Unexpected sidekiq jobs get executed

I'm using sidekiq cron to run some jobs. I have a parent job which only runs once, and that parent job starts 7 million child jobs. However, in my sidekiq dashboard, it says over 42 million jobs enqueued. I checked those enqueued jobs, they are my child jobs. I'm trying to figure out why so many more jobs than expected are enqueued. I checked the log in sidekiq, one thing I noticed is, "Cron Jobs - add job with name: new_topic_post_job" shows up many times in the log. new_topic_post is the name of the parent job in schedule.yml. Following lines also show up many times

2019-04-18T17:01:22.558Z 12605 TID-osb3infd0 WARN: Processing recovered job from queue queue:low (queue:low_i-03933b94d1503fec0.nodemodo.com_4): "{\"retry\":false,\"queue\":\"low\",\"backtrace\":true,\"class\":\"WeeklyNewTopicPostCron\",\"args\":[],\"jid\":\"f37382211fcbd4b335ce6c85\",\"created_at\":1555606809.2025042,\"locale\":\"en\",\"enqueued_at\":1555606809.202564}"
2019-04-18T17:01:22.559Z 12605 TID-osb2wh8to WeeklyNewTopicPostCron JID-f37382211fcbd4b335ce6c85 INFO: start

WeeklyNewTopicPostCron is the name of the parent job class. Wondering does this mean my parent job runs multiple times instead of only 1? If so, what's the cause? I'm pretty sure the time in the cron job is right, I set it to "0 17 * * 4" which means it only runs once a week. Also I set retry to false for parent job and 3 for child jobs. So even all child jobs fail, we should still only have 21 million jobs. Following is my cron job setting in schedule.yml

new_topic_post_job:
  cron: "0 17 * * 4"
  class: "WeeklyNewTopicPostCron"
  queue: low

and this is WeeklyNewTopicPostCron:

class WeeklyNewTopicPostCron
  include Sidekiq::Worker

  sidekiq_options queue: :low, retry: false, backtrace: true

  def perform
    processed_user_ids = Set.new
    TopicFollower.select("id, user_id").find_in_batches(batch_size: 1000000) do |topic_followers|
      new_user_ids = []
      topic_followers.map(&:user_id).each { |user_id| new_user_ids << user_id if processed_user_ids.add?(user_id) }
      batch_size = 1000
      offset = 0
      loop do
        batched_user_ids_for_redis = new_user_ids[offset, batch_size]
        Sidekiq::Client.push_bulk('class' => NewTopicPostSender, 
                                  'args' => batched_user_ids_for_redis.map { |user_id| [user_id, 7] }) if batched_user_ids_for_redis.present?
        break if batched_user_ids_for_redis.size < batch_size
        offset += batch_size
      end
    end
  end
end

Upvotes: 0

Views: 952

Answers (1)

amit_saxena
amit_saxena

Reputation: 7624

Most probably your parent sidekiq job is causing the sidekiq process to crash, which then results in a worker restart. On restart sidekiq probably tries to recover the interrupted job and starts processing it again (from the beginning). Some details here: https://github.com/mperham/sidekiq/wiki/Reliability#recovering-jobs

This probably happens multiple times before the parent job eventually finishes, and hence the extremely high number of child jobs are created. You can easily verify this by checking the process id of the sidekiq process while this job is being run and it most probably will keep changing after a while:

ps aux | grep sidekiq

It could be that you have some monit configuration to restart sidekiq in case memory usage goes too high.Or it might be that this query is causing the process to crash:

TopicFollower.select("id, user_id").find_in_batches(batch_size: 1000000)

Try reducing the batch_size. 1million feels like too high a number. But my best guess is that the sidekiq process dies while processing the long running parent process.

Upvotes: 1

Related Questions