profilers.ipynb

{
 "cells": [
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "# Profilers\n",
    "\n",
    "A quick introduction to profiling within a Jupyter notebook.\n",
    "\n",
    "We'll use Paul's prime sieve code from an earlier (or possibly later) training module."
   ]
  },
  {
   "cell_type": "code",
   "execution_count": null,
   "metadata": {},
   "outputs": [],
   "source": [
    "import  math\n",
    "def sieve_primes(n):\n",
    "    a = [True for x in range(n + 1)]\n",
    "    i = 2\n",
    "    while i <= math.sqrt(n):\n",
    "        if a[i]:\n",
    "            for j in range(i*i, n + 1, i):\n",
    "                a[j] = False\n",
    "        i += 1\n",
    "    return [i for i in range(2, len(a)) if a[i]]"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": null,
   "metadata": {},
   "outputs": [],
   "source": [
    "#Check it's working OK\n",
    "sieve_primes(30)"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "Now we'll measure sieve_primes using the time and timeit magic commands. "
   ]
  },
  {
   "cell_type": "code",
   "execution_count": null,
   "metadata": {},
   "outputs": [],
   "source": [
    "#Time it for all primes less than 5 million\n",
    "N = 5000000\n",
    "%time p = sieve_primes(N);"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": null,
   "metadata": {},
   "outputs": [],
   "source": [
    "%timeit p = sieve_primes(N);"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "Note the difference in execution time between `time` and `timeit`. We get more information from `timeit`, i.e. mean and standard deviation, but at the expense of waiting longer for the result. In general it's important to execute code a few times when timing and profiling to ensure the data is representative of typical runs. Code execution times may vary significantly for different input data sets, or different initial conditions. \n",
    "\n",
    "There's more information about the `%timeit` line magic and `%%timeit` cell magic in the [IPython docs](https://ipython.readthedocs.io/en/stable/interactive/magics.html), e.g. the `-o` flag can be used to return an object containing the results. "
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "### Let's use the Python profiler"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": null,
   "metadata": {},
   "outputs": [],
   "source": [
    "%prun p = sieve_primes(N)"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "If we want to apply the profiler to whole cell, we'd use the `%%prun` cell magic.\n",
    "\n",
    "For this example the data tells us `sieve_primes` is the function with the largest `tottime`, and gives us some insight into the internals of Python, but doesn't really tell us anything we can use to improve performance. However the Python profiler is a powerful tool whenever we have multiple functions and want to find out where time is spent.   "
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "### Now let's try the line profiler\n",
    "This isn't part of core Python, **so make sure the `line_profiler` package is installed** e.g. using `pip` or `conda`. The extension needs to be loaded using the `%load_ext` magic command."
   ]
  },
  {
   "cell_type": "code",
   "execution_count": null,
   "metadata": {},
   "outputs": [],
   "source": [
    "%load_ext line_profiler"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "Also, we need to tell the profiler which function(s) to profile with the `-f` flag. In this example we want to profile sieve_primes, so we need `-f sieve_primes`.  If we we're running in a Jupyter Notebook we'd need to use the `@profile` decorator. \n",
    "\n",
    "Also we can set the time units using with `-u`, i.e. `-u 1e-3` for ms. We'll use units of seconds. "
   ]
  },
  {
   "cell_type": "code",
   "execution_count": null,
   "metadata": {},
   "outputs": [],
   "source": [
    "%lprun -u 1 -f sieve_primes p = sieve_primes(N)"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "The `Total time` is much larger that the unprofiled run time, so are these values useful? Sometimes when profiling, there's no clear answer to questions like this! "
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "### What next?\n",
    "As you might expect, there's plenty of Python packages out there aiming to improve on these profilers. For example, SnakeViz is a browser based graphical viewer which can be used to display the output of Python’s cProfile module, and can be run within notebooks. You'll need to install `snakeviz` first using `pip` or `conda`, and then load the extension. "
   ]
  },
  {
   "cell_type": "code",
   "execution_count": null,
   "metadata": {},
   "outputs": [],
   "source": [
    "%load_ext snakeviz"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "Next we'll run SnakeViz. \n",
    "\n",
    "SnakeViz has two views:\n",
    "\n",
    "* Icicle\n",
    " * Fraction of time in a function is represented by width of a rectangle\n",
    " * The first function to be called is the top-most rectangle, with the functions it calls directly below it, etc.\n",
    " * Internal time (i.e. tottime) for each function is shown as an additional child function \n",
    "* Sunburst \n",
    " * Fraction of time in a function is represented by the angular extent of an arc\n",
    " * The first function to be called is the inner most circle, with functions it calls around it, etc. \n",
    " \n",
    "Clicking on a function in the visualisation will zoom in. \n",
    "\n",
    "SnakeViz also displays the same data we saw above with `%prun` in a table at the bottom. Clicking on a function in this table makes it the root function in the visualization.\n",
    "\n",
    "For more information e.g. on Cutoff and Depth see [the SnakeView docs](https://jiffyclub.github.io/snakeviz/). "
   ]
  },
  {
   "cell_type": "code",
   "execution_count": null,
   "metadata": {},
   "outputs": [],
   "source": [
    "%snakeviz p = sieve_primes(N)"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "## Exercise\n",
    "\n",
    " 1. Try different `prun` sort options using the `-s` flag as described in the documentation   https://ipython.readthedocs.io/en/stable/interactive/magics.html\n",
    " 1. Test the profilers on your own code. "
   ]
  },
  {
   "cell_type": "code",
   "execution_count": null,
   "metadata": {},
   "outputs": [],
   "source": []
  }
 ],
 "metadata": {
  "kernelspec": {
   "display_name": "Python 3",
   "language": "python",
   "name": "python3"
  },
  "language_info": {
   "codemirror_mode": {
    "name": "ipython",
    "version": 3
   },
   "file_extension": ".py",
   "mimetype": "text/x-python",
   "name": "python",
   "nbconvert_exporter": "python",
   "pygments_lexer": "ipython3",
   "version": "3.7.3"
  },
  "latex_envs": {
   "LaTeX_envs_menu_present": true,
   "autoclose": false,
   "autocomplete": true,
   "bibliofile": "biblio.bib",
   "cite_by": "apalike",
   "current_citInitial": 1,
   "eqLabelWithNumbers": true,
   "eqNumInitial": 1,
   "hotkeys": {
    "equation": "Ctrl-E",
    "itemize": "Ctrl-I"
   },
   "labels_anchors": false,
   "latex_user_defs": false,
   "report_style_numbering": false,
   "user_envs_cfg": false
  }
 },
 "nbformat": 4,
 "nbformat_minor": 2
}