Add logs for android cuttlefish startup issue (#3621)

Author: marktefftech

src/clusterfuzz/_internal/bot/init_scripts/android.py

@@ -33,17 +33,21 @@ def run():
     logs.log('Running Android init script on non-Cuttlefish.')
 
   # Check if we need to reflash device to latest build.
+  logs.log('Init: flash_to_latest_build_if_needed.')
   android.flash.flash_to_latest_build_if_needed()
 
   # Reconnect to cuttlefish device if connection is ever lost.
   if environment.is_android_cuttlefish():
+    logs.log('Init: connect_to_cuttlefish_device.')
     android.adb.connect_to_cuttlefish_device()
 
   # Reboot to bring device in a good state if not done recently.
   if android.adb.time_since_last_reboot() > TIME_SINCE_REBOOT_MIN_THRESHOLD:
+    logs.log('Init: reboot.')
     android.device.reboot()
 
   # Make sure that device is in a good condition before we move forward.
+  logs.log('Init: wait_until_fully_booted.')
   android.adb.wait_until_fully_booted()
 
   # Wait until battery charges to a minimum level and temperature threshold.

src/clusterfuzz/_internal/platforms/android/adb.py

@@ -31,8 +31,8 @@
 from clusterfuzz._internal.system import shell
 
 ADB_TIMEOUT = 1200  # Should be lower than |REBOOT_TIMEOUT|.
-BAD_STATE_WAIT = 900
-BOOT_WAIT_INTERVAL = 30
+BAD_STATE_WAIT = 60 * 60  # 60 mins
+BOOT_WAIT_INTERVAL = 60 * 2
 CUTTLEFISH_USER = 'vsoc-01'
 CUTTLEFISH_CVD_PORT = 6520
 DEFAULT_DEVICE_MEMORY_MB = 2048
@@ -48,7 +48,7 @@
 MONKEY_PROCESS_NAME = 'monkey'
 WAIT_FOR_DEVICE_TIMEOUT = 600
 REBOOT_TIMEOUT = 3600
-RECOVERY_CMD_TIMEOUT = 60
+RECOVERY_CMD_TIMEOUT = 60 * 2
 GET_DEVICE_STATE_TIMEOUT = 20
 STOP_CVD_WAIT = 20
 LAUNCH_CVD_TIMEOUT = 2700
@@ -183,6 +183,7 @@ def copy_to_cuttlefish(src_path, dest_path, timeout=None):
 
 def factory_reset():
   """Reset device to factory state."""
+  logs.log('reached factory_reset')
   if environment.is_android_cuttlefish():
     # We cannot recover from this since there can be cases like userdata image
     # corruption in /data/data. Till the bug is fixed, we just need to wait
@@ -438,6 +439,7 @@ def stop_cuttlefish_device():
   cvd_dir = environment.get_value('CVD_DIR')
   cvd_bin_dir = os.path.join(cvd_dir, 'bin')
   stop_cvd_cmd = os.path.join(cvd_bin_dir, 'stop_cvd')
+  logs.log('stop_cvd_cmd: %', str(stop_cvd_cmd))
 
   execute_command(
       stop_cvd_cmd, timeout=RECOVERY_CMD_TIMEOUT, on_cuttlefish_host=True)
@@ -457,6 +459,7 @@ def recreate_cuttlefish_device():
   """Recreate cuttlefish device, restoring from backup images."""
   logs.log('Reimaging cuttlefish device.')
   cvd_dir = environment.get_value('CVD_DIR')
+  logs.log('cvd_dir: %', cvd_dir)
 
   stop_cuttlefish_device()
 

src/clusterfuzz/_internal/platforms/android/fetch_artifact.py

@@ -49,12 +49,17 @@ def execute_request_with_retries(request):
 def download_artifact(client, bid, target, attempt_id, name, output_directory,
                       output_filename):
   """Download one artifact."""
+  logs.log('reached download_artifact')
+  logs.log('artifact to download: %', name)
+  logs.log('output_directory: %', output_directory)
+  logs.log('output_filename: %', output_filename)
   artifact_query = client.buildartifact().get(
       buildId=bid, target=target, attemptId=attempt_id, resourceId=name)
   artifact = execute_request_with_retries(artifact_query)
   if artifact is None:
-    logs.log_error('No artifact found with name %s, target %s and build id %s.'
-                   % (name, target, bid))
+    logs.log_error(
+        'Artifact unreachable with name %s, target %s and build id %s.' %
+        (name, target, bid))
     return False
 
   # Lucky us, we always have the size.
@@ -81,6 +86,7 @@ def download_artifact(client, bid, target, attempt_id, name, output_directory,
 
   logs.log('Downloading artifact %s.' % name)
   output_dir = os.path.dirname(output_path)
+  logs.log('Output dir: %', output_dir)
   if not os.path.exists(output_dir):
     logs.log(f'Creating directory {output_dir}')
     os.mkdir(output_dir)
@@ -198,8 +204,8 @@ def run_script(client, bid, target, regex, output_directory, output_filename):
   artifacts = get_artifacts_for_build(
       client=client, bid=bid, target=target, attempt_id='latest')
   if not artifacts:
-    logs.log_error(
-        'No artifact found for target %s, build id %s.' % (target, bid))
+    logs.log_error('Artifact could not be fetched for target %s, build id %s.' %
+                   (target, bid))
     return False
 
   regex = re.compile(regex)

src/clusterfuzz/_internal/platforms/android/flash.py

@@ -52,6 +52,8 @@
     ('userdata', 'userdata.img'),
 ]
 FLASH_DEFAULT_BUILD_TARGET = '-next-userdebug'
+FLASH_DEFAULT_IMAGES_DIR = os.path.join(
+    environment.get_value('ROOT_DIR'), 'bot', 'inputs', 'images')
 FLASH_INTERVAL = 1 * 24 * 60 * 60
 FLASH_RETRIES = 3
 FLASH_REBOOT_BOOTLOADER_WAIT = 15
@@ -147,6 +149,11 @@ def flash_to_latest_build_if_needed():
     return
 
   image_directory = environment.get_value('IMAGES_DIR')
+  logs.log('image_directory: %', image_directory)
+  if not image_directory:
+    logs.log('no image_directory set, setting to default')
+    image_directory = FLASH_DEFAULT_IMAGES_DIR
+    logs.log('image_directory: %', image_directory)
   build_info = fetch_artifact.get_latest_artifact_info(branch, target)
   if not build_info:
     logs.log_error('Unable to fetch information on latest build artifact for '