1 /* 2 * Copyright (C) 2010 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 17 package com.android.tradefed.command; 18 19 import com.google.common.annotations.VisibleForTesting; 20 21 import com.android.ddmlib.DdmPreferences; 22 import com.android.ddmlib.IDevice; 23 import com.android.ddmlib.Log; 24 import com.android.ddmlib.Log.LogLevel; 25 import com.android.tradefed.command.CommandFileParser.CommandLine; 26 import com.android.tradefed.command.CommandFileWatcher.ICommandFileListener; 27 import com.android.tradefed.command.CommandRunner.ExitCode; 28 import com.android.tradefed.command.remote.DeviceDescriptor; 29 import com.android.tradefed.command.remote.IRemoteClient; 30 import com.android.tradefed.command.remote.RemoteClient; 31 import com.android.tradefed.command.remote.RemoteException; 32 import com.android.tradefed.command.remote.RemoteManager; 33 import com.android.tradefed.config.ConfigurationDef; 34 import com.android.tradefed.config.ConfigurationException; 35 import com.android.tradefed.config.ConfigurationFactory; 36 import com.android.tradefed.config.GlobalConfiguration; 37 import com.android.tradefed.config.IConfiguration; 38 import com.android.tradefed.config.IConfigurationFactory; 39 import com.android.tradefed.config.IDeviceConfiguration; 40 import com.android.tradefed.config.IGlobalConfiguration; 41 import com.android.tradefed.config.Option; 42 import com.android.tradefed.device.DeviceAllocationState; 43 import com.android.tradefed.device.DeviceManager; 44 import com.android.tradefed.device.DeviceNotAvailableException; 45 import com.android.tradefed.device.DeviceUnresponsiveException; 46 import com.android.tradefed.device.FreeDeviceState; 47 import com.android.tradefed.device.IDeviceManager; 48 import com.android.tradefed.device.IDeviceMonitor; 49 import com.android.tradefed.device.IManagedTestDevice; 50 import com.android.tradefed.device.ITestDevice; 51 import com.android.tradefed.device.ITestDevice.RecoveryMode; 52 import com.android.tradefed.device.NoDeviceException; 53 import com.android.tradefed.device.StubDevice; 54 import com.android.tradefed.device.TestDeviceState; 55 import com.android.tradefed.invoker.IInvocationContext; 56 import com.android.tradefed.invoker.IRescheduler; 57 import com.android.tradefed.invoker.ITestInvocation; 58 import com.android.tradefed.invoker.InvocationContext; 59 import com.android.tradefed.invoker.TestInvocation; 60 import com.android.tradefed.log.ILogRegistry.EventType; 61 import com.android.tradefed.log.LogRegistry; 62 import com.android.tradefed.log.LogUtil.CLog; 63 import com.android.tradefed.result.ITestInvocationListener; 64 import com.android.tradefed.result.ResultForwarder; 65 import com.android.tradefed.util.ArrayUtil; 66 import com.android.tradefed.util.FileUtil; 67 import com.android.tradefed.util.QuotationAwareTokenizer; 68 import com.android.tradefed.util.RunUtil; 69 import com.android.tradefed.util.TableFormatter; 70 import com.android.tradefed.util.TimeUtil; 71 import com.android.tradefed.util.hostmetric.IHostMonitor; 72 import com.android.tradefed.util.hostmetric.IHostMonitor.HostDataPoint; 73 import com.android.tradefed.util.hostmetric.IHostMonitor.HostMetricType; 74 import com.android.tradefed.util.keystore.IKeyStoreClient; 75 import com.android.tradefed.util.keystore.IKeyStoreFactory; 76 import com.android.tradefed.util.keystore.KeyStoreException; 77 78 import org.json.JSONException; 79 80 import java.io.File; 81 import java.io.IOException; 82 import java.io.PrintWriter; 83 import java.util.ArrayList; 84 import java.util.Arrays; 85 import java.util.Collections; 86 import java.util.Comparator; 87 import java.util.HashMap; 88 import java.util.HashSet; 89 import java.util.Iterator; 90 import java.util.LinkedHashMap; 91 import java.util.LinkedHashSet; 92 import java.util.LinkedList; 93 import java.util.List; 94 import java.util.Map; 95 import java.util.Set; 96 import java.util.Timer; 97 import java.util.TimerTask; 98 import java.util.concurrent.CountDownLatch; 99 import java.util.concurrent.ExecutionException; 100 import java.util.concurrent.ScheduledThreadPoolExecutor; 101 import java.util.concurrent.TimeUnit; 102 import java.util.regex.Pattern; 103 104 /** 105 * A scheduler for running TradeFederation commands across all available devices. 106 * <p/> 107 * Will attempt to prioritize commands to run based on a total running count of their execution 108 * time. e.g. infrequent or fast running commands will get prioritized over long running commands. 109 * <p/> 110 * Runs forever in background until shutdown. 111 */ 112 public class CommandScheduler extends Thread implements ICommandScheduler, ICommandFileListener { 113 114 /** the queue of commands ready to be executed. */ 115 private List<ExecutableCommand> mReadyCommands; 116 private Set<ExecutableCommand> mUnscheduledWarning; 117 118 /** the queue of commands sleeping. */ 119 private Set<ExecutableCommand> mSleepingCommands; 120 121 /** the queue of commands current executing. */ 122 private Set<ExecutableCommand> mExecutingCommands; 123 124 /** map of device to active invocation threads */ 125 private Map<IInvocationContext, InvocationThread> mInvocationThreadMap; 126 127 /** timer for scheduling commands to be re-queued for execution */ 128 private ScheduledThreadPoolExecutor mCommandTimer; 129 130 private IRemoteClient mRemoteClient = null; 131 private RemoteManager mRemoteManager = null; 132 133 private CommandFileWatcher mCommandFileWatcher = null; 134 135 /** latch used to notify other threads that this thread is running */ 136 private final CountDownLatch mRunLatch; 137 138 /** maximum time to wait for handover initiation to complete */ 139 private static final long MAX_HANDOVER_INIT_TIME = 2 * 60 * 1000; 140 141 /** Maximum time to wait for adb to initialize and get the physical devices discovered */ 142 private static final long ADB_INIT_TIME_MS = 500; 143 144 /** used to assign unique ids to each CommandTracker created */ 145 private int mCurrentCommandId = 0; 146 147 /** flag for instructing scheduler to exit when no commands are present */ 148 private boolean mShutdownOnEmpty = false; 149 150 private boolean mStarted = false; 151 152 // flag to indicate this scheduler is currently handing over control to another remote TF 153 private boolean mPerformingHandover = false; 154 155 private WaitObj mHandoverHandshake = new WaitObj(); 156 157 private WaitObj mCommandProcessWait = new WaitObj(); 158 159 /** The last {@link InvocationThread} that ran error code and error stack*/ 160 private ExitCode mLastInvocationExitCode = ExitCode.NO_ERROR; 161 private Throwable mLastInvocationThrowable = null; 162 163 @Option(name = "reload-cmdfiles", description = 164 "Whether to enable the command file autoreload mechanism") 165 // FIXME: enable this to be enabled or disabled on a per-cmdfile basis 166 private boolean mReloadCmdfiles = false; 167 168 @Option( 169 name = "max-poll-time", 170 description = "ms between forced command scheduler execution time" 171 ) 172 private long mPollTime = 30 * 1000; // 30 seconds 173 174 @Option(name = "shutdown-on-cmdfile-error", description = 175 "terminate TF session if a configuration exception on command file occurs") 176 private boolean mShutdownOnCmdfileError = false; 177 178 @Option(name = "shutdown-delay", description = 179 "maximum time to wait before allowing final interruption of scheduler to terminate" 180 + " TF session. If value is zero, interruption will only be triggered" 181 + " when Invocation become interruptible. (Default behavior).", isTimeVal = true) 182 private long mShutdownTimeout = 0; 183 184 private enum CommandState { 185 WAITING_FOR_DEVICE("Wait_for_device"), 186 EXECUTING("Executing"), 187 SLEEPING("Sleeping"); 188 189 private final String mDisplayName; 190 191 CommandState(String displayName) { 192 mDisplayName = displayName; 193 } 194 195 public String getDisplayName() { 196 return mDisplayName; 197 } 198 } 199 200 /** 201 * Represents one active command added to the scheduler. Will track total execution time of all 202 * instances of this command 203 */ 204 static class CommandTracker { 205 private final int mId; 206 private final String[] mArgs; 207 private final String mCommandFilePath; 208 209 /** the total amount of time this command was executing. Used to prioritize */ 210 private long mTotalExecTime = 0; 211 212 CommandTracker(int id, String[] args, String commandFilePath) { 213 mId = id; 214 mArgs = args; 215 mCommandFilePath = commandFilePath; 216 } 217 218 synchronized void incrementExecTime(long execTime) { 219 mTotalExecTime += execTime; 220 } 221 222 /** 223 * @return the total amount of execution time for this command. 224 */ 225 synchronized long getTotalExecTime() { 226 return mTotalExecTime; 227 } 228 229 /** 230 * Get the full list of config arguments associated with this command. 231 */ 232 String[] getArgs() { 233 return mArgs; 234 } 235 236 int getId() { 237 return mId; 238 } 239 240 /** 241 * Return the path of the file this command is associated with. null if not applicable 242 */ 243 String getCommandFilePath() { 244 return mCommandFilePath; 245 } 246 } 247 248 /** 249 * Represents one instance of a command to be executed. 250 */ 251 private class ExecutableCommand { 252 private final CommandTracker mCmdTracker; 253 private final IConfiguration mConfig; 254 private final boolean mRescheduled; 255 private final long mCreationTime; 256 private Long mSleepTime; 257 258 private ExecutableCommand(CommandTracker tracker, IConfiguration config, 259 boolean rescheduled) { 260 mConfig = config; 261 mCmdTracker = tracker; 262 mRescheduled = rescheduled; 263 mCreationTime = System.currentTimeMillis(); 264 } 265 266 /** 267 * Gets the {@link IConfiguration} for this command instance 268 */ 269 public IConfiguration getConfiguration() { 270 return mConfig; 271 } 272 273 /** 274 * Gets the associated {@link CommandTracker}. 275 */ 276 CommandTracker getCommandTracker() { 277 return mCmdTracker; 278 } 279 280 /** 281 * Callback to inform listener that command has started execution. 282 */ 283 void commandStarted() { 284 mSleepTime = null; 285 } 286 287 public void commandFinished(long elapsedTime) { 288 getCommandTracker().incrementExecTime(elapsedTime); 289 CLog.d("removing exec command for id %d", getCommandTracker().getId()); 290 synchronized (CommandScheduler.this) { 291 mExecutingCommands.remove(this); 292 } 293 if (isShuttingDown()) { 294 mCommandProcessWait.signalEventReceived(); 295 } 296 } 297 298 public boolean isRescheduled() { 299 return mRescheduled; 300 } 301 302 public long getCreationTime() { 303 return mCreationTime; 304 } 305 306 public boolean isLoopMode() { 307 return mConfig.getCommandOptions().isLoopMode(); 308 } 309 310 public Long getSleepTime() { 311 return mSleepTime; 312 } 313 314 public String getCommandFilePath() { 315 return mCmdTracker.getCommandFilePath(); 316 } 317 } 318 319 /** 320 * struct for a command and its state 321 */ 322 private static class ExecutableCommandState { 323 final ExecutableCommand cmd; 324 final CommandState state; 325 326 ExecutableCommandState(ExecutableCommand cmd, CommandState state) { 327 this.cmd = cmd; 328 this.state = state; 329 } 330 } 331 332 /** 333 * A {@link IRescheduler} that will add a command back to the queue. 334 */ 335 private class Rescheduler implements IRescheduler { 336 337 private CommandTracker mCmdTracker; 338 339 Rescheduler(CommandTracker cmdTracker) { 340 mCmdTracker = cmdTracker; 341 } 342 343 /** 344 * {@inheritDoc} 345 */ 346 @Override 347 public boolean scheduleConfig(IConfiguration config) { 348 // force loop mode to off, otherwise each rescheduled config will be treated as 349 // a new command and added back to queue 350 config.getCommandOptions().setLoopMode(false); 351 ExecutableCommand rescheduledCmd = createExecutableCommand(mCmdTracker, config, true); 352 return addExecCommandToQueue(rescheduledCmd, 0); 353 } 354 355 /** 356 * {@inheritDoc} 357 */ 358 @Override 359 public boolean rescheduleCommand() { 360 try { 361 CLog.d("rescheduling for command %d", mCmdTracker.getId()); 362 IConfiguration config = getConfigFactory().createConfigurationFromArgs( 363 mCmdTracker.getArgs()); 364 ExecutableCommand execCmd = createExecutableCommand(mCmdTracker, config, true); 365 return addExecCommandToQueue(execCmd, config.getCommandOptions().getLoopTime()); 366 } catch (ConfigurationException e) { 367 // FIXME: do this with jline somehow for ANSI support 368 // note: make sure not to log (aka record) this line, as (args) may contain 369 // passwords. 370 System.out.println(String.format("Error while processing args: %s", 371 Arrays.toString(mCmdTracker.getArgs()))); 372 System.out.println(e.getMessage()); 373 System.out.println(); 374 return false; 375 } 376 } 377 } 378 379 /** 380 * Comparator for {@link ExecutableCommand}. 381 * <p/> 382 * Delegates to {@link CommandTrackerTimeComparator}. 383 */ 384 private static class ExecutableCommandComparator implements Comparator<ExecutableCommand> { 385 CommandTrackerTimeComparator mTrackerComparator = new CommandTrackerTimeComparator(); 386 387 /** 388 * {@inheritDoc} 389 */ 390 @Override 391 public int compare(ExecutableCommand c1, ExecutableCommand c2) { 392 return mTrackerComparator.compare(c1.getCommandTracker(), c2.getCommandTracker()); 393 } 394 } 395 396 /** 397 * Comparator for {@link CommandTracker}. 398 * <p/> 399 * Compares by mTotalExecTime, prioritizing configs with lower execution time 400 */ 401 private static class CommandTrackerTimeComparator implements Comparator<CommandTracker> { 402 403 @Override 404 public int compare(CommandTracker c1, CommandTracker c2) { 405 if (c1.getTotalExecTime() == c2.getTotalExecTime()) { 406 return 0; 407 } else if (c1.getTotalExecTime() < c2.getTotalExecTime()) { 408 return -1; 409 } else { 410 return 1; 411 } 412 } 413 } 414 415 /** 416 * Comparator for {@link CommandTracker}. 417 * <p/> 418 * Compares by id. 419 */ 420 static class CommandTrackerIdComparator implements Comparator<CommandTracker> { 421 422 @Override 423 public int compare(CommandTracker c1, CommandTracker c2) { 424 if (c1.getId() == c2.getId()) { 425 return 0; 426 } else if (c1.getId() < c2.getId()) { 427 return -1; 428 } else { 429 return 1; 430 } 431 } 432 } 433 434 /** 435 * An {@link com.android.tradefed.command.ICommandScheduler.IScheduledInvocationListener} 436 * for locally scheduled commands added via addCommand. 437 * <p/> 438 * Returns device to device manager and remote handover server if applicable. 439 */ 440 private class FreeDeviceHandler extends ResultForwarder implements 441 IScheduledInvocationListener { 442 443 private final IDeviceManager mDeviceManager; 444 445 FreeDeviceHandler(IDeviceManager deviceManager, 446 IScheduledInvocationListener... listeners) { 447 super(listeners); 448 mDeviceManager = deviceManager; 449 } 450 451 @Deprecated 452 @Override 453 public void invocationComplete(ITestDevice device, FreeDeviceState deviceState) { 454 IInvocationContext context = new InvocationContext(); 455 // Fake a single device context for compatibility 456 context.addAllocatedDevice(ConfigurationDef.DEFAULT_DEVICE_NAME, device); 457 Map<ITestDevice, FreeDeviceState> state = new HashMap<>(); 458 state.put(device, deviceState); 459 invocationComplete(context, state); 460 } 461 462 @Override 463 public void invocationComplete(IInvocationContext context, 464 Map<ITestDevice, FreeDeviceState> devicesStates) { 465 for (ITestInvocationListener listener : getListeners()) { 466 ((IScheduledInvocationListener) listener).invocationComplete(context, devicesStates); 467 } 468 469 for (ITestDevice device : context.getDevices()) { 470 mDeviceManager.freeDevice(device, devicesStates.get(device)); 471 remoteFreeDevice(device); 472 if (device instanceof IManagedTestDevice) { 473 // This quite an important setting so we do make sure it's reset. 474 ((IManagedTestDevice)device).setFastbootPath(mDeviceManager.getFastbootPath()); 475 } 476 } 477 } 478 } 479 480 /** 481 * Monitor Class for {@link InvocationThread} to make sure it does not run for too long. 482 */ 483 private class InvocationThreadMonitor extends TimerTask { 484 485 private InvocationThread mInvocationThread = null; 486 private boolean mTriggered = false; 487 488 public InvocationThreadMonitor(InvocationThread toMonitor) { 489 mInvocationThread = toMonitor; 490 } 491 492 @Override 493 public void run() { 494 if (mInvocationThread != null) { 495 mTriggered = true; 496 mInvocationThread.stopInvocation("Invocation Timeout Reached."); 497 } 498 } 499 500 public boolean isTriggered() { 501 return mTriggered; 502 } 503 } 504 505 private class InvocationThread extends Thread { 506 /** 507 * time to wait for device adb shell responsive connection before declaring it unavailable 508 * for the next iteration of testing. 509 */ 510 private static final long CHECK_WAIT_DEVICE_AVAIL_MS = 30 * 1000; 511 private static final int EXPECTED_THREAD_COUNT = 1; 512 private static final String INVOC_END_EVENT_ID_KEY = "id"; 513 private static final String INVOC_END_EVENT_ELAPSED_KEY = "elapsed-time"; 514 private static final String INVOC_END_EVENT_TAG_KEY = "test-tag"; 515 516 private final IScheduledInvocationListener[] mListeners; 517 private final IInvocationContext mInvocationContext; 518 private final ExecutableCommand mCmd; 519 private final ITestInvocation mInvocation; 520 private final InvocationThreadMonitor mInvocationThreadMonitor; 521 private final Timer mExecutionTimer; 522 private long mStartTime = -1; 523 524 public InvocationThread(String name, IInvocationContext invocationContext, 525 ExecutableCommand command, IScheduledInvocationListener... listeners) { 526 // create a thread group so LoggerRegistry can identify this as an invocationThread 527 super(new ThreadGroup(name), name); 528 mListeners = listeners; 529 mInvocationContext = invocationContext; 530 mCmd = command; 531 mInvocation = createRunInstance(); 532 533 // Daemon timer 534 mExecutionTimer = new Timer(true); 535 mInvocationThreadMonitor = new InvocationThreadMonitor(this); 536 } 537 538 public long getStartTime() { 539 return mStartTime; 540 } 541 542 @Override 543 public void run() { 544 Map<ITestDevice, FreeDeviceState> deviceStates = new HashMap<>(); 545 for (ITestDevice device : mInvocationContext.getDevices()) { 546 deviceStates.put(device, FreeDeviceState.AVAILABLE); 547 } 548 mStartTime = System.currentTimeMillis(); 549 ITestInvocation instance = getInvocation(); 550 IConfiguration config = mCmd.getConfiguration(); 551 552 // Copy the command options invocation attributes to the invocation. 553 // TODO: Implement a locking/read-only mechanism to prevent unwanted attributes to be 554 // added during the invocation. 555 if (!config.getCommandOptions().getInvocationData().isEmpty()) { 556 mInvocationContext.addInvocationAttributes( 557 config.getCommandOptions().getInvocationData()); 558 } 559 560 try { 561 mCmd.commandStarted(); 562 long invocTimeout = config.getCommandOptions().getInvocationTimeout(); 563 if (invocTimeout > 0) { 564 CLog.i("Setting a timer for the invocation in %sms", invocTimeout); 565 mExecutionTimer.schedule(mInvocationThreadMonitor, invocTimeout); 566 } 567 instance.invoke(mInvocationContext, config, 568 new Rescheduler(mCmd.getCommandTracker()), mListeners); 569 } catch (DeviceUnresponsiveException e) { 570 CLog.w("Device %s is unresponsive. Reason: %s", e.getSerial(), e.getMessage()); 571 ITestDevice badDevice = mInvocationContext.getDeviceBySerial(e.getSerial()); 572 if (badDevice != null) { 573 deviceStates.put(badDevice, FreeDeviceState.UNRESPONSIVE); 574 } 575 setLastInvocationExitCode(ExitCode.DEVICE_UNRESPONSIVE, e); 576 } catch (DeviceNotAvailableException e) { 577 CLog.w("Device %s is not available. Reason: %s", e.getSerial(), e.getMessage()); 578 ITestDevice badDevice = mInvocationContext.getDeviceBySerial(e.getSerial()); 579 if (badDevice != null) { 580 deviceStates.put(badDevice, FreeDeviceState.UNAVAILABLE); 581 } 582 setLastInvocationExitCode(ExitCode.DEVICE_UNAVAILABLE, e); 583 } catch (FatalHostError e) { 584 CLog.wtf(String.format("Fatal error occurred: %s, shutting down", e.getMessage()), 585 e); 586 setLastInvocationExitCode(ExitCode.FATAL_HOST_ERROR, e); 587 shutdown(); 588 } catch (Throwable e) { 589 setLastInvocationExitCode(ExitCode.THROWABLE_EXCEPTION, e); 590 CLog.e(e); 591 } finally { 592 mExecutionTimer.cancel(); 593 if (mInvocationThreadMonitor.isTriggered()) { 594 CLog.e("Invocation reached its timeout. Cleaning up."); 595 } 596 long elapsedTime = System.currentTimeMillis() - mStartTime; 597 CLog.i("Updating command %d with elapsed time %d ms", 598 mCmd.getCommandTracker().getId(), elapsedTime); 599 // remove invocation thread first so another invocation can be started on device 600 // when freed 601 removeInvocationThread(this); 602 for (ITestDevice device : mInvocationContext.getDevices()) { 603 if (device.getIDevice() instanceof StubDevice) { 604 // Never release stub and Tcp devices, otherwise they will disappear 605 // during deallocation since they are only placeholder. 606 deviceStates.put(device, FreeDeviceState.AVAILABLE); 607 } else if (!TestDeviceState.ONLINE.equals(device.getDeviceState())) { 608 // If the device is offline at the end of the test 609 deviceStates.put(device, FreeDeviceState.UNAVAILABLE); 610 } else if (!isDeviceResponsive(device)) { 611 // If device cannot pass basic shell responsiveness test. 612 deviceStates.put(device, FreeDeviceState.UNAVAILABLE); 613 } 614 // Reset the recovery mode at the end of the invocation. 615 device.setRecoveryMode(RecoveryMode.AVAILABLE); 616 } 617 618 checkStrayThreads(); 619 620 for (final IScheduledInvocationListener listener : mListeners) { 621 try { 622 listener.invocationComplete(mInvocationContext, deviceStates); 623 } catch (Throwable anyException) { 624 CLog.e("Exception caught while calling invocationComplete:"); 625 CLog.e(anyException); 626 } 627 } 628 mCmd.commandFinished(elapsedTime); 629 logInvocationEndedEvent( 630 mCmd.getCommandTracker().getId(), elapsedTime, mInvocationContext); 631 } 632 } 633 634 /** Check the number of thread in the ThreadGroup, only one should exists (itself). */ 635 private void checkStrayThreads() { 636 int numThread = this.getThreadGroup().activeCount(); 637 if (numThread == EXPECTED_THREAD_COUNT) { 638 // No stray thread detected at the end of invocation 639 return; 640 } 641 List<String> cmd = Arrays.asList(mCmd.getCommandTracker().getArgs()); 642 CLog.e( 643 "Stray thread detected for command %d, %s. %d threads instead of %d", 644 mCmd.getCommandTracker().getId(), cmd, numThread, EXPECTED_THREAD_COUNT); 645 // This is the best we have for debug, it prints to std out. 646 Thread[] listThreads = new Thread[numThread]; 647 this.getThreadGroup().enumerate(listThreads); 648 CLog.e("List of remaining threads: %s", Arrays.asList(listThreads)); 649 List<IHostMonitor> hostMonitors = GlobalConfiguration.getHostMonitorInstances(); 650 if (hostMonitors != null) { 651 for (IHostMonitor hm : hostMonitors) { 652 HostDataPoint data = new HostDataPoint("numThread", numThread, cmd.toString()); 653 hm.addHostEvent(HostMetricType.INVOCATION_STRAY_THREAD, data); 654 } 655 } 656 // printing to stderr will help to catch them. 657 System.err.println( 658 String.format( 659 "We have %s threads instead of 1: %s. Check the logs for list of " 660 + "threads.", 661 numThread, Arrays.asList(listThreads))); 662 } 663 664 /** Helper to log an invocation ended event. */ 665 private void logInvocationEndedEvent( 666 int invocId, long elapsedTime, final IInvocationContext context) { 667 Map<String, String> args = new HashMap<>(); 668 args.put(INVOC_END_EVENT_ID_KEY, Integer.toString(invocId)); 669 args.put(INVOC_END_EVENT_ELAPSED_KEY, TimeUtil.formatElapsedTime(elapsedTime)); 670 args.put(INVOC_END_EVENT_TAG_KEY, context.getTestTag()); 671 // Add all the invocation attributes to the final event logging. 672 // UniqueMultiMap cannot be easily converted to Map so we just iterate. 673 for (String key : context.getAttributes().keySet()) { 674 args.put(key, context.getAttributes().get(key).get(0)); 675 } 676 logEvent(EventType.INVOCATION_END, args); 677 } 678 679 /** Basic responsiveness check at the end of an invocation. */ 680 private boolean isDeviceResponsive(ITestDevice device) { 681 return device.waitForDeviceShell(CHECK_WAIT_DEVICE_AVAIL_MS); 682 } 683 684 ITestInvocation getInvocation() { 685 return mInvocation; 686 } 687 688 IInvocationContext getInvocationContext() { 689 return mInvocationContext; 690 } 691 692 /** 693 * Stops a running invocation. {@link CommandScheduler#shutdownHard()} will stop 694 * all running invocations. 695 */ 696 public void stopInvocation(String message) { 697 getInvocation().notifyInvocationStopped(); 698 for (ITestDevice device : mInvocationContext.getDevices()) { 699 if (device != null && device.getIDevice().isOnline()) { 700 // Kill all running processes on device. 701 try { 702 device.executeShellCommand("am kill-all"); 703 } catch (DeviceNotAvailableException e) { 704 CLog.e("failed to kill process on device %s", 705 device.getSerialNumber()); 706 CLog.e(e); 707 } 708 709 } 710 } 711 // If invocation is not currently in an interruptible state we provide a timer 712 // after which it will become interruptible. 713 // If timeout is 0, we do not enforce future interruption. 714 if (!mInvocationThreadMonitor.isTriggered() && getShutdownTimeout() != 0) { 715 RunUtil.getDefault().setInterruptibleInFuture(this, getShutdownTimeout()); 716 } 717 RunUtil.getDefault().interrupt(this, message); 718 719 if (mInvocationThreadMonitor.isTriggered()) { 720 // if we enforce the invocation timeout, we force interrupt the thread. 721 CLog.e("Forcing the interruption."); 722 this.interrupt(); 723 } 724 } 725 726 /** 727 * Disable the reporting from reporters that implements a non-default 728 * {@link ITestInvocationListener#invocationInterrupted()}. 729 * Should be called on shutdown. 730 */ 731 public void disableReporters() { 732 for (ITestInvocationListener listener : 733 mCmd.getConfiguration().getTestInvocationListeners()) { 734 listener.invocationInterrupted(); 735 } 736 } 737 738 /** 739 * Checks whether the device battery level is above the required value to keep running the 740 * invocation. 741 */ 742 public void checkDeviceBatteryLevel() { 743 for (String deviceName : mInvocationContext.getDeviceConfigNames()) { 744 if (mCmd.getConfiguration().getDeviceConfigByName(deviceName) 745 .getDeviceOptions() == null) { 746 CLog.d("No deviceOptions in the configuration, cannot do Battery level check"); 747 return; 748 } 749 final Integer cutoffBattery = mCmd.getConfiguration() 750 .getDeviceConfigByName(deviceName).getDeviceOptions().getCutoffBattery(); 751 752 if (mInvocationContext.getDevice(deviceName) != null && cutoffBattery != null) { 753 final IDevice device = mInvocationContext.getDevice(deviceName).getIDevice(); 754 int batteryLevel = -1; 755 try { 756 batteryLevel = device.getBattery(500, TimeUnit.MILLISECONDS).get(); 757 } catch (InterruptedException | ExecutionException e) { 758 // fall through 759 } 760 CLog.d("device %s: battery level=%d%%", device.getSerialNumber(), batteryLevel); 761 // This logic is based on the assumption that batterLevel will be 0 or -1 if TF 762 // fails to fetch a valid battery level or the device is not using a battery. 763 // So batteryLevel=0 will not trigger a stop. 764 if (0 < batteryLevel && batteryLevel < cutoffBattery) { 765 if (RunUtil.getDefault().isInterruptAllowed()) { 766 CLog.i("Stopping %s: battery too low (%d%% < %d%%)", 767 getName(), batteryLevel, cutoffBattery); 768 stopInvocation(String.format( 769 "battery too low (%d%% < %d%%)", batteryLevel, cutoffBattery)); 770 } else { 771 // In this case, the battery is check periodically by CommandScheduler 772 // so there will be more opportunity to terminate the invocation when 773 // it's interruptible. 774 CLog.w("device: %s has a low battery but is in uninterruptible state.", 775 device.getSerialNumber()); 776 } 777 } 778 } 779 } 780 } 781 } 782 783 /** 784 * A {@link IDeviceMonitor} that signals scheduler to process commands when an available device 785 * is added. 786 */ 787 private class AvailDeviceMonitor implements IDeviceMonitor { 788 789 @Override 790 public void run() { 791 // ignore 792 } 793 794 @Override 795 public void stop() { 796 // ignore 797 } 798 799 @Override 800 public void setDeviceLister(DeviceLister lister) { 801 // ignore 802 } 803 804 @Override 805 public void notifyDeviceStateChange(String serial, DeviceAllocationState oldState, 806 DeviceAllocationState newState) { 807 if (newState.equals(DeviceAllocationState.Available)) { 808 // new avail device was added, wake up scheduler 809 mCommandProcessWait.signalEventReceived(); 810 } 811 } 812 } 813 814 /** 815 * Creates a {@link CommandScheduler}. 816 * <p /> 817 * Note: start must be called before use. 818 */ 819 public CommandScheduler() { 820 super("CommandScheduler"); // set the thread name 821 mReadyCommands = new LinkedList<>(); 822 mUnscheduledWarning = new HashSet<>(); 823 mSleepingCommands = new HashSet<>(); 824 mExecutingCommands = new HashSet<>(); 825 mInvocationThreadMap = new HashMap<IInvocationContext, InvocationThread>(); 826 // use a ScheduledThreadPoolExecutorTimer as a single-threaded timer. This class 827 // is used instead of a java.util.Timer because it offers advanced shutdown options 828 mCommandTimer = new ScheduledThreadPoolExecutor(1); 829 mRunLatch = new CountDownLatch(1); 830 } 831 832 /** 833 * Starts the scheduler including setting up of logging, init of {@link DeviceManager} etc 834 */ 835 @Override 836 public void start() { 837 synchronized (this) { 838 if (mStarted) { 839 throw new IllegalStateException("scheduler has already been started"); 840 } 841 initLogging(); 842 843 initDeviceManager(); 844 845 mStarted = true; 846 } 847 super.start(); 848 } 849 850 /** 851 * {@inheritDoc} 852 */ 853 @Override 854 public synchronized CommandFileWatcher getCommandFileWatcher() { 855 assertStarted(); 856 if (mCommandFileWatcher == null) { 857 mCommandFileWatcher = new CommandFileWatcher(this); 858 mCommandFileWatcher.start(); 859 } 860 return mCommandFileWatcher; 861 } 862 863 /** 864 * Initialize the device manager, optionally using a global device filter if specified. 865 */ 866 void initDeviceManager() { 867 getDeviceManager().init(); 868 if (getDeviceManager().waitForFirstDeviceAdded(ADB_INIT_TIME_MS)) { 869 // If a first device is added we wait a short extra time to allow more devices to be 870 // discovered. 871 RunUtil.getDefault().sleep(ADB_INIT_TIME_MS); 872 } 873 } 874 875 /** 876 * Factory method for creating a {@link TestInvocation}. 877 * 878 * @return the {@link ITestInvocation} to use 879 */ 880 ITestInvocation createRunInstance() { 881 return new TestInvocation(); 882 } 883 884 /** 885 * Factory method for getting a reference to the {@link IDeviceManager} 886 * 887 * @return the {@link IDeviceManager} to use 888 */ 889 protected IDeviceManager getDeviceManager() { 890 return GlobalConfiguration.getDeviceManagerInstance(); 891 } 892 893 /** 894 * Factory method for getting a reference to the {@link IHostMonitor} 895 * 896 * @return the {@link IHostMonitor} to use 897 */ 898 List<IHostMonitor> getHostMonitor() { 899 return GlobalConfiguration.getHostMonitorInstances(); 900 } 901 902 /** 903 * Factory method for getting a reference to the {@link IConfigurationFactory} 904 * 905 * @return the {@link IConfigurationFactory} to use 906 */ 907 protected IConfigurationFactory getConfigFactory() { 908 return ConfigurationFactory.getInstance(); 909 } 910 911 /** 912 * Fetches a {@link IKeyStoreClient} using the {@link IKeyStoreFactory} 913 * declared in {@link IGlobalConfiguration} or null if none is defined. 914 * @return IKeyStoreClient 915 */ 916 protected IKeyStoreClient getKeyStoreClient() { 917 try { 918 IKeyStoreFactory f = GlobalConfiguration.getInstance().getKeyStoreFactory(); 919 if (f != null) { 920 try { 921 return f.createKeyStoreClient(); 922 } catch (KeyStoreException e) { 923 CLog.e("Failed to create key store client"); 924 CLog.e(e); 925 } 926 } 927 } catch (IllegalStateException e) { 928 CLog.w("Global configuration has not been created, failed to get keystore"); 929 CLog.e(e); 930 } 931 return null; 932 } 933 934 /** 935 * The main execution block of this thread. 936 */ 937 @Override 938 public void run() { 939 assertStarted(); 940 try { 941 IDeviceManager manager = getDeviceManager(); 942 943 startRemoteManager(); 944 945 // Notify other threads that we're running. 946 mRunLatch.countDown(); 947 948 // add a listener that will wake up scheduler when a new avail device is added 949 manager.addDeviceMonitor(new AvailDeviceMonitor()); 950 951 while (!isShutdown()) { 952 // wait until processing is required again 953 mCommandProcessWait.waitAndReset(mPollTime); 954 checkInvocations(); 955 processReadyCommands(manager); 956 postProcessReadyCommands(); 957 } 958 mCommandTimer.shutdown(); 959 // We signal the device manager to stop device recovery threads because it could 960 // potentially create more invocations. 961 manager.terminateDeviceRecovery(); 962 manager.terminateDeviceMonitor(); 963 CLog.i("Waiting for invocation threads to complete"); 964 waitForAllInvocationThreads(); 965 closeRemoteClient(); 966 if (mRemoteManager != null) { 967 mRemoteManager.cancelAndWait(); 968 } 969 exit(manager); 970 cleanUp(); 971 CLog.logAndDisplay(LogLevel.INFO, "All done"); 972 } finally { 973 // Make sure that we don't quit with messages still in the buffers 974 System.err.flush(); 975 System.out.flush(); 976 } 977 } 978 979 /** 980 * Placeholder method within the scheduler main loop, called after {@link 981 * #processReadyCommands(IDeviceManager)}. Default implementation is empty and does not provide 982 * any extra actions. 983 */ 984 protected void postProcessReadyCommands() {} 985 986 void checkInvocations() { 987 CLog.d("Checking invocations..."); 988 final List<InvocationThread> copy; 989 synchronized(this) { 990 copy = new ArrayList<InvocationThread>(mInvocationThreadMap.values()); 991 } 992 for (InvocationThread thread : copy) { 993 thread.checkDeviceBatteryLevel(); 994 } 995 } 996 997 protected void processReadyCommands(IDeviceManager manager) { 998 CLog.d("processReadyCommands..."); 999 Map<ExecutableCommand, IInvocationContext> scheduledCommandMap = new HashMap<>(); 1000 // minimize length of synchronized block by just matching commands with device first, 1001 // then scheduling invocations/adding looping commands back to queue 1002 synchronized (this) { 1003 // sort ready commands by priority, so high priority commands are matched first 1004 Collections.sort(mReadyCommands, new ExecutableCommandComparator()); 1005 Iterator<ExecutableCommand> cmdIter = mReadyCommands.iterator(); 1006 while (cmdIter.hasNext()) { 1007 ExecutableCommand cmd = cmdIter.next(); 1008 IConfiguration config = cmd.getConfiguration(); 1009 IInvocationContext context = new InvocationContext(); 1010 context.setConfigurationDescriptor(config.getConfigurationDescription()); 1011 Map<String, ITestDevice> devices = allocateDevices(config, manager); 1012 if (!devices.isEmpty()) { 1013 cmdIter.remove(); 1014 mExecutingCommands.add(cmd); 1015 context.addAllocatedDevice(devices); 1016 1017 // track command matched with device 1018 scheduledCommandMap.put(cmd, context); 1019 // clean warned list to avoid piling over time. 1020 mUnscheduledWarning.remove(cmd); 1021 } else { 1022 if (!mUnscheduledWarning.contains(cmd)) { 1023 CLog.logAndDisplay(LogLevel.DEBUG, "No available device matching all the " 1024 + "config's requirements for cmd id %d.", 1025 cmd.getCommandTracker().getId()); 1026 // make sure not to record since it may contains password 1027 System.out.println( 1028 String.format( 1029 "The command %s will be rescheduled.", 1030 Arrays.toString(cmd.getCommandTracker().getArgs()))); 1031 mUnscheduledWarning.add(cmd); 1032 } 1033 } 1034 } 1035 } 1036 1037 // now actually execute the commands 1038 for (Map.Entry<ExecutableCommand, IInvocationContext> cmdDeviceEntry : scheduledCommandMap 1039 .entrySet()) { 1040 ExecutableCommand cmd = cmdDeviceEntry.getKey(); 1041 startInvocation(cmdDeviceEntry.getValue(), cmd, 1042 new FreeDeviceHandler(getDeviceManager())); 1043 if (cmd.isLoopMode()) { 1044 addNewExecCommandToQueue(cmd.getCommandTracker()); 1045 } 1046 } 1047 CLog.d("done processReadyCommands..."); 1048 } 1049 1050 /** 1051 * {@inheritDoc} 1052 */ 1053 @Override 1054 public void await() throws InterruptedException { 1055 while (mRunLatch.getCount() > 0) { 1056 mRunLatch.await(); 1057 } 1058 } 1059 1060 private void closeRemoteClient() { 1061 if (mRemoteClient != null) { 1062 try { 1063 mRemoteClient.sendHandoverComplete(); 1064 mRemoteClient.close(); 1065 } catch (RemoteException e) { 1066 CLog.e(e); 1067 } 1068 } 1069 } 1070 1071 private void waitForThread(Thread thread) { 1072 try { 1073 thread.join(); 1074 } catch (InterruptedException e) { 1075 // ignore 1076 waitForThread(thread); 1077 } 1078 } 1079 1080 /** Wait until all invocation threads complete. */ 1081 protected void waitForAllInvocationThreads() { 1082 List<InvocationThread> threadListCopy; 1083 synchronized (this) { 1084 threadListCopy = new ArrayList<InvocationThread>(mInvocationThreadMap.size()); 1085 threadListCopy.addAll(mInvocationThreadMap.values()); 1086 } 1087 for (Thread thread : threadListCopy) { 1088 waitForThread(thread); 1089 } 1090 } 1091 1092 private void exit(IDeviceManager manager) { 1093 if (manager != null) { 1094 manager.terminate(); 1095 } 1096 } 1097 1098 /** 1099 * {@inheritDoc} 1100 */ 1101 @Override 1102 public boolean addCommand(String[] args) throws ConfigurationException { 1103 return addCommand(args, 0); 1104 } 1105 1106 /** 1107 * {@inheritDoc} 1108 */ 1109 @Override 1110 public boolean addCommand(String[] args, long totalExecTime) throws ConfigurationException { 1111 return internalAddCommand(args, totalExecTime, null); 1112 } 1113 1114 private boolean internalAddCommand(String[] args, long totalExecTime, String cmdFilePath) 1115 throws ConfigurationException { 1116 assertStarted(); 1117 IConfiguration config = getConfigFactory().createConfigurationFromArgs(args, null, 1118 getKeyStoreClient()); 1119 if (config.getCommandOptions().isHelpMode()) { 1120 getConfigFactory().printHelpForConfig(args, true, System.out); 1121 } else if (config.getCommandOptions().isFullHelpMode()) { 1122 getConfigFactory().printHelpForConfig(args, false, System.out); 1123 } else if (config.getCommandOptions().isJsonHelpMode()) { 1124 try { 1125 // Convert the JSON usage to a string (with 4 space indentation) and print to stdout 1126 System.out.println(config.getJsonCommandUsage().toString(4)); 1127 } catch (JSONException e) { 1128 CLog.logAndDisplay(LogLevel.ERROR, "Failed to get json command usage: %s", e); 1129 } 1130 } else if (config.getCommandOptions().isDryRunMode()) { 1131 config.validateOptions(); 1132 String cmdLine = QuotationAwareTokenizer.combineTokens(args); 1133 CLog.d("Dry run mode; skipping adding command: %s", cmdLine); 1134 if (config.getCommandOptions().isNoisyDryRunMode()) { 1135 System.out.println(cmdLine.replace("--noisy-dry-run", "")); 1136 System.out.println(""); 1137 } 1138 } else { 1139 config.validateOptions(); 1140 1141 if (config.getCommandOptions().runOnAllDevices()) { 1142 addCommandForAllDevices(totalExecTime, args, cmdFilePath); 1143 } else { 1144 CommandTracker cmdTracker = createCommandTracker(args, cmdFilePath); 1145 cmdTracker.incrementExecTime(totalExecTime); 1146 ExecutableCommand cmdInstance = createExecutableCommand(cmdTracker, config, false); 1147 addExecCommandToQueue(cmdInstance, 0); 1148 } 1149 return true; 1150 } 1151 return false; 1152 } 1153 1154 /** 1155 * {@inheritDoc} 1156 */ 1157 @Override 1158 public void addCommandFile(String cmdFilePath, List<String> extraArgs) 1159 throws ConfigurationException { 1160 // verify we aren't already watching this command file, don't want to add it twice! 1161 File cmdFile = new File(cmdFilePath); 1162 if (mReloadCmdfiles && getCommandFileWatcher().isFileWatched(cmdFile)) { 1163 CLog.logAndDisplay(LogLevel.INFO, 1164 "cmd file %s is already running and being watched for changes. Reloading", 1165 cmdFilePath); 1166 removeCommandsFromFile(cmdFile); 1167 } 1168 internalAddCommandFile(cmdFile, extraArgs); 1169 } 1170 1171 /** 1172 * Adds a command file without verifying if its already being watched 1173 */ 1174 private void internalAddCommandFile(File cmdFile, List<String> extraArgs) 1175 throws ConfigurationException { 1176 try { 1177 CommandFileParser parser = createCommandFileParser(); 1178 1179 List<CommandLine> commands = parser.parseFile(cmdFile); 1180 if (mReloadCmdfiles) { 1181 // note always should re-register for command file, even if already listening, 1182 // since the dependent file list might have changed 1183 getCommandFileWatcher().addCmdFile(cmdFile, extraArgs, parser.getIncludedFiles()); 1184 } 1185 for (CommandLine command : commands) { 1186 command.addAll(extraArgs); 1187 String[] arrayCommand = command.asArray(); 1188 final String prettyCmdLine = QuotationAwareTokenizer.combineTokens(arrayCommand); 1189 CLog.d("Adding command %s", prettyCmdLine); 1190 1191 try { 1192 internalAddCommand(arrayCommand, 0, cmdFile.getAbsolutePath()); 1193 } catch (ConfigurationException e) { 1194 throw new ConfigurationException(String.format( 1195 "Failed to add command '%s': %s", prettyCmdLine, e.getMessage()), e); 1196 } 1197 } 1198 } catch (IOException e) { 1199 throw new ConfigurationException("Failed to read file " + cmdFile.getAbsolutePath(), e); 1200 } 1201 } 1202 1203 /** 1204 * Factory method for creating a {@link CommandFileParser}. 1205 * 1206 * <p>Exposed for unit testing. 1207 */ 1208 CommandFileParser createCommandFileParser() { 1209 return new CommandFileParser(); 1210 } 1211 1212 /** 1213 * Creates a new command for each connected device, and adds each to the queue. 1214 * <p/> 1215 * Note this won't have the desired effect if user has specified other 1216 * conflicting {@link IConfiguration#getDeviceRequirements()}in the command. 1217 */ 1218 private void addCommandForAllDevices(long totalExecTime, String[] args, String cmdFilePath) 1219 throws ConfigurationException { 1220 List<DeviceDescriptor> deviceDescs = getDeviceManager().listAllDevices(); 1221 1222 for (DeviceDescriptor deviceDesc : deviceDescs) { 1223 if (!deviceDesc.isStubDevice()) { 1224 String device = deviceDesc.getSerial(); 1225 String[] argsWithDevice = Arrays.copyOf(args, args.length + 2); 1226 argsWithDevice[argsWithDevice.length - 2] = "-s"; 1227 argsWithDevice[argsWithDevice.length - 1] = device; 1228 CommandTracker cmdTracker = createCommandTracker(argsWithDevice, cmdFilePath); 1229 cmdTracker.incrementExecTime(totalExecTime); 1230 IConfiguration config = getConfigFactory().createConfigurationFromArgs( 1231 cmdTracker.getArgs(), null, getKeyStoreClient()); 1232 CLog.logAndDisplay(LogLevel.INFO, "Scheduling '%s' on '%s'", 1233 cmdTracker.getArgs()[0], device); 1234 config.getDeviceRequirements().setSerial(device); 1235 ExecutableCommand execCmd = createExecutableCommand(cmdTracker, config, false); 1236 addExecCommandToQueue(execCmd, 0); 1237 } 1238 } 1239 } 1240 1241 /** 1242 * Creates a new {@link CommandTracker} with a unique id. 1243 */ 1244 private synchronized CommandTracker createCommandTracker(String[] args, 1245 String commandFilePath) { 1246 mCurrentCommandId++; 1247 CLog.d("Creating command tracker id %d for command args: '%s'", mCurrentCommandId, 1248 ArrayUtil.join(" ", (Object[])args)); 1249 return new CommandTracker(mCurrentCommandId, args, commandFilePath); 1250 } 1251 1252 /** 1253 * Creates a new {@link ExecutableCommand}. 1254 */ 1255 private ExecutableCommand createExecutableCommand(CommandTracker cmdTracker, 1256 IConfiguration config, boolean rescheduled) { 1257 ExecutableCommand cmd = new ExecutableCommand(cmdTracker, config, rescheduled); 1258 CLog.d("creating exec command for id %d", cmdTracker.getId()); 1259 return cmd; 1260 } 1261 1262 /** 1263 * Creates a new {@link ExecutableCommand}, and adds it to queue 1264 * 1265 * @param commandTracker 1266 */ 1267 private void addNewExecCommandToQueue(CommandTracker commandTracker) { 1268 try { 1269 IConfiguration config = getConfigFactory().createConfigurationFromArgs( 1270 commandTracker.getArgs(), null, getKeyStoreClient()); 1271 ExecutableCommand execCmd = createExecutableCommand(commandTracker, config, false); 1272 addExecCommandToQueue(execCmd, config.getCommandOptions().getLoopTime()); 1273 } catch (ConfigurationException e) { 1274 CLog.e(e); 1275 } 1276 } 1277 1278 /** 1279 * Adds executable command instance to queue, with optional delay. 1280 * 1281 * @param cmd the {@link ExecutableCommand} to return to queue 1282 * @param delayTime the time in ms to delay before adding command to queue 1283 * @return <code>true</code> if command will be added to queue, <code>false</code> otherwise 1284 */ 1285 private synchronized boolean addExecCommandToQueue(final ExecutableCommand cmd, 1286 long delayTime) { 1287 if (isShutdown()) { 1288 return false; 1289 } 1290 if (delayTime > 0) { 1291 mSleepingCommands.add(cmd); 1292 // delay before making command active 1293 Runnable delayCommand = new Runnable() { 1294 @Override 1295 public void run() { 1296 synchronized (CommandScheduler.this) { 1297 if (mSleepingCommands.remove(cmd)) { 1298 mReadyCommands.add(cmd); 1299 mCommandProcessWait.signalEventReceived(); 1300 } 1301 } 1302 } 1303 }; 1304 mCommandTimer.schedule(delayCommand, delayTime, TimeUnit.MILLISECONDS); 1305 } else { 1306 mReadyCommands.add(cmd); 1307 mCommandProcessWait.signalEventReceived(); 1308 } 1309 return true; 1310 } 1311 1312 /** 1313 * Helper method to return an array of {@link String} elements as a readable {@link String} 1314 * 1315 * @param args the {@link String}[] to use 1316 * @return a display friendly {@link String} of args contents 1317 */ 1318 private String getArgString(String[] args) { 1319 return ArrayUtil.join(" ", (Object[])args); 1320 } 1321 1322 /** 1323 * {@inheritDoc} 1324 */ 1325 @Override 1326 public void execCommand(IScheduledInvocationListener listener, String[] args) 1327 throws ConfigurationException, NoDeviceException { 1328 assertStarted(); 1329 IDeviceManager manager = getDeviceManager(); 1330 CommandTracker cmdTracker = createCommandTracker(args, null); 1331 IConfiguration config = getConfigFactory().createConfigurationFromArgs( 1332 cmdTracker.getArgs(), null, getKeyStoreClient()); 1333 config.validateOptions(); 1334 1335 ExecutableCommand execCmd = createExecutableCommand(cmdTracker, config, false); 1336 IInvocationContext context = new InvocationContext(); 1337 context.setConfigurationDescriptor(config.getConfigurationDescription()); 1338 Map<String, ITestDevice> devices = allocateDevices(config, manager); 1339 if (!devices.isEmpty()) { 1340 context.addAllocatedDevice(devices); 1341 synchronized (this) { 1342 mExecutingCommands.add(execCmd); 1343 } 1344 CLog.d("Executing '%s' on '%s'", cmdTracker.getArgs()[0], devices); 1345 startInvocation(context, execCmd, listener, new FreeDeviceHandler(manager)); 1346 } else { 1347 throw new NoDeviceException( 1348 "no devices is available for command: " + Arrays.asList(args)); 1349 } 1350 } 1351 1352 /** 1353 * Allocate devices for a config. 1354 * @param config a {@link IConfiguration} has device requirements. 1355 * @param manager a {@link IDeviceManager} 1356 * @return allocated devices 1357 */ 1358 Map<String, ITestDevice> allocateDevices(IConfiguration config, IDeviceManager manager) { 1359 Map<String, ITestDevice> devices = new LinkedHashMap<String, ITestDevice>(); 1360 ITestDevice device = null; 1361 synchronized(this) { 1362 if (!config.getDeviceConfig().isEmpty()) { 1363 for (IDeviceConfiguration deviceConfig : config.getDeviceConfig()) { 1364 device = manager.allocateDevice(deviceConfig.getDeviceRequirements()); 1365 if (device != null) { 1366 devices.put(deviceConfig.getDeviceName(), device); 1367 } else { 1368 // If one of the several device cannot be allocated, we de-allocate 1369 // all the previous one. 1370 for (ITestDevice allocatedDevice : devices.values()) { 1371 FreeDeviceState deviceState = FreeDeviceState.AVAILABLE; 1372 if (allocatedDevice.getIDevice() instanceof StubDevice) { 1373 deviceState = FreeDeviceState.AVAILABLE; 1374 } else if (!TestDeviceState.ONLINE.equals( 1375 allocatedDevice.getDeviceState())) { 1376 // If the device is offline at the end of the test 1377 deviceState = FreeDeviceState.UNAVAILABLE; 1378 } 1379 manager.freeDevice(allocatedDevice, deviceState); 1380 } 1381 // Could not allocate all devices 1382 devices.clear(); 1383 break; 1384 } 1385 } 1386 } 1387 return devices; 1388 } 1389 } 1390 1391 /** 1392 * {@inheritDoc} 1393 */ 1394 @Override 1395 public void execCommand(IScheduledInvocationListener listener, ITestDevice device, 1396 String[] args) throws ConfigurationException { 1397 // TODO: add support for execCommand multi-device allocation 1398 assertStarted(); 1399 CommandTracker cmdTracker = createCommandTracker(args, null); 1400 IConfiguration config = getConfigFactory().createConfigurationFromArgs( 1401 cmdTracker.getArgs(), null, getKeyStoreClient()); 1402 config.validateOptions(); 1403 CLog.i("Executing '%s' on '%s'", cmdTracker.getArgs()[0], device.getSerialNumber()); 1404 ExecutableCommand execCmd = createExecutableCommand(cmdTracker, config, false); 1405 if (config.getDeviceConfig().size() > 1) { 1406 throw new RuntimeException("execCommand assume single device invocation."); 1407 } 1408 1409 synchronized(this) { 1410 mExecutingCommands.add(execCmd); 1411 } 1412 IInvocationContext context = new InvocationContext(); 1413 context.setConfigurationDescriptor(config.getConfigurationDescription()); 1414 context.addAllocatedDevice(config.getDeviceConfig().get(0).getDeviceName(), device); 1415 startInvocation(context, execCmd, listener); 1416 } 1417 1418 /** Optional initialization step before test invocation starts */ 1419 protected void initInvocation() {} 1420 1421 /** 1422 * Spawns off thread to run invocation for given device. 1423 * 1424 * @param context the {@link IInvocationContext} 1425 * @param cmd the {@link ExecutableCommand} to execute 1426 * @param listeners the {@link 1427 * com.android.tradefed.command.ICommandScheduler.IScheduledInvocationListener}s to invoke 1428 * when complete 1429 */ 1430 private void startInvocation( 1431 IInvocationContext context, 1432 ExecutableCommand cmd, 1433 IScheduledInvocationListener... listeners) { 1434 initInvocation(); 1435 1436 // Check if device is not used in another invocation. 1437 throwIfDeviceInInvocationThread(context.getDevices()); 1438 1439 CLog.d("starting invocation for command id %d", cmd.getCommandTracker().getId()); 1440 // Name invocation with first device serial 1441 final String invocationName = String.format("Invocation-%s", 1442 context.getSerials().get(0)); 1443 InvocationThread invocationThread = new InvocationThread(invocationName, context, cmd, 1444 listeners); 1445 logInvocationStartedEvent(cmd.getCommandTracker(), context); 1446 invocationThread.start(); 1447 addInvocationThread(invocationThread); 1448 } 1449 1450 /** Helper to log an invocation started event. */ 1451 private void logInvocationStartedEvent(CommandTracker tracker, IInvocationContext context) { 1452 Map<String, String> args = new HashMap<>(); 1453 args.put("id", Integer.toString(tracker.getId())); 1454 int i = 0; 1455 for (String serial : context.getSerials()) { 1456 args.put("serial" + i, serial); 1457 i++; 1458 } 1459 args.put("args", ArrayUtil.join(" ", Arrays.asList(tracker.getArgs()))); 1460 logEvent(EventType.INVOCATION_START, args); 1461 } 1462 1463 /** Removes a {@link InvocationThread} from the active list. */ 1464 private synchronized void removeInvocationThread(InvocationThread invThread) { 1465 mInvocationThreadMap.remove(invThread.getInvocationContext()); 1466 } 1467 1468 private synchronized void throwIfDeviceInInvocationThread(List<ITestDevice> devices) { 1469 for (ITestDevice device : devices) { 1470 for (IInvocationContext context : mInvocationThreadMap.keySet()) { 1471 if (context.getDevices().contains(device)) { 1472 throw new IllegalStateException( 1473 String.format( 1474 "Attempting invocation on device %s when one is already " 1475 + "running", 1476 device.getSerialNumber())); 1477 } 1478 } 1479 } 1480 } 1481 1482 /** 1483 * Adds a {@link InvocationThread} to the active list. 1484 */ 1485 private synchronized void addInvocationThread(InvocationThread invThread) { 1486 mInvocationThreadMap.put(invThread.getInvocationContext(), invThread); 1487 } 1488 1489 protected synchronized boolean isShutdown() { 1490 return mCommandTimer.isShutdown() || (mShutdownOnEmpty && getAllCommandsSize() == 0); 1491 } 1492 1493 protected synchronized boolean isShuttingDown() { 1494 return mCommandTimer.isShutdown() || mShutdownOnEmpty; 1495 } 1496 1497 /** 1498 * {@inheritDoc} 1499 */ 1500 @Override 1501 public synchronized void shutdown() { 1502 assertStarted(); 1503 if (!isShuttingDown()) { 1504 CLog.d("initiating shutdown"); 1505 removeAllCommands(); 1506 if (mCommandFileWatcher != null) { 1507 mCommandFileWatcher.cancel(); 1508 } 1509 if (mCommandTimer != null) { 1510 mCommandTimer.shutdownNow(); 1511 } 1512 mCommandProcessWait.signalEventReceived(); 1513 } 1514 } 1515 1516 /** 1517 * {@inheritDoc} 1518 */ 1519 @Override 1520 public synchronized void shutdownOnEmpty() { 1521 assertStarted(); 1522 if (!isShuttingDown()) { 1523 CLog.d("initiating shutdown on empty"); 1524 mShutdownOnEmpty = true; 1525 mCommandProcessWait.signalEventReceived(); 1526 } 1527 } 1528 1529 /** 1530 * {@inheritDoc} 1531 */ 1532 @Override 1533 public synchronized void removeAllCommands() { 1534 assertStarted(); 1535 CLog.d("removing all commands"); 1536 if (mReloadCmdfiles) { 1537 getCommandFileWatcher().removeAllFiles(); 1538 } 1539 if (mCommandTimer != null) { 1540 for (Runnable task : mCommandTimer.getQueue()) { 1541 mCommandTimer.remove(task); 1542 } 1543 } 1544 mReadyCommands.clear(); 1545 mSleepingCommands.clear(); 1546 if (isShuttingDown()) { 1547 mCommandProcessWait.signalEventReceived(); 1548 } 1549 } 1550 1551 /** 1552 * Remove commands originally added via the given command file 1553 * @param cmdFile 1554 */ 1555 private synchronized void removeCommandsFromFile(File cmdFile) { 1556 Iterator<ExecutableCommand> cmdIter = mReadyCommands.iterator(); 1557 while (cmdIter.hasNext()) { 1558 ExecutableCommand cmd = cmdIter.next(); 1559 String path = cmd.getCommandFilePath(); 1560 if (path != null && 1561 path.equals(cmdFile.getAbsolutePath())) { 1562 cmdIter.remove(); 1563 } 1564 } 1565 cmdIter = mSleepingCommands.iterator(); 1566 while (cmdIter.hasNext()) { 1567 ExecutableCommand cmd = cmdIter.next(); 1568 String path = cmd.getCommandFilePath(); 1569 if (path != null && 1570 path.equals(cmdFile.getAbsolutePath())) { 1571 cmdIter.remove(); 1572 } 1573 } 1574 if (isShuttingDown()) { 1575 mCommandProcessWait.signalEventReceived(); 1576 } 1577 } 1578 1579 /** 1580 * {@inheritDoc} 1581 */ 1582 @Override 1583 public synchronized boolean handoverShutdown(int handoverPort) { 1584 assertStarted(); 1585 if (mRemoteClient != null || mPerformingHandover) { 1586 CLog.e("A handover has already been initiated"); 1587 return false; 1588 } 1589 mPerformingHandover = true; 1590 try { 1591 mRemoteClient = RemoteClient.connect(handoverPort); 1592 CLog.d("Connected to remote manager at %d", handoverPort); 1593 handoverDevices(mRemoteClient); 1594 CLog.i("Done with device handover."); 1595 mRemoteClient.sendHandoverInitComplete(); 1596 shutdown(); 1597 return true; 1598 } catch (RemoteException e) { 1599 CLog.e(e); 1600 // TODO: reset state and recover 1601 } 1602 return false; 1603 } 1604 1605 /** Informs remote manager of the physical devices we are still using. */ 1606 private void handoverDevices(IRemoteClient client) throws RemoteException { 1607 for (DeviceDescriptor deviceDesc : getDeviceManager().listAllDevices()) { 1608 if (DeviceAllocationState.Allocated.equals(deviceDesc.getState()) 1609 && !deviceDesc.isStubDevice()) { 1610 client.sendAllocateDevice(deviceDesc.getSerial()); 1611 CLog.d("Sent filter device %s command", deviceDesc.getSerial()); 1612 } 1613 } 1614 } 1615 1616 /** 1617 * @return the list of active {@link CommandTracker}. 'Active' here means all commands added 1618 * to the scheduler that are either executing, waiting for a device to execute on, or looping. 1619 */ 1620 List<CommandTracker> getCommandTrackers() { 1621 List<ExecutableCommandState> cmdCopy = getAllCommands(); 1622 Set<CommandTracker> cmdTrackers = new LinkedHashSet<CommandTracker>(); 1623 for (ExecutableCommandState cmdState : cmdCopy) { 1624 cmdTrackers.add(cmdState.cmd.getCommandTracker()); 1625 } 1626 return new ArrayList<CommandTracker>(cmdTrackers); 1627 } 1628 1629 /** 1630 * Inform the remote listener of the freed device. Has no effect if there is no remote listener. 1631 * 1632 * @param device the freed {@link ITestDevice} 1633 */ 1634 private void remoteFreeDevice(ITestDevice device) { 1635 // TODO: send freed device state too 1636 if (mPerformingHandover && mRemoteClient != null) { 1637 try { 1638 mRemoteClient.sendFreeDevice(device.getSerialNumber()); 1639 } catch (RemoteException e) { 1640 CLog.e("Failed to send unfilter device %s to remote manager", 1641 device.getSerialNumber()); 1642 CLog.e(e); 1643 // TODO: send handover failed op? 1644 } 1645 } 1646 } 1647 1648 /** 1649 * {@inheritDoc} 1650 */ 1651 @Override 1652 public synchronized void shutdownHard() { 1653 shutdown(); 1654 1655 CLog.logAndDisplay(LogLevel.WARN, "Stopping invocation threads..."); 1656 for (InvocationThread thread : mInvocationThreadMap.values()) { 1657 thread.disableReporters(); 1658 thread.stopInvocation("TF is shutting down"); 1659 } 1660 getDeviceManager().terminateHard(); 1661 } 1662 1663 /** 1664 * Initializes the ddmlib log. 1665 * 1666 * <p>Exposed so unit tests can mock. 1667 */ 1668 @SuppressWarnings("deprecation") 1669 protected void initLogging() { 1670 DdmPreferences.setLogLevel(LogLevel.VERBOSE.getStringValue()); 1671 Log.setLogOutput(LogRegistry.getLogRegistry()); 1672 } 1673 1674 /** 1675 * Closes the logs and does any other necessary cleanup before we quit. 1676 * 1677 * <p>Exposed so unit tests can mock. 1678 */ 1679 protected void cleanUp() { 1680 LogRegistry.getLogRegistry().closeAndRemoveAllLogs(); 1681 } 1682 1683 /** log an event to the registry history logger. */ 1684 @VisibleForTesting 1685 void logEvent(EventType event, Map<String, String> args) { 1686 LogRegistry.getLogRegistry().logEvent(LogLevel.DEBUG, event, args); 1687 } 1688 1689 /** {@inheritDoc} */ 1690 @Override 1691 public void displayInvocationsInfo(PrintWriter printWriter) { 1692 assertStarted(); 1693 if (mInvocationThreadMap == null || mInvocationThreadMap.size() == 0) { 1694 return; 1695 } 1696 List<InvocationThread> copy = new ArrayList<InvocationThread>(); 1697 synchronized(this) { 1698 copy.addAll(mInvocationThreadMap.values()); 1699 } 1700 ArrayList<List<String>> displayRows = new ArrayList<List<String>>(); 1701 displayRows.add(Arrays.asList("Command Id", "Exec Time", "Device", "State")); 1702 long curTime = System.currentTimeMillis(); 1703 1704 for (InvocationThread invThread : copy) { 1705 displayRows.add(Arrays.asList( 1706 Integer.toString(invThread.mCmd.getCommandTracker().getId()), 1707 getTimeString(curTime - invThread.getStartTime()), 1708 invThread.getInvocationContext().getSerials().toString(), 1709 invThread.getInvocation().toString())); 1710 } 1711 new TableFormatter().displayTable(displayRows, printWriter); 1712 } 1713 1714 private String getTimeString(long elapsedTime) { 1715 long duration = elapsedTime / 1000; 1716 long secs = duration % 60; 1717 long mins = (duration / 60) % 60; 1718 long hrs = duration / (60 * 60); 1719 String time = "unknown"; 1720 if (hrs > 0) { 1721 time = String.format("%dh:%02d:%02d", hrs, mins, secs); 1722 } else { 1723 time = String.format("%dm:%02d", mins, secs); 1724 } 1725 return time; 1726 } 1727 1728 /** 1729 * {@inheritDoc} 1730 */ 1731 @Override 1732 public synchronized boolean stopInvocation(ITestInvocation invocation) { 1733 for (InvocationThread thread : mInvocationThreadMap.values()) { 1734 if (thread.getInvocation() == invocation) { 1735 thread.interrupt(); 1736 return true; 1737 } 1738 } 1739 return false; 1740 } 1741 1742 /** 1743 * {@inheritDoc} 1744 */ 1745 @Override 1746 public synchronized boolean stopInvocation(int invocationId) { 1747 // TODO: make invocationID part of InvocationContext 1748 for (InvocationThread thread : mInvocationThreadMap.values()) { 1749 if (thread.mCmd.getCommandTracker().mId == invocationId) { 1750 thread.stopInvocation("User requested stopping invocation " + invocationId); 1751 return true; 1752 } 1753 } 1754 CLog.w("No invocation found matching the id: %s", invocationId); 1755 return false; 1756 } 1757 1758 /** 1759 * {@inheritDoc} 1760 */ 1761 @Override 1762 public synchronized String getInvocationInfo(int invocationId) { 1763 for (InvocationThread thread : mInvocationThreadMap.values()) { 1764 if (thread.mCmd.getCommandTracker().mId == invocationId) { 1765 String info = Arrays.toString(thread.mCmd.getCommandTracker().getArgs()); 1766 return info; 1767 } 1768 } 1769 CLog.w("No invocation found matching the id: %s", invocationId); 1770 return null; 1771 } 1772 1773 /** 1774 * {@inheritDoc} 1775 */ 1776 @Override 1777 public void displayCommandsInfo(PrintWriter printWriter, String regex) { 1778 assertStarted(); 1779 Pattern regexPattern = null; 1780 if (regex != null) { 1781 regexPattern = Pattern.compile(regex); 1782 } 1783 1784 List<CommandTracker> cmds = getCommandTrackers(); 1785 Collections.sort(cmds, new CommandTrackerIdComparator()); 1786 for (CommandTracker cmd : cmds) { 1787 String argString = getArgString(cmd.getArgs()); 1788 if (regexPattern == null || regexPattern.matcher(argString).find()) { 1789 String cmdDesc = String.format("Command %d: [%s] %s", cmd.getId(), 1790 getTimeString(cmd.getTotalExecTime()), argString); 1791 printWriter.println(cmdDesc); 1792 } 1793 } 1794 } 1795 1796 /** 1797 * {@inheritDoc} 1798 */ 1799 @Override 1800 public void dumpCommandsXml(PrintWriter printWriter, String regex) { 1801 assertStarted(); 1802 Pattern regexPattern = null; 1803 if (regex != null) { 1804 regexPattern = Pattern.compile(regex); 1805 } 1806 1807 List<ExecutableCommandState> cmdCopy = getAllCommands(); 1808 for (ExecutableCommandState cmd : cmdCopy) { 1809 String[] args = cmd.cmd.getCommandTracker().getArgs(); 1810 String argString = getArgString(args); 1811 if (regexPattern == null || regexPattern.matcher(argString).find()) { 1812 // Use the config name prefixed by config__ for the file path 1813 String xmlPrefix = "config__" + args[0].replace("/", "__") + "__"; 1814 1815 // If the command line contains --template:map test config, use that config for the 1816 // file path. This is because in the template system, many tests will have same 1817 // base config and the distinguishing feature is the test included. 1818 boolean templateIncludeFound = false; 1819 boolean testFound = false; 1820 for (String arg : args) { 1821 if ("--template:map".equals(arg)) { 1822 templateIncludeFound = true; 1823 } else if (templateIncludeFound && "test".equals(arg)) { 1824 testFound = true; 1825 } else { 1826 if (templateIncludeFound && testFound) { 1827 xmlPrefix = "config__" + arg.replace("/", "__") + "__"; 1828 } 1829 templateIncludeFound = false; 1830 testFound = false; 1831 } 1832 } 1833 1834 try { 1835 File xmlFile = FileUtil.createTempFile(xmlPrefix, ".xml"); 1836 PrintWriter writer = new PrintWriter(xmlFile); 1837 cmd.cmd.getConfiguration().dumpXml(writer); 1838 printWriter.println(String.format("Saved command dump to %s", 1839 xmlFile.getAbsolutePath())); 1840 } catch (IOException e) { 1841 // Log exception and continue 1842 CLog.e("Could not dump config xml"); 1843 CLog.e(e); 1844 } 1845 } 1846 } 1847 } 1848 1849 /** 1850 * {@inheritDoc} 1851 */ 1852 @Override 1853 public void displayCommandQueue(PrintWriter printWriter) { 1854 assertStarted(); 1855 List<ExecutableCommandState> cmdCopy = getAllCommands(); 1856 if (cmdCopy.size() == 0) { 1857 return; 1858 } 1859 ArrayList<List<String>> displayRows = new ArrayList<List<String>>(); 1860 displayRows.add(Arrays.asList("Id", "Config", "Created", "Exec time", "State", "Sleep time", 1861 "Rescheduled", "Loop")); 1862 long curTime = System.currentTimeMillis(); 1863 for (ExecutableCommandState cmd : cmdCopy) { 1864 dumpCommand(curTime, cmd, displayRows); 1865 } 1866 new TableFormatter().displayTable(displayRows, printWriter); 1867 } 1868 1869 private void dumpCommand(long curTime, ExecutableCommandState cmdAndState, 1870 ArrayList<List<String>> displayRows) { 1871 ExecutableCommand cmd = cmdAndState.cmd; 1872 String sleepTime = cmd.getSleepTime() == null ? "N/A" : getTimeString(cmd.getSleepTime()); 1873 displayRows.add(Arrays.asList( 1874 Integer.toString(cmd.getCommandTracker().getId()), 1875 cmd.getCommandTracker().getArgs()[0], 1876 getTimeString(curTime - cmd.getCreationTime()), 1877 getTimeString(cmd.mCmdTracker.getTotalExecTime()), 1878 cmdAndState.state.getDisplayName(), 1879 sleepTime, 1880 Boolean.toString(cmd.isRescheduled()), 1881 Boolean.toString(cmd.isLoopMode()))); 1882 } 1883 1884 /** 1885 * Starts remote manager to listen to remote commands. 1886 * 1887 * <p>TODO: refactor to throw exception on failure 1888 */ 1889 private void startRemoteManager() { 1890 if (mRemoteManager != null && !mRemoteManager.isCanceled()) { 1891 String error = String.format("A remote manager is already running at port %d", 1892 mRemoteManager.getPort()); 1893 throw new IllegalStateException(error); 1894 } 1895 mRemoteManager = new RemoteManager(getDeviceManager(), this); 1896 // Read the args that were set by the global config. 1897 boolean startRmtMgrOnBoot = mRemoteManager.getStartRemoteMgrOnBoot(); 1898 int defaultRmtMgrPort = mRemoteManager.getRemoteManagerPort(); 1899 boolean autoHandover = mRemoteManager.getAutoHandover(); 1900 1901 if (!startRmtMgrOnBoot) { 1902 mRemoteManager = null; 1903 return; 1904 } 1905 if (mRemoteManager.connect()) { 1906 mRemoteManager.start(); 1907 CLog.logAndDisplay(LogLevel.INFO, "Started remote manager at port %d", 1908 mRemoteManager.getPort()); 1909 return; 1910 } 1911 CLog.logAndDisplay(LogLevel.INFO, "Failed to start remote manager at port %d", 1912 defaultRmtMgrPort); 1913 if (!autoHandover) { 1914 if (mRemoteManager.connectAnyPort()) { 1915 mRemoteManager.start(); 1916 CLog.logAndDisplay(LogLevel.INFO, 1917 "Started remote manager at port %d with no handover", 1918 mRemoteManager.getPort()); 1919 return; 1920 } else { 1921 CLog.logAndDisplay(LogLevel.ERROR, "Failed to auto start a remote manager on boot."); 1922 return; 1923 } 1924 } 1925 try { 1926 CLog.logAndDisplay(LogLevel.INFO, "Initiating handover with remote TF instance!"); 1927 mHandoverHandshake.reset(); 1928 initiateHandover(defaultRmtMgrPort); 1929 waitForHandoverHandshake(); 1930 CLog.logAndDisplay(LogLevel.INFO, "Handover initiation complete."); 1931 } catch (RemoteException e) { 1932 CLog.e(e); 1933 } 1934 } 1935 1936 private void waitForHandoverHandshake() { 1937 // block and wait to receive all the commands and 'device still in use' messages from remote 1938 mHandoverHandshake.waitForEvent(MAX_HANDOVER_INIT_TIME); 1939 // TODO: throw exception if not received 1940 } 1941 1942 /** 1943 * Helper object for allowing multiple threads to synchronize on an event. 1944 * 1945 * <p>Basically a modest wrapper around Object's wait and notify methods, that supports 1946 * remembering if a notify call was made. 1947 */ 1948 private static class WaitObj { 1949 boolean mEventReceived = false; 1950 1951 /** 1952 * Wait for signal for a max of given ms. 1953 * @return true if event received before time elapsed, false otherwise 1954 */ 1955 public synchronized boolean waitForEvent(long maxWaitTime) { 1956 if (maxWaitTime == 0) { 1957 return waitForEvent(); 1958 } 1959 long startTime = System.currentTimeMillis(); 1960 long remainingTime = maxWaitTime; 1961 while (!mEventReceived && remainingTime > 0) { 1962 try { 1963 wait(remainingTime); 1964 } catch (InterruptedException e) { 1965 CLog.w("interrupted"); 1966 } 1967 remainingTime = maxWaitTime - (System.currentTimeMillis() - startTime); 1968 } 1969 return mEventReceived; 1970 } 1971 1972 /** 1973 * Wait for signal indefinitely or until interrupted. 1974 * @return true if event received, false otherwise 1975 */ 1976 public synchronized boolean waitForEvent() { 1977 if (!mEventReceived) { 1978 try { 1979 wait(); 1980 } catch (InterruptedException e) { 1981 CLog.w("interrupted"); 1982 } 1983 } 1984 return mEventReceived; 1985 } 1986 1987 /** 1988 * Reset the event received flag. 1989 */ 1990 public synchronized void reset() { 1991 mEventReceived = false; 1992 } 1993 1994 /** 1995 * Wait for given ms for event to be received, and reset state back to 'no event received' 1996 * upon completion. 1997 */ 1998 public synchronized void waitAndReset(long maxWaitTime) { 1999 waitForEvent(maxWaitTime); 2000 reset(); 2001 } 2002 2003 /** 2004 * Notify listeners that event was received. 2005 */ 2006 public synchronized void signalEventReceived() { 2007 mEventReceived = true; 2008 notifyAll(); 2009 } 2010 } 2011 2012 @Override 2013 public void handoverInitiationComplete() { 2014 mHandoverHandshake.signalEventReceived(); 2015 } 2016 2017 @Override 2018 public void completeHandover() { 2019 CLog.logAndDisplay(LogLevel.INFO, "Completing handover."); 2020 if (mRemoteClient != null) { 2021 mRemoteClient.close(); 2022 mRemoteClient = null; 2023 } else { 2024 CLog.e("invalid state: received handover complete when remote client is null"); 2025 } 2026 2027 if (mRemoteManager != null) { 2028 mRemoteManager.cancelAndWait(); 2029 mRemoteManager = null; 2030 } else { 2031 CLog.e("invalid state: received handover complete when remote manager is null"); 2032 } 2033 2034 // Start a new remote manager and attempt to capture the original default port. 2035 mRemoteManager = new RemoteManager(getDeviceManager(), this); 2036 boolean success = false; 2037 for (int i=0; i < 10 && !success; i++) { 2038 try { 2039 sleep(2000); 2040 } catch (InterruptedException e) { 2041 CLog.e(e); 2042 return; 2043 } 2044 success = mRemoteManager.connect(); 2045 } 2046 if (!success) { 2047 CLog.e("failed to connect to default remote manager port"); 2048 return; 2049 } 2050 2051 mRemoteManager.start(); 2052 CLog.logAndDisplay(LogLevel.INFO, 2053 "Successfully started remote manager after handover on port %d", 2054 mRemoteManager.getPort()); 2055 } 2056 2057 private void initiateHandover(int port) throws RemoteException { 2058 mRemoteClient = RemoteClient.connect(port); 2059 CLog.i("Connecting local client with existing remote TF at %d - Attempting takeover", port); 2060 // Start up a temporary local remote manager for handover. 2061 if (mRemoteManager.connectAnyPort()) { 2062 mRemoteManager.start(); 2063 CLog.logAndDisplay(LogLevel.INFO, 2064 "Started local tmp remote manager for handover at port %d", 2065 mRemoteManager.getPort()); 2066 mRemoteClient.sendStartHandover(mRemoteManager.getPort()); 2067 } 2068 } 2069 2070 private synchronized void assertStarted() { 2071 if(!mStarted) { 2072 throw new IllegalStateException("start() must be called before this method"); 2073 } 2074 } 2075 2076 @Override 2077 public void notifyFileChanged(File cmdFile, List<String> extraArgs) { 2078 CLog.logAndDisplay(LogLevel.INFO, "Detected update for cmdfile '%s'. Reloading", 2079 cmdFile.getAbsolutePath()); 2080 removeCommandsFromFile(cmdFile); 2081 try { 2082 // just add the file again, including re-registering for command file watcher 2083 // don't want to remove the registration here in case file fails to load 2084 internalAddCommandFile(cmdFile, extraArgs); 2085 } catch (ConfigurationException e) { 2086 CLog.wtf(String.format("Failed to automatically reload cmdfile %s", 2087 cmdFile.getAbsolutePath()), e); 2088 } 2089 } 2090 2091 /** 2092 * Set the command file reloading flag. 2093 */ 2094 @VisibleForTesting 2095 void setCommandFileReload(boolean b) { 2096 mReloadCmdfiles = b; 2097 } 2098 2099 synchronized int getAllCommandsSize() { 2100 return mReadyCommands.size() + mExecutingCommands.size() + mSleepingCommands.size(); 2101 } 2102 2103 synchronized List<ExecutableCommandState> getAllCommands() { 2104 List<ExecutableCommandState> cmds = new ArrayList<>(getAllCommandsSize()); 2105 for (ExecutableCommand cmd : mExecutingCommands) { 2106 cmds.add(new ExecutableCommandState(cmd, CommandState.EXECUTING)); 2107 } 2108 for (ExecutableCommand cmd : mReadyCommands) { 2109 cmds.add(new ExecutableCommandState(cmd, CommandState.WAITING_FOR_DEVICE)); 2110 } 2111 for (ExecutableCommand cmd : mSleepingCommands) { 2112 cmds.add(new ExecutableCommandState(cmd, CommandState.SLEEPING)); 2113 } 2114 return cmds; 2115 } 2116 2117 @Override 2118 public boolean shouldShutdownOnCmdfileError() { 2119 return mShutdownOnCmdfileError; 2120 } 2121 2122 public long getShutdownTimeout() { 2123 return mShutdownTimeout; 2124 } 2125 2126 @Override 2127 public ExitCode getLastInvocationExitCode() { 2128 return mLastInvocationExitCode; 2129 } 2130 2131 @Override 2132 public Throwable getLastInvocationThrowable() { 2133 return mLastInvocationThrowable; 2134 } 2135 2136 @Override 2137 public void setLastInvocationExitCode(ExitCode code, Throwable throwable) { 2138 mLastInvocationExitCode = code; 2139 mLastInvocationThrowable = throwable; 2140 } 2141 } 2142