Track function start and ends for flame graphs

With this patch, and this file I called `log.py`:

    #!/usr/bin/env nix-shell
    #!nix-shell -i python3 -p python3 --pure

    import sys
    from pprint import pprint

    stack = []
    timestack = []

    for line in open(sys.argv[1]):
        components = line.strip().split(" ", 2)
        if components[0] != "function-trace":
            continue

        direction = components[1]
        components = components[2].rsplit(" ", 2)

        loc = components[0]
        _at = components[1]
        time = int(components[2])

        if direction == "entered":
            stack.append(loc)
            timestack.append(time)
        elif direction == "exited":
            dur = time - timestack.pop()
            vst = ";".join(stack)
            print(f"{vst} {dur}")
            stack.pop()

and:

    nix-instantiate --trace-function-calls -vvvv ../nixpkgs/pkgs/top-level/release.nix -A unstable > log.matthewbauer 2>&1
    ./log.py ./log.matthewbauer > log.matthewbauer.folded
    flamegraph.pl --title matthewbauer-post-pr log.matthewbauer.folded > log.matthewbauer.folded.svg

I can make flame graphs like: http://gsc.io/log.matthewbauer.folded.svg

---

Includes test cases around function call failures and tryEval. Uses
RAII so the finish is always called at the end of the function.

1 files changed, 28 insertions, 0 deletions

diff --git a/doc/manual/command-ref/conf-file.xml b/doc/manual/command-ref/conf-file.xml
index c7b540892..407e5d10b 100644
--- a/doc/manual/command-ref/conf-file.xml
+++ b/doc/manual/command-ref/conf-file.xml
@@ -973,6 +973,34 @@ requiredSystemFeatures = [ "kvm" ];
 
   </varlistentry>
 
+  <varlistentry xml:id="conf-trace-function-calls"><term><literal>trace-function-calls</literal></term>
+
+    <listitem>
+
+      <para>Default: <literal>false</literal>.</para>
+
+      <para>If set to <literal>true</literal>, the Nix evaluator will
+      trace every function call. Nix will print a log message at the
+      "vomit" level for every function entrance and function exit.</para>
+
+      <informalexample><screen>
+function-trace entered undefined position at 1565795816999559622
+function-trace exited undefined position at 1565795816999581277
+function-trace entered /nix/store/.../example.nix:226:41 at 1565795253249935150
+function-trace exited /nix/store/.../example.nix:226:41 at 1565795253249941684
+</screen></informalexample>
+
+      <para>The <literal>undefined position</literal> means the function
+      call is a builtin.</para>
+
+      <para>Use the <literal>contrib/stack-collapse.py</literal> script
+      distributed with the Nix source code to convert the trace logs
+      in to a format suitable for <command>flamegraph.pl</command>.</para>
+
+    </listitem>
+
+  </varlistentry>
+
   <varlistentry xml:id="conf-trusted-public-keys"><term><literal>trusted-public-keys</literal></term>
 
     <listitem><para>A whitespace-separated list of public keys. When