troggle/summarize_starstatement_timing.awk

# Usage: awk -f summarize_starstatement_timing.awk starstatement_timing.log

/^starstatement:\*begin/ {
    begin_count++
    begin_total += $2
}
# Example: starstatement:*end total=0.002345 assign_legs=0.000001 printend=0.000002 ...
/^starstatement:\*end/ {
    end_count++
    match($0, /total=([0-9.]+)/, t)
    end_total += t[1]
    n = split($0, fields, " ")
    for (i = 3; i <= n; i++) {
        split(fields[i], kv, "=")
        step = kv[1]
        val = kv[2]
        step_count[step]++
        step_total[step] += val
    }
}
END {
    printf "BEGIN: count=%d total=%.6f avg=%.6f\n", begin_count, begin_total, (begin_count ? begin_total/begin_count : 0)
    printf "END:   count=%d total=%.6f avg=%.6f\n", end_count, end_total, (end_count ? end_total/end_count : 0)
    for (step in step_count) {
        printf "  %-15s count=%d total=%.6f avg=%.6f\n", step, step_count[step], step_total[step], (step_count[step] ? step_total[step]/step_count[step] : 0)
    }
}