Donate to e Foundation | Murena handsets with /e/OS | Own a part of Murena! Learn more

Commit 67ee8a8e authored by Mark Salyzyn's avatar Mark Salyzyn
Browse files

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 <reason>,<subreason>,<detail>... can cause scenarios
where the <detail> 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
parent 2ddb8df2
Loading
Loading
Loading
Loading
+180 −28
Original line number Diff line number Diff line
@@ -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 <commands> </dev/stdin >/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 <commands> </dev/stdin >/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 </dev/null | wc -l` ]; then
    false
  fi
}
@@ -55,7 +86,7 @@ hasPstore() {

Returns the property value" ]
get_property() {
  adb shell getprop ${1} 2>&1 </dev/null
  adb_sh getprop ${1} 2>&1 </dev/null
}

[ "USAGE: isDebuggable
@@ -89,18 +120,18 @@ checkDebugBuild() {
Returns: true if device supports and set boot reason injection" ]
setBootloaderBootReason() {
  inAdb || ( echo "ERROR: device not in adb mode." >&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 </dev/null`" ]; then
    echo "ERROR: '${TEST}' test requires /etc/init/bootstat-debug.rc" >&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 |
     grep '^androidboot[.]bootreason=[^ ]' >/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 </dev/null
  test_reason="`get_property persist.test.boot.reason`"
  if [ X"${test_reason}" != X"${1}" ]; then
    echo "ERROR: can not set persist.test.boot.reason to '${1}'." >&2
@@ -299,7 +330,14 @@ EXPECT_PROPERTY() {
  return ${save_ret}
}

