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

adjust_total_time before running on_complete callbacks #84

Merged
merged 1 commit into from
May 27, 2021

Conversation

pedropb
Copy link
Contributor

@pedropb pedropb commented May 5, 2021

Closes #83

What are you trying to accomplish?

We were using the on_complete callback to report the job total run time but we noticed that total_time only gets updated after the callbacks are called.

What approach did you choose and why?

There were 3 options:

  1. Move adjust_total_time so that it's called before the callbacks.
  2. Copy adjust_total_time so that it's called before the callbacks and also right before logging the output summary. This could be useful in case the "total_time after callbacks" is valuable.
  3. Publish a new event via ActiveSupport::Notifications.instrument instead. This would overlap with the callback functionality.

I decided for 1 because I think it's the one that makes the most sense.

What reviewers should focus on?

  • I'm not familiar with writing RubyGems so I added Timecop as a dependency without a group. If that's problematic I can try to come up with another solution to stub the passage of time.
  • I would consider this a bugfix but if users are relying on the inaccurate total_time inside on_complete callbacks, this patch would be a breaking change.

Gemfile Outdated Show resolved Hide resolved
@pedropb pedropb force-pushed the on_completed_with_accurate_time branch from a189927 to fa25159 Compare May 6, 2021 20:37
@pedropb pedropb force-pushed the on_completed_with_accurate_time branch from fa25159 to 691c367 Compare May 6, 2021 20:38
@pedropb
Copy link
Contributor Author

pedropb commented May 6, 2021

Latest pushed changes:

  • Moved adjust_total_time from the completed? branch to the end of iterate_with_enumerator.
  • Dropped TimeCop in favour of ActiveSupport::Testing::TimeHelpers.
  • Consolidate the test files by merging the separate callbacks_test.rb logic into iteration_test.rb.

Comment on lines +239 to +243
def test_jobs_using_on_complete_have_accurate_total_time
freeze_time do
JobThatCompletesAfter3Seconds.perform_now(->(job) { assert_equal(3, job.total_time) })
end
end
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I would suggest simplifying the test:

def test_jobs_using_on_complete_have_accurate_total_time
    freeze_time do
      job = JobThatCompletesAfter3Seconds.new
      job.perform_now
      assert_equal(3, job.total_time)
    end
  end

That way you do not need to pass the assertion around, which is a little weird 😄

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This is a different test though and it would already pass on master without the patch.

The reason for passing the assertion around is so it can be injected in the on_complete handler to show that at that moment, it will/won't have the accurate total time.

Copy link
Contributor

@GustavoCaso GustavoCaso left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Code LGTM. I would like it if you could modify the test file to remove the need to pass the assertions around. Apart from that this is ready to be merge 😄

@pedropb
Copy link
Contributor Author

pedropb commented May 11, 2021

@djmortonShopify 2 questions before I hit merge:

  1. should I bump the version in this PR?
  2. what version bump (major, minor, patch) do you think this change should be?

@djmortonShopify
Copy link
Contributor

@djmortonShopify 2 questions before I hit merge:

1. should I bump the version in this PR?

2. what version bump (major, minor, patch) do you think this change should be?

I think we usually bump the version in a separate PR. I'm ok with a patch version bump for this because I'm still of a mind that this is a bug fix. There are no changes to the API, so it'll only "break" for people relying on the previous, arguably incorrect, behaviour. @GustavoCaso Thoughts?

@pedropb pedropb merged commit 1df2b75 into master May 27, 2021
@pedropb pedropb deleted the on_completed_with_accurate_time branch May 27, 2021 17:39
@shopify-shipit shopify-shipit bot temporarily deployed to rubygems May 27, 2021 17:41 Inactive
@pedropb pedropb mentioned this pull request May 28, 2021
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.

total_time is inaccurate when accessed inside on_complete callback
4 participants