fix: Explicitly wait for the server shutdown before killing it forcefully (#873)

Author: mykola-mokhnach

lib/uiautomator2.js

@@ -11,12 +11,14 @@ import B from 'bluebird';
 import axios from 'axios';
 
 const REQD_PARAMS = ['adb', 'tmpDir', 'host', 'systemPort', 'devicePort', 'disableWindowAnimation'];
-const SERVER_LAUNCH_TIMEOUT = 30000;
+const SERVER_LAUNCH_TIMEOUT_MS = 30000;
 const SERVER_INSTALL_RETRIES = 20;
-const SERVICES_LAUNCH_TIMEOUT = 30000;
-const SERVER_PACKAGE_ID = 'io.appium.uiautomator2.server';
-const SERVER_TEST_PACKAGE_ID = `${SERVER_PACKAGE_ID}.test`;
-const INSTRUMENTATION_TARGET = `${SERVER_TEST_PACKAGE_ID}/androidx.test.runner.AndroidJUnitRunner`;
+const SERVICES_LAUNCH_TIMEOUT_MS = 30000;
+const SERVER_SHUTDOWN_TIMEOUT_MS = 5000;
+const SERVER_REQUEST_TIMEOUT_MS = 500;
+export const SERVER_PACKAGE_ID = 'io.appium.uiautomator2.server';
+export const SERVER_TEST_PACKAGE_ID = `${SERVER_PACKAGE_ID}.test`;
+export const INSTRUMENTATION_TARGET = `${SERVER_TEST_PACKAGE_ID}/androidx.test.runner.AndroidJUnitRunner`;
 
 class UIA2Proxy extends JWProxy {
   /** @type {boolean} */
@@ -36,7 +38,7 @@ class UIA2Proxy extends JWProxy {
   }
 }
 
-class UiAutomator2Server {
+export class UiAutomator2Server {
   /** @type {string} */
   host;
 
@@ -209,7 +211,7 @@ class UiAutomator2Server {
   }
 
   async verifyServicesAvailability () {
-    this.log.debug(`Waiting up to ${SERVICES_LAUNCH_TIMEOUT}ms for services to be available`);
+    this.log.debug(`Waiting up to ${SERVICES_LAUNCH_TIMEOUT_MS}ms for services to be available`);
     let isPmServiceAvailable = false;
     let pmOutput = '';
     let pmError = null;
@@ -236,7 +238,7 @@ class UiAutomator2Server {
         }
         return isPmServiceAvailable;
       }, {
-        waitMs: SERVICES_LAUNCH_TIMEOUT,
+        waitMs: SERVICES_LAUNCH_TIMEOUT_MS,
         intervalMs: 1000,
       });
     } catch {
@@ -260,7 +262,7 @@ class UiAutomator2Server {
       this.log.info(`Using UIAutomator2 server from '${apkPath}' and test from '${testApkPath}'`);
     }
 
-    const timeout = caps.uiautomator2ServerLaunchTimeout || SERVER_LAUNCH_TIMEOUT;
+    const timeout = caps.uiautomator2ServerLaunchTimeout || SERVER_LAUNCH_TIMEOUT_MS;
     const timer = new timing.Timer().start();
     let retries = 0;
     const maxRetries = 2;
@@ -344,81 +346,67 @@ class UiAutomator2Server {
   }
 
   async stopInstrumentationProcess () {
-    if (!this.instrumentationProcess) {
-      return;
-    }
-
     try {
-      if (this.instrumentationProcess.isRunning) {
+      if (this.instrumentationProcess?.isRunning) {
         await this.instrumentationProcess.stop();
       }
     } finally {
-      this.instrumentationProcess.removeAllListeners();
+      this.instrumentationProcess?.removeAllListeners();
       this.instrumentationProcess = null;
     }
   }
 
   async deleteSession () {
     this.log.debug('Deleting UiAutomator2 server session');
-    // rely on jwproxy's intelligence to know what we're talking about and
-    // delete the current session
+
     try {
       await this.jwproxy.command('/', 'DELETE');
     } catch (err) {
-      this.log.warn(`Did not get confirmation UiAutomator2 deleteSession worked; ` +
-          `Error was: ${err}`);
+      this.log.warn(
+        `Did not get the confirmation of UiAutomator2 server session deletion. ` +
+        `Original error: ${err.message}`
+      );
     }
+
+    // Theoretically we could also force kill instumentation and server processes
+    // without waiting for them to properly quit on their own.
+    // This may cause unexpected error reports in device logs though.
+    await this._waitForTermination();
+
     try {
       await this.stopInstrumentationProcess();
     } catch (err) {
       this.log.warn(`Could not stop the instrumentation process. Original error: ${err.message}`);
     }
+
+    try {
+      await B.all([
+        this.adb.forceStop(SERVER_PACKAGE_ID),
+        this.adb.forceStop(SERVER_TEST_PACKAGE_ID)
+      ]);
+    } catch {}
   }
 
   async cleanupAutomationLeftovers (strictCleanup = false) {
     this.log.debug(`Performing ${strictCleanup ? 'strict' : 'shallow'} cleanup of automation leftovers`);
 
-    const axiosTimeout = 500;
-
-    const waitStop = async () => {
-      // Wait for the process stop by sending a status request to the port.
-      // We observed the process stop could be delayed, thus causing unexpected crashes
-      // in the middle of the session preparation process. It caused an invalid session error response
-      // by the uia2 server, but that was because the process stop's delay.
-      const timeout = 3000;
-      try {
-        await waitForCondition(async () => {
-          try {
-            await axios({
-              url: `http://${this.host}:${this.systemPort}/status`,
-              timeout: axiosTimeout,
-            });
-          } catch {
-            return true;
-          }
-        }, {
-          waitMs: timeout,
-          intervalMs: 100,
-        });
-      } catch {
-        this.log.warn(`The ${SERVER_TEST_PACKAGE_ID} process might fail to stop within ${timeout}ms timeout.`);
-      }
-    };
-
+    const serverBase = `http://${this.host}:${this.systemPort}`;
     try {
       const {value} = (await axios({
-        url: `http://${this.host}:${this.systemPort}/sessions`,
-        timeout: axiosTimeout,
+        url: `${serverBase}/sessions`,
+        timeout: SERVER_REQUEST_TIMEOUT_MS,
       })).data;
       const activeSessionIds = value.map(({id}) => id).filter(Boolean);
       if (activeSessionIds.length) {
-        this.log.debug(`The following obsolete sessions are still running: ${JSON.stringify(activeSessionIds)}`);
+        this.log.debug(`The following obsolete sessions are still running: ${activeSessionIds}`);
         this.log.debug(`Cleaning up ${util.pluralize('obsolete session', activeSessionIds.length, true)}`);
         await B.all(activeSessionIds
-          .map((id) => axios.delete(`http://${this.host}:${this.systemPort}/session/${id}`))
+          .map((/** @type {string} */ id) => axios.delete(`${serverBase}/session/${id}`, {
+            timeout: SERVER_REQUEST_TIMEOUT_MS,
+          }))
         );
-        // Let all sessions to be properly terminated before continuing
-        await B.delay(1000);
+        // Let the server to be properly terminated before continuing
+        await this._waitForTermination();
       } else {
         this.log.debug('No obsolete sessions have been detected');
       }
@@ -438,11 +426,35 @@ class UiAutomator2Server {
         await this.adb.killProcessesByName('uiautomator');
       } catch {}
     }
-    await waitStop();
+  }
+
+  /**
+   * Blocks until UIA2 server stops running
+   * or SERVER_SHUTDOWN_TIMEOUT_MS expires
+   *
+   * @returns {Promise<void>}
+   */
+  async _waitForTermination() {
+    try {
+      await waitForCondition(async () => {
+        try {
+          return !(await this.adb.processExists(SERVER_PACKAGE_ID));
+        } catch {
+          return true;
+        }
+      }, {
+        waitMs: SERVER_SHUTDOWN_TIMEOUT_MS,
+        intervalMs: 300,
+      });
+    } catch {
+      this.log.warn(
+        `The UIA2 server did has not been terminated within ${SERVER_SHUTDOWN_TIMEOUT_MS}ms timeout. ` +
+        `Continuing anyway`
+      );
+    }
   }
 }
 
-export { UiAutomator2Server, INSTRUMENTATION_TARGET, SERVER_PACKAGE_ID, SERVER_TEST_PACKAGE_ID };
 export default UiAutomator2Server;
 
 /**