From c563aff5f6d84fb8ba2950baa037b4f07473b4d1 Mon Sep 17 00:00:00 2001 From: Cedric St-Jean Date: Thu, 3 Aug 2017 16:25:47 -0400 Subject: [PATCH] Improve user manual --- README.ipynb | 178 +++++++++++++++++++-------------------------------- 1 file changed, 66 insertions(+), 112 deletions(-) diff --git a/README.ipynb b/README.ipynb index d0ce283..daf8dae 100644 --- a/README.ipynb +++ b/README.ipynb @@ -209,122 +209,26 @@ "source": [ "# Tracing code\n", "\n", - "The best way to trace your own codebase is to annotate key functions with `@traceable`." - ] - }, - { - "cell_type": "code", - "execution_count": 6, - "metadata": {}, - "outputs": [ - { - "data": { - "text/html": [ - "
#17() => 3
" - ], - "text/plain": [ - "- #17() => 3\n", - " - my_factorial(3) => 6\n", - " - my_factorial(2) => 2\n", - " - my_factorial(1) => 1\n", - " - my_factorial(0) => 1\n", - " - my_factorial(1) => 1\n", - " - my_factorial(0) => 1\n", - " - my_factorial(2) => 2\n", - " - my_factorial(1) => 1\n", - " - my_factorial(0) => 1\n" - ] - }, - "execution_count": 6, - "metadata": {}, - "output_type": "execute_result" - } - ], - "source": [ - "@traceable function my_factorial(n)\n", - " if n==0\n", - " return 1\n", - " else\n", - " return n * my_factorial(n-1)\n", - " end\n", - "end\n", + "#### Syntax\n", "\n", - "\"\"\" How many ways there are of selecting k objects amongst n. See https://en.wikipedia.org/wiki/Combination \"\"\"\n", - "combination(k, n) = Int(my_factorial(n) / (my_factorial(n-k) * my_factorial(k)))\n", + "```julia\n", + "@traceable function foo()\n", + "...\n", + "end\n", "\n", - "@trace combination(2, 3)" - ] - }, - { - "cell_type": "markdown", - "metadata": {}, - "source": [ - "In the example above, `my_factorial` is traced (each call to it will be recorded when `@trace` is used), but `combination` isn't. Crucially, the `@traceable` macro merely remembers the function definition, it does not modify it in any way. This means that **`@traceable` has zero impact on the performance of your code**. Sprinkle it liberally!\n", + "@trace (some_function, some_module, \"some_interactively_included_file.jl\") bar(1)\n", + "```\n", "\n", - "When it's not practical to add `@traceable` annotations, you can trace included files, entire modules, or specific functions by passing them to the `@trace` macro:" - ] - }, - { - "cell_type": "code", - "execution_count": 7, - "metadata": {}, - "outputs": [ - { - "name": "stderr", - "output_type": "stream", - "text": [ - "\u001b[1m\u001b[33mWARNING: \u001b[39m\u001b[22m\u001b[33mOnly 0/1 methods of DataStructures.compare in /Users/cedric/.julia/v0.6/DataStructures/src/tokens2.jl were found.\u001b[39m\n" - ] - }, - { - "data": { - "text/html": [ - "
#19() => [68, 21, 14]
" - ], - "text/plain": [ - "- #19() => [68, 21, 14]\n", - " - DataStructures.nextreme(DataStructures.LessThan(), 3, [0, 21, -12, 68, -25, 14]) => [68, 21, 14]\n", - " - DataStructures.compare(DataStructures.LessThan(), 21, 0) => false\n", - " - DataStructures.compare(DataStructures.LessThan(), -12, 0) => true\n", - " - DataStructures.compare(DataStructures.LessThan(), -12, 68) => true\n", - " - DataStructures.compare(DataStructures.LessThan(), 21, 0) => false\n", - " - DataStructures.compare(DataStructures.LessThan(), 68, 0) => false\n", - " - DataStructures.compare(DataStructures.LessThan(), 0, -25) => false\n", - " - DataStructures.compare(DataStructures.LessThan(), 0, 14) => true\n", - " - DataStructures.compare(DataStructures.LessThan(), 21, 68) => true\n", - " - DataStructures.compare(DataStructures.LessThan(), 14, 21) => true\n", - " - DataStructures.compare(DataStructures.LessThan(), 68, 21) => false\n" - ] - }, - "execution_count": 7, - "metadata": {}, - "output_type": "execute_result" - } - ], - "source": [ - "using DataStructures\n", - "to_trace = (DataStructures.nextreme, compare)\n", - "@trace to_trace nlargest(3, [0,21,-12,68,-25,14]) # returns the 3 largest values in the vector" - ] - }, - { - "cell_type": "markdown", - "metadata": {}, - "source": [ - "`@trace` attempts to find the source of every method of the traced functions, and emits a warning (see above) when it cannot find it. When tracing modules, `@trace` has to parse their source code looking for function definitions (using [Revise.jl](https://github.com/timholy/Revise.jl)). That is an inexact science; some code will not be traced. In particular, `@trace` and `@traceable` ignore:\n", + "This call to `@trace` will execute `bar(1)` while tracing all methods of `some_function`, all methods defined in `some_module / \"some_interactively_included_file.jl\"`, and all methods defined with `@traceable` (in this case, `foo()`). Tracing Julia code involves a fair amount of code analysis; TraceCalls.jl will error (when using `@traceable`), warn (when tracing a function), or silently skip (when tracing a module) the following:\n", "\n", " - Inner constructors\n", " - Functions that are defined by `eval`\n", - " - Function definitions inside a macroexpansion (eg. `@inline foo(x) = x+2`), unless `@traceable` is part of the macroexpansion.\n", + " - Function definitions inside a macroexpansion (eg. `@inline foo(x) = x+2`), unless `@traceable` is part of the macroexpansion. This should be fixed in the next `TraceCalls` release.\n", " - Callable objects (eg. `(func::Functor)(x) = ...`)\n", + " \n", + "Crucially, the `@traceable` macro merely remembers the function definition, it does not modify it in any way. This means that **`@traceable` has zero impact on the performance of your code**. It's reasonable to leave it permanently in front of commonly used/debugged methods. \n", "\n", - "#### Syntax\n", - "\n", - "The full syntax of `@trace` is:\n", - "\n", - " @trace (object1, object2, ...) code_to_execute\n", - " \n", - "where each `object` can be a function, a module, or a filename (that was `include`d interactively). It will trace the methods defined in the objects, _and all methods that were defined with `@traceable`_. The shorthand `@trace code_to_trace` is equivalent to `@trace () code_to_trace`.\n", + "`@trace bar(1)` is shorthand for `@trace () bar(1)`.\n", "\n", "#### Implementation of @trace\n", "\n", @@ -419,7 +323,7 @@ } ], "source": [ - "trace_walk[1][3] # can also be written graph_trace[1,3]" + "trace_walk[1][3] # can also be written trace_walk[1,3]" ] }, { @@ -736,7 +640,7 @@ "cell_type": "markdown", "metadata": {}, "source": [ - "For profiling, it's sometimes simpler to filter out all mutating functions:" + "Alternatively, it's sometimes simpler to filter out all mutating functions:" ] }, { @@ -768,7 +672,7 @@ "cell_type": "markdown", "metadata": {}, "source": [ - "The most drastic solution is to have TraceCalls store the text/HTML representation:\n", + "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", @@ -783,7 +687,7 @@ "source": [ "# Debugging with traces\n", "\n", - "The starting point for debugging exceptions is `@stacktrace`. It's like `@trace`, but uses `filter` to keep only the part of the trace involved in the exception." + "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." ] }, { @@ -1047,6 +951,56 @@ "using BenchmarkTools: @belapsed\n", "measure(:@belapsed, trace_pycall; normalize=true, threshold=0.005) # only show calls that take >0.5% of total runtime" ] + }, + { + "cell_type": "markdown", + "metadata": {}, + "source": [ + "Finally, `is_inferred` uses the same code as `Base.Test.@inferred`, but returns `true/false`. Combined with `map`, it's a useful tool for detecting type instability:" + ] + }, + { + "cell_type": "code", + "execution_count": 2, + "metadata": {}, + "outputs": [ + { + "data": { + "text/html": [ + "
#1() => false
" + ], + "text/plain": [ + "- #1() => false\n", + " - getindex(PyObject , :pi) => false\n", + " - getindex(PyObject , \"pi\") => true\n", + " - Base.unsafe_convert(Ptr{PyCall.PyObject_struct}, PyObject ) => true\n", + " - convert(PyCall.PyAny, PyObject 3.141592653589793) => false\n", + " - PyCall.pytype_query(PyObject 3.141592653589793, PyCall.PyObject) => false\n", + " - PyCall.pyint_query(PyObject 3.141592653589793) => false\n", + " - PyCall.pyisinstance(PyObject 3.141592653589793, Ptr{PyCall.PyObject_struct} @0x00000001198b0c98) => true\n", + " - Base.unsafe_convert(Ptr{PyCall.PyObject_struct}, PyObject 3.141592653589793) => true\n", + " - PyCall.pyisinstance(PyObject 3.141592653589793, Ptr{PyCall.PyObject_struct} @0x00000001198b2aa8) => true\n", + " - Base.unsafe_convert(Ptr{PyCall.PyObject_struct}, PyObject 3.141592653589793) => true\n", + " - PyCall.pyisinstance(PyObject 3.141592653589793, PyObject NULL) => true\n", + " - PyCall.pyisinstance(PyObject 3.141592653589793, PyObject NULL) => true\n", + " - PyCall.pyfloat_query(PyObject 3.141592653589793) => false\n", + " - PyCall.pyisinstance(PyObject 3.141592653589793, Ptr{PyCall.PyObject_struct} @0x00000001198ae998) => true\n", + " - Base.unsafe_convert(Ptr{PyCall.PyObject_struct}, PyObject 3.141592653589793) => true\n", + " - convert(Float64, PyObject 3.141592653589793) => true\n", + " - PyCall.asscalar(PyObject 3.141592653589793) => true\n", + " - PyCall.pyisinstance(PyObject 3.141592653589793, PyObject NULL) => true\n", + " - Base.unsafe_convert(Ptr{PyCall.PyObject_struct}, PyObject 3.141592653589793) => true\n", + " - PyCall.pyerr_check(\"ccall(@pysym(:PyFloat_AsDouble), Cdouble, (PyPtr,), asscalar(po))\", 3.141592653589793) => true\n" + ] + }, + "execution_count": 2, + "metadata": {}, + "output_type": "execute_result" + } + ], + "source": [ + "redgreen(map(is_inferred, trace_pycall))" + ] } ], "metadata": {