Fix: Restart ADB server when devices go offline #443

dpgraham · 2019-04-08T20:25:38Z

This addresses two problems: adb root/unroot 1. works intermittently, 2. sometimes cases the device to go offline.

The fix is:

retries root/unroot instead of calling it just once
after a root/unroot occurs, check if there's no connected devices and if there aren't any, restart adb (uses a new method called restartAdbIfDevicesOffline ()

This PR also:

Uses mocha multireporters so that the logs show tests being called
Fixes an IME test that wasn't working

dpgraham · 2019-04-10T20:02:14Z

@imurchie @mykola-mokhnach this is the cause of the ADB CI flakiness:

dbug ADB Running '/Users/vsts/Library/Android/sdk/platform-tools/adb -P 5037 shell 'ls -t -1 /data/local/tmp/appium_cache 2>&1 || echo _ERROR_''
dbug ADB Got an error 'ls: /data/local/tmp/appium_cache: No such file or directory' while getting the list of files in the cache. Assuming the cache does not exist yet
dbug ADB Running '/Users/vsts/Library/Android/sdk/platform-tools/adb -P 5037 shell mkdir -p /data/local/tmp/appium_cache'
dbug ADB The count of applications in the cache: 0
info ADB Caching the application at '/Users/vsts/agent/2.149.2/work/1/s/test/fixtures/ContactManager.apk' to '/data/local/tmp/appium_cache/3b32eb4d0ff70756a89a6801cf5b5d1fe2740b4b.apk'
dbug ADB Running '/Users/vsts/Library/Android/sdk/platform-tools/adb -P 5037 shell mkdir -p /data/local/tmp/appium_cache'
dbug ADB Running '/Users/vsts/Library/Android/sdk/platform-tools/adb -P 5037 push /Users/vsts/agent/2.149.2/work/1/s/test/fixtures/ContactManager.apk /data/local/tmp/appium_cache/3b32eb4d0ff70756a89a6801cf5b5d1fe2740b4b.apk'
info ADB The upload of 'ContactManager.apk' (25.32 KB) took 0.228s
dbug ADB Running '/Users/vsts/Library/Android/sdk/platform-tools/adb -P 5037 shell pm install -r /data/local/tmp/appium_cache/3b32eb4d0ff70756a89a6801cf5b5d1fe2740b4b.apk'
info ADB The installation of 'ContactManager.apk' took 4.772s
dbug ADB Install command stdout: Success
dbug ADB Running '/Users/vsts/Library/Android/sdk/platform-tools/adb -P 5037 shell am start -W -n com.example.android.contactmanager/ContactManager -S'
dbug ADB We tried to start an activity that doesn't exist, retrying with '.ContactManager' activity name
dbug ADB Running '/Users/vsts/Library/Android/sdk/platform-tools/adb -P 5037 shell am start -W -n com.example.android.contactmanager/.ContactManager -S'
dbug ADB Attempting to kill all com.example.android.contactmanager processes
dbug ADB Getting IDs of all 'com.example.android.contactmanager' processes
dbug ADB Running '/Users/vsts/Library/Android/sdk/platform-tools/adb -P 5037 shell pgrep -f com\\.example\\.android\\.contactmanager'
dbug ADB Attempting to kill process 2910
dbug ADB Running '/Users/vsts/Library/Android/sdk/platform-tools/adb -P 5037 shell kill -0 2910'
dbug ADB Running '/Users/vsts/Library/Android/sdk/platform-tools/adb -P 5037 shell whoami'
info ADB Cannot kill PID 2910 due to insufficient permissions. Retrying as root
dbug ADB Running '/Users/vsts/Library/Android/sdk/platform-tools/adb -P 5037 shell kill -0 2910'
dbug ADB Running '/Users/vsts/Library/Android/sdk/platform-tools/adb -P 5037 shell kill 2910'
dbug ADB Running '/Users/vsts/Library/Android/sdk/platform-tools/adb -P 5037 shell kill 2910'
WARN ADB Unable to unroot adb daemon: 'Command '/Users/vsts/Library/Android/sdk/platform-tools/adb unroot' exited with code 1'. Continuing
dbug ADB Getting IDs of all 'com.example.android.contactmanager' processes
dbug ADB Running '/Users/vsts/Library/Android/sdk/platform-tools/adb -P 5037 shell pgrep -f com\\.example\\.android\\.contactmanager'
    ✓ killProcessesByName should kill process (17881ms)
dbug ADB Running '/Users/vsts/Library/Android/sdk/platform-tools/adb -P 5037 shell 'ls -t -1 /data/local/tmp/appium_cache 2>&1 || echo _ERROR_''
dbug ADB Got an error 'Error executing adbExec. Original error: 'Command '/Users/vsts/Library/Android/sdk/platform-tools/adb -P 5037 shell 'ls -t -1 /data/local/tmp/appium_cache 2>&1 || echo _ERROR_'' exited with code 1'; Stderr: 'error: device offline'; Code: '1'' while getting the list of files in the cache. Assuming the cache does not exist yet
dbug ADB Running '/Users/vsts/Library/Android/sdk/platform-tools/adb -P 5037 shell mkdir -p /data/local/tmp/appium_cache'
    2) killProcessByPID should kill process

