Hi all,
For this Snippet Wednesday, I wanted to look at a slightly more advanced topic: “Optimizing your code performance”.
Please note, if you are still actively updating and reshaping your application, you might want to postpone optimizing your code until you have a stable implementation.
When Automating the boring, we often automate repetitive tasks that might need to be executed 100 to 10,000 times or more (especially in optimizations). By finding the bottlenecks, we can focus on optimizing the parts of the code that provides the most impact in reducing total computation time.
Let’s take the following example app:
class MyEntity(ViktorController):
...
@PlotlyAndDataView("Results", duration_guess=1)
def visualize_results(self, params, **kwargs) -> PlotlyAndDataResult:
x = calculate_x(params)
y = calculate_y(x)
plot = create_plot(x, y)
return PlotlyAndDataResult(..)
We have a PlotlyAndDataView that takes almost 20 seconds to complete, and you think this could be improved to provide a better user experience. We can look at the problem of ‘finding the bottleneck’ with two levels of complexity:
- Simple timing of code execution
- Advanced profiling of function calls (includes call frequency, call duration, etc.)
Today, we’ll focus on the first one. The code snippets below provide a nice Timer tool that can be used for ‘Simple timing of code execution’. This is usually the first tool that I go to, if I want to achieve some basic performance improvements.
import time
from contextlib import ContextDecorator
from dataclasses import dataclass, field
from typing import Any, Optional
class TimerError(Exception):
"""A custom exception used to report errors in use of Timer class"""
@dataclass
class Timer(ContextDecorator):
"""Time your code using a context manager, or decorator"""
text: str = "Elapsed time: {:0.4f} seconds"
_start_time: Optional[float] = field(default=None, init=False, repr=False)
def start(self) -> None:
"""Start a new timer"""
if self._start_time is not None:
raise TimerError(f"Timer is running. Use .stop() to stop it")
self._start_time = time.perf_counter()
def stop(self) -> float:
"""Stop the timer, and report the elapsed time"""
if self._start_time is None:
raise TimerError(f"Timer is not running. Use .start() to start it")
# Calculate elapsed time
elapsed_time = time.perf_counter() - self._start_time
self._start_time = None
# Report elapsed time
print(self.text.format(elapsed_time))
return elapsed_time
def __enter__(self) -> "Timer":
"""Start a new timer as a context manager"""
self.start()
return self
def __exit__(self, *exc_info: Any) -> None:
"""Stop the context manager timer"""
self.stop()
This can then be used in your App in the following ways.
class MyEntity(ViktorController):
...
@PlotlyAndDataView("Results", duration_guess=1)
def visualize_results(self, params, **kwargs) -> PlotlyAndDataResult:
t = Timer()
t.start() # Start the timer
x = calculate_x(params)
y = calculate_y(x)
plot = create_plot(x, y)
t.stop() # End the timer and print the duration
return PlotlyAndDataResult(..)
or using a with-statement and/or decorator:
@Timer(text="Created plot in {:.2f} seconds")
def create_plot(x, y):
...
class MyEntity(ViktorController):
...
@PlotlyAndDataView("Results", duration_guess=1)
def visualize_results(self, params, **kwargs) -> PlotlyAndDataResult:
with Timer(text="Calculated x and y in {:.2f} seconds"):
x = calculate_x(params)
y = calculate_y(x)
plot = create_plot(x, y)
return PlotlyAndDataResult(..)
When running the visualize_results method in your app, you might get the following prints in the terminal:
2023-08-22 14:57:20.010 INFO : Job (uid: 123) received - EntityType: MyEntity - call: visualize_results
Calculated x and y in 5.23 seconds
Created plot in 14.19 seconds
2023-08-22 14:57:39.460 INFO : Job (uid: 123) completed in 19450ms
Looking at the print statements you can see that, surprisingly, it is the plotting of the result that takes most time. This is your most likely ‘bottleneck’. You can now dive deeper into the create_plot function and use the Timer tool once again to find the ‘bottlenecks’.
Happy (bottleneck) hunting!
Credits where credits are due:
I was inspired by this Real Python Article and created a simplified version of the tool. The article also briefly discusses the more advanced profiling of code.
P.S.
I will soon post a follow-up that dives deeper into ‘Advanced profiling of function calls’. Advanced profiling will allow you to get more fine-grained insight into your code performance, but it does have a much steeper learning curve. Stay tuned!