1 /* 2 * Copyright (C) 2017 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.invoker; 17 18 import com.android.ddmlib.IDevice; 19 import com.android.ddmlib.Log.LogLevel; 20 import com.android.tradefed.build.BuildInfo; 21 import com.android.tradefed.build.BuildInfoKey.BuildInfoFileKey; 22 import com.android.tradefed.build.BuildRetrievalError; 23 import com.android.tradefed.build.IBuildInfo; 24 import com.android.tradefed.build.IBuildInfo.BuildInfoProperties; 25 import com.android.tradefed.build.IBuildProvider; 26 import com.android.tradefed.build.IDeviceBuildInfo; 27 import com.android.tradefed.build.IDeviceBuildProvider; 28 import com.android.tradefed.config.GlobalConfiguration; 29 import com.android.tradefed.config.IConfiguration; 30 import com.android.tradefed.config.IDeviceConfiguration; 31 import com.android.tradefed.device.DeviceNotAvailableException; 32 import com.android.tradefed.device.ITestDevice; 33 import com.android.tradefed.device.StubDevice; 34 import com.android.tradefed.device.metric.AutoLogCollector; 35 import com.android.tradefed.device.metric.CollectorHelper; 36 import com.android.tradefed.device.metric.IMetricCollector; 37 import com.android.tradefed.device.metric.IMetricCollectorReceiver; 38 import com.android.tradefed.invoker.ExecutionFiles.FilesKey; 39 import com.android.tradefed.invoker.TestInvocation.Stage; 40 import com.android.tradefed.invoker.logger.InvocationMetricLogger; 41 import com.android.tradefed.invoker.logger.InvocationMetricLogger.InvocationMetricKey; 42 import com.android.tradefed.invoker.logger.TfObjectTracker; 43 import com.android.tradefed.invoker.shard.IShardHelper; 44 import com.android.tradefed.invoker.shard.TestsPoolPoller; 45 import com.android.tradefed.log.ITestLogger; 46 import com.android.tradefed.log.LogUtil.CLog; 47 import com.android.tradefed.result.ByteArrayInputStreamSource; 48 import com.android.tradefed.result.ITestInvocationListener; 49 import com.android.tradefed.result.ITestLoggerReceiver; 50 import com.android.tradefed.result.InputStreamSource; 51 import com.android.tradefed.result.LogDataType; 52 import com.android.tradefed.retry.IRetryDecision; 53 import com.android.tradefed.retry.RetryLogSaverResultForwarder; 54 import com.android.tradefed.retry.RetryStatistics; 55 import com.android.tradefed.retry.RetryStrategy; 56 import com.android.tradefed.suite.checker.ISystemStatusCheckerReceiver; 57 import com.android.tradefed.targetprep.BuildError; 58 import com.android.tradefed.targetprep.IHostCleaner; 59 import com.android.tradefed.targetprep.ITargetPreparer; 60 import com.android.tradefed.targetprep.TargetSetupError; 61 import com.android.tradefed.targetprep.multi.IMultiTargetPreparer; 62 import com.android.tradefed.testtype.IBuildReceiver; 63 import com.android.tradefed.testtype.IDeviceTest; 64 import com.android.tradefed.testtype.IInvocationContextReceiver; 65 import com.android.tradefed.testtype.IRemoteTest; 66 import com.android.tradefed.testtype.ITestFilterReceiver; 67 import com.android.tradefed.testtype.retry.IAutoRetriableTest; 68 import com.android.tradefed.testtype.suite.ITestSuite; 69 import com.android.tradefed.testtype.suite.ModuleListener; 70 import com.android.tradefed.util.CommandResult; 71 import com.android.tradefed.util.CommandStatus; 72 import com.android.tradefed.util.FileUtil; 73 import com.android.tradefed.util.PrettyPrintDelimiter; 74 import com.android.tradefed.util.RunUtil; 75 import com.android.tradefed.util.SystemUtil; 76 import com.android.tradefed.util.SystemUtil.EnvVariable; 77 import com.android.tradefed.util.TimeUtil; 78 import com.android.tradefed.util.executor.ParallelDeviceExecutor; 79 80 import com.google.common.annotations.VisibleForTesting; 81 import com.google.common.base.Strings; 82 83 import java.io.File; 84 import java.io.IOException; 85 import java.util.ArrayList; 86 import java.util.HashSet; 87 import java.util.List; 88 import java.util.ListIterator; 89 import java.util.Map; 90 import java.util.Set; 91 import java.util.concurrent.Callable; 92 import java.util.concurrent.ConcurrentHashMap; 93 import java.util.concurrent.TimeUnit; 94 95 /** 96 * Class that describes all the invocation steps: build download, target_prep, run tests, clean up. 97 * Can be extended to override the default behavior of some steps. Order of the steps is driven by 98 * {@link TestInvocation}. 99 */ 100 public class InvocationExecution implements IInvocationExecution { 101 102 public static final String ADB_VERSION_KEY = "adb_version"; 103 public static final String JAVA_VERSION_KEY = "java_version"; 104 public static final String JAVA_CLASSPATH_KEY = "java_classpath"; 105 // Track which preparer ran in setup to ensure we don't trigger tearDown if setup was skipped. 106 private Set<IMultiTargetPreparer> mTrackMultiPreparers = null; 107 private Map<String, Set<ITargetPreparer>> mTrackTargetPreparers = null; 108 109 @Override fetchBuild( TestInformation testInfo, IConfiguration config, IRescheduler rescheduler, ITestInvocationListener listener)110 public boolean fetchBuild( 111 TestInformation testInfo, 112 IConfiguration config, 113 IRescheduler rescheduler, 114 ITestInvocationListener listener) 115 throws DeviceNotAvailableException, BuildRetrievalError { 116 String currentDeviceName = null; 117 IBuildInfo buildReplicat = null; 118 try { 119 // TODO: evaluate fetching build in parallel 120 for (int i = 0; i < testInfo.getContext().getDeviceConfigNames().size(); i++) { 121 currentDeviceName = testInfo.getContext().getDeviceConfigNames().get(i); 122 if (buildReplicat != null) { 123 // TODO: evaluate if cloning the build is needed 124 testInfo.getContext().addDeviceBuildInfo(currentDeviceName, buildReplicat); 125 continue; 126 } 127 IBuildInfo info = null; 128 ITestDevice device = testInfo.getContext().getDevice(currentDeviceName); 129 IDeviceConfiguration deviceConfig = config.getDeviceConfigByName(currentDeviceName); 130 IBuildProvider provider = deviceConfig.getBuildProvider(); 131 TfObjectTracker.countWithParents(provider.getClass()); 132 // Inject the context to the provider if it can receive it 133 if (provider instanceof IInvocationContextReceiver) { 134 ((IInvocationContextReceiver) provider) 135 .setInvocationContext(testInfo.getContext()); 136 } 137 // Get the build 138 if (provider instanceof IDeviceBuildProvider) { 139 // Download a device build if the provider can handle it. 140 info = ((IDeviceBuildProvider) provider).getBuild(device); 141 } else { 142 info = provider.getBuild(); 143 } 144 if (info != null) { 145 info.setDeviceSerial(device.getSerialNumber()); 146 testInfo.getContext().addDeviceBuildInfo(currentDeviceName, info); 147 device.setRecovery(deviceConfig.getDeviceRecovery()); 148 } else { 149 CLog.logAndDisplay( 150 LogLevel.WARN, 151 "No build found to test for device: %s", 152 device.getSerialNumber()); 153 IBuildInfo notFoundStub = new BuildInfo(); 154 updateBuild(notFoundStub, config); 155 testInfo.getContext().addDeviceBuildInfo(currentDeviceName, notFoundStub); 156 return false; 157 } 158 // TODO: remove build update when reporting is done on context 159 updateBuild(info, config); 160 linkExternalDirs(info, testInfo); 161 162 if (config.getCommandOptions().shouldUseReplicateSetup()) { 163 buildReplicat = info; 164 } 165 } 166 } catch (BuildRetrievalError e) { 167 CLog.e(e); 168 if (currentDeviceName != null) { 169 IBuildInfo errorBuild = e.getBuildInfo(); 170 updateBuild(errorBuild, config); 171 testInfo.getContext().addDeviceBuildInfo(currentDeviceName, errorBuild); 172 } 173 throw e; 174 } catch (RuntimeException re) { 175 if (currentDeviceName != null) { 176 IBuildInfo errorBuild = new BuildInfo(); 177 updateBuild(errorBuild, config); 178 testInfo.getContext().addDeviceBuildInfo(currentDeviceName, errorBuild); 179 } 180 throw re; 181 } 182 setBinariesVersion(testInfo.getContext()); 183 return true; 184 } 185 186 @Override cleanUpBuilds(IInvocationContext context, IConfiguration config)187 public void cleanUpBuilds(IInvocationContext context, IConfiguration config) { 188 // Ensure build infos are always cleaned up at the end of invocation. 189 for (String cleanUpDevice : context.getDeviceConfigNames()) { 190 if (context.getBuildInfo(cleanUpDevice) != null) { 191 try { 192 config.getDeviceConfigByName(cleanUpDevice) 193 .getBuildProvider() 194 .cleanUp(context.getBuildInfo(cleanUpDevice)); 195 } catch (RuntimeException e) { 196 // We catch an simply log exception in cleanUp to avoid missing any final 197 // step of the invocation. 198 CLog.e(e); 199 } 200 } 201 } 202 } 203 204 @Override shardConfig( IConfiguration config, TestInformation testInfo, IRescheduler rescheduler, ITestLogger logger)205 public boolean shardConfig( 206 IConfiguration config, 207 TestInformation testInfo, 208 IRescheduler rescheduler, 209 ITestLogger logger) { 210 return createShardHelper().shardConfig(config, testInfo, rescheduler, logger); 211 } 212 213 /** Create an return the {@link IShardHelper} to be used. */ 214 @VisibleForTesting createShardHelper()215 protected IShardHelper createShardHelper() { 216 return GlobalConfiguration.getInstance().getShardingStrategy(); 217 } 218 219 @Override doSetup(TestInformation testInfo, IConfiguration config, final ITestLogger listener)220 public void doSetup(TestInformation testInfo, IConfiguration config, final ITestLogger listener) 221 throws TargetSetupError, BuildError, DeviceNotAvailableException { 222 long start = System.currentTimeMillis(); 223 try { 224 // Before all the individual setup, make the multi-pre-target-preparer devices setup 225 runMultiTargetPreparers( 226 config.getMultiPreTargetPreparers(), 227 listener, 228 testInfo, 229 "multi pre target preparer setup"); 230 231 mTrackTargetPreparers = new ConcurrentHashMap<>(); 232 int index = 0; 233 if (config.getCommandOptions().shouldUseReplicateSetup() 234 && config.getDeviceConfig().size() > 1) { 235 CLog.d("Using parallel setup due to replicated setup enabled."); 236 ParallelDeviceExecutor<Boolean> executor = 237 new ParallelDeviceExecutor<>(testInfo.getContext().getDevices().size()); 238 List<Callable<Boolean>> callableTasks = new ArrayList<>(); 239 for (String deviceName : testInfo.getContext().getDeviceConfigNames()) { 240 mTrackTargetPreparers.put(deviceName, new HashSet<>()); 241 final int deviceIndex = index; 242 // Replicate TestInfo 243 TestInformation replicated = 244 TestInformation.createModuleTestInfo(testInfo, testInfo.getContext()); 245 Callable<Boolean> callableTask = 246 () -> { 247 runPreparationOnDevice( 248 replicated, deviceName, deviceIndex, config, listener); 249 return true; 250 }; 251 callableTasks.add(callableTask); 252 index++; 253 } 254 // Run setup with 30 minutes right now. 255 executor.invokeAll(callableTasks, 30, TimeUnit.MINUTES); 256 if (executor.hasErrors()) { 257 List<Throwable> errors = executor.getErrors(); 258 // TODO: Handle throwing multi-exceptions, right now throw the first one. 259 for (Throwable error : errors) { 260 if (error instanceof TargetSetupError) { 261 throw (TargetSetupError) error; 262 } 263 if (error instanceof BuildError) { 264 throw (BuildError) error; 265 } 266 if (error instanceof DeviceNotAvailableException) { 267 throw (DeviceNotAvailableException) error; 268 } 269 throw new RuntimeException(error); 270 } 271 } 272 } else { 273 for (String deviceName : testInfo.getContext().getDeviceConfigNames()) { 274 mTrackTargetPreparers.put(deviceName, new HashSet<>()); 275 runPreparationOnDevice(testInfo, deviceName, index, config, listener); 276 index++; 277 } 278 } 279 // After all the individual setup, make the multi-devices setup 280 runMultiTargetPreparers( 281 config.getMultiTargetPreparers(), 282 listener, 283 testInfo, 284 "multi target preparer setup"); 285 } finally { 286 // Note: These metrics are handled in a try in case of a kernel reset or device issue. 287 // Setup timing metric. It does not include flashing time on boot tests. 288 long setupDuration = System.currentTimeMillis() - start; 289 InvocationMetricLogger.addInvocationMetrics(InvocationMetricKey.SETUP, setupDuration); 290 CLog.d("Setup duration: %s'", TimeUtil.formatElapsedTime(setupDuration)); 291 // Upload the setup logcat after setup is complete. 292 for (String deviceName : testInfo.getContext().getDeviceConfigNames()) { 293 reportLogs(testInfo.getContext().getDevice(deviceName), listener, Stage.SETUP); 294 } 295 } 296 } 297 runPreparationOnDevice( TestInformation testInfo, String deviceName, int index, IConfiguration config, ITestLogger logger)298 private void runPreparationOnDevice( 299 TestInformation testInfo, 300 String deviceName, 301 int index, 302 IConfiguration config, 303 ITestLogger logger) 304 throws TargetSetupError, BuildError, DeviceNotAvailableException { 305 ITestDevice device = testInfo.getContext().getDevice(deviceName); 306 CLog.d("Starting setup for device: '%s'", device.getSerialNumber()); 307 if (device instanceof ITestLoggerReceiver) { 308 ((ITestLoggerReceiver) testInfo.getContext().getDevice(deviceName)) 309 .setTestLogger(logger); 310 } 311 for (ITargetPreparer preparer : 312 config.getDeviceConfigByName(deviceName).getTargetPreparers()) { 313 // do not call the preparer if it was disabled 314 if (preparer.isDisabled()) { 315 CLog.d("%s has been disabled. skipping.", preparer); 316 continue; 317 } 318 TfObjectTracker.countWithParents(preparer.getClass()); 319 if (preparer instanceof ITestLoggerReceiver) { 320 ((ITestLoggerReceiver) preparer).setTestLogger(logger); 321 } 322 CLog.d("starting preparer '%s' on device: '%s'", preparer, device.getSerialNumber()); 323 try { 324 testInfo.setActiveDeviceIndex(index); 325 preparer.setUp(testInfo); 326 } finally { 327 testInfo.setActiveDeviceIndex(0); 328 } 329 mTrackTargetPreparers.get(deviceName).add(preparer); 330 CLog.d("done with preparer '%s' on device: '%s'", preparer, device.getSerialNumber()); 331 } 332 CLog.d("Done with setup of device: '%s'", device.getSerialNumber()); 333 } 334 335 /** {@inheritDoc} */ 336 @Override runDevicePreInvocationSetup( IInvocationContext context, IConfiguration config, ITestLogger logger)337 public final void runDevicePreInvocationSetup( 338 IInvocationContext context, IConfiguration config, ITestLogger logger) 339 throws DeviceNotAvailableException, TargetSetupError { 340 customizeDevicePreInvocation(config, context); 341 for (String deviceName : context.getDeviceConfigNames()) { 342 ITestDevice device = context.getDevice(deviceName); 343 344 CLog.d("Starting device pre invocation setup for : '%s'", device.getSerialNumber()); 345 if (device instanceof ITestLoggerReceiver) { 346 ((ITestLoggerReceiver) context.getDevice(deviceName)).setTestLogger(logger); 347 } 348 device.preInvocationSetup(context.getBuildInfo(deviceName)); 349 } 350 } 351 352 /** 353 * Give a chance to customize some of the device before preInvocationSetup. 354 * 355 * @param config The config of the invocation. 356 * @param context The current invocation context. 357 */ customizeDevicePreInvocation(IConfiguration config, IInvocationContext context)358 protected void customizeDevicePreInvocation(IConfiguration config, IInvocationContext context) { 359 // Empty by default 360 } 361 362 /** {@inheritDoc} */ 363 @Override runDevicePostInvocationTearDown( IInvocationContext context, IConfiguration config, Throwable exception)364 public final void runDevicePostInvocationTearDown( 365 IInvocationContext context, IConfiguration config, Throwable exception) { 366 // Extra tear down step for the device 367 for (String deviceName : context.getDeviceConfigNames()) { 368 ITestDevice device = context.getDevice(deviceName); 369 device.postInvocationTearDown(exception); 370 } 371 } 372 373 /** Runs the {@link IMultiTargetPreparer} specified. */ runMultiTargetPreparers( List<IMultiTargetPreparer> multiPreparers, ITestLogger logger, TestInformation testInfo, String description)374 private void runMultiTargetPreparers( 375 List<IMultiTargetPreparer> multiPreparers, 376 ITestLogger logger, 377 TestInformation testInfo, 378 String description) 379 throws TargetSetupError, BuildError, DeviceNotAvailableException { 380 if (mTrackMultiPreparers == null) { 381 mTrackMultiPreparers = new HashSet<>(); 382 } 383 for (IMultiTargetPreparer multiPreparer : multiPreparers) { 384 // do not call the preparer if it was disabled 385 if (multiPreparer.isDisabled()) { 386 CLog.d("%s has been disabled. skipping.", multiPreparer); 387 continue; 388 } 389 TfObjectTracker.countWithParents(multiPreparer.getClass()); 390 if (multiPreparer instanceof ITestLoggerReceiver) { 391 ((ITestLoggerReceiver) multiPreparer).setTestLogger(logger); 392 } 393 CLog.d("Starting %s '%s'", description, multiPreparer); 394 multiPreparer.setUp(testInfo); 395 mTrackMultiPreparers.add(multiPreparer); 396 CLog.d("done with %s '%s'", description, multiPreparer); 397 } 398 } 399 400 /** Runs the {@link IMultiTargetPreparer} specified tearDown. */ runMultiTargetPreparersTearDown( List<IMultiTargetPreparer> multiPreparers, TestInformation testInfo, ITestLogger logger, Throwable throwable, String description)401 private Throwable runMultiTargetPreparersTearDown( 402 List<IMultiTargetPreparer> multiPreparers, 403 TestInformation testInfo, 404 ITestLogger logger, 405 Throwable throwable, 406 String description) 407 throws Throwable { 408 ListIterator<IMultiTargetPreparer> iterator = 409 multiPreparers.listIterator(multiPreparers.size()); 410 Throwable deferredThrowable = null; 411 412 while (iterator.hasPrevious()) { 413 IMultiTargetPreparer multipreparer = iterator.previous(); 414 if (multipreparer.isDisabled() || multipreparer.isTearDownDisabled()) { 415 CLog.d("%s has been disabled. skipping.", multipreparer); 416 continue; 417 } 418 if (mTrackMultiPreparers == null || !mTrackMultiPreparers.contains(multipreparer)) { 419 CLog.d("%s didn't run setUp, skipping tearDown.", multipreparer); 420 continue; 421 } 422 if (multipreparer instanceof ITestLoggerReceiver) { 423 ((ITestLoggerReceiver) multipreparer).setTestLogger(logger); 424 } 425 CLog.d("Starting %s '%s'", description, multipreparer); 426 try { 427 multipreparer.tearDown(testInfo, throwable); 428 } catch (Throwable t) { 429 // We catch it and rethrow later to allow each multi_targetprep to be attempted. 430 // Only the first one will be thrown but all should be logged. 431 CLog.e("Deferring throw for:"); 432 CLog.e(t); 433 if (deferredThrowable == null) { 434 deferredThrowable = t; 435 } 436 } 437 CLog.d("Done with %s '%s'", description, multipreparer); 438 } 439 440 return deferredThrowable; 441 } 442 443 @Override doTeardown( TestInformation testInfo, IConfiguration config, ITestLogger logger, Throwable exception)444 public void doTeardown( 445 TestInformation testInfo, 446 IConfiguration config, 447 ITestLogger logger, 448 Throwable exception) 449 throws Throwable { 450 IInvocationContext context = testInfo.getContext(); 451 Throwable deferredThrowable = null; 452 453 List<IMultiTargetPreparer> multiPreparers = config.getMultiTargetPreparers(); 454 deferredThrowable = 455 runMultiTargetPreparersTearDown( 456 multiPreparers, 457 testInfo, 458 logger, 459 exception, 460 "multi target preparer teardown"); 461 462 // Clear wifi settings, to prevent wifi errors from interfering with teardown process. 463 int deviceIndex = 0; 464 for (String deviceName : context.getDeviceConfigNames()) { 465 ITestDevice device = context.getDevice(deviceName); 466 device.clearLastConnectedWifiNetwork(); 467 List<ITargetPreparer> preparers = 468 config.getDeviceConfigByName(deviceName).getTargetPreparers(); 469 ListIterator<ITargetPreparer> itr = preparers.listIterator(preparers.size()); 470 while (itr.hasPrevious()) { 471 ITargetPreparer preparer = itr.previous(); 472 // do not call the cleaner if it was disabled 473 if (preparer.isDisabled() || preparer.isTearDownDisabled()) { 474 CLog.d("%s has been disabled. skipping.", preparer); 475 continue; 476 } 477 if (mTrackTargetPreparers == null 478 || !mTrackTargetPreparers.containsKey(deviceName) 479 || !mTrackTargetPreparers.get(deviceName).contains(preparer)) { 480 CLog.d("%s didn't run setUp, skipping tearDown.", preparer); 481 continue; 482 } 483 // If setup hit a targetSetupError, the setUp() and setTestLogger might not have 484 // run, ensure we still have the logger. 485 if (preparer instanceof ITestLoggerReceiver) { 486 ((ITestLoggerReceiver) preparer).setTestLogger(logger); 487 } 488 try { 489 CLog.d( 490 "starting tearDown '%s' on device: '%s'", 491 preparer, device.getSerialNumber()); 492 testInfo.setActiveDeviceIndex(deviceIndex); 493 preparer.tearDown(testInfo, exception); 494 CLog.d( 495 "done with tearDown '%s' on device: '%s'", 496 preparer, device.getSerialNumber()); 497 } catch (Throwable e) { 498 // We catch it and rethrow later to allow each targetprep to be attempted. 499 // Only the first one will be thrown but all should be logged. 500 CLog.e("Deferring throw for:"); 501 CLog.e(e); 502 if (deferredThrowable == null) { 503 deferredThrowable = e; 504 } 505 } finally { 506 testInfo.setActiveDeviceIndex(0); 507 } 508 } 509 deviceIndex++; 510 } 511 512 // Extra tear down step for the device 513 runDevicePostInvocationTearDown(context, config, exception); 514 515 // After all, run the multi_pre_target_preparer tearDown. 516 List<IMultiTargetPreparer> multiPrePreparers = config.getMultiPreTargetPreparers(); 517 Throwable preTargetTearDownException = 518 runMultiTargetPreparersTearDown( 519 multiPrePreparers, 520 testInfo, 521 logger, 522 exception, 523 "multi pre target preparer teardown"); 524 if (deferredThrowable == null) { 525 deferredThrowable = preTargetTearDownException; 526 } 527 528 // Collect adb logs. 529 logHostAdb(logger); 530 531 if (deferredThrowable != null) { 532 throw deferredThrowable; 533 } 534 } 535 536 @Override doCleanUp(IInvocationContext context, IConfiguration config, Throwable exception)537 public void doCleanUp(IInvocationContext context, IConfiguration config, Throwable exception) { 538 for (String deviceName : context.getDeviceConfigNames()) { 539 List<ITargetPreparer> preparers = 540 config.getDeviceConfigByName(deviceName).getTargetPreparers(); 541 ListIterator<ITargetPreparer> itr = preparers.listIterator(preparers.size()); 542 while (itr.hasPrevious()) { 543 ITargetPreparer preparer = itr.previous(); 544 if (preparer instanceof IHostCleaner) { 545 IHostCleaner cleaner = (IHostCleaner) preparer; 546 if (preparer.isDisabled() || preparer.isTearDownDisabled()) { 547 CLog.d("%s has been disabled. skipping.", cleaner); 548 continue; 549 } 550 cleaner.cleanUp(context.getBuildInfo(deviceName), exception); 551 } 552 } 553 } 554 } 555 556 @Override runTests( TestInformation info, IConfiguration config, ITestInvocationListener listener)557 public void runTests( 558 TestInformation info, IConfiguration config, ITestInvocationListener listener) 559 throws Throwable { 560 List<IRemoteTest> remainingTests = new ArrayList<>(config.getTests()); 561 UnexecutedTestReporterThread reporterThread = 562 new UnexecutedTestReporterThread(listener, remainingTests); 563 Runtime.getRuntime().addShutdownHook(reporterThread); 564 TestInvocation.printStageDelimiter(Stage.TEST, false); 565 try { 566 for (IRemoteTest test : config.getTests()) { 567 TfObjectTracker.countWithParents(test.getClass()); 568 // For compatibility of those receivers, they are assumed to be single device alloc. 569 if (test instanceof IDeviceTest) { 570 ((IDeviceTest) test).setDevice(info.getDevice()); 571 } 572 if (test instanceof IBuildReceiver) { 573 ((IBuildReceiver) test).setBuild(info.getBuildInfo()); 574 } 575 if (test instanceof ISystemStatusCheckerReceiver) { 576 ((ISystemStatusCheckerReceiver) test) 577 .setSystemStatusChecker(config.getSystemStatusCheckers()); 578 } 579 if (test instanceof IInvocationContextReceiver) { 580 ((IInvocationContextReceiver) test).setInvocationContext(info.getContext()); 581 } 582 583 updateAutoCollectors(config); 584 585 IRetryDecision decision = config.getRetryDecision(); 586 // Handle the no-retry use case 587 if (!decision.isAutoRetryEnabled() 588 || RetryStrategy.NO_RETRY.equals(decision.getRetryStrategy()) 589 || test instanceof ITestSuite 590 // TODO: Handle auto-retry in local-sharding for non-suite 591 || test instanceof TestsPoolPoller 592 // If test doesn't support auto-retry 593 || (!(test instanceof ITestFilterReceiver) 594 && !(test instanceof IAutoRetriableTest))) { 595 runTest(config, info, listener, test); 596 remainingTests.remove(test); 597 continue; 598 } 599 CLog.d("Using RetryLogSaverResultForwarder to forward results."); 600 ModuleListener mainGranularRunListener = new ModuleListener(null); 601 RetryLogSaverResultForwarder runListener = 602 initializeListeners(config, listener, mainGranularRunListener); 603 runTest(config, info, runListener, test); 604 remainingTests.remove(test); 605 runListener.incrementAttempt(); 606 607 // Avoid entering the loop if no retry to be done. 608 if (!decision.shouldRetry( 609 test, 0, mainGranularRunListener.getTestRunForAttempts(0))) { 610 continue; 611 } 612 613 long startTime = System.currentTimeMillis(); 614 try { 615 PrettyPrintDelimiter.printStageDelimiter("Starting auto-retry"); 616 for (int attemptNumber = 1; 617 attemptNumber < decision.getMaxRetryCount(); 618 attemptNumber++) { 619 boolean retry = 620 decision.shouldRetry( 621 test, 622 attemptNumber - 1, 623 mainGranularRunListener.getTestRunForAttempts( 624 attemptNumber - 1)); 625 if (!retry) { 626 continue; 627 } 628 CLog.d("auto-retry attempt number '%s'", attemptNumber); 629 // Run the tests again 630 runTest(config, info, runListener, test); 631 runListener.incrementAttempt(); 632 } 633 // Feed the last attempt if we reached here. 634 decision.addLastAttempt( 635 mainGranularRunListener.getTestRunForAttempts( 636 decision.getMaxRetryCount() - 1)); 637 } finally { 638 RetryStatistics retryStats = decision.getRetryStatistics(); 639 // Track how long we spend in retry 640 retryStats.mRetryTime = System.currentTimeMillis() - startTime; 641 addRetryTime(retryStats.mRetryTime); 642 } 643 } 644 } finally { 645 TestInvocation.printStageDelimiter(Stage.TEST, true); 646 // TODO: Look if this can be improved to DeviceNotAvailableException too. 647 Runtime.getRuntime().removeShutdownHook(reporterThread); 648 } 649 650 } 651 652 @Override reportLogs(ITestDevice device, ITestLogger listener, Stage stage)653 public void reportLogs(ITestDevice device, ITestLogger listener, Stage stage) { 654 if (device == null) { 655 return; 656 } 657 IDevice idevice = device.getIDevice(); 658 // non stub device 659 if (!(idevice instanceof StubDevice)) { 660 try (InputStreamSource logcatSource = device.getLogcat()) { 661 device.clearLogcat(); 662 String name = 663 String.format( 664 "%s_%s", 665 TestInvocation.getDeviceLogName(stage), device.getSerialNumber()); 666 listener.testLog(name, LogDataType.LOGCAT, logcatSource); 667 } 668 } 669 // emulator logs 670 if (idevice != null && idevice.isEmulator()) { 671 try (InputStreamSource emulatorOutput = device.getEmulatorOutput()) { 672 // TODO: Clear the emulator log 673 String name = TestInvocation.getEmulatorLogName(stage); 674 listener.testLog(name, LogDataType.TEXT, emulatorOutput); 675 } 676 } 677 } 678 679 /** Helper to create the test tag from the configuration. */ getTestTag(IConfiguration config)680 private String getTestTag(IConfiguration config) { 681 String testTag = config.getCommandOptions().getTestTag(); 682 if (config.getCommandOptions().getTestTagSuffix() != null) { 683 testTag = 684 String.format("%s-%s", testTag, config.getCommandOptions().getTestTagSuffix()); 685 } 686 return testTag; 687 } 688 689 /** Handle setting the test tag on the build info. */ setTestTag(IBuildInfo info, IConfiguration config)690 protected void setTestTag(IBuildInfo info, IConfiguration config) { 691 // When CommandOption is set, it overrides any test-tag from build_providers 692 if (!"stub".equals(config.getCommandOptions().getTestTag())) { 693 info.setTestTag(getTestTag(config)); 694 } else if (Strings.isNullOrEmpty(info.getTestTag())) { 695 // We ensure that that a default test-tag is always available. 696 info.setTestTag("stub"); 697 } 698 } 699 700 /** 701 * Update the {@link IBuildInfo} with additional info from the {@link IConfiguration}. 702 * 703 * @param info the {@link IBuildInfo} 704 * @param config the {@link IConfiguration} 705 */ updateBuild(IBuildInfo info, IConfiguration config)706 void updateBuild(IBuildInfo info, IConfiguration config) { 707 if (config.getCommandLine() != null) { 708 // TODO: obfuscate the password if any. 709 info.addBuildAttribute(TestInvocation.COMMAND_ARGS_KEY, config.getCommandLine()); 710 } 711 if (config.getCommandOptions().getShardCount() != null) { 712 info.addBuildAttribute( 713 "shard_count", config.getCommandOptions().getShardCount().toString()); 714 } 715 if (config.getCommandOptions().getShardIndex() != null) { 716 info.addBuildAttribute( 717 "shard_index", config.getCommandOptions().getShardIndex().toString()); 718 } 719 setTestTag(info, config); 720 } 721 runTest( IConfiguration config, TestInformation info, ITestInvocationListener listener, IRemoteTest test)722 private void runTest( 723 IConfiguration config, 724 TestInformation info, 725 ITestInvocationListener listener, 726 IRemoteTest test) 727 throws DeviceNotAvailableException { 728 // We clone the collectors for each IRemoteTest to ensure no state conflicts. 729 List<IMetricCollector> clonedCollectors = new ArrayList<>(); 730 // Add automated collectors 731 for (AutoLogCollector auto : config.getCommandOptions().getAutoLogCollectors()) { 732 clonedCollectors.add(auto.getInstanceForValue()); 733 } 734 // Add the collector from the configuration 735 clonedCollectors.addAll(CollectorHelper.cloneCollectors(config.getMetricCollectors())); 736 if (test instanceof IMetricCollectorReceiver) { 737 ((IMetricCollectorReceiver) test).setMetricCollectors(clonedCollectors); 738 // If test can receive collectors then let it handle the how to set them up 739 test.run(info, listener); 740 } else { 741 // Wrap collectors in each other and collection will be sequential, do this in the 742 // loop to ensure they are always initialized against the right context. 743 ITestInvocationListener listenerWithCollectors = listener; 744 for (IMetricCollector collector : clonedCollectors) { 745 if (collector.isDisabled()) { 746 CLog.d("%s has been disabled. Skipping.", collector); 747 } else { 748 listenerWithCollectors = 749 collector.init(info.getContext(), listenerWithCollectors); 750 TfObjectTracker.countWithParents(collector.getClass()); 751 } 752 } 753 test.run(info, listenerWithCollectors); 754 } 755 } 756 initializeListeners( IConfiguration config, ITestInvocationListener mainListener, ITestInvocationListener mainGranularLevelListener)757 private RetryLogSaverResultForwarder initializeListeners( 758 IConfiguration config, 759 ITestInvocationListener mainListener, 760 ITestInvocationListener mainGranularLevelListener) { 761 List<ITestInvocationListener> currentTestListeners = new ArrayList<>(); 762 currentTestListeners.add(mainGranularLevelListener); 763 currentTestListeners.add(mainListener); 764 return new RetryLogSaverResultForwarder(config.getLogSaver(), currentTestListeners) { 765 @Override 766 public void testLog( 767 String dataName, LogDataType dataType, InputStreamSource dataStream) { 768 // We know for sure that the sub-listeners are LogSaverResultForwarder 769 // so we delegate to them to save and generate the logAssociation. 770 testLogForward(dataName, dataType, dataStream); 771 } 772 }; 773 } 774 775 private void addRetryTime(long retryTimeMs) { 776 // InvocationMetricLogger automatically adds the auto retry time. 777 InvocationMetricLogger.addInvocationMetrics( 778 InvocationMetricKey.AUTO_RETRY_TIME, retryTimeMs); 779 } 780 781 private void linkExternalDirs(IBuildInfo info, TestInformation testInfo) { 782 if (info.getProperties().contains(BuildInfoProperties.DO_NOT_LINK_TESTS_DIR)) { 783 CLog.d("Skip linking external directory as FileProperty was set."); 784 return; 785 } 786 // Load environment tests dir. 787 if (info instanceof IDeviceBuildInfo) { 788 // TODO: Use tests directory from TestInformation instead. 789 File testsDir = ((IDeviceBuildInfo) info).getTestsDir(); 790 if (testsDir != null && testsDir.exists()) { 791 if (testInfo.executionFiles().get(FilesKey.TARGET_TESTS_DIRECTORY) == null) { 792 File targetTestCases = 793 handleLinkingExternalDirs( 794 (IDeviceBuildInfo) info, 795 testsDir, 796 EnvVariable.ANDROID_TARGET_OUT_TESTCASES, 797 BuildInfoFileKey.TARGET_LINKED_DIR.getFileKey()); 798 if (targetTestCases != null) { 799 testInfo.executionFiles() 800 .put(FilesKey.TARGET_TESTS_DIRECTORY, targetTestCases, true); 801 } 802 } 803 if (testInfo.executionFiles().get(FilesKey.HOST_TESTS_DIRECTORY) == null) { 804 File hostTestCases = 805 handleLinkingExternalDirs( 806 (IDeviceBuildInfo) info, 807 testsDir, 808 EnvVariable.ANDROID_HOST_OUT_TESTCASES, 809 BuildInfoFileKey.HOST_LINKED_DIR.getFileKey()); 810 if (hostTestCases != null) { 811 testInfo.executionFiles() 812 .put(FilesKey.HOST_TESTS_DIRECTORY, hostTestCases, true); 813 } 814 } 815 } 816 } 817 } 818 819 private File handleLinkingExternalDirs( 820 IDeviceBuildInfo info, File testsDir, EnvVariable var, String baseName) { 821 File externalDir = getExternalTestCasesDirs(var); 822 if (externalDir == null) { 823 String path = SystemUtil.ENV_VARIABLE_PATHS_IN_TESTS_DIR.get(var); 824 File varDir = FileUtil.getFileForPath(testsDir, path); 825 if (varDir.exists()) { 826 // If we found a dir already in the tests dir we keep track of it 827 info.setFile( 828 baseName, 829 varDir, 830 /** version */ 831 "v1"); 832 return varDir; 833 } 834 return null; 835 } 836 try { 837 // Avoid conflict by creating a randomized name for the arriving symlink file. 838 File subDir = FileUtil.createTempDir(baseName, testsDir); 839 subDir.delete(); 840 FileUtil.symlinkFile(externalDir, subDir); 841 // Tag the dir in the build info to be possibly cleaned. 842 info.setFile( 843 baseName, 844 subDir, 845 /** version */ 846 "v1"); 847 // Ensure we always delete the linking, no matter how the JVM exits. 848 subDir.deleteOnExit(); 849 return subDir; 850 } catch (IOException e) { 851 CLog.e("Failed to load external test dir %s. Ignoring it.", externalDir); 852 CLog.e(e); 853 } 854 return null; 855 } 856 857 private void setBinariesVersion(IInvocationContext context) { 858 String version = getAdbVersion(); 859 if (version != null) { 860 context.addInvocationAttribute(ADB_VERSION_KEY, version); 861 } 862 String javaVersion = System.getProperty("java.version"); 863 if (javaVersion != null && !javaVersion.isEmpty()) { 864 context.addInvocationAttribute(JAVA_VERSION_KEY, javaVersion); 865 } 866 String javaClasspath = System.getProperty("java.class.path"); 867 if (javaClasspath != null && !javaClasspath.isEmpty()) { 868 context.addInvocationAttribute(JAVA_CLASSPATH_KEY, javaClasspath); 869 } 870 } 871 872 /** Convert the legacy *-on-failure options to the new auto-collect. */ 873 private void updateAutoCollectors(IConfiguration config) { 874 if (config.getCommandOptions().captureScreenshotOnFailure()) { 875 config.getCommandOptions() 876 .getAutoLogCollectors() 877 .add(AutoLogCollector.SCREENSHOT_ON_FAILURE); 878 } 879 if (config.getCommandOptions().captureLogcatOnFailure()) { 880 config.getCommandOptions() 881 .getAutoLogCollectors() 882 .add(AutoLogCollector.LOGCAT_ON_FAILURE); 883 } 884 } 885 886 /** Collect the logs from $TMPDIR/adb.$UID.log. */ 887 @VisibleForTesting 888 void logHostAdb(ITestLogger logger) { 889 String tmpDir = "/tmp"; 890 if (System.getenv("TMPDIR") != null) { 891 tmpDir = System.getenv("TMPDIR"); 892 } 893 CommandResult uidRes = 894 RunUtil.getDefault() 895 .runTimedCmd(60000, "id", "-u", System.getProperty("user.name")); 896 if (!CommandStatus.SUCCESS.equals(uidRes.getStatus())) { 897 CLog.e("Failed to collect UID for adb logs: %s", uidRes.getStderr()); 898 return; 899 } 900 String uid = uidRes.getStdout().trim(); 901 File adbLog = new File(tmpDir, String.format("adb.%s.log", uid)); 902 if (!adbLog.exists()) { 903 CLog.i("Did not find adb log file: %s, upload skipped.", adbLog); 904 return; 905 } 906 CommandResult truncAdb = 907 RunUtil.getDefault() 908 .runTimedCmd(60000, "tail", "--bytes=10MB", adbLog.getAbsolutePath()); 909 if (!CommandStatus.SUCCESS.equals(truncAdb.getStatus())) { 910 CLog.e("Fail to truncate the adb log: %s\n%s", adbLog, truncAdb.getStderr()); 911 return; 912 } 913 try (InputStreamSource source = 914 new ByteArrayInputStreamSource(truncAdb.getStdout().getBytes())) { 915 logger.testLog("host_adb_log", LogDataType.TEXT, source); 916 } 917 } 918 919 /** Returns the external directory coming from the environment. */ 920 @VisibleForTesting 921 File getExternalTestCasesDirs(EnvVariable envVar) { 922 return SystemUtil.getExternalTestCasesDir(envVar); 923 } 924 925 /** Returns the adb version in use for the invocation. */ 926 protected String getAdbVersion() { 927 return GlobalConfiguration.getDeviceManagerInstance().getAdbVersion(); 928 } 929 } 930