Skip to content

Commit 471877d

Browse files
committed
WIP: parse data
1 parent 2172626 commit 471877d

File tree

1 file changed

+70
-93
lines changed

1 file changed

+70
-93
lines changed

analyze.sh

Lines changed: 70 additions & 93 deletions
Original file line numberDiff line numberDiff line change
@@ -1,124 +1,101 @@
11
#!/usr/bin/env bash
22
#
3-
# parse_results.sh:
4-
# Parse "emulator_SMP_{N}.log" and "gprof_SMP_{N}.log" for each N=1..32
5-
# to extract:
6-
# - predict_sec
7-
# - real_boot_time
8-
# - times (calls)
9-
# - semu_timer_clocksource percentage
10-
# - ns_per_call
11-
# - real_ns_per_call (calculated)
12-
# - scale_factor
3+
# parse_results_new.sh
134
#
14-
# Output a summary line for each SMP=N in tab-delimited format.
5+
# Parses new logs named "emulator_SMP_{N}.log" (N=1..32). Each log's final lines look like:
6+
#
7+
# [SEMU LOG]: Real boot time: 233.04606 seconds, called 3628365913 times semu_timer_clocksource
8+
# [SEMU LOG]: ns_per_call = 6.26153, predict_sec = 225.41525, scale_factor = 0.04436
9+
# [SEMU LOG]: test_total_clocksource_ns = 92301869299, real_total_clocksource_ns = 46863590994, percentage = 0.20109
10+
# [SEMU LOG]: real_ns_per_call = 12.91589, diff_ns_per_call = 6.65436
11+
#
12+
# We output results_summary.txt with 11 columns in tab-delimited format:
13+
# 1) SMP
14+
# 2) real_boot_time
15+
# 3) times_called
16+
# 4) ns_per_call
17+
# 5) predict_sec
18+
# 6) scale_factor
19+
# 7) test_total_clocksource_ns
20+
# 8) real_total_clocksource_ns
21+
# 9) percentage
22+
# 10) real_ns_per_call
23+
# 11) diff_ns_per_call
24+
#
25+
# We specifically remove any ANSI color codes and ensure each line is a single line, so the output doesn't break.
1526

16-
LOGDIR="logs" # or wherever your logs are
27+
LOGDIR="logs" # Directory containing the log files
1728
OUTFILE="results_summary.txt"
1829

19-
echo -e "SMP\treal_boot_time\ttimes\t\tns_per_call\tpredict_sec\tscale_factor\tpercentage\treal_ns_per_call" > "$OUTFILE"
30+
# Print header (11 columns)
31+
echo -e "SMP\treal_boot_time\ttimes_called\tns_per_call\tpredict_sec\tscale_factor\ttest_total_clocksource_ns\treal_total_clocksource_ns\tpercentage\treal_ns_per_call\tdiff_ns_per_call" > "$OUTFILE"
2032

2133
for N in $(seq 1 32); do
22-
EMU_LOG="$LOGDIR/emulator_SMP_${N}.log"
23-
GPROF_LOG="$LOGDIR/gprof_SMP_${N}.log"
34+
FILE="$LOGDIR/emulator_SMP_${N}.log"
2435

25-
# Check that the files exist
26-
if [[ ! -f "$EMU_LOG" ]]; then
27-
echo "Warning: $EMU_LOG not found, skipping"
28-
continue
29-
fi
30-
if [[ ! -f "$GPROF_LOG" ]]; then
31-
echo "Warning: $GPROF_LOG not found, skipping"
36+
if [[ ! -f "$FILE" ]]; then
37+
echo "Skipping N=$N; file not found: $FILE"
3238
continue
3339
fi
3440

35-
# Initialize variables we want to parse
36-
predict_sec=""
41+
# Initialize variables
3742
real_boot_time=""
3843
times_called=""
3944
ns_per_call=""
45+
predict_sec=""
4046
scale_factor=""
47+
test_total_clocksource_ns=""
48+
real_total_clocksource_ns=""
4149
percentage=""
4250
real_ns_per_call=""
51+
diff_ns_per_call=""
4352

