Skip to content

Add framework for timer startup log statement#47

Merged
gahjelle merged 6 commits into
realpython:mainfrom
pricemg:main
Nov 8, 2022
Merged

Add framework for timer startup log statement#47
gahjelle merged 6 commits into
realpython:mainfrom
pricemg:main

Conversation

@pricemg
Copy link
Copy Markdown
Contributor

@pricemg pricemg commented Nov 6, 2022

When using the timer I always put an additional log statement when instantiating the timer to provide feedback that the timer has begun (in my particular case it's to provide feedback to users that the stage in the script is running instead of staring at a screen for several minutes to see the final stop timer logging statement).

With that in mind I'm opening this PR to see if this is a feature(?) that people think would be worthwhile folding into the codetiming package proper.

The example output with the changes implemented would be

>>> t = Timer()
>>> t.start()
>>> time.sleep(5)
>>> t.stop()

Timer started...
Elapsed time: 5.0015 seconds

>>> with Timer(name="context manager"):
>>>     time.sleep(5)

Timer context manager started...
Elapsed time: 5.0028 seconds

>>> @Timer(name="decorator")
>>> def stuff():
>>>     time.sleep(5)
>>> stuff()

Timer decorator started...
Elapsed time: 5.0025 seconds


>>> import logging
>>> logging.basicConfig(
>>>     level=logging.INFO,
>>>     format='%(asctime)s %(levelname)s %(name)s: %(message)s',
>>> )
>>> logger = logging.getLogger(__name__)
>>> t = Timer(logger=logger.info)
>>> t.start()
>>> time.sleep(5)
>>> t.stop()

2022-11-06 21:13:13,174 INFO __main__: Timer started...
2022-11-06 21:13:18,176 INFO __main__: Elapsed time: 5.0014 seconds

I am in no way tied to the string I've chosen for printing when a timer in instantiated, so if people had a preferred statement I can swap it out.

I've updated all the tests to handle the change with the exception of test_accumulated_explicit_timer, which fails due to the two timers in the test no longer having the same total time recorded (e.g. assert 0.0006444760000000049 == 0.0020246230000000587 as an output for the failing test). I'm at a bit of a loss on how to reconcile this particular test so would appreciate some guidance here also if the PR is to precede.

@gahjelle
Copy link
Copy Markdown
Collaborator

gahjelle commented Nov 7, 2022

Hi @pricemg

Thanks a lot for this! I think that this can be a worthwhile feature to have in the library that can be useful in many settings.

However, I think that it should be opt-in and not always show, as that would break the current behavior. For example, in many of my projects, I already log the beginning of a stage with other means, so this message would just add noise. Maybe we can add an argument named initial_text or something to that effect.

This would also allow users to provide their own phrasing of the text that is logged, maybe with a default for convenience. The API could then look something like this (context manager examples, but similar in all use cases):

>>> with Timer():
>>>     time.sleep(1)
...
Elapsed time: 1.0008 seconds

>>> with Timer(initial_text=True):
>>>     time.sleep(1)
...
Timer started
Elapsed time: 1.0008 seconds

>>> with Timer(name="pancakes", initial_text=True):
>>>     time.sleep(1)
...
Timer 'pancakes' started
Elapsed time: 1.0008 seconds

>>> with Timer(initial_text="And so it begins ..."):
>>>     time.sleep(1)
...
And so it begins ...
Elapsed time: 1.0008 seconds

>>> with Timer(name="pancakes", initial_text="It's time for {name}"):
>>>     time.sleep(1)
...
It's time for pancakes
Elapsed time: 1.0008 seconds

Regarding the failing test: I wonder if it's caused by the naming of the timer. It should have a unique name so that it doesn't accumulate from other tests as well.

Do you want to continue your work on this? Also, feel free to add yourself to AUTHORS.md and a note under Unreleased in CHANGELOG.md as part of this PR.

Thanks again!

@pricemg
Copy link
Copy Markdown
Contributor Author

pricemg commented Nov 7, 2022

Hi @gahjelle, glad you like the sound of this idea! Thanks for the comments also, having it default to not printing on startup would've made my life a lot easier for tweaking the tests!

I've revised the implementation to mimic the functionality as you detailed it. As I say it meant I could revert all the tests back to initial state, and just add new tests for when initial_text is specified. Everything else seems ok to go then :D

@gahjelle gahjelle merged commit 59c13ab into realpython:main Nov 8, 2022
@gahjelle
Copy link
Copy Markdown
Collaborator

gahjelle commented Nov 8, 2022

This is great @pricemg Thank you so much for implementing this! Also, thank you for the extra clean-up in the existing tests. I did a few small tweaks and have now merged this.

I'll go ahead and make a new release of the package as well so that your updates should be available on PyPI shortly.

@pricemg
Copy link
Copy Markdown
Contributor Author

pricemg commented Nov 8, 2022

Fab! Glad I could contribute and thanks for the speedy review and tidy up!

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.

2 participants