README.ipynb

{
 "cells": [
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "# Contents\n",
    "\n",
    "[Overview](#Overview)\n",
    "\n",
    "[Tracing code](#Tracing-code)\n",
    "  * [Syntax](#Syntax)\n",
    "  * [Tracing tips](#Tracing-tips)\n",
    "  * [Implementation](#Implementation-of-@trace)\n",
    "\n",
    "[Manipulating traces](#Manipulating-traces)\n",
    "  * [Custom text/HTML](#Custom-text/HTML)\n",
    "  * [Map, filter, collect](#Map,-filter,-collect)\n",
    "\n",
    "[Saving traces to disk](#Saving-traces-to-disk)\n",
    "\n",
    "[Working with mutable state](#Working-with-mutable-state)\n",
    "\n",
    "[Debugging with traces](#Debugging-with-traces)\n",
    "  * [Debugging test failures](#Debugging-test-failures)\n",
    "  * [Displaying extra information](#Displaying-extra-information)\n",
    "\n",
    "[Profiling](#Profiling)\n",
    "  * [Type stability](#Type-stability)\n",
    "  * [Grouping and benchmarking](#Grouping-and-benchmarking)\n",
    "  * [Profiling the compiler](#Profiling-the-compiler)"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "# Overview\n",
    "\n",
    "[TraceCalls.jl](https://github.com/cstjean/TraceCalls.jl) is a functional tracing package for debugging and exploring Julia code. It records and displays a tree of function calls. For example, here is how [Calculus.jl](https://github.com/johnmyleswhite/Calculus.jl) computes the second-derivative of `sin(x) + sqrt(x)`:"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 1,
   "metadata": {
    "scrolled": false
   },
   "outputs": [
    {
     "data": {
      "text/html": [
       "<pre style=\"display: inline; \"><a href=\"https://github.com/cstjean/TraceCalls.jl/tree/dc190779a2e0b30e00c775a9448d48491402a901//src/TraceCalls.jl#L359\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">#1</a>() => <b><font color=green>-1.0914708926553454</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline; \"><a href=\"https://github.com/johnmyleswhite/Calculus.jl/tree/f7b5556a9ebd0cdde45f15d1b2cde331fe5efdd4//src/derivative.jl#L71\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">Calculus.second_derivative</a>(f, 1.0) => <b><font color=green>-1.0914708926553454</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline; \"><a href=\"https://github.com/johnmyleswhite/Calculus.jl/tree/f7b5556a9ebd0cdde45f15d1b2cde331fe5efdd4//src/derivative.jl#L11\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">Calculus.derivative</a>(f, :central) => <b><font color=green>Calculus.#20</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline; \"><a href=\"https://github.com/johnmyleswhite/Calculus.jl/tree/f7b5556a9ebd0cdde45f15d1b2cde331fe5efdd4//src/derivative.jl#L2\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">Calculus.derivative</a>(f, :scalar, :central) => <b><font color=green>Calculus.#20</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li></ul></li><li><pre style=\"display: inline; \"><a href=\"https://github.com/johnmyleswhite/Calculus.jl/tree/f7b5556a9ebd0cdde45f15d1b2cde331fe5efdd4//src/finite_difference.jl#L224\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">Calculus.finite_difference_hessian</a>(f, Calculus.#20, 1.0, :central) => <b><font color=green>-1.0914708926553454</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline; \"><a href=\"https://github.com/johnmyleswhite/Calculus.jl/tree/f7b5556a9ebd0cdde45f15d1b2cde331fe5efdd4//src/finite_difference.jl#L48\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">Calculus.finite_difference</a>(Calculus.#20, 1.0, :central) => <b><font color=green>-1.0914708926553454</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline; \"><a href=\"https://github.com/johnmyleswhite/Calculus.jl/tree/f7b5556a9ebd0cdde45f15d1b2cde331fe5efdd4//src/finite_difference.jl#L48\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">Calculus.finite_difference</a>(f, 1.0000060554544523, :central) => <b><font color=green>1.0402956965076036</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline; \">f(1.0000121109455733) => <b><font color=green>1.8414835837724568</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li><li><pre style=\"display: inline; \">f(0.9999999999633314) => <b><font color=green>1.8414709847697501</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li></ul></li><li><pre style=\"display: inline; \"><a href=\"https://github.com/johnmyleswhite/Calculus.jl/tree/f7b5556a9ebd0cdde45f15d1b2cde331fe5efdd4//src/finite_difference.jl#L48\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">Calculus.finite_difference</a>(f, 0.9999939445455476, :central) => <b><font color=green>1.0403089152121567</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline; \">f(1.0) => <b><font color=green>1.8414709848078965</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li><li><pre style=\"display: inline; \">f(0.9999878890910952) => <b><font color=green>1.8414583857213915</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li></ul></li></ul></li></ul></li></ul></li></ul>"
      ],
      "text/plain": [
       "- #1() => \u001b[1m\u001b[32m-1.0914708926553454\u001b[39m\u001b[22m\n",
       "   - Calculus.second_derivative(f, 1.0) => \u001b[1m\u001b[32m-1.0914708926553454\u001b[39m\u001b[22m\n",
       "      - Calculus.derivative(f, :central) => \u001b[1m\u001b[32mCalculus.#20\u001b[39m\u001b[22m\n",
       "         - Calculus.derivative(f, :scalar, :central) => \u001b[1m\u001b[32mCalculus.#20\u001b[39m\u001b[22m\n",
       "      - Calculus.finite_difference_hessian(f, Calculus.#20, 1.0, :central) => \u001b[1m\u001b[32m-1.0914708926553454\u001b[39m\u001b[22m\n",
       "         - Calculus.finite_difference(Calculus.#20, 1.0, :central) => \u001b[1m\u001b[32m-1.0914708926553454\u001b[39m\u001b[22m\n",
       "            - Calculus.finite_difference(f, 1.0000060554544523, :central) => \u001b[1m\u001b[32m1.0402956965076036\u001b[39m\u001b[22m\n",
       "               - f(1.0000121109455733) => \u001b[1m\u001b[32m1.8414835837724568\u001b[39m\u001b[22m\n",
       "               - f(0.9999999999633314) => \u001b[1m\u001b[32m1.8414709847697501\u001b[39m\u001b[22m\n",
       "            - Calculus.finite_difference(f, 0.9999939445455476, :central) => \u001b[1m\u001b[32m1.0403089152121567\u001b[39m\u001b[22m\n",
       "               - f(1.0) => \u001b[1m\u001b[32m1.8414709848078965\u001b[39m\u001b[22m\n",
       "               - f(0.9999878890910952) => \u001b[1m\u001b[32m1.8414583857213915\u001b[39m\u001b[22m\n"
      ]
     },
     "execution_count": 1,
     "metadata": {},
     "output_type": "execute_result"
    }
   ],
   "source": [
    "using Calculus, TraceCalls\n",
    "\n",
    "@traceable f(x) = sin(x) + sqrt(x)\n",
    "trace_derivative = @trace Calculus second_derivative(f, 1.0)"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "The output of `@trace` is a `Trace` object --- an explorable tree-like datastructure:"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 2,
   "metadata": {},
   "outputs": [
    {
     "data": {
      "text/html": [
       "<pre style=\"display: inline; \"><a href=\"https://github.com/johnmyleswhite/Calculus.jl/tree/f7b5556a9ebd0cdde45f15d1b2cde331fe5efdd4//src/derivative.jl#L11\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">Calculus.derivative</a>(f, :central) => <b><font color=green>Calculus.#20</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline; \"><a href=\"https://github.com/johnmyleswhite/Calculus.jl/tree/f7b5556a9ebd0cdde45f15d1b2cde331fe5efdd4//src/derivative.jl#L2\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">Calculus.derivative</a>(f, :scalar, :central) => <b><font color=green>Calculus.#20</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li></ul>"
      ],
      "text/plain": [
       "- Calculus.derivative(f, :central) => \u001b[1m\u001b[32mCalculus.#20\u001b[39m\u001b[22m\n",
       "   - Calculus.derivative(f, :scalar, :central) => \u001b[1m\u001b[32mCalculus.#20\u001b[39m\u001b[22m\n"
      ]
     },
     "execution_count": 2,
     "metadata": {},
     "output_type": "execute_result"
    }
   ],
   "source": [
    "trace_derivative[1][1]          # get the first call of the first call."
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 3,
   "metadata": {},
   "outputs": [
    {
     "data": {
      "text/plain": [
       ":central"
      ]
     },
     "execution_count": 3,
     "metadata": {},
     "output_type": "execute_result"
    }
   ],
   "source": [
    "trace_derivative[1][1].args[2]  # get its second argument"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "It can work as a [more-informative stack-trace](#Debugging-with-traces) (which contains _values_ rather than just types - see `@stacktrace`):"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 4,
   "metadata": {},
   "outputs": [
    {
     "data": {
      "text/html": [
       "<pre style=\"display: inline; \"><a href=\"https://github.com/cstjean/TraceCalls.jl/tree/3fffcc34b86870fb09e1c0cf9651f8396ff7032e//src/TraceCalls.jl#L311\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">#3</a>() => <font color=red>DomainError()</font></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline; \"><a href=\"https://github.com/johnmyleswhite/Calculus.jl/tree/f7b5556a9ebd0cdde45f15d1b2cde331fe5efdd4//src/derivative.jl#L71\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">Calculus.second_derivative</a>(f, 0.0) => <font color=red>DomainError()</font></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline; \"><a href=\"https://github.com/johnmyleswhite/Calculus.jl/tree/f7b5556a9ebd0cdde45f15d1b2cde331fe5efdd4//src/derivative.jl#L11\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">Calculus.derivative</a>(f, :central) => <b><font color=green>Calculus.#58</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline; \"><a href=\"https://github.com/johnmyleswhite/Calculus.jl/tree/f7b5556a9ebd0cdde45f15d1b2cde331fe5efdd4//src/derivative.jl#L2\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">Calculus.derivative</a>(f, :scalar, :central) => <b><font color=green>Calculus.#58</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li></ul></li><li><pre style=\"display: inline; \"><a href=\"https://github.com/johnmyleswhite/Calculus.jl/tree/f7b5556a9ebd0cdde45f15d1b2cde331fe5efdd4//src/finite_difference.jl#L224\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">Calculus.finite_difference_hessian</a>(f, Calculus.#58, 0.0, :central) => <font color=red>DomainError()</font></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline; \"><a href=\"https://github.com/johnmyleswhite/Calculus.jl/tree/f7b5556a9ebd0cdde45f15d1b2cde331fe5efdd4//src/finite_difference.jl#L48\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">Calculus.finite_difference</a>(Calculus.#58, 0.0, :central) => <font color=red>DomainError()</font></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline; \"><a href=\"https://github.com/johnmyleswhite/Calculus.jl/tree/f7b5556a9ebd0cdde45f15d1b2cde331fe5efdd4//src/finite_difference.jl#L48\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">Calculus.finite_difference</a>(f, 6.0554544523933395e-6, :central) => <b><font color=green>288.35028436717505</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline; \">f(1.2110908904786679e-5) => <b><font color=green>0.0034921840266401915</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li><li><pre style=\"display: inline; \">f(0.0) => <b><font color=green>0.0</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li></ul></li><li><pre style=\"display: inline; \"><a href=\"https://github.com/johnmyleswhite/Calculus.jl/tree/f7b5556a9ebd0cdde45f15d1b2cde331fe5efdd4//src/finite_difference.jl#L48\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">Calculus.finite_difference</a>(f, -6.0554544523933395e-6, :central) => <font color=red>DomainError()</font></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline; \">f(0.0) => <b><font color=green>0.0</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li><li><pre style=\"display: inline; \">f(-1.2110908904786679e-5) => <font color=red>DomainError()</font></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li></ul></li></ul></li></ul></li></ul></li></ul>"
      ],
      "text/plain": [
       "- #3() => \u001b[31mDomainError()\u001b[39m\n",
       "   - Calculus.second_derivative(f, 0.0) => \u001b[31mDomainError()\u001b[39m\n",
       "      - Calculus.derivative(f, :central) => \u001b[1m\u001b[32mCalculus.#58\u001b[39m\u001b[22m\n",
       "         - Calculus.derivative(f, :scalar, :central) => \u001b[1m\u001b[32mCalculus.#58\u001b[39m\u001b[22m\n",
       "      - Calculus.finite_difference_hessian(f, Calculus.#58, 0.0, :central) => \u001b[31mDomainError()\u001b[39m\n",
       "         - Calculus.finite_difference(Calculus.#58, 0.0, :central) => \u001b[31mDomainError()\u001b[39m\n",
       "            - Calculus.finite_difference(f, 6.0554544523933395e-6, :central) => \u001b[1m\u001b[32m288.35028436717505\u001b[39m\u001b[22m\n",
       "               - f(1.2110908904786679e-5) => \u001b[1m\u001b[32m0.0034921840266401915\u001b[39m\u001b[22m\n",
       "               - f(0.0) => \u001b[1m\u001b[32m0.0\u001b[39m\u001b[22m\n",
       "            - Calculus.finite_difference(f, -6.0554544523933395e-6, :central) => \u001b[31mDomainError()\u001b[39m\n",
       "               - f(0.0) => \u001b[1m\u001b[32m0.0\u001b[39m\u001b[22m\n",
       "               - f(-1.2110908904786679e-5) => \u001b[31mDomainError()\u001b[39m\n"
      ]
     },
     "execution_count": 4,
     "metadata": {},
     "output_type": "execute_result"
    }
   ],
   "source": [
    "@trace Calculus second_derivative(f, 0.0)"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "And finally, since full call data is recorded, we can rerun every part of the trace for [profiling](#Profiling), [debugging](#Debugging-with-traces), and testing."
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 18,
   "metadata": {},
   "outputs": [
    {
     "data": {
      "text/html": [
       "<pre style=\"display: inline; \"><a href=\"https://github.com/cstjean/TraceCalls.jl/tree/3fffcc34b86870fb09e1c0cf9651f8396ff7032e//src/TraceCalls.jl#L311\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">#1</a>() => <b><font color=green><font color=ff0000>256</font></font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline; \"><a href=\"https://github.com/johnmyleswhite/Calculus.jl/tree/f7b5556a9ebd0cdde45f15d1b2cde331fe5efdd4//src/derivative.jl#L71\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">Calculus.second_derivative</a>(f, 1.0) => <b><font color=green><font color=ff0000>256</font></font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline; \"><a href=\"https://github.com/johnmyleswhite/Calculus.jl/tree/f7b5556a9ebd0cdde45f15d1b2cde331fe5efdd4//src/derivative.jl#L11\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">Calculus.derivative</a>(f, :central) => <b><font color=green><font color=ff0000>208</font></font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline; \"><a href=\"https://github.com/johnmyleswhite/Calculus.jl/tree/f7b5556a9ebd0cdde45f15d1b2cde331fe5efdd4//src/derivative.jl#L2\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">Calculus.derivative</a>(f, :scalar, :central) => <b><font color=green><font color=ff0000>208</font></font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li></ul></li><li><pre style=\"display: inline; \"><a href=\"https://github.com/johnmyleswhite/Calculus.jl/tree/f7b5556a9ebd0cdde45f15d1b2cde331fe5efdd4//src/finite_difference.jl#L224\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">Calculus.finite_difference_hessian</a>(f, Calculus.#20, 1.0, :central) => <b><font color=green><font color=ff0000>16</font></font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline; \"><a href=\"https://github.com/johnmyleswhite/Calculus.jl/tree/f7b5556a9ebd0cdde45f15d1b2cde331fe5efdd4//src/finite_difference.jl#L48\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">Calculus.finite_difference</a>(Calculus.#20, 1.0, :central) => <b><font color=green><font color=ff0000>16</font></font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline; \"><a href=\"https://github.com/johnmyleswhite/Calculus.jl/tree/f7b5556a9ebd0cdde45f15d1b2cde331fe5efdd4//src/finite_difference.jl#L48\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">Calculus.finite_difference</a>(f, 1.0000060554544523, :central) => <b><font color=green><font color=00ff00>0</font></font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline; \">f(1.0000121109455733) => <b><font color=green><font color=00ff00>0</font></font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li><li><pre style=\"display: inline; \">f(0.9999999999633314) => <b><font color=green><font color=00ff00>0</font></font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li></ul></li><li><pre style=\"display: inline; \"><a href=\"https://github.com/johnmyleswhite/Calculus.jl/tree/f7b5556a9ebd0cdde45f15d1b2cde331fe5efdd4//src/finite_difference.jl#L48\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">Calculus.finite_difference</a>(f, 0.9999939445455476, :central) => <b><font color=green><font color=00ff00>0</font></font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline; \">f(1.0) => <b><font color=green><font color=00ff00>0</font></font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li><li><pre style=\"display: inline; \">f(0.9999878890910952) => <b><font color=green><font color=00ff00>0</font></font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li></ul></li></ul></li></ul></li></ul></li></ul>"
      ],
      "text/plain": [
       "- #1() => \u001b[1m\u001b[32m\u001b[38;2;255;0;0m256\u001b[39m\u001b[39m\u001b[22m\n",
       "   - Calculus.second_derivative(f, 1.0) => \u001b[1m\u001b[32m\u001b[38;2;255;0;0m256\u001b[39m\u001b[39m\u001b[22m\n",
       "      - Calculus.derivative(f, :central) => \u001b[1m\u001b[32m\u001b[38;2;255;0;0m208\u001b[39m\u001b[39m\u001b[22m\n",
       "         - Calculus.derivative(f, :scalar, :central) => \u001b[1m\u001b[32m\u001b[38;2;255;0;0m208\u001b[39m\u001b[39m\u001b[22m\n",
       "      - Calculus.finite_difference_hessian(f, Calculus.#20, 1.0, :central) => \u001b[1m\u001b[32m\u001b[38;2;255;0;0m16\u001b[39m\u001b[39m\u001b[22m\n",
       "         - Calculus.finite_difference(Calculus.#20, 1.0, :central) => \u001b[1m\u001b[32m\u001b[38;2;255;0;0m16\u001b[39m\u001b[39m\u001b[22m\n",
       "            - Calculus.finite_difference(f, 1.0000060554544523, :central) => \u001b[1m\u001b[32m\u001b[38;2;0;255;0m0\u001b[39m\u001b[39m\u001b[22m\n",
       "               - f(1.0000121109455733) => \u001b[1m\u001b[32m\u001b[38;2;0;255;0m0\u001b[39m\u001b[39m\u001b[22m\n",
       "               - f(0.9999999999633314) => \u001b[1m\u001b[32m\u001b[38;2;0;255;0m0\u001b[39m\u001b[39m\u001b[22m\n",
       "            - Calculus.finite_difference(f, 0.9999939445455476, :central) => \u001b[1m\u001b[32m\u001b[38;2;0;255;0m0\u001b[39m\u001b[39m\u001b[22m\n",
       "               - f(1.0) => \u001b[1m\u001b[32m\u001b[38;2;0;255;0m0\u001b[39m\u001b[39m\u001b[22m\n",
       "               - f(0.9999878890910952) => \u001b[1m\u001b[32m\u001b[38;2;0;255;0m0\u001b[39m\u001b[39m\u001b[22m\n"
      ]
     },
     "execution_count": 18,
     "metadata": {},
     "output_type": "execute_result"
    }
   ],
   "source": [
    "greenred(map(:@allocated, trace_derivative))    # compute how many bytes were allocated in each function call"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "# Tracing code\n",
    "\n",
    "#### Syntax\n",
    "\n",
    "```julia\n",
    "@traceable function foo()\n",
    "...\n",
    "end\n",
    "\n",
    "@trace (some_function, SomeModule, \"some_interactively_included_file.jl\") bar(1)\n",
    "```\n",
    "\n",
    "This call to `@trace` will execute `bar(1)` while tracing all methods of `some_function`, all methods defined in `SomeModule / \"some_interactively_included_file.jl\"`, and all methods defined with `@traceable` (in this case, `foo()`). \n",
    "\n",
    "Tracing Julia code involves a fair amount of code analysis; TraceCalls.jl will error, warn, or silently skip (when tracing a module) the following:\n",
    "\n",
    " - Inner constructors\n",
    " - Functions that are defined by `eval`\n",
    " - Callable objects (eg. `(func::Functor)(x) = ...`)\n",
    " \n",
    "The `@traceable` macro (to be used primarily for interactively-defined functions) remembers the function definition without modifying it. It has no impact on the performance of your code.\n",
    "\n",
    "#### Tracing tips\n",
    "\n",
    "It might be tempting to run `@trace MyModule some_long_computation()`, but a) there is a small cost to every traced call, and b) a trace with a million calls is too large and unwieldy to be of much use anyway. If you are only interested in the details of one particular `my_fun` call that happens during `some_long_computation()`, then it's usually better to do this:\n",
    "\n",
    "```julia\n",
    "trace_my_fun = @trace my_fun some_long_computation()     # fast, because we're only tracing one function\n",
    "trace = @trace MyModule trace_my_fun[3]()                # select the third `my_fun()` call, and trace it fully\n",
    "```\n",
    "\n",
    "This strategy also works with [`@stacktrace`](#Debugging-with-traces). \n",
    "\n",
    "#### Implementation of @trace\n",
    "\n",
    "`@trace some_fn foo(10)` performs these operations:\n",
    "\n",
    "1. Find the source code of `some_fn`\n",
    "2. Replace the definition(s) of `some_fn` with a tracing version (using `eval`)\n",
    "3. Run `foo(10)`\n",
    "4. Restore the original definition(s) of `some_fn` (using `eval`)\n",
    "\n",
    "The downside of this scheme is that `@trace` can trigger significant JIT compiling time. Tracing large modules can be slow the first time around, but caching is used to avoid repeated computations."
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "# Manipulating traces\n",
    "\n",
    "Consider computing a [random walk](https://en.wikipedia.org/wiki/Random_walk) on a small graph, using [LightGraphs.jl](http://juliagraphs.github.io/LightGraphs.jl/latest/)"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 1,
   "metadata": {},
   "outputs": [
    {
     "data": {
      "text/html": [
       "<pre style=\"display: inline; \"><a href=\"https://github.com/cstjean/TraceCalls.jl/tree/a2e82eae2bd58855165eafae8966dd08aeca6cb0//src/TraceCalls.jl#L347\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">#1</a>() => <b><font color=green>[2, 1, 2, 3, 2]</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaGraphs/LightGraphs.jl/tree/e8a7726b30d9557ad5abd3a63c2084b76c8157ad//src/traversals/randomwalks.jl#L8\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">LightGraphs.randomwalk</a>({3, 2} undirected simple Int64 graph, 2, 5) => <b><font color=green>[2, 1, 2, 3, 2]</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaGraphs/LightGraphs.jl/tree/e8a7726b30d9557ad5abd3a63c2084b76c8157ad//src/graphtypes/simplegraphs/simplegraph.jl#L13\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">eltype</a>({3, 2} undirected simple Int64 graph) => <b><font color=green>Int64</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaGraphs/LightGraphs.jl/tree/e8a7726b30d9557ad5abd3a63c2084b76c8157ad//src/graphtypes/simplegraphs/SimpleGraphs.jl#L44\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">LightGraphs.vertices</a>({3, 2} undirected simple Int64 graph) => <b><font color=green>1:3</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaGraphs/LightGraphs.jl/tree/e8a7726b30d9557ad5abd3a63c2084b76c8157ad//src/graphtypes/simplegraphs/SimpleGraphs.jl#L43\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">LightGraphs.nv</a>({3, 2} undirected simple Int64 graph) => <b><font color=green>3</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaGraphs/LightGraphs.jl/tree/e8a7726b30d9557ad5abd3a63c2084b76c8157ad//src/graphtypes/simplegraphs/simplegraph.jl#L13\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">eltype</a>({3, 2} undirected simple Int64 graph) => <b><font color=green>Int64</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaGraphs/LightGraphs.jl/tree/e8a7726b30d9557ad5abd3a63c2084b76c8157ad//src/graphtypes/simplegraphs/SimpleGraphs.jl#L50\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">LightGraphs.SimpleGraphs.fadj</a>({3, 2} undirected simple Int64 graph) => <b><font color=green>Array{Int64,1}[[2], [1, 3], [2]]</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li></ul></li></ul></li><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaGraphs/LightGraphs.jl/tree/e8a7726b30d9557ad5abd3a63c2084b76c8157ad//src/graphtypes/simplegraphs/SimpleGraphs.jl#L65\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">LightGraphs.out_neighbors</a>({3, 2} undirected simple Int64 graph, 2) => <b><font color=green>[1, 3]</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaGraphs/LightGraphs.jl/tree/e8a7726b30d9557ad5abd3a63c2084b76c8157ad//src/graphtypes/simplegraphs/SimpleGraphs.jl#L51\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">LightGraphs.SimpleGraphs.fadj</a>({3, 2} undirected simple Int64 graph, 2) => <b><font color=green>[1, 3]</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li></ul></li><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaGraphs/LightGraphs.jl/tree/e8a7726b30d9557ad5abd3a63c2084b76c8157ad//src/graphtypes/simplegraphs/SimpleGraphs.jl#L65\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">LightGraphs.out_neighbors</a>({3, 2} undirected simple Int64 graph, 1) => <b><font color=green>[2]</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaGraphs/LightGraphs.jl/tree/e8a7726b30d9557ad5abd3a63c2084b76c8157ad//src/graphtypes/simplegraphs/SimpleGraphs.jl#L51\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">LightGraphs.SimpleGraphs.fadj</a>({3, 2} undirected simple Int64 graph, 1) => <b><font color=green>[2]</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li></ul></li><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaGraphs/LightGraphs.jl/tree/e8a7726b30d9557ad5abd3a63c2084b76c8157ad//src/graphtypes/simplegraphs/SimpleGraphs.jl#L65\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">LightGraphs.out_neighbors</a>({3, 2} undirected simple Int64 graph, 2) => <b><font color=green>[1, 3]</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaGraphs/LightGraphs.jl/tree/e8a7726b30d9557ad5abd3a63c2084b76c8157ad//src/graphtypes/simplegraphs/SimpleGraphs.jl#L51\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">LightGraphs.SimpleGraphs.fadj</a>({3, 2} undirected simple Int64 graph, 2) => <b><font color=green>[1, 3]</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li></ul></li><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaGraphs/LightGraphs.jl/tree/e8a7726b30d9557ad5abd3a63c2084b76c8157ad//src/graphtypes/simplegraphs/SimpleGraphs.jl#L65\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">LightGraphs.out_neighbors</a>({3, 2} undirected simple Int64 graph, 3) => <b><font color=green>[2]</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaGraphs/LightGraphs.jl/tree/e8a7726b30d9557ad5abd3a63c2084b76c8157ad//src/graphtypes/simplegraphs/SimpleGraphs.jl#L51\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">LightGraphs.SimpleGraphs.fadj</a>({3, 2} undirected simple Int64 graph, 3) => <b><font color=green>[2]</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li></ul></li><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaGraphs/LightGraphs.jl/tree/e8a7726b30d9557ad5abd3a63c2084b76c8157ad//src/graphtypes/simplegraphs/SimpleGraphs.jl#L65\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">LightGraphs.out_neighbors</a>({3, 2} undirected simple Int64 graph, 2) => <b><font color=green>[1, 3]</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaGraphs/LightGraphs.jl/tree/e8a7726b30d9557ad5abd3a63c2084b76c8157ad//src/graphtypes/simplegraphs/SimpleGraphs.jl#L51\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">LightGraphs.SimpleGraphs.fadj</a>({3, 2} undirected simple Int64 graph, 2) => <b><font color=green>[1, 3]</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li></ul></li></ul></li></ul>"
      ],
      "text/plain": [
       "- #1() => \u001b[1m\u001b[32m[2, 1, 2, 3, 2]\u001b[39m\u001b[22m\n",
       "   - LightGraphs.randomwalk({3, 2} undirected simple Int64 graph, 2, 5) => \u001b[1m\u001b[32m[2, 1, 2, 3, 2]\u001b[39m\u001b[22m\n",
       "      - eltype({3, 2} undirected simple Int64 graph) => \u001b[1m\u001b[32mInt64\u001b[39m\u001b[22m\n",
       "      - LightGraphs.vertices({3, 2} undirected simple Int64 graph) => \u001b[1m\u001b[32m1:3\u001b[39m\u001b[22m\n",
       "         - LightGraphs.nv({3, 2} undirected simple Int64 graph) => \u001b[1m\u001b[32m3\u001b[39m\u001b[22m\n",
       "            - eltype({3, 2} undirected simple Int64 graph) => \u001b[1m\u001b[32mInt64\u001b[39m\u001b[22m\n",
       "            - LightGraphs.SimpleGraphs.fadj({3, 2} undirected simple Int64 graph) => \u001b[1m\u001b[32mArray{Int64,1}[[2], [1, 3], [2]]\u001b[39m\u001b[22m\n",
       "      - LightGraphs.out_neighbors({3, 2} undirected simple Int64 graph, 2) => \u001b[1m\u001b[32m[1, 3]\u001b[39m\u001b[22m\n",
       "         - LightGraphs.SimpleGraphs.fadj({3, 2} undirected simple Int64 graph, 2) => \u001b[1m\u001b[32m[1, 3]\u001b[39m\u001b[22m\n",
       "      - LightGraphs.out_neighbors({3, 2} undirected simple Int64 graph, 1) => \u001b[1m\u001b[32m[2]\u001b[39m\u001b[22m\n",
       "         - LightGraphs.SimpleGraphs.fadj({3, 2} undirected simple Int64 graph, 1) => \u001b[1m\u001b[32m[2]\u001b[39m\u001b[22m\n",
       "      - LightGraphs.out_neighbors({3, 2} undirected simple Int64 graph, 2) => \u001b[1m\u001b[32m[1, 3]\u001b[39m\u001b[22m\n",
       "         - LightGraphs.SimpleGraphs.fadj({3, 2} undirected simple Int64 graph, 2) => \u001b[1m\u001b[32m[1, 3]\u001b[39m\u001b[22m\n",
       "      - LightGraphs.out_neighbors({3, 2} undirected simple Int64 graph, 3) => \u001b[1m\u001b[32m[2]\u001b[39m\u001b[22m\n",
       "         - LightGraphs.SimpleGraphs.fadj({3, 2} undirected simple Int64 graph, 3) => \u001b[1m\u001b[32m[2]\u001b[39m\u001b[22m\n",
       "      - LightGraphs.out_neighbors({3, 2} undirected simple Int64 graph, 2) => \u001b[1m\u001b[32m[1, 3]\u001b[39m\u001b[22m\n",
       "         - LightGraphs.SimpleGraphs.fadj({3, 2} undirected simple Int64 graph, 2) => \u001b[1m\u001b[32m[1, 3]\u001b[39m\u001b[22m\n"
      ]
     },
     "execution_count": 1,
     "metadata": {},
     "output_type": "execute_result"
    }
   ],
   "source": [
    "using LightGraphs, TraceCalls\n",
    "\n",
    "graph = Graph(3)                                      # build an undirected graph with three connected vertices\n",
    "add_edge!(graph, 1, 2); add_edge!(graph, 2, 3) \n",
    "\n",
    "trace_walk = @trace LightGraphs randomwalk(graph, 2, 5)"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "The trace can be indexed:"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 2,
   "metadata": {},
   "outputs": [
    {
     "data": {
      "text/html": [
       "<pre style=\"display: inline; \"><a href=\"https://github.com/JuliaGraphs/LightGraphs.jl/tree/e8a7726b30d9557ad5abd3a63c2084b76c8157ad//src/graphtypes/simplegraphs/SimpleGraphs.jl#L65\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">LightGraphs.out_neighbors</a>({3, 2} undirected simple Int64 graph, 2) => <b><font color=green>[1, 3]</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaGraphs/LightGraphs.jl/tree/e8a7726b30d9557ad5abd3a63c2084b76c8157ad//src/graphtypes/simplegraphs/SimpleGraphs.jl#L51\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">LightGraphs.SimpleGraphs.fadj</a>({3, 2} undirected simple Int64 graph, 2) => <b><font color=green>[1, 3]</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li></ul>"
      ],
      "text/plain": [
       "- LightGraphs.out_neighbors({3, 2} undirected simple Int64 graph, 2) => \u001b[1m\u001b[32m[1, 3]\u001b[39m\u001b[22m\n",
       "   - LightGraphs.SimpleGraphs.fadj({3, 2} undirected simple Int64 graph, 2) => \u001b[1m\u001b[32m[1, 3]\u001b[39m\u001b[22m\n"
      ]
     },
     "execution_count": 2,
     "metadata": {},
     "output_type": "execute_result"
    }
   ],
   "source": [
    "trace_walk[1][3]    # can also be written trace_walk[1,3]"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 3,
   "metadata": {},
   "outputs": [
    {
     "data": {
      "text/plain": [
       "2"
      ]
     },
     "execution_count": 3,
     "metadata": {},
     "output_type": "execute_result"
    }
   ],
   "source": [
    "trace_walk[1][3][:v]   # get the second argument by name. To get it by position, use trace_walk[1][3].args[2]"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "Called:"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 4,
   "metadata": {},
   "outputs": [
    {
     "data": {
      "text/plain": [
       "2-element Array{Int64,1}:\n",
       " 1\n",
       " 3"
      ]
     },
     "execution_count": 4,
     "metadata": {},
     "output_type": "execute_result"
    }
   ],
   "source": [
    "trace_walk[1,3]()   # call `LightGraphs.out_neighbors(...)`"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "Or pruned (useful for exploring large traces):"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 5,
   "metadata": {},
   "outputs": [
    {
     "data": {
      "text/html": [
       "<pre style=\"display: inline; \"><a href=\"https://github.com/cstjean/TraceCalls.jl/tree/a2e82eae2bd58855165eafae8966dd08aeca6cb0//src/TraceCalls.jl#L347\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">#1</a>() => <b><font color=green>[2, 1, 2, 3, 2]</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaGraphs/LightGraphs.jl/tree/e8a7726b30d9557ad5abd3a63c2084b76c8157ad//src/traversals/randomwalks.jl#L8\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">LightGraphs.randomwalk</a>({3, 2} undirected simple Int64 graph, 2, 5) => <b><font color=green>[2, 1, 2, 3, 2]</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaGraphs/LightGraphs.jl/tree/e8a7726b30d9557ad5abd3a63c2084b76c8157ad//src/graphtypes/simplegraphs/simplegraph.jl#L13\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">eltype</a>({3, 2} undirected simple Int64 graph) => <b><font color=green>Int64</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaGraphs/LightGraphs.jl/tree/e8a7726b30d9557ad5abd3a63c2084b76c8157ad//src/graphtypes/simplegraphs/SimpleGraphs.jl#L44\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">LightGraphs.vertices</a>({3, 2} undirected simple Int64 graph) => <b><font color=green>1:3</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaGraphs/LightGraphs.jl/tree/e8a7726b30d9557ad5abd3a63c2084b76c8157ad//src/graphtypes/simplegraphs/SimpleGraphs.jl#L65\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">LightGraphs.out_neighbors</a>({3, 2} undirected simple Int64 graph, 2) => <b><font color=green>[1, 3]</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaGraphs/LightGraphs.jl/tree/e8a7726b30d9557ad5abd3a63c2084b76c8157ad//src/graphtypes/simplegraphs/SimpleGraphs.jl#L65\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">LightGraphs.out_neighbors</a>({3, 2} undirected simple Int64 graph, 1) => <b><font color=green>[2]</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li></ul></li></ul>"
      ],
      "text/plain": [
       "- #1() => \u001b[1m\u001b[32m[2, 1, 2, 3, 2]\u001b[39m\u001b[22m\n",
       "   - LightGraphs.randomwalk({3, 2} undirected simple Int64 graph, 2, 5) => \u001b[1m\u001b[32m[2, 1, 2, 3, 2]\u001b[39m\u001b[22m\n",
       "      - eltype({3, 2} undirected simple Int64 graph) => \u001b[1m\u001b[32mInt64\u001b[39m\u001b[22m\n",
       "      - LightGraphs.vertices({3, 2} undirected simple Int64 graph) => \u001b[1m\u001b[32m1:3\u001b[39m\u001b[22m\n",
       "      - LightGraphs.out_neighbors({3, 2} undirected simple Int64 graph, 2) => \u001b[1m\u001b[32m[1, 3]\u001b[39m\u001b[22m\n",
       "      - LightGraphs.out_neighbors({3, 2} undirected simple Int64 graph, 1) => \u001b[1m\u001b[32m[2]\u001b[39m\u001b[22m\n"
      ]
     },
     "execution_count": 5,
     "metadata": {},
     "output_type": "execute_result"
    }
   ],
   "source": [
    "pruned_trace = prune(trace_walk, \n",
    "                     2,  # maximum depth\n",
    "                     4)  # maximum length of each trace (eg. if foo() calls bar() 100 times, keep the first 4 times)"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "A subcall of a pruned/filtered trace can be reexpanded by retracing it:"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 8,
   "metadata": {},
   "outputs": [
    {
     "data": {
      "text/html": [
       "<pre style=\"display: inline; \"><a href=\"https://github.com/cstjean/TraceCalls.jl/tree/a2e82eae2bd58855165eafae8966dd08aeca6cb0//src/TraceCalls.jl#L347\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">#7</a>() => <b><font color=green>1:3</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaGraphs/LightGraphs.jl/tree/e8a7726b30d9557ad5abd3a63c2084b76c8157ad//src/graphtypes/simplegraphs/SimpleGraphs.jl#L44\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">LightGraphs.vertices</a>({3, 2} undirected simple Int64 graph) => <b><font color=green>1:3</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaGraphs/LightGraphs.jl/tree/e8a7726b30d9557ad5abd3a63c2084b76c8157ad//src/graphtypes/simplegraphs/SimpleGraphs.jl#L43\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">LightGraphs.nv</a>({3, 2} undirected simple Int64 graph) => <b><font color=green>3</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaGraphs/LightGraphs.jl/tree/e8a7726b30d9557ad5abd3a63c2084b76c8157ad//src/graphtypes/simplegraphs/simplegraph.jl#L13\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">eltype</a>({3, 2} undirected simple Int64 graph) => <b><font color=green>Int64</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaGraphs/LightGraphs.jl/tree/e8a7726b30d9557ad5abd3a63c2084b76c8157ad//src/graphtypes/simplegraphs/SimpleGraphs.jl#L50\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">LightGraphs.SimpleGraphs.fadj</a>({3, 2} undirected simple Int64 graph) => <b><font color=green>Array{Int64,1}[[2], [1, 3], [2]]</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li></ul></li></ul></li></ul>"
      ],
      "text/plain": [
       "- #7() => \u001b[1m\u001b[32m1:3\u001b[39m\u001b[22m\n",
       "   - LightGraphs.vertices({3, 2} undirected simple Int64 graph) => \u001b[1m\u001b[32m1:3\u001b[39m\u001b[22m\n",
       "      - LightGraphs.nv({3, 2} undirected simple Int64 graph) => \u001b[1m\u001b[32m3\u001b[39m\u001b[22m\n",
       "         - eltype({3, 2} undirected simple Int64 graph) => \u001b[1m\u001b[32mInt64\u001b[39m\u001b[22m\n",
       "         - LightGraphs.SimpleGraphs.fadj({3, 2} undirected simple Int64 graph) => \u001b[1m\u001b[32mArray{Int64,1}[[2], [1, 3], [2]]\u001b[39m\u001b[22m\n"
      ]
     },
     "execution_count": 8,
     "metadata": {},
     "output_type": "execute_result"
    }
   ],
   "source": [
    "@trace LightGraphs pruned_trace[1, 2]()   # don't forget the (); it triggers the computation for that call"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "#### Custom text/HTML\n",
    "\n",
    "TraceCalls.jl calls `TraceCalls.show_val(io::IO, mime, x)` to display each argument and return value. It defaults to `show(io, x)`, but can be customized, either to highlight certain values, or to shorten objects that are not important for the task at hand. Implement `TraceCalls.show_val(::IO, ::MIME\"text/html\", value)` for Atom/IJulia, and `TraceCalls.show_val(::IO, ::MIME\"text/plain\", value)` for the REPL and other non-HTML environments. See [the Julia manual on custom pretty-printing](https://docs.julialang.org/en/stable/manual/types/#Custom-pretty-printing-1) for more information, and [print_with_color](https://docs.julialang.org/en/stable/stdlib/io-network/#Base.print_with_color) / [Crayons.jl](https://github.com/KristofferC/Crayons.jl) for colorful REPL display."
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 10,
   "metadata": {},
   "outputs": [
    {
     "data": {
      "text/html": [
       "<pre style=\"display: inline; \"><a href=\"https://github.com/cstjean/TraceCalls.jl/tree/3fffcc34b86870fb09e1c0cf9651f8396ff7032e//src/TraceCalls.jl#L311\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">#17</a>() => <b><font color=green>[<font color=red>2</font>,1,<font color=red>2</font>,1,<font color=red>2</font>]</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaGraphs/LightGraphs.jl/tree/e8a7726b30d9557ad5abd3a63c2084b76c8157ad//src/traversals/randomwalks.jl#L8\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">LightGraphs.randomwalk</a>(AnyOldGraph, 2, 5) => <b><font color=green>[<font color=red>2</font>,1,<font color=red>2</font>,1,<font color=red>2</font>]</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaGraphs/LightGraphs.jl/tree/e8a7726b30d9557ad5abd3a63c2084b76c8157ad//src/graphtypes/simplegraphs/simplegraph.jl#L13\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">eltype</a>(AnyOldGraph) => <b><font color=green>Int64</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaGraphs/LightGraphs.jl/tree/e8a7726b30d9557ad5abd3a63c2084b76c8157ad//src/graphtypes/simplegraphs/SimpleGraphs.jl#L44\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">LightGraphs.vertices</a>(AnyOldGraph) => <b><font color=green>1:3</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaGraphs/LightGraphs.jl/tree/e8a7726b30d9557ad5abd3a63c2084b76c8157ad//src/graphtypes/simplegraphs/SimpleGraphs.jl#L43\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">LightGraphs.nv</a>(AnyOldGraph) => <b><font color=green>3</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaGraphs/LightGraphs.jl/tree/e8a7726b30d9557ad5abd3a63c2084b76c8157ad//src/graphtypes/simplegraphs/simplegraph.jl#L13\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">eltype</a>(AnyOldGraph) => <b><font color=green>Int64</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaGraphs/LightGraphs.jl/tree/e8a7726b30d9557ad5abd3a63c2084b76c8157ad//src/graphtypes/simplegraphs/SimpleGraphs.jl#L50\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">LightGraphs.SimpleGraphs.fadj</a>(AnyOldGraph) => <b><font color=green>Array{Int64,1}[[2], [1, 3], [2]]</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li></ul></li></ul></li><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaGraphs/LightGraphs.jl/tree/e8a7726b30d9557ad5abd3a63c2084b76c8157ad//src/graphtypes/simplegraphs/SimpleGraphs.jl#L65\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">LightGraphs.out_neighbors</a>(AnyOldGraph, 2) => <b><font color=green>[1,3]</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaGraphs/LightGraphs.jl/tree/e8a7726b30d9557ad5abd3a63c2084b76c8157ad//src/graphtypes/simplegraphs/SimpleGraphs.jl#L51\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">LightGraphs.SimpleGraphs.fadj</a>(AnyOldGraph, 2) => <b><font color=green>[1,3]</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li></ul></li><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaGraphs/LightGraphs.jl/tree/e8a7726b30d9557ad5abd3a63c2084b76c8157ad//src/graphtypes/simplegraphs/SimpleGraphs.jl#L65\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">LightGraphs.out_neighbors</a>(AnyOldGraph, 1) => <b><font color=green>[<font color=red>2</font>]</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaGraphs/LightGraphs.jl/tree/e8a7726b30d9557ad5abd3a63c2084b76c8157ad//src/graphtypes/simplegraphs/SimpleGraphs.jl#L51\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">LightGraphs.SimpleGraphs.fadj</a>(AnyOldGraph, 1) => <b><font color=green>[<font color=red>2</font>]</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li></ul></li><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaGraphs/LightGraphs.jl/tree/e8a7726b30d9557ad5abd3a63c2084b76c8157ad//src/graphtypes/simplegraphs/SimpleGraphs.jl#L65\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">LightGraphs.out_neighbors</a>(AnyOldGraph, 2) => <b><font color=green>[1,3]</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaGraphs/LightGraphs.jl/tree/e8a7726b30d9557ad5abd3a63c2084b76c8157ad//src/graphtypes/simplegraphs/SimpleGraphs.jl#L51\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">LightGraphs.SimpleGraphs.fadj</a>(AnyOldGraph, 2) => <b><font color=green>[1,3]</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li></ul></li><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaGraphs/LightGraphs.jl/tree/e8a7726b30d9557ad5abd3a63c2084b76c8157ad//src/graphtypes/simplegraphs/SimpleGraphs.jl#L65\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">LightGraphs.out_neighbors</a>(AnyOldGraph, 1) => <b><font color=green>[<font color=red>2</font>]</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaGraphs/LightGraphs.jl/tree/e8a7726b30d9557ad5abd3a63c2084b76c8157ad//src/graphtypes/simplegraphs/SimpleGraphs.jl#L51\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">LightGraphs.SimpleGraphs.fadj</a>(AnyOldGraph, 1) => <b><font color=green>[<font color=red>2</font>]</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li></ul></li><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaGraphs/LightGraphs.jl/tree/e8a7726b30d9557ad5abd3a63c2084b76c8157ad//src/graphtypes/simplegraphs/SimpleGraphs.jl#L65\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">LightGraphs.out_neighbors</a>(AnyOldGraph, 2) => <b><font color=green>[1,3]</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaGraphs/LightGraphs.jl/tree/e8a7726b30d9557ad5abd3a63c2084b76c8157ad//src/graphtypes/simplegraphs/SimpleGraphs.jl#L51\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">LightGraphs.SimpleGraphs.fadj</a>(AnyOldGraph, 2) => <b><font color=green>[1,3]</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li></ul></li></ul></li></ul>"
      ],
      "text/plain": [
       "- #17() => \u001b[1m\u001b[32m[2, 1, 2, 1, 2]\u001b[39m\u001b[22m\n",
       "   - LightGraphs.randomwalk({3, 2} undirected simple Int64 graph, 2, 5) => \u001b[1m\u001b[32m[2, 1, 2, 1, 2]\u001b[39m\u001b[22m\n",
       "      - eltype({3, 2} undirected simple Int64 graph) => \u001b[1m\u001b[32mInt64\u001b[39m\u001b[22m\n",
       "      - LightGraphs.vertices({3, 2} undirected simple Int64 graph) => \u001b[1m\u001b[32m1:3\u001b[39m\u001b[22m\n",
       "         - LightGraphs.nv({3, 2} undirected simple Int64 graph) => \u001b[1m\u001b[32m3\u001b[39m\u001b[22m\n",
       "            - eltype({3, 2} undirected simple Int64 graph) => \u001b[1m\u001b[32mInt64\u001b[39m\u001b[22m\n",
       "            - LightGraphs.SimpleGraphs.fadj({3, 2} undirected simple Int64 graph) => \u001b[1m\u001b[32mArray{Int64,1}[[2], [1, 3], [2]]\u001b[39m\u001b[22m\n",
       "      - LightGraphs.out_neighbors({3, 2} undirected simple Int64 graph, 2) => \u001b[1m\u001b[32m[1, 3]\u001b[39m\u001b[22m\n",
       "         - LightGraphs.SimpleGraphs.fadj({3, 2} undirected simple Int64 graph, 2) => \u001b[1m\u001b[32m[1, 3]\u001b[39m\u001b[22m\n",
       "      - LightGraphs.out_neighbors({3, 2} undirected simple Int64 graph, 1) => \u001b[1m\u001b[32m[2]\u001b[39m\u001b[22m\n",
       "         - LightGraphs.SimpleGraphs.fadj({3, 2} undirected simple Int64 graph, 1) => \u001b[1m\u001b[32m[2]\u001b[39m\u001b[22m\n",
       "      - LightGraphs.out_neighbors({3, 2} undirected simple Int64 graph, 2) => \u001b[1m\u001b[32m[1, 3]\u001b[39m\u001b[22m\n",
       "         - LightGraphs.SimpleGraphs.fadj({3, 2} undirected simple Int64 graph, 2) => \u001b[1m\u001b[32m[1, 3]\u001b[39m\u001b[22m\n",
       "      - LightGraphs.out_neighbors({3, 2} undirected simple Int64 graph, 1) => \u001b[1m\u001b[32m[2]\u001b[39m\u001b[22m\n",
       "         - LightGraphs.SimpleGraphs.fadj({3, 2} undirected simple Int64 graph, 1) => \u001b[1m\u001b[32m[2]\u001b[39m\u001b[22m\n",
       "      - LightGraphs.out_neighbors({3, 2} undirected simple Int64 graph, 2) => \u001b[1m\u001b[32m[1, 3]\u001b[39m\u001b[22m\n",
       "         - LightGraphs.SimpleGraphs.fadj({3, 2} undirected simple Int64 graph, 2) => \u001b[1m\u001b[32m[1, 3]\u001b[39m\u001b[22m\n"
      ]
     },
     "execution_count": 10,
     "metadata": {},
     "output_type": "execute_result"
    }
   ],
   "source": [
    "TraceCalls.show_val(io::IO, ::MIME\"text/html\", v::Vector{Int}) = \n",
    "    write(io, string(\"[\", join([x==2 ? \"<font color=red>2</font>\" : x for x in v], \",\"), \"]\"))\n",
    "TraceCalls.show_val(io::IO, ::MIME\"text/html\", ::Graph) =  # could also be done with `@show_val_only_type Graph`\n",
    "    write(io, \"AnyOldGraph\")   \n",
    "trace_walk"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "See also `?@show_val_only_type`, `?TraceCalls.show_call`, `?TraceCalls.show_return_val` and `?highlight`."
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "#### Map, filter, collect\n",
    "\n",
    "Each function call in a trace is represented by an instance of the `Trace` structure:\n",
    "\n",
    "```julia\n",
    "struct Trace\n",
    "    func::Function        # the function called\n",
    "    args::Tuple           # the positional arguments\n",
    "    kwargs::Tuple         # the keyword arguments\n",
    "    called::Vector{Trace} # the functions called within the execution of this function call \n",
    "    value                 # This is the return value of the func(args...; kwargs...) call, but it's also where\n",
    "                          # the result of `map(f, ::Trace)` will be stored.\n",
    "end\n",
    "```"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "The following filtering functions are provided:\n",
    "\n",
    "- `filter(f, trace)` keeps all function calls for which `f(::Trace)` is true. It's useful to cut out uninteresting intermediate functions. \n",
    "- `filter_cutting(f, trace)` is like `filter`, but will remove all descendents of the traces for which `f(trace)` is false. \n",
    "- `filter_lineage(f, trace)` keeps all function calls for which `f(::Trace)` is true of at least one of its descendents or ancestors. Use it to focus on some interesting part of the trace. "
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 11,
   "metadata": {},
   "outputs": [
    {
     "data": {
      "text/html": [
       "<pre style=\"display: inline; \"><a href=\"https://github.com/cstjean/TraceCalls.jl/tree/3fffcc34b86870fb09e1c0cf9651f8396ff7032e//src/TraceCalls.jl#L311\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">#17</a>() => <b><font color=green>[<font color=red>2</font>,1,<font color=red>2</font>,1,<font color=red>2</font>]</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaGraphs/LightGraphs.jl/tree/e8a7726b30d9557ad5abd3a63c2084b76c8157ad//src/traversals/randomwalks.jl#L8\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">LightGraphs.randomwalk</a>(AnyOldGraph, 2, 5) => <b><font color=green>[<font color=red>2</font>,1,<font color=red>2</font>,1,<font color=red>2</font>]</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaGraphs/LightGraphs.jl/tree/e8a7726b30d9557ad5abd3a63c2084b76c8157ad//src/graphtypes/simplegraphs/simplegraph.jl#L13\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">eltype</a>(AnyOldGraph) => <b><font color=green>Int64</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaGraphs/LightGraphs.jl/tree/e8a7726b30d9557ad5abd3a63c2084b76c8157ad//src/graphtypes/simplegraphs/SimpleGraphs.jl#L44\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">LightGraphs.vertices</a>(AnyOldGraph) => <b><font color=green>1:3</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaGraphs/LightGraphs.jl/tree/e8a7726b30d9557ad5abd3a63c2084b76c8157ad//src/graphtypes/simplegraphs/SimpleGraphs.jl#L43\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">LightGraphs.nv</a>(AnyOldGraph) => <b><font color=green>3</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaGraphs/LightGraphs.jl/tree/e8a7726b30d9557ad5abd3a63c2084b76c8157ad//src/graphtypes/simplegraphs/simplegraph.jl#L13\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">eltype</a>(AnyOldGraph) => <b><font color=green>Int64</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li></ul></li></ul></li><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaGraphs/LightGraphs.jl/tree/e8a7726b30d9557ad5abd3a63c2084b76c8157ad//src/graphtypes/simplegraphs/SimpleGraphs.jl#L65\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">LightGraphs.out_neighbors</a>(AnyOldGraph, 2) => <b><font color=green>[1,3]</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaGraphs/LightGraphs.jl/tree/e8a7726b30d9557ad5abd3a63c2084b76c8157ad//src/graphtypes/simplegraphs/SimpleGraphs.jl#L65\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">LightGraphs.out_neighbors</a>(AnyOldGraph, 1) => <b><font color=green>[<font color=red>2</font>]</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaGraphs/LightGraphs.jl/tree/e8a7726b30d9557ad5abd3a63c2084b76c8157ad//src/graphtypes/simplegraphs/SimpleGraphs.jl#L65\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">LightGraphs.out_neighbors</a>(AnyOldGraph, 2) => <b><font color=green>[1,3]</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaGraphs/LightGraphs.jl/tree/e8a7726b30d9557ad5abd3a63c2084b76c8157ad//src/graphtypes/simplegraphs/SimpleGraphs.jl#L65\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">LightGraphs.out_neighbors</a>(AnyOldGraph, 1) => <b><font color=green>[<font color=red>2</font>]</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaGraphs/LightGraphs.jl/tree/e8a7726b30d9557ad5abd3a63c2084b76c8157ad//src/graphtypes/simplegraphs/SimpleGraphs.jl#L65\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">LightGraphs.out_neighbors</a>(AnyOldGraph, 2) => <b><font color=green>[1,3]</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li></ul></li></ul>"
      ],
      "text/plain": [
       "- #17() => \u001b[1m\u001b[32m[2, 1, 2, 1, 2]\u001b[39m\u001b[22m\n",
       "   - LightGraphs.randomwalk({3, 2} undirected simple Int64 graph, 2, 5) => \u001b[1m\u001b[32m[2, 1, 2, 1, 2]\u001b[39m\u001b[22m\n",
       "      - eltype({3, 2} undirected simple Int64 graph) => \u001b[1m\u001b[32mInt64\u001b[39m\u001b[22m\n",
       "      - LightGraphs.vertices({3, 2} undirected simple Int64 graph) => \u001b[1m\u001b[32m1:3\u001b[39m\u001b[22m\n",
       "         - LightGraphs.nv({3, 2} undirected simple Int64 graph) => \u001b[1m\u001b[32m3\u001b[39m\u001b[22m\n",
       "            - eltype({3, 2} undirected simple Int64 graph) => \u001b[1m\u001b[32mInt64\u001b[39m\u001b[22m\n",
       "      - LightGraphs.out_neighbors({3, 2} undirected simple Int64 graph, 2) => \u001b[1m\u001b[32m[1, 3]\u001b[39m\u001b[22m\n",
       "      - LightGraphs.out_neighbors({3, 2} undirected simple Int64 graph, 1) => \u001b[1m\u001b[32m[2]\u001b[39m\u001b[22m\n",
       "      - LightGraphs.out_neighbors({3, 2} undirected simple Int64 graph, 2) => \u001b[1m\u001b[32m[1, 3]\u001b[39m\u001b[22m\n",
       "      - LightGraphs.out_neighbors({3, 2} undirected simple Int64 graph, 1) => \u001b[1m\u001b[32m[2]\u001b[39m\u001b[22m\n",
       "      - LightGraphs.out_neighbors({3, 2} undirected simple Int64 graph, 2) => \u001b[1m\u001b[32m[1, 3]\u001b[39m\u001b[22m\n"
      ]
     },
     "execution_count": 11,
     "metadata": {},
     "output_type": "execute_result"
    }
   ],
   "source": [
    "# Get rid of the `fadj` calls\n",
    "filter(trace->trace.func != LightGraphs.SimpleGraphs.fadj, trace_walk)"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 55,
   "metadata": {},
   "outputs": [
    {
     "data": {
      "text/html": [
       "<pre style=\"display: inline; \"><a href=\"https://github.com/cstjean/TraceCalls.jl/tree/7b29d8bdc58caba686e98e75ccf856ce20486d12//src/TraceCalls.jl#L311\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">#17</a>() => <b><font color=green>[<font color=red>2</font>,1,<font color=red>2</font>,1,<font color=red>2</font>]</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaGraphs/LightGraphs.jl/tree/e8a7726b30d9557ad5abd3a63c2084b76c8157ad//src/traversals/randomwalks.jl#L8\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">LightGraphs.randomwalk</a>(AnyOldGraph, 2, 5) => <b><font color=green>[<font color=red>2</font>,1,<font color=red>2</font>,1,<font color=red>2</font>]</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline; background-color:greenyellow\"><a href=\"https://github.com/JuliaGraphs/LightGraphs.jl/tree/e8a7726b30d9557ad5abd3a63c2084b76c8157ad//src/graphtypes/simplegraphs/SimpleGraphs.jl#L65\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">LightGraphs.out_neighbors</a>(AnyOldGraph, 2) => <b><font color=green>[1,3]</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaGraphs/LightGraphs.jl/tree/e8a7726b30d9557ad5abd3a63c2084b76c8157ad//src/graphtypes/simplegraphs/SimpleGraphs.jl#L51\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">LightGraphs.SimpleGraphs.fadj</a>(AnyOldGraph, 2) => <b><font color=green>[1,3]</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li></ul></li><li><pre style=\"display: inline; background-color:greenyellow\"><a href=\"https://github.com/JuliaGraphs/LightGraphs.jl/tree/e8a7726b30d9557ad5abd3a63c2084b76c8157ad//src/graphtypes/simplegraphs/SimpleGraphs.jl#L65\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">LightGraphs.out_neighbors</a>(AnyOldGraph, 2) => <b><font color=green>[1,3]</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaGraphs/LightGraphs.jl/tree/e8a7726b30d9557ad5abd3a63c2084b76c8157ad//src/graphtypes/simplegraphs/SimpleGraphs.jl#L51\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">LightGraphs.SimpleGraphs.fadj</a>(AnyOldGraph, 2) => <b><font color=green>[1,3]</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li></ul></li><li><pre style=\"display: inline; background-color:greenyellow\"><a href=\"https://github.com/JuliaGraphs/LightGraphs.jl/tree/e8a7726b30d9557ad5abd3a63c2084b76c8157ad//src/graphtypes/simplegraphs/SimpleGraphs.jl#L65\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">LightGraphs.out_neighbors</a>(AnyOldGraph, 2) => <b><font color=green>[1,3]</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaGraphs/LightGraphs.jl/tree/e8a7726b30d9557ad5abd3a63c2084b76c8157ad//src/graphtypes/simplegraphs/SimpleGraphs.jl#L51\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">LightGraphs.SimpleGraphs.fadj</a>(AnyOldGraph, 2) => <b><font color=green>[1,3]</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li></ul></li></ul></li></ul>"
      ],
      "text/plain": [
       "- \n",
       "   - \n",
       "      - \n",
       "         - \n",
       "      - \n",
       "         - \n",
       "      - \n",
       "         - \n"
      ]
     },
     "execution_count": 55,
     "metadata": {},
     "output_type": "execute_result"
    }
   ],
   "source": [
    "# Focus on the callers and callees of `LightGraphs.out_neighbors(AnyOldGraph, 2)`\n",
    "filter_lineage(trace -> trace.func==out_neighbors && trace[:v]==2, \n",
    "               trace_walk; highlight=true)"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "`map(f, trace)` applies `f` (whether a function or quoted macro such as `:@which`) to each `Trace`, and stores the result in `Trace`'s `value` field. "
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 14,
   "metadata": {},
   "outputs": [
    {
     "data": {
      "text/html": [
       "<pre style=\"display: inline\"><a href=\"https://github.com/cstjean/TraceCalls.jl/tree/840dc236a17d421c208f2867a01087db5793032f//src/TraceCalls.jl#L279\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">#21</a>() => <b><font color=green>nothing</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline\"><a href=\"https://github.com/JuliaGraphs/LightGraphs.jl/tree/dccaac4faf9e25c5ec592242c0cf9866fd081ac0//src/graphtypes/simplegraphs/SimpleGraphs.jl#L65\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">LightGraphs.out_neighbors</a>(AnyOldGraph, 2) => <b><font color=green>2</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li><li><pre style=\"display: inline\"><a href=\"https://github.com/JuliaGraphs/LightGraphs.jl/tree/dccaac4faf9e25c5ec592242c0cf9866fd081ac0//src/graphtypes/simplegraphs/SimpleGraphs.jl#L65\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">LightGraphs.out_neighbors</a>(AnyOldGraph, 3) => <b><font color=green>3</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li><li><pre style=\"display: inline\"><a href=\"https://github.com/JuliaGraphs/LightGraphs.jl/tree/dccaac4faf9e25c5ec592242c0cf9866fd081ac0//src/graphtypes/simplegraphs/SimpleGraphs.jl#L65\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">LightGraphs.out_neighbors</a>(AnyOldGraph, 2) => <b><font color=green>2</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li><li><pre style=\"display: inline\"><a href=\"https://github.com/JuliaGraphs/LightGraphs.jl/tree/dccaac4faf9e25c5ec592242c0cf9866fd081ac0//src/graphtypes/simplegraphs/SimpleGraphs.jl#L65\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">LightGraphs.out_neighbors</a>(AnyOldGraph, 1) => <b><font color=green>1</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li><li><pre style=\"display: inline\"><a href=\"https://github.com/JuliaGraphs/LightGraphs.jl/tree/dccaac4faf9e25c5ec592242c0cf9866fd081ac0//src/graphtypes/simplegraphs/SimpleGraphs.jl#L65\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">LightGraphs.out_neighbors</a>(AnyOldGraph, 2) => <b><font color=green>2</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li></ul>"
      ],
      "text/plain": [
       "- #21() => nothing\n",
       "   - LightGraphs.out_neighbors({3, 2} undirected simple Int64 graph, 2) => 2\n",
       "   - LightGraphs.out_neighbors({3, 2} undirected simple Int64 graph, 3) => 3\n",
       "   - LightGraphs.out_neighbors({3, 2} undirected simple Int64 graph, 2) => 2\n",
       "   - LightGraphs.out_neighbors({3, 2} undirected simple Int64 graph, 1) => 1\n",
       "   - LightGraphs.out_neighbors({3, 2} undirected simple Int64 graph, 2) => 2\n"
      ]
     },
     "execution_count": 14,
     "metadata": {},
     "output_type": "execute_result"
    }
   ],
   "source": [
    "# Take the second argument of every call to LightGraphs.out_neighbors\n",
    "map(trace->trace.func == LightGraphs.out_neighbors ? trace.args[2] : nothing,\n",
    "    filter(trace->trace.func == LightGraphs.out_neighbors, trace_walk))"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "`objects_in(trace)` returns all passed arguments and the return value as a vector. For example, `filter(tr->any(x==3.1 for x in objects_in(tr)), trace)` keeps all calls that contain the value `3.1`. `collect(trace)` returns a `Vector` of all `Trace` objects in `trace`. "
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "# Saving traces to disk\n",
    "\n",
    "Traces can be saved and reloaded with [JLD2.jl](https://github.com/simonster/JLD2.jl):\n",
    "\n",
    "```julia\n",
    "using TraceCalls, JLD2, FileIO\n",
    "save(\"test.jld2\", \"tracing_foo\", some_trace)\n",
    "reloaded_trace = load(\"test.jld2\", \"tracing_foo\")\n",
    "```\n",
    "\n",
    "Notes: \n",
    "\n",
    "- JLD2.jl will save closures without error, but when they are reloaded (as `ReconstructedTypes` instances), they will usually not be callable.\n",
    "- Before loading a trace, make sure to `import/using` all the modules defining the types and functions that the saved trace refers to."
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "# Working with mutable state\n",
    "\n",
    "By default, `@trace` stores the function call's arguments without copying them. This can yield surprising results when tracing functions that modify their arguments. Consider generating a vector of `n` 5s using `push!`:"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 15,
   "metadata": {},
   "outputs": [
    {
     "data": {
      "text/html": [
       "<pre style=\"display: inline\"><a href=\"https://github.com/cstjean/TraceCalls.jl/tree/840dc236a17d421c208f2867a01087db5793032f//src/TraceCalls.jl#L275\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">#31</a>() => <b><font color=green>[5,5,5]</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline\">many_5s(3) => <b><font color=green>[5,5,5]</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline\">push5!([5,5,5]) => <b><font color=green>[5,5,5]</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li><li><pre style=\"display: inline\">push5!([5,5,5]) => <b><font color=green>[5,5,5]</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li><li><pre style=\"display: inline\">push5!([5,5,5]) => <b><font color=green>[5,5,5]</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li></ul></li></ul>"
      ],
      "text/plain": [
       "- #31() => [5, 5, 5]\n",
       "   - many_5s(3) => [5, 5, 5]\n",
       "      - push5!([5, 5, 5]) => [5, 5, 5]\n",
       "      - push5!([5, 5, 5]) => [5, 5, 5]\n",
       "      - push5!([5, 5, 5]) => [5, 5, 5]\n"
      ]
     },
     "execution_count": 15,
     "metadata": {},
     "output_type": "execute_result"
    }
   ],
   "source": [
    "@traceable push5!(vec::Vector) = push!(vec, 5)\n",
    "@traceable function many_5s(n)\n",
    "    vec = Int[]\n",
    "    for i in 1:n\n",
    "        push5!(vec)\n",
    "    end\n",
    "    return vec\n",
    "end\n",
    "\n",
    "@trace many_5s(3)"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "When `push5!` was first called, `vec` was empty, but this trace makes it look like it already had three 5s in it. This is because all vectors in that trace are [the same object](http://www.johnmyleswhite.com/notebook/2014/09/06/values-vs-bindings-the-map-is-not-the-territory/). You can fix this (if you care) by telling TraceCalls to make a copy of every vector argument and return value:"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 16,
   "metadata": {},
   "outputs": [
    {
     "data": {
      "text/html": [
       "<pre style=\"display: inline\"><a href=\"https://github.com/cstjean/TraceCalls.jl/tree/840dc236a17d421c208f2867a01087db5793032f//src/TraceCalls.jl#L275\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">#33</a>() => <b><font color=green>[5,5,5]</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline\">many_5s(3) => <b><font color=green>[5,5,5]</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline\">push5!([]) => <b><font color=green>[5]</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li><li><pre style=\"display: inline\">push5!([5]) => <b><font color=green>[5,5]</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li><li><pre style=\"display: inline\">push5!([5,5]) => <b><font color=green>[5,5,5]</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li></ul></li></ul>"
      ],
      "text/plain": [
       "- #33() => [5, 5, 5]\n",
       "   - many_5s(3) => [5, 5, 5]\n",
       "      - push5!(Int64[]) => [5]\n",
       "      - push5!([5]) => [5, 5]\n",
       "      - push5!([5, 5]) => [5, 5, 5]\n"
      ]
     },
     "execution_count": 16,
     "metadata": {},
     "output_type": "execute_result"
    }
   ],
   "source": [
    "TraceCalls.store(x::Vector) = copy(x)    # the default is `store(x) = x`\n",
    "@trace many_5s(3)"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "Alternatively, it's sometimes simpler to filter out all mutating functions:"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 17,
   "metadata": {},
   "outputs": [
    {
     "data": {
      "text/html": [
       "<pre style=\"display: inline\"><a href=\"https://github.com/cstjean/TraceCalls.jl/tree/840dc236a17d421c208f2867a01087db5793032f//src/TraceCalls.jl#L275\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">#35</a>() => <b><font color=green>[5,5,5]</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline\">many_5s(3) => <b><font color=green>[5,5,5]</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li></ul>"
      ],
      "text/plain": [
       "- #35() => [5, 5, 5]\n",
       "   - many_5s(3) => [5, 5, 5]\n"
      ]
     },
     "execution_count": 17,
     "metadata": {},
     "output_type": "execute_result"
    }
   ],
   "source": [
    "tr = @trace many_5s(3)\n",
    "filter(!is_mutating, tr)    # filter out every function that ends with a ! (see https://docs.julialang.org/en/stable/manual/style-guide/#Append-!-to-names-of-functions-that-modify-their-arguments-1)"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "The most drastic solution is to have TraceCalls store the text/HTML representation of each value:\n",
    "\n",
    "```julia\n",
    "TraceCalls.store(x) = REPR(x)\n",
    "```\n",
    "\n",
    "This essentially turns TraceCalls.jl into a traditional, non-inspectable tracing package, but it guarantees that each value is shown as it was when the call was made."
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "# Debugging with traces\n",
    "\n",
    "The starting point for debugging exceptions is `@stacktrace`. It works like `@trace`, but uses `filter` to keep only the part of the trace involved in the exception."
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 18,
   "metadata": {},
   "outputs": [
    {
     "data": {
      "text/html": [
       "<pre style=\"display: inline\"><a href=\"https://github.com/cstjean/TraceCalls.jl/tree/840dc236a17d421c208f2867a01087db5793032f//src/TraceCalls.jl#L279\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">#37</a>() => <font color=red>DomainError()</font></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline\"><a href=\"https://github.com/JuliaNLSolvers/Optim.jl/tree/250b50ab5f9bb87576c623fa20fdafb981ce40a1//src/optimize.jl#L91\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">Optim.optimize</a>(logplus10, [0.0], Optim.BFGS{LineSearches.#hagerzhang!,Optim.##115#119}(LineSearches.hagerzhang!, Optim.#115, true), Optim.Options{Void}(1.0e-32, 1.0e-32, 1.0e-8, false, 1000, false, false, false, false, 1, nothing, NaN)) => <font color=red>DomainError()</font></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline\"><a href=\"https://github.com/JuliaNLSolvers/Optim.jl/tree/250b50ab5f9bb87576c623fa20fdafb981ce40a1//src/optimize.jl#L165\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">Optim.optimize</a>(Optim.OnceDifferentiable(logplus10, Optim.g!, Optim.fg!), [0.0], Optim.BFGS{LineSearches.#hagerzhang!,Optim.##115#119}(LineSearches.hagerzhang!, Optim.#115, true), Optim.Options{Void}(1.0e-32, 1.0e-32, 1.0e-8, false, 1000, false, false, false, false, 1, nothing, NaN)) => <font color=red>DomainError()</font></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline\"><a href=\"https://github.com/JuliaNLSolvers/Optim.jl/tree/250b50ab5f9bb87576c623fa20fdafb981ce40a1//src/bfgs.jl#L64\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">Optim.update_state!</a>(Optim.OnceDifferentiable(logplus10, Optim.g!, Optim.fg!), Optim.BFGSState{Float64,1,Array{Float64,1}}(\"BFGS\", 1, [0.0], 2.302585092994046, 1, 1, 0, [NaN], [0.1], [0.1], NaN, [2.37575e-314], [1.69069e-320], [NaN], [1.0], [-0.1], [-12.4999], [0.133333], 1.0, false, LineSearches.LineSearchResults{Float64}([0.0, 1.0, 5.0, 25.0], [2.30259, 2.29253, 2.25129, 2.0149], [-0.01, -0.010101, -0.0105263, -0.0133333], 0)), Optim.BFGS{LineSearches.#hagerzhang!,Optim.##115#119}(LineSearches.hagerzhang!, Optim.#115, true)) => <font color=red>DomainError()</font></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline\"><a href=\"https://github.com/JuliaNLSolvers/Optim.jl/tree/250b50ab5f9bb87576c623fa20fdafb981ce40a1//src/utilities/perform_linesearch.jl#L63\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">Optim.perform_linesearch!</a>(Optim.BFGSState{Float64,1,Array{Float64,1}}(\"BFGS\", 1, [0.0], 2.302585092994046, 1, 1, 0, [NaN], [0.1], [0.1], NaN, [2.37575e-314], [1.69069e-320], [NaN], [1.0], [-0.1], [-12.4999], [0.133333], 1.0, false, LineSearches.LineSearchResults{Float64}([0.0, 1.0, 5.0, 25.0], [2.30259, 2.29253, 2.25129, 2.0149], [-0.01, -0.010101, -0.0105263, -0.0133333], 0)), Optim.BFGS{LineSearches.#hagerzhang!,Optim.##115#119}(LineSearches.hagerzhang!, Optim.#115, true), Optim.OnceDifferentiable(logplus10, Optim.g!, Optim.fg!)) => <font color=red>DomainError()</font></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline\"><a href=\"https://github.com/johnmyleswhite/Calculus.jl/tree/f7b5556a9ebd0cdde45f15d1b2cde331fe5efdd4//src/finite_difference.jl#L105\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">Calculus.finite_difference!</a>(logplus10, [-12.5], [0.133333], :central) => <font color=red>DomainError()</font></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline\">logplus10([-12.4999]) => <font color=red>DomainError()</font></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li></ul></li></ul></li></ul></li></ul></li></ul></li></ul>"
      ],
      "text/plain": [
       "- #37() => DomainError()\n",
       "   - Optim.optimize(logplus10, [0.0], Optim.BFGS{LineSearches.#hagerzhang!,Optim.##115#119}(LineSearches.hagerzhang!, Optim.#115, true), Optim.Options{Void}(1.0e-32, 1.0e-32, 1.0e-8, false, 1000, false, false, false, false, 1, nothing, NaN)) => DomainError()\n",
       "      - Optim.optimize(Optim.OnceDifferentiable(logplus10, Optim.g!, Optim.fg!), [0.0], Optim.BFGS{LineSearches.#hagerzhang!,Optim.##115#119}(LineSearches.hagerzhang!, Optim.#115, true), Optim.Options{Void}(1.0e-32, 1.0e-32, 1.0e-8, false, 1000, false, false, false, false, 1, nothing, NaN)) => DomainError()\n",
       "         - Optim.update_state!(Optim.OnceDifferentiable(logplus10, Optim.g!, Optim.fg!), Optim.BFGSState{Float64,1,Array{Float64,1}}(\"BFGS\", 1, [0.0], 2.302585092994046, 1, 1, 0, [NaN], [0.1], [0.1], NaN, [2.37575e-314], [1.69069e-320], [NaN], [1.0], [-0.1], [-12.4999], [0.133333], 1.0, false, LineSearches.LineSearchResults{Float64}([0.0, 1.0, 5.0, 25.0], [2.30259, 2.29253, 2.25129, 2.0149], [-0.01, -0.010101, -0.0105263, -0.0133333], 0)), Optim.BFGS{LineSearches.#hagerzhang!,Optim.##115#119}(LineSearches.hagerzhang!, Optim.#115, true)) => DomainError()\n",
       "            - Optim.perform_linesearch!(Optim.BFGSState{Float64,1,Array{Float64,1}}(\"BFGS\", 1, [0.0], 2.302585092994046, 1, 1, 0, [NaN], [0.1], [0.1], NaN, [2.37575e-314], [1.69069e-320], [NaN], [1.0], [-0.1], [-12.4999], [0.133333], 1.0, false, LineSearches.LineSearchResults{Float64}([0.0, 1.0, 5.0, 25.0], [2.30259, 2.29253, 2.25129, 2.0149], [-0.01, -0.010101, -0.0105263, -0.0133333], 0)), Optim.BFGS{LineSearches.#hagerzhang!,Optim.##115#119}(LineSearches.hagerzhang!, Optim.#115, true), Optim.OnceDifferentiable(logplus10, Optim.g!, Optim.fg!)) => DomainError()\n",
       "               - Calculus.finite_difference!(logplus10, [-12.5], [0.133333], :central) => DomainError()\n",
       "                  - logplus10([-12.4999]) => DomainError()\n"
      ]
     },
     "execution_count": 18,
     "metadata": {},
     "output_type": "execute_result"
    }
   ],
   "source": [
    "using Optim, TraceCalls\n",
    "@traceable logplus10(x) = log(x[1]+10)\n",
    "TraceCalls.store(v::Vector) = copy(v)\n",
    "\n",
    "# Minimize the function x -> log(x[1]+10) starting at x = 0\n",
    "strace = @stacktrace (Optim, Calculus) optimize(logplus10, [0.0], BFGS())"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "Then we can zoom in on the most interesting part of the stack-trace: "
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 19,
   "metadata": {},
   "outputs": [
    {
     "data": {
      "text/html": [
       "<pre style=\"display: inline\"><a href=\"https://github.com/JuliaNLSolvers/Optim.jl/tree/250b50ab5f9bb87576c623fa20fdafb981ce40a1//src/utilities/perform_linesearch.jl#L63\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">Optim.perform_linesearch!</a>(Optim.BFGSState{Float64,1,Array{Float64,1}}(\"BFGS\", 1, [0.0], 2.302585092994046, 1, 1, 0, [NaN], [0.1], [0.1], NaN, [2.37575e-314], [1.69069e-320], [NaN], [1.0], [-0.1], [-12.4999], [0.133333], 1.0, false, LineSearches.LineSearchResults{Float64}([0.0, 1.0, 5.0, 25.0], [2.30259, 2.29253, 2.25129, 2.0149], [-0.01, -0.010101, -0.0105263, -0.0133333], 0)), Optim.BFGS{LineSearches.#hagerzhang!,Optim.##115#119}(LineSearches.hagerzhang!, Optim.#115, true), Optim.OnceDifferentiable(logplus10, Optim.g!, Optim.fg!)) => <font color=red>DomainError()</font></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline\"><a href=\"https://github.com/johnmyleswhite/Calculus.jl/tree/f7b5556a9ebd0cdde45f15d1b2cde331fe5efdd4//src/finite_difference.jl#L105\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">Calculus.finite_difference!</a>(logplus10, [-12.5], [0.133333], :central) => <font color=red>DomainError()</font></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline\">logplus10([-12.4999]) => <font color=red>DomainError()</font></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li></ul></li></ul>"
      ],
      "text/plain": [
       "- Optim.perform_linesearch!(Optim.BFGSState{Float64,1,Array{Float64,1}}(\"BFGS\", 1, [0.0], 2.302585092994046, 1, 1, 0, [NaN], [0.1], [0.1], NaN, [2.37575e-314], [1.69069e-320], [NaN], [1.0], [-0.1], [-12.4999], [0.133333], 1.0, false, LineSearches.LineSearchResults{Float64}([0.0, 1.0, 5.0, 25.0], [2.30259, 2.29253, 2.25129, 2.0149], [-0.01, -0.010101, -0.0105263, -0.0133333], 0)), Optim.BFGS{LineSearches.#hagerzhang!,Optim.##115#119}(LineSearches.hagerzhang!, Optim.#115, true), Optim.OnceDifferentiable(logplus10, Optim.g!, Optim.fg!)) => DomainError()\n",
       "   - Calculus.finite_difference!(logplus10, [-12.5], [0.133333], :central) => DomainError()\n",
       "      - logplus10([-12.4999]) => DomainError()\n"
      ]
     },
     "execution_count": 19,
     "metadata": {},
     "output_type": "execute_result"
    }
   ],
   "source": [
    "strace[1,1,1,1]   # could also use `strace[bottom-2]`, or `strace[top+4]` --- bottom/top are special values like `end`"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "Calling a `Trace` object performs its computation. By tracing `strace[1,1,1,1]()`, we get the full trace for this part of the computation:"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 20,
   "metadata": {},
   "outputs": [
    {
     "data": {
      "text/html": [
       "<pre style=\"display: inline\"><a href=\"https://github.com/cstjean/TraceCalls.jl/tree/840dc236a17d421c208f2867a01087db5793032f//src/TraceCalls.jl#L279\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">#39</a>() => <font color=red>DomainError()</font></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline\"><a href=\"https://github.com/JuliaNLSolvers/Optim.jl/tree/250b50ab5f9bb87576c623fa20fdafb981ce40a1//src/utilities/perform_linesearch.jl#L63\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">Optim.perform_linesearch!</a>(Optim.BFGSState{Float64,1,Array{Float64,1}}(\"BFGS\", 1, [0.0], 2.302585092994046, 1, 1, 0, [NaN], [0.1], [0.1], NaN, [2.37575e-314], [1.69069e-320], [NaN], [1.0], [-0.1], [-12.4999], [0.133333], 1.0, false, LineSearches.LineSearchResults{Float64}([0.0, 1.0, 5.0, 25.0], [2.30259, 2.29253, 2.25129, 2.0149], [-0.01, -0.010101, -0.0105263, -0.0133333], 0)), Optim.BFGS{LineSearches.#hagerzhang!,Optim.##115#119}(LineSearches.hagerzhang!, Optim.#115, true), Optim.OnceDifferentiable(logplus10, Optim.g!, Optim.fg!)) => <font color=red>DomainError()</font></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline\"><a href=\"https://github.com/JuliaNLSolvers/Optim.jl/tree/250b50ab5f9bb87576c623fa20fdafb981ce40a1//src/utilities/perform_linesearch.jl#L4\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">Optim.checked_dphi0!</a>(Optim.BFGSState{Float64,1,Array{Float64,1}}(\"BFGS\", 1, [0.0], 2.302585092994046, 1, 1, 0, [NaN], [0.1], [0.1], NaN, [2.37575e-314], [1.69069e-320], [NaN], [1.0], [-0.1], [-12.4999], [0.133333], 1.0, false, LineSearches.LineSearchResults{Float64}([0.0, 1.0, 5.0, 25.0], [2.30259, 2.29253, 2.25129, 2.0149], [-0.01, -0.010101, -0.0105263, -0.0133333], 0)), Optim.BFGS{LineSearches.#hagerzhang!,Optim.##115#119}(LineSearches.hagerzhang!, Optim.#115, true)) => <b><font color=green>-0.009999999996070853</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li><li><pre style=\"display: inline\"><a href=\"https://github.com/JuliaNLSolvers/Optim.jl/tree/250b50ab5f9bb87576c623fa20fdafb981ce40a1//src/utilities/perform_linesearch.jl#L51\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">Optim.alphaguess!</a>(Optim.BFGSState{Float64,1,Array{Float64,1}}(\"BFGS\", 1, [0.0], 2.302585092994046, 1, 1, 0, [NaN], [0.1], [0.1], NaN, [2.37575e-314], [1.69069e-320], [NaN], [1.0], [-0.1], [-12.4999], [0.133333], 1.0, false, LineSearches.LineSearchResults{Float64}([0.0, 1.0, 5.0, 25.0], [2.30259, 2.29253, 2.25129, 2.0149], [-0.01, -0.010101, -0.0105263, -0.0133333], 0)), Optim.BFGS{LineSearches.#hagerzhang!,Optim.##115#119}(LineSearches.hagerzhang!, Optim.#115, true), -0.009999999996070853, Optim.OnceDifferentiable(logplus10, Optim.g!, Optim.fg!)) => <b><font color=green>1.0</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li><li><pre style=\"display: inline\"><a href=\"https://github.com/johnmyleswhite/Calculus.jl/tree/f7b5556a9ebd0cdde45f15d1b2cde331fe5efdd4//src/finite_difference.jl#L105\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">Calculus.finite_difference!</a>(logplus10, [-0.1], [0.133333], :central) => <b><font color=green>nothing</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline\">logplus10([-0.0999939]) => <b><font color=green>2.2925353688044074</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li><li><pre style=\"display: inline\">logplus10([-0.100006]) => <b><font color=green>2.2925341454802757</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li></ul></li><li><pre style=\"display: inline\">logplus10([-0.1]) => <b><font color=green>2.2925347571425285</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li><li><pre style=\"display: inline\"><a href=\"https://github.com/johnmyleswhite/Calculus.jl/tree/f7b5556a9ebd0cdde45f15d1b2cde331fe5efdd4//src/finite_difference.jl#L105\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">Calculus.finite_difference!</a>(logplus10, [-0.5], [0.10101], :central) => <b><font color=green>nothing</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline\">logplus10([-0.499994]) => <b><font color=green>2.25129243603289</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li><li><pre style=\"display: inline\">logplus10([-0.500006]) => <b><font color=green>2.2512911612003736</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li></ul></li><li><pre style=\"display: inline\">logplus10([-0.5]) => <b><font color=green>2.251291798616835</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li><li><pre style=\"display: inline\"><a href=\"https://github.com/johnmyleswhite/Calculus.jl/tree/f7b5556a9ebd0cdde45f15d1b2cde331fe5efdd4//src/finite_difference.jl#L105\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">Calculus.finite_difference!</a>(logplus10, [-2.5], [0.105263], :central) => <b><font color=green>nothing</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline\">logplus10([-2.49998]) => <b><font color=green>2.01490503909053</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li><li><pre style=\"display: inline\">logplus10([-2.50002]) => <b><font color=green>2.0149010021208964</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li></ul></li><li><pre style=\"display: inline\">logplus10([-2.5]) => <b><font color=green>2.0149030206077505</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li><li><pre style=\"display: inline\"><a href=\"https://github.com/johnmyleswhite/Calculus.jl/tree/f7b5556a9ebd0cdde45f15d1b2cde331fe5efdd4//src/finite_difference.jl#L105\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">Calculus.finite_difference!</a>(logplus10, [-12.5], [0.133333], :central) => <font color=red>DomainError()</font></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline\">logplus10([-12.4999]) => <font color=red>DomainError()</font></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li></ul></li></ul></li></ul>"
      ],
      "text/plain": [
       "- #39() => DomainError()\n",
       "   - Optim.perform_linesearch!(Optim.BFGSState{Float64,1,Array{Float64,1}}(\"BFGS\", 1, [0.0], 2.302585092994046, 1, 1, 0, [NaN], [0.1], [0.1], NaN, [2.37575e-314], [1.69069e-320], [NaN], [1.0], [-0.1], [-12.4999], [0.133333], 1.0, false, LineSearches.LineSearchResults{Float64}([0.0, 1.0, 5.0, 25.0], [2.30259, 2.29253, 2.25129, 2.0149], [-0.01, -0.010101, -0.0105263, -0.0133333], 0)), Optim.BFGS{LineSearches.#hagerzhang!,Optim.##115#119}(LineSearches.hagerzhang!, Optim.#115, true), Optim.OnceDifferentiable(logplus10, Optim.g!, Optim.fg!)) => DomainError()\n",
       "      - Optim.checked_dphi0!(Optim.BFGSState{Float64,1,Array{Float64,1}}(\"BFGS\", 1, [0.0], 2.302585092994046, 1, 1, 0, [NaN], [0.1], [0.1], NaN, [2.37575e-314], [1.69069e-320], [NaN], [1.0], [-0.1], [-12.4999], [0.133333], 1.0, false, LineSearches.LineSearchResults{Float64}([0.0, 1.0, 5.0, 25.0], [2.30259, 2.29253, 2.25129, 2.0149], [-0.01, -0.010101, -0.0105263, -0.0133333], 0)), Optim.BFGS{LineSearches.#hagerzhang!,Optim.##115#119}(LineSearches.hagerzhang!, Optim.#115, true)) => -0.009999999996070853\n",
       "      - Optim.alphaguess!(Optim.BFGSState{Float64,1,Array{Float64,1}}(\"BFGS\", 1, [0.0], 2.302585092994046, 1, 1, 0, [NaN], [0.1], [0.1], NaN, [2.37575e-314], [1.69069e-320], [NaN], [1.0], [-0.1], [-12.4999], [0.133333], 1.0, false, LineSearches.LineSearchResults{Float64}([0.0, 1.0, 5.0, 25.0], [2.30259, 2.29253, 2.25129, 2.0149], [-0.01, -0.010101, -0.0105263, -0.0133333], 0)), Optim.BFGS{LineSearches.#hagerzhang!,Optim.##115#119}(LineSearches.hagerzhang!, Optim.#115, true), -0.009999999996070853, Optim.OnceDifferentiable(logplus10, Optim.g!, Optim.fg!)) => 1.0\n",
       "      - Calculus.finite_difference!(logplus10, [-0.1], [0.133333], :central) => nothing\n",
       "         - logplus10([-0.0999939]) => 2.2925353688044074\n",
       "         - logplus10([-0.100006]) => 2.2925341454802757\n",
       "      - logplus10([-0.1]) => 2.2925347571425285\n",
       "      - Calculus.finite_difference!(logplus10, [-0.5], [0.10101], :central) => nothing\n",
       "         - logplus10([-0.499994]) => 2.25129243603289\n",
       "         - logplus10([-0.500006]) => 2.2512911612003736\n",
       "      - logplus10([-0.5]) => 2.251291798616835\n",
       "      - Calculus.finite_difference!(logplus10, [-2.5], [0.105263], :central) => nothing\n",
       "         - logplus10([-2.49998]) => 2.01490503909053\n",
       "         - logplus10([-2.50002]) => 2.0149010021208964\n",
       "      - logplus10([-2.5]) => 2.0149030206077505\n",
       "      - Calculus.finite_difference!(logplus10, [-12.5], [0.133333], :central) => DomainError()\n",
       "         - logplus10([-12.4999]) => DomainError()\n"
      ]
     },
     "execution_count": 20,
     "metadata": {},
     "output_type": "execute_result"
    }
   ],
   "source": [
    "linesearch_trace = @trace (Optim, Calculus) strace[1,1,1,1]()"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "Focusing on just `finite_difference!` shows what happened: the line search keeps going for lower and lower values of `x`, until it tries `log(-12.5+10) == log(-2.5)`, which is a `DomainError`."
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 21,
   "metadata": {},
   "outputs": [
    {
     "data": {
      "text/html": [
       "<pre style=\"display: inline\"><a href=\"https://github.com/cstjean/TraceCalls.jl/tree/840dc236a17d421c208f2867a01087db5793032f//src/TraceCalls.jl#L279\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">#39</a>() => <font color=red>DomainError()</font></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline\"><a href=\"https://github.com/johnmyleswhite/Calculus.jl/tree/f7b5556a9ebd0cdde45f15d1b2cde331fe5efdd4//src/finite_difference.jl#L105\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">Calculus.finite_difference!</a>(logplus10, [-0.1], [0.133333], :central) => <b><font color=green>nothing</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li><li><pre style=\"display: inline\"><a href=\"https://github.com/johnmyleswhite/Calculus.jl/tree/f7b5556a9ebd0cdde45f15d1b2cde331fe5efdd4//src/finite_difference.jl#L105\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">Calculus.finite_difference!</a>(logplus10, [-0.5], [0.10101], :central) => <b><font color=green>nothing</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li><li><pre style=\"display: inline\"><a href=\"https://github.com/johnmyleswhite/Calculus.jl/tree/f7b5556a9ebd0cdde45f15d1b2cde331fe5efdd4//src/finite_difference.jl#L105\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">Calculus.finite_difference!</a>(logplus10, [-2.5], [0.105263], :central) => <b><font color=green>nothing</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li><li><pre style=\"display: inline\"><a href=\"https://github.com/johnmyleswhite/Calculus.jl/tree/f7b5556a9ebd0cdde45f15d1b2cde331fe5efdd4//src/finite_difference.jl#L105\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">Calculus.finite_difference!</a>(logplus10, [-12.5], [0.133333], :central) => <font color=red>DomainError()</font></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li></ul>"
      ],
      "text/plain": [
       "- #39() => DomainError()\n",
       "   - Calculus.finite_difference!(logplus10, [-0.1], [0.133333], :central) => nothing\n",
       "   - Calculus.finite_difference!(logplus10, [-0.5], [0.10101], :central) => nothing\n",
       "   - Calculus.finite_difference!(logplus10, [-2.5], [0.105263], :central) => nothing\n",
       "   - Calculus.finite_difference!(logplus10, [-12.5], [0.133333], :central) => DomainError()\n"
      ]
     },
     "execution_count": 21,
     "metadata": {},
     "output_type": "execute_result"
    }
   ],
   "source": [
    "filter(tr->tr.func==Calculus.finite_difference!, linesearch_trace)"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "We could fix the error (for instance, by changing `logplus10`'s definition) and call `linesearch_trace()` to check that this part of the computation now returns a sensible result.\n",
    "\n",
    "`filter` is useful even when there is no exception to debug. By selecting only certain parts of the trace, it's the TraceCalls equivalent of setting a breakpoint. \n",
    "\n",
    "TraceCalls.jl implements `which(::Trace)` and `edit(::Trace)`. They point to the source location for that function call."
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "#### Debugging test failures\n",
    "\n",
    "When a test used to pass, but now fails after a code change, `compare_past_trace` can be used to highlight the differences."
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 22,
   "metadata": {},
   "outputs": [
    {
     "name": "stdout",
     "output_type": "stream",
     "text": [
      "search: \u001b[1mc\u001b[22m\u001b[1mo\u001b[22m\u001b[1mm\u001b[22m\u001b[1mp\u001b[22m\u001b[1ma\u001b[22m\u001b[1mr\u001b[22m\u001b[1me\u001b[22m\u001b[1m_\u001b[22m\u001b[1mp\u001b[22m\u001b[1ma\u001b[22m\u001b[1ms\u001b[22m\u001b[1mt\u001b[22m\u001b[1m_\u001b[22m\u001b[1mt\u001b[22m\u001b[1mr\u001b[22m\u001b[1ma\u001b[22m\u001b[1mc\u001b[22m\u001b[1me\u001b[22m\n",
      "\n"
     ]
    },
    {
     "data": {
      "text/markdown": [
       "`compare_past_trace(old_trace::Trace; filter_out_equal=true))` reruns every function call in `old_trace`, and shows in red where the new result differs from the old.  If `filter_out_equal==true`, only show the non-equal results. \n"
      ],
      "text/plain": [
       "`compare_past_trace(old_trace::Trace; filter_out_equal=true))` reruns every function call in `old_trace`, and shows in red where the new result differs from the old.  If `filter_out_equal==true`, only show the non-equal results. \n"
      ]
     },
     "execution_count": 22,
     "metadata": {},
     "output_type": "execute_result"
    }
   ],
   "source": [
    "?compare_past_trace"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "To use it:\n",
    "\n",
    "1. Trace the failing test/computation under the correct code (it won't fail, of course)\n",
    "2. `git checkout` the bad code (or make the changes manually - I recommend [git stash](https://git-scm.com/docs/git-stash) for switching back and forth). `TraceCalls` imports `Revise.jl`, so the code changes will take effect automatically.\n",
    "3. Call `compare_past_trace` on the trace from step 1\n",
    "\n",
    "You may also call `compare_past_trace` on an old trace [loaded from disk](#Saving-traces-to-disk)."
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "#### Displaying extra information\n",
    "\n",
    "To display intermediate results in your traces, use `trace_log` instead of `println/@show`:"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 26,
   "metadata": {},
   "outputs": [
    {
     "data": {
      "text/html": [
       "<pre style=\"display: inline\"><a href=\"https://github.com/cstjean/TraceCalls.jl/tree/68a10f7e0d52af0587f8713e307afef00f77e5ff//src/TraceCalls.jl#L283\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">#18</a>() => <b><font color=green>5.0</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline\">hypothenuse_length(3, 4) => <b><font color=green>5.0</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline\">TraceCalls.trace_log(; a2=9, b2=<font color=blue>16</font>) => <b><font color=green>nothing</font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li></ul></li></ul>"
      ],
      "text/plain": [
       "- #18() => 5.0\n",
       "   - hypothenuse_length(3, 4) => 5.0\n",
       "      - TraceCalls.trace_log(; a2=9, b2=16) => nothing\n"
      ]
     },
     "execution_count": 26,
     "metadata": {},
     "output_type": "execute_result"
    }
   ],
   "source": [
    "using TraceCalls\n",
    "\n",
    "@traceable function hypothenuse_length(a, b)\n",
    "    a2 = a * a\n",
    "    b2 = b * b\n",
    "    trace_log(a2=a2, b2=FontColor(:blue, b2))   # FontColor is also useful in Base.show_val or Base.map\n",
    "    return sqrt(a2+b2)\n",
    "end\n",
    "\n",
    "@trace hypothenuse_length(3, 4)"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "# Profiling\n",
    "\n",
    "`measure(:@measuring_macro, trace)` applies the given _quoted_ macro (put a `:` in front of the `@`) to every function call in `trace`. Useful macros/functions are `@allocated` and `@elapsed`, as well as [BenchmarkTools](https://github.com/JuliaCI/BenchmarkTools.jl)' `@belapsed`, `median∘benchmark` and `minimum∘benchmark` (see [here](https://github.com/JuliaCI/BenchmarkTools.jl/blob/master/doc/manual.md#which-estimator-should-i-use)). Because measuring involves rerunning every function call in the trace, it can be slow. A good rule-of-thumb is to use the more accurate `@belapsed` when the code to profile takes less than half a second and the trace is relatively short, and `@elapsed` when it takes less than a minute. When the trace is very large, try the `explore_worst=true` option, which will only profile the worst callee of each call (so the runtime is $O(wd)$ instead of $O(w^d)$). You can also [`prune` or `filter` the trace first](#Manipulating-traces).\n",
    "\n",
    "The output of `measure` is a normal, [explorable and callable](#Manipulating-traces) Trace object. Remember that due to timing fluctuations, even if `f(x)` calls `g(x)`, it does not imply that `@elapsed(f(x)) >= @elapsed(g(x))`."
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 3,
   "metadata": {
    "scrolled": false
   },
   "outputs": [
    {
     "data": {
      "text/html": [
       "<pre style=\"display: inline; \"><a href=\"https://github.com/cstjean/TraceCalls.jl/tree/94fbefaa9c035531006eeebb0c3f8cbde6a4c538//src/TraceCalls.jl#L395\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">#8</a>() => <b><font color=green><font color=ff0000>1.0</font></font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaPy/PyCall.jl/tree/0550f890c86878375f74821a459da41e7cc943f6//src/PyCall.jl#L252\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">getindex</a>(PyObject <module 'math' from '/Users/cedric/.julia/v0.6/Conda/deps/usr/lib/python2.7/lib-dynload/math.so'>, :pi) => <b><font color=green><font color=f70800>0.9699</font></font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaPy/PyCall.jl/tree/0550f890c86878375f74821a459da41e7cc943f6//src/PyCall.jl#L241\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">getindex</a>(PyObject <module 'math' from '/Users/cedric/.julia/v0.6/Conda/deps/usr/lib/python2.7/lib-dynload/math.so'>, \"pi\") => <b><font color=green><font color=1de200>0.114</font></font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaPy/PyCall.jl/tree/0550f890c86878375f74821a459da41e7cc943f6//src/conversions.jl#L800\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">convert</a>(PyCall.PyAny, PyObject 3.141592653589793) => <b><font color=green><font color=bc4300>0.7366</font></font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaPy/PyCall.jl/tree/0550f890c86878375f74821a459da41e7cc943f6//src/conversions.jl#L779\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">PyCall.pytype_query</a>(PyObject 3.141592653589793, PyCall.PyObject) => <b><font color=green><font color=7b8400>0.4832</font></font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaPy/PyCall.jl/tree/0550f890c86878375f74821a459da41e7cc943f6//src/conversions.jl#L691\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">PyCall.pyint_query</a>(PyObject 3.141592653589793) => <b><font color=green><font color=23dc00>0.1354</font></font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaPy/PyCall.jl/tree/0550f890c86878375f74821a459da41e7cc943f6//src/PyCall.jl#L137\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">PyCall.pyisinstance</a>(PyObject 3.141592653589793, Ptr{PyCall.PyObject_struct} @0x000000011ef9cc98) => <b><font color=green><font color=11ee00>0.0663</font></font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaPy/PyCall.jl/tree/0550f890c86878375f74821a459da41e7cc943f6//src/PyCall.jl#L137\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">PyCall.pyisinstance</a>(PyObject 3.141592653589793, Ptr{PyCall.PyObject_struct} @0x000000011ef9eaa8) => <b><font color=green><font color=11ee00>0.06704</font></font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li></ul></li></ul></li><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaPy/PyCall.jl/tree/0550f890c86878375f74821a459da41e7cc943f6//src/conversions.jl#L42\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">convert</a>(Float64, PyObject 3.141592653589793) => <b><font color=green><font color=03fc00>0.009888</font></font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaPy/PyCall.jl/tree/0550f890c86878375f74821a459da41e7cc943f6//src/conversions.jl#L29\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">PyCall.asscalar</a>(PyObject 3.141592653589793) => <b><font color=green><font color=01fe00>0.005534</font></font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li></ul></li></ul></li></ul></li></ul>"
      ],
      "text/plain": [
       "- #8() => \u001b[1m\u001b[32m\u001b[38;2;255;0;0m1.0\u001b[39m\u001b[39m\u001b[22m\n",
       "   - getindex(PyObject <module 'math' from '/Users/cedric/.julia/v0.6/Conda/deps/usr/lib/python2.7/lib-dynload/math.so'>, :pi) => \u001b[1m\u001b[32m\u001b[38;2;247;8;0m0.9699\u001b[39m\u001b[39m\u001b[22m\n",
       "      - getindex(PyObject <module 'math' from '/Users/cedric/.julia/v0.6/Conda/deps/usr/lib/python2.7/lib-dynload/math.so'>, \"pi\") => \u001b[1m\u001b[32m\u001b[38;2;29;226;0m0.114\u001b[39m\u001b[39m\u001b[22m\n",
       "      - convert(PyCall.PyAny, PyObject 3.141592653589793) => \u001b[1m\u001b[32m\u001b[38;2;188;67;0m0.7366\u001b[39m\u001b[39m\u001b[22m\n",
       "         - PyCall.pytype_query(PyObject 3.141592653589793, PyCall.PyObject) => \u001b[1m\u001b[32m\u001b[38;2;123;132;0m0.4832\u001b[39m\u001b[39m\u001b[22m\n",
       "            - PyCall.pyint_query(PyObject 3.141592653589793) => \u001b[1m\u001b[32m\u001b[38;2;35;220;0m0.1354\u001b[39m\u001b[39m\u001b[22m\n",
       "               - PyCall.pyisinstance(PyObject 3.141592653589793, Ptr{PyCall.PyObject_struct} @0x000000011ef9cc98) => \u001b[1m\u001b[32m\u001b[38;2;17;238;0m0.0663\u001b[39m\u001b[39m\u001b[22m\n",
       "               - PyCall.pyisinstance(PyObject 3.141592653589793, Ptr{PyCall.PyObject_struct} @0x000000011ef9eaa8) => \u001b[1m\u001b[32m\u001b[38;2;17;238;0m0.06704\u001b[39m\u001b[39m\u001b[22m\n",
       "         - convert(Float64, PyObject 3.141592653589793) => \u001b[1m\u001b[32m\u001b[38;2;3;252;0m0.009888\u001b[39m\u001b[39m\u001b[22m\n",
       "            - PyCall.asscalar(PyObject 3.141592653589793) => \u001b[1m\u001b[32m\u001b[38;2;1;254;0m0.005534\u001b[39m\u001b[39m\u001b[22m\n"
      ]
     },
     "execution_count": 3,
     "metadata": {},
     "output_type": "execute_result"
    }
   ],
   "source": [
    "## Profile the PyCall code for accessing Python's `math.pi` \n",
    "using PyCall, TraceCalls\n",
    "\n",
    "math = pyimport(:math)\n",
    "trace_pycall = @trace PyCall math[:pi];\n",
    "\n",
    "using BenchmarkTools: @belapsed\n",
    "m_trace = measure(:@belapsed, trace_pycall; normalize=true, threshold=0.005)  # only show/explore calls that take >0.5% of total runtime"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "`normalize(m_trace[1,2,1])` can be used to make the numbers in a subtrace more comparable."
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "#### Type stability\n",
    "\n",
    "`code_warntype(trace_pycall[1,2])` returns the type-annotated code for that function call. Similarly for `code_llvm, code_lowered, code_native` and `code_typed`. `is_inferred(::Trace)` uses the same code as `Base.Test.@inferred`, but returns `true/false`, which is useful with `map`:"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 2,
   "metadata": {},
   "outputs": [
    {
     "data": {
      "text/html": [
       "<pre style=\"display: inline; \"><a href=\"https://github.com/cstjean/TraceCalls.jl/tree/c4ac4819070c1bdd43854554997354c54476fda5//src/TraceCalls.jl#L386\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">#1</a>() => <b><font color=green><font color=red>false</font></font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaPy/PyCall.jl/tree/0550f890c86878375f74821a459da41e7cc943f6//src/PyCall.jl#L252\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">getindex</a>(PyObject <module 'math' from '/Users/cedric/.julia/v0.6/Conda/deps/usr/lib/python2.7/lib-dynload/math.so'>, :pi) => <b><font color=green><font color=red>false</font></font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaPy/PyCall.jl/tree/0550f890c86878375f74821a459da41e7cc943f6//src/PyCall.jl#L241\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">getindex</a>(PyObject <module 'math' from '/Users/cedric/.julia/v0.6/Conda/deps/usr/lib/python2.7/lib-dynload/math.so'>, \"pi\") => <b><font color=green><font color=green>true</font></font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaPy/PyCall.jl/tree/0550f890c86878375f74821a459da41e7cc943f6//src/PyCall.jl#L144\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">Base.unsafe_convert</a>(Ptr{PyCall.PyObject_struct}, PyObject <module 'math' from '/Users/cedric/.julia/v0.6/Conda/deps/usr/lib/python2.7/lib-dynload/math.so'>) => <b><font color=green><font color=green>true</font></font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li></ul></li><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaPy/PyCall.jl/tree/0550f890c86878375f74821a459da41e7cc943f6//src/conversions.jl#L800\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">convert</a>(PyCall.PyAny, PyObject 3.141592653589793) => <b><font color=green><font color=red>false</font></font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaPy/PyCall.jl/tree/0550f890c86878375f74821a459da41e7cc943f6//src/conversions.jl#L779\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">PyCall.pytype_query</a>(PyObject 3.141592653589793, PyCall.PyObject) => <b><font color=green><font color=red>false</font></font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaPy/PyCall.jl/tree/0550f890c86878375f74821a459da41e7cc943f6//src/conversions.jl#L691\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">PyCall.pyint_query</a>(PyObject 3.141592653589793) => <b><font color=green><font color=red>false</font></font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaPy/PyCall.jl/tree/0550f890c86878375f74821a459da41e7cc943f6//src/PyCall.jl#L137\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">PyCall.pyisinstance</a>(PyObject 3.141592653589793, Ptr{PyCall.PyObject_struct} @0x0000000124956c98) => <b><font color=green><font color=green>true</font></font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaPy/PyCall.jl/tree/0550f890c86878375f74821a459da41e7cc943f6//src/PyCall.jl#L144\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">Base.unsafe_convert</a>(Ptr{PyCall.PyObject_struct}, PyObject 3.141592653589793) => <b><font color=green><font color=green>true</font></font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li></ul></li><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaPy/PyCall.jl/tree/0550f890c86878375f74821a459da41e7cc943f6//src/PyCall.jl#L137\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">PyCall.pyisinstance</a>(PyObject 3.141592653589793, Ptr{PyCall.PyObject_struct} @0x0000000124958aa8) => <b><font color=green><font color=green>true</font></font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaPy/PyCall.jl/tree/0550f890c86878375f74821a459da41e7cc943f6//src/PyCall.jl#L144\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">Base.unsafe_convert</a>(Ptr{PyCall.PyObject_struct}, PyObject 3.141592653589793) => <b><font color=green><font color=green>true</font></font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li></ul></li><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaPy/PyCall.jl/tree/0550f890c86878375f74821a459da41e7cc943f6//src/PyCall.jl#L134\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">PyCall.pyisinstance</a>(PyObject 3.141592653589793, PyObject NULL) => <b><font color=green><font color=green>true</font></font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li></ul></li><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaPy/PyCall.jl/tree/0550f890c86878375f74821a459da41e7cc943f6//src/PyCall.jl#L134\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">PyCall.pyisinstance</a>(PyObject 3.141592653589793, PyObject NULL) => <b><font color=green><font color=green>true</font></font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaPy/PyCall.jl/tree/0550f890c86878375f74821a459da41e7cc943f6//src/conversions.jl#L696\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">PyCall.pyfloat_query</a>(PyObject 3.141592653589793) => <b><font color=green><font color=red>false</font></font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaPy/PyCall.jl/tree/0550f890c86878375f74821a459da41e7cc943f6//src/PyCall.jl#L137\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">PyCall.pyisinstance</a>(PyObject 3.141592653589793, Ptr{PyCall.PyObject_struct} @0x0000000124954998) => <b><font color=green><font color=green>true</font></font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaPy/PyCall.jl/tree/0550f890c86878375f74821a459da41e7cc943f6//src/PyCall.jl#L144\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">Base.unsafe_convert</a>(Ptr{PyCall.PyObject_struct}, PyObject 3.141592653589793) => <b><font color=green><font color=green>true</font></font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li></ul></li></ul></li></ul></li><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaPy/PyCall.jl/tree/0550f890c86878375f74821a459da41e7cc943f6//src/conversions.jl#L42\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">convert</a>(Float64, PyObject 3.141592653589793) => <b><font color=green><font color=green>true</font></font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaPy/PyCall.jl/tree/0550f890c86878375f74821a459da41e7cc943f6//src/conversions.jl#L29\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">PyCall.asscalar</a>(PyObject 3.141592653589793) => <b><font color=green><font color=green>true</font></font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaPy/PyCall.jl/tree/0550f890c86878375f74821a459da41e7cc943f6//src/PyCall.jl#L134\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">PyCall.pyisinstance</a>(PyObject 3.141592653589793, PyObject NULL) => <b><font color=green><font color=green>true</font></font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li></ul></li><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaPy/PyCall.jl/tree/0550f890c86878375f74821a459da41e7cc943f6//src/PyCall.jl#L144\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">Base.unsafe_convert</a>(Ptr{PyCall.PyObject_struct}, PyObject 3.141592653589793) => <b><font color=green><font color=green>true</font></font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li><li><pre style=\"display: inline; \"><a href=\"https://github.com/JuliaPy/PyCall.jl/tree/0550f890c86878375f74821a459da41e7cc943f6//src/exception.jl#L55\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">PyCall.pyerr_check</a>(\"ccall(@pysym(:PyFloat_AsDouble), Cdouble, (PyPtr,), asscalar(po))\", 3.141592653589793) => <b><font color=green><font color=green>true</font></font></b></pre><ul style=\"  margin-top: 4px; margin-bottom: 4px;\"></ul></li></ul></li></ul></li></ul></li></ul>"
      ],
      "text/plain": [
       "- #1() => \u001b[1m\u001b[32m\u001b[31mfalse\u001b[39m\u001b[39m\u001b[22m\n",
       "   - getindex(PyObject <module 'math' from '/Users/cedric/.julia/v0.6/Conda/deps/usr/lib/python2.7/lib-dynload/math.so'>, :pi) => \u001b[1m\u001b[32m\u001b[31mfalse\u001b[39m\u001b[39m\u001b[22m\n",
       "      - getindex(PyObject <module 'math' from '/Users/cedric/.julia/v0.6/Conda/deps/usr/lib/python2.7/lib-dynload/math.so'>, \"pi\") => \u001b[1m\u001b[32m\u001b[32mtrue\u001b[39m\u001b[39m\u001b[22m\n",
       "         - Base.unsafe_convert(Ptr{PyCall.PyObject_struct}, PyObject <module 'math' from '/Users/cedric/.julia/v0.6/Conda/deps/usr/lib/python2.7/lib-dynload/math.so'>) => \u001b[1m\u001b[32m\u001b[32mtrue\u001b[39m\u001b[39m\u001b[22m\n",
       "      - convert(PyCall.PyAny, PyObject 3.141592653589793) => \u001b[1m\u001b[32m\u001b[31mfalse\u001b[39m\u001b[39m\u001b[22m\n",
       "         - PyCall.pytype_query(PyObject 3.141592653589793, PyCall.PyObject) => \u001b[1m\u001b[32m\u001b[31mfalse\u001b[39m\u001b[39m\u001b[22m\n",
       "            - PyCall.pyint_query(PyObject 3.141592653589793) => \u001b[1m\u001b[32m\u001b[31mfalse\u001b[39m\u001b[39m\u001b[22m\n",
       "               - PyCall.pyisinstance(PyObject 3.141592653589793, Ptr{PyCall.PyObject_struct} @0x0000000124956c98) => \u001b[1m\u001b[32m\u001b[32mtrue\u001b[39m\u001b[39m\u001b[22m\n",
       "                  - Base.unsafe_convert(Ptr{PyCall.PyObject_struct}, PyObject 3.141592653589793) => \u001b[1m\u001b[32m\u001b[32mtrue\u001b[39m\u001b[39m\u001b[22m\n",
       "               - PyCall.pyisinstance(PyObject 3.141592653589793, Ptr{PyCall.PyObject_struct} @0x0000000124958aa8) => \u001b[1m\u001b[32m\u001b[32mtrue\u001b[39m\u001b[39m\u001b[22m\n",
       "                  - Base.unsafe_convert(Ptr{PyCall.PyObject_struct}, PyObject 3.141592653589793) => \u001b[1m\u001b[32m\u001b[32mtrue\u001b[39m\u001b[39m\u001b[22m\n",
       "               - PyCall.pyisinstance(PyObject 3.141592653589793, PyObject NULL) => \u001b[1m\u001b[32m\u001b[32mtrue\u001b[39m\u001b[39m\u001b[22m\n",
       "            - PyCall.pyisinstance(PyObject 3.141592653589793, PyObject NULL) => \u001b[1m\u001b[32m\u001b[32mtrue\u001b[39m\u001b[39m\u001b[22m\n",
       "            - PyCall.pyfloat_query(PyObject 3.141592653589793) => \u001b[1m\u001b[32m\u001b[31mfalse\u001b[39m\u001b[39m\u001b[22m\n",
       "               - PyCall.pyisinstance(PyObject 3.141592653589793, Ptr{PyCall.PyObject_struct} @0x0000000124954998) => \u001b[1m\u001b[32m\u001b[32mtrue\u001b[39m\u001b[39m\u001b[22m\n",
       "                  - Base.unsafe_convert(Ptr{PyCall.PyObject_struct}, PyObject 3.141592653589793) => \u001b[1m\u001b[32m\u001b[32mtrue\u001b[39m\u001b[39m\u001b[22m\n",
       "         - convert(Float64, PyObject 3.141592653589793) => \u001b[1m\u001b[32m\u001b[32mtrue\u001b[39m\u001b[39m\u001b[22m\n",
       "            - PyCall.asscalar(PyObject 3.141592653589793) => \u001b[1m\u001b[32m\u001b[32mtrue\u001b[39m\u001b[39m\u001b[22m\n",
       "               - PyCall.pyisinstance(PyObject 3.141592653589793, PyObject NULL) => \u001b[1m\u001b[32m\u001b[32mtrue\u001b[39m\u001b[39m\u001b[22m\n",
       "            - Base.unsafe_convert(Ptr{PyCall.PyObject_struct}, PyObject 3.141592653589793) => \u001b[1m\u001b[32m\u001b[32mtrue\u001b[39m\u001b[39m\u001b[22m\n",
       "            - PyCall.pyerr_check(\"ccall(@pysym(:PyFloat_AsDouble), Cdouble, (PyPtr,), asscalar(po))\", 3.141592653589793) => \u001b[1m\u001b[32m\u001b[32mtrue\u001b[39m\u001b[39m\u001b[22m\n"
      ]
     },
     "execution_count": 2,
     "metadata": {},
     "output_type": "execute_result"
    }
   ],
   "source": [
    "redgreen(map(is_inferred, trace_pycall))   # ignore the top-most call - it will always be `false`"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "#### Grouping and benchmarking\n",
    "\n",
    "TraceCalls.jl also provides a flat, more efficient profiling tool: `trace_benchmark`. It groups the calls by their signature (for example, `sin(1.3)` and `sin(2.3)` will be in the same group, but `sin(1)` will be in a different one) and only profiles one of the calls in each group."
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 3,
   "metadata": {
    "scrolled": false
   },
   "outputs": [
    {
     "data": {
      "text/html": [
       "Benchmark\n",
       " <pre>2 calls like <a href=\"https://github.com/JuliaPy/PyCall.jl/tree/0550f890c86878375f74821a459da41e7cc943f6//src/conversions.jl#L800\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">convert</a>(PyCall.PyAny, PyObject 3.141592653589793) => <b><font color=green>TrialEstimate(900.426 ns, 16 bytes)</font></b></pre>\n",
       " <pre>1 call like <a href=\"https://github.com/cstjean/TraceCalls.jl/tree/c4ac4819070c1bdd43854554997354c54476fda5//src/TraceCalls.jl#L386\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">#1</a>() => <b><font color=green>TrialEstimate(1.355 μs, 224 bytes)</font></b></pre>\n",
       " <pre>1 call like <a href=\"https://github.com/JuliaPy/PyCall.jl/tree/0550f890c86878375f74821a459da41e7cc943f6//src/PyCall.jl#L252\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">getindex</a>(PyObject <module 'math' from '/Users/cedric/.julia/v0.6/Conda/deps/usr/lib/python2.7/lib-dynload/math.so'>, :pi) => <b><font color=green>TrialEstimate(1.350 μs, 224 bytes)</font></b></pre>\n",
       " <pre>1 call like <a href=\"https://github.com/JuliaPy/PyCall.jl/tree/0550f890c86878375f74821a459da41e7cc943f6//src/conversions.jl#L779\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">PyCall.pytype_query</a>(PyObject 3.141592653589793, PyCall.PyObject) => <b><font color=green>TrialEstimate(605.153 ns, 0 bytes)</font></b></pre>\n",
       " <pre>3 calls like <a href=\"https://github.com/JuliaPy/PyCall.jl/tree/0550f890c86878375f74821a459da41e7cc943f6//src/PyCall.jl#L137\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">PyCall.pyisinstance</a>(PyObject 3.141592653589793, Ptr{PyCall.PyObject_struct} @0x0000000124956c98) => <b><font color=green>TrialEstimate(86.650 ns, 0 bytes)</font></b></pre>\n",
       " <pre>1 call like <a href=\"https://github.com/JuliaPy/PyCall.jl/tree/0550f890c86878375f74821a459da41e7cc943f6//src/PyCall.jl#L241\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">getindex</a>(PyObject <module 'math' from '/Users/cedric/.julia/v0.6/Conda/deps/usr/lib/python2.7/lib-dynload/math.so'>, \"pi\") => <b><font color=green>TrialEstimate(194.738 ns, 16 bytes)</font></b></pre>\n",
       " <pre>1 call like <a href=\"https://github.com/JuliaPy/PyCall.jl/tree/0550f890c86878375f74821a459da41e7cc943f6//src/conversions.jl#L691\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">PyCall.pyint_query</a>(PyObject 3.141592653589793) => <b><font color=green>TrialEstimate(177.301 ns, 0 bytes)</font></b></pre>\n",
       " <pre>3 calls like <a href=\"https://github.com/JuliaPy/PyCall.jl/tree/0550f890c86878375f74821a459da41e7cc943f6//src/PyCall.jl#L134\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">PyCall.pyisinstance</a>(PyObject 3.141592653589793, PyObject NULL) => <b><font color=green>TrialEstimate(3.368 ns, 0 bytes)</font></b></pre>\n",
       " <pre>5 calls like <a href=\"https://github.com/JuliaPy/PyCall.jl/tree/0550f890c86878375f74821a459da41e7cc943f6//src/PyCall.jl#L144\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">Base.unsafe_convert</a>(Ptr{PyCall.PyObject_struct}, PyObject <module 'math' from '/Users/cedric/.julia/v0.6/Conda/deps/usr/lib/python2.7/lib-dynload/math.so'>) => <b><font color=green>TrialEstimate(1.843 ns, 0 bytes)</font></b></pre>\n",
       " <pre>1 call like <a href=\"https://github.com/JuliaPy/PyCall.jl/tree/0550f890c86878375f74821a459da41e7cc943f6//src/conversions.jl#L29\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">PyCall.asscalar</a>(PyObject 3.141592653589793) => <b><font color=green>TrialEstimate(6.723 ns, 0 bytes)</font></b></pre>\n",
       " <pre>1 call like <a href=\"https://github.com/JuliaPy/PyCall.jl/tree/0550f890c86878375f74821a459da41e7cc943f6//src/exception.jl#L55\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">PyCall.pyerr_check</a>(\"ccall(@pysym(:PyFloat_AsDouble), Cdouble, (PyPtr,), asscalar(po))\", 3.141592653589793) => <b><font color=green>TrialEstimate(5.806 ns, 0 bytes)</font></b></pre>\n",
       " <pre>1 call like <a href=\"https://github.com/JuliaPy/PyCall.jl/tree/0550f890c86878375f74821a459da41e7cc943f6//src/conversions.jl#L696\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">PyCall.pyfloat_query</a>(PyObject 3.141592653589793) => <b><font color=green>TrialEstimate(5.797 ns, 0 bytes)</font></b></pre>\n"
      ],
      "text/plain": [
       "Benchmark\n",
       " 2 calls like convert(PyCall.PyAny, PyObject 3.141592653589793) => \u001b[1m\u001b[32mTrialEstimate(900.426 ns, 16 bytes)\u001b[39m\u001b[22m\n",
       " 1 call like #1() => \u001b[1m\u001b[32mTrialEstimate(1.355 μs, 224 bytes)\u001b[39m\u001b[22m\n",
       " 1 call like getindex(PyObject <module 'math' from '/Users/cedric/.julia/v0.6/Conda/deps/usr/lib/python2.7/lib-dynload/math.so'>, :pi) => \u001b[1m\u001b[32mTrialEstimate(1.350 μs, 224 bytes)\u001b[39m\u001b[22m\n",
       " 1 call like PyCall.pytype_query(PyObject 3.141592653589793, PyCall.PyObject) => \u001b[1m\u001b[32mTrialEstimate(605.153 ns, 0 bytes)\u001b[39m\u001b[22m\n",
       " 3 calls like PyCall.pyisinstance(PyObject 3.141592653589793, Ptr{PyCall.PyObject_struct} @0x0000000124956c98) => \u001b[1m\u001b[32mTrialEstimate(86.650 ns, 0 bytes)\u001b[39m\u001b[22m\n",
       " 1 call like getindex(PyObject <module 'math' from '/Users/cedric/.julia/v0.6/Conda/deps/usr/lib/python2.7/lib-dynload/math.so'>, \"pi\") => \u001b[1m\u001b[32mTrialEstimate(194.738 ns, 16 bytes)\u001b[39m\u001b[22m\n",
       " 1 call like PyCall.pyint_query(PyObject 3.141592653589793) => \u001b[1m\u001b[32mTrialEstimate(177.301 ns, 0 bytes)\u001b[39m\u001b[22m\n",
       " 3 calls like PyCall.pyisinstance(PyObject 3.141592653589793, PyObject NULL) => \u001b[1m\u001b[32mTrialEstimate(3.368 ns, 0 bytes)\u001b[39m\u001b[22m\n",
       " 5 calls like Base.unsafe_convert(Ptr{PyCall.PyObject_struct}, PyObject <module 'math' from '/Users/cedric/.julia/v0.6/Conda/deps/usr/lib/python2.7/lib-dynload/math.so'>) => \u001b[1m\u001b[32mTrialEstimate(1.843 ns, 0 bytes)\u001b[39m\u001b[22m\n",
       " 1 call like PyCall.asscalar(PyObject 3.141592653589793) => \u001b[1m\u001b[32mTrialEstimate(6.723 ns, 0 bytes)\u001b[39m\u001b[22m\n",
       " 1 call like PyCall.pyerr_check(\"ccall(@pysym(:PyFloat_AsDouble), Cdouble, (PyPtr,), asscalar(po))\", 3.141592653589793) => \u001b[1m\u001b[32mTrialEstimate(5.806 ns, 0 bytes)\u001b[39m\u001b[22m\n",
       " 1 call like PyCall.pyfloat_query(PyObject 3.141592653589793) => \u001b[1m\u001b[32mTrialEstimate(5.797 ns, 0 bytes)\u001b[39m\u001b[22m\n"
      ]
     },
     "execution_count": 3,
     "metadata": {},
     "output_type": "execute_result"
    }
   ],
   "source": [
    "using BenchmarkTools    # necessary for trace_benchmark\n",
    "bench = trace_benchmark(trace_pycall)"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "After doing some code changes, you can rerun the same benchmark with `run` (technical note: it will use the same [tuning parameters](https://github.com/JuliaCI/BenchmarkTools.jl/blob/master/doc/manual.md#caching-parameters)). Then [call `ratio` or `judge`](https://github.com/JuliaCI/BenchmarkTools.jl/blob/master/doc/manual.md#trialratio-and-trialjudgement) to get a report on regressions and improvements."
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 4,
   "metadata": {},
   "outputs": [
    {
     "data": {
      "text/html": [
       "Benchmark\n",
       " <pre>1 call like <a href=\"https://github.com/JuliaPy/PyCall.jl/tree/0550f890c86878375f74821a459da41e7cc943f6//src/exception.jl#L55\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">PyCall.pyerr_check</a>(\"ccall(@pysym(:PyFloat_AsDouble), Cdouble, (PyPtr,), asscalar(po))\", 3.141592653589793) => <b><font color=green><font color=black>TrialJudgement(+4.89% => invariant)</font></font></b></pre>\n",
       " <pre>2 calls like <a href=\"https://github.com/JuliaPy/PyCall.jl/tree/0550f890c86878375f74821a459da41e7cc943f6//src/conversions.jl#L800\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">convert</a>(PyCall.PyAny, PyObject 3.141592653589793) => <b><font color=green><font color=black>TrialJudgement(+0.97% => invariant)</font></font></b></pre>\n",
       " <pre>1 call like <a href=\"https://github.com/JuliaPy/PyCall.jl/tree/0550f890c86878375f74821a459da41e7cc943f6//src/conversions.jl#L779\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">PyCall.pytype_query</a>(PyObject 3.141592653589793, PyCall.PyObject) => <b><font color=green><font color=black>TrialJudgement(+0.90% => invariant)</font></font></b></pre>\n",
       " <pre>1 call like <a href=\"https://github.com/JuliaPy/PyCall.jl/tree/0550f890c86878375f74821a459da41e7cc943f6//src/conversions.jl#L691\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">PyCall.pyint_query</a>(PyObject 3.141592653589793) => <b><font color=green><font color=black>TrialJudgement(+0.34% => invariant)</font></font></b></pre>\n",
       " <pre>5 calls like <a href=\"https://github.com/JuliaPy/PyCall.jl/tree/0550f890c86878375f74821a459da41e7cc943f6//src/PyCall.jl#L144\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">Base.unsafe_convert</a>(Ptr{PyCall.PyObject_struct}, PyObject <module 'math' from '/Users/cedric/.julia/v0.6/Conda/deps/usr/lib/python2.7/lib-dynload/math.so'>) => <b><font color=green><font color=black>TrialJudgement(+0.00% => invariant)</font></font></b></pre>\n",
       " <pre>1 call like <a href=\"https://github.com/JuliaPy/PyCall.jl/tree/0550f890c86878375f74821a459da41e7cc943f6//src/conversions.jl#L696\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">PyCall.pyfloat_query</a>(PyObject 3.141592653589793) => <b><font color=green><font color=black>TrialJudgement(+0.00% => invariant)</font></font></b></pre>\n",
       " <pre>3 calls like <a href=\"https://github.com/JuliaPy/PyCall.jl/tree/0550f890c86878375f74821a459da41e7cc943f6//src/PyCall.jl#L134\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">PyCall.pyisinstance</a>(PyObject 3.141592653589793, PyObject NULL) => <b><font color=green><font color=black>TrialJudgement(-0.03% => invariant)</font></font></b></pre>\n",
       " <pre>1 call like <a href=\"https://github.com/JuliaPy/PyCall.jl/tree/0550f890c86878375f74821a459da41e7cc943f6//src/conversions.jl#L29\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">PyCall.asscalar</a>(PyObject 3.141592653589793) => <b><font color=green><font color=black>TrialJudgement(-0.18% => invariant)</font></font></b></pre>\n",
       " <pre>1 call like <a href=\"https://github.com/JuliaPy/PyCall.jl/tree/0550f890c86878375f74821a459da41e7cc943f6//src/PyCall.jl#L241\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">getindex</a>(PyObject <module 'math' from '/Users/cedric/.julia/v0.6/Conda/deps/usr/lib/python2.7/lib-dynload/math.so'>, \"pi\") => <b><font color=green><font color=black>TrialJudgement(-0.49% => invariant)</font></font></b></pre>\n",
       " <pre>1 call like <a href=\"https://github.com/cstjean/TraceCalls.jl/tree/c4ac4819070c1bdd43854554997354c54476fda5//src/TraceCalls.jl#L386\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">#1</a>() => <b><font color=green><font color=black>TrialJudgement(-1.75% => invariant)</font></font></b></pre>\n",
       " <pre>3 calls like <a href=\"https://github.com/JuliaPy/PyCall.jl/tree/0550f890c86878375f74821a459da41e7cc943f6//src/PyCall.jl#L137\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">PyCall.pyisinstance</a>(PyObject 3.141592653589793, Ptr{PyCall.PyObject_struct} @0x0000000124956c98) => <b><font color=green><font color=black>TrialJudgement(-0.97% => invariant)</font></font></b></pre>\n",
       " <pre>1 call like <a href=\"https://github.com/JuliaPy/PyCall.jl/tree/0550f890c86878375f74821a459da41e7cc943f6//src/PyCall.jl#L252\" target=\"_blank\" style=\"color: black; text-decoration: none; border-bottom: 1px #C3C3C3 dotted\">getindex</a>(PyObject <module 'math' from '/Users/cedric/.julia/v0.6/Conda/deps/usr/lib/python2.7/lib-dynload/math.so'>, :pi) => <b><font color=green><font color=green>TrialJudgement(-5.19% => improvement)</font></font></b></pre>\n"
      ],
      "text/plain": [
       "Benchmark\n",
       " 1 call like PyCall.pyerr_check(\"ccall(@pysym(:PyFloat_AsDouble), Cdouble, (PyPtr,), asscalar(po))\", 3.141592653589793) => \u001b[1m\u001b[32m\u001b[91m<error displaying TraceCalls.FontColor instance>\u001b[39m\u001b[39m\u001b[22m\n",
       " 2 calls like convert(PyCall.PyAny, PyObject 3.141592653589793) => \u001b[1m\u001b[32m\u001b[91m<error displaying TraceCalls.FontColor instance>\u001b[39m\u001b[39m\u001b[22m\n",
       " 1 call like PyCall.pytype_query(PyObject 3.141592653589793, PyCall.PyObject) => \u001b[1m\u001b[32m\u001b[91m<error displaying TraceCalls.FontColor instance>\u001b[39m\u001b[39m\u001b[22m\n",
       " 1 call like PyCall.pyint_query(PyObject 3.141592653589793) => \u001b[1m\u001b[32m\u001b[91m<error displaying TraceCalls.FontColor instance>\u001b[39m\u001b[39m\u001b[22m\n",
       " 5 calls like Base.unsafe_convert(Ptr{PyCall.PyObject_struct}, PyObject <module 'math' from '/Users/cedric/.julia/v0.6/Conda/deps/usr/lib/python2.7/lib-dynload/math.so'>) => \u001b[1m\u001b[32m\u001b[91m<error displaying TraceCalls.FontColor instance>\u001b[39m\u001b[39m\u001b[22m\n",
       " 1 call like PyCall.pyfloat_query(PyObject 3.141592653589793) => \u001b[1m\u001b[32m\u001b[91m<error displaying TraceCalls.FontColor instance>\u001b[39m\u001b[39m\u001b[22m\n",
       " 3 calls like PyCall.pyisinstance(PyObject 3.141592653589793, PyObject NULL) => \u001b[1m\u001b[32m\u001b[91m<error displaying TraceCalls.FontColor instance>\u001b[39m\u001b[39m\u001b[22m\n",
       " 1 call like PyCall.asscalar(PyObject 3.141592653589793) => \u001b[1m\u001b[32m\u001b[91m<error displaying TraceCalls.FontColor instance>\u001b[39m\u001b[39m\u001b[22m\n",
       " 1 call like getindex(PyObject <module 'math' from '/Users/cedric/.julia/v0.6/Conda/deps/usr/lib/python2.7/lib-dynload/math.so'>, \"pi\") => \u001b[1m\u001b[32m\u001b[91m<error displaying TraceCalls.FontColor instance>\u001b[39m\u001b[39m\u001b[22m\n",
       " 1 call like #1() => \u001b[1m\u001b[32m\u001b[91m<error displaying TraceCalls.FontColor instance>\u001b[39m\u001b[39m\u001b[22m\n",
       " 3 calls like PyCall.pyisinstance(PyObject 3.141592653589793, Ptr{PyCall.PyObject_struct} @0x0000000124956c98) => \u001b[1m\u001b[32m\u001b[91m<error displaying TraceCalls.FontColor instance>\u001b[39m\u001b[39m\u001b[22m\n",
       " 1 call like getindex(PyObject <module 'math' from '/Users/cedric/.julia/v0.6/Conda/deps/usr/lib/python2.7/lib-dynload/math.so'>, :pi) => \u001b[1m\u001b[32m\u001b[91m<error displaying TraceCalls.FontColor instance>\u001b[39m\u001b[39m\u001b[22m\n"
      ]
     },
     "execution_count": 4,
     "metadata": {},
     "output_type": "execute_result"
    }
   ],
   "source": [
    "bench_new = run(bench);\n",
    "judge(bench_new, bench; sort=true)"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "It's possible to save the benchmark to disk, but [please read these notes carefully](#Saving-traces-to-disk). The reloaded benchmark is likely to have one or more \"broken\" closure, and those will show up in the `run/judge` outputs as red exceptions (which can usually be ignored)."
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "#### Profiling the compiler\n",
    "\n",
    "Parametric types sometimes trigger very long compilation times. You can use `@compilation_times to_trace expr` to estimate each method's total compilation time (in seconds). _This is very, very approximate and experimental_. This macro has the [same syntax and limitations](#Syntax) as `@trace`. It will estimate the compilation time of every method specialization that appears in `@trace to_trace expr`. It is based on `precompile` and is [subject to precompile's limitations](https://github.com/JuliaLang/julia/issues/23548) (notably, keyword-argument functions are essentially ignored)."
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 4,
   "metadata": {},
   "outputs": [
    {
     "data": {
      "text/plain": [
       "DataStructures.OrderedDict{Any,Float64} with 13 entries:\n",
       "  convert(::Type{T}, po::PyCall.PyObject) where T<:Real in PyCall… => 0.0822036\n",
       "  getindex(o::PyCall.PyObject, s::Symbol) in PyCall at /Users/ced… => 0.00703522\n",
       "  pyerr_check(msg::AbstractString, val) in PyCall at /Users/cedri… => 9.4938e-5\n",
       "  pyisinstance(o::PyCall.PyObject, t::Union{Ptr{PyCall.PyObject_s… => 9.1195e-5\n",
       "  asscalar(o::PyCall.PyObject) in PyCall at /Users/cedric/.julia/… => 8.8809e-5\n",
       "  convert(::Type{PyCall.PyAny}, o::PyCall.PyObject) in PyCall at … => 8.6389e-5\n",
       "  unsafe_convert(::Type{Ptr{PyCall.PyObject_struct}}, po::PyCall.… => 6.4736e-5\n",
       "  pytype_query(o::PyCall.PyObject, default::Union{Tuple{Vararg{Ty… => 4.3544e-5\n",
       "  (::##29#30)() in Main at /Users/cedric/.julia/v0.6/TraceCalls/s… => 1.2242e-5\n",
       "  getindex(o::PyCall.PyObject, s::AbstractString) in PyCall at /U… => 8.009e-6\n",
       "  pyint_query(o::PyCall.PyObject) in PyCall at /Users/cedric/.jul… => 4.477e-6\n",
       "  pyfloat_query(o::PyCall.PyObject) in PyCall at /Users/cedric/.j… => 3.236e-6\n",
       "  pyisinstance(o::PyCall.PyObject, t::PyCall.PyObject) in PyCall … => 3.118e-6"
      ]
     },
     "execution_count": 4,
     "metadata": {},
     "output_type": "execute_result"
    }
   ],
   "source": [
    "@compilation_times PyCall math[:pi]"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "To improve compilation time, consider [::ANY](https://docs.julialang.org/en/stable/stdlib/constants/#Core.ANY), [SnoopCompile.jl](https://github.com/timholy/SnoopCompile.jl), and <a href=\"https://docs.julialang.org/en/latest/manual/performance-tips/#The-dangers-of-abusing-multiple-dispatch-(aka,-more-on-types-with-values-as-parameters)-1\">using parametric types less</a>.\n",
    "\n",
    "Technical note: consider the two function definitions `traced_1() = traced_2() + untraced()` and `traced_3() = untraced()`. The compilation time of `traced_2` won't be part of the compilation time of `traced_1` (by design), but `untraced()` may be counted in either `traced_1` or `traced_3`, depending on which one is profiled first. You can either accept this as measurement noise, or make sure that `untraced` is traced."
   ]
  }
 ],
 "metadata": {
  "kernelspec": {
   "display_name": "Julia 0.6.0 (Programa)",
   "language": "julia",
   "name": "julia-0.6-programa"
  },
  "language_info": {
   "file_extension": ".jl",
   "mimetype": "application/julia",
   "name": "julia",
   "version": "0.6.0"
  }
 },
 "nbformat": 4,
 "nbformat_minor": 2
}