Measuring Time

In some recent script at some point I wanted to measure the time consumed in different sections of code (in a basic manner, it's not profiling information to store somewhere or anything, just to print on screen and probably end up removing it). I ended up with this:

start = time.time()
# do things
print(time.time()-start)
start = time.time()
# do something
print(time.time()-start)
start = time.time()
# do something
print(time.time()-start)
start = time.time()

Those 2 lines for each time I want to print and start the next "snapshot" add quite a bit of noise to the code. Oddly, I did not find an immediate, ready-made solution for this. so I came up with a nice use for a generator. We can have a generator function like this:

def elapsed_generator_fn():
    start = time.time()
    yield # we need a first next() call to perform this initialization
    while True:
        now = time.time()
        elapsed = now - start
        start = now
        yield elapsed

And write our code this way:

    elapsed = elapsed_generator_fn()
    # init it
    next(elapsed)

	# do something
    print(f"elapsed: {next(elapsed)}")

	# do something
    print(f"elapsed: {next(elapsed)}")

	# do something
    print(f"elapsed: {next(elapsed)}")

In the above code the first next() call is for initialization (setting the initial start value). It looks a bit odd in the code, so we could fix it by adding a function that creates the generator-iterator, does this init call, and returns it.

def elapsed_generator_factory():
    generator = elapsed_generator_fn()
    next(generator)
    return generator
	
elapsed = elapsed_generator_factory()
# do something
print(f"elapsed: {next(elapsed)}")

# do something
print(f"elapsed: {next(elapsed)}")

# do something
print(f"elapsed: {next(elapsed)}")

As I've said, it seems to me like a cool use for generators. If we want something more complete (that gives us the total time, that stores the different snapshots...) we should move on and end up with a simple class like this.

class Elapsed:
    def __init__(self):
        self.initial_start = None
        self.snapshots = {}

    def start(self):
        self.initial_start = time.time()
        self.start = self.initial_start

    def take_snapshot(self, name):
        now = time.time()
        self.snapshots[name] = now - self.start
        self.start = now
        return self.snapshots[name]
    
    def total(self):
        return time.time() - self.initial_start

    def retrieve_snapshots(self):
        return self.snapshots
		
    elapsed = Elapsed()
    elapsed.start()
    time.sleep(2)
    print(f"elapsed: {elapsed.take_snapshot('first')}")

    time.sleep(1)
    print(f"elapsed: {elapsed.take_snapshot('second')}")

    time.sleep(3)
    print(f"elapsed: {elapsed.take_snapshot('third')}")

    print(f"total elapsed: {elapsed.total()}")

    print(f"snapshots: {elapsed.retrieve_snapshots()}")