Scale frequency to suppress RCU CPU stall warning

Makefile

@@ -78,6 +78,7 @@ E :=
 S := $E $E
 
 SMP ?= 1
+CFLAGS += -D SEMU_BOOT_TARGET_TIME=10
 .PHONY: riscv-harts.dtsi
 riscv-harts.dtsi:
 	$(Q)python3 scripts/gen-hart-dts.py $@ $(SMP) $(CLOCK_FREQ)

analyze.sh

@@ -0,0 +1,101 @@
+#!/usr/bin/env bash
+#
+# parse_results_new.sh
+#
+# Parses new logs named "emulator_SMP_{N}.log" (N=1..32). Each log's final lines look like:
+#
+#   [SEMU LOG]: Real boot time: 233.04606 seconds, called 3628365913 times semu_timer_clocksource
+#   [SEMU LOG]: ns_per_call = 6.26153, predict_sec = 225.41525, scale_factor = 0.04436
+#   [SEMU LOG]: test_total_clocksource_ns = 92301869299, real_total_clocksource_ns = 46863590994, percentage = 0.20109
+#   [SEMU LOG]: real_ns_per_call = 12.91589, diff_ns_per_call = 6.65436
+#
+# We output results_summary.txt with 11 columns in tab-delimited format:
+#   1) SMP
+#   2) real_boot_time
+#   3) times_called
+#   4) ns_per_call
+#   5) predict_sec
+#   6) scale_factor
+#   7) test_total_clocksource_ns
+#   8) real_total_clocksource_ns
+#   9) percentage
+#   10) real_ns_per_call
+#   11) diff_ns_per_call
+#
+# We specifically remove any ANSI color codes and ensure each line is a single line, so the output doesn't break.
+
+LOGDIR="logs"           # Directory containing the log files
+OUTFILE="results_summary.txt"
+
+# Print header (11 columns)
+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"
+
+for N in $(seq 1 32); do
+    FILE="$LOGDIR/emulator_SMP_${N}.log"
+
+    if [[ ! -f "$FILE" ]]; then
+        echo "Skipping N=$N; file not found: $FILE"
+        continue
+    fi
+
+    # Initialize variables
+    real_boot_time=""
+    times_called=""
+    ns_per_call=""
+    predict_sec=""
+    scale_factor=""
+    test_total_clocksource_ns=""
+    real_total_clocksource_ns=""
+    percentage=""
+    real_ns_per_call=""
+    diff_ns_per_call=""
+
+    # A helper function to grep for a specific pattern once, strip ANSI codes, unify line
+    grep_single_line() {
+        # Usage: grep_single_line "<pattern>"
+        # We'll grep for this pattern, take only the first match, remove color codes, unify line
+        grep -m1 "$1" "$FILE" \
+          | sed 's/\x1b\[[0-9;]*m//g' \
+          | tr '\n' ' '
+    }
+
+    # 1) Real boot time line
+    # e.g. "[SEMU LOG]: Real boot time: 233.04606 seconds, called 3628365913 times semu_timer_clocksource"
+    line_boot="$(grep_single_line 'Real boot time:')"
+    if [[ -n "$line_boot" ]]; then
+        # extract real_boot_time, times_called
+        real_boot_time="$(echo "$line_boot" | sed -E 's/.*Real boot time: ([0-9.]+) seconds, called ([0-9]+) .*/\1/')"
+        times_called="$(echo "$line_boot"    | sed -E 's/.*Real boot time: ([0-9.]+) seconds, called ([0-9]+) .*/\2/')"
+    fi
+
+    # 2) ns_per_call line
+    # e.g.: "[SEMU LOG]: ns_per_call = 6.26153, predict_sec = 225.41525, scale_factor = 0.04436"
+    line_nscall="$(grep_single_line 'ns_per_call =')"
+    if [[ -n "$line_nscall" ]]; then
+        ns_per_call="$(echo "$line_nscall"     | sed -E 's/.*ns_per_call = ([0-9.]+).*/\1/')"
+        predict_sec="$(echo "$line_nscall"     | sed -E 's/.*predict_sec = ([0-9.]+).*/\1/')"
+        scale_factor="$(echo "$line_nscall"    | sed -E 's/.*scale_factor = ([0-9.]+).*/\1/')"
+    fi
+
+    # 3) total_clocksource_ns line
+    # e.g. "[SEMU LOG]: test_total_clocksource_ns = 92301869299, real_total_clocksource_ns = 46863590994, percentage = 0.20109"
+    line_totals="$(grep_single_line 'test_total_clocksource_ns =')"
+    if [[ -n "$line_totals" ]]; then
+        test_total_clocksource_ns="$(echo "$line_totals"  | sed -E 's/.*test_total_clocksource_ns = ([0-9]+).*/\1/')"
+        real_total_clocksource_ns="$(echo "$line_totals"  | sed -E 's/.*real_total_clocksource_ns = ([0-9]+).*/\1/')"
+        percentage="$(echo "$line_totals"                 | sed -E 's/.*percentage = ([0-9.]+).*/\1/')"
+    fi
+
+    # 4) real_ns_per_call line
+    # e.g. "[SEMU LOG]: real_ns_per_call = 12.91589, diff_ns_per_call = 6.65436"
+    line_realns="$(grep_single_line 'real_ns_per_call =')"
+    if [[ -n "$line_realns" ]]; then
+        real_ns_per_call="$(echo "$line_realns" | sed -E 's/.*real_ns_per_call = ([0-9.]+).*/\1/')"
+        diff_ns_per_call="$(echo "$line_realns" | sed -E 's/.*diff_ns_per_call = ([0-9.]+).*/\1/')"
+    fi
+
+    # Print a single line with 11 columns in tab-delimited format
+    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"
+done
+
+echo "Data parsed and saved to $OUTFILE."

