From 2450cb1a3024e1a2e3e27c5508ecd7b9e4122df8 Mon Sep 17 00:00:00 2001 From: Mark Salyzyn Date: Tue, 10 Oct 2017 10:44:57 -0700 Subject: [PATCH] bootstat: test: refine reported test durations Use actual test durations to refine future duration estimates. Better estimates are cosmetic, but lend confidence to the test results. SideEffects: none Test: system/core/bootstat/boot_reason_test.sh Bug: 63736262 Change-Id: I49143b78a6dc6fb21838a3d6c70b7eb5a8b4cba5 --- bootstat/boot_reason_test.sh | 89 ++++++++++++++++++++++++++++-------- 1 file changed, 70 insertions(+), 19 deletions(-) diff --git a/bootstat/boot_reason_test.sh b/bootstat/boot_reason_test.sh index 5425fd37b..c42680cba 100755 --- a/bootstat/boot_reason_test.sh +++ b/bootstat/boot_reason_test.sh @@ -22,6 +22,8 @@ TAB=" " GREEN="${ESCAPE}[38;5;40m" RED="${ESCAPE}[38;5;196m" NORMAL="${ESCAPE}[0m" +# Best guess to an average device's reboot time, refined as tests return +DURATION_DEFAULT=45 # Helper functions @@ -57,12 +59,15 @@ isDebuggable() { fi } -[ "USAGE: checkDebugBuild +[ "USAGE: checkDebugBuild [--noerror] Returns: true if device is a userdebug or eng release" ] checkDebugBuild() { if isDebuggable; then echo "INFO: '${TEST}' test requires userdebug build" + elif [ -n "${1}" ]; then + echo "WARNING: '${TEST}' test requires userdebug build" + false else echo "ERROR: '${TEST}' test requires userdebug build, skipping FAILURE" false @@ -204,7 +209,7 @@ EXPECT_EQ() { return 0 } -[ "USAGE: EXPECT_PROPERTY +[ "USAGE: EXPECT_PROPERTY [--allow_failure] Returns true if current return (regex) value is true and the result matches" ] EXPECT_PROPERTY() { @@ -214,6 +219,7 @@ EXPECT_PROPERTY() { shift 2 val=`adb shell getprop ${property} 2>&1` EXPECT_EQ "${value}" "${val}" for Android property ${property} || + [ -n "${1}" ] || save_ret=${?} return ${save_ret} } @@ -279,11 +285,44 @@ init : Command 'exec - system log -- /system/bin/bootstat --record_time_since Record start of test, preserve exit status" ] start_test() { save_ret=${?} + duration_prefix="~" + duration_estimate=1 START=`date +%s` echo "${GREEN}[ RUN ]${NORMAL} ${TEST} ${*}" return ${save_ret} } +duration_sum_diff=0 +duration_num=0 +[ "USAGE: duration_test [[prefix]seconds] + +Report the adjusted and expected test duration" ] +duration_test() { + duration_prefix=${1%%[0123456789]*} + if [ -z "${duration_prefix}" ]; then + duration_prefix="~" + fi + duration_estimate="${1#${duration_prefix}}" + if [ -z "${duration_estimate}" ]; then + duration_estimate="${DURATION_DEFAULT}" + fi + duration_new_estimate="${duration_estimate}" + if [ 0 -ne ${duration_num} ]; then + duration_new_estimate=`expr ${duration_new_estimate} + \ + \( ${duration_num} / 2 + ${duration_sum_diff} \) / ${duration_num}` + # guard against catastrophe + if [ -z "${duration_new_estimate}" ]; then + duration_new_estimate=${duration_estimate} + fi + fi + # negative values are so undignified + if [ 0 -ge ${duration_new_estimate} ]; then + duration_new_estimate=1 + fi + echo "INFO: expected duration of '${TEST}' test" \ + "${duration_prefix}`format_duration ${duration_new_estimate}`" >&2 +} + [ "USAGE: end_test [message] Document duration and success of test, preserve exit status" ] @@ -291,9 +330,16 @@ end_test() { save_ret=${?} END=`date +%s` duration=`expr ${END} - ${START} 2>/dev/null` - [ 0 = ${duration} ] || + [ 0 -ge ${duration} ] || echo "INFO: '${TEST}' test duration `format_duration ${duration}`" >&2 if [ ${save_ret} = 0 ]; then + if [ 0 -lt ${duration} -a 0 -lt ${duration_estimate} -a \( \ + X"~" = X"${duration_prefix}" -o \ + ${duration_estimate} -gt ${duration} \) ]; then + duration_sum_diff=`expr ${duration_sum_diff} + \ + ${duration} - ${duration_estimate}` + duration_num=`expr ${duration_num} + 1` + fi echo "${GREEN}[ OK ]${NORMAL} ${TEST} ${*}" else echo "${RED}[ FAILED ]${NORMAL} ${TEST} ${*}" @@ -372,6 +418,7 @@ properties test - adb shell getprop sys.boot.reason (system reason) - NB: all should have a value that is compliant with our known set." ] test_properties() { + duration_test 1 wait_for_screen retval=0 check_set="ro.boot.bootreason persist.sys.boot.reason sys.boot.reason" @@ -410,7 +457,7 @@ ota test Decision to change the build itself rather than trick bootstat by rummaging through its data files was made." ] test_ota() { - echo "INFO: expected duration of '${TEST}' test >`format_duration 300`" >&2 + duration_test ">300" echo " extended by build and flashing times" >&2 if [ -z "${TARGET_PRODUCT}" -o \ -z "${ANDROID_PRODUCT_OUT}" -o \ @@ -451,7 +498,7 @@ test_ota() { fast and fake (touch build_date on device to make it different)" ] test_optional_ota() { checkDebugBuild || return - echo "INFO: expected duration of '${TEST}' test ~`format_duration 45`" >&2 + duration_test adb shell su root touch /data/misc/bootstat/build_date >&2 adb reboot ota wait_for_screen @@ -472,11 +519,11 @@ We interleave the simple reboot tests between the hard/complex ones as a means of checking sanity and any persistent side effect of the other tests." ] blind_reboot_test() { + duration_test case ${TEST} in bootloader | recovery | cold | hard | warm ) reason=${TEST} ;; *) reason=reboot,${TEST} ;; esac - echo "INFO: expected duration of '${TEST}' test ~`format_duration 45`" >&2 adb reboot ${TEST} wait_for_screen EXPECT_PROPERTY sys.boot.reason ${reason} @@ -508,7 +555,7 @@ Decision to rummage through bootstat data files was made as a _real_ factory_reset is too destructive to the device." ] test_factory_reset() { checkDebugBuild || return - echo "INFO: expected duration of '${TEST}' test ~`format_duration 45`" >&2 + duration_test adb shell su root rm /data/misc/bootstat/build_date >&2 adb reboot >&2 wait_for_screen @@ -531,7 +578,7 @@ factory_reset test For realz, and disruptive" ] test_optional_factory_reset() { - echo "INFO: expected duration of '${TEST}' test ~`format_duration 60`" >&2 + duration_test 60 if ! inFastboot; then adb reboot-bootloader fi @@ -585,7 +632,7 @@ battery test (trick): - (replace set logd.kernel true to the above, and retry test)" ] test_battery() { checkDebugBuild || return - echo "INFO: expected duration of '${TEST}' test ~`format_duration 120`" >&2 + duration_test 120 enterPstore # Send it _many_ times to combat devices with flakey pstore for i in a b c d e f g h i j k l m n o p q r s t u v w x y z; do @@ -626,7 +673,7 @@ battery shutdown test: - adb shell getprop sys.boot.reason - NB: should report shutdown,battery" ] test_optional_battery() { - echo "INFO: expected duration of '${TEST}' test >`format_duration 60`" >&2 + duration_test ">60" echo " power on request" >&2 adb shell setprop sys.powerctl shutdown,battery sleep 5 @@ -646,7 +693,7 @@ battery thermal shutdown test: - adb shell getprop sys.boot.reason - NB: should report shutdown,thermal,battery" ] test_optional_battery_thermal() { - echo "INFO: expected duration of '${TEST}' test >`format_duration 60`" >&2 + duration_test ">60" echo " power on request" >&2 adb shell setprop sys.powerctl shutdown,thermal,battery sleep 5 @@ -678,7 +725,7 @@ kernel_panic test: - NB: should report kernel_panic,sysrq" ] test_kernel_panic() { checkDebugBuild || return - echo "INFO: expected duration of '${TEST}' test >`format_duration 120`" >&2 + duration_test ">90" panic_msg="kernel_panic,sysrq" enterPstore || panic_msg="\(kernel_panic,sysrq\|kernel_panic\)" echo c | adb shell su root tee /proc/sysrq-trigger >/dev/null @@ -709,7 +756,7 @@ thermal shutdown test: - adb shell getprop sys.boot.reason - NB: should report shutdown,thermal" ] test_thermal_shutdown() { - echo "INFO: expected duration of '${TEST}' test >`format_duration 60`" >&2 + durtion_test ">60" echo " power on request" >&2 adb shell setprop sys.powerctl shutdown,thermal sleep 5 @@ -729,7 +776,7 @@ userrequested shutdown test: - adb shell getprop sys.boot.reason - NB: should report shutdown,userrequested" ] test_userrequested_shutdown() { - echo "INFO: expected duration of '${TEST}' test >`format_duration 60`" >&2 + duration_test ">60" echo " power on request" >&2 adb shell setprop sys.powerctl shutdown,userrequested sleep 5 @@ -748,7 +795,7 @@ shell reboot test: - adb shell getprop sys.boot.reason - NB: should report reboot,shell" ] test_shell_reboot() { - echo "INFO: expected duration of '${TEST}' test ~`format_duration 45`" >&2 + duration_test adb shell reboot wait_for_screen EXPECT_PROPERTY sys.boot.reason reboot,shell @@ -764,7 +811,7 @@ adb reboot test: - adb shell getprop sys.boot.reason - NB: should report reboot,adb" ] test_adb_reboot() { - echo "INFO: expected duration of '${TEST}' test ~`format_duration 45`" >&2 + duration_test adb reboot wait_for_screen EXPECT_PROPERTY sys.boot.reason reboot,adb @@ -781,14 +828,18 @@ Its Just So Hard reboot test: - NB: should report reboot,its_just_so_hard - NB: expect log \"... I bootstat: Unknown boot reason: reboot,its_just_so_hard\"" ] test_Its_Just_So_Hard_reboot() { - checkDebugBuild || return - echo "INFO: expected duration of '${TEST}' test ~`format_duration 45`" >&2 + duration_test adb shell 'reboot "Its Just So Hard"' wait_for_screen EXPECT_PROPERTY sys.boot.reason reboot,its_just_so_hard EXPECT_PROPERTY persist.sys.boot.reason "reboot,Its Just So Hard" adb shell su root setprop persist.sys.boot.reason reboot,its_just_so_hard - EXPECT_PROPERTY persist.sys.boot.reason reboot,its_just_so_hard + if checkDebugBuild; then + flag="" + else + flag="--allow_failure" + fi + EXPECT_PROPERTY persist.sys.boot.reason reboot,its_just_so_hard ${flag} report_bootstat_logs reboot,its_just_so_hard }