I was looking for a solution for timing code execution. Of course, I found all sorts of solutions mostly suggesting the use of timeit module - which is pretty cool - or just using the time module. Neither of those really provides what I'm after.
I wanted a simple solution that
- I can quickly add to the code without changing the structure or logic
- can cover a single line or code block
- elegant and clean enough to even leave it in
I think I finally figured it out - using the context manager's dunder methods __enter__ and __exit__.
The idea is we capture the time when the context manager starts (__enter__), then just let the code run in the context-manager-block, finally, we capture the time when the context manager ends (__exit__) and do something with the result (print and/or return).
So here's the snippet:
import time
class ExecutionTimer:
def __init__(self, message='Execution time', unit='s'):
self.message = message
self.unit = unit
self.start_time = None
self.end_time = None
self.result = None
def __enter__(self):
self.start_time = time.time()
return self
def __exit__(self, exc_type, exc_value, traceback):
self.end_time = time.time()
self.result = self.end_time - self.start_time
self.print_time()
def print_time(self):
elapsed_time = self.result
if self.unit == 'ms':
elapsed_time *= 1000 # convert to milliseconds
elif self.unit == 'us':
elapsed_time *= 1e6 # convert to microseconds
elif self.unit == 'ns':
elapsed_time *= 1e9 # convert to nanoseconds
print(f"{self.message}: {elapsed_time}{self.unit}")
if __name__ == '__main__':
start_time = time.time()
time.sleep(1)
end_time = time.time()
print(f"Execution (s): {end_time - start_time}s")
with ExecutionTimer(message='Execution (s)', unit='s'):
time.sleep(1)
with ExecutionTimer(message="Execution (ms)", unit='ms'):
time.sleep(1)
with ExecutionTimer(message="Execution (us)", unit='us'):
time.sleep(1)
with ExecutionTimer(message="Execution (ns)", unit='ns'):
time.sleep(1)
# or just capture the value
with ExecutionTimer(message="Execution (ns)", unit='ns') as my_timer:
time.sleep(1)
# notice we are not in the context manager any more
print(my_timer.result)
print(my_timer.result)
and its output:
Execution (s): 1.0000789165496826s
Execution (s): 1.0000693798065186s
Execution (ms): 1000.067949295044ms
Execution (us): 1000072.0024108887us
Execution (ns): 1000071287.1551514ns
Execution (ns): 1000077962.8753662ns
1.0000779628753662
1.0000779628753662
Process finished with exit code 0
There's definitely some room for improvement. It can be integrated with logging to only emit messages to a certain log level OR it could use a "dry run" parameter to control the execution print method. Etc.
Feel free to use, test, and modify it as you please. It would be awesome if you could leave your constructive comments, ideas, and improvements so we can all learn from them.
Answer
Your implementation using a context manager (ExecutionTimer) for timing code execution is very elegant and clean! It provides a simple and reusable solution to measure execution time across different code blocks, which is exactly what you were looking for.
Here are a few suggestions and possible improvements for your code:
1. Customizable Output Handling
You mentioned the possibility of integrating it with logging, which is a great idea. By default, printing to the console may not be ideal in many production scenarios. Here's how you can integrate the ExecutionTimer with Python's logging module to control output based on logging levels.
import time
import logging
class ExecutionTimer:
def __init__(self, message='Execution time', unit='s', dry_run=False):
self.message = message
self.unit = unit
self.start_time = None
self.end_time = None
self.result = None
self.dry_run = dry_run
# Set up logging
self.logger = logging.getLogger(__name__)
if not self.logger.hasHandlers():
handler = logging.StreamHandler()
formatter = logging.Formatter('%(asctime)s - %(message)s')
handler.setFormatter(formatter)
self.logger.addHandler(handler)
self.logger.setLevel(logging.INFO)
def __enter__(self):
self.start_time = time.time()
return self
def __exit__(self, exc_type, exc_value, traceback):
self.end_time = time.time()
self.result = self.end_time - self.start_time
self.print_time()
def print_time(self):
elapsed_time = self.result
if self.unit == 'ms':
elapsed_time *= 1000 # convert to milliseconds
elif self.unit == 'us':
elapsed_time *= 1e6 # convert to microseconds
elif self.unit == 'ns':
elapsed_time *= 1e9 # convert to nanoseconds
if not self.dry_run:
self.logger.info(f"{self.message}: {elapsed_time}{self.unit}")
else:
self.logger.debug(f"{self.message}: {elapsed_time}{self.unit}")
# Usage examples
if __name__ == '__main__':
logging.basicConfig(level=logging.INFO)
with ExecutionTimer(message="Execution (s)", unit='s', dry_run=False):
time.sleep(1)
with ExecutionTimer(message="Execution (ms)", unit='ms', dry_run=False):
time.sleep(1)
with ExecutionTimer(message="Execution (us)", unit='us', dry_run=True):
time.sleep(1)
Now, you can control the output with the logging level:
logging.DEBUGfor more detailed info (e.g., dry runs).logging.INFOor higher for standard output.
2. Return the Result (Optional)
Sometimes you may want to capture the time result for further use (e.g., for comparisons, charts, etc.). While you already handle this via self.result, you can explicitly return it from the context manager so it can be assigned to a variable if needed.
class ExecutionTimer:
def __init__(self, message='Execution time', unit='s', dry_run=False):
self.message = message
self.unit = unit
self.start_time = None
self.end_time = None
self.result = None
self.dry_run = dry_run
def __enter__(self):
self.start_time = time.time()
return self
def __exit__(self, exc_type, exc_value, traceback):
self.end_time = time.time()
self.result = self.end_time - self.start_time
self.print_time()
return self.result # Optionally return the result
def print_time(self):
elapsed_time = self.result
if self.unit == 'ms':
elapsed_time *= 1000 # convert to milliseconds
elif self.unit == 'us':
elapsed_time *= 1e6 # convert to microseconds
elif self.unit == 'ns':
elapsed_time *= 1e9 # convert to nanoseconds
if not self.dry_run:
print(f"{self.message}: {elapsed_time}{self.unit}")
else:
print(f"[DEBUG] {self.message}: {elapsed_time}{self.unit}")
# Usage example
if __name__ == '__main__':
with ExecutionTimer(message="Execution (ms)", unit='ms') as timer:
time.sleep(1)
print(f"Elapsed time: {timer.result} seconds")
Now, you can retrieve the time result for further use after the block ends.
3. Consider Handling Exceptions Gracefully
If there's an exception within the context manager's block, you might want to handle it gracefully and still get the time output.
class ExecutionTimer:
def __init__(self, message='Execution time', unit='s', dry_run=False):
self.message = message
self.unit = unit
self.start_time = None
self.end_time = None
self.result = None
self.dry_run = dry_run
def __enter__(self):
self.start_time = time.time()
return self
def __exit__(self, exc_type, exc_value, traceback):
self.end_time = time.time()
self.result = self.end_time - self.start_time
self.print_time()
if exc_type is not None:
# Handle the exception if needed
print(f"Exception occurred: {exc_value}")
return True # Prevent the exception from propagating
def print_time(self):
elapsed_time = self.result
if self.unit == 'ms':
elapsed_time *= 1000 # convert to milliseconds
elif self.unit == 'us':
elapsed_time *= 1e6 # convert to microseconds
elif self.unit == 'ns':
elapsed_time *= 1e9 # convert to nanoseconds
if not self.dry_run:
print(f"{self.message}: {elapsed_time}{self.unit}")
else:
print(f"[DEBUG] {self.message}: {elapsed_time}{self.unit}")
This way, if an exception is raised in the context manager block, it will be caught and handled, and the time will still be printed.
4. Improved Time Conversion
Currently, your time conversion logic multiplies values based on the unit chosen. An improvement might be to include the exact time unit name when printing, so you can ensure users understand exactly what is being measured.
def print_time(self):
elapsed_time = self.result
unit_name = self.unit
if self.unit == 'ms':
elapsed_time *= 1000
unit_name = "milliseconds"
elif self.unit == 'us':
elapsed_time *= 1e6
unit_name = "microseconds"
elif self.unit == 'ns':
elapsed_time *= 1e9
unit_name = "nanoseconds"
print(f"{self.message}: {elapsed_time:.6f} {unit_name}")
This will give you a more descriptive output such as "Execution: 1000.123456 milliseconds".
Final Thoughts
Your solution is already quite clean, reusable, and adaptable. The above suggestions are optional but can add more flexibility and robustness to your implementation. Using context managers to handle timing in such an elegant way is definitely a great approach. It keeps your code clean and modular without disrupting the overall flow, making it easy to add to any part of the codebase.
Feel free to test and modify these ideas based on your specific needs. Great work!