The device goes offline when we retry as root and then fail to unroot.

dpgraham · 2019-04-10T20:06:08Z

I'm going to try restarting ADB whenever unroot fails.

dpgraham · 2019-04-10T20:18:11Z

This is what happens when it passes

dbug ADB Running '/Users/vsts/Library/Android/sdk/platform-tools/adb -P 5037 shell 'ls -t -1 /data/local/tmp/appium_cache 2>&1 || echo _ERROR_''
dbug ADB The count of applications in the cache: 1
info ADB The application at '/Users/vsts/agent/2.149.2/work/1/s/test/fixtures/ContactManager.apk' is already cached to '/data/local/tmp/appium_cache/3b32eb4d0ff70756a89a6801cf5b5d1fe2740b4b.apk'
dbug ADB Running '/Users/vsts/Library/Android/sdk/platform-tools/adb -P 5037 shell pm install -r /data/local/tmp/appium_cache/3b32eb4d0ff70756a89a6801cf5b5d1fe2740b4b.apk'
info ADB The installation of 'ContactManager.apk' took 2.035s
dbug ADB Install command stdout: Success
dbug ADB Running '/Users/vsts/Library/Android/sdk/platform-tools/adb -P 5037 shell am start -W -n com.example.android.contactmanager/ContactManager -S'
dbug ADB We tried to start an activity that doesn't exist, retrying with '.ContactManager' activity name
dbug ADB Running '/Users/vsts/Library/Android/sdk/platform-tools/adb -P 5037 shell am start -W -n com.example.android.contactmanager/.ContactManager -S'
dbug ADB Getting IDs of all 'com.example.android.contactmanager' processes
dbug ADB Running '/Users/vsts/Library/Android/sdk/platform-tools/adb -P 5037 shell pgrep -f com\\.example\\.android\\.contactmanager'
dbug ADB Attempting to kill process 3341
dbug ADB Running '/Users/vsts/Library/Android/sdk/platform-tools/adb -P 5037 shell kill -0 3341'
dbug ADB Running '/Users/vsts/Library/Android/sdk/platform-tools/adb -P 5037 shell whoami'
info ADB Cannot kill PID 3341 due to insufficient permissions. Retrying as root
dbug ADB Running '/Users/vsts/Library/Android/sdk/platform-tools/adb -P 5037 shell kill -0 3341'
dbug ADB Running '/Users/vsts/Library/Android/sdk/platform-tools/adb -P 5037 shell kill 3341'
dbug ADB Running '/Users/vsts/Library/Android/sdk/platform-tools/adb -P 5037 shell kill 3341'
dbug ADB Getting IDs of all 'com.example.android.contactmanager' processes
dbug ADB Running '/Users/vsts/Library/Android/sdk/platform-tools/adb -P 5037 shell pgrep -f com\\.example\\.android\\.contactmanager'
    ✓ killProcessByPID should kill process (11285ms)
    - should get device language and country
dbug ADB Running '/Users/vsts/Library/Android/sdk/platform-tools/adb -P 5037 shell am broadcast -a io.appium.settings.locale -n io.appium.settings/.receivers.LocaleSettingReceiver --es lang en --es country US'
dbug ADB Running '/Users/vsts/Library/Android/sdk/platform-tools/adb -P 5037 shell getprop persist.sys.locale'
dbug ADB Current device property 'persist.sys.locale': 
dbug ADB Running '/Users/vsts/Library/Android/sdk/platform-tools/adb -P 5037 shell getprop ro.product.locale'
dbug ADB Current device property 'ro.product.locale': en-US
    ✓ should get device locale (20257ms)

Doesn't fail to unroot

lib/tools/system-calls.js

lib/tools/adb-commands.js

lib/tools/system-calls.js

lib/tools/adb-commands.js

dpgraham · 2019-04-12T05:36:26Z

Changes pushed and CI passing (Azure at least). Any more comments will be addressed tomorrow.

mykola-mokhnach · 2019-04-12T06:01:35Z

lib/tools/adb-commands.js

@@ -1456,19 +1460,26 @@ methods.getDeviceProperty = async function getDeviceProperty (property) {
  return val;
 };

