Python Timer Functions: Three Ways to Monitor Your Code

Python Timer Functions

If you check out the built-in time module in Python, then you’ll notice several functions that can measure time:

• monotonic()
• perf_counter()
• process_time()
• time()

Python 3.7 introduced several new functions, like thread_time(), as well as nanosecond versions of all the functions above, named with an _ns suffix. For example, perf_counter_ns() is the nanosecond version of perf_counter(). You’ll learn more about these functions later. For now, note what the documentation has to say about perf_counter():

Return the value (in fractional seconds) of a performance counter, i.e. a clock with the highest available resolution to measure a short duration. (Source)

First, you’ll use perf_counter() to create a Python timer. Later, you’ll compare this with other Python timer functions and learn why perf_counter() is usually the best choice.

Example: Download Tutorials

To better compare the different ways that you can add a Python timer to your code, you’ll apply different Python timer functions to the same code example throughout this tutorial. If you already have code that you’d like to measure, then feel free to follow the examples with that instead.

The example that you’ll use in this tutorial is a short function that uses the realpython-reader package to download the latest tutorials available here on Real Python. To learn more about the Real Python Reader and how it works, check out How to Publish an Open-Source Python Package to PyPI. You can install realpython-reader on your system with pip:

$ python -m pip install realpython-reader

Then, you can import the package as reader.

You’ll store the example in a file named latest_tutorial.py. The code consists of one function that downloads and prints the latest tutorial from Real Python:

 1# latest_tutorial.py
 2
 3from reader import feed
 4
 5def main():
 6    """Download and print the latest tutorial from Real Python"""
 7    tutorial = feed.get_article(0)
 8    print(tutorial)
 9
10if __name__ == "__main__":
11    main()

realpython-reader handles most of the hard work:

• Line 3 imports feed from realpython-reader. This module contains functionality for downloading tutorials from the Real Python feed.
• Line 7 downloads the latest tutorial from Real Python. The number 0 is an offset, where 0 means the most recent tutorial, 1 is the previous tutorial, and so on.
• Line 8 prints the tutorial to the console.
• Line 11 calls main() when you run the script.

When you run this example, your output will typically look something like this:

$ python latest_tutorial.py
# Python Timer Functions: Three Ways to Monitor Your Code

While many developers recognize Python as an effective programming language,
pure Python programs may run more slowly than their counterparts in compiled
languages like C, Rust, and Java. In this tutorial, you'll learn how to use
a Python timer to monitor how quickly your programs are running.

[ ... ]

## Read the full article at https://realpython.com/python-timer/ »

* * *

The code may take a little while to run depending on your network, so you might want to use a Python timer to monitor the performance of the script.

Your First Python Timer

Now you’ll add a bare-bones Python timer to the example with time.perf_counter(). Again, this is a performance counter that’s well-suited for timing parts of your code.

perf_counter() measures the time in seconds from some unspecified moment in time, which means that the return value of a single call to the function isn’t useful. However, when you look at the difference between two calls to perf_counter(), you can figure out how many seconds passed between the two calls:

>>> import time
>>> time.perf_counter()
32311.48899951

>>> time.perf_counter()  # A few seconds later
32315.261320793

In this example, you made two calls to perf_counter() almost 4 seconds apart. You can confirm this by calculating the difference between the two outputs: 32315.26 - 32311.49 = 3.77.

You can now add a Python timer to the example code:

 1# latest_tutorial.py
 2
 3import time
 4from reader import feed
 5
 6def main():
 7    """Print the latest tutorial from Real Python"""
 8    tic = time.perf_counter()
 9    tutorial = feed.get_article(0)
10    toc = time.perf_counter()
11    print(f"Downloaded the tutorial in {toc - tic:0.4f} seconds")
12
13    print(tutorial)
14
15if __name__ == "__main__":
16    main()

Note that you call perf_counter() both before and after downloading the tutorial. You then print the time it took to download the tutorial by calculating the difference between the two calls.

Now, when you run the example, you’ll see the elapsed time before the tutorial:

$ python latest_tutorial.py
Downloaded the tutorial in 0.6721 seconds
# Python Timer Functions: Three Ways to Monitor Your Code

[ ... ]

That’s it! You’ve covered the basics of timing your own Python code. In the rest of the tutorial, you’ll learn how you can wrap a Python timer into a class, a context manager, and a decorator to make it more consistent and convenient to use.

Understanding Classes in Python

Classes are the main building blocks of object-oriented programming. A class is essentially a template that you can use to create objects. While Python doesn’t force you to program in an object-oriented manner, classes are everywhere in the language. For quick proof, investigate the time module:

>>> import time
>>> type(time)
<class 'module'>

>>> time.__class__
<class 'module'>

type() returns the type of an object. Here you can see that modules are, in fact, objects created from a module class. You can use the special attribute .__class__ to get access to the class that defines an object. In fact, almost everything in Python is a class:

>>> type(3)
<class 'int'>

>>> type(None)
<class 'NoneType'>

>>> type(print)
<class 'builtin_function_or_method'>

>>> type(type)
<class 'type'>

In Python, classes are great when you need to model something that needs to keep track of a particular state. In general, a class is a collection of properties, called attributes, and behaviors, called methods. For more background on classes and object-oriented programming, check out Python Classes: The Power of Object-Oriented Programming, Object-Oriented Programming (OOP) in Python or the official documentation.

Creating a Python Timer Class

Classes are good for tracking state. In a Timer class, you want to keep track of when a timer starts and how much time has passed since then. For the first implementation of Timer, you’ll add a ._start_time attribute, as well as .start() and .stop() methods. Add the following code to a file named timer.py:

 1# timer.py
 2
 3import time
 4
 5class TimerError(Exception):
 6    """A custom exception used to report errors in use of Timer class"""
 7
 8class Timer:
 9    def __init__(self):
10        self._start_time = None
11
12    def start(self):
13        """Start a new timer"""
14        if self._start_time is not None:
15            raise TimerError(f"Timer is running. Use .stop() to stop it")
16
17        self._start_time = time.perf_counter()
18
19    def stop(self):
20        """Stop the timer, and report the elapsed time"""
21        if self._start_time is None:
22            raise TimerError(f"Timer is not running. Use .start() to start it")
23
24        elapsed_time = time.perf_counter() - self._start_time
25        self._start_time = None
26        print(f"Elapsed time: {elapsed_time:0.4f} seconds")

A few different things are happening here, so take a moment to walk through the code step by step.

In line 5, you define a TimerError class. The (Exception) notation means that TimerError inherits from another class called Exception. Python uses this built-in class for error handling. You don’t need to add any attributes or methods to TimerError, but having a custom error will give you more flexibility to handle problems inside Timer. For more information, check out Python Exceptions: An Introduction.

