From e7f4b61ed2452023dc1a66cf94323d5f3b8199bb Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?Oliv=C3=A9r=20Falvai?= <oliver.falvai@bitrise.io>
Date: Thu, 7 Jul 2022 10:35:40 +0200
Subject: [PATCH] Increase boot timeout, better error messages (#40)

* Increase boot timeout, better error messages

* Cleanup
---
 main.go | 46 +++++++++++++++++++++++++++++++---------------
 1 file changed, 31 insertions(+), 15 deletions(-)

diff --git a/main.go b/main.go
index d2a9bfd..d1421eb 100755
--- a/main.go
+++ b/main.go
@@ -37,13 +37,16 @@ var (
 )
 
 const (
-	maxAttempts = 5
+	bootTimeout         = time.Duration(10) * time.Minute
+	deviceCheckInterval = time.Duration(5) * time.Second
+	maxBootAttempts     = 5
 )
 
 func runningDeviceInfos(androidHome string) (map[string]string, error) {
 	cmd := command.New(filepath.Join(androidHome, "platform-tools", "adb"), "devices")
 	out, err := cmd.RunAndReturnTrimmedCombinedOutput()
 	if err != nil {
+		log.Printf(err.Error())
 		return map[string]string{}, fmt.Errorf("command failed, error: %s", err)
 	}
 
@@ -229,32 +232,45 @@ func startEmulator(emulatorPath string, args []string, androidHome string, runni
 
 	log.Infof("Starting device")
 	log.Donef("$ %s", deviceStartCmd.PrintableCommandArgs())
-	// start the emlator as a detached process
-	emulatorWaitCh := make(chan error, 1)
+
+	// The emulator command won't exit after the boot completes, so we start the command and not wait for its result.
+	// Instead, we have a loop with 3 channels:
+	// 1. One that waits for the emulator process to exit
+	// 2. A boot timeout timer
+	// 3. A ticker that periodically checks if the device has become online
 	if err := deviceStartCmd.GetCmd().Start(); err != nil {
 		failf("Failed to run device start command: %v", err)
 	}
+
+	emulatorWaitCh := make(chan error, 1)
 	go func() {
 		emulatorWaitCh <- deviceStartCmd.GetCmd().Wait()
 	}()
 
+	timeoutTimer := time.NewTimer(bootTimeout)
+
+	deviceCheckTicker := time.NewTicker(deviceCheckInterval)
+
 	var serial string
-	const bootWaitTime = time.Duration(300)
-	timeout := time.NewTimer(bootWaitTime * time.Second)
-	deviceCheckTicker := time.NewTicker(5 * time.Second)
 	retry := false
 waitLoop:
 	for {
 		select {
 		case err := <-emulatorWaitCh:
-			log.Warnf("Emulator log: %s", output)
+			log.Warnf("Emulator process exited early")
 			if err != nil {
-				failf("Emulator exited unexpectedly: %v", err)
+				log.Errorf("Emulator exit reason: %v", err)
+			} else {
+				log.Warnf("A possible cause can be the emulator process having received a KILL signal.")
 			}
-			failf("Emulator exited early, without error. A possible cause can be the emulator process having received a KILL signal.")
-		case <-timeout.C:
-			log.Warnf("Emulator log: %s", output)
-			failf("Failed to boot emulator device within %d seconds.", bootWaitTime)
+			log.Printf("Emulator log: %s", output)
+			failf("Emulator exited early, see logs above.")
+		case <-timeoutTimer.C:
+			// Include error before and after printing the emulator log because it's so long
+			errorMsg := fmt.Sprintf("Failed to boot emulator device within %d seconds.", bootTimeout/time.Second)
+			log.Errorf(errorMsg)
+			log.Printf("Emulator log: %s", output)
+			failf(errorMsg)
 		case <-deviceCheckTicker.C:
 			var err error
 			serial, err = queryNewDeviceSerial(androidHome, runningDevices)
@@ -269,17 +285,17 @@ waitLoop:
 				if err := deviceStartCmd.GetCmd().Process.Kill(); err != nil {
 					failf("Couldn't finish emulator process: %v", err)
 				}
-				if attempt < maxAttempts {
+				if attempt < maxBootAttempts {
 					log.Warnf("Trying to start emulator process again...")
 					retry = true
 					break waitLoop
 				} else {
-					failf("Failed to boot device due to faults after %d tries", maxAttempts)
+					failf("Failed to boot device due to faults after %d tries", maxBootAttempts)
 				}
 			}
 		}
 	}
-	timeout.Stop()
+	timeoutTimer.Stop()
 	deviceCheckTicker.Stop()
 	if retry {
 		return startEmulator(emulatorPath, args, androidHome, runningDevices, attempt+1)