Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Use sidekiq/testing Worker.clear API in sidekiq_unique_jobs/testing #713

Merged

Conversation

dsander
Copy link
Contributor

@dsander dsander commented May 31, 2022

Instead of reimplementing the logic, we use the upstream Worker.clear API
in the sidekiq_unique_jobs/testing Worker.clear overwrite.

This fixes an issue that causes an infinite loop in drain_all after
calling clear on a worker class that has it's queue name defined as a
symbol. Because sidekiq/testing uses strings as the keys for the
internal state tracking calling Sidekiq::Queues[queue].clear cleared a
queue that never contained a job, while leaving jobs in the
"string-indexed" queue.

This only actually works after this is merged into sidekiq until
then the old behaviour remains the same (clearing workers with their
queue name defined as strings is fine).

Instead of reimplementing the logic, we use the upstream `Worker.clear` API
in the `sidekiq_unique_jobs/testing` `Worker.clear` overwrite.

This fixes an issue that causes an infinite loop in `drain_all` after
calling `clear` on a worker class that has it's queue name defined as a
symbol. Because `sidekiq/testing` uses strings as the keys for the
internal state tracking calling `Sidekiq::Queues[queue].clear` cleared a
queue that never contained a job, while leaving jobs in the
"string-indexed" queue.

This only actually works after [this][1] is merged into `sidekiq` until
then the old behaviour remains the same (clearing workers with their
queue name defined as strings is fine).

[1]: sidekiq/sidekiq#5352
@dsander dsander force-pushed the fix-testing-api-worker-clear branch from 119c643 to 68872b2 Compare May 31, 2022 12:27
@mhenrixon mhenrixon merged commit 2eb4b99 into mhenrixon:main Jun 2, 2022
@fotinakis
Copy link

@dsander @mhenrixon I think this change may have introduced very noisy logging into all test runs:

image

(This rspec test is completely unrelated to jobs and sidekiq-unique-jobs.)

Is that possible?

@dsander
Copy link
Contributor Author

dsander commented Jul 12, 2022

@fotinakis Unsure, are you maybe using Sidekiq::Worker.clear_all in a global before hook or always clear one specific worker? To me the log output read more like it's coming from the reaper, though.

@fotinakis
Copy link

@dsander interesting — yes, apparently we are doing this in our main spec_helper:

  config.before(:each) { Sidekiq::Worker.clear_all }

I've disabled the sidekiq-unique-jobs logger in tests as a workaround for now. I'm not sure if you'd consider this a common flow/bug or not, so will just silence it on our end for now.

@dsander
Copy link
Contributor Author

dsander commented Jul 12, 2022

@fotinakis I don't think it is a bug, before this change the Sidekiq::Testing state could get out of sync in certain situations. Not sure how and why it would cause those reaper related log output. I think you should also be able to lower the log level of sidekiq-unique-jobs in the tests.

@fotinakis
Copy link

FYI that many more people may encounter this noisy logging once this is released — apparently calling Sidekiq::Worker.clear_all in a before(:each) is sidekiq's officially-documented way to do test harness setup: https://github.com/mperham/sidekiq/wiki/Testing#testing-worker-queueing-fake

@dsander
Copy link
Contributor Author

dsander commented Jul 12, 2022

FWIW we don't see it in our test suite, but that might be because of the log level. I'd need to double check if we have set it to WARN explicitly somewhere. I still don't really understand how this change here would trigger runs of the reaper. Have you tried git bisecting this repo to find the commit that introduced the log output?

@mhenrixon
Copy link
Owner

Actually @fotinakis the reason for why you see this now is most likely that it wasn't working before.

I agree on bumping the log level. Rails for example almost completely turn off logging manually enabled in the test environment.

I think it is valuable information that keys are being deleted and since I don't know how to check what environment your code is running in I'd rather leave that to the user.

Please let me know if you differ in opinion and or have any solutions to this that I haven't thought of.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

3 participants