lix/tests/function-trace.sh
Graham Christensen ee9c988a1b
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.
2019-08-14 16:09:35 -04:00

87 lines
2.1 KiB
Bash
Executable file

source common.sh
set +x
expect_trace() {
expr="$1"
expect="$2"
actual=$(
nix-instantiate \
--trace-function-calls \
-vvvv \
--expr "$expr" 2>&1 \
| grep "function-trace" \
| sed -e 's/ [0-9]*$//'
);
echo -n "Tracing expression '$expr'"
set +e
msg=$(diff -swB \
<(echo "$expect") \
<(echo "$actual")
);
result=$?
set -e
if [ $result -eq 0 ]; then
echo " ok."
else
echo " failed. difference:"
echo "$msg"
return $result
fi
}
# failure inside a tryEval
expect_trace 'builtins.tryEval (throw "example")' "
function-trace entered undefined position at
function-trace exited undefined position at
function-trace entered (string):1:1 at
function-trace entered (string):1:19 at
function-trace exited (string):1:19 at
function-trace exited (string):1:1 at
"
# Missing argument to a formal function
expect_trace '({ x }: x) { }' "
function-trace entered undefined position at
function-trace exited undefined position at
function-trace entered (string):1:1 at
function-trace exited (string):1:1 at
"
# Too many arguments to a formal function
expect_trace '({ x }: x) { x = "x"; y = "y"; }' "
function-trace entered undefined position at
function-trace exited undefined position at
function-trace entered (string):1:1 at
function-trace exited (string):1:1 at
"
# Not enough arguments to a lambda
expect_trace '(x: y: x + y) 1' "
function-trace entered undefined position at
function-trace exited undefined position at
function-trace entered (string):1:1 at
function-trace exited (string):1:1 at
"
# Too many arguments to a lambda
expect_trace '(x: x) 1 2' "
function-trace entered undefined position at
function-trace exited undefined position at
function-trace entered (string):1:1 at
function-trace exited (string):1:1 at
function-trace entered (string):1:1 at
function-trace exited (string):1:1 at
"
# Not a function
expect_trace '1 2' "
function-trace entered undefined position at
function-trace exited undefined position at
function-trace entered (string):1:1 at
function-trace exited (string):1:1 at
"
set -e