From 271485feba3cd47f1a78be6a590d9e24c7c5229d Mon Sep 17 00:00:00 2001
From: Mark Salyzyn <salyzyn@google.com>
Date: Fri, 9 Nov 2018 13:45:36 -0800
Subject: [PATCH] fs_mgr: overlayfs: test: adding diagnostic value

Add a test report df before overlay applied to make it clearer what
the device looked like before applying for remount.  Check error
code from adb disable-verity and use that to terminate test if bad.
Collect a sliced logcat for failures to help diagnose problems.
If the device does not come back after flashing, timeout and fail
when waiting.  Fix some issues that result when running script under
set -x when diagnosing the tests logistics.

Test: adb-remount-test.sh
Bug: 109821005
Change-Id: Iffbd6261703393417cb6ec3a12042d59523c348d
---
 fs_mgr/tests/adb-remount-test.sh | 55 ++++++++++++++++++++++++++------
 1 file changed, 45 insertions(+), 10 deletions(-)

diff --git a/fs_mgr/tests/adb-remount-test.sh b/fs_mgr/tests/adb-remount-test.sh
index 6cb7502ca..7a0019452 100755
--- a/fs_mgr/tests/adb-remount-test.sh
+++ b/fs_mgr/tests/adb-remount-test.sh
@@ -52,11 +52,27 @@ adb_sh() {
   adb shell "${@}"
 }
 
+[ "USAGE: adb_date >/dev/stdout
+
+Returns: report device epoch time (suitable for logcat -t)" ]
+adb_date() {
+  adb_sh date +%s.%N </dev/null
+}
+
+[ "USAGE: adb_logcat [arguments] >/dev/stdout
+
+Returns: the logcat output" ]
+adb_logcat() {
+  adb logcat "${@}" </dev/null |
+    grep -v 'logd    : logdr: UID=' |
+    sed -e '${/------- beginning of kernel/d}' -e 's/^[0-1][0-9]-[0-3][0-9] //'
+}
+
 [ "USAGE: get_property <prop>
 
 Returns the property value" ]
 get_property() {
-  adb_sh getprop ${1} 2>&1 </dev/null
+  adb_sh getprop ${1} </dev/null
 }
 
 [ "USAGE: isDebuggable
@@ -108,13 +124,22 @@ adb_wait() {
 
 Returns: true if device in root state" ]
 adb_root() {
-  adb root >/dev/null </dev/null 2>&1 &&
+  adb root >/dev/null </dev/null 2>/dev/null &&
   sleep 1 &&
   adb_wait &&
   sleep 1
 }
 
+[ "USAGE: die [-t <epoch>] [message] >/dev/stderr
+
+If -t <epoch> argument is supplied, dump logcat.
+
+Returns: exit failure, report status" ]
 die() {
+  if [ X"-t" = X"${1}" -a -n "${2}" ]; then
+    adb_logcat -b all -v nsec -t ${2} >&2
+    shift 2
+  fi
   echo "${RED}[  FAILED  ]${NORMAL} ${@}" >&2
   exit 1
 }
@@ -214,7 +239,7 @@ adb_root &&
 reboot=false
 OVERLAYFS_BACKING="cache mnt/scratch"
 for d in ${OVERLAYFS_BACKING}; do
-  if adb_sh ls -d /${d}/overlay </dev/null >/dev/null 2>&1; then
+  if adb_sh ls -d /${d}/overlay </dev/null >/dev/null 2>/dev/null; then
     echo "${ORANGE}[  WARNING ]${NORMAL} /${d}/overlay is setup, wiping" >&2
     adb_sh rm -rf /${d}/overlay </dev/null ||
       die "/${d}/overlay wipe"
@@ -236,10 +261,17 @@ D=`adb_sh df -k </dev/null` &&
   echo "${D}" &&
   echo "${ORANGE}[  WARNING ]${NORMAL} overlays present before setup" >&2 ||
   echo "${GREEN}[       OK ]${NORMAL} no overlay present before setup" >&2
+adb_sh df -k `adb_sh cat /proc/mounts |
+                skip_administrative_mounts |
+                cut -s -d' ' -f1`
 
-D=`adb disable-verity 2>&1` ||
-  die "setup for overlay ${D}"
+T=`adb_date`
+D=`adb disable-verity 2>&1`
+err=${?}
 echo "${D}"
+if [ ${err} != 0 -o X"${D}" != X"${D##*setup failed}" ]; then
+  die -t ${T} "setup for overlay"
+fi
 if [ X"${D}" != X"${D##*using overlayfs}" ]; then
   echo "${GREEN}[       OK ]${NORMAL} using overlayfs" >&2
 fi
@@ -254,11 +286,12 @@ adb_reboot &&
 echo "${D}" | grep "^overlay .* /system\$" >/dev/null ||
   echo "${ORANGE}[  WARNING ]${NORMAL} overlay takeover before remount not complete" >&2
 
+T=`adb_date`
 adb_root &&
   adb_wait &&
   adb remount &&
   D=`adb_sh df -k </dev/null` ||
-  die "can not collect filesystem data"
+  die -t ${T} "can not collect filesystem data"
 if echo "${D}" | grep " /mnt/scratch" >/dev/null; then
   echo "${ORANGE}[     INFO ]${NORMAL} using scratch dynamic partition for overrides" >&2
   H=`adb_sh cat /proc/mounts | sed -n 's@\([^ ]*\) /mnt/scratch \([^ ]*\) .*@\2 on \1@p'`
@@ -266,7 +299,7 @@ if echo "${D}" | grep " /mnt/scratch" >/dev/null; then
     echo "${ORANGE}[     INFO ]${NORMAL} scratch filesystem ${H}"
 fi
 for d in ${OVERLAYFS_BACKING}; do
-  if adb_sh ls -d /${d}/overlay/system/upper </dev/null >/dev/null 2>&1; then
+  if adb_sh ls -d /${d}/overlay/system/upper </dev/null >/dev/null 2>/dev/null; then
     echo "${ORANGE}[     INFO ]${NORMAL} /${d}/overlay is setup" >&2
   fi
 done
@@ -316,8 +349,9 @@ adb reboot-fastboot &&
   fastboot flash vendor &&
   fastboot reboot ||
   die "fastbootd flash vendor"
-adb_wait &&
-  adb_root &&
+adb_wait 2m ||
+  die "did not reboot after flash"
+adb_root &&
   adb_wait &&
   D=`adb_sh df -k </dev/null` &&
   H=`echo "${D}" | head -1` &&
@@ -338,10 +372,11 @@ B="`adb_cat /vendor/hello`" &&
   die "re-read vendor hello after flash vendor"
 check_eq "cat: /vendor/hello: No such file or directory" "${B}" vendor after flash vendor
 
+T=`adb_date`
 adb remount &&
   ( adb_sh rm /vendor/hello </dev/null 2>/dev/null || true ) &&
   adb_sh rm /system/hello </dev/null ||
-  die "cleanup hello"
+  die -t ${T} "cleanup hello"
 B="`adb_cat /system/hello`" &&
   die "re-read system hello after rm"
 check_eq "cat: /system/hello: No such file or directory" "${B}" after flash rm