.. DO NOT EDIT. .. THIS FILE WAS AUTOMATICALLY GENERATED BY SPHINX-GALLERY. .. TO MAKE CHANGES, EDIT THE SOURCE PYTHON FILE: .. "_build/auto_examples/tutorial/10-TimeTrains.py" .. LINE NUMBERS ARE GIVEN BELOW. .. only:: html .. note:: :class: sphx-glr-download-link-note :ref:`Go to the end ` to download the full example code. .. rst-class:: sphx-glr-example-title .. _sphx_glr__build_auto_examples_tutorial_10-TimeTrains.py: Time Trains =========== .. GENERATED FROM PYTHON SOURCE LINES 7-8 As demonstrated in earlier posts in the tutorial, :mod:`pyquickbench` can be useful to measure the wall time of python functions. More often than not however, it can be useful to have a more precise idea of where CPU cycles are spent. This is the raison d'être of :class:`pyquickbench.TimeTrain`. As shown in the following few lines, using a :class:`pyquickbench.TimeTrain` is extremely simple: simply call the :meth:`pyquickbench.TimeTrain.toc` method between snippets of code you want to time and :mod:`pyquickbench` takes care of the rest! .. GENERATED FROM PYTHON SOURCE LINES 8-13 .. code-block:: Python import time import pyquickbench .. GENERATED FROM PYTHON SOURCE LINES 45-66 .. code-block:: Python TT = pyquickbench.TimeTrain() time.sleep(0.01) TT.toc() time.sleep(0.02) TT.toc() time.sleep(0.03) TT.toc() time.sleep(0.04) TT.toc() time.sleep(0.01) TT.toc() print(TT) .. rst-class:: sphx-glr-script-out .. code-block:: none TimeTrain results: 0.01005455 s at file 10-TimeTrains.py line 49 0.02003816 s at file 10-TimeTrains.py line 52 0.03004684 s at file 10-TimeTrains.py line 55 0.04003194 s at file 10-TimeTrains.py line 58 0.01006837 s at file 10-TimeTrains.py line 61 Total: 0.11023987 s .. GENERATED FROM PYTHON SOURCE LINES 67-68 Individual calls to :meth:`pyquickbench.TimeTrain.toc` can be named. .. GENERATED FROM PYTHON SOURCE LINES 68-81 .. code-block:: Python TT = pyquickbench.TimeTrain() for i in range(3): time.sleep(0.01) TT.toc("repeated") for i in range(3): time.sleep(0.01) TT.toc(f"unique {i+1}") print(TT) .. rst-class:: sphx-glr-script-out .. code-block:: none TimeTrain results: repeated : 0.01006465 s at file 10-TimeTrains.py line 73 repeated : 0.01006365 s at file 10-TimeTrains.py line 73 repeated : 0.01006117 s at file 10-TimeTrains.py line 73 unique 1 : 0.01007218 s at file 10-TimeTrains.py line 77 unique 2 : 0.01006285 s at file 10-TimeTrains.py line 77 unique 3 : 0.01006304 s at file 10-TimeTrains.py line 77 Total: 0.06038754 s .. GENERATED FROM PYTHON SOURCE LINES 82-83 Timing measurements relative to identical names can be reduced using any reduction method in :data:`pyquickbench.all_reductions`. .. GENERATED FROM PYTHON SOURCE LINES 83-98 .. code-block:: Python TT = pyquickbench.TimeTrain( names_reduction = 'sum', ) for i in range(3): time.sleep(0.01) TT.toc("repeated") for i in range(3): time.sleep(0.01) TT.toc(f"unique {i+1}") print(TT) .. rst-class:: sphx-glr-script-out .. code-block:: none /home/gfo/pyquickbench/pyquickbench/_time_train.py:113: UserWarning: include_locs and names_reduction were both enabled. Only the first location will be displayed for every name. warnings.warn("include_locs and names_reduction were both enabled. Only the first location will be displayed for every name.") TimeTrain results: Reduction: sum repeated : 0.03018809 s at file 10-TimeTrains.py line 90 unique 1 : 0.01007752 s at file 10-TimeTrains.py line 94 unique 2 : 0.01007652 s at file 10-TimeTrains.py line 94 unique 3 : 0.01006756 s at file 10-TimeTrains.py line 94 Total: 0.06040969 s .. GENERATED FROM PYTHON SOURCE LINES 99-100 Relative measured times can be reported using the keyword ``relative_timings``. .. GENERATED FROM PYTHON SOURCE LINES 100-117 .. code-block:: Python TT = pyquickbench.TimeTrain( names_reduction = 'avg', relative_timings = True, ) for i in range(3): time.sleep(0.01) TT.toc("repeated") for i in range(3): time.sleep(0.01) TT.toc(f"unique {i+1}") print(TT) .. rst-class:: sphx-glr-script-out .. code-block:: none /home/gfo/pyquickbench/pyquickbench/_time_train.py:119: UserWarning: Reduction avg combined with "relative_timings = True" will lead to reported timings not adding up to 100%. warnings.warn(f"Reduction {self.names_reduction_key} combined with \"relative_timings = True\" will lead to reported timings not adding up to 100%.") TimeTrain results: Reduction: avg repeated : 16.66770650 % at file 10-TimeTrains.py line 108 unique 1 : 16.66453319 % at file 10-TimeTrains.py line 112 unique 2 : 16.66254677 % at file 10-TimeTrains.py line 112 unique 3 : 16.66980052 % at file 10-TimeTrains.py line 112 Total: 0.06041013 s .. GENERATED FROM PYTHON SOURCE LINES 118-120 Reductions make locations ill-defined, which is why :class:`pyquickbench.TimeTrain` is issuing a warning. Another good reason to disable location recording is that the corresponding call to :func:`python:inspect.stack` can be non-negligible (around 0.01s on a generic laptop computer). Displaying locations can be disabled like so: .. GENERATED FROM PYTHON SOURCE LINES 120-137 .. code-block:: Python TT = pyquickbench.TimeTrain( names_reduction = 'sum', include_locs = False, ) for i in range(3): time.sleep(0.01) TT.toc("repeated") for i in range(3): time.sleep(0.01) TT.toc(f"unique {i+1}") print(TT) .. rst-class:: sphx-glr-script-out .. code-block:: none TimeTrain results: Reduction: sum repeated : 0.03020864 s unique 1 : 0.01009330 s unique 2 : 0.01006893 s unique 3 : 0.01006521 s Total: 0.06043607 s .. GENERATED FROM PYTHON SOURCE LINES 138-139 TimeTrains can also time calls to a function. The function :meth:`pyquickbench.TimeTrain.tictoc` will instrument a given function to record its execution time. The most starightforward is to use :meth:`pyquickbench.TimeTrain.tictoc` with a decorator syntax: .. GENERATED FROM PYTHON SOURCE LINES 139-156 .. code-block:: Python TT = pyquickbench.TimeTrain() @TT.tictoc def wait_a_bit(): time.sleep(0.01) @TT.tictoc def wait_more(): time.sleep(0.01) wait_a_bit() wait_more() print(TT) .. rst-class:: sphx-glr-script-out .. code-block:: none TimeTrain results: wait_a_bit : 0.01007944 s at file 10-TimeTrains.py line 151 wait_more : 0.01007003 s at file 10-TimeTrains.py line 152 Total: 0.02014947 s .. GENERATED FROM PYTHON SOURCE LINES 157-158 Using :meth:`pyquickbench.TimeTrain.tictoc` with a regular wrapping syntax might lead to surprizing results: .. GENERATED FROM PYTHON SOURCE LINES 158-171 .. code-block:: Python TT = pyquickbench.TimeTrain() def wait_unrecorded(): time.sleep(0.01) wait_recorded = TT.tictoc(wait_unrecorded) wait_unrecorded() wait_recorded() print(TT) .. rst-class:: sphx-glr-script-out .. code-block:: none TimeTrain results: wait_unrecorded : 0.01007392 s at file 10-TimeTrains.py line 167 Total: 0.01007392 s .. GENERATED FROM PYTHON SOURCE LINES 172-173 This behavior is to be expected because under the hood, :meth:`pyquickbench.TimeTrain.tictoc` uses the ``__name__`` attribute of the wrapped function. .. GENERATED FROM PYTHON SOURCE LINES 173-176 .. code-block:: Python print(f'{wait_recorded.__name__ = }') .. rst-class:: sphx-glr-script-out .. code-block:: none wait_recorded.__name__ = 'wait_unrecorded' .. GENERATED FROM PYTHON SOURCE LINES 177-178 Overriding the ``__name__`` of the wrapped function gives the expected result: .. GENERATED FROM PYTHON SOURCE LINES 178-191 .. code-block:: Python TT = pyquickbench.TimeTrain() def wait_unrecorded(): time.sleep(0.01) wait_recorded = TT.tictoc(wait_unrecorded) wait_recorded.__name__ = 'wait_recorded' wait_unrecorded() wait_recorded() print(TT) .. rst-class:: sphx-glr-script-out .. code-block:: none TimeTrain results: wait_recorded : 0.01006476 s at file 10-TimeTrains.py line 188 Total: 0.01006476 s .. GENERATED FROM PYTHON SOURCE LINES 192-193 More simply, you can set a custom name with the following syntax: .. GENERATED FROM PYTHON SOURCE LINES 193-206 .. code-block:: Python TT = pyquickbench.TimeTrain() def wait_unrecorded(): time.sleep(0.01) wait_recorded = TT.tictoc(wait_unrecorded, name = "my_custom_name") wait_unrecorded() wait_recorded() print(TT) .. rst-class:: sphx-glr-script-out .. code-block:: none TimeTrain results: my_custom_name : 0.01006429 s at file 10-TimeTrains.py line 202 Total: 0.01006429 s .. GENERATED FROM PYTHON SOURCE LINES 207-208 By default, a :class:`pyquickbench.TimeTrain` will not show timings occuring in between decorated function. This behavior can be overriden setting the ``ignore_names`` argument to an empty iterator: .. GENERATED FROM PYTHON SOURCE LINES 208-224 .. code-block:: Python TT = pyquickbench.TimeTrain(ignore_names = []) def wait_unrecorded(): time.sleep(0.01) @TT.tictoc def wait_recorded(): time.sleep(0.02) wait_unrecorded() wait_recorded() print(TT) .. rst-class:: sphx-glr-script-out .. code-block:: none TimeTrain results: pyquickbench_sync : 0.01009569 s at file 10-TimeTrains.py line 219 wait_recorded : 0.02007292 s at file 10-TimeTrains.py line 219 Total: 0.03016861 s .. GENERATED FROM PYTHON SOURCE LINES 225-227 Let's revisit the benchmark in :ref:`sphx_glr__build_auto_examples_tutorial_09-Vector_output.py` and measure the execution time of different parts of the function ``uniform_quantiles`` using :class:`pyquickbench.TimeTrain`. .. GENERATED FROM PYTHON SOURCE LINES 227-245 .. code-block:: Python def uniform_quantiles(n, m): TT = pyquickbench.TimeTrain( include_locs = False, ) vec = np.random.random((n+1)) TT.toc("Random sampling") vec.sort() TT.toc("Sorting") res = np.array([abs(vec[(n // m)*i]) for i in range(m+1)]) TT.toc("Building result") return TT .. GENERATED FROM PYTHON SOURCE LINES 246-251 This function can be divided up into three main parts: * A random sampling phase, where data is generated. This part is expected to scale as :math:`\mathcal{O}(n)`. * A sorting phase where the random vector is sorted in-place. This part is expected to scale as :math:`\mathcal{O}(n\log(n))`, and thus be dominant for large :math:`n`. * A last phase where estimated quantiles are built and returned. This phase is expected to scale as :math:`\mathcal{O}(1)` and be negligible for large :math:`n`. .. GENERATED FROM PYTHON SOURCE LINES 252-282 .. code-block:: Python m = 10 uniform_decile = functools.partial(uniform_quantiles, m=m) uniform_decile.__name__ = "uniform_decile" all_funs = [ uniform_decile , ] n_bench = 20 all_sizes = [m * 2**n for n in range(n_bench)] n_repeat = 100 plot_intent = { pyquickbench.default_ax_name : "points" , pyquickbench.out_ax_name : "curve_color" , } pyquickbench.run_benchmark( all_sizes , all_funs , n_repeat = n_repeat , mode = "vector_output" , StopOnExcept = True , plot_intent = plot_intent , show = True , ) .. image-sg:: /_build/auto_examples/tutorial/images/sphx_glr_10-TimeTrains_001.png :alt: 10 TimeTrains :srcset: /_build/auto_examples/tutorial/images/sphx_glr_10-TimeTrains_001.png :class: sphx-glr-single-img .. _sphx_glr_download__build_auto_examples_tutorial_10-TimeTrains.py: .. only:: html .. container:: sphx-glr-footer sphx-glr-footer-example .. container:: sphx-glr-download sphx-glr-download-jupyter :download:`Download Jupyter notebook: 10-TimeTrains.ipynb <10-TimeTrains.ipynb>` .. container:: sphx-glr-download sphx-glr-download-python :download:`Download Python source code: 10-TimeTrains.py <10-TimeTrains.py>` .. container:: sphx-glr-download sphx-glr-download-zip :download:`Download zipped: 10-TimeTrains.zip <10-TimeTrains.zip>` .. only:: html .. rst-class:: sphx-glr-signature `Gallery generated by Sphinx-Gallery `_