From 3fba24f36020d20dde22274ade2cbda07e2ce8df Mon Sep 17 00:00:00 2001 From: Ivaylo Asenov Date: Tue, 21 Feb 2017 09:58:45 +0000 Subject: android boottime2: add ANDROID_UI_SHOWN. Change-Id: I10cc8b9f2aa2de15dea933b0657d86f21fad679a Signed-off-by: Ivaylo Asenov --- android/scripts/boottime2.sh | 45 ++++++++++++++++++++++++++++++++++++++++++++ 1 file changed, 45 insertions(+) (limited to 'android/scripts/boottime2.sh') diff --git a/android/scripts/boottime2.sh b/android/scripts/boottime2.sh index 95a2511..b9366a9 100755 --- a/android/scripts/boottime2.sh +++ b/android/scripts/boottime2.sh @@ -70,6 +70,10 @@ ## ## ANDROID_SERVICE_START_TIME: ## from the time kernel started to the time healthd service started +## +## ANDROID_UI_SHOWN: +## time from freeing unused kernel memory to the time +## when UI is shown on display ############################################################################## local_file_path="$0" @@ -99,6 +103,25 @@ getTime(){ fi } + +# logcat_all line example +# 01-01 00:00:26.313 I/SurfaceFlinger( 1850): Boot is finished (11570 ms) +getTimeStampFromLogcat(){ + key=$1 + if [ -z "${key}" ]; then + return + fi + + key_line=$(grep "${key}" "${LOG_LOGCAT_ALL}") + if [ -n "${key_line}" ]; then + timestamp_sec=$(echo "${key_line}"|awk '{print $2}' | awk -F ":" '{print $3}') + timestamp_min=$(echo "${key_line}"|awk '{print $2}' | awk -F ":" '{print $2}') + timestamp=$(echo "${timestamp_sec} ${timestamp_min}" | awk '{printf "%.3f",$1 + $2 * 60;}') + echo "${timestamp}" + fi +} + + getBootTimeInfoFromDmesg(){ COLLECT_NO=$1 @@ -153,6 +176,10 @@ getBootTimeInfoFromDmesg(){ output_test_result "INIT_TO_SURFACEFLINGER_START_TIME" "fail" "-1" "s" fi + POINT_SURFACEFLINGER_BOOT=$(getTimeStampFromLogcat "Boot is finished") + POINT_SURFACEFLINGER_START=$(getTimeStampFromLogcat "SurfaceFlinger is starting") + POINT_LAUNCHER_DISPLAYED=$(getTimeStampFromLogcat "Displayed com.android.launcher") + ## When there are 2 lines of "Boot is finished", ## it mostly means that the surfaceflinger service restarted by some reason ## but here when there are multiple lines of "Boot is finished", @@ -167,6 +194,24 @@ getBootTimeInfoFromDmesg(){ SURFACEFLINGER_BOOT_TIME_MS=$(echo "${SURFACEFLINGER_BOOT_TIME_INFO}"|cut -d\ -f1) SURFACEFLINGER_BOOT_TIME=$(echo "${SURFACEFLINGER_BOOT_TIME_MS}" | awk '{printf "%.3f",$1/1000;}') output_test_result "SURFACEFLINGER_BOOT_TIME" "pass" "${SURFACEFLINGER_BOOT_TIME}" "s" + + if [ ! -z "${POINT_SURFACEFLINGER_BOOT}" ] && [ ! -z "${POINT_LAUNCHER_DISPLAYED}" ] && [ ! -z "${POINT_SURFACEFLINGER_START}" ] && [ ! -z "${INIT_TO_SURFACEFLINGER_START_TIME}" ]; then + + min=$(echo "${POINT_LAUNCHER_DISPLAYED} ${POINT_SURFACEFLINGER_BOOT}" | awk '{if ($1 < $2) printf $1; else print $2}') + + ## In case timestamp of "Boot is finished" is smaller than timestamp of "Displayed com.android.launcher" we calculate ANDROID_UI_SHOWN as "Boot is finished" time minus difference + ## between two timestamps plus INIT_TO_SURFACEFLINGER_START_TIME + if [ "${min}" = "${POINT_SURFACEFLINGER_BOOT}" ]; then + ANDROID_UI_SHOWN=$(echo "${POINT_SURFACEFLINGER_BOOT} ${POINT_SURFACEFLINGER_START} ${POINT_SURFACEFLINGER_BOOT} ${POINT_LAUNCHER_DISPLAYED} ${INIT_TO_SURFACEFLINGER_START_TIME}" | awk '{printf "%.3f",$1 - $2 + $4 - $3 + $5;}') + ## I case timestamp of "Boot is finished" is greater than timestamp of "Displayed com.android.launcher" we use "Boot is finished" time plus INIT_TO_SURFACEFLINGER_START_TIME + ## as ANDROID_UI_SHOWN + else + ANDROID_UI_SHOWN=$(echo "${POINT_SURFACEFLINGER_BOOT} ${POINT_SURFACEFLINGER_START} ${INIT_TO_SURFACEFLINGER_START_TIME}" | awk '{printf "%.3f",$1 - $2 + $3;}') + fi + output_test_result "ANDROID_UI_SHOWN" "pass" "${ANDROID_UI_SHOWN}" "s" + else + output_test_result "ANDROID_UI_SHOWN" "fail" "-1" "s" + fi fi -- cgit v1.2.3