aboutsummaryrefslogtreecommitdiff
path: root/tests/helpers/profiler.bash
blob: c3d520705d7077cb4aeed55322553e89842aaa9c (plain)
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
# Profiler implementation
profile() {
    # Set default options
    local file=profiler.log

    # Open a file descriptor for writing to $file and save it in $tracefd
    exec {tracefd}>"$file"
    # Send trace output to $tracefd
    export BASH_XTRACEFD="$tracefd"
    # Print microsecond time in trace output
    export PS4='+ $EPOCHREALTIME '
    # Enable tracing, run script, and disable tracing
    set -x
    bash -x -- "$@"
    set +x
    # Un-redirect the trace output. This also closes the file descriptor.
    unset BASH_XTRACEFD
    export -n BASH_XTRACEFD PS4

    # Remove "source" line from output and change last line to only include the
    # timestamp with no name.
    sed -i -e 1d -e '$s/\(+\+ [0-9\.]\+\) .*$/\1/' "$file"
}

analyze() {
    # Set defaults
    local file=profiler.log
    local -a sortcmd=(cat) tablecmd=(cat)

    # Declare variables
    local timestamp nestlvl cmd next_timestamp next_nestlvl next_cmd duration
    # Open file as a file descriptor so we can re-use the same stream
    exec {fd}<"$file";
    # Read first line
    read -r nestlvl timestamp cmd <&"$fd"
    # Process each line
    while read -r next_nestlvl next_timestamp next_cmd
    do
        duration="$(echo "scale=6; $next_timestamp" - "$timestamp" | bc)"
        # Prepend leading zero
        if [ "${duration:0:1}" = . ]
        then
            duration="0$duration"
        fi
        echo "$duration" "$nestlvl" "$cmd"

        timestamp="$next_timestamp"
        nestlvl="$next_nestlvl"
        cmd="$next_cmd"
    done <&"$fd" | "${sortcmd[@]}" | "${tablecmd[@]}"
    # Close file descriptor
    exec {fd}<&-
}