Add updates from ORT android emulator handling (#588)

* Update JDK version to 17 in ci.yml

* Update com.diffplug.spotless to 6.22.0.

* Copy updated scripts to start/stop the emulator from ORT from https://github.com/microsoft/onnxruntime/pull/17903.
Minimize the time the emulator is running as well.

* Fix includes

* Update to JDK 17 in packaging pipelines.

* Fix pool name.

---------

Co-authored-by: Edward Chen <18449977+edgchen1@users.noreply.github.com>

.pipelines/android_packaging.yml

@@ -32,27 +32,27 @@ jobs:
           python ./tools/gen_selectedops.py ./tools/android/package_ops.config
         displayName: "Generate selected ops CMake file"
 
+      - bash: |
+          set -e -x
+
+          python ./tools/android/build_aar.py \
+            --output_dir $(Build.BinariesDirectory)/android_aar \
+            --config $(buildConfig) \
+            -- \
+            --one_cmake_extra_define OCOS_ENABLE_SELECTED_OPLIST=ON
+
+          VERSION=$(cat ./version.txt)
+          AAR_PATH="$(Build.BinariesDirectory)/android_aar/aar_out/$(buildConfig)/com/microsoft/onnxruntime/onnxruntime-extensions-android/${VERSION}/onnxruntime-extensions-android-${VERSION}.aar"
+
+          # Do not output ##vso[] commands with `set -x` or they may be parsed again and include a trailing quote.
+          set +x
+          echo "##vso[task.setvariable variable=ORT_EXTENSIONS_AAR_PATH]${AAR_PATH}"
+        displayName: Build onnxruntime-extensions AAR package
+
       - template: templates/run-with-android-emulator-steps.yml
         parameters:
           steps:
 
-          - bash: |
-              set -e -x
-
-              python ./tools/android/build_aar.py \
-                --output_dir $(Build.BinariesDirectory)/android_aar \
-                --config $(buildConfig) \
-                -- \
-                --one_cmake_extra_define OCOS_ENABLE_SELECTED_OPLIST=ON
-
-              VERSION=$(cat ./version.txt)
-              AAR_PATH="$(Build.BinariesDirectory)/android_aar/aar_out/$(buildConfig)/com/microsoft/onnxruntime/onnxruntime-extensions-android/${VERSION}/onnxruntime-extensions-android-${VERSION}.aar"
-
-              # Do not output ##vso[] commands with `set -x` or they may be parsed again and include a trailing quote.
-              set +x
-              echo "##vso[task.setvariable variable=ORT_EXTENSIONS_AAR_PATH]${AAR_PATH}"
-            displayName: Build onnxruntime-extensions AAR package
-
           - bash: |
               set -e -x
 

.pipelines/ci.yml

@@ -95,7 +95,7 @@ stages:
 
     - script: cd test && python -m pytest . --verbose
       displayName: Run python test
-  
+
   ###############
   # Linux PyDebug
   ###############
@@ -452,7 +452,7 @@ stages:
         set OCOS_SCB_DEBUG=1
         python -m pip install -v -e .
       displayName: Build onnxruntime-extensions in editable mode.
-        
+
     - script: |
         python -m pip install -r requirements-dev.txt
         python -m pip install torch torchvision torchaudio
@@ -521,23 +521,23 @@ stages:
     - script: brew install coreutils ninja
       displayName: Install coreutils and ninja
 
+    - bash: |
+        set -e -x
+
+        _BUILD_CFG="x86_64 $(Build.BinariesDirectory)/android_aar" ./build.android
+
+        VERSION=$(cat ./version.txt)
+        AAR_PATH="$(Build.BinariesDirectory)/android_aar/aar_out/com/microsoft/onnxruntime/onnxruntime-extensions-android/${VERSION}/onnxruntime-extensions-android-${VERSION}.aar"
+
+        # Do not output ##vso[] commands with `set -x` or they may be parsed again and include a trailing quote.
+        set +x
+        echo "##vso[task.setvariable variable=ORT_EXTENSIONS_AAR_PATH]${AAR_PATH}"
+      displayName: Build onnxruntime-extensions AAR package
+
     - template: templates/run-with-android-emulator-steps.yml
       parameters:
         steps:
 
-        - bash: |
-            set -e -x
-
-            _BUILD_CFG="x86_64 $(Build.BinariesDirectory)/android_aar" ./build.android
-
-            VERSION=$(cat ./version.txt)
-            AAR_PATH="$(Build.BinariesDirectory)/android_aar/aar_out/com/microsoft/onnxruntime/onnxruntime-extensions-android/${VERSION}/onnxruntime-extensions-android-${VERSION}.aar"
-
-            # Do not output ##vso[] commands with `set -x` or they may be parsed again and include a trailing quote.
-            set +x
-            echo "##vso[task.setvariable variable=ORT_EXTENSIONS_AAR_PATH]${AAR_PATH}"
-          displayName: Build onnxruntime-extensions AAR package
-
         - bash: |
             set -e -x
 
@@ -570,18 +570,26 @@ stages:
       - script: brew install ninja
         displayName: Install ninja
 
+      - bash: |
+          python ./tools/build.py \
+            --config RelWithDebInfo \
+            --android \
+            --android_abi x86_64 \
+            --enable_cxx_tests \
+            --update --build --parallel
+        displayName: Build onnxruntime-extensions for Android
+
       - template: templates/run-with-android-emulator-steps.yml
         parameters:
           steps:
-
           - bash: |
               python ./tools/build.py \
                 --config RelWithDebInfo \
                 --android \
                 --android_abi x86_64 \
                 --enable_cxx_tests \
-                --update --build --test --parallel
-            displayName: Build onnxruntime-extensions for Android and run C++ tests on emulator
+                --test
+            displayName: Run C++ tests on emulator
 
 - stage: IosBuilds
   dependsOn: []

.pipelines/templates/run-with-android-emulator-steps.yml

@@ -3,34 +3,13 @@ parameters:
   type: stepList
 
 steps:
-- bash: |
-    set -e -x
-
-    ORT_EXTENSIONS_BUILD_ANDROID_EMULATOR_PID_FILE="$(Build.BinariesDirectory)/android_emulator.pid"
-
-    python ./tools/android/run_android_emulator.py \
-      --android-sdk-root "${ANDROID_SDK_ROOT}" \
-      --create-avd --system-image "system-images;android-31;default;x86_64" \
-      --start --emulator-extra-args="-partition-size 4096" \
-      --emulator-pid-file "${ORT_EXTENSIONS_BUILD_ANDROID_EMULATOR_PID_FILE}"
-
-    # Do not output ##vso[] commands with `set -x` or they may be parsed again and include a trailing quote.
-    set +x
-    echo "##vso[task.setvariable variable=ORT_EXTENSIONS_BUILD_ANDROID_EMULATOR_PID_FILE]${ORT_EXTENSIONS_BUILD_ANDROID_EMULATOR_PID_FILE}"
-  displayName: "Create and start Android emulator"
+- template: use-android-emulator.yml
+  parameters:
+    create: true
+    start: true
 
 - ${{ parameters.steps }}
 
-- bash: |
-    set -e -x
-
-    if [[ -n "${ORT_EXTENSIONS_BUILD_ANDROID_EMULATOR_PID_FILE-}" ]]; then
-      python ./tools/android/run_android_emulator.py \
-        --android-sdk-root "${ANDROID_SDK_ROOT}" \
-        --stop \
-        --emulator-pid-file "${ORT_EXTENSIONS_BUILD_ANDROID_EMULATOR_PID_FILE}"
-
-      rm "${ORT_EXTENSIONS_BUILD_ANDROID_EMULATOR_PID_FILE}"
-    fi
-  displayName: "Stop Android emulator"
-  condition: always()
+- template: use-android-emulator.yml
+  parameters:
+    stop: true

.pipelines/templates/use-android-emulator.yml

@@ -0,0 +1,64 @@
+# Android Emulator helpers
+# Copied from https://github.com/microsoft/onnxruntime/blob/main/tools/ci_build/github/azure-pipelines/templates/use-android-emulator.yml
+parameters:
+- name: create
+  type: boolean
+  default: false
+
+- name: start
+  type: boolean
+  default: false
+
+- name: stop
+  type: boolean
+  default: false
+
+steps:
+- ${{ if eq(parameters.create, true) }}:
+  - script: |
+      set -e -x
+      python3 tools/android/run_android_emulator.py \
+        --android-sdk-root $(ANDROID_SDK_ROOT) \
+        --create-avd --system-image "system-images;android-31;default;x86_64"
+    displayName: Create Android Emulator
+
+- ${{ if eq(parameters.start, true) }}:
+  - script: |
+      if test -f $(Build.BinariesDirectory)/emulator.pid; then
+        echo "Emulator PID file was not expected to exist but does and has pid:" \
+          `cat $(Build.BinariesDirectory)/emulator.pid`
+        exit 1
+      fi
+    displayName: Check emulator.pid does not exist
+
+  # Add -verbose to --emulator-extra-args to enable additional logging.
+  - script: |
+      set -e -x
+      python3 tools/android/run_android_emulator.py \
+        --android-sdk-root $(ANDROID_SDK_ROOT) \
+        --start --emulator-extra-args="-partition-size 2047" \
+        --emulator-pid-file $(Build.BinariesDirectory)/emulator.pid
+      echo "Emulator PID:"`cat $(Build.BinariesDirectory)/emulator.pid`
+    displayName: Start Android Emulator
+
+- ${{ if eq(parameters.stop, true) }}:
+  - script: |
+      set -e -x
+      python3 -m pip install psutil
+    displayName: Install psutil for emulator shutdown by run_android_emulator.py
+    condition: always()
+
+  - script: |
+      set -e -x
+      if test -f $(Build.BinariesDirectory)/emulator.pid; then
+        echo "Emulator PID:"`cat $(Build.BinariesDirectory)/emulator.pid`
+        python3 tools/android/run_android_emulator.py \
+          --android-sdk-root $(ANDROID_SDK_ROOT) \
+          --stop \
+          --emulator-pid-file $(Build.BinariesDirectory)/emulator.pid
+        rm $(Build.BinariesDirectory)/emulator.pid
+      else
+        echo "Emulator PID file was expected to exist but does not."
+      fi
+    displayName: Stop Android Emulator
+    condition: always()

tools/android/run_android_emulator.py

@@ -22,8 +22,8 @@ log = get_logger("run_android_emulator")
 def parse_args():
     parser = argparse.ArgumentParser(
         description="Manages the running of an Android emulator. "
-        "Supported modes are to start and stop (default), only start, or only "
-        "stop the emulator."
+        "Supported modes are to create an AVD, and start or stop the emulator. "
+        "The default is to start the emulator and wait for a keypress to stop it (start and stop)."
     )
 
     parser.add_argument("--create-avd", action="store_true", help="Whether to create the Android virtual device.")
@@ -49,8 +49,8 @@ def parse_args():
 
     args = parser.parse_args()
 
-    if not args.start and not args.stop:
-        # unspecified means start and stop
+    if not args.start and not args.stop and not args.create_avd:
+        # unspecified means start and stop if not creating the AVD
         args.start = args.stop = True
 
     if args.start != args.stop and args.emulator_pid_file is None:
@@ -86,14 +86,14 @@ def main():
         emulator_proc = android.start_emulator(**start_emulator_args)
 
         with open(args.emulator_pid_file, mode="w") as emulator_pid_file:
-            print("{}".format(emulator_proc.pid), file=emulator_pid_file)
+            print(f"{emulator_proc.pid}", file=emulator_pid_file)
 
     elif args.stop:
-        with open(args.emulator_pid_file, mode="r") as emulator_pid_file:
+        with open(args.emulator_pid_file) as emulator_pid_file:
             emulator_pid = int(emulator_pid_file.readline().strip())
 
         android.stop_emulator(emulator_pid)
 
 
 if __name__ == "__main__":
-    main()
+    sys.exit(main())

tools/utils/android.py

@@ -3,7 +3,7 @@
 
 import collections
 import contextlib
-import logging
+import datetime
 import os
 import shutil
 import signal
@@ -11,10 +11,11 @@ import subprocess
 import time
 import typing
 
-from .platform_helpers import is_windows
+from .logger import get_logger
+from .platform_helpers import is_linux, is_windows
 from .run import run
 
-_log = logging.getLogger("util.android")
+_log = get_logger("util.android")
 
 
 SdkToolPaths = collections.namedtuple("SdkToolPaths", ["emulator", "adb", "sdkmanager", "avdmanager"])
@@ -23,19 +24,19 @@ SdkToolPaths = collections.namedtuple("SdkToolPaths", ["emulator", "adb", "sdkma
 def get_sdk_tool_paths(sdk_root: str):
     def filename(name, windows_extension):
         if is_windows():
-            return "{}.{}".format(name, windows_extension)
+            return f"{name}.{windows_extension}"
         else:
             return name
 
     def resolve_path(dirnames, basename):
         dirnames.insert(0, "")
         for dirname in dirnames:
-            path = shutil.which(os.path.join(dirname, basename))
+            path = shutil.which(os.path.join(os.path.expanduser(dirname), basename))
             if path is not None:
                 path = os.path.realpath(path)
-                _log.debug("Found {} at {}".format(basename, path))
+                _log.debug(f"Found {basename} at {path}")
                 return path
-        raise FileNotFoundError("Failed to resolve path for {}".format(basename))
+        raise FileNotFoundError(f"Failed to resolve path for {basename}")
 
     return SdkToolPaths(
         emulator=resolve_path([os.path.join(sdk_root, "emulator")], filename("emulator", "exe")),
@@ -71,7 +72,7 @@ _process_creationflags = subprocess.CREATE_NEW_PROCESS_GROUP if is_windows() els
 
 
 def _start_process(*args) -> subprocess.Popen:
-    _log.debug("Starting process - args: {}".format([*args]))
+    _log.debug(f"Starting process - args: {[*args]}")
     return subprocess.Popen([*args], creationflags=_process_creationflags)
 
 
@@ -79,7 +80,11 @@ _stop_signal = signal.CTRL_BREAK_EVENT if is_windows() else signal.SIGTERM
 
 
 def _stop_process(proc: subprocess.Popen):
-    _log.debug("Stopping process - args: {}".format(proc.args))
+    if proc.returncode is not None:
+        # process has exited
+        return
+
+    _log.debug(f"Stopping process - args: {proc.args}")
     proc.send_signal(_stop_signal)
 
     try:
@@ -90,9 +95,23 @@ def _stop_process(proc: subprocess.Popen):
 
 
 def _stop_process_with_pid(pid: int):
-    # not attempting anything fancier than just sending _stop_signal for now
-    _log.debug("Stopping process - pid: {}".format(pid))
-    os.kill(pid, _stop_signal)
+    # minimize scope of external module usage
+    import psutil
+
+    if psutil.pid_exists(pid):
+        process = psutil.Process(pid)
+        _log.debug(f"Stopping process - pid={pid}")
+        process.terminate()
+        try:
+            process.wait(60)
+        except psutil.TimeoutExpired:
+            print("Process did not terminate within 60 seconds. Killing.")
+            process.kill()
+            time.sleep(10)
+            if psutil.pid_exists(pid):
+                print(f"Process still exists. State:{process.status()}")
+    else:
+        _log.debug(f"No process exists with pid={pid}")
 
 
 def start_emulator(
@@ -107,48 +126,95 @@ def start_emulator(
             "4096",
             "-timezone",
             "America/Los_Angeles",
-            "-no-snapshot",
+            "-no-snapstorage",
             "-no-audio",
             "-no-boot-anim",
-            "-no-window",
             "-gpu",
-            "swiftshader_indirect",
+            "guest",
+            "-delay-adb",
         ]
+
+        # For Linux CIs we must use "-no-window" otherwise you'll get
+        #   Fatal: This application failed to start because no Qt platform plugin could be initialized
+        #
+        # For macOS CIs use a window so that we can potentially capture the desktop and the emulator screen
+        # and publish screenshot.jpg and emulator.png as artifacts to debug issues.
+        #   screencapture screenshot.jpg
+        #   $(ANDROID_SDK_HOME)/platform-tools/adb exec-out screencap -p > emulator.png
+        #
+        # On Windows it doesn't matter (AFAIK) so allow a window which is nicer for local debugging.
+        if is_linux():
+            emulator_args.append("-no-window")
+
         if extra_args is not None:
             emulator_args += extra_args
 
         emulator_process = emulator_stack.enter_context(_start_process(*emulator_args))
         emulator_stack.callback(_stop_process, emulator_process)
 
+        # we're specifying -delay-adb so use a trivial command to check when adb is available.
         waiter_process = waiter_stack.enter_context(
             _start_process(
                 sdk_tool_paths.adb,
-                "-e",
                 "wait-for-device",
                 "shell",
-                "while [[ -z $(getprop sys.boot_completed) ]]; do sleep 1; done; input keyevent 82",
+                "ls /data/local/tmp",
             )
         )
+
         waiter_stack.callback(_stop_process, waiter_process)
 
-        # poll subprocesses
-        sleep_interval_seconds = 1
+        # poll subprocesses.
+        # allow 20 minutes for startup as some CIs are slow. TODO: Make timeout configurable if needed.
+        sleep_interval_seconds = 10
+        end_time = datetime.datetime.now() + datetime.timedelta(minutes=20)
+
         while True:
             waiter_ret, emulator_ret = waiter_process.poll(), emulator_process.poll()
 
             if emulator_ret is not None:
                 # emulator exited early
-                raise RuntimeError("Emulator exited early with return code: {}".format(emulator_ret))
+                raise RuntimeError(f"Emulator exited early with return code: {emulator_ret}")
 
             if waiter_ret is not None:
                 if waiter_ret == 0:
+                    _log.debug("adb wait-for-device process has completed.")
                     break
-                raise RuntimeError("Waiter process exited with return code: {}".format(waiter_ret))
+                raise RuntimeError(f"Waiter process exited with return code: {waiter_ret}")
+
+            if datetime.datetime.now() > end_time:
+                raise RuntimeError("Emulator startup timeout")
 
             time.sleep(sleep_interval_seconds)
 
-        # emulator is ready now
+        # emulator is started
         emulator_stack.pop_all()
+
+        # loop to check for sys.boot_completed being set.
+        # in theory `-delay-adb` should be enough but this extra check seems to be required to be sure.
+        while True:
+            # looping on device with `while` seems to be flaky so loop here and call getprop once
+            args = [
+                sdk_tool_paths.adb,
+                "shell",
+                # "while [[ -z $(getprop sys.boot_completed) | tr -d '\r' ]]; do sleep 5; done; input keyevent 82",
+                "getprop sys.boot_completed",
+            ]
+
+            _log.debug(f"Starting process - args: {args}")
+
+            getprop_output = subprocess.check_output(args, timeout=10)
+            getprop_value = bytes.decode(getprop_output).strip()
+
+            if getprop_value == "1":
+                break
+
+            elif datetime.datetime.now() > end_time:
+                raise RuntimeError("Emulator startup timeout. sys.boot_completed was not set.")
+
+            _log.debug(f"sys.boot_completed='{getprop_value}'. Sleeping for {sleep_interval_seconds} before retrying.")
+            time.sleep(sleep_interval_seconds)
+
         return emulator_process