44-
# 1) Parse from emulator_SMP_{N}.log:
45-
# We look for lines:
46-
# "[SEMU LOG]: Boot time: 7.82979 seconds, called 233068043 times semu_timer_clocksource"
47-
# next line: "ns_per_call = 5.10756, predict_sec = 10.21511, scale_factor = 0.97894"
48-
# We can do it with grep + sed or awk or a while-read approach
49-
50-
# Extract the "Boot time" line
51-
# e.g. "Boot time: 7.82979 seconds, called 233068043 times semu_timer_clocksource"
52-
# We'll parse the "7.82979" as real_boot_time, "233068043" as times_called
53-
line_boot_time="$(grep -Eo '\[SEMU LOG\]: Boot time: [^,]*, called [^ ]* times semu_timerclocksource.*' "$EMU_LOG")"
54-
# Alternatively you might want a simpler approach:
55-
# Let's do a grep for "Boot time:" and read the line with everything
56-
if [[ -z "$line_boot_time" ]]; then
57-
# Possibly there's an ANSI color code. Let's remove them with sed
58-
line_boot_time="$(grep 'Boot time:' "$EMU_LOG" | sed 's/\x1b\[[0-9;]*m//g')"
59-
fi
60-
61-
# Now parse it. Example format:
62-
# Boot time: 7.82979 seconds, called 233068043 times semu_timer_clocksource
63-
# We can use sed or awk:
64-
if [[ -n "$line_boot_time" ]]; then
65-
# Remove ANSI codes again if needed:
66-
no_ansi="$(echo "$line_boot_time" | sed 's/\x1b\[[0-9;]*m//g')"
67-
# Extract e.g. 7.82979 and 233068043
68-
real_boot_time="$(echo "$no_ansi" | sed -E 's/.*Boot time: ([0-9.]+) seconds, called ([0-9]+) times.*/\1/')"
69-
times_called="$(echo "$no_ansi" | sed -E 's/.*Boot time: ([0-9.]+) seconds, called ([0-9]+) times.*/\2/')"
70-
fi
53+
# A helper function to grep for a specific pattern once, strip ANSI codes, unify line
54+
grep_single_line() {
55+
# Usage: grep_single_line "<pattern>"
56+
# We'll grep for this pattern, take only the first match, remove color codes, unify line
57+
grep -m1 "$1" "$FILE" \
58+
| sed 's/\x1b\[[0-9;]*m//g' \
59+
| tr '\n' ' '
60+
}
7161

72-
# Next line with "ns_per_call = 5.10756, predict_sec = 10.21511, scale_factor = 0.97894"
73-
# We'll grep and parse similarly
74-
line_ns_call="$(grep -Eo 'ns_per_call = [^,]*, predict_sec = [^,]*, scale_factor = [^ ]*' "$EMU_LOG" | sed 's/\x1b\[[0-9;]*m//g')"
75-
if [[ -n "$line_ns_call" ]]; then
76-
# Example: "ns_per_call = 5.10756, predict_sec = 10.21511, scale_factor = 0.97894"
77-
ns_per_call="$(echo "$line_ns_call" | sed -E 's/.*ns_per_call = ([0-9.]+), predict_sec = ([0-9.]+), scale_factor = ([0-9.]+)/\1/')"
78-
predict_sec="$(echo "$line_ns_call" | sed -E 's/.*ns_per_call = ([0-9.]+), predict_sec = ([0-9.]+), scale_factor = ([0-9.]+)/\2/')"
79-
scale_factor="$(echo "$line_ns_call" | sed -E 's/.*ns_per_call = ([0-9.]+), predict_sec = ([0-9.]+), scale_factor = ([0-9.]+)/\3/')"
62+
# 1) Real boot time line
63+
# e.g. "[SEMU LOG]: Real boot time: 233.04606 seconds, called 3628365913 times semu_timer_clocksource"
64+
line_boot="$(grep_single_line 'Real boot time:')"
65+
if [[ -n "$line_boot" ]]; then
66+
# extract real_boot_time, times_called
67+
real_boot_time="$(echo "$line_boot" | sed -E 's/.*Real boot time: ([0-9.]+) seconds, called ([0-9]+) .*/\1/')"
68+
times_called="$(echo "$line_boot" | sed -E 's/.*Real boot time: ([0-9.]+) seconds, called ([0-9]+) .*/\2/')"
8069
fi
8170

