diff --git a/test-case/check-suspend-resume.sh b/test-case/check-suspend-resume.sh index a1f59764..4fccea9e 100755 --- a/test-case/check-suspend-resume.sh +++ b/test-case/check-suspend-resume.sh @@ -5,7 +5,7 @@ set -e ## ## Case Name: check suspend/resume status ## Preconditions: -## N/A +## - (if ran with --sleepgraph) Sleepgraph installed on dut ## Description: ## Run the suspend/resume command to check device status ## Case step: @@ -26,27 +26,39 @@ source "$TOPDIR"/case-lib/lib.sh random_min=3 # wait time should >= 3 for other device wakeup from sleep random_max=20 -OPT_NAME['l']='loop' OPT_DESC['l']='loop count' -OPT_HAS_ARG['l']=1 OPT_VAL['l']=5 +OPT_NAME['l']='loop' OPT_DESC['l']='loop count' +OPT_HAS_ARG['l']=1 OPT_VAL['l']=5 -OPT_NAME['T']='type' OPT_DESC['T']="suspend/resume type from /sys/power/mem_sleep" -OPT_HAS_ARG['T']=1 OPT_VAL['T']="" +OPT_NAME['T']='type' OPT_DESC['T']="suspend/resume type from /sys/power/mem_sleep" +OPT_HAS_ARG['T']=1 OPT_VAL['T']="" -OPT_NAME['S']='sleep' OPT_DESC['S']='suspend/resume command:rtcwake sleep duration' -OPT_HAS_ARG['S']=1 OPT_VAL['S']=5 +OPT_NAME['S']='sleep' OPT_DESC['S']='suspend/resume command:rtcwake sleep duration' +OPT_HAS_ARG['S']=1 OPT_VAL['S']=5 -OPT_NAME['u']='unload-audio' OPT_DESC['u']='unload audio modules for the test' -OPT_HAS_ARG['u']=0 OPT_VAL['u']=0 +OPT_NAME['u']='unload-audio' OPT_DESC['u']='unload audio modules for the test' +OPT_HAS_ARG['u']=0 OPT_VAL['u']=0 -OPT_NAME['w']='wait' OPT_DESC['w']='idle time after suspend/resume wakeup' -OPT_HAS_ARG['w']=1 OPT_VAL['w']=5 +OPT_NAME['w']='wait' OPT_DESC['w']='idle time after suspend/resume wakeup' +OPT_HAS_ARG['w']=1 OPT_VAL['w']=5 -OPT_NAME['r']='random' OPT_DESC['r']="Randomly setup wait/sleep time, range is [$random_min-$random_max], this option will overwrite s & w option" -OPT_HAS_ARG['r']=0 OPT_VAL['r']=0 +OPT_NAME['r']='random' OPT_DESC['r']="Randomly setup wait/sleep time, range is [$random_min-$random_max], this option will overwrite s & w option" +OPT_HAS_ARG['r']=0 OPT_VAL['r']=0 # processid is set by check-suspend-resume-with-audio.sh for audio test case -OPT_NAME['p']='processid' OPT_DESC['p']='Fail immediately if this process dies' -OPT_HAS_ARG['p']=1 OPT_VAL['p']='' +OPT_NAME['p']='processid' OPT_DESC['p']='Fail immediately if this process dies' +OPT_HAS_ARG['p']=1 OPT_VAL['p']='' + +OPT_NAME['s']='sleepgraph' OPT_DESC['s']='run with sleepgraph (http://github.com/intel/pm-graph.git)' +OPT_HAS_ARG['s']=0 OPT_VAL['s']=0 + +OPT_NAME['c']='component-name' OPT_DESC['c']='component for which we check resume time' +OPT_HAS_ARG['c']=1 OPT_VAL['c']='' + +OPT_NAME['t']='resume-time' OPT_DESC['t']='resume time threshold' +OPT_HAS_ARG['t']=1 OPT_VAL['t']='' + +OPT_NAME['a']='acceptance-range' OPT_DESC['a']='acceptance range for thresholds' +OPT_HAS_ARG['a']=1 OPT_VAL['a']=0.3 func_opt_parse_option "$@" func_lib_check_sudo @@ -69,21 +81,28 @@ dlogi "Current suspend/resume type mode: $(cat /sys/power/mem_sleep)" loop_count=${OPT_VAL['l']} declare -a sleep_lst wait_lst -if [ ${OPT_VAL['r']} -eq 1 ]; then +if [ "${OPT_VAL['r']}" -eq 1 ]; then # create random number list - for i in $(seq 1 $loop_count) + for i in $(seq 1 "$loop_count") do - sleep_lst[$i]=$(func_lib_get_random $random_max $random_min) - wait_lst[$i]=$(func_lib_get_random $random_max $random_min) + sleep_lst[i]=$(func_lib_get_random $random_max $random_min) + wait_lst[i]=$(func_lib_get_random $random_max $random_min) done else - for i in $(seq 1 $loop_count) + for i in $(seq 1 "$loop_count") do - sleep_lst[$i]=${OPT_VAL['S']} - wait_lst[$i]=${OPT_VAL['w']} + sleep_lst[i]=${OPT_VAL['S']} + wait_lst[i]=${OPT_VAL['w']} done fi +if [ "${OPT_VAL['s']}" -eq 1 ]; then + if ! command -v sleepgraph >/dev/null 2>&1; then + echo "Sleepgraph is not installed! Exiting..." + exit 1 + fi +fi + save_initial_stats() { printf '\n\n' @@ -142,8 +161,9 @@ main() sleep 1 local keep_modules=true already_unloaded=false + sleepgraph_failures=0 - if [ ${OPT_VAL['u']} = 1 ]; then + if [ "${OPT_VAL['u']}" = 1 ]; then keep_modules=false fi @@ -159,7 +179,7 @@ main() expected_wakeup_count=$(cat /sys/power/wakeup_count) expected_stats_success=$(cat /sys/power/suspend_stats/success) save_initial_stats - for i in $(seq 1 $loop_count) + for i in $(seq 1 "$loop_count") do sleep_once "$i" done @@ -168,6 +188,51 @@ main() die "Failed to reload audio drivers" sof-kernel-log-check.sh "$KERNEL_CHECKPOINT" || die "Found kernel error after reloading audio drivers" + + if [ $sleepgraph_failures -eq 0 ]; then + dlogi "FINAL TEST RESULT: All time measurements within the thresholds." + else + die "FINAL TEST RESULT: Some time measurements not within the thresholds!" + fi +} + +analyze_sleepgraph_results() +{ + dlogi "Analyzing sleepgraph results" + results_file=$(find suspend-*/*.html) + cp "$results_file" "$LOG_ROOT/" + + thresholds=$( jq -n \ + --arg component_name "${OPT_VAL['c']}" \ + --arg resume_time "${OPT_VAL['t']}" \ + '{$component_name:{"resume":$resume_time}}') + + thresholds_acceptance_range="${OPT_VAL['a']}" + + dlogi "Analyzing $results_file file..." + if python3 "$SCRIPT_HOME"/tools/analyze-sleepgraph-results.py "$results_file" "$thresholds" "$thresholds_acceptance_range"; then + dlogi "All times measurements within the thresholds" + else + dlogw "Time measurements not within the thresholds!" + sleepgraph_failures=$((sleepgraph_failures+1)) + fi +} + +run_rtcwake() +{ + if [ "${OPT_VAL['s']}" -eq 1 ]; then + # remove any files from previous sleepgraph runs + rm -rf suspend-* + + dlogc "Run the command: sleepgraph -rtcwake ${sleep_lst[$i]} -m freeze" + sudo sleepgraph -rtcwake "${sleep_lst[$i]}" -m freeze || + dump_and_die "rtcwake returned $?" + analyze_sleepgraph_results + else + dlogc "Run the command: rtcwake -m mem -s ${sleep_lst[$i]}" + sudo rtcwake -m mem -s "${sleep_lst[$i]}" || + dump_and_die "rtcwake returned $?" + fi } sleep_once() @@ -179,11 +244,9 @@ sleep_once() setup_kernel_check_point expected_wakeup_count=$((expected_wakeup_count+1)) expected_stats_success=$((expected_stats_success+1)) - dlogc "Run the command: rtcwake -m mem -s ${sleep_lst[$i]}" - sudo rtcwake -m mem -s "${sleep_lst[$i]}" || - dump_and_die "rtcwake returned $?" + run_rtcwake dlogc "sleep for ${wait_lst[$i]}" - sleep ${wait_lst[$i]} + sleep "${wait_lst[$i]}" dlogi "Check for the kernel log status" # check kernel log for each iteration to catch issues sof-kernel-log-check.sh "$KERNEL_CHECKPOINT" || dump_and_die "Caught error in kernel log" diff --git a/test-case/test-socwatch.sh b/test-case/residency-time-test.sh similarity index 52% rename from test-case/test-socwatch.sh rename to test-case/residency-time-test.sh index 3056ac4f..71f5738b 100755 --- a/test-case/test-socwatch.sh +++ b/test-case/residency-time-test.sh @@ -38,11 +38,7 @@ OPT_NAME['u']='unload-audio' OPT_DESC['u']='unload audio modules for the test' OPT_HAS_ARG['u']=0 OPT_VAL['u']=0 : "${SOCWATCH_PATH:=$HOME/socwatch}" -SOCWATCH_VERSION=$("$SOCWATCH_PATH"/socwatch --version |grep Version) - -# reference cmd: sudo ./socwatch -t 20 -s 5 -f cpu-cstate -f pkg-pwr -o fredtest5 -#SOCWATCH_CMD="./socwatch" -SOCWATCH_FEATURE_PARAMS=( -f cpu-cstate -f pkg-pwr ) +SOCWATCH_VERSION=$(sudo "$SOCWATCH_PATH"/socwatch --version | grep Version) func_opt_parse_option "$@" func_lib_check_sudo @@ -54,7 +50,29 @@ start_test check_socwatch_module_loaded() { - lsmod | grep -q socwatch || dlogi "socwatch is not loaded" + lsmod | grep -q socwatch || die "socwatch is not loaded" +} + +check_for_PC10_state() +{ + pc10_count=$(awk '/Package C-State Summary: Entry Counts/{f=1; next} f && /PC10/{print $3; exit}' "$socwatch_output".csv) + if [ -z "$pc10_count" ]; then + die "PC10 State not achieved" + fi + dlogi "Entered into PC10 State $pc10_count times" + + pc10_per=$(awk '/Package C-State Summary: Residency/{f=1; next} f && /PC10/{print $3; exit}' "$socwatch_output".csv) + pc10_time=$(awk '/Package C-State Summary: Residency/{f=1; next} f && /PC10/{print $5; exit}' "$socwatch_output".csv) + dlogi "Spent $pc10_time ms ($pc10_per %) in PC10 State" + + json_str=$( jq -n \ + --arg id "$i" \ + --arg cnt "$pc10_count" \ + --arg time "$pc10_time" \ + --arg per "$pc10_per" \ + '{$id: {pc10_entires_count: $cnt, time_ms: $time, time_percentage: $per}}' ) + + results=$(jq --slurp 'add' <(echo "$results") <(echo "$json_str")) } socwatch_test_once() @@ -63,35 +81,29 @@ socwatch_test_once() dlogi "===== Loop($i/$loop_count) =====" dlogi "SoCWatch version: ${SOCWATCH_VERSION}" + socwatch_output="$LOG_ROOT/socwatch-results/socwatch_output_$i" + # set up checkpoint for each iteration setup_kernel_check_point - # load socwatch module, if the module is loaded, go ahead with the testing (-q) - sudo "$SOCWATCH_PATH"/drivers/insmod-socwatch -q || true - check_socwatch_module_loaded || die "socwatch module not loaded" - ( set -x - sudo "$SOCWATCH_PATH"/socwatch -t "$duration" -s "$wait_time" "${SOCWATCH_FEATURE_PARAMS[@]}" -o "$SOCWATCH_PATH/sofsocwatch-$i" ) || + sudo "$SOCWATCH_PATH"/socwatch -m -f sys -f cpu -f cpu-hw -f pcie -f hw-cpu-cstate \ + -f pcd-slps0 -f tcss-state -f tcss -f pcie-lpm -n 200 -t "$duration" -s "$wait_time" \ + -r json -o "$socwatch_output" ) || die "socwatch returned $?" - # filter output and copy to log directory - grep "Package C-State Summary: Residency" -B 8 -A 11 "$SOCWATCH_PATH/sofsocwatch-$i.csv" | tee "$SOCWATCH_PATH/socwatch-$i.txt" - grep "Package Power Summary: Average Rate" -B 6 -A 4 "$SOCWATCH_PATH/sofsocwatch-$i.csv" | tee -a "$SOCWATCH_PATH/socwatch-$i.txt" - # zip original csv report - gzip "$SOCWATCH_PATH/sofsocwatch-$i.csv" - mv "$SOCWATCH_PATH/socwatch-$i.txt" "$SOCWATCH_PATH/sofsocwatch-$i.csv.gz" "$LOG_ROOT"/ + # analyze SoCWatch results + check_for_PC10_state - dlogi "Check for the kernel log status" # check kernel log for each iteration to catch issues + dlogi "Check for the kernel log status" sof-kernel-log-check.sh "$KERNEL_CHECKPOINT" || die "Caught error in kernel log" - - # unload socwatch module - sudo "$SOCWATCH_PATH"/drivers/rmmod-socwatch || true } -main() +unload_modules() { - local keep_modules=true already_unloaded=false + keep_modules=true + already_unloaded=false [ -d "$SOCWATCH_PATH" ] || die "SOCWATCH not found in SOCWATCH_PATH=$SOCWATCH_PATH" @@ -106,22 +118,57 @@ main() dlogw 'modules already unloaded, ignoring option -u!' } - $already_unloaded || $keep_modules || "$TOPDIR"/tools/kmod/sof_remove.sh || + if ! [ $already_unloaded ] || [ $keep_modules ]; then + "$TOPDIR"/tools/kmod/sof_remove.sh || die "Failed to unload audio drivers" + fi +} + +load_modules() +{ + if ! [ $already_unloaded ] || [ $keep_modules ]; then + "$TOPDIR"/tools/kmod/sof_insert.sh || + die "Failed to reload audio drivers" + fi + + sof-kernel-log-check.sh "$KERNEL_CHECKPOINT" || + die "Found kernel error after reloading audio drivers" +} + +run_socwatch_tests() +{ + # load socwatch module, if the module is loaded, go ahead with the testing + sudo bash "$SOCWATCH_PATH"/drivers/insmod-socwatch || true + check_socwatch_module_loaded || die "socwatch module not loaded" + + # Create a dir for all socwatch reports + mkdir "$LOG_ROOT/socwatch-results" + pc10_results_file="$LOG_ROOT/socwatch-results/pc10_results.json" + touch "$pc10_results_file" - # socwatch test from here for i in $(seq 1 "$loop_count") do socwatch_test_once "$i" done + echo "$results" > "$pc10_results_file" + dlogi "****** PC10 STATE RESULTS: ******" + dlogi "$results" + dlogi "*********************************" - $already_unloaded || $keep_modules || "$TOPDIR"/tools/kmod/sof_insert.sh || - die "Failed to reload audio drivers" - sof-kernel-log-check.sh "$KERNEL_CHECKPOINT" || - die "Found kernel error after reloading audio drivers" + # zip all SoCWatch reports + cd "$LOG_ROOT" + tar -zcvf socwatch-results.tar.gz socwatch-results/ + rm -rf "$LOG_ROOT/socwatch-results/" - # DON"T delete socwatch directory after test, delete before new test - # rm -rf $SOCWATCH_PATH + # unload socwatch module + sudo bash "$SOCWATCH_PATH"/drivers/rmmod-socwatch +} + +main() +{ + unload_modules + run_socwatch_tests + load_modules } main "$@" diff --git a/tools/analyze-sleepgraph-results.py b/tools/analyze-sleepgraph-results.py new file mode 100644 index 00000000..e54c519e --- /dev/null +++ b/tools/analyze-sleepgraph-results.py @@ -0,0 +1,74 @@ +from bs4 import BeautifulSoup +from pathlib import Path +import re +import sys +import json +import os + + +# pylint: disable=R0914 +def analyze_sleepgraph_file(file, thresholds, acceptance_range): + with open(file, 'r', encoding='utf-8') as f: + soup = BeautifulSoup(f, 'lxml') + complete_results={} + test_passed=True + + components=thresholds.keys() + for component in components: + # pylint: disable=W0621 + results = {} + divs = soup.find_all("div", title=lambda t, component=component: t and component in t) + + for div in divs: + title = div.get('title') + match = re.search(r'\((\d+(?:\.\d+)?)\s*ms\)\s+(\S+)$', title) + if match: + time_ms = float(match.group(1)) + measurement_name = match.group(2) + if measurement_name in thresholds[component]: + results[measurement_name] = {"value": time_ms, "pass": True} + threshold = float(thresholds[component][measurement_name]) + # pylint: disable=R1716 + if time_ms<(threshold * (1-acceptance_range)) or time_ms>(threshold * (1+acceptance_range)): + results[measurement_name]["pass"] = False + test_passed = False + + complete_results[component]=results + + print(complete_results) + return test_passed, complete_results + + +def save_results_to_file(result): + # pylint: disable=W0621 + results_file = f'{os.getenv("LOG_ROOT")}/resume_time_results.json' + data = [] + + if Path(results_file).is_file(): + with open(results_file, 'r', encoding='utf-8') as f: + data = json.load(f) + + data.append(result) + print(f"Current results: {data}") + + with open(results_file, "w", encoding='utf-8') as f: + f.write(json.dumps(data)) + return results_file + + +if __name__ == "__main__": + if len(sys.argv) != 4: + print("Incorrect number of args!") + sys.exit(1) + + sleepgraph_file = sys.argv[1] + sleepgraph_thresholds = json.loads(sys.argv[2]) + thresholds_buffer = float(sys.argv[3]) + + test_pass, results = analyze_sleepgraph_file(sleepgraph_file, sleepgraph_thresholds, thresholds_buffer) + print(f"Sleepgraph report analysis passed: {test_pass}") + + results_file = save_results_to_file(results) + print(f"Saved results to file: {results_file}") + + sys.exit(0 if test_pass else 1)