The definition of Timer itself starts on line 8. When you first create or instantiate an object from a class, your code calls .__init__(), one of Python’s special methods. In this first version of Timer, you only initialize the ._start_time attribute, which you’ll use to track the state of your Python timer. It has the value None when the timer isn’t running. Once the timer is running, ._start_time keeps track of when the timer started.

When you call .start() to start a new Python timer, you first check that the timer isn’t already running. Then you store the current value of perf_counter() in ._start_time.

On the other hand, when you call .stop(), you first check that the Python timer is running. If it is, then you calculate the elapsed time as the difference between the current value of perf_counter() and the one that you stored in ._start_time. Finally, you reset ._start_time so that the timer can be restarted, and print the elapsed time.

Here’s how you use Timer:

>>> from timer import Timer
>>> t = Timer()
>>> t.start()

>>> t.stop()  # A few seconds later
Elapsed time: 3.8191 seconds

Compare this to the earlier example where you used perf_counter() directly. The structure of the code is fairly similar, but now the code is clearer, and this is one of the benefits of using classes. By carefully choosing your class, method, and attribute names, you can make your code very descriptive!

Using the Python Timer Class

Now apply Timer to latest_tutorial.py. You only need to make a few changes to your previous code:

# latest_tutorial.py

from timer import Timer
from reader import feed

def main():
    """Print the latest tutorial from Real Python"""
    t = Timer()
    t.start()
    tutorial = feed.get_article(0)
    t.stop()

    print(tutorial)

if __name__ == "__main__":
    main()

Notice that the code is very similar to what you used earlier. In addition to making the code more readable, Timer takes care of printing the elapsed time to the console, which makes the logging of time spent more consistent. When you run the code, you’ll get pretty much the same output:

$ python latest_tutorial.py
Elapsed time: 0.6462 seconds
# Python Timer Functions: Three Ways to Monitor Your Code

[ ... ]

Printing the elapsed time from Timer may be consistent, but it seems that this approach is not very flexible. In the next section, you’ll see how to customize your class.

Adding More Convenience and Flexibility

So far, you’ve learned that classes are suitable for when you want to encapsulate state and ensure consistent behavior in your code. In this section, you’ll add more convenience and flexibility to your Python timer:

• Use adaptable text and formatting when reporting the time spent
• Apply flexible logging, either to the screen, to a log file, or other parts of your program
• Create a Python timer that can accumulate over several invocations
• Build an informative representation of a Python timer

First, see how you can customize the text used to report the time spent. In the previous code, the text f"Elapsed time: {elapsed_time:0.4f} seconds" is hard-coded into .stop(). You can add flexibility to classes using instance variables, whose values are normally passed as arguments to .__init__() and stored as self attributes. For convenience, you can also provide reasonable default values.

To add .text as a Timer instance variable, you’ll do something like this in timer.py:

# timer.py

def __init__(self, text="Elapsed time: {:0.4f} seconds"):
    self._start_time = None
    self.text = text

Note that the default text, "Elapsed time: {:0.4f} seconds", is given as a regular string, not as an f-string. You can’t use an f-string here because f-strings evaluate immediately, and when you instantiate Timer, your code hasn’t yet calculated the elapsed time.

In .stop(), you use .text as a template and .format() to populate the template:

# timer.py

