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

Prettify duration message at end of execution #5364

Conversation

jared-rimmer
Copy link
Contributor

@jared-rimmer jared-rimmer commented Jun 11, 2022

resolves #5253

Description

  • Added a new function in utils called humanise_execution_time that returns a string in the format: X hours Y minutes and Z seconds
  • Format execution, as a string, with hours/minutes/seconds (1 hours 6 minutes and 51 seconds)
  • Add execution_time (float, representing seconds) as a dataclass attribute that gets passed into HookFinished, and included in its structured (JSON) output, even if it isn't templated into the human-freindly message
  • Final output after a dbt run looks like Finished running 1 table model, 1 view model in 0 hours 0 minutes and 0.36 seconds (0.36s).

Checklist

@jared-rimmer jared-rimmer requested a review from a team June 11, 2022 15:31
@jared-rimmer jared-rimmer requested review from a team as code owners June 11, 2022 15:31
@cla-bot cla-bot bot added the cla:yes label Jun 11, 2022
Copy link
Contributor

@jtcohen6 jtcohen6 left a comment

Choose a reason for hiding this comment

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

Nice, thanks for picking this up @jared-rimmer! The change proposed here looks good to me. I'll leave final code review to folks on the Core engineering team.

@@ -398,11 +398,15 @@ def print_results_line(self, results, execution_time):
execution = ""

if execution_time is not None:
execution = " in {execution_time:0.2f}s".format(execution_time=execution_time)
execution = utils.humanise_execution_time(execution_time=execution_time)
Copy link
Contributor

Choose a reason for hiding this comment

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

Question for Core engineers: Does it make sense to have this prettification/humanisation logic live in the run task / event call-site? Or should it be within the class definition for HookFinished?

(Also, my EU-resident computer is very happy with this spelling of humanise, but we may wish to Americanize it for consistency)

Copy link
Contributor Author

Choose a reason for hiding this comment

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

I've Americanized the spelling to Humanize as you suggested.

I'll wait on the response from the core engineers about the other point and will be happy to make the change if needed.

This is my first contribution so it would also be good to understand where some tests for the new functions should live.

Copy link
Contributor

Choose a reason for hiding this comment

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

I think for now it's fine to leave the prettification it where it is. I suspect that HookFinished may be one of the events that we'll be touching with the upcoming event work, so rather than guess what info people will want in it, let's just defer it :)

I think a test in test/unit/test_utils.py would be fine. You could create a basic test that does 'run_dbt_and_capture' (grep tests/functional for examples). I'm not sure exactly where to put it, but someplace neutral like tests/functional/basic/test_jaffle_shop.py should be fine.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Thanks for the guidance @gshank. I've gone ahead and done those things. Let me know what you think.

fire_event(HookFinished(stat_line=stat_line, execution=execution))
fire_event(
HookFinished(
stat_line=stat_line, execution=execution, execution_time=execution_time
Copy link
Contributor

Choose a reason for hiding this comment

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

👍 Thanks for adding the real float in here as well!

@jtcohen6 jtcohen6 added the ready_for_review Externally contributed PR has functional approval, ready for code review from Core engineering label Jun 14, 2022
@gshank
Copy link
Contributor

gshank commented Jun 14, 2022

Oh, it looks like you need to pip install pre-commit and run 'pre-commit run --all-files' to get the black formatting.

@gshank
Copy link
Contributor

gshank commented Jun 14, 2022

And test/unit/test_events.py needs to be updated.

Copy link
Contributor

@ChenyuLInx ChenyuLInx left a comment

Choose a reason for hiding this comment

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

@jared-rimmer Thanks for the quick turn over and added the tests!!

@ChenyuLInx
Copy link
Contributor

@jared-rimmer looks like there might be some issue with the tests

@gshank
Copy link
Contributor

gshank commented Jun 15, 2022

I believe that the functional test is failing because the order of the tests isn't guaranteed. You can either add a "seed" command to the new test, or combine it with the existing one (which already has run seed).

Otherwise looks good!

@ChenyuLInx
Copy link
Contributor

@jared-rimmer I went ahead and added the seed step to you test, hope you don't mind it.

@ChenyuLInx ChenyuLInx merged commit 6572b7e into dbt-labs:main Jun 15, 2022
@ChenyuLInx
Copy link
Contributor

@jared-rimmer Merged! Thanks for taking the time to implement this!!

@jared-rimmer
Copy link
Contributor Author

Not at all @ChenyuLInx thanks for all your help!

@jared-rimmer jared-rimmer deleted the feature/ct-649-prettify-duration-at-the-end-of-execution branch September 8, 2022 10:07
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
cla:yes ready_for_review Externally contributed PR has functional approval, ready for code review from Core engineering
Projects
None yet
Development

Successfully merging this pull request may close these issues.

[CT-649] [Feature] Prettify duration message at the end of execution
4 participants