code-advcd-best-practice.ipynb

{
 "cells": [
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "(code-advcd-best-practice)=\n",
    "# Shortcuts to Better Coding"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "## Introduction\n",
    "\n",
    "This chapter covers the tools and knowledge that will help you to write better code faster and to understand what's going on when your code goes wrong! This includes practical topics such as debugging code, logging, linting, and the magic of auto-formatting. Some of the topics are a bit more advanced and come with a warning to tell you so.\n",
    "\n",
    "As ever, you may need to `conda install packagename` or `pip install packagename` on the terminal before being able to use some of the packages that are featured."
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "## Auto-magically improving your code\n",
    "\n",
    "In the previous chapter, we met the idea of *code style*: even for code that runs, *how* you write it matters for readability. (And it goes without saying that you don't want bugs in your code that stop it running at all.) It is possible to catch some errors, to flag style issues, and even to re-format code to comply with a code style automatically. In this section, we'll see how to use tools to perform these functions automatically.\n",
    "\n",
    "### Linting\n",
    "\n",
    "Linters are tools that analyse code for programmatic and stylistic errors, assuming you have declared a style. A linting tool flags any potential errors and deviations from style before you even run it. When you run a linter, you get a report of what line the issue is on and why it has been raised. They are supposedly named after the lint trap in a clothes dryer because of the way they catch small errors that could have big effects.\n",
    "\n",
    "One of the most popular linters in Python is the blazingly-fast [**Ruff**](https://docs.astral.sh/ruff/) but you might also come across [**flake8**](https://flake8.pycqa.org/en/latest/), [**pycodestyle**](https://pycodestyle.pycqa.org/en/latest/intro.html), and [**pylint**](https://pypi.org/project/pylint/).\n",
    "\n",
    "Let's see an example of running a linter. VS Code has direct integration with a range of linters. To get going, use `⇧⌘P` (Mac) and then type 'Python Select Linter'. In the example below, we'll use **flake8** (and **pylance**, another VS Code extension that you will likely have already). Let's pretend we have a script, `test.py`, containing\n",
    "\n",
    "```python\n",
    "list_defn = [1,5, 6,\n",
    "7]\n",
    "\n",
    "def this_is_a_func():\n",
    "   print('hello')\n",
    "\n",
    "print(X)\n",
    "\n",
    "import numpy as np\n",
    "```\n",
    "\n",
    "To see the linting report, press <kbd>^</kbd> + <kbd>\\`</kbd> (Mac) or <kbd>ctrl</kbd> + <kbd>`</kbd> (otherwise) and navigate to the 'Problems' tab. We get a whole load of error messages about this script, here are a few:\n",
    "\n",
    "- ⓧ missing whitespace after ',' flake8(E231) 1, 15\n",
    "- ⓧ continuation line under-indented for visual indent flake8(E128) 2, 1\n",
    "- ⓧ expected 2 blank lines, found 1 flake8(E302) 4, 1\n",
    "- ⓧ indentation is not a multiple of 4 flake8(E111) 5, 4\n",
    "- ⓧ undefined name 'X' flake8(F821) 7, 7\n",
    "- ⓧ module level import not at top of file flake8(E402) 9, 1\n",
    "- ⓧ 'numpy as np' imported but unused flake8(F3401) 9, 1\n",
    "- ⚠ \"X\" is not defined Pylance(reportUndefinedVariable) 7, 7\n",
    "- ⚠ no newline at end of file flake8(W292) 78, 338\n",
    "\n",
    "each message is a warning or error that says what the problem is (for example, missing whitespace after ','), what library is reporting it (mostly **flake8** here), the name of the rule that has been broken (E231), and the line, row position (1, 15). Very helpfully, we get an undefined name message for variable `X`, this is especially handy because it would cause an error on execution otherwise. The same goes for the indentation message (indentation matters!). You can customise your [linting settings](https://code.visualstudio.com/docs/python/linting) in VS Code too.\n",
    "\n",
    "Although the automatic linting offered by an IDE is very convenient, it's not the only way to use linting tools. You can also run them from the command line. For example, for **flake8**, the command is `flake8 test.py`.\n",
    "\n",
    "### Formatting\n",
    "\n",
    "It's great to find out all the ways in which you are failing with respect to code style from a linter but wouldn't it be *even* better if you could fix those style issues automatically? The answer is clearly yes! This is where formatters come in; they can take valid code and forcibly apply a code style to them. This is really handy in practice for all kinds of reasons.\n",
    "\n",
    "The most popular code formatters in Python are probably: [**yapf**](https://github.com/google/yapf), 'yet another Python formatter', from Google; [**autopep8**](https://github.com/hhatto/autopep8), which applies PEP8 to your code; [**black**](https://black.readthedocs.io/en/stable/), the 'uncompromising formatter' that is very opinionated (\"any colour, as long as it's black\"); and [**Ruff**](https://docs.astral.sh/ruff/formatter/).\n",
    "\n",
    "There are two ways to use formatters, line-by-line (though **black** doesn't work in this mode) or on an entire script at once. VS Code offers an integration with formatters. To select a formatter in VS Code, bring up the settings using <kbd>⌘</kbd> + <kbd>,</kbd> (Mac) or <kbd>ctrl</kbd> + <kbd>,</kbd> (otherwise) and type 'python formatting provider' and you can choose from autopep8, black, and yapf. \n",
    "\n",
    "If you choose **autopep8** and then open a script you can format a *selection* of code by pressing <kbd>⌘</kbd> + <kbd>k</kbd>, <kbd>⌘</kbd> + <kbd>f</kbd> (Mac) or <kbd>ctrl</kbd> + <kbd>k</kbd>, <kbd>ctrl</kbd> + <kbd>f</kbd> (otherwise). They can also (and only, in the case of **black**) be used from the command line. For instance, to use **black**, the command is `black test.py`, assuming you have it installed.\n",
    "\n",
    "Let's see an example of a poorly styled script and see what happens when we select all lines and use <kbd>ctrl</kbd> + <kbd>k</kbd>, <kbd>ctrl</kbd> + <kbd>f</kbd> to auto format with **autopep8**. The contents of `test.py` before formatting are:\n",
    "\n",
    "```python\n",
    "def very_important_function(y_val,debug = False, keyword_arg=0, another_arg  =2):\n",
    "    X = np.linspace(0,10,5)\n",
    "    return X+  y_val +keyword_arg\n",
    "very_important_function(2)\n",
    "\n",
    "list_defn = [1,\n",
    "2,\n",
    "3,\n",
    "5,\n",
    "6,\n",
    "7]\n",
    "\n",
    "import numpy as np\n",
    "```\n",
    "\n",
    "and, after running the auto-formatting command,\n",
    "\n",
    "```python\n",
    "import numpy as np\n",
    "\n",
    "\n",
    "def very_important_function(y_val, debug=False, keyword_arg=0, another_arg=2):\n",
    "    X = np.linspace(0, 10, 5)\n",
    "    return X + y_val + keyword_arg\n",
    "\n",
    "\n",
    "very_important_function(2)\n",
    "\n",
    "list_defn = [1,\n",
    "             2,\n",
    "             3,\n",
    "             5,\n",
    "             6,\n",
    "             7]\n",
    "```\n",
    "\n",
    "So what did the formatter do? Many things. It moved the import to the top, put two blank lines after the function definition, removed whitespace around keyword arguments, added a new line at the end, and fixed some of the indentation. The different formatters have different strengths and weaknesses; for example, **black** is not so good at putting imports in the right place but excels at splitting up troublesome wide lines. If you need a formatter that deals specifically with module imports, check out [**isort**](https://pycqa.github.io/isort/) or [**Ruff**](https://docs.astral.sh/ruff/).\n",
    "\n",
    "Apart from taking the pressure off you to always be thinking about code style, formatters can be useful when working collaboratively too. For some open source packages, maintainers ask that new code or changed code be run through a particular formatter if it is to be incorporated into the main branch. This helps ensure the code style is consistent regardless of who is writing it. Running the code formatter can even be automated to happen every time someone *commits* some code to a shared code repository too, using something called a *pre-commit hook*.\n",
    "\n",
    "NB: **Black** can run on Jupyter Notebooks too: just install it with `pip install \"black[jupyter]\"` instead of `pip install black`."
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "## Inspecting Variables\n",
    "\n",
    "### **rich** for beautiful inspection\n",
    "\n",
    "[**rich**](https://github.com/willmcgugan/rich) is much more than just a tool for inspecting variables, it's a way to create beautiful renderings of all objects both in the terminal and in interactive Python windows. You can use it to build fantastic looking command line interfaces. Here, we'll see how it can help us find what value a variable takes *and* what methods can be used on a variable via its `inspect()` function."
   ]
  },
  {
   "cell_type": "code",
   "execution_count": null,
   "metadata": {},
   "outputs": [],
   "source": [
    "from rich import inspect\n",
    "\n",
    "my_list = [\"foo\", \"bar\"]\n",
    "inspect(my_list, methods=True)"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "Check out all of the many options for `inspect()` using `help(inspect)`. We ran it here with `methods=True`, but there are plenty of other options.\n",
    "\n",
    "```{admonition} Exercise\n",
    "Create a dictionary (it doesn't matter what's in it, but you could map the integer 1 to the letter \"a\"). Then use `inspect()` with `methods=True` to find out about all the methods you can call on an object of type dict.\n",
    "```"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "## Errors and Exceptions\n",
    "\n",
    "When a programme goes wrong, it throws up an error and halts. You won't be coding for long before you hit one of these errors, which have special names depending on what triggered them.\n",
    "\n",
    "Let's see a real-life error in action:"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "```python\n",
    "denom = 0\n",
    "\n",
    "print(1/denom)\n",
    "```\n",
    "\n",
    "```python\n",
    "---------------------------------------------------------------------------\n",
    "ZeroDivisionError                         Traceback (most recent call last)\n",
    "<ipython-input-39-e45c0e0a3e37> in <module>\n",
    "      1 denom = 0\n",
    "      2 \n",
    "----> 3 print(1/denom)\n",
    "\n",
    "ZeroDivisionError: division by zero\n",
    "```"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "Oh no! We got a `ZeroDivisionError` and our programme crashed. Note that the error includes a 'Traceback' to show which line went wrong, which is helpful for debugging.\n",
    "\n",
    "In practice, there are often times when we know that an error *could* arise, and we would like to specify what should happen when it does (rather than having the programme crash). \n",
    "\n",
    "We can use *exceptions* to do this. These come in a `try` ... `except` pattern, which looks like an `if` ... `else` pattern but applies to errors. If no errors occur inside the `try` block, the `except` block isn’t run but *if* something goes wrong inside the `try` then the `except` block is executed. Let's see an example:"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": null,
   "metadata": {},
   "outputs": [],
   "source": [
    "for denom in [-5, 0, 5]:\n",
    "    try:\n",
    "        result = 1 / denom\n",
    "        print(f\"1/{denom} == {result}\")\n",
    "    except ZeroDivisionError:\n",
    "        print(f\"Cannot divide by {denom}\")"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "Now we can see two differences. First: the code executed just fine *without* halting. Second: when we hit the error, the `except` block was executed and told us what was going on. Note that we could have just used `except` in the above but it's best practice, where you can, to use one of the built-in error keywords that Python comes with.\n",
    "\n",
    "For error messages, it's convenient to use Python's built in messages whenever you can—the more specific, the better. You can see that in the case above we used `ZeroDivisionError`, which is pretty specific.\n",
    "\n",
    "If you do need to use a generic error, use an informative message to help the user understand what's going on:"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": null,
   "metadata": {},
   "outputs": [],
   "source": [
    "for denom in [-5, 0, 5]:\n",
    "    try:\n",
    "        result = 1 / denom\n",
    "        print(f\"1/{denom} == {result}\")\n",
    "    except Exception as error:\n",
    "        print(f\"{denom} has no reciprocal; error is: {error}\")"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "Sadly, division by zero is just one of the many errors you might encounter. What if a function is likely to end up running into several different errors? We can have multiple `except` clauses to catch these:"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": null,
   "metadata": {},
   "outputs": [],
   "source": [
    "numbers = [-5, 0, 5]\n",
    "for i in [0, 1, 2, 3]:\n",
    "    try:\n",
    "        denom = numbers[i]\n",
    "        result = 1 / denom\n",
    "        print(f\"1/{denom} == {result}\")\n",
    "    except IndexError as error:\n",
    "        print(f\"index {i} out of range; error is {error}\")\n",
    "    except ZeroDivisionError as error:\n",
    "        print(f\"{denom} has no reciprocal; error is: {error}\")"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "A full list of built-in errors may be [found here](https://docs.python.org/3/library/exceptions.html#exception-hierarchy) and they are nested in classes (eg `ZeroDivisionError` is a special case of a `ArithmeticError`)."
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "Where do these errors come from anyway? What tells the programming language to throw a tantrum when it encounters certain combinations of values and operations.\n",
    "\n",
    "The answer is that the person or people who wrote the code that's 'under the hood' can specify when such errors should be raised. Remember, the philosophy of Python is that things should fail loudly (so that they do not cause issues downstream). Here's an example of some code that raises its own errors using the `raise` keyword:"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": null,
   "metadata": {},
   "outputs": [],
   "source": [
    "for number in [1, 0, -1]:\n",
    "    try:\n",
    "        if number < 0:\n",
    "            raise ValueError(f\"no negatives: {number}\")\n",
    "        print(number)\n",
    "    except ValueError as error:\n",
    "        print(f\"exception: {error}\")"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "A `ValueError` is a built-in type of error and there are plenty of ones to choose from for your case. Some big or specialised libraries define their own types of error too.\n",
    "\n",
    "One very clever feature of Python's exception handling is \"throw low, catch high\", which means that even if an error gets thrown way deep down in the middle of a code block, the catching exception can be used some way away. Here's an example: the error arises *within* the `sum_reciprocals()` function, but is caught elsewhere."
   ]
  },
  {
   "cell_type": "code",
   "execution_count": null,
   "metadata": {},
   "outputs": [],
   "source": [
    "def sum_reciprocals(values):\n",
    "    result = 0\n",
    "    for v in values:\n",
    "        result += 1 / v\n",
    "    return result\n",
    "\n",
    "\n",
    "numbers = [-1, 0, 1]\n",
    "try:\n",
    "    one_over = sum_reciprocals(numbers)\n",
    "except ArithmeticError as error:\n",
    "    print(f\"Error trying to sum reciprocals: {error}\")"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "Here's an example of combining a `try`, several `except` statements, an `else` that gets executed if `try` is, and a `finally` that always get executed."
   ]
  },
  {
   "cell_type": "code",
   "execution_count": null,
   "metadata": {},
   "outputs": [],
   "source": [
    "import datetime\n",
    "\n",
    "b_year = 1852\n",
    "name_input = \"Ada\"\n",
    "\n",
    "\n",
    "def process_input(name_input, b_year):\n",
    "    try:\n",
    "        name = str(name_input)\n",
    "        year_born = int(b_year)\n",
    "        age = datetime.datetime.now().year - int(year_born)\n",
    "        print(f\"You are {name}. And your age is {age}.\")\n",
    "    except TypeError:\n",
    "        print(\"Type error occur\")\n",
    "    except ValueError:\n",
    "        print(\"Value error occur\")\n",
    "    except ZeroDivisionError:\n",
    "        print(\"zero division error occur\")\n",
    "    else:\n",
    "        print(\"I usually run with the try block\")\n",
    "    finally:\n",
    "        print(\"I always run.\")\n",
    "\n",
    "\n",
    "process_input(name_input, b_year)"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "## Debugging Code\n",
    "\n",
    "Computers are *very* literal, so literal that unless you're perfectly precise about what you want, they will end up doing something different. When that happens, one of the most difficult issues in programming is to understand *why* the code isn't doing what you expected. When the code doesn't do what we expect, it's called a bug.\n",
    "\n",
    "Bugs could be fundamental issues with the code you're using (in fact, the term originated because a moth causing a problem in an early computer) and, if you find one of these, you should file an issue with the maintainers of the code. However, what's much more likely is that the instructions you gave aren't quite what is needed to produce the outcome that you want. And, in this case, you might need to *debug* the code: to find out which part of it isn't doing what you expect.\n",
    "\n",
    "Even with a small code base, it can be tricky to track down where the bug is: but don't fear, there are tools on hand to help you find where the bug is.\n",
    "\n",
    "### Print statements\n",
    "\n",
    "The simplest, and I'm afraid to say the most common, way to debug code is to plonk `print` statements in the code. Let's take a common example in which we perform some simple array operations, here multiplying an array and then summing it with another array:"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "```python\n",
    "import numpy as np\n",
    "\n",
    "\n",
    "def array_operations(in_arr_one, in_arr_two):\n",
    "    out_arr = in_arr_one*1.5\n",
    "    out_arr = out_arr + in_arr_two\n",
    "    return out_arr\n",
    "\n",
    "\n",
    "in_vals_one = np.array([3, 2, 5, 16, '7', 8, 9, 22])\n",
    "in_vals_two = np.array([4, 7, 3, 23, 6, 8, 0])\n",
    "\n",
    "result = array_operations(in_vals_one, in_vals_two)\n",
    "result\n",
    "```\n",
    "\n",
    "```python\n",
    "---------------------------------------------------------------------------\n",
    "UFuncTypeError                            Traceback (most recent call last)\n",
    "<ipython-input-1-166160824d19> in <module>\n",
    "     11 in_vals_two = np.array([4, 7, 3, 23, 6, 8, 0])\n",
    "     12 \n",
    "---> 13 result = array_operations(in_vals_one, in_vals_two)\n",
    "     14 result\n",
    "\n",
    "<ipython-input-1-166160824d19> in array_operations(in_arr_one, in_arr_two)\n",
    "      3 \n",
    "      4 def array_operations(in_arr_one, in_arr_two):\n",
    "----> 5     out_arr = in_arr_one*1.5\n",
    "      6     out_arr = out_arr + in_arr_two\n",
    "      7     return out_arr\n",
    "\n",
    "UFuncTypeError: ufunc 'multiply' did not contain a loop with signature matching types (dtype('<U32'), dtype('<U32')) -> dtype('<U32')\n",
    "```"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "Oh no! We've got a `UFuncTypeError` here, perhaps not the most illuminating error message we've ever seen. We'd like to know what's going wrong here. The `Traceback` did give us a hint about where the issue occurred though; it happens in the multiplication line of the function we wrote.\n",
    "\n",
    "To debug the error with print statements, we might re-run the code like this:"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "```python\n",
    "def array_operations(in_arr_one, in_arr_two):\n",
    "    print(f'in_arr_one is {in_arr_one}')\n",
    "    out_arr = in_arr_one*1.5\n",
    "    out_arr = out_arr + in_arr_two\n",
    "    return out_arr\n",
    "\n",
    "\n",
    "in_vals_one = np.array([3, 2, 5, 16, '7', 8, 9, 22])\n",
    "in_vals_two = np.array([4, 7, 3, 23, 6, 8, 0])\n",
    "\n",
    "result = array_operations(in_vals_one, in_vals_two)\n",
    "result\n",
    "```\n",
    "\n",
    "```\n",
    "in_arr_one is ['3' '2' '5' '16' '7' '8' '9' '22']\n",
    "```\n",
    "\n",
    "```python\n",
    "---------------------------------------------------------------------------\n",
    "UFuncTypeError                            Traceback (most recent call last)\n",
    "<ipython-input-2-6a04719bc0ff> in <module>\n",
    "      9 in_vals_two = np.array([4, 7, 3, 23, 6, 8, 0])\n",
    "     10 \n",
    "---> 11 result = array_operations(in_vals_one, in_vals_two)\n",
    "     12 result\n",
    "\n",
    "<ipython-input-2-6a04719bc0ff> in array_operations(in_arr_one, in_arr_two)\n",
    "      1 def array_operations(in_arr_one, in_arr_two):\n",
    "      2     print(f'in_arr_one is {in_arr_one}')\n",
    "----> 3     out_arr = in_arr_one*1.5\n",
    "      4     out_arr = out_arr + in_arr_two\n",
    "      5     return out_arr\n",
    "\n",
    "UFuncTypeError: ufunc 'multiply' did not contain a loop with signature matching types (dtype('<U32'), dtype('<U32')) -> dtype('<U32')\n",
    "```"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "What can we tell from the values of `in_arr_one` that are now being printed? Well, they seem to have quote marks around them and what that means is that they're strings, *not* floating point numbers or integers! Multiplying a string by 1.5 doesn't make sense here, so that's our error. If we did this, we might then trace the origin of that array back to find out where it was defined and see that instead of `np.array([3, 2, 5, 16, 7, 8, 9, 22])` being declared, we have `np.array([3, 2, 5, 16, '7', 8, 9, 22])` instead and `numpy` decides to cast the whole array as a string to ensure consistency.\n",
    "\n",
    "Let's fix that problem by turning `'7'` into `7` and run it again:"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "```python\n",
    "def array_operations(in_arr_one, in_arr_two):\n",
    "    out_arr = in_arr_one*1.5\n",
    "    out_arr = out_arr + in_arr_two\n",
    "    return out_arr\n",
    "\n",
    "\n",
    "in_vals_one = np.array([3, 2, 5, 16, 7, 8, 9, 22])\n",
    "in_vals_two = np.array([4, 7, 3, 23, 6, 8, 0])\n",
    "\n",
    "result = array_operations(in_vals_one, in_vals_two)\n",
    "result\n",
    "```\n",
    "\n",
    "```python\n",
    "---------------------------------------------------------------------------\n",
    "ValueError                                Traceback (most recent call last)\n",
    "<ipython-input-3-ebd3efde9b3e> in <module>\n",
    "      8 in_vals_two = np.array([4, 7, 3, 23, 6, 8, 0])\n",
    "      9 \n",
    "---> 10 result = array_operations(in_vals_one, in_vals_two)\n",
    "     11 result\n",
    "\n",
    "<ipython-input-3-ebd3efde9b3e> in array_operations(in_arr_one, in_arr_two)\n",
    "      1 def array_operations(in_arr_one, in_arr_two):\n",
    "      2     out_arr = in_arr_one*1.5\n",
    "----> 3     out_arr = out_arr + in_arr_two\n",
    "      4     return out_arr\n",
    "      5 \n",
    "\n",
    "ValueError: operands could not be broadcast together with shapes (8,) (7,) \n",
    "```"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "Still not working! But we've moved on to a different error now. We can still use a print statement to debug this one, which seems to be related to the shapes of variables passed into the function:"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "```python\n",
    "def array_operations(in_arr_one, in_arr_two):\n",
    "    print(f'in_arr_one shape is {in_arr_one.shape}')\n",
    "    out_arr = in_arr_one*1.5\n",
    "    print(f'intermediate out_arr shape is {out_arr.shape}')\n",
    "    print(f'in_arr_two shape is {in_arr_two.shape}')\n",
    "    out_arr = out_arr + in_arr_two\n",
    "    return out_arr\n",
    "\n",
    "\n",
    "in_vals_one = np.array([3, 2, 5, 16, 7, 8, 9, 22])\n",
    "in_vals_two = np.array([4, 7, 3, 23, 6, 8, 0])\n",
    "\n",
    "result = array_operations(in_vals_one, in_vals_two)\n",
    "result\n",
    "```\n",
    "\n",
    "```\n",
    "in_arr_one shape is (8,)\n",
    "intermediate out_arr shape is (8,)\n",
    "in_arr_two shape is (7,)\n",
    "```\n",
    "\n",
    "```python\n",
    "---------------------------------------------------------------------------\n",
    "ValueError                                Traceback (most recent call last)\n",
    "<ipython-input-4-4961f476c7eb> in <module>\n",
    "     11 in_vals_two = np.array([4, 7, 3, 23, 6, 8, 0])\n",
    "     12 \n",
    "---> 13 result = array_operations(in_vals_one, in_vals_two)\n",
    "     14 result\n",
    "\n",
    "<ipython-input-4-4961f476c7eb> in array_operations(in_arr_one, in_arr_two)\n",
    "      4     print(f'intermediate out_arr shape is {out_arr.shape}')\n",
    "      5     print(f'in_arr_two shape is {in_arr_two.shape}')\n",
    "----> 6     out_arr = out_arr + in_arr_two\n",
    "      7     return out_arr\n",
    "      8 \n",
    "\n",
    "ValueError: operands could not be broadcast together with shapes (8,) (7,) \n",
    "```"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "The print statement now tells us the shapes of the arrays as we go through the function. We can see that in the line before the `return` statement the two arrays that are being combined using the `+` operator don't have the same shape, so we're effectively adding two vectors from two differently dimensioned vector spaces and, understandably, we are being called out on our nonsense. To fix this problem, we would have to ensure that the input arrays are the same shape (it looks like we may have just missed a value from `in_vals_two`).\n",
    "\n",
    "`print` statements are great for a quick bit of debugging and you are likely to want to use them more frequently than any other debugging tool. However, for complex, nested code debugging, they aren't always very efficient and you will sometimes feel like you are playing battleships in continually refining where they should go until you have pinpointed the actual problem, so they're far from perfect. Fortunately, there are other tools in the debugging toolbox...\n"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "### Debugging with the IDE\n",
    "\n",
    "In this section, we'll learn about how your Integrated Development Environment, or IDE, can aid you with debugging. While we'll talk through the use of Visual Studio Code, which is free, directly supports Python, R, and other languages, and is especially rich, many of the features will be present in other IDEs too and the ideas are somewhat general. \n",
    "\n",
    "To begin debugging using Visual Studio Code, get a script ready, for example `script.py`, that you'd like to debug. If your script has an error in, a debug run will automatically run into it and stop on the error; alternatively you can click to the left of the line number in your script to create a *breakpoint* that your code will stop at anyway when in debug mode.\n",
    "\n",
    "To begin a debug session, click on the play button partially covered by a bug that's on the left hand ribbon of the VS Code window. It will bring up a menu. Click 'Run and debug' and select 'Python file'. The debugger will now start running the script you had open. When it reaches and error or a breakpoint it will stop. \n",
    "\n",
    "Why is this useful? Once the code stops, you can hover over any variables and see what's 'inside' them, which is useful for working out what's going on. Remember, in the examples above, we only saw variables that we asked for. Using the debugger, we can hover over any variable we're interested in without having to decide ahead of time! We can also see other useful bits of info such as the *call stack* of functions that have been called, what local (within the current scope) and global (available everywhere) variables have been defined, and we can nominate variables to watch too.\n",
    "\n",
    "Perhaps you now want to progress the code on from a breakpoint; you can do this too. You'll see that a menu has appeared with stop, restart, play, and other buttons on it. To skip over the next line of code, use the curved arrow over the dot. To dig in to the next line of code, for example if it's a function, use the arrow pointing toward a dot. To carry on running the code, use the play button.\n",
    "\n",
    "This is only really scratching the surface of what you can do with IDE based debugging, but even that surface layer provides lots of really useful tools for finding out what's going on when your code executes.\n",
    "\n",
    "You can find a short 'hello world!' debugging tutorial in the [official VS Code documentation](https://code.visualstudio.com/docs/python/python-tutorial#_configure-and-run-the-debugger)."
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "### Logging\n",
    "\n",
    "Logging is a means of tracking events that happen when software runs. It's really the best way to debug code. An event is described by a descriptive message that can optionally contain data about variables that are defined as the code is executing.\n",
    "\n",
    "Logging has two main purposes: to record events of interest, such as an error, and to act as an auditable account of what happened after the fact.\n",
    "\n",
    "Although Python has a built-in logger, we will see an example of logging using [**loguru**](https://github.com/Delgan/loguru), a package that makes logging a little easier and has some nice settings.\n",
    "\n",
    "Let's see how to log a debug message:"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": null,
   "metadata": {},
   "outputs": [],
   "source": [
    "from loguru import logger\n",
    "\n",
    "logger.debug(\"Simple logging!\")"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "The default message includes the time, the type of log entry message it is, what bit of code it happened in (including a line number), and the message itself (basically all the info we need). There are different levels of code messages. They are:\n",
    "\n",
    "- CRITICAL\n",
    "- ERROR\n",
    "- WARNING\n",
    "- SUCCESS\n",
    "- INFO\n",
    "- DEBUG\n",
    "- TRACE\n",
    "\n",
    "You can find advice on what level to use for what message [here](https://reflectoring.io/logging-levels/), but it will depend a bit on what you're using your logs for.\n",
    "\n",
    "What we've just seen are logging messages written out to the console, which doesn't persist. This is clearly no good for auditing what happened long after the fact (and it may not be that good for debugging either) so we also need a way to write a log to a file. This snippet of code\n",
    "\n",
    "```python\n",
    "logger.add(\"file_{time}.log\")\n",
    "```\n",
    "\n",
    "tells **loguru** to send your logging messages to a *log file* instead of to the console. This is really handy for auditing what happened when your code executed long after it ran. You can choose any name for your log file, using \"{time}\" as part of the string is a shorthand that tells **loguru** to use the current datetime to name the file.\n",
    "\n",
    "Log files can become quite numerous and quite large, which you might not want. Those logs from 6 months ago may just be taking up space and not be all that useful, for example. So, what you can also do, is tell **loguru** to use a new log file. Some examples of this would be `logger.add(\"file_1.log\", rotation=\"500 MB\")` to clean up a file after it reaches 500 MB in size, `rotation=\"12:00\"` to refresh the log file at lunch time, and `retention=\"10 days\"` to keep the file for 10 days.\n",
    "\n",
    "One further feature that is worth being aware of is the capability to trace what caused errors, including the trace back through functions and modules, and report them in the log. Of course, you can debug these using the console, but sometimes having such complex errors written to a file (in full) can be handy. This example of a full traceback comes from the **loguru** documentation. The script would have:\n",
    "\n",
    "```python\n",
    "logger.add(\"out.log\", backtrace=True, diagnose=True)  # Caution, may leak sensitive data if used in production\n",
    "\n",
    "def func(a, b):\n",
    "    return a / b\n",
    "\n",
    "def nested(c):\n",
    "    try:\n",
    "        func(5, c)\n",
    "    except ZeroDivisionError:\n",
    "        logger.exception(\"What?!\")\n",
    "\n",
    "nested(0)\n",
    "```\n",
    "\n",
    "while the log file would record:\n",
    "\n",
    "```\n",
    "2018-07-17 01:38:43.975 | ERROR    | __main__:nested:10 - What?!\n",
    "Traceback (most recent call last):\n",
    "\n",
    "  File \"test.py\", line 12, in <module>\n",
    "    nested(0)\n",
    "    └ <function nested at 0x7f5c755322f0>\n",
    "\n",
    "> File \"test.py\", line 8, in nested\n",
    "    func(5, c)\n",
    "    │       └ 0\n",
    "    └ <function func at 0x7f5c79fc2e18>\n",
    "\n",
    "  File \"test.py\", line 4, in func\n",
    "    return a / b\n",
    "           │   └ 0\n",
    "           └ 5\n",
    "\n",
    "ZeroDivisionError: division by zero\n",
    "```"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "## Tests\n",
    "\n",
    "```{note}\n",
    "While this is a slightly more advanced topic, the quality and robustness improvements you will get from writing tests mean it's still really useful to use the tricks from it.\n",
    "```\n",
    "\n",
    "Tests check that your code is behaving as you expect, even as parts of it change or are updated. They most commonly compare an expected input and output with what actually comes out of your code for a given input.\n",
    "\n",
    "Writing tests for code is often an after thought for research code, if it's a thought at all. That's understandable. But it can really boost reliability and robustness. This excerpt from [Research Software Engineering with Python](https://merely-useful.github.io/py-rse/testing.html) explains why testing even research code is extremely useful:\n",
    "\n",
    "> Why is testing research software important? A successful early career researcher in protein crystallography, Geoffrey Chang, had to retract five published papers—three from the journal Science—because his code had inadvertently flipped two columns of data (Miller 2006). More recently, a simple calculation mistake in a paper by Reinhart and Rogoff contributed to making the financial crash of 2008 even worse for millions of people (Borwein and Bailey 2013). Testing helps to catch errors like these.\n",
    "\n",
    "The Reinhart and Rogoff paper used Excel for its analysis; while Excel has some pros and does some good in the world, my strong recommendation is that it should *not* be used for any important analysis.\n",
    "\n",
    "Back to testing: if you're writing a *package* of code for others to use, one that will change and grow over time, tests are essential. These are some general guidelines for good testing, such as:\n",
    "\n",
    "- A testing 'unit' should focus on a single bit of functionality;\n",
    "- Each test unit must be fully independent (in practice, this means that `setUp()` and `tearDown()` methods need to be defined to prep data or objects to the point where they can be used by the testing unit);\n",
    "- Tests should run fast if possible;\n",
    "- If you know how, it's a good idea to use something like a 'Git hook' that runs tests before code is saved in a shared repository;\n",
    "- If you find a bug in your code, it's good practice to write a new test that targets it; and\n",
    "- Although long, extremely descriptive names are not very helpful in regular code, they *should* be used for functions that test code because this is the name you will see when the test fails (and you want to know what it refers to).\n",
    "\n",
    "The most common way to run tests is to add assertions to code. An assertion is a statement that something must be true at a certain point in a program. When an assertion evaluates to true, nothing happens; if it’s false, the programme stops and prints a user-defined error message. Here's an example of an assertion:"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": null,
   "metadata": {},
   "outputs": [],
   "source": [
    "positive_num = 5\n",
    "\n",
    "assert positive_num > 0"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "If we had run \n",
    "\n",
    "```python\n",
    "positive_num = 5\n",
    "\n",
    "assert positive_num < 0\n",
    "```\n",
    "\n",
    "it would have resulted in\n",
    "\n",
    "```python\n",
    "---------------------------------------------------------------------------\n",
    "AssertionError                            Traceback (most recent call last)\n",
    "<ipython-input-55-db0e55fa5cb7> in <module>\n",
    "      1 positive_num = 5\n",
    "      2 \n",
    "----> 3 assert positive_num < 0\n",
    "\n",
    "AssertionError:\n",
    "``` \n",
    "\n",
    "Putting assertions into code here and there is one way to check that everything is working as you anticipate, but you won't find out about it until you actually run the code! A testing framework allows you to separate checking the code behaves as you'd expect from running the code, so that you can ensure everything works before putting that big run on.\n",
    "\n",
    "To run lots of tests, we can use a test framework (also called a test runner). A commonly used test framework is [**pytest**](https://docs.pytest.org/en/latest/). Essentially it will run anything that you've flagged as a test in your code and report back to you on whether it passed or not. Here's how it works: tests are put in files whose names begin with `test_`, each test is a function whose name also begins with `test_`, and these functions use `assert` statements to check results.\n",
    "\n",
    "Normally, your functions would be in a different script but here's an example of a code function and a testing function (that tests it) that you might put in a file called `test.py`."
   ]
  },
  {
   "cell_type": "code",
   "execution_count": null,
   "metadata": {},
   "outputs": [],
   "source": [
    "# content of test.py\n",
    "def inc(x):\n",
    "    return x + 1\n",
    "\n",
    "\n",
    "def test_answer():\n",
    "    assert inc(3) == 5"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "To run this, we would enter\n",
    "\n",
    "```bash\n",
    "pytest\n",
    "```\n",
    "\n",
    "on the command line. This would yield\n",
    "\n",
    "```bash\n",
    "=========================== test session starts ============================\n",
    "platform linux -- Python 3.x.y, pytest-6.x.y, py-1.x.y, pluggy-0.x.y\n",
    "cachedir: $PYTHON_PREFIX/.pytest_cache\n",
    "rootdir: $REGENDOC_TMPDIR\n",
    "collected 1 item\n",
    "\n",
    "test.py F                                                     [100%]\n",
    "\n",
    "================================= FAILURES =================================\n",
    "_______________________________ test_answer ________________________________\n",
    "\n",
    "    def test_answer():\n",
    ">       assert inc(3) == 5\n",
    "E       assert 4 == 5\n",
    "E        +  where 4 = inc(3)\n",
    "\n",
    "test_sample.py:6: AssertionError\n",
    "========================= short test summary info ==========================\n",
    "FAILED test.py::test_answer - assert 4 == 5\n",
    "============================ 1 failed in 0.12s =============================\n",
    "```\n",
    "\n",
    "As you add more tests, they will be automatically picked up and run by `pytest`.\n",
    "\n",
    "When writing tests, think about whether you have tested realistic combinations of input parameters, tested all discrete outputs at least once, tested the boundaries of continuous outputs, and ensured that informative errors are raised when things go wrong.\n",
    "\n",
    "If you're using Visual Studio Code, support for **pytest** comes built-in."
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "### Testing continuous variables\n",
    "\n",
    "Imagine we are not testing for an integer, such as 4, but instead for a real number, such as 4.32838. Computers are nothing if not punishingly literal, however, so if evaluation of the code produces 4.32837 instead of 4.32838 the `assert` statement will fail and the test won't pass even if the two numbers are close enough for our purposes. It's even worse than that because computers *cannot* accurately represent real numbers to arbitrary levels of precision. \n",
    "\n",
    "To avoid tests that fail even though nothing's really wrong, most testing packages come with tools for real numbers. Here's an example where we have a parameter alpha that we'd like to test against an expected value of 1 but with a tolerance of 0.01."
   ]
  },
  {
   "cell_type": "code",
   "execution_count": null,
   "metadata": {},
   "outputs": [],
   "source": [
    "import pytest\n",
    "\n",
    "\n",
    "def complicated_func():\n",
    "    \"\"\"A really complicated func\"\"\"\n",
    "    return 0.998\n",
    "\n",
    "\n",
    "alpha = complicated_func()\n",
    "expected_alpha = pytest.approx(1.0, abs=0.01)\n",
    "assert alpha == expected_alpha\n",
    "print(expected_alpha)"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "### Test coverage\n",
    "\n",
    "A production-ready code should be heavily tested. Coverage tests ask how much of your code is actually covered by tests and where the code is that isn't tested. One package to do this is called [**coverage**](https://coverage.readthedocs.io/en/coverage-5.5/). If you already have code tests written, you can run:\n",
    "\n",
    "```bash\n",
    "coverage run -m pytest\n",
    "```\n",
    "\n",
    "on the command line instead of just running `pytest`. To get a report on the success use\n",
    "\n",
    "```bash\n",
    "$ coverage report -m\n",
    "Name                      Stmts   Miss  Cover   Missing\n",
    "-------------------------------------------------------\n",
    "my_program.py                20      4    80%   33-35, 39\n",
    "my_other_module.py           56      6    89%   17-23\n",
    "-------------------------------------------------------\n",
    "TOTAL                        76     10    87%\n",
    "```\n",
    "\n",
    "If you would prefer a html report over one in the terminal, use `$ coverage html` to create a report at `htmlcov/index.html`."
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "## Timing and profiling\n",
    "\n",
    "```{note}\n",
    "This is a more advanced topic.\n",
    "```\n",
    "\n",
    "Timing and profiling your code are useful to understand where bottlenecks might be. One of the principles of programming is don't optimise too soon, so, if you are reaching for timing and profiling, you've probably already hit that bottleneck.\n",
    "\n",
    "```{note}\n",
    "This section just deals with diagnosing slow code: how to speed code up will be covered elsewhere.\n",
    "```\n",
    "\n",
    "There are different levels of sophistication for timing and profiling. The simplest way to time is to use the built-in library."
   ]
  },
  {
   "cell_type": "code",
   "execution_count": null,
   "metadata": {},
   "outputs": [],
   "source": [
    "import time\n",
    "import timeit\n",
    "\n",
    "\n",
    "def f(nsec=1.0):\n",
    "    \"\"\"Function sleeps for nsec seconds.\"\"\"\n",
    "    time.sleep(nsec)\n",
    "\n",
    "\n",
    "start = timeit.default_timer()\n",
    "f()\n",
    "elapsed = timeit.default_timer() - start\n",
    "elapsed"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "If you're working jupyter notebooks (which is what this book is written in), you can use the `timeit` magic, a convenient shortcut for timing a line or chunk of code (more on magics, and timeit, [here](https://ipython.readthedocs.io/en/stable/interactive/magics.html#magic-time)):"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": null,
   "metadata": {},
   "outputs": [],
   "source": [
    "%timeit f(0.01)"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "timeit will adjust the number of repeats according to how slow the code is to run. Several other magics are available:\n",
    "\n",
    "- `%time`: Time the execution of a single statement\n",
    "- `%timeit`: Time repeated execution of a single statement for more accuracy\n",
    "- `%prun`: Run code with the profiler\n",
    "- `%lprun`: Run code with the line-by-line profiler\n",
    "- `%memit`: Measure the memory use of a single statement\n",
    "- `%mprun`: Run code with the line-by-line memory profiler\n",
    "\n",
    "Another way to time functions is via decorators:"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": null,
   "metadata": {},
   "outputs": [],
   "source": [
    "def process_time(f, *args, **kwargs):\n",
    "    def func(*args, **kwargs):\n",
    "        import timeit\n",
    "\n",
    "        start = timeit.default_timer()\n",
    "        f(*args, **kwargs)\n",
    "        print(timeit.default_timer() - start)\n",
    "\n",
    "    return func\n",
    "\n",
    "\n",
    "@process_time\n",
    "def f1(nsec=1.0):\n",
    "    \"\"\"Function sleeps for nsec seconds.\"\"\"\n",
    "    time.sleep(nsec)\n",
    "\n",
    "\n",
    "f1()"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "Timing is very simple and just tells you the total time of what's inbetween the start and end points. Often, you would want a bit more detail about what's being slow, or you may wish to profile an entire script. For that, there's `cProfile`, which is a built-in package. You can use it on the command line or within scripts, like this:"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": null,
   "metadata": {},
   "outputs": [],
   "source": [
    "import cProfile\n",
    "\n",
    "\n",
    "def foo():\n",
    "    time.sleep(1.0)\n",
    "    time.sleep(2.5)\n",
    "\n",
    "\n",
    "cProfile.run(\"foo()\")"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "What do we get here? The `percall` columns are `tottime` and `cumtime` (respectively) divided by `ncalls`. `tottime` is the time spent in the function excluding any sub-functions, while `cumtime` is the cumulative time spent.\n",
    "\n",
    "There are various profilers out there that extend the basics provided by **cProfile**. Let's look at a few others to get a sense of what extra they offer.\n",
    "\n",
    "[**pyinstrument**](https://github.com/joerick/pyinstrument) attempts to improve on the standard profilers by recording the 'entire stack' of methods so that identifying expensive sub-calls to methods is easier. There are two ways to run it: on the command line, using `pyinstrument script.py` instead of `python script.py`, or by wedging the code you're interested in *within* a script between a `.start()` and `.stop()` method like this:"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": null,
   "metadata": {},
   "outputs": [],
   "source": [
    "from pyinstrument import Profiler\n",
    "\n",
    "profiler = Profiler()\n",
    "profiler.start()\n",
    "\n",
    "\n",
    "def fibonacci(n):\n",
    "    if n < 0:\n",
    "        raise Exception(\"n must be a positive integer\")\n",
    "    elif n == 1:\n",
    "        return 0\n",
    "    elif n == 2:\n",
    "        return 1\n",
    "    else:\n",
    "        return fibonacci(n - 1) + fibonacci(n - 2)\n",
    "\n",
    "\n",
    "fibonacci(20)\n",
    "\n",
    "profiler.stop()\n",
    "\n",
    "# Print the results of the profiling to screen\n",
    "print(profiler.output_text(unicode=True, color=True))"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "Because our function, `fibonacci`, is nested, the function call breakdown that **pyinstrument** produces is likewise nested so that you can see how the code calls progresses.\n",
    "\n",
    "The output analysis can be written to an interactive HTML file too: just use `profiler.output_html()`"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "Time to execute code is not the only thing we care about. In fact, for economics applications, it's much more likely to be a memory bottleneck than a speed one. Operations that involve lots of data, large matrices, or both, might be memory hogs. If you hit the memory (RAM) limit on your machine, it will slow right down and the process that's running might just crash completely. So wouldn't it be great it we had a way to profile both code and memory!? Well, we do.\n",
    "\n",
    "[**scalene**](https://github.com/plasma-umass/scalene) is a command-line utility for profiling code execution time *and* memory. It profiles whole scripts, run `scalene script.py` on the command line, and produces HTML reports. Here's an example of some output:\n",
    "\n",
    "![Screenshot from scalene running on a problem](https://raw.githubusercontent.com/plasma-umass/scalene/master/docs/images/sample-profile-pystone.png)\n",
    "\n",
    "What's particularly useful is having the part of the code where the bottleneck is displayed on the right. Memory usage over time tells you where the memory-hogging lines are, while the two CPU % columns tell you how much of the total time (shown at the top) was spent in Python code and in non-Python ('native') code, which Python often calls under the hood."
   ]
  }
 ],
 "metadata": {
  "celltoolbar": "Tags",
  "kernelspec": {
   "display_name": "Python 3.10.12 ('codeforecon')",
   "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.10.13"
  },
  "vscode": {
   "interpreter": {
    "hash": "c4570b151692b3082981c89d172815ada9960dee4eb0bedb37dc10c95601d3bd"
   }
  }
 },
 "nbformat": 4,
 "nbformat_minor": 4
}