diff options
-rw-r--r-- | android/boottime2.yaml | 24 | ||||
-rwxr-xr-x | android/scripts/boottime2.sh | 162 | ||||
-rw-r--r-- | android/scripts/common.sh | 89 |
3 files changed, 233 insertions, 42 deletions
diff --git a/android/boottime2.yaml b/android/boottime2.yaml new file mode 100644 index 0000000..b4044bd --- /dev/null +++ b/android/boottime2.yaml @@ -0,0 +1,24 @@ +metadata: + name: boottime2 + format: "Lava-Test-Shell Test Definition 1.0" + description: "collect the boottime data many times and try to analyse, + when run more than 4 times(including), the average will be + calculated without the maximum and the minmun, if run less + than or equal to 3 time, the average will be calculated with + all data" + maintainer: + - yongqin.liu@linaro.org + os: + - android + scope: + - performance + devices: + - juno + +params: + OPERATION: "COLLECT" + COLLECT_NO: "1" + +run: + steps: + - ./android/scripts/boottime2.sh ${OPERATION} ${COLLECT_NO} diff --git a/android/scripts/boottime2.sh b/android/scripts/boottime2.sh new file mode 100755 index 0000000..d867b0d --- /dev/null +++ b/android/scripts/boottime2.sh @@ -0,0 +1,162 @@ +#!/system/bin/sh + +local_file_path="$0" +local_file_parent=$(dirname "${local_file_path}") +local_file_parent=$(cd "${local_file_parent}"||exit; pwd) +# shellcheck source=android/scripts/common.sh +. "${local_file_parent}/common.sh" + +local_tmp="/data/local/tmp/" +dir_boottime_data="${local_tmp}/boottime" +F_RAW_DATA_CSV="${dir_boottime_data}/boot_time_raw_data.csv" +F_STATISTIC_DATA_CSV="${dir_boottime_data}/boot_time_statistic_data.csv" + + +# dmeg line example +# [ 7.410422] init: Starting service 'logd'... +getTime(){ + key=$1 + if [ -z "${key}" ]; then + return + fi + + key_line=$(grep "${key}" "${LOG_DMESG}") + if [ -n "${key_line}" ]; then + timestamp=$(echo "${key_line}"|awk '{print $2}' | awk -F "]" '{print $1}') + echo "${timestamp}" + fi +} + +getBootTimeInfoFromDmesg(){ + COLLECT_NO=$1 + + LOG_LOGCAT_ALL="${dir_boottime_data}/logcat_all_${COLLECT_NO}.log" + LOG_DMESG="${dir_boottime_data}/dmesg_${COLLECT_NO}.log" + + # dmesg starts before all timers are initialized, so kernel reports time as 0.0. + # we can't work around this without external time metering. + # here we presume kernel message starts from 0 + CONSOLE_SECONDS_START=0 + CONSOLE_SECONDS_END=$(getTime "Freeing unused kernel memory") + if [ ! -z "${CONSOLE_SECONDS_END}" ] && [ ! -z "${CONSOLE_SECONDS_START}" ]; then + CONSOLE_SECONDS=$(echo "$CONSOLE_SECONDS_END $CONSOLE_SECONDS_START - p" | dc) + output_test_result "KERNEL_BOOT_TIME" "pass" "${CONSOLE_SECONDS}" "s" + else + output_test_result "KERNEL_BOOT_TIME" "fail" "-1" "s" + fi + + POINT_FS_MOUNT_START=$(getTime "Freeing unused kernel memory:"|tail -n1) + POINT_FS_MOUNT_END=$(getTime "init: Starting service 'logd'...") + if [ ! -z "${POINT_FS_MOUNT_END}" ] && [ ! -z "${POINT_FS_MOUNT_START}" ]; then + FS_MOUNT_TIME=$(echo "${POINT_FS_MOUNT_END} ${POINT_FS_MOUNT_START} - p" | dc) + output_test_result "FS_MOUNT_TIME" "pass" "${FS_MOUNT_TIME}" "s" + else + output_test_result "FS_MOUNT_TIME" "fail" "-1" "s" + fi + + POINT_FS_DURATION_START=$(getTime "init: /dev/hw_random not found"|tail -n1) + POINT_FS_DURATION_END=$(getTime "init: Starting service 'logd'...") + if [ ! -z "${POINT_FS_DURATION_END}" ] && [ ! -z "${POINT_FS_DURATION_START}" ]; then + FS_MOUNT_DURATION=$(echo "${POINT_FS_DURATION_END} ${POINT_FS_DURATION_START} - p" | dc) + output_test_result "FS_MOUNT_DURATION" "pass" "${FS_MOUNT_DURATION}" "s" + else + output_test_result "FS_MOUNT_DURATION" "fail" "-1" "s" + fi + + POINT_SERVICE_BOOTANIM_START=$(getTime "init: Starting service \'bootanim\'...") + POINT_SERVICE_BOOTANIM_END=$(getTime "init: Service 'bootanim'.* exited with status") + if [ ! -z "${POINT_SERVICE_BOOTANIM_END}" ] && [ ! -z "${POINT_SERVICE_BOOTANIM_START}" ]; then + BOOTANIM_TIME=$(echo "${POINT_SERVICE_BOOTANIM_END} ${POINT_SERVICE_BOOTANIM_START} - p" | dc) + output_test_result "BOOTANIM_TIME" "pass" "${BOOTANIM_TIME}" "s" + else + output_test_result "BOOTANIM_TIME" "fail" "-1" "s" + fi + + TIME_INFO=$(grep "Boot is finished" "${LOG_LOGCAT_ALL}") + if [ -z "${TIME_INFO}" ]; then + output_test_result "ANDROID_BOOT_TIME" "fail" "-1" "s" + else + while echo "${TIME_INFO}"|grep -q "("; do + TIME_INFO=$(echo "${TIME_INFO}"|cut -d\( -f2-) + done + TIME_VALUE=$(echo "${TIME_INFO}"|cut -d\ -f1) + ANDROID_BOOT_TIME=$(echo "${TIME_VALUE} 1000 / p" | dc) + output_test_result "ANDROID_BOOT_TIME" "pass" "${ANDROID_BOOT_TIME}" "s" + fi + + SERVICE_START_TIME_INFO=$(grep "healthd:" "${LOG_DMESG}"|head -n 1) + SERVICE_START_TIME_END=$(echo "$SERVICE_START_TIME_INFO"|cut -d] -f 1|cut -d[ -f2| tr -d " ") + if [ ! -z "${SERVICE_START_TIME_END}" ] && [ ! -z "${CONSOLE_SECONDS_START}" ]; then + SERVICE_START_TIME=$(echo "$SERVICE_START_TIME_END $CONSOLE_SECONDS_START - p" | dc) + output_test_result "ANDROID_SERVICE_START_TIME" "pass" "${SERVICE_START_TIME}" "s" + else + output_test_result "ANDROID_SERVICE_START_TIME" "fail" "-1" "s" + fi + + echo "$CONSOLE_SECONDS $TIME_VALUE 1000 / + p" + if [ ! -z "${CONSOLE_SECONDS}" ] && [ ! -z "${TIME_VALUE}" ]; then + TOTAL_SECONDS=$(echo "$CONSOLE_SECONDS $TIME_VALUE 1000 / + p" | dc) + output_test_result "TOTAL_BOOT_TIME" "pass" "${TOTAL_SECONDS}" "s" + else + output_test_result "TOTAL_BOOT_TIME" "fail" "-1" "s" + fi +} + +OPERATION=$1 +if [ "X${OPERATION}" = "XCOLLECT" ]; then + G_VERBOSE_OUTPUT=FALSE + G_RECORD_LOCAL_CSV=FALSE + COLLECT_NO=$2 + mkdir -p ${dir_boottime_data} + + # shellcheck disable=SC2035 + logcat -d -v time *:V > "${dir_boottime_data}/logcat_all_${COLLECT_NO}.log" + output_test_result "BOOTTIME_LOGCAT_ALL_COLLECT" "pass" + logcat -d -b events -v time > "${dir_boottime_data}/logcat_events_${COLLECT_NO}.log" + output_test_result "BOOTTIME_LOGCAT_EVENTS_COLLECT" "pass" + dmesg > "${dir_boottime_data}/dmesg_${COLLECT_NO}.log" + output_test_result "BOOTTIME_DMESG_COLLECT" "pass" +elif [ "X${OPERATION}" = "XANALYZE" ]; then + count=$2 + i=1 + G_RESULT_NOT_RECORD=TRUE + G_RECORD_LOCAL_CSV=TRUE + export G_RECORD_LOCAL_CSV G_RESULT_NOT_RECORD + while true; do + if [ $i -gt "$count" ]; then + break + fi + getBootTimeInfoFromDmesg ${i} + i=$((i+1)) + done + G_RESULT_NOT_RECORD=FALSE + export G_RESULT_NOT_RECORD + if [ "X${G_RECORD_LOCAL_CSV}" = "XTRUE" ]; then + statistic ${F_RAW_DATA_CSV} 2 |tee ${F_STATISTIC_DATA_CSV} + sed -i 's/=/,/' "${F_STATISTIC_DATA_CSV}" + + G_RECORD_LOCAL_CSV=FALSE + export G_RECORD_LOCAL_CSV + while read -r line; do + if ! echo "$line"|grep -q ,; then + continue + fi + key=$(echo "$line"|cut -d, -f1) + measurement=$(echo "$line"|cut -d, -f2) + units=$(echo "$line"|cut -d, -f3) + output_test_result "${key}" "pass" "${measurement}" "${units}" + done < "${F_STATISTIC_DATA_CSV}" + fi + # set again for following output_test_result + G_RECORD_LOCAL_CSV=FALSE + cd ${local_tmp}|| exit 1 + tar -czvf boottime.tgz boottime + lava-test-run-attach boottime.tgz application/x-gzip + output_test_result "BOOTTIME_ANALYZE" "pass" +else + G_VERBOSE_OUTPUT=FALSE + G_RECORD_LOCAL_CSV=FALSE + export G_VERBOSE_OUTPUT G_RECORD_LOCAL_CSV + echo "Not recognised operation" + output_test_result "BOOTTIME" "fail" +fi diff --git a/android/scripts/common.sh b/android/scripts/common.sh index bc4a526..b2f9091 100644 --- a/android/scripts/common.sh +++ b/android/scripts/common.sh @@ -3,8 +3,10 @@ G_LOOP_COUNT=12 G_RECORD_LOCAL_CSV=TRUE G_VERBOSE_OUTPUT=FALSE +G_RESULT_NOT_RECORD=FALSE F_RAW_DATA_CSV="/data/local/tmp/lava_test_shell_raw_data.csv" F_STATISTIC_DATA_CSV="/data/local/tmp/lava_test_shell_statistic_data.csv" +var_test_func="" ## Description: ## output the max value of the passed 2 parameters @@ -13,10 +15,10 @@ F_STATISTIC_DATA_CSV="/data/local/tmp/lava_test_shell_statistic_data.csv" ## Example: ## max=$(f_max "1.5" "2.0") f_max(){ - local val1=$1 - local val2=$2 - [ -z "$val1" ] && echo $val2 - [ -z "$val2" ] && echo $val1 + val1=$1 + val2=$2 + [ -z "$val1" ] && echo "$val2" + [ -z "$val2" ] && echo "$val1" echo "$val1,$val2"|awk -F, '{if($1<$2) print $2; else print $1}' } @@ -28,10 +30,10 @@ f_max(){ ## Example: ## min=$(f_min "1.5" "2.0") f_min(){ - local val1=$1 - local val2=$2 - [ -z "$val1" ] && echo $val1 - [ -z "$val2" ] && echo $val2 + val1=$1 + val2=$2 + [ -z "$val1" ] && echo "$val1" + [ -z "$val2" ] && echo "$val2" echo "$val1,$val2"|awk -F, '{if($1>$2) print $2; else print $1}' } @@ -48,30 +50,31 @@ f_min(){ ## if less than 4 samples for that key/item there, average will be calculated as total/count ## if 4 or more samples for that key/item there, average will be calculated with max and min excluded statistic(){ - local f_data=$1 + f_data=$1 if ! [ -f "$f_data" ]; then return fi - local field_no=$2 + field_no=$2 if [ -z "$field_no" ]; then field_no=2 fi - local total=0 - local max=0 - local min=0 - local old_key="" - local new_key="" - local count=0 - local units="" - sort ${f_data} >${f_data}.sort - for line in $(cat "${f_data}.sort" |tr ' ' '~'); do + total=0 + max=0 + min=0 + old_key="" + new_key="" + count=0 + units="" + sort "${f_data}" >"${f_data}.sort" + while read -r line; do + line=$(echo "$line"|tr ' ' '~') if ! echo "$line"|grep -q ,; then continue fi - new_key=$(echo $line|cut -d, -f1) - local measurement_units=$(echo $line|cut -d, -f${field_no}) - if echo ${measurement_units}|grep -q '~'; then - value=$(echo ${measurement_units}|cut -d~ -f1) + new_key=$(echo "$line"|cut -d, -f1) + measurement_units=$(echo "$line"|cut -d, -f${field_no}) + if echo "${measurement_units}"|grep -q '~'; then + value=$(echo "${measurement_units}"|cut -d~ -f1) else value=${measurement_units} fi @@ -83,7 +86,7 @@ statistic(){ min=$(f_min "$min" "$value") else if [ "X${old_key}" != "X" ]; then - if [ $count -ge 4 ]; then + if [ "${count}" -ge 4 ]; then average=$(echo "${total},${max},${min},$count"|awk -F, '{printf "%.2f",($1-$2-$3)/($4-2);}') else average=$(echo "${total},$count"|awk -F, '{printf "%.2f",$1/$2;}') @@ -99,13 +102,13 @@ statistic(){ min="${value}" old_key="${new_key}" count=1 - if echo ${measurement_units}|grep -q '~'; then - units=$(echo ${measurement_units}|cut -d~ -f2) + if echo "${measurement_units}"|grep -q '~'; then + units=$(echo "${measurement_units}"|cut -d~ -f2) else units="" fi fi - done + done < "${f_data}.sort" if [ "X${new_key}" != "X" ]; then if [ $count -ge 4 ]; then average=$(echo "${total},${max},${min},$count"|awk -F, '{printf "%.2f",($1-$2-$3)/($4-2);}') @@ -133,17 +136,17 @@ statistic(){ ## G_VERBOSE_OUTPUT: when this environment variant is set to "TRUE", and only it is TRUE, ## the verbose informain about the result will be outputed output_test_result(){ - local test_name=$1 - local result=$2 - local measurement=$3 - local units=$4 + test_name=$1 + result=$2 + measurement=$3 + units=$4 if [ -z "${test_name}" ] || [ -z "$result" ]; then return fi - local output="" - local lava_paras="" - local output_csv="" + output="" + lava_paras="" + output_csv="" if [ -z "$units" ]; then units="points" fi @@ -160,8 +163,9 @@ output_test_result(){ echo "${output}" fi - local cmd="lava-test-case" - if [ -n "$(which $cmd)" ];then + cmd="lava-test-case" + if [ "X${G_RESULT_NOT_RECORD}" = "XFALSE" ] && [ -n "$(which $cmd)" ];then + # shellcheck disable=SC2086 $cmd ${lava_paras} elif [ "X${G_VERBOSE_OUTPUT}" = "XTRUE" ];then echo "$cmd ${lava_paras}" @@ -174,17 +178,18 @@ output_test_result(){ } func_print_usage_common(){ - echo "$(basename $0) [--record-csv TRUE|others] [--loop-count LOOP_COUNT]" + script_name=$(basename "$0") + echo "${script_name} [--record-csv TRUE|others] [--loop-count LOOP_COUNT]" echo " --record-csv: specify if record the result in csv format in file ${F_RAW_DATA_CSV}" echo " Only record the file when TRUE is specified." echo " --loop-count: specify the number that how many times should be run for each application to get the average result, default is 12" echo " --verbose-output: output the result and lava-test-case command for each test case each time it is run" - echo "$(basename $0) [--help|-h]" + echo "${script_name} [--help|-h]" echo " print out this usage." } func_parse_parameters_common(){ - local para_loop_count="" + para_loop_count="" while [ -n "$1" ]; do case "X$1" in X--record-csv) @@ -228,7 +233,7 @@ func_parse_parameters_common(){ done if [ -n "${para_loop_count}" ]; then - local tmp_str=$(echo ${para_loop_count}|tr -d '[:digit:]') + tmp_str=$(echo "${para_loop_count}"|tr -d '[:digit:]') if [ -z "${tmp_str}" ]; then G_LOOP_COUNT=${para_loop_count} else @@ -264,11 +269,11 @@ run_test(){ if [ "X${G_RECORD_LOCAL_CSV}" = "XTRUE" ]; then [ -f "${F_RAW_DATA_CSV}" ] && rm "${F_RAW_DATA_CSV}" [ -f "${F_STATISTIC_DATA_CSV}" ] && rm "${F_STATISTIC_DATA_CSV}" - mkdir -p $(dirname ${F_RAW_DATA_CSV}) + mkdir -p "$(dirname ${F_RAW_DATA_CSV})" fi loop_index=0 - while [ ${loop_index} -lt ${G_LOOP_COUNT} ]; do + while [ "${loop_index}" -lt "${G_LOOP_COUNT}" ]; do if [ -n "${var_test_func}" ]; then ${var_test_func} fi |