Update 01.07 and 01.08

Author: jakevdp

notebooks_v2/01.07-Timing-and-Profiling.ipynb

@@ -37,7 +37,7 @@
     "Early in developing your algorithm, it can be counterproductive to worry about such things. As Donald Knuth famously quipped, \"We should forget about small efficiencies, say about 97% of the time: premature optimization is the root of all evil.\"\n",
     "\n",
     "But once you have your code working, it can be useful to dig into its efficiency a bit.\n",
-    "Sometimes it's useful to check the execution time of a given command or set of commands; other times it's useful to dig into a multiline process and determine where the bottleneck lies in some complicated series of operations.\n",
+    "Sometimes it's useful to check the execution time of a given command or set of commands; other times it's useful to examine a multiline process and determine where the bottleneck lies in some complicated series of operations.\n",
     "IPython provides access to a wide array of functionality for this kind of timing and profiling of code.\n",
     "Here we'll discuss the following IPython magic commands:\n",
     "\n",
@@ -69,7 +69,7 @@
      "name": "stdout",
      "output_type": "stream",
      "text": [
-      "100000 loops, best of 3: 1.54 µs per loop\n"
+      "1.53 µs ± 47.8 ns per loop (mean ± std. dev. of 7 runs, 1000000 loops each)\n"
      ]
     }
    ],
@@ -94,7 +94,7 @@
      "name": "stdout",
      "output_type": "stream",
      "text": [
-      "1 loops, best of 3: 407 ms per loop\n"
+      "536 ms ± 15.9 ms per loop (mean ± std. dev. of 7 runs, 1 loop each)\n"
      ]
     }
    ],
@@ -124,7 +124,7 @@
      "name": "stdout",
      "output_type": "stream",
      "text": [
-      "100 loops, best of 3: 1.9 ms per loop\n"
+      "1.71 ms ± 334 µs per loop (mean ± std. dev. of 7 runs, 1000 loops each)\n"
      ]
     }
    ],
@@ -152,8 +152,8 @@
      "output_type": "stream",
      "text": [
       "sorting an unsorted list:\n",
-      "CPU times: user 40.6 ms, sys: 896 µs, total: 41.5 ms\n",
-      "Wall time: 41.5 ms\n"
+      "CPU times: user 31.3 ms, sys: 686 µs, total: 32 ms\n",
+      "Wall time: 33.3 ms\n"
      ]
     }
    ],
@@ -174,8 +174,8 @@
      "output_type": "stream",
      "text": [
       "sorting an already sorted list:\n",
-      "CPU times: user 8.18 ms, sys: 10 µs, total: 8.19 ms\n",
-      "Wall time: 8.24 ms\n"
+      "CPU times: user 5.19 ms, sys: 268 µs, total: 5.46 ms\n",
+      "Wall time: 14.1 ms\n"
      ]
     }
    ],
@@ -205,8 +205,8 @@
      "name": "stdout",
      "output_type": "stream",
      "text": [
-      "CPU times: user 504 ms, sys: 979 µs, total: 505 ms\n",
-      "Wall time: 505 ms\n"
+      "CPU times: user 655 ms, sys: 5.68 ms, total: 661 ms\n",
+      "Wall time: 710 ms\n"
      ]
     }
    ],
@@ -269,6 +269,25 @@
      "text": [
       " "
      ]
