1 /* 2 * Copyright (C) 2020 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.testtype; 17 18 import com.android.tradefed.device.DeviceNotAvailableException; 19 import com.android.tradefed.device.ITestDevice; 20 import com.android.tradefed.device.TestDeviceState; 21 import com.android.tradefed.invoker.tracing.CloseableTraceScope; 22 import com.android.tradefed.log.LogUtil.CLog; 23 import com.android.tradefed.metrics.proto.MetricMeasurement.Metric; 24 import com.android.tradefed.result.FailureDescription; 25 import com.android.tradefed.result.ITestInvocationListener; 26 import com.android.tradefed.result.LogcatCrashResultForwarder; 27 import com.android.tradefed.result.TestDescription; 28 import com.android.tradefed.result.error.DeviceErrorIdentifier; 29 import com.android.tradefed.result.error.InfraErrorIdentifier; 30 import com.android.tradefed.result.error.TestErrorIdentifier; 31 import com.android.tradefed.result.proto.TestRecordProto.FailureStatus; 32 import com.android.tradefed.result.skipped.SkipReason; 33 import com.android.tradefed.util.ProcessInfo; 34 35 import java.util.ArrayList; 36 import java.util.Collection; 37 import java.util.HashMap; 38 import java.util.HashSet; 39 import java.util.LinkedHashSet; 40 import java.util.List; 41 import java.util.Map; 42 import java.util.Set; 43 44 /** 45 * Internal listener to Trade Federation for {@link InstrumentationTest}. It allows to collect extra 46 * information needed for easier debugging. 47 */ 48 final class InstrumentationListener extends LogcatCrashResultForwarder { 49 50 // Message from ddmlib InstrumentationResultParser for interrupted instrumentation. 51 private static final String DDMLIB_INSTRU_FAILURE_MSG = "Test run failed to complete"; 52 // Message from ddmlib for ShellCommandUnresponsiveException 53 private static final String DDMLIB_SHELL_UNRESPONSIVE = 54 "Failed to receive adb shell test output within"; 55 private static final String JUNIT4_TIMEOUT = 56 "org.junit.runners.model.TestTimedOutException: test timed out"; 57 // Message from ddmlib when there is a mismatch of test cases count 58 private static final String DDMLIB_UNEXPECTED_COUNT = "Instrumentation reported numtests="; 59 60 private Set<TestDescription> mTests = new HashSet<>(); 61 private Map<String, String> mClassAssumptionFailure = new HashMap<>(); 62 private Set<TestDescription> mDuplicateTests = new HashSet<>(); 63 private final Collection<TestDescription> mExpectedTests; 64 private boolean mDisableDuplicateCheck = false; 65 private boolean mReportUnexecutedTests = false; 66 private ProcessInfo mSystemServerProcess = null; 67 private String runLevelError = null; 68 private TestDescription mLastTest = null; 69 private TestDescription mLastStartedTest = null; 70 71 private CloseableTraceScope mMethodScope = null; 72 73 /** 74 * @param device 75 * @param listeners 76 */ InstrumentationListener( ITestDevice device, Collection<TestDescription> expectedTests, ITestInvocationListener... listeners)77 public InstrumentationListener( 78 ITestDevice device, 79 Collection<TestDescription> expectedTests, 80 ITestInvocationListener... listeners) { 81 super(device, listeners); 82 mExpectedTests = expectedTests; 83 } 84 addListener(ITestInvocationListener listener)85 public void addListener(ITestInvocationListener listener) { 86 List<ITestInvocationListener> listeners = new ArrayList<>(); 87 listeners.addAll(getListeners()); 88 listeners.add(listener); 89 setListeners(listeners); 90 } 91 92 /** Whether or not to disable the duplicate test method check. */ setDisableDuplicateCheck(boolean disable)93 public void setDisableDuplicateCheck(boolean disable) { 94 mDisableDuplicateCheck = disable; 95 } 96 setOriginalSystemServer(ProcessInfo info)97 public void setOriginalSystemServer(ProcessInfo info) { 98 mSystemServerProcess = info; 99 } 100 setReportUnexecutedTests(boolean enable)101 public void setReportUnexecutedTests(boolean enable) { 102 mReportUnexecutedTests = enable; 103 } 104 105 @Override testRunStarted(String runName, int testCount)106 public void testRunStarted(String runName, int testCount) { 107 runLevelError = null; 108 // In case of crash, run will attempt to report with 0 109 if (testCount == 0 && mExpectedTests != null && !mExpectedTests.isEmpty()) { 110 CLog.e("Run reported 0 tests while we collected %s", mExpectedTests.size()); 111 super.testRunStarted(runName, mExpectedTests.size()); 112 } else { 113 super.testRunStarted(runName, testCount); 114 } 115 } 116 117 @Override testStarted(TestDescription test, long startTime)118 public void testStarted(TestDescription test, long startTime) { 119 mMethodScope = new CloseableTraceScope(test.toString()); 120 super.testStarted(test, startTime); 121 if (!mTests.add(test)) { 122 mDuplicateTests.add(test); 123 } 124 mLastStartedTest = test; 125 } 126 127 @Override testFailed(TestDescription test, FailureDescription failure)128 public void testFailed(TestDescription test, FailureDescription failure) { 129 String message = failure.getErrorMessage(); 130 if (message.startsWith(JUNIT4_TIMEOUT) || message.contains(DDMLIB_SHELL_UNRESPONSIVE)) { 131 failure.setErrorIdentifier(TestErrorIdentifier.TEST_TIMEOUT).setRetriable(false); 132 } 133 super.testFailed(test, failure); 134 } 135 136 @Override testAssumptionFailure(TestDescription test, String trace)137 public void testAssumptionFailure(TestDescription test, String trace) { 138 if (test.getTestName().equals("null")) { 139 mClassAssumptionFailure.put(test.getClassName(), trace); 140 } else { 141 super.testAssumptionFailure(test, trace); 142 } 143 } 144 145 @Override testEnded(TestDescription test, long endTime, HashMap<String, Metric> testMetrics)146 public void testEnded(TestDescription test, long endTime, HashMap<String, Metric> testMetrics) { 147 mLastTest = test; 148 mLastStartedTest = null; 149 super.testEnded(test, endTime, testMetrics); 150 if (mMethodScope != null) { 151 mMethodScope.close(); 152 mMethodScope = null; 153 } 154 } 155 156 @Override testRunFailed(FailureDescription error)157 public void testRunFailed(FailureDescription error) { 158 if (error.getErrorMessage().startsWith(DDMLIB_INSTRU_FAILURE_MSG)) { 159 if (mExpectedTests != null) { 160 Set<TestDescription> expected = new LinkedHashSet<>(mExpectedTests); 161 expected.removeAll(mTests); 162 String helpMessage = String.format("The following tests didn't run: %s", expected); 163 error.setDebugHelpMessage(helpMessage); 164 } 165 error.setFailureStatus(FailureStatus.TEST_FAILURE); 166 String wrapMessage = error.getErrorMessage(); 167 boolean restarted = false; 168 if (mSystemServerProcess != null) { 169 try { 170 restarted = getDevice().deviceSoftRestarted(mSystemServerProcess); 171 } catch (DeviceNotAvailableException e) { 172 // Ignore 173 } 174 if (restarted) { 175 error.setFailureStatus(FailureStatus.SYSTEM_UNDER_TEST_CRASHED); 176 error.setErrorIdentifier(DeviceErrorIdentifier.DEVICE_CRASHED); 177 wrapMessage = 178 String.format( 179 "Detected system_server restart causing instrumentation error:" 180 + " %s", 181 error.getErrorMessage()); 182 } 183 } 184 if (!restarted && !TestDeviceState.ONLINE.equals(getDevice().getDeviceState())) { 185 error.setErrorIdentifier(DeviceErrorIdentifier.ADB_DISCONNECT); 186 wrapMessage = 187 String.format( 188 "Detected device offline causing instrumentation error: %s", 189 error.getErrorMessage()); 190 } 191 error.setErrorMessage(wrapMessage); 192 } else if (error.getErrorMessage().startsWith(DDMLIB_SHELL_UNRESPONSIVE)) { 193 String wrapMessage = "Instrumentation ran for longer than the configured timeout."; 194 if (mLastStartedTest != null) { 195 wrapMessage += String.format(" The last started but unfinished test was: %s.", 196 mLastStartedTest.toString()); 197 } 198 CLog.w("ddmlib reported error: %s.", error.getErrorMessage()); 199 error.setErrorMessage(wrapMessage); 200 error.setFailureStatus(FailureStatus.TIMED_OUT); 201 error.setErrorIdentifier(TestErrorIdentifier.INSTRUMENTATION_TIMED_OUT); 202 } else if (error.getErrorMessage().startsWith(DDMLIB_UNEXPECTED_COUNT)) { 203 error.setFailureStatus(FailureStatus.TEST_FAILURE); 204 error.setErrorIdentifier(InfraErrorIdentifier.EXPECTED_TESTS_MISMATCH); 205 } 206 // Use error before injecting the crashes 207 runLevelError = error.getErrorMessage(); 208 super.testRunFailed(error); 209 } 210 211 @Override testRunEnded(long elapsedTime, HashMap<String, Metric> runMetrics)212 public void testRunEnded(long elapsedTime, HashMap<String, Metric> runMetrics) { 213 if (!mDuplicateTests.isEmpty() && !mDisableDuplicateCheck) { 214 FailureDescription error = 215 FailureDescription.create( 216 String.format( 217 "The following tests ran more than once: %s. Check " 218 + "your run configuration, you might be " 219 + "including the same test class several " 220 + "times.", 221 mDuplicateTests)); 222 error.setFailureStatus(FailureStatus.TEST_FAILURE) 223 .setRetriable(false); // Don't retry duplicate tests. 224 super.testRunFailed(error); 225 } else if (mReportUnexecutedTests 226 && mExpectedTests != null 227 && (mExpectedTests.size() > mTests.size() || !mExpectedTests.isEmpty())) { 228 Set<TestDescription> missingTests = new LinkedHashSet<>(mExpectedTests); 229 missingTests.removeAll(mTests); 230 231 TestDescription lastTest = mLastTest; 232 String lastExecutedLog = ""; 233 if (lastTest != null) { 234 lastExecutedLog = "Last executed test was " + lastTest.toString() + "."; 235 } 236 if (runLevelError == null) { 237 runLevelError = "Method was expected to run but didn't."; 238 } else { 239 runLevelError = 240 String.format("Run level error reported reason: '%s", runLevelError); 241 } 242 for (TestDescription miss : missingTests) { 243 super.testStarted(miss); 244 if (mClassAssumptionFailure.containsKey(miss.getClassName())) { 245 super.testAssumptionFailure( 246 miss, mClassAssumptionFailure.get(miss.getClassName())); 247 } else { 248 SkipReason reason = 249 new SkipReason( 250 String.format( 251 "Test did not run due to instrumentation issue. %s %s", 252 lastExecutedLog, runLevelError), 253 "INSTRUMENTATION_ERROR"); 254 super.testSkipped(miss, reason); 255 } 256 super.testEnded(miss, new HashMap<String, Metric>()); 257 } 258 } 259 runLevelError = null; 260 mClassAssumptionFailure = new HashMap<String, String>(); 261 super.testRunEnded(elapsedTime, runMetrics); 262 } 263 } 264