auto_test.sh

@@ -0,0 +1,19 @@
+#!/usr/bin/env bash
+
+# Create a directory to store logs (optional)
+mkdir -p logs
+
+for N in $(seq 1 32); do
+    echo "============================================="
+    echo "Starting experiment with SMP=$N"
+    echo "============================================="
+
+    echo "Building and running 'make check SMP=$N'..."
+    make check SMP=$N 2>&1 | tee "logs/emulator_SMP_${N}.log"
+
+    echo "Done with SMP=$N. Logs saved:"
+    echo "  - logs/emulator_SMP_${N}.log"
+    echo
+done
+
+echo "All experiments complete!"

mac_analyze.sh

@@ -0,0 +1,75 @@
+#!/usr/bin/env bash
+#
+# parse_results_macos.sh
+#
+# Parses log files of the form: emulator_SMP_{N}.log
+# Each log ends with lines like:
+#   [SEMU LOG]: Real boot time: 43.63820 seconds, called 220128512 times semu_timer_clocksource
+#   [SEMU LOG]: ns_per_call = 4.46425, predict_sec = 8.92851, scale_factor = 1.12001
+#
+# We output a table with columns:
+#   1) SMP
+#   2) real_boot_time
+#   3) times_called
+#   4) ns_per_call
+#   5) predict_sec
+#   6) scale_factor
+#
+# We do not parse total_clocksource_ns or percentage, as they do not appear in this log snippet.
+
+LOGDIR="mac_log"      # Directory containing emulator_SMP_{N}.log
+OUTFILE="results_summary.txt"
+
+# Print a header:
+echo -e "SMP\treal_boot_time\ttimes\t\tns_per_call\tpredict_sec\tscale_factor" > "$OUTFILE"
+
+# Iterate from SMP=1..32 (adjust if needed)
+for N in $(seq 1 32); do
+    FILE="$LOGDIR/emulator_SMP_${N}.log"
+
+    if [[ ! -f "$FILE" ]]; then
+        echo "Skipping N=$N, file not found: $FILE"
+        continue
+    fi
+
+    # Initialize variables
+    real_boot_time=""
+    times_called=""
+    ns_per_call=""
+    predict_sec=""
+    scale_factor=""
+
+    # 1) Parse the "Real boot time" line:
+    # Example:
+    #   [SEMU LOG]: Real boot time: 43.63820 seconds, called 220128512 times semu_timer_clocksource
+    line_boot="$(grep 'Real boot time:' "$FILE")"
+    if [[ -n "$line_boot" ]]; then
+        # Remove ANSI color codes, if any
+        line_no_ansi="$(echo "$line_boot" | sed 's/\x1b\[[0-9;]*m//g')"
+        # e.g. "[SEMU LOG]: Real boot time: 43.63820 seconds, called 220128512 times semu_timer_clocksource"
+        # We'll extract:
+        #   real_boot_time = 43.63820
+        #   times = 220128512
+        real_boot_time="$(echo "$line_no_ansi" | sed -E 's/.*Real boot time: ([0-9.]+) seconds, called ([0-9]+) .*/\1/')"
+        times_called="$(echo "$line_no_ansi"    | sed -E 's/.*Real boot time: ([0-9.]+) seconds, called ([0-9]+) .*/\2/')"
+    fi
+
+    # 2) Parse the "ns_per_call" line:
+    # Example:
+    #   [SEMU LOG]: ns_per_call = 4.46425, predict_sec = 8.92851, scale_factor = 1.12001
+    line_ns="$(grep 'ns_per_call =' "$FILE")"
+    if [[ -n "$line_ns" ]]; then
+        # Also remove ANSI codes
+        ns_no_ansi="$(echo "$line_ns" | sed 's/\x1b\[[0-9;]*m//g')"
+        # e.g. "ns_per_call = 4.46425, predict_sec = 8.92851, scale_factor = 1.12001"
+        # We'll extract them
+        ns_per_call="$(echo "$ns_no_ansi"  | sed -E 's/.*ns_per_call = ([0-9.]+).*/\1/')"
+        predict_sec="$(echo "$ns_no_ansi"  | sed -E 's/.*predict_sec = ([0-9.]+).*/\1/')"
+        scale_factor="$(echo "$ns_no_ansi" | sed -E 's/.*scale_factor = ([0-9.]+).*/\1/')"
+    fi
+
+    # 3) Print a line with the data
+    echo -e "${N}\t${real_boot_time}\t${times_called}\t${ns_per_call}\t${predict_sec}\t${scale_factor}" >> "$OUTFILE"
+done
+
+echo "Done. Results saved to ${OUTFILE}."

