From c805a48b116a0b5879f524fa34411d5f91fef6ff Mon Sep 17 00:00:00 2001 From: Mark Salyzyn Date: Thu, 18 Apr 2019 12:41:29 -0700 Subject: [PATCH] bootstat: Allow regex matches for boot reasons If the matching string contains a [, \ or *, then it is also checked with a regex match. Exact match is always tried firsts. If we do not find an exact string match, switch to iterate through the entire list for regex strings to find a match. This allows us to scale with details without consuming a large number of enums, permitting details that we do not necessarily want resolution on to propagate to TRON. The hierarchical nature of the boot reason ,,... can cause scenarios where the does not matter to TRON, but does matter to bugreport collection. Add a bootstat --boot_reason_enum function to expose and test the kBootReasonMap matchihg algorithm. Add a kBootReasonMap test that exhaustively tests all built-in entries, and an example of one regex entry. New regex entries added to bootstat.cpp will need a series of exact match examples added into filter_kBootReasonMap() function. Test: boot_reason_test.sh kBootReasonMap (or all tests) Bug: 116838876 Bug: 128929506 Change-Id: I3f7b5de22f99195b7ce99672a212174365960b3f Merged-In: I3f7b5de22f99195b7ce99672a212174365960b3f --- bootstat/boot_reason_test.sh | 208 ++++++++++++++++++++++++++++++----- bootstat/bootstat.cpp | 37 ++++++- 2 files changed, 213 insertions(+), 32 deletions(-) diff --git a/bootstat/boot_reason_test.sh b/bootstat/boot_reason_test.sh index 71d3ecbeb..cb09433d1 100755 --- a/bootstat/boot_reason_test.sh +++ b/bootstat/boot_reason_test.sh @@ -25,6 +25,8 @@ NORMAL="${ESCAPE}[0m" # Best guess to an average device's reboot time, refined as tests return DURATION_DEFAULT=45 STOP_ON_FAILURE=false +progname="${0##*/}" +progpath="${0%${progname}}" # Helper functions @@ -42,11 +44,40 @@ inAdb() { adb devices | grep -v 'List of devices attached' | grep "^${ANDROID_SERIAL}[${SPACE}${TAB}]" > /dev/null } +[ "USAGE: adb_sh /dev/stdout 2>/dev/stderr + +Returns: true if the command succeeded" ] +adb_sh() { + local args= + for i in "${@}"; do + [ -z "${args}" ] || args="${args} " + if [ X"${i}" != X"${i#\'}" ]; then + args="${args}${i}" + elif [ X"${i}" != X"${i#*\\}" ]; then + args="${args}`echo ${i} | sed 's/\\\\/\\\\\\\\/g'`" + elif [ X"${i}" != X"${i#* }" ]; then + args="${args}'${i}'" + elif [ X"${i}" != X"${i#*${TAB}}" ]; then + args="${args}'${i}'" + else + args="${args}${i}" + fi + done + adb shell "${args}" +} + +[ "USAGE: adb_su /dev/stdout 2>/dev/stderr + +Returns: true if the command running as root succeeded" ] +adb_su() { + adb_sh su root "${@}" +} + [ "USAGE: hasPstore Returns: true if device (likely) has pstore data" ] hasPstore() { - if inAdb && [ 0 -eq `adb shell su root ls /sys/fs/pstore | wc -l` ]; then + if inAdb && [ 0 -eq `adb_su ls /sys/fs/pstore &1 &1 &2 ; false ) || return 1 - if [ -z "`adb shell ls /etc/init/bootstat-debug.rc 2>/dev/null`" ]; then + if [ -z "`adb_sh ls /etc/init/bootstat-debug.rc 2>/dev/null &2 return 1 fi checkDebugBuild || return 1 - if adb shell su root "cat /proc/cmdline | tr '\\0 ' '\\n\\n'" | + if adb_su "cat /proc/cmdline | tr '\\0 ' '\\n\\n'" /dev/null; then echo "ERROR: '${TEST}' test requires a device with a bootloader that" >&2 echo " does not set androidboot.bootreason kernel parameter." >&2 return 1 fi - adb shell su root setprop persist.test.boot.reason "'${1}'" 2>/dev/null + adb_su setprop persist.test.boot.reason "'${1}'" 2>/dev/null &2 @@ -299,7 +330,14 @@ EXPECT_PROPERTY() { return ${save_ret} } -[ "USAGE: report_bootstat_logs ... +[ "USAGE: adb_date >/dev/stdout + +Returns: report device epoch time (suitable for logcat -t)" ] +adb_date() { + adb_sh date +%s.%N ] ... if not prefixed with a minus (-), will become a series of expected matches: @@ -314,8 +352,11 @@ Report any logs, minus a known blacklist, preserve the current exit status" ] report_bootstat_logs() { save_ret=${?} match= + timestamp=-d for i in "${@}"; do - if [ X"${i}" != X"${i#-}" ] ; then + if [ X"${i}" != X"${i#-t}" ]; then + timestamp="${i}" + elif [ X"${i}" != X"${i#-}" ]; then match="${match} ${i#-}" else @@ -323,12 +364,13 @@ ${i#-}" bootstat: Canonical boot reason: ${i}" fi done - adb logcat -b all -d | + adb logcat -b all ${timestamp} | grep bootstat[^e] | grep -v -F "bootstat: Service started: /system/bin/bootstat --record_boot_complete${match} bootstat: Failed to read /data/misc/bootstat/post_decrypt_time_elapsed: No such file or directory bootstat: Failed to parse boot time record: /data/misc/bootstat/post_decrypt_time_elapsed bootstat: Service started: /system/bin/bootstat --record_boot_reason +bootstat: Service started: /system/bin/bootstat --set_system_boot_reason bootstat: Service started: /system/bin/bootstat --record_time_since_factory_reset bootstat: Service started: /system/bin/bootstat -l bootstat: Service started: /system/bin/bootstat --set_system_boot_reason --record_boot_complete --record_boot_reason --record_time_since_factory_reset -l @@ -341,6 +383,8 @@ init : Command 'setprop ro.boot.bootreason \${persist.test.boot.reason}' acti init : processing action (post-fs-data) from (/system/etc/init/bootstat.rc init : processing action (boot) from (/system/etc/init/bootstat.rc init : processing action (ro.boot.bootreason=*) from (/system/etc/init/bootstat.rc +init : processing action (ro.boot.bootreason=* && post-fs) from (/system/etc/init/bootstat.rc +init : processing action (zygote-start) from (/system/etc/init/bootstat.rc init : processing action (sys.boot_completed=1 && sys.logbootcomplete=1) from (/system/etc/init/bootstat.rc (/system/bin/bootstat --record_boot_complete --record_boot_reason --record_time_since_factory_reset -l)' (/system/bin/bootstat --set_system_boot_reason --record_boot_complete --record_boot_reason --record_time_since_factory_reset -l)' @@ -355,6 +399,8 @@ init : Command 'exec_background - system log -- /system/bin/bootstat --set_sy (/system/bin/bootstat --record_boot_reason)' (pid${SPACE} (/system/bin/bootstat --record_time_since_factory_reset)'... (/system/bin/bootstat --record_time_since_factory_reset)' (pid${SPACE} + (/system/bin/bootstat --set_system_boot_reason)'... + (/system/bin/bootstat --set_system_boot_reason)' (pid${SPACE} (/system/bin/bootstat -l)'... (/system/bin/bootstat -l)' (pid " | grep -v 'bootstat: Unknown boot reason: $' # Hikey Special @@ -613,7 +659,7 @@ fast and fake (touch build_date on device to make it different)" ] test_optional_ota() { checkDebugBuild || return duration_test - adb shell su root touch /data/misc/bootstat/build_date >&2 + adb_su touch /data/misc/bootstat/build_date >&2 &2 + adb_su rm /data/misc/bootstat/build_date >&2 &2 wait_for_screen EXPECT_PROPERTY sys.boot.reason reboot,factory_reset @@ -715,7 +761,7 @@ test_optional_factory_reset() { wait_for_screen ( exit ${save_ret} ) # because one can not just do ?=${save_ret} EXPECT_PROPERTY sys.boot.reason reboot,factory_reset - EXPECT_PROPERTY sys.boot.reason.last "" + EXPECT_PROPERTY sys.boot.reason.last "\(\|bootloader\)" check_boilerplate_properties report_bootstat_logs reboot,factory_reset bootloader \ "-bootstat: Failed to read /data/misc/bootstat/last_boot_time_utc: No such file or directory" \ @@ -766,12 +812,12 @@ test_battery() { 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 - echo 'healthd: battery l=2 ' | adb shell su root tee /dev/kmsg >/dev/null + echo 'healthd: battery l=2 ' | adb_su tee /dev/kmsg >/dev/null done adb reboot cold >&2 adb wait-for-device wait_for_screen - adb shell su root \ + adb_su /dev/null | grep 'healthd: battery l=' | @@ -780,7 +826,7 @@ test_battery() { if ! EXPECT_PROPERTY sys.boot.reason reboot,battery >/dev/null 2>/dev/null; then # retry 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 - echo 'healthd: battery l=2 ' | adb shell su root tee /dev/kmsg >/dev/null + echo 'healthd: battery l=2 ' | adb_su tee /dev/kmsg >/dev/null done adb reboot cold >&2 adb wait-for-device @@ -806,7 +852,7 @@ battery shutdown test: test_optional_battery() { duration_test ">60" echo " power on request" >&2 - adb shell setprop sys.powerctl shutdown,battery + adb_sh setprop sys.powerctl shutdown,battery &2 wait_for_screen -n >&2 @@ -827,7 +873,7 @@ battery thermal shutdown test: test_optional_battery_thermal() { duration_test ">60" echo " power on request" >&2 - adb shell setprop sys.powerctl shutdown,thermal,battery + adb_sh setprop sys.powerctl shutdown,thermal,battery &2 wait_for_screen -n >&2 @@ -866,7 +912,7 @@ test_kernel_panic() { panic_msg="\(kernel_panic,sysrq\|kernel_panic\)" pstore_ok=true fi - echo c | adb shell su root tee /proc/sysrq-trigger >/dev/null + echo c | adb_su tee /proc/sysrq-trigger >/dev/null wait_for_screen EXPECT_PROPERTY sys.boot.reason ${panic_msg} EXPECT_PROPERTY sys.boot.reason.last ${panic_msg} @@ -893,8 +939,8 @@ test_kernel_panic_subreason() { panic_msg="\(kernel_panic,sysrq,test\|kernel_panic\)" pstore_ok=true fi - echo "SysRq : Trigger a crash : 'test'" | adb shell su root tee /dev/kmsg - echo c | adb shell su root tee /proc/sysrq-trigger >/dev/null + echo "SysRq : Trigger a crash : 'test'" | adb_su tee /dev/kmsg + echo c | adb_su tee /proc/sysrq-trigger >/dev/null wait_for_screen EXPECT_PROPERTY sys.boot.reason ${panic_msg} EXPECT_PROPERTY sys.boot.reason.last ${panic_msg} @@ -924,7 +970,7 @@ test_kernel_panic_hung() { pstore_ok=true fi echo "Kernel panic - not syncing: hung_task: blocked tasks" | - adb shell su root tee /dev/kmsg + adb_su tee /dev/kmsg adb reboot warm wait_for_screen EXPECT_PROPERTY sys.boot.reason ${panic_msg} @@ -956,7 +1002,7 @@ thermal shutdown test: test_thermal_shutdown() { duration_test ">60" echo " power on request" >&2 - adb shell setprop sys.powerctl shutdown,thermal + adb_sh setprop sys.powerctl shutdown,thermal &2 wait_for_screen -n >&2 @@ -977,7 +1023,7 @@ userrequested shutdown test: test_userrequested_shutdown() { duration_test ">60" echo " power on request" >&2 - adb shell setprop sys.powerctl shutdown,userrequested + adb_sh setprop sys.powerctl shutdown,userrequested &2 wait_for_screen -n >&2 @@ -996,7 +1042,7 @@ shell reboot test: - NB: should report reboot,shell" ] test_shell_reboot() { duration_test - adb shell reboot + adb_sh reboot &2 - EXPECT_PROPERTY ro.boot.bootreason reboot,rescueparty + EXPECT_PROPERTY ro.boot.bootreason '\(reboot\|reboot,rescueparty\)' } [ "USAGE: test_Its_Just_So_Hard_reboot @@ -1049,7 +1095,7 @@ test_Its_Just_So_Hard_reboot() { else duration_test `expr ${DURATION_DEFAULT} + ${DURATION_DEFAULT}` fi - adb shell 'reboot "Its Just So Hard"' + adb_sh 'reboot "Its Just So Hard"' &2 + retval=1 + fi + done + exit ${retval} + ) + return + fi + local sys_expected="${1}" + shift + local enum_expected="${1}" + adb_su setprop sys.boot.reason "${sys_expected}" /dev/null` + [ "${enum_expected}" = "${result}" ] || + ( + [ -n "${result}" ] || result="" + echo "ERROR: ${enum_expected} ${sys_expected} got ${result}" >&2 + false + ) || + retval=${?} + return ${retval} +} + +[ "USAGE: filter_kBootReasonMap /dev/stdout + +convert any regex expressions into a series of non-regex test strings" ] +filter_kBootReasonMap() { + while read -r id match; do + case ${match} in + 'reboot,[empty]') + echo ${id} # matches b/c of special case + echo ${id} reboot,y # matches b/c of regex + echo 1 reboot,empty # negative test (ID for unknown is 1) + ;; + reboot) + echo 1 reboo # negative test (ID for unknown is 1) + ;; + esac + echo ${id} "${match}" # matches b/c of exact + done +} + +[ "USAGE: test_kBootReasonMap + +kBootReasonMap test +- (wait until screen is up, boot has completed) +- read bootstat for kBootReasonMap entries and test them all" ] +test_kBootReasonMap() { + local tempfile="`mktemp`" + local arg=--boot_reason_enum + adb_su bootstat ${arg} /dev/null | + filter_kBootReasonMap >${tempfile} + if [ ! -s "${tempfile}" ]; then + wait_for_screen + arg= + sed -n <${progpath}bootstat.cpp \ + '/kBootReasonMap = {/,/^};/s/.*{"\([^"]*\)", *\([0-9][0-9]*\)},.*/\2 \1/p' | + sed 's/\\\\/\\/g' | + filter_kBootReasonMap >${tempfile} + fi + T=`adb_date` + retval=0 + while read -r enum string; do + if [ X"${string}" != X"${string#*[[].[]]}" -o X"${string}" != X"${string#*\\.}" ]; then + if [ 'reboot\.empty' != "${string}" ]; then + echo "WARNING: regex snuck through filter_kBootReasonMap ${enum} ${string}" >&2 + enum=1 + fi + fi + run_kBootReasonMap ${arg} "${string}" "${enum}" Report the match to the kBootReasonMap table\n"); } // Constructs a readable, printable string from the givencommand line @@ -120,9 +121,10 @@ constexpr int32_t kUnknownBootReason = 1; // A mapping from boot reason string, as read from the ro.boot.bootreason // system property, to a unique integer ID. Viewers of log data dashboards for // the boot_reason metric may refer to this mapping to discern the histogram -// values. +// values. Regex matching, to manage the scale, as a minimum require either +// [, \ or * to be present in the string to switch to checking. const std::map kBootReasonMap = { - {"empty", kEmptyBootReason}, + {"reboot,[empty]", kEmptyBootReason}, {"__BOOTSTAT_UNKNOWN__", kUnknownBootReason}, {"normal", 2}, {"recovery", 3}, @@ -314,6 +316,16 @@ int32_t BootReasonStrToEnum(const std::string& boot_reason) { return kEmptyBootReason; } + for (const auto& [match, id] : kBootReasonMap) { + // Regex matches as a minimum require either [, \ or * to be present. + if (match.find_first_of("[\\*") == match.npos) continue; + // enforce match from beginning to end + auto exact = match; + if (exact[0] != '^') exact = "^" + exact; + if (exact[exact.size() - 1] != '$') exact = exact + "$"; + if (std::regex_search(boot_reason, std::regex(exact))) return id; + } + LOG(INFO) << "Unknown boot reason: " << boot_reason; return kUnknownBootReason; } @@ -1266,6 +1278,19 @@ void RecordFactoryReset() { boot_event_store.AddBootEventWithValue("time_since_factory_reset", time_since_factory_reset); } +// List the associated boot reason(s), if arg is nullptr then all. +void PrintBootReasonEnum(const char* arg) { + int value = -1; + if (arg != nullptr) { + value = BootReasonStrToEnum(arg); + } + for (const auto& [match, id] : kBootReasonMap) { + if ((value < 0) || (value == id)) { + printf("%u\t%s\n", id, match.c_str()); + } + } +} + } // namespace int main(int argc, char** argv) { @@ -1280,6 +1305,7 @@ int main(int argc, char** argv) { static const char boot_complete_str[] = "record_boot_complete"; static const char boot_reason_str[] = "record_boot_reason"; static const char factory_reset_str[] = "record_time_since_factory_reset"; + static const char boot_reason_enum_str[] = "boot_reason_enum"; static const struct option long_options[] = { // clang-format off { "help", no_argument, NULL, 'h' }, @@ -1291,6 +1317,7 @@ int main(int argc, char** argv) { { boot_complete_str, no_argument, NULL, 0 }, { boot_reason_str, no_argument, NULL, 0 }, { factory_reset_str, no_argument, NULL, 0 }, + { boot_reason_enum_str, optional_argument, NULL, 0 }, { NULL, 0, NULL, 0 } // clang-format on }; @@ -1315,6 +1342,8 @@ int main(int argc, char** argv) { RecordBootReason(); } else if (option_name == factory_reset_str) { RecordFactoryReset(); + } else if (option_name == boot_reason_enum_str) { + PrintBootReasonEnum(optarg); } else { LOG(ERROR) << "Invalid option: " << option_name; }