Skip to content

Commit

Permalink
Only perform uiautomation process cleanup if instrumentation crashes
Browse files Browse the repository at this point in the history
  • Loading branch information
@mykola-mokhnach
mykola-mokhnach committed Jan 11, 2019
1 parent a91a341 commit cf120f8
Show file tree
Hide file tree
Showing 2 changed files with 131 additions and 88 deletions.
202 changes: 131 additions & 71 deletions lib/uiautomator2.js
View file
Original file line number Diff line number Diff line change
@@ -1,20 +1,20 @@
import _ from 'lodash';
import { JWProxy } from 'appium-base-driver';
import { retryInterval } from 'asyncbox';
import logger from './logger';
import { retryInterval, waitForCondition } from 'asyncbox';
import log from './logger';
import { SERVER_APK_PATH as apkPath, TEST_APK_PATH as testApkPath, version as serverVersion } from 'appium-uiautomator2-server';
import adbkit from 'adbkit';
import { getRetries } from './utils';
import { util } from 'appium-support';
import { util, logger } from 'appium-support';


const REQD_PARAMS = ['adb', 'tmpDir', 'host', 'systemPort', 'devicePort', 'disableWindowAnimation'];
const SERVER_LAUNCH_RETRIES = 20;
const SERVER_LAUNCH_TIMEOUT = 30000;
const SERVER_INSTALL_RETRIES = 20;
const INSTRUMENTATION_TARGET = 'io.appium.uiautomator2.server.test/androidx.test.runner.AndroidJUnitRunner';
const SERVICES_PING_RETRIES = 20;
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 instrumentationLogger = logger.getLogger('Intrumentation');