82-
# 2) From gprof_SMP_{N}.log:
83-
# We search for the line that includes "semu_timer_clocksource" in the "Flat profile:" section
84-
# Example: "47.74 3.07 3.07 ... semu_timer_clocksource"
85-
# We'll parse the first field as the percentage
86-
# We'll do something like:
87-
line_gprof="$(grep -E '[0-9]+\.[0-9]+[[:space:]]+[0-9]+\.[0-9]+[[:space:]]+[0-9]+\.[0-9]+.*semu_timer_clocksource' "$GPROF_LOG")"
88-
# fallback if the spacing is different, or just search for 'semu_timer_clocksource'
89-
if [[ -z "$line_gprof" ]]; then
90-
line_gprof="$(grep 'semu_timer_clocksource' "$GPROF_LOG")"
71+
# 2) ns_per_call line
72+
# e.g.: "[SEMU LOG]: ns_per_call = 6.26153, predict_sec = 225.41525, scale_factor = 0.04436"
73+
line_nscall="$(grep_single_line 'ns_per_call =')"
74+
if [[ -n "$line_nscall" ]]; then
75+
ns_per_call="$(echo "$line_nscall" | sed -E 's/.*ns_per_call = ([0-9.]+).*/\1/')"
76+
predict_sec="$(echo "$line_nscall" | sed -E 's/.*predict_sec = ([0-9.]+).*/\1/')"
77+
scale_factor="$(echo "$line_nscall" | sed -E 's/.*scale_factor = ([0-9.]+).*/\1/')"
9178
fi
9279

93-
# e.g.: " 47.74 3.07 3.07 semu_timer_clocksource"
94-
# The first column is 47.74. We'll parse that:
95-
if [[ -n "$line_gprof" ]]; then
96-
# remove leading spaces
97-
no_space="$(echo "$line_gprof" | sed 's/^[[:space:]]*//')"
98-
# e.g. "47.74 3.07 ...
99-
# let's cut by spaces
100-
percentage="$(echo "$no_space" | awk '{print $1}')"
80+
# 3) total_clocksource_ns line
81+
# e.g. "[SEMU LOG]: test_total_clocksource_ns = 92301869299, real_total_clocksource_ns = 46863590994, percentage = 0.20109"
82+
line_totals="$(grep_single_line 'test_total_clocksource_ns =')"
83+
if [[ -n "$line_totals" ]]; then
84+
test_total_clocksource_ns="$(echo "$line_totals" | sed -E 's/.*test_total_clocksource_ns = ([0-9]+).*/\1/')"
85+
real_total_clocksource_ns="$(echo "$line_totals" | sed -E 's/.*real_total_clocksource_ns = ([0-9]+).*/\1/')"
86+
percentage="$(echo "$line_totals" | sed -E 's/.*percentage = ([0-9.]+).*/\1/')"
10187
fi
10288

103-
# 3) Compute real_ns_per_call
104-
# real_ns_per_call = real_boot_time * (percentage/100) * 1e9 / times_called
105-
# Check if the fields are not empty
106-
if [[ -n "$real_boot_time" && -n "$percentage" && -n "$times_called" ]]; then
107-
real_ns_per_call="$(awk -v rbt="$real_boot_time" -v pct="$percentage" -v calls="$times_called" '
108-
BEGIN {
109-
# real_boot_time * (percentage/100) * 1e9 / times
110-
if (calls == 0) {
111-
print 0
112-
} else {
113-
val = rbt * (pct/100.0) * 1e9 / calls
114-
printf("%.5f", val)
115-
}
116-
}')"
89+
# 4) real_ns_per_call line
90+
# e.g. "[SEMU LOG]: real_ns_per_call = 12.91589, diff_ns_per_call = 6.65436"
91+
line_realns="$(grep_single_line 'real_ns_per_call =')"
92+
if [[ -n "$line_realns" ]]; then
93+
real_ns_per_call="$(echo "$line_realns" | sed -E 's/.*real_ns_per_call = ([0-9.]+).*/\1/')"
94+
diff_ns_per_call="$(echo "$line_realns" | sed -E 's/.*diff_ns_per_call = ([0-9.]+).*/\1/')"
11795
fi
11896

119-
# 4) Print in tab-delimited format
120-
echo -e "${N}\t${real_boot_time}\t${times_called}\t${ns_per_call}\t${predict_sec}\t${scale_factor}\t${percentage}\t${real_ns_per_call}" >> "$OUTFILE"
121-
97+
# Print a single line with 11 columns in tab-delimited format
98+
echo -e "${N}\t${real_boot_time}\t${times_called}\t${ns_per_call}\t${predict_sec}\t${scale_factor}\t${test_total_clocksource_ns}\t${real_total_clocksource_ns}\t${percentage}\t${real_ns_per_call}\t${diff_ns_per_call}" >> "$OUTFILE"
12299
done
123100

124101
echo "Data parsed and saved to $OUTFILE."

0 commit comments

Comments
 (0)