Query about order of timings

[bml1g12]

Love this library @mbdevpl . Was just playing around with some benchmarks for an article I plan to write on Python multiprocessing + numpy arrays, and I ran into some unintuitive behaviour:

    for _ in _TIME.measure_many("baseline", samples=n_frames):
        baseline_benchmark(np_arr)

    for _ in _TIME.measure_many("mp_queue", samples=n_frames):
        mp_queue_benchmark(np_arr, mp_queue)

    for _ in _TIME.measure_many("queue_module", samples=n_frames):
        queue_module_benchmark(np_arr, queue_module)

    timings.append(get_timings("baseline", n_frames))
    timings.append(get_timings("mp_queue", n_frames))
    timings.append(get_timings("queue_module", n_frames))

This code works. But rearranging the same code to:

    for _ in _TIME.measure_many("baseline", samples=n_frames):
        baseline_benchmark(np_arr)
    timings.append(get_timings("baseline", n_frames))
    for _ in _TIME.measure_many("mp_queue", samples=n_frames):
        mp_queue_benchmark(np_arr, mp_queue)
    timings.append(get_timings("mp_queue", n_frames))
    for _ in _TIME.measure_many("queue_module", samples=n_frames):
        queue_module_benchmark(np_arr, queue_module)
    timings.append(get_timings("queue_module", n_frames))

Returns

╰─❯ python array_benchmark/queue_benchmarking/queues.py
baseline: time: = 0.0008 +/- 0.0001 or FPS = 121740.87059304002
Traceback (most recent call last):
  File "array_benchmark/queue_benchmarking/queues.py", line 100, in <module>
    DF = benchmark_queues()
  File "array_benchmark/queue_benchmarking/queues.py", line 83, in benchmark_queues
    timings.append(get_timings("mp_queue", n_frames))
  File "array_benchmark/queue_benchmarking/queues.py", line 61, in get_timings
    mean = f"{_TIME.summary[groupname]['mean']:.4f}"
KeyError: 'mp_queue'

Whereby I am using this function.

def get_timings(groupname, n_frames):
    """ Get a dictionary of the mean/std and FPS of the timing group.

    :param str groupname: name of the timing group
    :param int n_frames: number of timing repeats
    :return: mean/std and FPS of the timing group as a dictionary
    :rtype: dict
    """
    mean = f"{_TIME.summary[groupname]['mean']:.4f}"
    stddev = f"{_TIME.summary[groupname]['stddev']:.4f}"
    fps = f"{n_frames / _TIME.summary[groupname]['mean']}"
    print(f"{groupname}: time: = {mean} +/- "
          f"{stddev}"
          f" or FPS = {fps}")
    return {"groupname": groupname, "mean": mean, "stddev": stddev, "fps": fps}

Not sure if it is a bug or expected behaviour, but it seems that a requirement is that all summary metrics are calculated after all timings are complete, is that the case, if so might best to add to the docs.

[bml1g12]

Also is there a way to reset the cache, so we can start from fresh timings using the same names? Tried

from timing.cache import TimingCache
TimingCache.clear()

But seems to cause key errors doing so

[mbdevpl]

@bml1g12 Sorry for super-late response here 😭

I think the counter-intuitive part comes from the "caching" nature of _TIME.summary -> the implementation of .summary is something like:

        if self._summary is None:
            self.summarize()  # this re-generates self._summary
        return self._summary

So if you refer to the .summary and then run additional benchmarks, your summary will be out of date. This is intended due to the how big the overhead can get when generating statistics on very big collection of timings. So first reference to .summary will run summarize() (i.e. the costly calculating function) but subsequent will not.

I'd highly recommend either keeping the 1st approach (run and then analyse stats), or if you need to calculate intermediate stats, directly call _TIME.summarize() to do that as necessary.

If you don't care about penalty in your get_timings function, you can even just run _TIME.summarize() on the 1st line of the function. I don't think this should be too costly if you have relatively few timings to generate stats for.

I've added a a following docs note on the .summary to be released soon to PyPI (in upcoming version 0.5.1).

    @property
    def summary(self) -> t.Dict[str, t.Any]:
        """Return a collection of statistics for the timings in this group.

        Calculate statistics if not already calculated, and use cached values otherwise.
        """
        ...