bensheldon / good_job

Multithreaded, Postgres-based, Active Job backend for Ruby on Rails.
https://goodjob-demo.herokuapp.com/
MIT License
2.53k stars 190 forks source link

Unexpected behavior of calling perform_now inside another job #1379

Closed mgn200 closed 3 weeks ago

mgn200 commented 3 weeks ago

Good day! I've experienced problem with calling Job1.perform_now inside a Job2 that has been called with #perform_later. Both of the jobs have set good_job_control_concurrency_with(total_limit: 1)

I am using Rails 7.1 with good_job v 3.28 Problem can be reproduced like this:

class SecondJob < ApplicationJob

  good_job_control_concurrency_with(total_limit: 1)

  def perform
      puts "Doing something inside SecondJob"
  end

end

class FirstJob < ApplicationJob
  good_job_control_concurrency_with(total_limit: 1)

  def perform
      puts "Starting first job"
      result = SecondJob.perform_now
      puts "After second job"
      puts "Result of the second job: #{result}"
  end
end

I call FirsJob.perform_later and expect SecondJob to be done in place, not to be enqued. But the printing goes like this(i omitted the queue_name in class definitions):

[GoodJob] [341350] GoodJob 3.28.0 started scheduler with queues=* max_threads=5.
[GoodJob] Notifier subscribed with LISTEN
per[GoodJob] Notifier received payload: {"queue_name":"cron","scheduled_at":"2024-06-19T13:59:00.013+03:00"}

Starting first job

[GoodJob] Notifier received payload: {"queue_name":"cron","scheduled_at":"2024-06-19T13:59:08.554+03:00"}

After second job
Result of the second job: GoodJob::ActiveJobExtensions::Concurrency::ConcurrencyExceededError
Doing something inside SecondJob

[GoodJob] [341350] [GoodJob::Scheduler(queues=* max_threads=5)-thread-1] Executed GoodJob ad21a53b-b832-4d5f-853f-a278e8efaab3

So it seems that SecondJob is not getting executed in place and instead tries to get enqueued, and fails with ConcurrencyExceededError - not sure why.

I see two records in the good_jobs table. The first is FirstJob, with an error column that has doubled error:

error:
   "GoodJob::ActiveJobExtensions::Concurrency::ConcurrencyExceededError: GoodJob::ActiveJobExtensions::Concurrency::ConcurrencyExceededError"

And the second record is a SecondJob, it has an empty error field, but populated serialized_params["exception_executions"]

 "exception_executions"=>
     {"[GoodJob::ActiveJobExtensions::Concurrency::ConcurrencyExceededError]"

Everything seems to be working fine if i remove concurrency_key from SecondJob. Trying to understand if this is a bug, or an expected behavior.

Thank you.

bensheldon commented 3 weeks ago

Have you upgraded to v3.28.1? I think this is fixed in that release: https://github.com/bensheldon/good_job/releases/tag/v3.28.1

Let me know if it isn't and I'll take another look.

mgn200 commented 3 weeks ago

Have you upgraded to v3.28.1? I think this is fixed in that release: https://github.com/bensheldon/good_job/releases/tag/v3.28.1

Let me know if it isn't and I'll take another look.

Yes, it is fixed now, thank you! Should have checked changelog and update gem in the first place.