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.
		
	
			
		
			
				
	
	
		
			86 lines
		
	
	
	
		
			2.1 KiB
		
	
	
	
		
			Bash
		
	
	
		
			Executable file
		
	
	
	
	
			
		
		
	
	
			86 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
 |