def stop(self):
    """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")

    elapsed_time = time.perf_counter() - self._start_time
    self._start_time = None
    print(self.text.format(elapsed_time))

After this update to timer.py, you can change the text as follows:

>>> from timer import Timer
>>> t = Timer(text="You waited {:.1f} seconds")
>>> t.start()

>>> t.stop()  # A few seconds later
You waited 4.1 seconds

Next, assume that you don’t just want to print a message to the console. Maybe you want to save your time measurements so that you can store them in a database. You can do this by returning the value of elapsed_time from .stop(). Then, the calling code can choose to either ignore that return value or save it for later processing.

Perhaps you want to integrate Timer into your logging routines. To support logging or other outputs from Timer, you need to change the call to print() so that the user can supply their own logging function. This can be done similarly to how you customized the text earlier:

 1# timer.py
 2
 3# ...
 4
 5class Timer:
 6    def __init__(
 7        self,
 8        text="Elapsed time: {:0.4f} seconds",
 9        logger=print
10    ):
11        self._start_time = None
12        self.text = text
13        self.logger = logger
14
15    # Other methods are unchanged
16
17    def stop(self):
18        """Stop the timer, and report the elapsed time"""
19        if self._start_time is None:
20            raise TimerError(f"Timer is not running. Use .start() to start it")
21
22        elapsed_time = time.perf_counter() - self._start_time
23        self._start_time = None
24
25        if self.logger:
26            self.logger(self.text.format(elapsed_time))
27
28        return elapsed_time

Instead of using print() directly, you create another instance variable in line 13, self.logger, that should refer to a function that takes a string as an argument. In addition to print(), you can use functions like logging.info() or .write() on file objects. Also note the if test in line 25, which allows you to turn off printing completely by passing logger=None.

Here are two examples that show the new functionality in action:

>>> from timer import Timer
>>> import logging
>>> t = Timer(logger=logging.warning)
>>> t.start()

>>> t.stop()  # A few seconds later
WARNING:root:Elapsed time: 3.1610 seconds
3.1609658249999484

>>> t = Timer(logger=None)
>>> t.start()

>>> value = t.stop()  # A few seconds later
>>> value
4.710851433001153

When you run these examples in an interactive shell, Python prints the return value automatically.

The third improvement that you’ll add is the ability to accumulate time measurements. You may want to do this, for example, when you’re calling a slow function in a loop. You’ll add a bit more functionality in the form of named timers with a dictionary that keeps track of every Python timer in your code.

Assume that you’re expanding latest_tutorial.py to a latest_tutorials.py script that downloads and prints the ten latest tutorials from Real Python. The following is one possible implementation:

# latest_tutorials.py

from timer import Timer
from reader import feed

def main():
    """Print the 10 latest tutorials from Real Python"""
    t = Timer(text="Downloaded 10 tutorials in {:0.2f} seconds")
    t.start()
    for tutorial_num in range(10):
        tutorial = feed.get_article(tutorial_num)
        print(tutorial)
    t.stop()

if __name__ == "__main__":
    main()

The code loops over the numbers from 0 to 9 and uses those as offset arguments to feed.get_article(). When you run the script, you’ll print a lot of information to your console:

$ python latest_tutorials.py
# Python Timer Functions: Three Ways to Monitor Your Code

[ ... The text of the tutorials ... ]
Downloaded 10 tutorials in 0.67 seconds

One subtle issue with this code is that you’re measuring not only the time it takes to download the tutorials, but also the time Python spends printing the tutorials to your screen. This might not be that important because the time spent printing should be negligible compared to the time spent downloading. Still, it would be good to have a way to precisely time what you’re after in these kinds of situations.

There are several ways that you can work around this without changing the current implementation of Timer. However, supporting this use case will be quite useful, and you can do it with just a few lines of code.

First, you’ll introduce a dictionary called .timers as a class variable on Timer, which means that all instances of Timer will share it. You implement it by defining it outside any methods:

class Timer:
    timers = {}

Class variables can be accessed either directly on the class or through an instance of the class:

>>> from timer import Timer
>>> Timer.timers
{}

>>> t = Timer()
>>> t.timers
{}

>>> Timer.timers is t.timers
True

In both cases, the code returns the same empty class dictionary.

Next, you’ll add optional names to your Python timer. You can use the name for two different purposes:

1. Looking up the elapsed time later in your code
2. Accumulating timers with the same name

To add names to your Python timer, you need to make two more changes to timer.py. First, Timer should accept name as a parameter. Second, the elapsed time should be added to .timers when a timer stops:

 1# timer.py
 2
 3# ...
 4
 5class Timer:
 6    timers = {}
 7
 8    def __init__(
 9        self,
10        name=None,
11        text="Elapsed time: {:0.4f} seconds",
12        logger=print,
13    ):
14        self._start_time = None
15        self.name = name
16        self.text = text
17        self.logger = logger
18
19        # Add new named timers to dictionary of timers
20        if name:
21            self.timers.setdefault(name, 0)
22
23    # Other methods are unchanged
24
25    def stop(self):
26        """Stop the timer, and report the elapsed time"""
27        if self._start_time is None:
28            raise TimerError(f"Timer is not running. Use .start() to start it")
29
30        elapsed_time = time.perf_counter() - self._start_time
31        self._start_time = None
32
33        if self.logger:
34            self.logger(self.text.format(elapsed_time))
35        if self.name:
36            self.timers[self.name] += elapsed_time
37
38        return elapsed_time

Note that you use .setdefault() when adding the new Python timer to .timers. This is a great feature that only sets the value if name isn’t already defined in the dictionary. If name is already used in .timers, then the value is left untouched. This allows you to accumulate several timers:

>>> from timer import Timer
>>> t = Timer("accumulate")
>>> t.start()

>>> t.stop()  # A few seconds later
Elapsed time: 3.7036 seconds
3.703554293999332

>>> t.start()

>>> t.stop()  # A few seconds later
Elapsed time: 2.3449 seconds
2.3448921170001995

>>> Timer.timers
{'accumulate': 6.0484464109995315}

You can now revisit latest_tutorials.py and make sure only the time spent on downloading the tutorials is measured:

# latest_tutorials.py

from timer import Timer
from reader import feed

def main():
    """Print the 10 latest tutorials from Real Python"""
    t = Timer("download", logger=None)
    for tutorial_num in range(10):
        t.start()
        tutorial = feed.get_article(tutorial_num)
        t.stop()
        print(tutorial)

    download_time = Timer.timers["download"]
    print(f"Downloaded 10 tutorials in {download_time:0.2f} seconds")

if __name__ == "__main__":
    main()

Rerunning the script will give output similar to earlier, although now you’re only timing the actual download of the tutorials:

$ python latest_tutorials.py
# Python Timer Functions: Three Ways to Monitor Your Code

[ ... The text of the tutorials ... ]
Downloaded 10 tutorials in 0.65 seconds

The final improvement that you’ll make to Timer is to make it more informative when you’re working with it interactively. Try the following:

>>> from timer import Timer
>>> t = Timer()
>>> t
<timer.Timer object at 0x7f0578804320>

That last line is the default way that Python represents objects. While you can glean some information from it, it’s usually not very useful. Instead, it would be nice to see information like the name of Timer, or how it’ll report on the timings.

In Python 3.7, data classes were added to the standard library. These provide several conveniences to your classes, including a more informative representation string.

$ python -m pip install dataclasses

You convert your Python timer to a data class using the @dataclass decorator. You’ll learn more about decorators later in this tutorial. For now, you can think of this as a notation that tells Python that Timer is a data class:

 1# timer.py
 2
 3import time
 4from dataclasses import dataclass, field
 5from typing import Any, ClassVar
 6
 7# ...
 8
 9@dataclass
10class Timer:
11    timers: ClassVar = {}
12    name: Any = None
13    text: Any = "Elapsed time: {:0.4f} seconds"
14    logger: Any = print
15    _start_time: Any = field(default=None, init=False, repr=False)
16
17    def __post_init__(self):
18        """Initialization: add timer to dict of timers"""
19        if self.name:
20            self.timers.setdefault(self.name, 0)
21
22    # The rest of the code is unchanged

This code replaces your earlier .__init__() method. Note how data classes use syntax that looks similar to the class variable syntax that you saw earlier for defining all variables. In fact, .__init__() is created automatically for data classes, based on annotated variables in the definition of the class.

You need to annotate your variables to use a data class. You can use this annotation to add type hints to your code. If you don’t want to use type hints, then you can instead annotate all variables with Any, just like you did above. You’ll soon learn how to add actual type hints to your data class.

Here are a few notes about the Timer data class:

• Line 9: The @dataclass decorator defines Timer as a data class.

• Line 11: The special ClassVar annotation is necessary for data classes to specify that .timers is a class variable.

• Lines 12 to 14: .name, .text, and .logger will be defined as attributes on Timer, whose values can be specified when creating Timer instances. They all have the given default values.

• Line 15: Recall that ._start_time is a special attribute that’s used to keep track of the state of the Python timer, but it should be hidden from the user. Using dataclasses.field(), you say that ._start_time should be removed from .__init__() and the representation of Timer.

• Lines 17 to 20: You can use the special .__post_init__() method for any initialization that you need to do apart from setting the instance attributes. Here, you use it to add named timers to .timers.

Your new Timer data class works just like your previous regular class, except that it now has a nice representation:

>>> from timer import Timer
>>> t = Timer()
>>> t
Timer(name=None, text='Elapsed time: {:0.4f} seconds',
      logger=<built-in function print>)

>>> t.start()

>>> t.stop()  # A few seconds later
Elapsed time: 6.7197 seconds
6.719705373998295

Now you have a pretty neat version of Timer that’s consistent, flexible, convenient, and informative! You can apply many of the improvements that you’ve made in this section to other types of classes in your projects as well.

Before ending this section, revisit the complete source code of Timer as it currently stands. You’ll notice the addition of type hints to the code for extra documentation:

# timer.py

from dataclasses import dataclass, field
import time
from typing import Callable, ClassVar, Dict, Optional

class TimerError(Exception):
    """A custom exception used to report errors in use of Timer class"""

@dataclass
class Timer:
    timers: ClassVar[Dict[str, float]] = {}
    name: Optional[str] = None
    text: str = "Elapsed time: {:0.4f} seconds"
    logger: Optional[Callable[[str], None]] = print
    _start_time: Optional[float] = field(default=None, init=False, repr=False)

    def __post_init__(self) -> None:
        """Add timer to dict of timers after initialization"""
        if self.name is not None:
            self.timers.setdefault(self.name, 0)

    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
        if self.logger:
            self.logger(self.text.format(elapsed_time))
        if self.name:
            self.timers[self.name] += elapsed_time

        return elapsed_time

Using a class to create a Python timer has several benefits:

• Readability: Your code will read more naturally if you carefully choose class and method names.
• Consistency: Your code will be easier to use if you encapsulate properties and behaviors into attributes and methods.
• Flexibility: Your code will be reusable if you use attributes with default values instead of hard-coded values.

This class is very flexible, and you can use it in almost any situation where you want to monitor the time it takes for code to run. However, in the next sections, you’ll learn about using context managers and decorators, which will be more convenient for timing code blocks and functions.

Understanding Context Managers in Python

Context managers have been a part of Python for a long time. They were introduced by PEP 343 in 2005, and first implemented in Python 2.5. You can recognize context managers in code by the use of the with keyword:

with EXPRESSION as VARIABLE:
    BLOCK

EXPRESSION is some Python expression that returns a context manager. The context manager is optionally bound to the name VARIABLE. Finally, BLOCK is any regular Python code block. The context manager will guarantee that your program calls some code before BLOCK and some other code after BLOCK executes. The latter will happen, even if BLOCK raises an exception.

The most common use of context managers is probably handling different resources, like files, locks, and database connections. The context manager is then used to free and clean up the resource after you’ve used it. The following example reveals the fundamental structure of timer.py by only printing lines that contain a colon. More importantly, it shows the common idiom for opening a file in Python:

>>> with open("timer.py") as fp:
...     print("".join(ln for ln in fp if ":" in ln))
...
class TimerError(Exception):
class Timer:
    timers: ClassVar[Dict[str, float]] = {}
    name: Optional[str] = None
    text: str = "Elapsed time: {:0.4f} seconds"
    logger: Optional[Callable[[str], None]] = print
    _start_time: Optional[float] = field(default=None, init=False, repr=False)
    def __post_init__(self) -> None:
        if self.name is not None:
    def start(self) -> None:
        if self._start_time is not None:
    def stop(self) -> float:
        if self._start_time is None:
        if self.logger:
        if self.name:

Note that fp, the file pointer, is never explicitly closed because you used open() as a context manager. You can confirm that fp has closed automatically:

>>> fp.closed
True

In this example, open("timer.py") is an expression that returns a context manager. That context manager is bound to the name fp. The context manager is in effect during the execution of print(). This one-line code block executes in the context of fp.

What does it mean that fp is a context manager? Technically, it means that fp implements the context manager protocol. There are many different protocols underlying the Python language. You can think of a protocol as a contract that states what specific methods your code must implement.

The context manager protocol consists of two methods:

1. Call .__enter__() when entering the context related to the context manager.
2. Call .__exit__() when exiting the context related to the context manager.

In other words, to create a context manager yourself, you need to write a class that implements .__enter__() and .__exit__(). No more, no less. Try a Hello, World! context manager example:

# greeter.py

class Greeter:
    def __init__(self, name):
        self.name = name

    def __enter__(self):
        print(f"Hello {self.name}")
        return self

    def __exit__(self, exc_type, exc_value, exc_tb):
        print(f"See you later, {self.name}")

Greeter is a context manager because it implements the context manager protocol. You can use it like this:

>>> from greeter import Greeter
>>> with Greeter("Akshay"):
...     print("Doing stuff ...")
...
Hello Akshay
Doing stuff ...
See you later, Akshay

First, note how .__enter__() is called before you’re doing stuff, while .__exit__() is called after. In this simplified example, you’re not referencing the context manager. In such cases, you don’t need to give the context manager a name with as.

Next, notice how .__enter__() returns self. The return value of .__enter__() is bound by as. You usually want to return self from .__enter__() when creating context managers. You can use that return value as follows:

>>> from greeter import Greeter
>>> with Greeter("Bethan") as grt:
...     print(f"{grt.name} is doing stuff ...")
...
Hello Bethan
Bethan is doing stuff ...
See you later, Bethan

Finally, .__exit__() takes three arguments: exc_type, exc_value, and exc_tb. These are used for error handling within the context manager, and they mirror the return values of sys.exc_info().

If an exception happens while the block is being executed, then your code calls .__exit__() with the type of the exception, an exception instance, and a traceback object. Often, you can ignore these in your context manager, in which case .__exit__() is called before the exception is reraised:

>>> from greeter import Greeter
>>> with Greeter("Rascal") as grt:
...     print(f"{grt.age} does not exist")
...
Hello Rascal
See you later, Rascal
Traceback (most recent call last):
  File "<stdin>", line 2, in <module>
AttributeError: 'Greeter' object has no attribute 'age'

You can see that "See you later, Rascal" is printed, even though there is an error in the code.

Now you know what context managers are and how you can create your own. If you want to dive deeper, then check out contextlib in the standard library. It includes convenient ways for defining new context managers, as well as ready-made context managers that you can use to close objects, suppress errors, or even do nothing! For even more information, check out Context Managers and Python’s with Statement.

Creating a Python Timer Context Manager

You’ve seen how context managers work in general, but how can they help with timing code? If you can run certain functions before and after a block of code, then you can simplify how your Python timer works. So far, you’ve needed to call .start() and .stop() explicitly when timing your code, but a context manager can do this automatically.

Again, for Timer to work as a context manager, it needs to adhere to the context manager protocol. In other words, it must implement .__enter__() and .__exit__() to start and stop the Python timer. All the necessary functionality is already available, so there’s not much new code you need to write. Just add the following methods to your Timer class:

# timer.py

# ...

@dataclass
class Timer:
    # The rest of the code is unchanged

    def __enter__(self):
        """Start a new timer as a context manager"""
        self.start()
        return self

    def __exit__(self, *exc_info):
        """Stop the context manager timer"""
        self.stop()

Timer is now a context manager. The important part of the implementation is that .__enter__() calls .start() to start a Python timer when the context is entered, and .__exit__() uses .stop() to stop the Python timer when the code leaves the context. Try it out:

>>> from timer import Timer
>>> import time
>>> with Timer():
...     time.sleep(0.7)
...
Elapsed time: 0.7012 seconds

You should also note two more subtle details:

1. .__enter__() returns self, the Timer instance, which allows the user to bind the Timer instance to a variable using as. For example, with Timer() as t: will create the variable t pointing to the Timer object.

2. .__exit__() expects three arguments with information about any exception that occurred during the execution of the context. In your code, these arguments are packed into a tuple called exc_info and then ignored, which means that Timer won’t attempt any exception handling.

.__exit__() doesn’t do any error handling in this case. Still, one of the great features of context managers is that they’re guaranteed to call .__exit__(), no matter how the context exits. In the following example, you purposely create an error by dividing by zero:

>>> from timer import Timer
>>> with Timer():
...     for num in range(-3, 3):
...         print(f"1 / {num} = {1 / num:.3f}")
...
1 / -3 = -0.333
1 / -2 = -0.500
1 / -1 = -1.000
Elapsed time: 0.0001 seconds
Traceback (most recent call last):
  File "<stdin>", line 3, in <module>
ZeroDivisionError: division by zero

Note that Timer prints out the elapsed time, even though the code crashed. It’s possible to inspect and suppress errors in .__exit__(). See the documentation for more information.

Using the Python Timer Context Manager

Now you’ll learn how to use the Timer context manager to time the download of Real Python tutorials. Recall how you used Timer earlier:

# latest_tutorial.py

from timer import Timer
from reader import feed

def main():
    """Print the latest tutorial from Real Python"""
    t = Timer()
    t.start()
    tutorial = feed.get_article(0)
    t.stop()

    print(tutorial)

if __name__ == "__main__":
    main()

You’re timing the call to feed.get_article(). You can use the context manager to make the code shorter, simpler, and more readable:

# latest_tutorial.py

from timer import Timer
from reader import feed

def main():
    """Print the latest tutorial from Real Python"""
    with Timer():
        tutorial = feed.get_article(0)

    print(tutorial)

if __name__ == "__main__":
    main()

This code does virtually the same as the code above. The main difference is that you don’t define the extraneous variable t, which keeps your namespace cleaner.

Running the script should give a familiar result:

$ python latest_tutorial.py
Elapsed time: 0.71 seconds
# Python Timer Functions: Three Ways to Monitor Your Code

[ ... ]

There are a few advantages to adding context manager capabilities to your Python timer class:

• Low effort: You only need one extra line of code to time the execution of a block of code.
• Readability: Invoking the context manager is readable, and you can more clearly visualize the code block that you’re timing.

Using Timer as a context manager is almost as flexible as using .start() and .stop() directly, while it has less boilerplate code. In the next section, you’ll learn how you can use Timer as a decorator as well. This will make it easier to monitor the runtime of complete functions.

Understanding Decorators in Python

A decorator is a function that wraps another function to modify its behavior. This technique is possible because functions are first-class objects in Python. In other words, functions can be assigned to variables and used as arguments to other functions, just like any other object. This gives you a lot of flexibility and is the basis for several of Python’s most powerful features.

As a first example, you’ll create a decorator that does nothing:

def turn_off(func):
    return lambda *args, **kwargs: None

First, note that turn_off() is just a regular function. What makes this a decorator is that it takes a function as its only argument and returns a function. You can use turn_off() to modify other functions, like this:

>>> print("Hello")
Hello

>>> print = turn_off(print)
>>> print("Hush")
>>> # Nothing is printed

The line print = turn_off(print) decorates the print statement with the turn_off() decorator. Effectively, it replaces print() with lambda *args, **kwargs: None returned by turn_off(). The lambda statement represents an anonymous function that does nothing except return None.

To define more interesting decorators, you need to know about inner functions. An inner function is a function that’s defined inside another function. One common use of inner functions is to create function factories:

def create_multiplier(factor):
    def multiplier(num):
        return factor * num
    return multiplier

multiplier() is an inner function, defined inside create_multiplier(). Note that you have access to factor inside multiplier(), while multiplier() isn’t defined outside create_multiplier():

>>> multiplier
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
NameError: name 'multiplier' is not defined

Instead you use create_multiplier() to create new multiplier functions, each based on a different factor:

>>> double = create_multiplier(factor=2)
>>> double(3)
6

>>> quadruple = create_multiplier(factor=4)
>>> quadruple(7)
28

Similarly, you can use inner functions to create decorators. Remember, a decorator is a function that returns a function:

 1def triple(func):
 2    def wrapper_triple(*args, **kwargs):
 3        print(f"Tripled {func.__name__!r}")
 4        value = func(*args, **kwargs)
 5        return value * 3
 6    return wrapper_triple

triple() is a decorator, because it’s a function that expects a function, func(), as its only argument and returns another function, wrapper_triple(). Note the structure of triple() itself:

• Line 1 starts the definition of triple() and expects a function as an argument.
• Lines 2 to 5 define the inner function wrapper_triple().
• Line 6 returns wrapper_triple().

This pattern is prevalent for defining decorators. The interesting parts are those happening inside the inner function:

• Line 2 starts the definition of wrapper_triple(). This function will replace whichever function triple() decorates. The parameters are *args and **kwargs, which collect whichever positional and keyword arguments you pass to the function. This gives you the flexibility to use triple() on any function.
• Line 3 prints out the name of the decorated function and notes that triple() has been applied to it.
• Line 4 calls func(), the function that triple() has decorated. It passes on all arguments passed to wrapper_triple().
• Line 5 triples the return value of func() and returns it.

Try it out! knock() is a function that returns the word Penny. See what happens if it’s tripled:

>>> def knock():
...     return "Penny! "
...
>>> knock = triple(knock)
>>> result = knock()
Tripled 'knock'

>>> result
'Penny! Penny! Penny! '

Multiplying a text string by a number is a form of repetition, so Penny repeats three times. The decoration happens at knock = triple(knock).

It feels a bit clunky to keep repeating knock. Instead, PEP 318 introduced a more convenient syntax for applying decorators. The following definition of knock() does the same as the one above:

>>> @triple
... def knock():
...     return "Penny! "
...
>>> result = knock()
Tripled 'knock'

>>> result
'Penny! Penny! Penny! '

The @ symbol is used to apply decorators. In this case, @triple means that triple() is applied to the function defined just after it.

One of the few decorators defined in the standard library is @functools.wraps. This one is quite helpful when defining your own decorators. Because decorators effectively replace one function with another, they create a subtle issue with your functions:

>>> knock
<function triple.<locals>.wrapper_triple at 0x7fa3bfe5dd90>

@triple decorates knock(), which is then replaced by the wrapper_triple() inner function, as the output above confirms. This will also replace the name, docstring, and other metadata. Often, this won’t have much effect, but it can make introspection difficult.

Sometimes, decorated functions must have correct metadata. @functools.wraps fixes exactly this issue:

import functools

def triple(func):
    @functools.wraps(func)
    def wrapper_triple(*args, **kwargs):
        print(f"Tripled {func.__name__!r}")
        value = func(*args, **kwargs)
        return value * 3
    return wrapper_triple

With this new definition of @triple, metadata is preserved:

>>> @triple
... def knock():
...     return "Penny! "
...
>>> knock
<function knock at 0x7fa3bfe5df28>

Note that knock() now keeps its proper name, even after being decorated. It’s good form to use @functools.wraps whenever you define a decorator. A blueprint that you can use for most of your decorators is the following:

import functools

def decorator(func):
    @functools.wraps(func)
    def wrapper_decorator(*args, **kwargs):
        # Do something before
        value = func(*args, **kwargs)
        # Do something after
        return value
    return wrapper_decorator

To see more examples of how to define decorators, check out the examples listed in Primer on Python Decorators.

Creating a Python Timer Decorator

In this section, you’ll learn how to extend your Python timer so that you can use it as a decorator as well. However, as a first exercise, you’ll create a Python timer decorator from scratch.

Based on the blueprint above, you only need to decide what to do before and after you call the decorated function. This is similar to the considerations about what to do when entering and exiting the context manager. You want to start a Python timer before calling the decorated function, and stop the Python timer after the call finishes. You can define a @timer decorator as follows:

import functools
import time

def timer(func):
    @functools.wraps(func)
    def wrapper_timer(*args, **kwargs):
        tic = time.perf_counter()
        value = func(*args, **kwargs)
        toc = time.perf_counter()
        elapsed_time = toc - tic
        print(f"Elapsed time: {elapsed_time:0.4f} seconds")
        return value
    return wrapper_timer

Note how much wrapper_timer() resembles the earlier pattern that you established for timing Python code. You can apply @timer as follows:

>>> @timer
... def latest_tutorial():
...     tutorial = feed.get_article(0)
...     print(tutorial)
...
>>> latest_tutorial()
# Python Timer Functions: Three Ways to Monitor Your Code

[ ... ]
Elapsed time: 0.5414 seconds

Recall that you can also apply a decorator to a previously defined function:

>>> feed.get_article = timer(feed.get_article)

Because @ applies when functions are defined, you need to use the more basic form in these cases. One advantage of using a decorator is that you only need to apply it once, and it’ll time the function every time:

>>> tutorial = feed.get_article(0)
Elapsed time: 0.5512 seconds

@timer does the job. However, in a sense, you’re back to square one, since @timer doesn’t have any of the flexibility or convenience of Timer. Can you also make your Timer class act like a decorator?

So far, you’ve used decorators as functions applied to other functions, but that’s not entirely correct. Decorators must be callables. There are many callable types in Python. You can make your own objects callable by defining the special .__call__() method in their class. The following function and class behave similarly:

>>> def square(num):
...     return num ** 2
...
>>> square(4)
16

>>> class Squarer:
...     def __call__(self, num):
...         return num ** 2
...
>>> square = Squarer()
>>> square(4)
16

Here, square is an instance that is callable and can square numbers, just like the square() function in the first example.

This gives you a way of adding decorator capabilities to the existing Timer class:

# timer.py

import functools

# ...

@dataclass
class Timer:

    # The rest of the code is unchanged

    def __call__(self, func):
        """Support using Timer as a decorator"""
        @functools.wraps(func)
        def wrapper_timer(*args, **kwargs):
            with self:
                return func(*args, **kwargs)

        return wrapper_timer

.__call__() uses the fact that Timer is already a context manager to take advantage of the conveniences that you’ve already defined there. Make sure you also import functools at the top of timer.py.

You can now use Timer as a decorator:

>>> @Timer(text="Downloaded the tutorial in {:.2f} seconds")
... def latest_tutorial():
...     tutorial = feed.get_article(0)
...     print(tutorial)
...
>>> latest_tutorial()
# Python Timer Functions: Three Ways to Monitor Your Code

[ ... ]
Downloaded the tutorial in 0.72 seconds

Before rounding out this section, know that there’s a more straightforward way of turning your Python timer into a decorator. You’ve already seen some of the similarities between context managers and decorators. They’re both typically used to do something before and after executing some given code.

Based on these similarities, there’s a mixin class defined in the standard library called ContextDecorator. You can add decorator abilities to your context manager classes simply by inheriting ContextDecorator:

from contextlib import ContextDecorator

# ...

@dataclass
class Timer(ContextDecorator):
    # Implementation of Timer is unchanged

When you use ContextDecorator this way, there’s no need to implement .__call__() yourself, so you can safely delete it from the Timer class.

Using the Python Timer Decorator

Next up, you’ll redo the latest_tutorial.py example one last time, using the Python timer as a decorator:

 1# latest_tutorial.py
 2
 3from timer import Timer
 4from reader import feed
 5
 6@Timer()
 7def main():
 8    """Print the latest tutorial from Real Python"""
 9    tutorial = feed.get_article(0)
10    print(tutorial)
11
12if __name__ == "__main__":
13    main()

If you compare this implementation with the original implementation without any timing, then you’ll notice that the only differences are the import of Timer on line 3 and the application of @Timer() on line 6. A significant advantage of using decorators is that they’re usually straightforward to apply, as you see here.

However, the decorator still applies to the whole function. This means that your code is taking into account the time it takes to print the tutorial, in addition to the time it takes to download. Run the script one final time:

$ python latest_tutorial.py
# Python Timer Functions: Three Ways to Monitor Your Code

[ ... ]
Elapsed time: 0.69 seconds

The location of the elapsed time output is a telltale sign that your code is considering the time it takes to print as well. As you see here, your code prints the elapsed time after the tutorial.

When you use Timer as a decorator, you’ll see similar advantages as you did with context managers:

• Low effort: You only need one extra line of code to time the execution of a function.
• Readability: When you add the decorator, you can note more clearly that your code will time the function.
• Consistency: You only need to add the decorator when the function is defined. Your code will consistently time it every time it’s called.

However, decorators are not as flexible as context managers. You can only apply them to complete functions. It’s possible to add decorators to already defined functions, but this is a bit clunky and less common.

Using Alternative Python Timer Functions

You’ve been using perf_counter() throughout this tutorial to do the actual time measurements, but Python’s time library comes with several other functions that also measure time. Here are some alternatives:

• time()
• perf_counter_ns()
• monotonic()
• process_time()

One reason for having several functions is that Python represents time as a float. Floating-point numbers are inaccurate by nature. You may have seen results like these before:

>>> 0.1 + 0.1 + 0.1
0.30000000000000004

>>> 0.1 + 0.1 + 0.1 == 0.3
False

Python’s float follows the IEEE 754 Standard for Floating-Point Arithmetic, which tries to represent all floating-point numbers in 64 bits. Because there are infinitely many floating-point numbers, you can’t express them all with a finite number of bits.

IEEE 754 prescribes a system where the density of numbers that you can represent varies. The closer you are to one, the more numbers you can represent. For larger numbers, there’s more space between the numbers that you can express. This has some consequences when you use a float to represent time.

Consider time(). The main purpose of this function is to represent the actual time right now. It does this as the number of seconds since a given point in time, called the epoch. The number returned by time() is quite big, which means that there are fewer numbers available, and the resolution suffers. Specifically, time() is not able to measure nanosecond differences:

>>> import time
>>> t = time.time()
>>> t
1564342757.0654016

>>> t + 1e-9
1564342757.0654016

>>> t == t + 1e-9
True

A nanosecond is one-billionth of a second. Note that adding a nanosecond to t doesn’t affect the result. perf_counter(), on the other hand, uses some undefined point in time as its epoch, allowing it to work with smaller numbers and therefore obtain a better resolution:

>>> import time
>>> p = time.perf_counter()
>>> p
11370.015653846

>>> p + 1e-9
11370.015653847

>>> p == p + 1e-9
False

Here, you notice that adding a nanosecond to p actually affects the outcome. For more information about how to work with time(), see A Beginner’s Guide to the Python time Module.

The challenges with representing time as a float are well known, so Python 3.7 introduced a new option. Each time measurement function now has a corresponding _ns function that returns the number of nanoseconds as an int instead of the number of seconds as a float. For instance, time() now has a nanosecond counterpart called time_ns():

>>> import time
>>> time.time_ns()
1564342792866601283

Integers are unbounded in Python, so this allows time_ns() to give nanosecond resolution for all eternity. Similarly, perf_counter_ns() is a nanosecond variant of perf_counter():

>>> import time
>>> time.perf_counter()
13580.153084446

>>> time.perf_counter_ns()
13580765666638

Because perf_counter() already provides nanosecond resolution, there are fewer advantages to using perf_counter_ns().

There are two functions in time that do not measure the time spent sleeping. These are process_time() and thread_time(), which are useful in some settings. However, for Timer, you typically want to measure the full time spent. The final function in the list above is monotonic(). The name alludes to this function being a monotonic timer, which is a Python timer that can never move backward.

All these functions are monotonic except time(), which can go backward if the system time is adjusted. On some systems, monotonic() is the same function as perf_counter(), and you can use them interchangeably. However, this is not always the case. You can use time.get_clock_info() to get more information about a Python timer function:

>>> import time
>>> time.get_clock_info("monotonic")
namespace(adjustable=False, implementation='clock_gettime(CLOCK_MONOTONIC)',
          monotonic=True, resolution=1e-09)

>>> time.get_clock_info("perf_counter")
namespace(adjustable=False, implementation='clock_gettime(CLOCK_MONOTONIC)',
          monotonic=True, resolution=1e-09)

The results could be different on your system.

PEP 418 describes some of the rationale behind introducing these functions. It includes the following short descriptions:

• time.monotonic(): timeout and scheduling, not affected by system clock updates
• time.perf_counter(): benchmarking, most precise clock for short period
• time.process_time(): profiling, CPU time of the process (Source)

As you can tell, perf_counter() is usually the best choice for your Python timer.

Estimating Running Time With timeit

Say you’re trying to squeeze the last bit of performance out of your code, and you’re wondering about the most effective way to convert a list to a set. You want to compare using set() and the set literal, {...}. You can use your Python timer for this:

>>> from timer import Timer
>>> numbers = [7, 6, 1, 4, 1, 8, 0, 6]
>>> with Timer(text="{:.8f}"):
...     set(numbers)
...
{0, 1, 4, 6, 7, 8}
0.00007373

>>> with Timer(text="{:.8f}"):
...     {*numbers}
...
{0, 1, 4, 6, 7, 8}
0.00006204

This test seems to indicate that the set literal might be slightly faster. However, these results are quite uncertain, and if you rerun the code, you might get wildly different results. That’s because you’re only trying the code once. You could, for instance, get unlucky and run the script just as your computer is becoming busy with other tasks.

A better way is to use the timeit standard library. It’s designed precisely to measure the execution time of small code snippets. While you can import and call timeit.timeit() from Python as a regular function, it’s usually more convenient to use the command-line interface. You can time the two variants as follows:

$ python -m timeit --setup "nums = [7, 6, 1, 4, 1, 8, 0, 6]" "set(nums)"
2000000 loops, best of 5: 163 nsec per loop

$ python -m timeit --setup "nums = [7, 6, 1, 4, 1, 8, 0, 6]" "{*nums}"
2000000 loops, best of 5: 121 nsec per loop

timeit automatically calls your code many times to average out noisy measurements. The results from timeit confirm that the set literal is faster than set().

Finally, the IPython interactive shell and the Jupyter Notebook have extra support for this functionality with the %timeit magic command:

In [1]: numbers = [7, 6, 1, 4, 1, 8, 0, 6]

In [2]: %timeit set(numbers)
171 ns ± 0.748 ns per loop (mean ± std. dev. of 7 runs, 10000000 loops each)

In [3]: %timeit {*numbers}
147 ns ± 2.62 ns per loop (mean ± std. dev. of 7 runs, 10000000 loops each)

Again, the measurements indicate that using a set literal is faster. In Jupyter Notebooks, you can also use the %%timeit cell-magic to measure the time of running a whole cell.

Finding Bottlenecks in Your Code With Profilers

timeit is excellent for benchmarking a particular snippet of code. However, it would be very cumbersome to use it to check all parts of your program and locate which sections take the most time. Instead, you can use a profiler.

cProfile is a profiler that you can access at any time from the standard library. You can use it in several ways, although it’s usually most straightforward to use it as a command-line tool:

$ python -m cProfile -o latest_tutorial.prof latest_tutorial.py

This command runs latest_tutorial.py with profiling turned on. You save the output from cProfile in latest_tutorial.prof, as specified by the -o option. The output data is in a binary format that needs a dedicated program to make sense of it. Again, Python has an option right in the standard library! Running the pstats module on your .prof file opens an interactive profile statistics browser:

$ python -m pstats latest_tutorial.prof
Welcome to the profile statistics browser.
latest_tutorial.prof% help

Documented commands (type help <topic>):
========================================
EOF  add  callees  callers  help  quit  read  reverse  sort  stats  strip

To use pstats, you type commands at the prompt. Here you can see the integrated help system. Typically you’ll use the sort and stats commands. To get a cleaner output, strip can be useful:

latest_tutorial.prof% strip
latest_tutorial.prof% sort cumtime
latest_tutorial.prof% stats 10
         1393801 function calls (1389027 primitive calls) in 0.586 seconds

 Ordered by: cumulative time
 List reduced from 1443 to 10 due to restriction <10>

 ncalls tottime percall cumtime percall filename:lineno(function)
  144/1   0.001   0.000   0.586   0.586 {built-in method builtins.exec}
      1   0.000   0.000   0.586   0.586 latest_tutorial.py:3(<module>)
      1   0.000   0.000   0.521   0.521 contextlib.py:71(inner)
      1   0.000   0.000   0.521   0.521 latest_tutorial.py:6(read_latest_tutorial)
      1   0.000   0.000   0.521   0.521 feed.py:28(get_article)
      1   0.000   0.000   0.469   0.469 feed.py:15(_feed)
      1   0.000   0.000   0.469   0.469 feedparser.py:3817(parse)
      1   0.000   0.000   0.271   0.271 expatreader.py:103(parse)
      1   0.000   0.000   0.271   0.271 xmlreader.py:115(parse)
     13   0.000   0.000   0.270   0.021 expatreader.py:206(feed)

This output shows that the total runtime was 0.586 seconds. It also lists the ten functions where your code spent most of its time. Here you’ve sorted by cumulative time (cumtime), which means that your code counts time when the given function has called another function.

You can see that your code spends virtually all its time inside the latest_tutorial module, and in particular, inside read_latest_tutorial(). While this might be useful confirmation of what you already know, it’s often more interesting to find where your code actually spends time.

The total time (tottime) column indicates how much time your code spent inside a function, excluding time in sub-functions. You can see that none of the functions above really spend any time doing this. To find where the code spent most of its time, issue another sort command:

latest_tutorial.prof% sort tottime
latest_tutorial.prof% stats 10
         1393801 function calls (1389027 primitive calls) in 0.586 seconds

 Ordered by: internal time
 List reduced from 1443 to 10 due to restriction <10>

 ncalls tottime percall cumtime percall filename:lineno(function)
     59   0.091   0.002   0.091   0.002 {method 'read' of '_ssl._SSLSocket'}
 114215   0.070   0.000   0.099   0.000 feedparser.py:308(__getitem__)
 113341   0.046   0.000   0.173   0.000 feedparser.py:756(handle_data)
      1   0.033   0.033   0.033   0.033 {method 'do_handshake' of '_ssl._SSLSocket'}
      1   0.029   0.029   0.029   0.029 {method 'connect' of '_socket.socket'}
     13   0.026   0.002   0.270   0.021 {method 'Parse' of 'pyexpat.xmlparser'}
 113806   0.024   0.000   0.123   0.000 feedparser.py:373(get)
   3455   0.023   0.000   0.024   0.000 {method 'sub' of 're.Pattern'}
 113341   0.019   0.000   0.193   0.000 feedparser.py:2033(characters)
    236   0.017   0.000   0.017   0.000 {method 'translate' of 'str'}

You can now see that latest_tutorial.py actually spends most of its time working with sockets or handling data inside feedparser. The latter is one of the dependencies of the Real Python Reader that’s used to parse the tutorial feed.

You can use pstats to get some idea of where your code is spending most of its time and then try to optimize any bottlenecks you find. You can also use the tool to understand the structure of your code better. For instance, the commands callees and callers will show you which functions call and are called by a given function.

You can also investigate certain functions. Check how much overhead Timer causes by filtering the results with the phrase timer:

latest_tutorial.prof% stats timer
         1393801 function calls (1389027 primitive calls) in 0.586 seconds

 Ordered by: internal time
 List reduced from 1443 to 8 due to restriction <'timer'>

 ncalls tottime percall cumtime percall filename:lineno(function)
      1   0.000   0.000   0.000   0.000 timer.py:13(Timer)
      1   0.000   0.000   0.000   0.000 timer.py:35(stop)
      1   0.000   0.000   0.003   0.003 timer.py:3(<module>)
      1   0.000   0.000   0.000   0.000 timer.py:28(start)
      1   0.000   0.000   0.000   0.000 timer.py:9(TimerError)
      1   0.000   0.000   0.000   0.000 timer.py:23(__post_init__)
      1   0.000   0.000   0.000   0.000 timer.py:57(__exit__)
      1   0.000   0.000   0.000   0.000 timer.py:52(__enter__)

Luckily, Timer causes only minimal overhead. Use quit to leave the pstats browser when you’re done investigating.

For a more powerful interface into profile data, check out KCacheGrind. It uses its own data format, but you can convert data from cProfile using pyprof2calltree:

$ pyprof2calltree -k -i latest_tutorial.prof

This command will convert latest_tutorial.prof and open KCacheGrind to analyze the data.

The last option that you’ll try here for timing your code is line_profiler. cProfile can tell you which functions your code spends the most time in, but it won’t give you insights into which lines inside that function are the slowest. That’s where line_profiler can help you.

Note that line profiling takes time and adds a fair bit of overhead to your runtime. A normal workflow is first to use cProfile to identify which functions to investigate and then run line_profiler on those functions. line_profiler isn’t part of the standard library, so you should first follow the installation instructions to set it up.

Before you run the profiler, you need to tell it which functions to profile. You do this by adding a @profile decorator inside your source code. For example, to profile Timer.stop(), you add the following inside timer.py:

@profile
def stop(self) -> float:
    # The rest of the code is unchanged

Note that you don’t import profile anywhere. Instead, it’s automatically added to the global namespace when you run the profiler. You need to delete the line when you’re done profiling, though. Otherwise, you’ll get a NameError.

Next, run the profiler using kernprof, which is part of the line_profiler package:

$ kernprof -l latest_tutorial.py

This command automatically saves the profiler data in a file called latest_tutorial.py.lprof. You can see those results using line_profiler:

$ python -m line_profiler latest_tutorial.py.lprof
Timer unit: 1e-06 s

Total time: 1.6e-05 s
File: /home/realpython/timer.py
Function: stop at line 35

# Hits Time PrHit %Time Line Contents
=====================================
35                      @profile
36                      def stop(self) -> float:
37                          """Stop the timer, and report the elapsed time"""
38  1   1.0   1.0   6.2     if self._start_time is None:
39                              raise TimerError(f"Timer is not running. ...")
40
41                          # Calculate elapsed time
42  1   2.0   2.0  12.5     elapsed_time = time.perf_counter() - self._start_time
43  1   0.0   0.0   0.0     self._start_time = None
44
45                          # Report elapsed time
46  1   0.0   0.0   0.0     if self.logger:
47  1  11.0  11.0  68.8         self.logger(self.text.format(elapsed_time))
48  1   1.0   1.0   6.2     if self.name:
49  1   1.0   1.0   6.2         self.timers[self.name] += elapsed_time
50
51  1   0.0   0.0   0.0     return elapsed_time

First, note that the time unit in this report is microseconds (1e-06 s). Usually, the most accessible number to look at is %Time, which tells you the percentage of the total time your code spends inside a function at each line. In this example, you can see that your code spends almost 70 percent of the time on line 47, which is the line that formats and prints the result of the timer.