[ "USAGE: report_bootstat_logs <expected> ...
[ "USAGE: adb_date >/dev/stdout

Returns: report device epoch time (suitable for logcat -t)" ]
adb_date() {
  adb_sh date +%s.%N </dev/null
}

[ "USAGE: report_bootstat_logs [-t<timestamp>] <expected> ...

if not prefixed with a minus (-), <expected> 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 </dev/null
  adb reboot ota
  wait_for_screen
  EXPECT_PROPERTY sys.boot.reason reboot,ota
@@ -679,7 +725,7 @@ a _real_ factory_reset is too destructive to the device." ]
test_factory_reset() {
  checkDebugBuild || return
  duration_test
  adb shell su root rm /data/misc/bootstat/build_date >&2
  adb_su rm /data/misc/bootstat/build_date >&2 </dev/null
  adb reboot >&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 \
    cat /proc/fs/pstore/console-ramoops \
        /proc/fs/pstore/console-ramoops-0 2>/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 </dev/null
  sleep 5
  echo -n "WARNING: Please power device back up, waiting ... " >&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 </dev/null
  sleep 5
  echo -n "WARNING: Please power device back up, waiting ... " >&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 </dev/null
  sleep 5
  echo -n "WARNING: Please power device back up, waiting ... " >&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 </dev/null
  sleep 5
  echo -n "WARNING: Please power device back up, waiting ... " >&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 </dev/null
  wait_for_screen
  EXPECT_PROPERTY sys.boot.reason reboot,shell
  EXPECT_PROPERTY sys.boot.reason.last reboot,shell
@@ -1032,7 +1078,7 @@ rescueparty test
test_optional_rescueparty() {
  blind_reboot_test
  echo "WARNING: legacy devices are allowed to fail following ro.boot.bootreason result" >&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"' </dev/null
  wait_for_screen
  EXPECT_PROPERTY sys.boot.reason reboot,its_just_so_hard
  EXPECT_PROPERTY sys.boot.reason.last reboot,its_just_so_hard
@@ -1146,7 +1192,113 @@ test_bootloader_recovery() {
  run_bootloader
}

[ "USAGE: ${0##*/} [-s SERIAL] [tests]
[ "USAGE: run_kBootReasonMap [--boot_reason_enum] value expected

bootloader boot reason injection tests:
- if --boot_reason_enum run bootstat executable for result instead.
- inject boot reason into sys.boot.reason
- run bootstat --set_system_boot_reason
- check for expected enum
- " ]
run_kBootReasonMap() {
  if [ X"--boot_reason_enum" = X"${1}" ]; then
    shift
    local sys_expected="${1}"
    shift
    local enum_expected="${1}"
    adb_su bootstat --boot_reason_enum="${sys_expected}" |
      (
        local retval=-1
        while read -r id match; do
          if [ ${retval} = -1 -a ${enum_expected} = ${id} ]; then
            retval=0
          fi
          if [ ${enum_expected} != ${id} ]; then
            echo "ERROR: ${enum_expected} ${sys_expected} got ${id} ${match}" >&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
  adb_su bootstat --record_boot_reason </dev/null
  # Check values
  EXPECT_PROPERTY sys.boot.reason "${sys_expected}"
  local retval=${?}
  local result=`adb_su stat -c %Y /data/misc/bootstat/system_boot_reason </dev/null 2>/dev/null`
  [ "${enum_expected}" = "${result}" ] ||
    (
      [ -n "${result}" ] || result="<nothing>"
      echo "ERROR: ${enum_expected} ${sys_expected} got ${result}" >&2
      false
    ) ||
    retval=${?}
  return ${retval}
}

[ "USAGE: filter_kBootReasonMap </dev/stdin >/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 2>/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}" </dev/null || retval=${?}
  done <${tempfile}
  rm ${tempfile}
  ( exit ${retval} )
  # See filter_kBootReasonMap() for negative tests and add them here too
  report_bootstat_logs -t${T} \
    '-bootstat: Service started: bootstat --boot_reason_enum=' \
    '-bootstat: Unknown boot reason: reboot,empty' \
    '-bootstat: Unknown boot reason: reboo'
}

[ "USAGE: ${progname} [-s SERIAL] [tests]...

Mainline executive to run the above tests" ]

@@ -1161,7 +1313,7 @@ fi
if [ X"--macros" != X"${1}" ]; then

  if [ X"--help" = X"${1}" -o X"-h" = X"${1}" -o X"-?" = X"${1}" ]; then
    echo "USAGE: ${0##*/} [-s SERIAL] [tests]"
    echo "USAGE: ${progname} [-s SERIAL] [tests]..."
    echo tests - `sed -n 's/^test_\([^ ()]*\)() {/\1/p' $0 </dev/null`
    exit 0
  fi
@@ -1210,7 +1362,7 @@ if [ X"--macros" != X"${1}" ]; then
               Its_Just_So_Hard_reboot bootloader_normal bootloader_watchdog \
               bootloader_kernel_panic bootloader_oem_powerkey \
               bootloader_wdog_reset bootloader_cold bootloader_warm \
               bootloader_hard bootloader_recovery
               bootloader_hard bootloader_recovery kBootReasonMap
    fi
    if [ X"nothing" = X"${1}" ]; then
      shift 1
+33 −4
Original line number Diff line number Diff line
@@ -89,7 +89,7 @@ void PrintBootEvents() {
}

void ShowHelp(const char* cmd) {
  fprintf(stderr, "Usage: %s [options]\n", cmd);
  fprintf(stderr, "Usage: %s [options]...\n", cmd);
  fprintf(stderr,
          "options include:\n"
          "  -h, --help              Show this help\n"
@@ -99,7 +99,8 @@ void ShowHelp(const char* cmd) {
          "  --value                 Optional value to associate with the boot event\n"
          "  --record_boot_complete  Record metrics related to the time for the device boot\n"
          "  --record_boot_reason    Record the reason why the device booted\n"
          "  --record_time_since_factory_reset Record the time since the device was reset\n");
          "  --record_time_since_factory_reset  Record the time since the device was reset\n"
          "  --boot_reason_enum=<reason>  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<std::string, int32_t> 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;
        }