class UiAutomator2Server {
constructor (opts = {}) {
Expand Down Expand Up @@ -64,7 +64,7 @@ class UiAutomator2Server {
}

const appState = await this.adb.getApplicationInstallState(appPath, appId);
logger.debug(`${appId} installation state: ${appState}`);
log.debug(`${appId} installation state: ${appState}`);
if (await this.adb.checkApkCert(appPath, appId)) {
shouldUninstallServerPackages = shouldUninstallServerPackages || [
this.adb.APP_INSTALL_STATE.OLDER_VERSION_INSTALLED,
Expand All @@ -80,16 +80,16 @@ class UiAutomator2Server {
this.adb.APP_INSTALL_STATE.NOT_INSTALLED,
].includes(appState);
}
logger.info(`Server packages are ${shouldInstallServerPackages ? '' : 'not '}going to be (re)installed`);
log.info(`Server packages are ${shouldInstallServerPackages ? '' : 'not '}going to be (re)installed`);
if (shouldInstallServerPackages && shouldUninstallServerPackages) {
logger.info('Full packages reinstall is going to be performed');
log.info('Full packages reinstall is going to be performed');
}
for (const {appId, appPath} of packagesInfo) {
if (shouldUninstallServerPackages) {
try {
await this.adb.uninstallApk(appId);
} catch (err) {
logger.warn(`Error uninstalling '${appId}': ${err.message}`);
log.warn(`Error uninstalling '${appId}': ${err.message}`);
}
}
if (shouldInstallServerPackages) {
Expand All @@ -99,42 +99,69 @@ class UiAutomator2Server {
});
}
}
let retries = getRetries('Server install', installTimeout, SERVER_INSTALL_RETRIES);

logger.debug(`Waiting up to ${retries * 1000}ms for instrumentation '${INSTRUMENTATION_TARGET}' to be available`);
let output;
await this.verifyServicesAvailability();
}

async verifyServicesAvailability () {
log.debug(`Waiting up to ${SERVICES_PING_RETRIES * 1000}ms for services to be available`);
let isInstrumentationServiceAvailable = false;
let isAmServiceAvailable = false;
let pmOutput = null;
let amError = null;
try {
await retryInterval(retries, 1000, async () => {
output = await this.adb.shell(['pm', 'list', 'instrumentation']);
if (output.indexOf('Could not access the Package Manager') !== -1) {
let err = new Error(`Problem running package manager: ${output}`);
output = null; // remove output, so it is not printed below
throw err;
} else if (output.indexOf(INSTRUMENTATION_TARGET) === -1) {
throw new Error('No instrumentation process found. Retrying...');
await retryInterval(SERVICES_PING_RETRIES, 1000, async () => {
if (!isInstrumentationServiceAvailable) {
pmOutput = await this.adb.shell(['pm', 'list', 'instrumentation']);
if (pmOutput.includes('Could not access the Package Manager')) {
let err = new Error(`Problem running package manager: ${pmOutput}`);
pmOutput = null; // remove output, so it is not printed below
throw err;
} else if (!pmOutput.includes(INSTRUMENTATION_TARGET)) {
throw new Error('No instrumentation process found. Retrying...');
}
pmOutput = null; // remove output, so it is not printed below
log.debug(`Instrumentation target '${INSTRUMENTATION_TARGET}' is available`);
isInstrumentationServiceAvailable = true;
}
if (!isAmServiceAvailable) {
// https://travis-ci.org/appium/appium-uiautomator2-driver/jobs/478514097#L4806
amError = null;
try {
await this.adb.shell(['am']);
log.debug('Activity manager service is available');
isAmServiceAvailable = true;
} catch (e) {
amError = e.message;
}
}
logger.debug(`Instrumentation '${INSTRUMENTATION_TARGET}' available`);
});
} catch (err) {
logger.error(`Unable to find instrumentation target '${INSTRUMENTATION_TARGET}': ${err.message}`);
if (output) {
logger.debug('Available targets:');
for (let line of output.split('\n')) {
logger.debug(` ${line.replace('instrumentation:', '')}`);
if (!isInstrumentationServiceAvailable) {
log.error(`Unable to find instrumentation target '${INSTRUMENTATION_TARGET}': ${err.message}`);
if (pmOutput) {
log.debug('Available targets:');
for (let line of pmOutput.split('\n')) {
log.debug(` ${line.replace('instrumentation:', '')}`);
}
}
}
if (!isAmServiceAvailable) {
log.error(`Activity manager service is not available`);
if (amError) {
log.debug(amError);
}
}
}
}

async startSession (caps) {
// kill any uiautomator existing processes
await this.killUiAutomatorOnDevice();

await this.cleanupAutomationLeftovers(false);
if (caps.skipServerInstallation) {
logger.info(`'skipServerInstallation' is set. Attempting to use UIAutomator2 server from the device.`);
log.info(`'skipServerInstallation' is set. Attempting to use UIAutomator2 server from the device`);
} else {
logger.info(`Starting UIAutomator2 server ${serverVersion}`);
logger.info(`Using UIAutomator2 server from '${apkPath}' and test from '${testApkPath}'`);
log.info(`Starting UIAutomator2 server ${serverVersion}`);
log.info(`Using UIAutomator2 server from '${apkPath}' and test from '${testApkPath}'`);
}

// let cmd = ['am', 'instrument', '-w',
Expand All @@ -144,71 +171,104 @@ class UiAutomator2Server {
// facing IllegalStateException: UiAutomation not connected exception
// https://github.com/appium/appium-uiautomator2-driver/issues/19

await this.startSessionUsingAdbKit(caps.deviceUDID);
const initStarted = process.hrtime();
let retries = 0;
const maxRetries = 2;
while (retries < maxRetries) {
let didInstrumentsCrash = false;
await this.startSessionUsingAdbKit(caps.deviceUDID, (output) => {
if (output.includes('Process crashed')) {
didInstrumentsCrash = true;
}
});
const timeout = caps.uiautomator2ServerLaunchTimeout || SERVER_LAUNCH_TIMEOUT;
log.info(`Waiting up to ${timeout}ms for UiAutomator2 to be online...`);
try {
await waitForCondition(async () => {
try {
await this.jwproxy.command('/status', 'GET');
return true;
} catch (err) {
if (didInstrumentsCrash) {
// short circuit to retry or fail
return true;
}
return false;
}
}, {
waitMs: timeout,
intervalMs: 1000,
});
} catch (err) {
log.errorAndThrow(`Test instrumentation cannot be initialized within ${timeout}ms timeout. `
+ 'Make sure the application under test does not crash and investigate the logcat output. '
+ `You could also try to increase the value of 'uiautomator2ServerLaunchTimeout' capability. `);
}
if (!didInstrumentsCrash) {
break;
}

let retries = getRetries('Server launch', caps.uiautomator2ServerLaunchTimeout, SERVER_LAUNCH_RETRIES);
retries++;
if (retries >= maxRetries) {
log.errorAndThrow('Test instrumentation cannot be initialized. '
+ 'Make sure the application under test does not crash and investigate the logcat output.');
}
log.warn(`Instrumentation process has crashed. `
+ `Retrying UiAutomator 2 startup (#${retries} of ${maxRetries - 1})`);
await this.cleanupAutomationLeftovers(true);
}

logger.info(`Waiting up to ${retries * 1000}ms for UiAutomator2 to be online...`);
// wait for UiAutomator2 to be online
await retryInterval(retries, 1000, this.jwproxy.command.bind(this.jwproxy), '/status', 'GET');
const [seconds, nanoseconds] = process.hrtime(initStarted);
log.info(`Instrumentation process initialization took ${seconds * 1000 + nanoseconds / 1000000}ms`);
await this.jwproxy.command('/session', 'POST', {desiredCapabilities: caps});
}

async startSessionUsingAdbKit (deviceUDID) { // eslint-disable-line require-await
let cmd = 'am instrument -w';
async startSessionUsingAdbKit (deviceUDID, onDebugLog = null) { // eslint-disable-line require-await
const cmd = ['am', 'instrument', '-w'];
if (this.disableWindowAnimation) {
cmd = `${cmd} --no-window-animation`;
cmd.push('--no-window-animation');
}
cmd = `${cmd} ${INSTRUMENTATION_TARGET}`;
logger.info(`Running command: 'adb -s ${deviceUDID} shell ${cmd}'`);
this.client.shell(deviceUDID, cmd)
cmd.push(INSTRUMENTATION_TARGET);
log.info(`Starting instrumentation: 'adb -s ${deviceUDID} shell ${cmd.join(' ')}'`);
this.client.shell(deviceUDID, cmd.join(' '))
.then(adbkit.util.readAll) // eslint-disable-line promise/prefer-await-to-then
.then(function (output) { // eslint-disable-line promise/prefer-await-to-then
for (let line of output.toString().split('\n')) {
if (line.length) {
logger.debug(`[UIAutomator2] ${line}`);
for (const line of output.toString().split('\n').filter((x) => !_.isEmpty(x))) {
instrumentationLogger.debug(line);
if (_.isFunction(onDebugLog)) {
onDebugLog(line);
}
}
}).catch(function (err) { // eslint-disable-line promise/prefer-await-to-callbacks
logger.error(`[UIAutomator2 Error] ${err.message}`);
logger.debug(`Full error: ${err.stack}`);
instrumentationLogger.error(err.message);
instrumentationLogger.debug(`Full error: ${err.stack}`);
});
}

async deleteSession () {
logger.debug('Deleting UiAutomator2 server session');
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) {
logger.warn(`Did not get confirmation UiAutomator2 deleteSession worked; ` +
log.warn(`Did not get confirmation UiAutomator2 deleteSession worked; ` +
`Error was: ${err}`);
}
}

async killUiAutomatorOnDevice () {
async cleanupAutomationLeftovers (strictCleanup = false) {
log.debug(`Performing ${strictCleanup ? 'strict' : 'shallow'} cleanup of automation leftovers`);
try {
const pids = (await this.adb.getPIDsByName('uiautomator')).map((p) => `${p}`);
if (!_.isEmpty(pids)) {
const isRoot = await this.adb.root();
try {
await this.adb.shell(['kill', '-9', ...pids]);
} finally {
if (isRoot) {
await this.adb.unroot();
}
}
}
} catch (err) {
logger.warn(`Unable to stop uiautomator process: ${err.message}`);
await this.adb.forceStop(SERVER_TEST_PACKAGE_ID);
} catch (ignore) {}
if (!strictCleanup) {
return;
}

// https://github.com/appium/appium/issues/10749
try {
await this.adb.forceStop('io.appium.uiautomator2.server');
} catch (ignore) {
logger.info('Unable to kill the io.appium.uiautomator2.server process, assuming it is already killed');
}
await this.adb.killProcessesByName('uiautomator');
} catch (ignore) {}
}
}

Expand Down
17 changes: 0 additions & 17 deletions lib/utils.js
View file

This file was deleted.

0 comments on commit cf120f8

Please sign in to comment.