main.c

@@ -619,7 +619,7 @@ static int semu_start(int argc, char **argv)
     emu.disk = virtio_blk_init(&(emu.vblk), disk_file);
 #endif
     /* Set up ACLINT */
-    semu_timer_init(&emu.mtimer.mtime, CLOCK_FREQ);
+    semu_timer_init(&emu.mtimer.mtime, CLOCK_FREQ, hart_count);
     emu.mtimer.mtimecmp = calloc(vm.n_hart, sizeof(uint64_t));
     emu.mswi.msip = calloc(vm.n_hart, sizeof(uint32_t));
     emu.sswi.ssip = calloc(vm.n_hart, sizeof(uint32_t));
@@ -677,7 +677,17 @@ static int semu_start(int argc, char **argv)
     return 0;
 }
 
+#include <time.h>
+#ifdef CLOCK_MONOTONIC_COARSE
+#define CLOCKID CLOCK_MONOTONIC_COARSE
+#else
+#define CLOCKID CLOCK_REALTIME_COARSE
+#endif
+
+extern struct timespec boot_begin;
+
 int main(int argc, char **argv)
 {
+    clock_gettime(CLOCK_REALTIME, &boot_begin);
     return semu_start(argc, argv);
 }

riscv.c

@@ -382,6 +382,14 @@ static void op_sret(hart_t *vm)
     vm->s_mode = vm->sstatus_spp;
     vm->sstatus_sie = vm->sstatus_spie;
 
+    /* After the booting process is complete, initrd will be loaded. At this
+     * point, the sytstem will switch to U mode for the first time. Therefore,
+     * by checking whether the switch to U mode has already occurred, we can
+     * determine if the boot process has been completed.
+     */
+    if (!boot_complete && !vm->s_mode)
+        boot_complete = true;
+
     /* Reset stack */
     vm->sstatus_spp = false;
     vm->sstatus_spie = true;

statistic/README

@@ -0,0 +1,6 @@
+1: 13th Gen Intel(R) Core(TM) i7-13700
+2: Intel(R) Xeon(R) CPU E5-2640 v4 @ 2.40GHz
+3: Intel(R) Core(TM) i7-1065G7 CPU @ 1.30GHz
+4: arm (ThunderX2-99xx)
+5: mag
+6: M2 Pro Max