+    },
+    {
+     "data": {
+      "text/plain": [
+       "         14 function calls in 0.932 seconds\n",
+       "\n",
+       "   Ordered by: internal time\n",
+       "\n",
+       "   ncalls  tottime  percall  cumtime  percall filename:lineno(function)\n",
+       "        5    0.808    0.162    0.808    0.162 <ipython-input-7-f105717832a2>:4(<listcomp>)\n",
+       "        5    0.066    0.013    0.066    0.013 {built-in method builtins.sum}\n",
+       "        1    0.044    0.044    0.918    0.918 <ipython-input-7-f105717832a2>:1(sum_of_lists)\n",
+       "        1    0.014    0.014    0.932    0.932 <string>:1(<module>)\n",
+       "        1    0.000    0.000    0.932    0.932 {built-in method builtins.exec}\n",
+       "        1    0.000    0.000    0.000    0.000 {method 'disable' of '_lsprof.Profiler' objects}"
+      ]
+     },
+     "metadata": {},
+     "output_type": "display_data"
     }
    ],
    "source": [
@@ -279,21 +298,6 @@
    "cell_type": "markdown",
    "metadata": {},
    "source": [
-    "In the notebook, the output is printed to the pager, and looks something like this:\n",
-    "\n",
-    "```\n",
-    "14 function calls in 0.714 seconds\n",
-    "\n",
-    "   Ordered by: internal time\n",
-    "\n",
-    "   ncalls  tottime  percall  cumtime  percall filename:lineno(function)\n",
-    "        5    0.599    0.120    0.599    0.120 <ipython-input-19>:4(<listcomp>)\n",
-    "        5    0.064    0.013    0.064    0.013 {built-in method sum}\n",
-    "        1    0.036    0.036    0.699    0.699 <ipython-input-19>:1(sum_of_lists)\n",
-    "        1    0.014    0.014    0.714    0.714 <string>:1(<module>)\n",
-    "        1    0.000    0.000    0.714    0.714 {built-in method exec}\n",
-    "```\n",
-    "\n",
     "The result is a table that indicates, in order of total time on each function call, where the execution is spending the most time. In this case, the bulk of execution time is in the list comprehension inside ``sum_of_lists``.\n",
     "From here, we could start thinking about what changes we might make to improve the performance in the algorithm.\n",
     "\n",
@@ -337,7 +341,30 @@
    "cell_type": "code",
    "execution_count": 10,
    "metadata": {},
-   "outputs": [],
+   "outputs": [
+    {
+     "data": {
+      "text/plain": [
+       "Timer unit: 1e-06 s\n",
+       "\n",
+       "Total time: 0.014803 s\n",
+       "File: <ipython-input-7-f105717832a2>\n",
+       "Function: sum_of_lists at line 1\n",
+       "\n",
+       "Line #      Hits         Time  Per Hit   % Time  Line Contents\n",
+       "==============================================================\n",
+       "     1                                           def sum_of_lists(N):\n",
+       "     2         1          6.0      6.0      0.0      total = 0\n",
+       "     3         6         13.0      2.2      0.1      for i in range(5):\n",
+       "     4         5      14242.0   2848.4     96.2          L = [j ^ (j >> i) for j in range(N)]\n",
+       "     5         5        541.0    108.2      3.7          total += sum(L)\n",
+       "     6         1          1.0      1.0      0.0      return total"
+      ]
+     },
+     "metadata": {},
+     "output_type": "display_data"
+    }
+   ],
    "source": [
     "%lprun -f sum_of_lists sum_of_lists(5000)"
    ]
@@ -346,25 +373,6 @@
    "cell_type": "markdown",
    "metadata": {},
    "source": [
-    "As before, the notebook sends the result to the pager, but it looks something like this:\n",
-    "\n",
-    "```\n",
-    "Timer unit: 1e-06 s\n",
-    "\n",
-    "Total time: 0.009382 s\n",
-    "File: <ipython-input-19-fa2be176cc3e>\n",
-    "Function: sum_of_lists at line 1\n",
-    "\n",
-    "Line #      Hits         Time  Per Hit   % Time  Line Contents\n",
-    "==============================================================\n",
-    "     1                                           def sum_of_lists(N):\n",
-    "     2         1            2      2.0      0.0      total = 0\n",
-    "     3         6            8      1.3      0.1      for i in range(5):\n",
-    "     4         5         9001   1800.2     95.9          L = [j ^ (j >> i) for j in range(N)]\n",
-    "     5         5          371     74.2      4.0          total += sum(L)\n",
-    "     6         1            0      0.0      0.0      return total\n",
-    "```\n",
-    "\n",
     "The information at the top gives us the key to reading the results: the time is reported in microseconds and we can see where the program is spending the most time.\n",
     "At this point, we may be able to use this information to modify aspects of the script and make it perform better for our desired use case.\n",
     "\n",
@@ -390,7 +398,7 @@
   },
   {
    "cell_type": "code",
-   "execution_count": 12,
+   "execution_count": 11,
    "metadata": {},
    "outputs": [],
    "source": [
@@ -407,14 +415,14 @@
   },
   {
    "cell_type": "code",
-   "execution_count": 13,
+   "execution_count": 12,
    "metadata": {},
    "outputs": [
     {
      "name": "stdout",
      "output_type": "stream",
      "text": [
-      "peak memory: 100.08 MiB, increment: 61.36 MiB\n"
+      "peak memory: 141.70 MiB, increment: 75.65 MiB\n"
      ]
     }
    ],
@@ -426,15 +434,15 @@
    "cell_type": "markdown",
    "metadata": {},
    "source": [
-    "We see that this function uses about 100 MB of memory.\n",
+    "We see that this function uses about 140 MB of memory.\n",
     "\n",
     "For a line-by-line description of memory use, we can use the ``%mprun`` magic.\n",
     "Unfortunately, this magic works only for functions defined in separate modules rather than the notebook itself, so we'll start by using the ``%%file`` magic to create a simple module called ``mprun_demo.py``, which contains our ``sum_of_lists`` function, with one addition that will make our memory profiling results more clear:"
    ]
   },
   {
    "cell_type": "code",
-   "execution_count": 14,
+   "execution_count": 13,
    "metadata": {},
    "outputs": [
     {
@@ -465,7 +473,7 @@
   },
   {
    "cell_type": "code",
-   "execution_count": 15,
+   "execution_count": 14,
    "metadata": {},
    "outputs": [
     {
@@ -474,6 +482,25 @@
      "text": [
       "\n"
      ]
+    },
+    {
+     "data": {
+      "text/plain": [
+       "Filename: /Users/jakevdp/github/jakevdp/PythonDataScienceHandbook/notebooks_v2/mprun_demo.py\n",
+       "\n",
+       "Line #    Mem usage    Increment  Occurences   Line Contents\n",
+       "============================================================\n",
+       "     1     66.7 MiB     66.7 MiB           1   def sum_of_lists(N):\n",
+       "     2     66.7 MiB      0.0 MiB           1       total = 0\n",
+       "     3     75.1 MiB      8.4 MiB           6       for i in range(5):\n",
+       "     4    105.9 MiB     30.8 MiB     5000015           L = [j ^ (j >> i) for j in range(N)]\n",
+       "     5    109.8 MiB      3.8 MiB           5           total += sum(L)\n",
+       "     6     75.1 MiB    -34.6 MiB           5           del L # remove reference to L\n",
+       "     7     66.9 MiB     -8.2 MiB           1       return total"
+      ]
+     },
+     "metadata": {},
+     "output_type": "display_data"
     }
    ],
    "source": [
@@ -485,28 +512,7 @@
    "cell_type": "markdown",
    "metadata": {},
    "source": [
-    "The result, printed to the pager, gives us a summary of the memory use of the function, and looks something like this:\n",
-    "```\n",
-    "Filename: ./mprun_demo.py\n",
-    "\n",
-    "Line #    Mem usage    Increment   Line Contents\n",
-    "================================================\n",
-    "     4     71.9 MiB      0.0 MiB           L = [j ^ (j >> i) for j in range(N)]\n",
-    "\n",
-    "\n",
-    "Filename: ./mprun_demo.py\n",
-    "\n",
-    "Line #    Mem usage    Increment   Line Contents\n",
-    "================================================\n",
-    "     1     39.0 MiB      0.0 MiB   def sum_of_lists(N):\n",
-    "     2     39.0 MiB      0.0 MiB       total = 0\n",
-    "     3     46.5 MiB      7.5 MiB       for i in range(5):\n",
-    "     4     71.9 MiB     25.4 MiB           L = [j ^ (j >> i) for j in range(N)]\n",
-    "     5     71.9 MiB      0.0 MiB           total += sum(L)\n",
-    "     6     46.5 MiB    -25.4 MiB           del L # remove reference to L\n",
-    "     7     39.1 MiB     -7.4 MiB       return total\n",
-    "```\n",
-    "Here the ``Increment`` column tells us how much each line affects the total memory budget: observe that when we create and delete the list ``L``, we are adding about 25 MB of memory usage.\n",
+    "Here the ``Increment`` column tells us how much each line affects the total memory budget: observe that when we create and delete the list ``L``, we are adding about 30 MB of memory usage.\n",
     "This is on top of the background memory usage from the Python interpreter itself.\n",
     "\n",
     "For more information on ``%memit`` and ``%mprun``, as well as their available options, use the IPython help functionality (i.e., type ``%memit?`` at the IPython prompt)."
@@ -529,7 +535,7 @@
    "formats": "ipynb,md"
   },
   "kernelspec": {
-   "display_name": "Python [default]",
+   "display_name": "Python 3",
    "language": "python",
    "name": "python3"
   },
@@ -543,9 +549,9 @@
    "name": "python",
    "nbconvert_exporter": "python",
    "pygments_lexer": "ipython3",
-   "version": "3.6.1"
+   "version": "3.9.2"
   }
  },
  "nbformat": 4,
- "nbformat_minor": 1
+ "nbformat_minor": 4
 }