1 /* 2 * Copyright (C) 2016 The Android Open Source Project 3 * 4 * Licensed under the Apache License, Version 2.0 (the "License"); 5 * you may not use this file except in compliance with the License. 6 * You may obtain a copy of the License at 7 * 8 * http://www.apache.org/licenses/LICENSE-2.0 9 * 10 * Unless required by applicable law or agreed to in writing, software 11 * distributed under the License is distributed on an "AS IS" BASIS, 12 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. 13 * See the License for the specific language governing permissions and 14 * limitations under the License. 15 */ 16 package com.android.tradefed.device; 17 18 import com.android.ddmlib.AdbCommandRejectedException; 19 import com.android.ddmlib.CollectingOutputReceiver; 20 import com.android.ddmlib.IDevice; 21 import com.android.ddmlib.ShellCommandUnresponsiveException; 22 import com.android.ddmlib.TimeoutException; 23 import com.android.tradefed.device.IDeviceManager.IFastbootListener; 24 import com.android.tradefed.log.LogUtil.CLog; 25 import com.android.tradefed.util.IRunUtil; 26 import com.android.tradefed.util.RunInterruptedException; 27 import com.android.tradefed.util.RunUtil; 28 29 import java.io.IOException; 30 import java.util.ArrayList; 31 import java.util.Collection; 32 import java.util.List; 33 import java.util.concurrent.ExecutionException; 34 import java.util.concurrent.TimeUnit; 35 36 /** 37 * Helper class for monitoring the state of a {@link IDevice} with no framework support. 38 */ 39 public class NativeDeviceStateMonitor implements IDeviceStateMonitor { 40 41 static final String BOOTCOMPLETE_PROP = "dev.bootcomplete"; 42 43 private IDevice mDevice; 44 private TestDeviceState mDeviceState; 45 46 /** the time in ms to wait between 'poll for responsiveness' attempts */ 47 private static final long CHECK_POLL_TIME = 3 * 1000; 48 protected static final long MAX_CHECK_POLL_TIME = 30 * 1000; 49 /** the maximum operation time in ms for a 'poll for responsiveness' command */ 50 protected static final int MAX_OP_TIME = 10 * 1000; 51 52 /** The time in ms to wait for a device to be online. */ 53 private long mDefaultOnlineTimeout = 1 * 60 * 1000; 54 55 /** The time in ms to wait for a device to available. */ 56 private long mDefaultAvailableTimeout = 6 * 60 * 1000; 57 58 private List<DeviceStateListener> mStateListeners; 59 private IDeviceManager mMgr; 60 private final boolean mFastbootEnabled; 61 62 protected static final String PERM_DENIED_ERROR_PATTERN = "Permission denied"; 63 NativeDeviceStateMonitor(IDeviceManager mgr, IDevice device, boolean fastbootEnabled)64 public NativeDeviceStateMonitor(IDeviceManager mgr, IDevice device, 65 boolean fastbootEnabled) { 66 mMgr = mgr; 67 mDevice = device; 68 mStateListeners = new ArrayList<DeviceStateListener>(); 69 mDeviceState = TestDeviceState.getStateByDdms(device.getState()); 70 mFastbootEnabled = fastbootEnabled; 71 } 72 73 /** 74 * Get the {@link RunUtil} instance to use. 75 * <p/> 76 * Exposed for unit testing. 77 */ getRunUtil()78 IRunUtil getRunUtil() { 79 return RunUtil.getDefault(); 80 } 81 82 /** 83 * Set the time in ms to wait for a device to be online in {@link #waitForDeviceOnline()}. 84 */ 85 @Override setDefaultOnlineTimeout(long timeoutMs)86 public void setDefaultOnlineTimeout(long timeoutMs) { 87 mDefaultOnlineTimeout = timeoutMs; 88 } 89 90 /** 91 * Set the time in ms to wait for a device to be available in {@link #waitForDeviceAvailable()}. 92 */ 93 @Override setDefaultAvailableTimeout(long timeoutMs)94 public void setDefaultAvailableTimeout(long timeoutMs) { 95 mDefaultAvailableTimeout = timeoutMs; 96 } 97 98 /** 99 * {@inheritDoc} 100 */ 101 @Override waitForDeviceOnline(long waitTime)102 public IDevice waitForDeviceOnline(long waitTime) { 103 if (waitForDeviceState(TestDeviceState.ONLINE, waitTime)) { 104 return getIDevice(); 105 } 106 return null; 107 } 108 109 @Override waitForDeviceInRecovery()110 public IDevice waitForDeviceInRecovery() { 111 if (waitForDeviceState(TestDeviceState.RECOVERY, mDefaultOnlineTimeout)) { 112 return getIDevice(); 113 } 114 return null; 115 } 116 117 /** 118 * @return {@link IDevice} associate with the state monitor 119 */ getIDevice()120 protected IDevice getIDevice() { 121 synchronized (mDevice) { 122 return mDevice; 123 } 124 } 125 126 /** 127 * {@inheritDoc} 128 */ 129 @Override getSerialNumber()130 public String getSerialNumber() { 131 return getIDevice().getSerialNumber(); 132 } 133 134 /** 135 * {@inheritDoc} 136 */ 137 @Override waitForDeviceOnline()138 public IDevice waitForDeviceOnline() { 139 return waitForDeviceOnline(mDefaultOnlineTimeout); 140 } 141 142 /** 143 * {@inheritDoc} 144 */ 145 @Override waitForDeviceNotAvailable(long waitTime)146 public boolean waitForDeviceNotAvailable(long waitTime) { 147 IFastbootListener listener = new StubFastbootListener(); 148 if (mFastbootEnabled) { 149 mMgr.addFastbootListener(listener); 150 } 151 boolean result = waitForDeviceState(TestDeviceState.NOT_AVAILABLE, waitTime); 152 if (mFastbootEnabled) { 153 mMgr.removeFastbootListener(listener); 154 } 155 return result; 156 } 157 158 /** 159 * {@inheritDoc} 160 */ 161 @Override waitForDeviceInRecovery(long waitTime)162 public boolean waitForDeviceInRecovery(long waitTime) { 163 return waitForDeviceState(TestDeviceState.RECOVERY, waitTime); 164 } 165 166 /** {@inheritDoc} */ 167 @Override waitForDeviceInSideload(long waitTime)168 public boolean waitForDeviceInSideload(long waitTime) { 169 return waitForDeviceState(TestDeviceState.SIDELOAD, waitTime); 170 } 171 172 /** 173 * {@inheritDoc} 174 */ 175 @Override waitForDeviceShell(final long waitTime)176 public boolean waitForDeviceShell(final long waitTime) { 177 CLog.i("Waiting %d ms for device %s shell to be responsive", waitTime, 178 getSerialNumber()); 179 long startTime = System.currentTimeMillis(); 180 int counter = 1; 181 while (System.currentTimeMillis() - startTime < waitTime) { 182 final CollectingOutputReceiver receiver = createOutputReceiver(); 183 final String cmd = "ls /system/bin/adb"; 184 try { 185 getIDevice().executeShellCommand(cmd, receiver, MAX_OP_TIME, TimeUnit.MILLISECONDS); 186 String output = receiver.getOutput(); 187 if (output.contains("/system/bin/adb")) { 188 return true; 189 } 190 } catch (IOException | AdbCommandRejectedException | 191 ShellCommandUnresponsiveException e) { 192 CLog.e("%s failed on: %s", cmd, getSerialNumber()); 193 CLog.e(e); 194 } catch (TimeoutException e) { 195 CLog.e("%s failed on %s: timeout", cmd, getSerialNumber()); 196 CLog.e(e); 197 } 198 getRunUtil().sleep(Math.min(getCheckPollTime() * counter, MAX_CHECK_POLL_TIME)); 199 counter++; 200 } 201 CLog.w("Device %s shell is unresponsive", getSerialNumber()); 202 return false; 203 } 204 205 /** 206 * {@inheritDoc} 207 */ 208 @Override waitForDeviceAvailable(final long waitTime)209 public IDevice waitForDeviceAvailable(final long waitTime) { 210 // A device is currently considered "available" if and only if four events are true: 211 // 1. Device is online aka visible via DDMS/adb 212 // 2. Device has dev.bootcomplete flag set 213 // 3. Device's package manager is responsive (may be inop) 214 // 4. Device's external storage is mounted 215 // 216 // The current implementation waits for each event to occur in sequence. 217 // 218 // it will track the currently elapsed time and fail if it is 219 // greater than waitTime 220 221 long startTime = System.currentTimeMillis(); 222 IDevice device = waitForDeviceOnline(waitTime); 223 if (device == null) { 224 return null; 225 } 226 long elapsedTime = System.currentTimeMillis() - startTime; 227 if (!waitForBootComplete(waitTime - elapsedTime)) { 228 return null; 229 } 230 elapsedTime = System.currentTimeMillis() - startTime; 231 if (!postOnlineCheck(waitTime - elapsedTime)) { 232 return null; 233 } 234 return device; 235 } 236 237 /** 238 * {@inheritDoc} 239 */ 240 @Override waitForDeviceAvailable()241 public IDevice waitForDeviceAvailable() { 242 return waitForDeviceAvailable(mDefaultAvailableTimeout); 243 } 244 245 /** 246 * {@inheritDoc} 247 */ 248 @Override waitForBootComplete(final long waitTime)249 public boolean waitForBootComplete(final long waitTime) { 250 CLog.i("Waiting %d ms for device %s boot complete", waitTime, getSerialNumber()); 251 int counter = 1; 252 long startTime = System.currentTimeMillis(); 253 final String cmd = "getprop " + BOOTCOMPLETE_PROP; 254 while ((System.currentTimeMillis() - startTime) < waitTime) { 255 try { 256 String bootFlag = getIDevice().getSystemProperty("dev.bootcomplete").get(); 257 if ("1".equals(bootFlag)) { 258 return true; 259 } 260 } catch (InterruptedException e) { 261 CLog.i("%s on device %s failed: %s", cmd, getSerialNumber(), e.getMessage()); 262 // exit the loop for InterruptedException 263 break; 264 } catch (ExecutionException e) { 265 CLog.i("%s on device %s failed: %s", cmd, getSerialNumber(), e.getMessage()); 266 } 267 getRunUtil().sleep(Math.min(getCheckPollTime() * counter, MAX_CHECK_POLL_TIME)); 268 counter++; 269 } 270 CLog.w("Device %s did not boot after %d ms", getSerialNumber(), waitTime); 271 return false; 272 } 273 274 /** 275 * Additional checks to be done on an Online device 276 * 277 * @param waitTime time in ms to wait before giving up 278 * @return <code>true</code> if checks are successful before waitTime expires. 279 * <code>false</code> otherwise 280 */ postOnlineCheck(final long waitTime)281 protected boolean postOnlineCheck(final long waitTime) { 282 return waitForStoreMount(waitTime); 283 } 284 285 /** 286 * Waits for the device's external store to be mounted. 287 * 288 * @param waitTime time in ms to wait before giving up 289 * @return <code>true</code> if external store is mounted before waitTime expires. 290 * <code>false</code> otherwise 291 */ waitForStoreMount(final long waitTime)292 protected boolean waitForStoreMount(final long waitTime) { 293 CLog.i("Waiting %d ms for device %s external store", waitTime, getSerialNumber()); 294 long startTime = System.currentTimeMillis(); 295 int counter = 1; 296 // TODO(b/151119210): Remove this 'retryOnPermissionDenied' workaround when we figure out 297 // what causes "Permission denied" to be returned incorrectly. 298 int retryOnPermissionDenied = 1; 299 while (System.currentTimeMillis() - startTime < waitTime) { 300 final CollectingOutputReceiver receiver = createOutputReceiver(); 301 final CollectingOutputReceiver bitBucket = new CollectingOutputReceiver(); 302 final long number = getCurrentTime(); 303 final String externalStore = getMountPoint(IDevice.MNT_EXTERNAL_STORAGE); 304 305 final String testFile = String.format("'%s/%d'", externalStore, number); 306 final String testString = String.format("number %d one", number); 307 final String writeCmd = String.format("echo '%s' > %s", testString, testFile); 308 final String checkCmd = String.format("cat %s", testFile); 309 final String cleanupCmd = String.format("rm %s", testFile); 310 String cmd = null; 311 if (externalStore != null) { 312 try { 313 cmd = writeCmd; 314 getIDevice().executeShellCommand(writeCmd, bitBucket, 315 MAX_OP_TIME, TimeUnit.MILLISECONDS); 316 cmd = checkCmd; 317 getIDevice().executeShellCommand(checkCmd, receiver, 318 MAX_OP_TIME, TimeUnit.MILLISECONDS); 319 cmd = cleanupCmd; 320 getIDevice().executeShellCommand(cleanupCmd, bitBucket, 321 MAX_OP_TIME, TimeUnit.MILLISECONDS); 322 323 String output = receiver.getOutput(); 324 CLog.v("%s returned %s", checkCmd, output); 325 if (output.contains(testString)) { 326 return true; 327 } else if (output.contains(PERM_DENIED_ERROR_PATTERN) 328 && --retryOnPermissionDenied < 0) { 329 CLog.w("Device %s mount check returned Permision Denied, " 330 + "issue with mounting.", getSerialNumber()); 331 return false; 332 } 333 } catch (IOException | AdbCommandRejectedException | 334 ShellCommandUnresponsiveException e) { 335 CLog.i("%s on device %s failed:", cmd, getSerialNumber()); 336 CLog.e(e); 337 } catch (TimeoutException e) { 338 CLog.i("%s on device %s failed: timeout", cmd, getSerialNumber()); 339 CLog.e(e); 340 } 341 } else { 342 CLog.w("Failed to get external store mount point for %s", getSerialNumber()); 343 } 344 getRunUtil().sleep(Math.min(getCheckPollTime() * counter, MAX_CHECK_POLL_TIME)); 345 counter++; 346 } 347 CLog.w("Device %s external storage is not mounted after %d ms", 348 getSerialNumber(), waitTime); 349 return false; 350 } 351 352 /** 353 * {@inheritDoc} 354 */ 355 @Override getMountPoint(String mountName)356 public String getMountPoint(String mountName) { 357 String mountPoint = getIDevice().getMountPoint(mountName); 358 if (mountPoint != null) { 359 return mountPoint; 360 } 361 // cached mount point is null - try querying directly 362 CollectingOutputReceiver receiver = createOutputReceiver(); 363 try { 364 getIDevice().executeShellCommand("echo $" + mountName, receiver); 365 return receiver.getOutput().trim(); 366 } catch (IOException e) { 367 return null; 368 } catch (TimeoutException e) { 369 return null; 370 } catch (AdbCommandRejectedException e) { 371 return null; 372 } catch (ShellCommandUnresponsiveException e) { 373 return null; 374 } 375 } 376 377 /** 378 * {@inheritDoc} 379 */ 380 @Override getDeviceState()381 public TestDeviceState getDeviceState() { 382 return mDeviceState; 383 } 384 385 /** 386 * {@inheritDoc} 387 */ 388 @Override waitForDeviceBootloader(long time)389 public boolean waitForDeviceBootloader(long time) { 390 return waitForDeviceBootloaderOrFastbootd(time, false); 391 } 392 393 /** {@inheritDoc} */ 394 @Override waitForDeviceFastbootd(String fastbootPath, long time)395 public boolean waitForDeviceFastbootd(String fastbootPath, long time) { 396 return waitForDeviceBootloaderOrFastbootd(time, true); 397 } 398 waitForDeviceBootloaderOrFastbootd(long time, boolean fastbootd)399 private boolean waitForDeviceBootloaderOrFastbootd(long time, boolean fastbootd) { 400 if (!mFastbootEnabled) { 401 return false; 402 } 403 long startTime = System.currentTimeMillis(); 404 // ensure fastboot state is updated at least once 405 waitForDeviceBootloaderStateUpdate(); 406 long elapsedTime = System.currentTimeMillis() - startTime; 407 IFastbootListener listener = new StubFastbootListener(); 408 mMgr.addFastbootListener(listener); 409 long waitTime = time - elapsedTime; 410 if (waitTime < 0) { 411 // wait at least 200ms 412 waitTime = 200; 413 } 414 TestDeviceState mode = TestDeviceState.FASTBOOT; 415 if (fastbootd) { 416 mode = TestDeviceState.FASTBOOTD; 417 } 418 boolean result = waitForDeviceState(mode, waitTime); 419 mMgr.removeFastbootListener(listener); 420 return result; 421 } 422 423 @Override waitForDeviceBootloaderStateUpdate()424 public void waitForDeviceBootloaderStateUpdate() { 425 if (!mFastbootEnabled) { 426 return; 427 } 428 IFastbootListener listener = new NotifyFastbootListener(); 429 synchronized (listener) { 430 mMgr.addFastbootListener(listener); 431 try { 432 listener.wait(); 433 } catch (InterruptedException e) { 434 CLog.w("wait for device bootloader state update interrupted"); 435 CLog.w(e); 436 throw new RunInterruptedException(e); 437 } finally { 438 mMgr.removeFastbootListener(listener); 439 } 440 } 441 } 442 waitForDeviceState(TestDeviceState state, long time)443 private boolean waitForDeviceState(TestDeviceState state, long time) { 444 String deviceSerial = getSerialNumber(); 445 if (getDeviceState() == state) { 446 CLog.i("Device %s is already %s", deviceSerial, state); 447 return true; 448 } 449 CLog.i("Waiting for device %s to be %s; it is currently %s...", deviceSerial, 450 state, getDeviceState()); 451 DeviceStateListener listener = new DeviceStateListener(state); 452 addDeviceStateListener(listener); 453 synchronized (listener) { 454 try { 455 listener.wait(time); 456 } catch (InterruptedException e) { 457 CLog.w("wait for device state interrupted"); 458 CLog.w(e); 459 throw new RunInterruptedException(e); 460 } finally { 461 removeDeviceStateListener(listener); 462 } 463 } 464 return getDeviceState().equals(state); 465 } 466 467 /** 468 * @param listener 469 */ removeDeviceStateListener(DeviceStateListener listener)470 private void removeDeviceStateListener(DeviceStateListener listener) { 471 synchronized (mStateListeners) { 472 mStateListeners.remove(listener); 473 } 474 } 475 476 /** 477 * @param listener 478 */ addDeviceStateListener(DeviceStateListener listener)479 private void addDeviceStateListener(DeviceStateListener listener) { 480 synchronized (mStateListeners) { 481 mStateListeners.add(listener); 482 } 483 } 484 485 /** 486 * {@inheritDoc} 487 */ 488 @Override setState(TestDeviceState deviceState)489 public void setState(TestDeviceState deviceState) { 490 mDeviceState = deviceState; 491 // create a copy of listeners to prevent holding mStateListeners lock when notifying 492 // and to protect from list modification when iterating 493 Collection<DeviceStateListener> listenerCopy = new ArrayList<DeviceStateListener>( 494 mStateListeners.size()); 495 synchronized (mStateListeners) { 496 listenerCopy.addAll(mStateListeners); 497 } 498 for (DeviceStateListener listener: listenerCopy) { 499 listener.stateChanged(deviceState); 500 } 501 } 502 503 @Override setIDevice(IDevice newDevice)504 public void setIDevice(IDevice newDevice) { 505 IDevice currentDevice = mDevice; 506 if (!getIDevice().equals(newDevice)) { 507 synchronized (currentDevice) { 508 mDevice = newDevice; 509 } 510 } 511 } 512 513 private static class DeviceStateListener { 514 private final TestDeviceState mExpectedState; 515 DeviceStateListener(TestDeviceState expectedState)516 public DeviceStateListener(TestDeviceState expectedState) { 517 mExpectedState = expectedState; 518 } 519 stateChanged(TestDeviceState newState)520 public void stateChanged(TestDeviceState newState) { 521 if (mExpectedState.equals(newState)) { 522 synchronized (this) { 523 notify(); 524 } 525 } 526 } 527 } 528 529 /** 530 * An empty implementation of {@link IFastbootListener} 531 */ 532 private static class StubFastbootListener implements IFastbootListener { 533 @Override stateUpdated()534 public void stateUpdated() { 535 // ignore 536 } 537 } 538 539 /** 540 * A {@link IFastbootListener} that notifies when a status update has been received. 541 */ 542 private static class NotifyFastbootListener implements IFastbootListener { 543 @Override stateUpdated()544 public void stateUpdated() { 545 synchronized (this) { 546 notify(); 547 } 548 } 549 } 550 551 /** 552 * {@inheritDoc} 553 */ 554 @Override isAdbTcp()555 public boolean isAdbTcp() { 556 return mDevice.getSerialNumber().contains(":"); 557 } 558 559 /** 560 * Exposed for testing 561 * @return {@link CollectingOutputReceiver} 562 */ createOutputReceiver()563 protected CollectingOutputReceiver createOutputReceiver() { 564 return new CollectingOutputReceiver(); 565 } 566 567 /** 568 * Exposed for testing 569 */ getCheckPollTime()570 protected long getCheckPollTime() { 571 return CHECK_POLL_TIME; 572 } 573 574 /** 575 * Exposed for testing 576 */ getCurrentTime()577 protected long getCurrentTime() { 578 return System.currentTimeMillis(); 579 } 580 } 581