From ee9c988a1b2e3c511b8613e698a0f9632ab1538f Mon Sep 17 00:00:00 2001
From: Graham Christensen <graham@grahamc.com>
Date: Fri, 12 Apr 2019 12:31:33 -0400
Subject: 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.
---
 src/libexpr/eval.hh | 4 ++++
 1 file changed, 4 insertions(+)

(limited to 'src/libexpr/eval.hh')

diff --git a/src/libexpr/eval.hh b/src/libexpr/eval.hh
index a314e01e0a71..22472fd726b2 100644
--- a/src/libexpr/eval.hh
+++ b/src/libexpr/eval.hh
@@ -6,6 +6,7 @@
 #include "symbol-table.hh"
 #include "hash.hh"
 #include "config.hh"
+#include "function-trace.hh"
 
 #include <map>
 #include <unordered_map>
@@ -349,6 +350,9 @@ struct EvalSettings : Config
 
     Setting<Strings> allowedUris{this, {}, "allowed-uris",
         "Prefixes of URIs that builtin functions such as fetchurl and fetchGit are allowed to fetch."};
+
+    Setting<bool> traceFunctionCalls{this, false, "trace-function-calls",
+        "Emit log messages for each function entry and exit at the 'vomit' log level (-vvvv)"};
 };
 
 extern EvalSettings evalSettings;
-- 
cgit 1.4.1