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