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 package com.android.tradefed.invoker;
17 
18 import com.android.ddmlib.Log.LogLevel;
19 import com.android.tradefed.build.BuildInfo;
20 import com.android.tradefed.build.BuildRetrievalError;
21 import com.android.tradefed.build.IBuildInfo;
22 import com.android.tradefed.command.CommandRunner.ExitCode;
23 import com.android.tradefed.command.CommandScheduler;
24 import com.android.tradefed.command.ICommandScheduler.IScheduledInvocationListener;
25 import com.android.tradefed.config.ConfigurationException;
26 import com.android.tradefed.config.DynamicRemoteFileResolver;
27 import com.android.tradefed.config.GlobalConfiguration;
28 import com.android.tradefed.config.IConfiguration;
29 import com.android.tradefed.config.proxy.AutomatedReporters;
30 import com.android.tradefed.config.proxy.TradefedDelegator;
31 import com.android.tradefed.device.DeviceManager;
32 import com.android.tradefed.device.DeviceNotAvailableException;
33 import com.android.tradefed.device.DeviceUnresponsiveException;
34 import com.android.tradefed.device.FreeDeviceState;
35 import com.android.tradefed.device.ITestDevice;
36 import com.android.tradefed.device.ITestDevice.RecoveryMode;
37 import com.android.tradefed.device.NativeDevice;
38 import com.android.tradefed.device.StubDevice;
39 import com.android.tradefed.device.TcpDevice;
40 import com.android.tradefed.device.TestDeviceState;
41 import com.android.tradefed.device.cloud.ManagedRemoteDevice;
42 import com.android.tradefed.device.cloud.NestedRemoteDevice;
43 import com.android.tradefed.device.cloud.RemoteAndroidVirtualDevice;
44 import com.android.tradefed.error.HarnessException;
45 import com.android.tradefed.error.IHarnessException;
46 import com.android.tradefed.guice.InvocationScope;
47 import com.android.tradefed.invoker.logger.CurrentInvocation;
48 import com.android.tradefed.invoker.logger.CurrentInvocation.InvocationInfo;
49 import com.android.tradefed.invoker.logger.InvocationMetricLogger;
50 import com.android.tradefed.invoker.logger.InvocationMetricLogger.InvocationMetricKey;
51 import com.android.tradefed.invoker.logger.TfObjectTracker;
52 import com.android.tradefed.invoker.sandbox.ParentSandboxInvocationExecution;
53 import com.android.tradefed.invoker.sandbox.SandboxedInvocationExecution;
54 import com.android.tradefed.invoker.shard.LastShardDetector;
55 import com.android.tradefed.invoker.shard.ShardHelper;
56 import com.android.tradefed.log.BaseLeveledLogOutput;
57 import com.android.tradefed.log.ILeveledLogOutput;
58 import com.android.tradefed.log.ILogRegistry;
59 import com.android.tradefed.log.ITestLogger;
60 import com.android.tradefed.log.LogRegistry;
61 import com.android.tradefed.log.LogUtil.CLog;
62 import com.android.tradefed.log.StdoutLogger;
63 import com.android.tradefed.postprocessor.IPostProcessor;
64 import com.android.tradefed.result.ActionInProgress;
65 import com.android.tradefed.result.FailureDescription;
66 import com.android.tradefed.result.FileInputStreamSource;
67 import com.android.tradefed.result.ITestInvocationListener;
68 import com.android.tradefed.result.InputStreamSource;
69 import com.android.tradefed.result.LogDataType;
70 import com.android.tradefed.result.LogSaverResultForwarder;
71 import com.android.tradefed.result.ResultAndLogForwarder;
72 import com.android.tradefed.result.error.ErrorIdentifier;
73 import com.android.tradefed.result.error.InfraErrorIdentifier;
74 import com.android.tradefed.result.proto.TestRecordProto.FailureStatus;
75 import com.android.tradefed.retry.IRetryDecision;
76 import com.android.tradefed.retry.ResultAggregator;
77 import com.android.tradefed.retry.RetryStrategy;
78 import com.android.tradefed.targetprep.BuildError;
79 import com.android.tradefed.targetprep.DeviceFailedToBootError;
80 import com.android.tradefed.targetprep.TargetSetupError;
81 import com.android.tradefed.testtype.SubprocessTfLauncher;
82 import com.android.tradefed.util.FileUtil;
83 import com.android.tradefed.util.IRunUtil;
84 import com.android.tradefed.util.PrettyPrintDelimiter;
85 import com.android.tradefed.util.RunInterruptedException;
86 import com.android.tradefed.util.RunUtil;
87 import com.android.tradefed.util.TimeUtil;
88 import com.android.tradefed.util.executor.ParallelDeviceExecutor;
89 
90 import com.google.common.annotations.VisibleForTesting;
91 
92 import java.io.File;
93 import java.io.IOException;
94 import java.util.ArrayList;
95 import java.util.Arrays;
96 import java.util.List;
97 import java.util.Map;
98 import java.util.Map.Entry;
99 import java.util.concurrent.Callable;
100 import java.util.concurrent.TimeUnit;
101 
102 /**
103  * Default implementation of {@link ITestInvocation}.
104  * <p/>
105  * Loads major objects based on {@link IConfiguration}
106  *   - retrieves build
107  *   - prepares target
108  *   - runs tests
109  *   - reports results
110  */
111 public class TestInvocation implements ITestInvocation {
112 
113     /** Key of the command line args attributes */
114     public static final String COMMAND_ARGS_KEY = "command_line_args";
115 
116     /**
117      * Format of the key in {@link IBuildInfo} to log the battery level for each step of the
118      * invocation. (Setup, test, tear down).
119      */
120     private static final String BATTERY_ATTRIBUTE_FORMAT_KEY = "%s-battery-%s";
121 
122     public static final String TRADEFED_LOG_NAME = "host_log";
123     public static final String TRADEFED_END_HOST_LOG = "end_host_log";
124     private static final String TRADEFED_DELEGATED_LOG_NAME = "delegated_parent_log";
125     /** Suffix used on host_log for the part before sharding occurs. */
126     static final String BEFORE_SHARDING_SUFFIX = "_before_sharding";
127     static final String DEVICE_LOG_NAME_PREFIX = "device_logcat_";
128     static final String EMULATOR_LOG_NAME_PREFIX = "emulator_log_";
129     static final String BUILD_ERROR_BUGREPORT_NAME = "build_error_bugreport";
130     static final String DEVICE_UNRESPONSIVE_BUGREPORT_NAME = "device_unresponsive_bugreport";
131     static final String INVOCATION_ENDED_BUGREPORT_NAME = "invocation_ended_bugreport";
132     static final String TARGET_SETUP_ERROR_BUGREPORT_NAME = "target_setup_error_bugreport";
133     static final String BATT_TAG = "[battery level]";
134 
135     public enum Stage {
136         ERROR("error"),
137         SETUP("setup"),
138         TEST("test"),
139         TEARDOWN("teardown");
140 
141         private final String mName;
142 
Stage(String name)143         Stage(String name) {
144             mName = name;
145         }
146 
getName()147         public String getName() {
148             return mName;
149         }
150     }
151 
152     /** The different mode an invocation can run into. */
153     public enum RunMode {
154         REGULAR,
155         PARENT_SANDBOX,
156         SANDBOX,
157         REMOTE_INVOCATION,
158         DELEGATED_INVOCATION
159     }
160 
161     private String mStatus = "(not invoked)";
162     private String mStopCause = null;
163     private Long mStopRequestTime = null;
164     private boolean mTestStarted = false;
165     private boolean mInvocationFailed = false;
166     private List<IScheduledInvocationListener> mSchedulerListeners = new ArrayList<>();
167 
168     /**
169      * Display a log message informing the user of a invocation being started.
170      *
171      * @param context the {@link IInvocationContext}
172      * @param config the {@link IConfiguration}
173      */
logStartInvocation(IInvocationContext context, IConfiguration config)174     private void logStartInvocation(IInvocationContext context, IConfiguration config) {
175         String shardSuffix = "";
176         if (config.getCommandOptions().getShardIndex() != null) {
177             shardSuffix =
178                     String.format(
179                             " (shard %d of %d)",
180                             config.getCommandOptions().getShardIndex() + 1,
181                             config.getCommandOptions().getShardCount());
182         }
183         StringBuilder buildInfos = new StringBuilder();
184         StringBuilder msg = new StringBuilder("Starting invocation for '");
185         msg.append(context.getTestTag());
186         msg.append("' with ");
187         for (Entry<ITestDevice, IBuildInfo> entry : context.getDeviceBuildMap().entrySet()) {
188             msg.append("'[ ");
189             msg.append(entry.getValue().toString());
190             buildInfos.append(entry.getValue().toString());
191             msg.append(" on device '");
192             msg.append(entry.getKey().getSerialNumber());
193             msg.append("'] ");
194         }
195         msg.append(shardSuffix);
196         CLog.logAndDisplay(LogLevel.INFO, msg.toString());
197         mStatus = String.format("running %s on build(s) '%s'", context.getTestTag(),
198                 buildInfos.toString()) + shardSuffix;
199     }
200 
201     /**
202      * Performs the invocation
203      *
204      * @param config the {@link IConfiguration}
205      * @param testInfo the {@link TestInformation} to use for the invocation.
206      */
performInvocation( IConfiguration config, TestInformation testInfo, IInvocationExecution invocationPath, ITestInvocationListener listener, boolean devicePreSetupDone)207     private void performInvocation(
208             IConfiguration config,
209             TestInformation testInfo,
210             IInvocationExecution invocationPath,
211             ITestInvocationListener listener,
212             boolean devicePreSetupDone)
213             throws Throwable {
214         ReportHostLog reportThread = new ReportHostLog(listener, config);
215         Runtime.getRuntime().addShutdownHook(reportThread);
216         boolean resumed = false;
217         String bugreportName = null;
218         long startTime = System.currentTimeMillis();
219         long elapsedTime = -1;
220         Throwable exception = null;
221         Throwable tearDownException = null;
222         ITestDevice badDevice = null;
223         IInvocationContext context = testInfo.getContext();
224 
225         // Ensure that no unexpected attributes are added afterward
226         ((InvocationContext) context).lockAttributes();
227         try {
228             logDeviceBatteryLevel(context, "initial");
229             // Run the preInvocationSetup on devices.
230             if (!devicePreSetupDone) {
231                 if (!config.getCommandOptions().shouldUseSandboxing()) {
232                     invocationPath.runDevicePreInvocationSetup(context, config, listener);
233                 }
234             }
235             // Then run the regular setup and run
236             prepareAndRun(config, testInfo, invocationPath, listener);
237         } catch (BuildError e) {
238             exception = e;
239             CLog.w("BuildError on device '%s'. Reason: %s", e.getDeviceSerial(), e.toString());
240             bugreportName = BUILD_ERROR_BUGREPORT_NAME;
241             if (e.getDeviceSerial() != null) {
242                 badDevice = context.getDeviceBySerial(e.getDeviceSerial());
243             }
244             if (e instanceof DeviceFailedToBootError) {
245                 if (badDevice == null) {
246                     context.setRecoveryModeForAllDevices(RecoveryMode.NONE);
247                 } else {
248                     badDevice.setRecoveryMode(RecoveryMode.NONE);
249                 }
250             }
251             reportFailure(createFailureFromException(e, FailureStatus.INFRA_FAILURE), listener);
252         } catch (TargetSetupError e) {
253             exception = e;
254             CLog.e("Caught exception while running invocation");
255             CLog.e(e);
256             bugreportName = TARGET_SETUP_ERROR_BUGREPORT_NAME;
257             if (e.getDeviceSerial() != null) {
258                 badDevice = context.getDeviceBySerial(e.getDeviceSerial());
259             }
260             reportFailure(createFailureFromException(e, FailureStatus.INFRA_FAILURE), listener);
261         } catch (DeviceNotAvailableException e) {
262             exception = e;
263             // log a warning here so its captured before reportLogs is called
264             CLog.w("Invocation did not complete due to device %s becoming not available. " +
265                     "Reason: %s", e.getSerial(), e.getMessage());
266             badDevice = context.getDeviceBySerial(e.getSerial());
267             if ((e instanceof DeviceUnresponsiveException) && badDevice != null
268                     && TestDeviceState.ONLINE.equals(badDevice.getDeviceState())) {
269                 // under certain cases it might still be possible to grab a bugreport
270                 bugreportName = DEVICE_UNRESPONSIVE_BUGREPORT_NAME;
271             }
272             reportFailure(createFailureFromException(e, FailureStatus.INFRA_FAILURE), listener);
273             // Upon reaching here after an exception, it is safe to assume that recovery
274             // has already been attempted so we disable it to avoid re-entry during clean up.
275             if (badDevice != null) {
276                 badDevice.setRecoveryMode(RecoveryMode.NONE);
277             }
278             throw e;
279         } catch (RunInterruptedException e) {
280             exception = e;
281             CLog.w("Invocation interrupted");
282             // if a stop cause was set, the interruption is most likely due to the invocation being
283             // cancelled
284             if (mStopCause == null) {
285                 reportFailure(createFailureFromException(e, FailureStatus.UNSET), listener);
286             }
287         } catch (AssertionError e) {
288             exception = e;
289             CLog.e("Caught AssertionError while running invocation: %s", e.toString());
290             CLog.e(e);
291             reportFailure(createFailureFromException(e, FailureStatus.UNSET), listener);
292         } catch (Throwable t) {
293             exception = t;
294             // log a warning here so its captured before reportLogs is called
295             CLog.e("Unexpected exception when running invocation: %s", t.toString());
296             CLog.e(t);
297             reportFailure(createFailureFromException(t, FailureStatus.UNSET), listener);
298             throw t;
299         } finally {
300             // Only capture logcat for TEST if we started the test phase.
301             if (mTestStarted) {
302                 for (ITestDevice device : context.getDevices()) {
303                     invocationPath.reportLogs(device, listener, Stage.TEST);
304                 }
305             }
306             CurrentInvocation.setActionInProgress(ActionInProgress.TEAR_DOWN);
307             getRunUtil().allowInterrupt(false);
308             if (config.getCommandOptions().takeBugreportOnInvocationEnded() ||
309                     config.getCommandOptions().takeBugreportzOnInvocationEnded()) {
310                 if (bugreportName != null) {
311                     CLog.i("Bugreport to be taken for failure instead of invocation ended.");
312                 } else {
313                     bugreportName = INVOCATION_ENDED_BUGREPORT_NAME;
314                 }
315             }
316             if (bugreportName != null) {
317                 if (context.getDevices().size() == 1 || badDevice != null) {
318                     ITestDevice collectBugreport = badDevice;
319                     if (collectBugreport == null) {
320                         collectBugreport = context.getDevices().get(0);
321                     }
322                     // If we have identified a faulty device only take the bugreport on it.
323                     takeBugreport(collectBugreport, listener, bugreportName);
324                 } else if (context.getDevices().size() > 1) {
325                     ParallelDeviceExecutor<Boolean> executor =
326                             new ParallelDeviceExecutor<>(context.getDevices().size());
327                     List<Callable<Boolean>> callableTasks = new ArrayList<>();
328                     final String reportName = bugreportName;
329                     for (ITestDevice device : context.getDevices()) {
330                         Callable<Boolean> callableTask =
331                                 () -> {
332                                     takeBugreport(device, listener, reportName);
333                                     return true;
334                                 };
335                         callableTasks.add(callableTask);
336                     }
337                     // Capture the bugreports best effort, ignore the results.
338                     executor.invokeAll(callableTasks, 5, TimeUnit.MINUTES);
339                 }
340             }
341             // Save the device executeShellCommand logs
342             logExecuteShellCommand(context.getDevices(), listener);
343 
344             mStatus = "tearing down";
345             try {
346                 invocationPath.doTeardown(testInfo, config, listener, exception);
347             } catch (Throwable e) {
348                 tearDownException = e;
349                 CLog.e("Exception when tearing down invocation: %s", tearDownException.toString());
350                 CLog.e(tearDownException);
351                 if (exception == null) {
352                     // only report when the exception is new during tear down
353                     reportFailure(
354                             createFailureFromException(
355                                     tearDownException, FailureStatus.INFRA_FAILURE),
356                             listener);
357                 }
358             }
359             mStatus = "done running tests";
360             CurrentInvocation.setActionInProgress(ActionInProgress.FREE_RESOURCES);
361             // Track the timestamp when we are done with devices
362             addInvocationMetric(
363                     InvocationMetricKey.DEVICE_DONE_TIMESTAMP, System.currentTimeMillis());
364             Map<ITestDevice, FreeDeviceState> devicesStates =
365                     handleAndLogReleaseState(context, exception);
366             if (config.getCommandOptions().earlyDeviceRelease()) {
367                 context.markReleasedEarly();
368                 for (IScheduledInvocationListener scheduleListener : mSchedulerListeners) {
369                     scheduleListener.releaseDevices(context, devicesStates);
370                 }
371             }
372             try {
373                 // Clean up host.
374                 invocationPath.doCleanUp(context, config, exception);
375                 for (ITestDevice device : context.getDevices()) {
376                     invocationPath.reportLogs(device, listener, Stage.TEARDOWN);
377                 }
378                 if (mStopCause != null) {
379                     String message =
380                             String.format(
381                                     "Invocation was interrupted due to: %s, results will be "
382                                             + "affected.",
383                                     mStopCause);
384                     FailureDescription failure =
385                             FailureDescription.create(message, FailureStatus.CANCELLED);
386                     reportFailure(failure, listener);
387                     PrettyPrintDelimiter.printStageDelimiter(message);
388                     if (mStopRequestTime != null) {
389                         // This is not 100% perfect since result reporting can still run a bit
390                         // longer, but this is our last opportunity to report it.
391                         long latency = System.currentTimeMillis() - mStopRequestTime;
392                         InvocationMetricLogger.addInvocationMetrics(
393                                 InvocationMetricKey.SHUTDOWN_HARD_LATENCY, latency);
394                     }
395                 }
396                 reportHostLog(listener, config);
397                 // If host_log is reported, remove the hook
398                 Runtime.getRuntime().removeShutdownHook(reportThread);
399 
400                 elapsedTime = System.currentTimeMillis() - startTime;
401                 if (!resumed) {
402                     // Init a log for the end of the host_log.
403                     ILeveledLogOutput endHostLog = config.getLogOutput();
404                     endHostLog.init();
405                     getLogRegistry().registerLogger(endHostLog);
406                     PrettyPrintDelimiter.printStageDelimiter("===== Result Reporters =====");
407                     try {
408                         // Copy the invocation metrics to the context
409                         ((InvocationContext) context).logInvocationMetrics();
410                         listener.invocationEnded(elapsedTime);
411                     } finally {
412                         InvocationMetricLogger.clearInvocationMetrics();
413                         endHostLog.closeLog();
414                         getLogRegistry().unregisterLogger();
415                     }
416                 }
417             } finally {
418                 TfObjectTracker.clearTracking();
419                 CurrentInvocation.clearInvocationInfos();
420             }
421         }
422         if (tearDownException != null) {
423             // this means a DNAE or RTE has happened during teardown, need to throw
424             // if there was a preceding RTE or DNAE stored in 'exception', it would have already
425             // been thrown before exiting the previous try...catch...finally block
426             throw tearDownException;
427         }
428     }
429 
430     /** Do setup and run the tests */
prepareAndRun( IConfiguration config, TestInformation testInfo, IInvocationExecution invocationPath, ITestInvocationListener listener)431     private void prepareAndRun(
432             IConfiguration config,
433             TestInformation testInfo,
434             IInvocationExecution invocationPath,
435             ITestInvocationListener listener)
436             throws Throwable {
437         getRunUtil().allowInterrupt(true);
438         logDeviceBatteryLevel(testInfo.getContext(), "initial -> setup");
439         CurrentInvocation.setActionInProgress(ActionInProgress.SETUP);
440         invocationPath.doSetup(testInfo, config, listener);
441         logDeviceBatteryLevel(testInfo.getContext(), "setup -> test");
442         mTestStarted = true;
443         CurrentInvocation.setActionInProgress(ActionInProgress.TEST);
444         invocationPath.runTests(testInfo, config, listener);
445         logDeviceBatteryLevel(testInfo.getContext(), "after test");
446         CurrentInvocation.setActionInProgress(ActionInProgress.UNSET);
447     }
448 
449     /**
450      * Starts the invocation.
451      * <p/>
452      * Starts logging, and informs listeners that invocation has been started.
453      *
454      * @param config
455      * @param context
456      */
startInvocation(IConfiguration config, IInvocationContext context, ITestInvocationListener listener)457     private void startInvocation(IConfiguration config, IInvocationContext context,
458             ITestInvocationListener listener) {
459         logStartInvocation(context, config);
460         listener.invocationStarted(context);
461     }
462 
463     /** Report the exception failure as an invocation failure. */
reportFailure(FailureDescription failure, ITestInvocationListener listener)464     private void reportFailure(FailureDescription failure, ITestInvocationListener listener) {
465         if (mInvocationFailed) {
466             CLog.e("An invocation failure was already reported, ignoring %s", failure);
467             return;
468         }
469         // Always report the failure
470         listener.invocationFailed(failure);
471         mInvocationFailed = true;
472     }
473 
474     /**
475      * Create a {@link FailureDescription} from an invocation exception.
476      *
477      * @param exception The exception to convert
478      * @param defaultStatus The status to use by default if the exception is not a {@link
479      *     IHarnessException}.
480      */
createFailureFromException( Throwable exception, FailureStatus defaultStatus)481     private FailureDescription createFailureFromException(
482             Throwable exception, FailureStatus defaultStatus) {
483         ErrorIdentifier id = null;
484         if (exception instanceof IHarnessException) {
485             id = ((HarnessException) exception).getErrorId();
486         }
487         FailureDescription failure =
488                 CurrentInvocation.createFailure(exception.getMessage(), id)
489                         .setCause(exception)
490                         .setFailureStatus(defaultStatus);
491         if (id != null) {
492             failure.setErrorIdentifier(id);
493             failure.setFailureStatus(id.status());
494         }
495         return failure;
496     }
497 
reportHostLog(ITestInvocationListener listener, IConfiguration config)498     private void reportHostLog(ITestInvocationListener listener, IConfiguration config) {
499         String name = TRADEFED_LOG_NAME;
500         if (config.getConfigurationObject(TradefedDelegator.DELEGATE_OBJECT) != null) {
501             name = TRADEFED_DELEGATED_LOG_NAME;
502         }
503         reportHostLog(listener, config, name);
504     }
505 
reportHostLog( ITestInvocationListener listener, IConfiguration config, String name)506     private void reportHostLog(
507             ITestInvocationListener listener, IConfiguration config, String name) {
508         ILeveledLogOutput logger = config.getLogOutput();
509         try (InputStreamSource globalLogSource = logger.getLog()) {
510             if (globalLogSource != null) {
511                 if (config.getCommandOptions().getHostLogSuffix() != null) {
512                     name += config.getCommandOptions().getHostLogSuffix();
513                 }
514                 listener.testLog(name, LogDataType.HOST_LOG, globalLogSource);
515             } else {
516                 // Only print the non-logging if we are not a stdout logger
517                 if (!(logger instanceof StdoutLogger)) {
518                     CLog.i("Skip logging %s to a file with logger '%s'", name, logger);
519                 }
520             }
521         }
522         // once tradefed log is reported, all further log calls for this invocation can get lost
523         // unregister logger so future log calls get directed to the tradefed global log
524         getLogRegistry().unregisterLogger();
525         logger.closeLog();
526     }
527 
takeBugreport( ITestDevice device, ITestInvocationListener listener, String bugreportName)528     private void takeBugreport(
529             ITestDevice device, ITestInvocationListener listener, String bugreportName) {
530         if (device == null) {
531             return;
532         }
533         if (device.getIDevice() instanceof StubDevice) {
534             return;
535         }
536         // logBugreport will report a regular bugreport if bugreportz is not supported.
537         boolean res =
538                 device.logBugreport(
539                         String.format("%s_%s", bugreportName, device.getSerialNumber()), listener);
540         if (!res) {
541             CLog.w("Error when collecting bugreport for device '%s'", device.getSerialNumber());
542         }
543     }
544 
545     /**
546      * Gets the {@link ILogRegistry} to use.
547      * <p/>
548      * Exposed for unit testing.
549      */
getLogRegistry()550     ILogRegistry getLogRegistry() {
551         return LogRegistry.getLogRegistry();
552     }
553 
554     /**
555      * Utility method to fetch the default {@link IRunUtil} singleton
556      * <p />
557      * Exposed for unit testing.
558      */
getRunUtil()559     IRunUtil getRunUtil() {
560         return RunUtil.getDefault();
561     }
562 
563     @Override
toString()564     public String toString() {
565         return mStatus;
566     }
567 
568     /**
569      * Log the battery level of each device in the invocation.
570      *
571      * @param context the {@link IInvocationContext} of the invocation.
572      * @param event a {@link String} describing the context of the logging (initial, setup, etc.).
573      */
574     @VisibleForTesting
logDeviceBatteryLevel(IInvocationContext context, String event)575     void logDeviceBatteryLevel(IInvocationContext context, String event) {
576         for (ITestDevice testDevice : context.getDevices()) {
577             if (testDevice == null) {
578                 continue;
579             }
580             if (testDevice.getIDevice() instanceof StubDevice) {
581                 continue;
582             }
583             if (testDevice instanceof RemoteAndroidVirtualDevice
584                     || testDevice instanceof NestedRemoteDevice) {
585                 // Vritual devices have a fake battery there is no point in logging it.
586                 continue;
587             }
588             Integer batteryLevel = testDevice.getBattery();
589             if (batteryLevel == null) {
590                 CLog.v("Failed to get battery level for %s", testDevice.getSerialNumber());
591                 continue;
592             }
593             CLog.v("%s - %s - %d%%", BATT_TAG, event, batteryLevel);
594             context.getBuildInfo(testDevice)
595                     .addBuildAttribute(
596                             String.format(
597                                     BATTERY_ATTRIBUTE_FORMAT_KEY,
598                                     testDevice.getSerialNumber(),
599                                     event),
600                             batteryLevel.toString());
601         }
602     }
603 
604     /**
605      * Invoke {@link IInvocationExecution#fetchBuild(TestInformation, IConfiguration, IRescheduler,
606      * ITestInvocationListener)} and handles the output as well as failures.
607      *
608      * @param testInfo the {@link TestInformation} of the invocation.
609      * @param config the {@link IConfiguration} of this test run.
610      * @param rescheduler the {@link IRescheduler}, for rescheduling portions of the invocation for
611      *     execution on another resource(s)
612      * @param listener the {@link ITestInvocation} to report build download failures.
613      * @param invocationPath the {@link IInvocationExecution} driving the invocation.
614      * @return True if we successfully downloaded the build, false otherwise.
615      * @throws DeviceNotAvailableException
616      */
invokeFetchBuild( TestInformation testInfo, IConfiguration config, IRescheduler rescheduler, ITestInvocationListener listener, IInvocationExecution invocationPath)617     private boolean invokeFetchBuild(
618             TestInformation testInfo,
619             IConfiguration config,
620             IRescheduler rescheduler,
621             ITestInvocationListener listener,
622             IInvocationExecution invocationPath)
623             throws DeviceNotAvailableException {
624         CurrentInvocation.setActionInProgress(ActionInProgress.FETCHING_ARTIFACTS);
625         Exception buildException = null;
626         boolean res = false;
627         try {
628             res = invocationPath.fetchBuild(testInfo, config, rescheduler, listener);
629             if (res) {
630                 // Successful fetch of build.
631                 CurrentInvocation.setActionInProgress(ActionInProgress.UNSET);
632                 return true;
633             }
634             // In case of build not found issues.
635             mStatus = "(no build to test)";
636             // Set the exit code to error
637             buildException =
638                     new BuildRetrievalError(
639                             "No build found to test.", InfraErrorIdentifier.ARTIFACT_NOT_FOUND);
640         } catch (BuildRetrievalError | RuntimeException e) {
641             buildException = e;
642         }
643         setExitCode(ExitCode.NO_BUILD, buildException);
644         // Report an empty invocation, so this error is sent to listeners
645         startInvocation(config, testInfo.getContext(), listener);
646         reportFailure(
647                 createFailureFromException(buildException, FailureStatus.INFRA_FAILURE), listener);
648         for (ITestDevice device : testInfo.getContext().getDevices()) {
649             invocationPath.reportLogs(device, listener, Stage.ERROR);
650         }
651         reportHostLog(listener, config);
652         listener.invocationEnded(0L);
653         return false;
654     }
655 
656     /**
657      * Invoke {@link IConfiguration#resolveDynamicOptions(DynamicRemoteFileResolver)} to resolve the
658      * dynamic files.
659      *
660      * @param context the {@link IInvocationContext} of the invocation.
661      * @param config the {@link IConfiguration} of this test run.
662      * @param rescheduler the {@link IRescheduler}, for rescheduling portions of the invocation for
663      *     execution on another resource(s)
664      * @param listener the {@link ITestInvocation} to report build download failures.
665      * @param invocationPath the {@link IInvocationExecution} driving the invocation.
666      * @param mode The current {@link RunMode} of the invocation.
667      * @return True if we successfully downloaded the build, false otherwise.
668      */
invokeRemoteDynamic( IInvocationContext context, IConfiguration config, IRescheduler rescheduler, ITestInvocationListener listener, IInvocationExecution invocationPath, RunMode mode)669     private boolean invokeRemoteDynamic(
670             IInvocationContext context,
671             IConfiguration config,
672             IRescheduler rescheduler,
673             ITestInvocationListener listener,
674             IInvocationExecution invocationPath,
675             RunMode mode) {
676         try {
677             // Don't resolve for remote invocation, wait until we are inside the remote.
678             if (RunMode.REMOTE_INVOCATION.equals(mode)) {
679                 return true;
680             }
681             CurrentInvocation.setActionInProgress(ActionInProgress.FETCHING_ARTIFACTS);
682             DynamicRemoteFileResolver resolver = new DynamicRemoteFileResolver();
683             resolver.setDevice(context.getDevices().get(0));
684             resolver.addExtraArgs(config.getCommandOptions().getDynamicDownloadArgs());
685             config.resolveDynamicOptions(resolver);
686             CurrentInvocation.setActionInProgress(ActionInProgress.UNSET);
687             return true;
688         } catch (RuntimeException | BuildRetrievalError | ConfigurationException e) {
689             // In case of build not found issues.
690             mStatus = "(failed dynamic download)";
691             // Set the exit code to error
692             setExitCode(ExitCode.NO_BUILD, e);
693 
694             // We don't have a reporting buildInfo at this point
695             IBuildInfo info = new BuildInfo();
696             context.addDeviceBuildInfo(context.getDeviceConfigNames().get(0), info);
697 
698             // Report an empty invocation, so this error is sent to listeners
699             startInvocation(config, context, listener);
700             reportFailure(createFailureFromException(e, FailureStatus.INFRA_FAILURE), listener);
701             for (ITestDevice device : context.getDevices()) {
702                 invocationPath.reportLogs(device, listener, Stage.ERROR);
703             }
704             reportHostLog(listener, config);
705             listener.invocationEnded(0L);
706             return false;
707         }
708     }
709 
710     /** {@inheritDoc} */
711     @Override
invoke( IInvocationContext context, IConfiguration config, IRescheduler rescheduler, ITestInvocationListener... extraListeners)712     public void invoke(
713             IInvocationContext context,
714             IConfiguration config,
715             IRescheduler rescheduler,
716             ITestInvocationListener... extraListeners)
717             throws DeviceNotAvailableException, Throwable {
718         // Handle the automated reporting
719         applyAutomatedReporters(config);
720 
721         for (ITestInvocationListener listener : extraListeners) {
722             if (listener instanceof IScheduledInvocationListener) {
723                 mSchedulerListeners.add((IScheduledInvocationListener) listener);
724             }
725         }
726         // Create the TestInformation for the invocation
727         // TODO: Use invocation-id in the workfolder name
728         Object sharedInfoObject =
729                 config.getConfigurationObject(ShardHelper.SHARED_TEST_INFORMATION);
730         TestInformation sharedTestInfo = null;
731         TestInformation info = null;
732         if (sharedInfoObject != null) {
733             sharedTestInfo = (TestInformation) sharedInfoObject;
734             // During sharding we share everything except the invocation context
735             info = TestInformation.createModuleTestInfo(sharedTestInfo, context);
736         }
737         if (info == null) {
738             File mWorkFolder = FileUtil.createTempDir("tradefed-invocation-workfolder");
739             info =
740                     TestInformation.newBuilder()
741                             .setInvocationContext(context)
742                             .setDependenciesFolder(mWorkFolder)
743                             .build();
744         }
745         CurrentInvocation.addInvocationInfo(InvocationInfo.WORK_FOLDER, info.dependenciesFolder());
746 
747         CleanUpInvocationFiles cleanUpThread = new CleanUpInvocationFiles(info, config);
748         Runtime.getRuntime().addShutdownHook(cleanUpThread);
749         registerExecutionFiles(info.executionFiles());
750 
751         List<ITestInvocationListener> allListeners =
752                 new ArrayList<>(config.getTestInvocationListeners().size() + extraListeners.length);
753         allListeners.addAll(config.getTestInvocationListeners());
754         allListeners.addAll(Arrays.asList(extraListeners));
755         ITestInvocationListener listener = null;
756 
757         // Auto retry feature
758         IRetryDecision decision = config.getRetryDecision();
759         ResultAggregator aggregator = null;
760         decision.setInvocationContext(context);
761         // We don't need the aggregator in the subprocess because the parent will take care of it.
762         if (!config.getCommandOptions()
763                         .getInvocationData()
764                         .containsKey(SubprocessTfLauncher.SUBPROCESS_TAG_NAME)
765                 && decision.isAutoRetryEnabled()
766                 && decision.getMaxRetryCount() > 1
767                 && !RetryStrategy.NO_RETRY.equals(decision.getRetryStrategy())) {
768             CLog.d("Auto-retry enabled, using the ResultAggregator to handle multiple retries.");
769             aggregator = new ResultAggregator(allListeners, decision.getRetryStrategy());
770             allListeners = Arrays.asList(aggregator);
771         }
772 
773         if (!config.getPostProcessors().isEmpty()) {
774             ITestInvocationListener forwarder = new ResultAndLogForwarder(allListeners);
775             // Post-processors are the first layer around the final reporters.
776             for (IPostProcessor postProcessor : config.getPostProcessors()) {
777                 if (postProcessor.isDisabled()) {
778                     CLog.d("%s has been disabled. skipping.", postProcessor);
779                 } else {
780                     forwarder = postProcessor.init(forwarder);
781                 }
782             }
783             listener = new LogSaverResultForwarder(config.getLogSaver(), Arrays.asList(forwarder));
784         } else {
785             listener = new LogSaverResultForwarder(config.getLogSaver(), allListeners);
786         }
787 
788         RunMode mode = RunMode.REGULAR;
789         if (config.getConfigurationDescription().shouldUseSandbox()) {
790             mode = RunMode.SANDBOX;
791         }
792         if (config.getCommandOptions().shouldUseSandboxing()) {
793             mode = RunMode.PARENT_SANDBOX;
794         }
795         if (context.getDevices().get(0) instanceof ManagedRemoteDevice) {
796             mode = RunMode.REMOTE_INVOCATION;
797         }
798         if (config.getConfigurationObject(TradefedDelegator.DELEGATE_OBJECT) != null) {
799             mode = RunMode.DELEGATED_INVOCATION;
800         }
801         IInvocationExecution invocationPath = createInvocationExec(mode);
802         updateInvocationContext(context, config);
803 
804         // Create the Guice scope
805         InvocationScope scope = getInvocationScope();
806         scope.enter();
807         // Seed our TF objects to the Guice scope
808         scope.seed(IRescheduler.class, rescheduler);
809         scope.seedConfiguration(config);
810         boolean sharding = false;
811         try {
812             ILeveledLogOutput leveledLogOutput = config.getLogOutput();
813             leveledLogOutput.init();
814             if (leveledLogOutput instanceof BaseLeveledLogOutput) {
815                 ((BaseLeveledLogOutput) leveledLogOutput).initFilters(config);
816             }
817             getLogRegistry().registerLogger(leveledLogOutput);
818             mStatus = "resolving dynamic options";
819             boolean resolverSuccess =
820                     invokeRemoteDynamic(
821                             context, config, rescheduler, listener, invocationPath, mode);
822             if (!resolverSuccess) {
823                 return;
824             }
825 
826             mStatus = "fetching build";
827             for (String deviceName : context.getDeviceConfigNames()) {
828                 context.getDevice(deviceName).clearLastConnectedWifiNetwork();
829                 context.getDevice(deviceName)
830                         .setOptions(config.getDeviceConfigByName(deviceName).getDeviceOptions());
831                 if (config.getDeviceConfigByName(deviceName)
832                         .getDeviceOptions()
833                         .isLogcatCaptureEnabled()) {
834                     if (!(context.getDevice(deviceName).getIDevice() instanceof StubDevice)) {
835                         context.getDevice(deviceName).startLogcat();
836                     }
837                 }
838             }
839 
840             String cmdLineArgs = config.getCommandLine();
841             if (cmdLineArgs != null) {
842                 CLog.i("Invocation was started with cmd: %s", cmdLineArgs);
843             }
844 
845             long start = System.currentTimeMillis();
846             boolean providerSuccess =
847                     invokeFetchBuild(info, config, rescheduler, listener, invocationPath);
848             long fetchBuildDuration = System.currentTimeMillis() - start;
849             InvocationMetricLogger.addInvocationMetrics(
850                     InvocationMetricKey.FETCH_BUILD, fetchBuildDuration);
851             CLog.d("Fetch build duration: %s", TimeUtil.formatElapsedTime(fetchBuildDuration));
852             if (!providerSuccess) {
853                 return;
854             }
855 
856             boolean deviceInit = false;
857             // If the top level invocation has --use-sandbox do not shard there. It will shard in
858             // the child invocation.
859             if (RunMode.REGULAR.equals(mode) || RunMode.SANDBOX.equals(mode)) {
860                 mStatus = "sharding";
861 
862                 // TODO: Handle local sharding and special devices
863                 Integer shardCount = config.getCommandOptions().getShardCount();
864                 Integer shardIndex = config.getCommandOptions().getShardIndex();
865                 // Special Handling in case of sharding within the same invocation (in-place): Some
866                 // devices (Remote devices for example) require extra preparation step to be
867                 // available, but sharding requires the device to be available in some cases. So
868                 // we call the device setup early to meet all the requirements.
869                 if (shardCount != null && shardIndex != null) {
870                     deviceInit = true;
871                     startInvocation(config, context, listener);
872                     try {
873                         invocationPath.runDevicePreInvocationSetup(context, config, listener);
874                     } catch (DeviceNotAvailableException | TargetSetupError e) {
875                         CLog.e(e);
876                         FailureDescription failure = FailureDescription.create(e.getMessage());
877                         failure.setCause(e).setFailureStatus(FailureStatus.INFRA_FAILURE);
878                         if (e instanceof DeviceNotAvailableException) {
879                             setExitCode(ExitCode.DEVICE_UNAVAILABLE, e);
880                         } else {
881                             setExitCode(ExitCode.THROWABLE_EXCEPTION, e);
882                         }
883                         try {
884                             invocationPath.runDevicePostInvocationTearDown(context, config, e);
885                         } finally {
886                             reportFailure(
887                                     createFailureFromException(e, FailureStatus.INFRA_FAILURE),
888                                     listener);
889                             // Reports the logs
890                             for (ITestDevice device : context.getDevices()) {
891                                 invocationPath.reportLogs(device, listener, Stage.ERROR);
892                             }
893                             reportHostLog(listener, config);
894                             listener.invocationEnded(0L);
895                         }
896                         return;
897                     }
898                 }
899 
900                 try {
901                     sharding = invocationPath.shardConfig(config, info, rescheduler, listener);
902                 } catch (RuntimeException unexpected) {
903                     if (deviceInit) {
904                         // If we did an early setup, do the tear down.
905                         invocationPath.runDevicePostInvocationTearDown(context, config, null);
906                     }
907                     throw unexpected;
908                 }
909                 if (sharding) {
910                     CLog.i(
911                             "Invocation for %s has been sharded, rescheduling",
912                             context.getSerials());
913                     // Log the chunk of parent host_log before sharding
914                     reportHostLog(listener, config, TRADEFED_LOG_NAME + BEFORE_SHARDING_SUFFIX);
915                     config.getLogSaver().invocationEnded(0L);
916                     if (aggregator != null) {
917                         // The host_log is not available yet to reporters that don't support
918                         // granular results, so forward it.
919                         aggregator.forwardAggregatedInvocationLogs();
920                     }
921                     return;
922                 }
923             }
924             // Once we have all the information we can start the invocation.
925             if (!deviceInit) {
926                 startInvocation(config, context, listener);
927             }
928             if (!RunMode.DELEGATED_INVOCATION.equals(mode)
929                     && (config.getTests() == null || config.getTests().isEmpty())) {
930                 CLog.e("No tests to run");
931                 if (deviceInit) {
932                     // If we did an early setup, do the tear down.
933                     invocationPath.runDevicePostInvocationTearDown(context, config, null);
934                 }
935                 listener.invocationEnded(0L);
936                 return;
937             }
938 
939             performInvocation(config, info, invocationPath, listener, deviceInit);
940             setExitCode(ExitCode.NO_ERROR, null);
941         } catch (IOException e) {
942             CLog.e(e);
943         } finally {
944             scope.exit();
945             // Ensure build infos are always cleaned up at the end of invocation.
946             invocationPath.cleanUpBuilds(context, config);
947             // ensure we always deregister the logger
948             for (String deviceName : context.getDeviceConfigNames()) {
949                 if (!(context.getDevice(deviceName).getIDevice() instanceof StubDevice)) {
950                     context.getDevice(deviceName).stopLogcat();
951                 }
952             }
953             if (!sharding) {
954                 // If we are the parent shard, we do not delete the test information
955                 deleteInvocationFiles(info, config);
956             }
957             // save remaining logs contents to global log
958             getLogRegistry().dumpToGlobalLog(config.getLogOutput());
959             // Ensure log is unregistered and closed
960             getLogRegistry().unregisterLogger();
961             config.getLogOutput().closeLog();
962             config.cleanConfigurationData();
963 
964             Runtime.getRuntime().removeShutdownHook(cleanUpThread);
965         }
966     }
967 
968     /** Returns the current {@link InvocationScope}. */
969     @VisibleForTesting
getInvocationScope()970     InvocationScope getInvocationScope() {
971         return InvocationScope.getDefault();
972     }
973 
974     @VisibleForTesting
registerExecutionFiles(ExecutionFiles executionFiles)975     public void registerExecutionFiles(ExecutionFiles executionFiles) {
976         CurrentInvocation.registerExecutionFiles(executionFiles);
977     }
978 
979     /**
980      * Helper to set the exit code. Exposed for testing.
981      */
setExitCode(ExitCode code, Throwable stack)982     protected void setExitCode(ExitCode code, Throwable stack) {
983         GlobalConfiguration.getInstance().getCommandScheduler()
984                 .setLastInvocationExitCode(code, stack);
985     }
986 
addInvocationMetric(InvocationMetricKey key, long value)987     protected void addInvocationMetric(InvocationMetricKey key, long value) {
988         InvocationMetricLogger.addInvocationMetrics(key, value);
989     }
990 
addInvocationMetric(InvocationMetricKey key, String value)991     protected void addInvocationMetric(InvocationMetricKey key, String value) {
992         InvocationMetricLogger.addInvocationMetrics(key, value);
993     }
994 
getDeviceLogName(Stage stage)995     public static String getDeviceLogName(Stage stage) {
996         return DEVICE_LOG_NAME_PREFIX + stage.getName();
997     }
998 
getEmulatorLogName(Stage stage)999     public static String getEmulatorLogName(Stage stage) {
1000         return EMULATOR_LOG_NAME_PREFIX + stage.getName();
1001     }
1002 
1003     @Override
notifyInvocationStopped(String message)1004     public void notifyInvocationStopped(String message) {
1005         mStopCause = message;
1006         if (mStopRequestTime == null) {
1007             mStopRequestTime = System.currentTimeMillis();
1008         }
1009     }
1010 
1011     /**
1012      * Create the invocation path that should be followed.
1013      *
1014      * @param mode The mode we are currently running as.
1015      * @return The {@link IInvocationExecution} describing the invocation.
1016      */
createInvocationExec(RunMode mode)1017     public IInvocationExecution createInvocationExec(RunMode mode) {
1018         switch (mode) {
1019             case PARENT_SANDBOX:
1020                 return new ParentSandboxInvocationExecution();
1021             case SANDBOX:
1022                 return new SandboxedInvocationExecution();
1023             case REMOTE_INVOCATION:
1024                 return new RemoteInvocationExecution();
1025             case DELEGATED_INVOCATION:
1026                 return new DelegatedInvocationExecution();
1027             default:
1028                 return new InvocationExecution();
1029         }
1030     }
1031 
1032     /** Prints a delimiter for a given Stage of the invocation. */
printStageDelimiter(Stage phase, boolean end)1033     public static void printStageDelimiter(Stage phase, boolean end) {
1034         String startEnd = end ? "ENDING" : "STARTING";
1035         String message = String.format("===== %s PHASE %s =====", phase, startEnd);
1036         PrettyPrintDelimiter.printStageDelimiter(message);
1037     }
1038 
1039     @VisibleForTesting
applyAutomatedReporters(IConfiguration config)1040     protected void applyAutomatedReporters(IConfiguration config) {
1041         AutomatedReporters autoReport = new AutomatedReporters();
1042         autoReport.applyAutomatedReporters(config);
1043     }
1044 
logExecuteShellCommand(List<ITestDevice> devices, ITestLogger logger)1045     private void logExecuteShellCommand(List<ITestDevice> devices, ITestLogger logger) {
1046         for (ITestDevice device : devices) {
1047             if (!(device instanceof NativeDevice)) {
1048                 return;
1049             }
1050             File log = ((NativeDevice) device).getExecuteShellCommandLog();
1051             if (log == null || !log.exists()) {
1052                 return;
1053             }
1054             if (log.length() == 0) {
1055                 CLog.d("executeShellCommandLog file was empty, skip logging.");
1056                 return;
1057             }
1058             try (InputStreamSource source = new FileInputStreamSource(log)) {
1059                 logger.testLog(
1060                         String.format("executeShellCommandLog_%s", device.getSerialNumber()),
1061                         LogDataType.TEXT,
1062                         source);
1063             }
1064         }
1065     }
1066 
1067     /**
1068      * Update the {@link IInvocationContext} with additional info from the {@link IConfiguration}.
1069      *
1070      * @param context the {@link IInvocationContext}
1071      * @param config the {@link IConfiguration}
1072      */
updateInvocationContext(IInvocationContext context, IConfiguration config)1073     private void updateInvocationContext(IInvocationContext context, IConfiguration config) {
1074         if (config.getCommandLine() != null) {
1075             context.addInvocationAttribute(
1076                     TestInvocation.COMMAND_ARGS_KEY, config.getCommandLine());
1077         }
1078         if (config.getCommandOptions().getShardCount() != null) {
1079             context.addInvocationAttribute(
1080                     "shard_count", config.getCommandOptions().getShardCount().toString());
1081         }
1082         if (config.getCommandOptions().getShardIndex() != null) {
1083             context.addInvocationAttribute(
1084                     "shard_index", config.getCommandOptions().getShardIndex().toString());
1085         }
1086         context.setTestTag(getTestTag(config));
1087     }
1088 
1089     /** Helper to create the test tag from the configuration. */
getTestTag(IConfiguration config)1090     private String getTestTag(IConfiguration config) {
1091         String testTag = config.getCommandOptions().getTestTag();
1092         if (config.getCommandOptions().getTestTagSuffix() != null) {
1093             testTag =
1094                     String.format("%s-%s", testTag, config.getCommandOptions().getTestTagSuffix());
1095         }
1096         return testTag;
1097     }
1098 
1099     /**
1100      * Delete the invocation files if this is the last shard for local sharding or if we are not in
1101      * a local sharding situation.
1102      */
deleteInvocationFiles(TestInformation testInfo, IConfiguration config)1103     private void deleteInvocationFiles(TestInformation testInfo, IConfiguration config) {
1104         Object obj = config.getConfigurationObject(ShardHelper.LAST_SHARD_DETECTOR);
1105         if (obj != null) {
1106             LastShardDetector lastShardDetector = (LastShardDetector) obj;
1107             if (!lastShardDetector.isLastShardDone()) {
1108                 return;
1109             }
1110         }
1111         // Delete the invocation work directory at the end
1112         FileUtil.recursiveDelete(testInfo.dependenciesFolder());
1113         // Delete all the execution files
1114         testInfo.executionFiles().clearFiles();
1115     }
1116 
handleAndLogReleaseState( IInvocationContext context, Throwable exception)1117     private Map<ITestDevice, FreeDeviceState> handleAndLogReleaseState(
1118             IInvocationContext context, Throwable exception) {
1119         // Capture the FreeDeviceState of the primary device
1120         Map<ITestDevice, FreeDeviceState> devicesStates =
1121                 CommandScheduler.createReleaseMap(context, exception);
1122         if (devicesStates.size() >= 1) {
1123             addInvocationMetric(
1124                     InvocationMetricKey.DEVICE_RELEASE_STATE,
1125                     devicesStates.values().iterator().next().toString());
1126         }
1127         int countPhysicalLost = 0;
1128         int countVirtualLost = 0;
1129         for (Entry<ITestDevice, FreeDeviceState> fds : devicesStates.entrySet()) {
1130             // TODO: Rely on the FailureStatus for lost devices instead
1131             if (fds.getKey().getIDevice() instanceof TcpDevice
1132                     && exception instanceof DeviceNotAvailableException) {
1133                 countVirtualLost++;
1134                 continue;
1135             }
1136             if (fds.getKey().getIDevice() instanceof StubDevice) {
1137                 continue;
1138             }
1139             if (FreeDeviceState.UNAVAILABLE.equals(fds.getValue())) {
1140                 countPhysicalLost++;
1141             }
1142         }
1143         if (countPhysicalLost > 0) {
1144             addInvocationMetric(InvocationMetricKey.DEVICE_LOST_DETECTED, countPhysicalLost);
1145             if (GlobalConfiguration.getDeviceManagerInstance() instanceof DeviceManager) {
1146                 String adbOutput =
1147                         ((DeviceManager) GlobalConfiguration.getDeviceManagerInstance())
1148                                 .executeGlobalAdbCommand("devices");
1149                 CLog.e("'adb devices' output:\n%s", adbOutput);
1150             }
1151         } else if (countVirtualLost > 0) {
1152             addInvocationMetric(InvocationMetricKey.VIRTUAL_DEVICE_LOST_DETECTED, countVirtualLost);
1153         }
1154         return devicesStates;
1155     }
1156 
1157     /** Helper Thread that ensures host_log is reported in case of killed JVM */
1158     private class ReportHostLog extends Thread {
1159 
1160         private ITestInvocationListener mListener;
1161         private IConfiguration mConfiguration;
1162 
ReportHostLog(ITestInvocationListener listener, IConfiguration config)1163         public ReportHostLog(ITestInvocationListener listener, IConfiguration config) {
1164             mListener = listener;
1165             mConfiguration = config;
1166         }
1167 
1168         @Override
run()1169         public void run() {
1170             // Report all the logs that always be reported anyway.
1171             reportHostLog(mListener, mConfiguration);
1172         }
1173     }
1174 
1175     /** Helper Thread to ensure invocation files are deleted in case of killed JVM */
1176     private class CleanUpInvocationFiles extends Thread {
1177 
1178         private TestInformation mTestInfo;
1179         private IConfiguration mConfig;
1180 
CleanUpInvocationFiles(TestInformation currentInfo, IConfiguration config)1181         public CleanUpInvocationFiles(TestInformation currentInfo, IConfiguration config) {
1182             mTestInfo = currentInfo;
1183             mConfig = config;
1184         }
1185 
1186         @Override
run()1187         public void run() {
1188             deleteInvocationFiles(mTestInfo, mConfig);
1189         }
1190     }
1191 }
1192