.. DO NOT EDIT.
.. THIS FILE WAS AUTOMATICALLY GENERATED BY SPHINX-GALLERY.
.. TO MAKE CHANGES, EDIT THE SOURCE PYTHON FILE:
.. "auto_examples/plot_profile.py"
.. LINE NUMBERS ARE GIVEN BELOW.

.. only:: html

    .. note::
        :class: sphx-glr-download-link-note

        :ref:`Go to the end <sphx_glr_download_auto_examples_plot_profile.py>`
        to download the full example code

.. rst-class:: sphx-glr-example-title

.. _sphx_glr_auto_examples_plot_profile.py:


.. _l-example-dot-profile:

Profile a function
==================

:epkg:`pyinstrument` is a profiler for :epkg:`python` functions.
It tells how long the program stays in every function.
Because numerical functions are usually very short,
it is usually helpful to call them multiple times
before the cause becomes significant.

.. content::
    :local:

.. GENERATED FROM PYTHON SOURCE LINES 17-65

.. code-block:: default


    from sys import executable
    import sys
    import numpy
    from pyinstrument import Profiler
    from pyquickhelper.loghelper import run_cmd
    from td3a_cpp.tutorial import pydot, cblas_ddot


    va = numpy.random.randn(100000).astype(numpy.float64)
    vb = numpy.random.randn(100000).astype(numpy.float64)


    def f1_python(va, vb, n=10):
        # pydot is really too slow, let's run 10 times only
        for i in range(n):
            pydot(va, vb)


    def f2_numpy(va, vb, n=100000):
        for i in range(n):
            numpy.dot(va, vb)


    def f3_blas(va, vb, n=100000):
        for i in range(n):
            cblas_ddot(va, vb)


    if '--pyspy' in sys.argv:
        # When called with option --pyspy
        f1_python(va, vb)
        f2_numpy(va, vb)
        f3_blas(va, vb)
        profiler = None
    else:
        profiler = Profiler()
        profiler.start()

        f1_python(va, vb)
        f2_numpy(va, vb)
        f3_blas(va, vb)

        profiler.stop()

        print(profiler.output_text(unicode=False, color=False))






.. rst-class:: sphx-glr-script-out

 .. code-block:: none


      _     ._   __/__   _ _  _  _ _/_   Recorded: 05:37:11 AM Samples:  9232
     /_//_/// /_\ / //_// / //_'/ //     Duration: 9.377     CPU time: 65.105
    /   _/                      v4.3.0

    Program: somewheretd3a_cpp_39_std/td3a_cpp/examples/plot_profile.py

    9.376 <module>  plot_profile.py:18
    |- 4.007 f3_blas  plot_profile.py:41
    |     [4 frames hidden]  plot_profile, <built-in>
    |        3.837 cblas_ddot  <built-in>:0
    |- 3.963 f2_numpy  plot_profile.py:36
    |     [4 frames hidden]  plot_profile, numpy
    |        3.869 [self]  
    `- 1.405 f1_python  plot_profile.py:30
          [5 frames hidden]  plot_profile, td3a_cpp






.. GENERATED FROM PYTHON SOURCE LINES 66-76

numpy is much faster and does not always appear
if pydot is run the same number of times.
The program is spied on a given number of times
per seconds, each time the system records
which function the program is executing.
At the end, the profiler is able to approximatvely tell
how long the program stayed in every function.
If a function does not appear, it means it was never executed
or too fast to be caught.
An HTML report can be generated.

.. GENERATED FROM PYTHON SOURCE LINES 76-81

.. code-block:: default


    if profiler is not None:
        with open("dot_pyinstrument.html", "w", encoding="utf-8") as f:
            f.write(profiler.output_html())








.. GENERATED FROM PYTHON SOURCE LINES 82-90

See :ref:`l-appendix-example-dot-profile`.
:epkg:`pyinstrument` does not measure native function (C++)
very well. For this module :epkg:`py-spy` is more efficient
but it only works in command line as the package itself
is written in :epkg:`RUST`
(see `Taking ML to production with Rust: a 25x speedup
<https://www.lpalmieri.com/posts/
2019-12-01-taking-ml-to-production-with-rust-a-25x-speedup/>`_).

.. GENERATED FROM PYTHON SOURCE LINES 90-96

.. code-block:: default


    if profiler is not None:
        cmd = ("py-spy record --native --function --rate=10 "
               "-o dotpyspy.svg -- {0} plot_profile.py --pyspy").format(executable)
        run_cmd(cmd, wait=True, fLOG=print)





.. rst-class:: sphx-glr-script-out

 .. code-block:: none

    [run_cmd] execute py-spy record --native --function --rate=10 -o dotpyspy.svg -- somewheretd3a_cpp_39_std/_venv/bin/python plot_profile.py --pyspy
    end of execution py-spy record --native --function --rate=10 -o dotpyspy.svg -- somewheretd3a_cpp_39_std/_venv/bin/python plot_profile.py --pyspy




.. GENERATED FROM PYTHON SOURCE LINES 97-103

See :ref:`l-appendix-example-dot-profile`.
We see that :func:`cblas_ddot
<td3a_cpp.tutorial.cblas_ddot>`
and :func:`numpy.dot` uses
the same C function but the wrapping is not the same
and numpy is more efficient.


.. rst-class:: sphx-glr-timing

   **Total running time of the script:** ( 0 minutes  22.328 seconds)


.. _sphx_glr_download_auto_examples_plot_profile.py:

.. only:: html

  .. container:: sphx-glr-footer sphx-glr-footer-example




    .. container:: sphx-glr-download sphx-glr-download-python

      :download:`Download Python source code: plot_profile.py <plot_profile.py>`

    .. container:: sphx-glr-download sphx-glr-download-jupyter

      :download:`Download Jupyter notebook: plot_profile.ipynb <plot_profile.ipynb>`


.. only:: html

 .. rst-class:: sphx-glr-signature

    `Gallery generated by Sphinx-Gallery <https://sphinx-gallery.github.io>`_