+/**
+ * @typedef {object} setPropOpts
+ * @property {boolean} privileged - Do we run setProp as a privileged command?


true by default

mykola-mokhnach · 2019-04-12T06:02:38Z

lib/tools/system-calls.js

-      } catch (err) {
-        log.warn(`Cannot run adbd as non-root. Original error: ${err.message}`);
-      }
+      log.info(`Call to '${cmd}' completed. Returning device to original unrooted state.`);


this log line seems redundant to me

mykola-mokhnach · 2019-04-12T06:02:49Z

lib/tools/system-calls.js

-        // Do not show the warning for real devices, where root is locked
-        log.warn(`Cannot run adbd as root. Original error: ${err.message}`);
-      }
+    log.info(`'adb shell ${cmd}' requires root access. Attempting to gain root access now.`);


mykola-mokhnach · 2019-04-12T06:03:39Z

lib/tools/system-calls.js

+    return {isSuccessful: true, wasAlreadyRooted: isRoot};
+  }
+
+  let wasAlreadyRooted = false;


mykola-mokhnach · 2019-04-12T06:04:43Z

lib/tools/system-calls.js

-      throw new Error(stdout.trim());
+    if (stdout) {
+      if (stdout.includes('adbd cannot run as root')) {
+        log.warn('Cannot run device as root');


I think we can skip this log at all otherwise it will appear too often on real devices

mykola-mokhnach · 2019-04-12T06:05:14Z

lib/tools/system-calls.js

+  // If it's already rooted, our job is done. No need to root it again.
+  const isRoot = await this.isRoot();
+  if ((isRoot && isElevated) || (!isRoot && !isElevated)) {
+    return {isSuccessful: true, wasAlreadyRooted: isRoot};


mykola-mokhnach · 2019-04-12T06:06:25Z

lib/tools/system-calls.js

+    // Check the output of the stdErr to see if there's any clues that show that the device went offline
+    // and if it did go offline, restart ADB
+    const s = stderr.toLowerCase();
+    if (s.includes('closed') || s.includes('device offline')) {


['closed', 'device offline'].some((x) => stderr.toLowerCase().includes(x))

mykola-mokhnach · 2019-04-12T06:07:30Z

lib/tools/system-calls.js

+ * @property {boolean} isSuccessful True if the call to root/unroot was successful
+ * @property {boolean} wasAlreadyRooted True if the device was already rooted
+ */
+
 /**
 * Switch adb server to root mode.


Please update the description

mykola-mokhnach · 2019-04-12T06:09:37Z

lib/tools/adb-commands.js

@@ -1301,7 +1304,8 @@ methods.killProcessByPID = async function killProcessByPID (pid) {
      }
      log.info(`Cannot kill PID ${pid} due to insufficient permissions. Retrying as root`);
      try {


try block is now redundant, since root call is not going to throw an exception

mykola-mokhnach · 2019-04-12T06:10:29Z

lib/tools/system-calls.js

-      }
+      log.info(`Call to '${cmd}' completed. Returning device to original unrooted state.`);
+      const {isSuccessful} = await this.unroot();
+      log.info(isSuccessful ? 'Returned device to unrooted state' : 'Could not return device to unrooted state');


mykola-mokhnach · 2019-04-12T06:12:29Z

lib/tools/system-calls.js

+    // Stop and re-start the device
+    await this.shell(['stop']);
+    await B.delay(2000); // let the emu finish stopping;
+    await this.setDeviceProperty('sys.boot_completed', 0, {privileged: false});


a comment about why privileged is set to false would be useful here

mykola-mokhnach

Minor comments. Otherwise looks good

dpgraham changed the title ~~[WIP] Azure flakiness~~ Fix 'device offline' problems caused by root/unroot Apr 10, 2019

dpgraham changed the title ~~Fix 'device offline' problems caused by root/unroot~~ [WIP] Fix 'device offline' problems caused by root/unroot Apr 10, 2019

dpgraham requested review from imurchie and mykola-mokhnach April 10, 2019 23:24

dpgraham changed the title ~~[WIP] Fix 'device offline' problems caused by root/unroot~~ Fix 'device offline' problems caused by root/unroot Apr 10, 2019

dpgraham closed this Apr 10, 2019

dpgraham reopened this Apr 10, 2019

dpgraham changed the title ~~Fix 'device offline' problems caused by root/unroot~~ fix: After root/unroot check if device is offline Apr 10, 2019

dpgraham added 19 commits April 10, 2019 16:57

Dummy

e97b71a

Try capture logcat

eb824c3

Try capture logcat

8af9277

Try capture logcat

8b65354

Artifacts

95593e8

Artifacts

c020ee2

Artifacts

0782fe3

Try restart on fail to unroot

b642d8b

Try restart on root

46287ff

Restart if offline

aecde7d

Test fix

19d71d9

Restart if offline

b92af7b

Add retries for root and unroot

b13d326

Skip reboot device again

25a7e68

Fix

b519a29

Try again

c9d8829

No test skipping

439f221

Wording fix

9a71d85

Fix

1a678a3