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.result.suite; 17 18 import com.android.ddmlib.Log.LogLevel; 19 import com.android.ddmlib.testrunner.TestResult.TestStatus; 20 import com.android.tradefed.invoker.IInvocationContext; 21 import com.android.tradefed.log.LogUtil.CLog; 22 import com.android.tradefed.result.CollectingTestListener; 23 import com.android.tradefed.result.TestRunResult; 24 import com.android.tradefed.result.TestSummary; 25 import com.android.tradefed.result.TestSummary.Type; 26 import com.android.tradefed.result.TestSummary.TypedString; 27 import com.android.tradefed.testtype.Abi; 28 import com.android.tradefed.testtype.IAbi; 29 import com.android.tradefed.testtype.suite.ITestSuite; 30 import com.android.tradefed.testtype.suite.ModuleDefinition; 31 import com.android.tradefed.util.AbiUtils; 32 import com.android.tradefed.util.TimeUtil; 33 34 import java.util.ArrayList; 35 import java.util.Collection; 36 import java.util.Collections; 37 import java.util.Comparator; 38 import java.util.HashMap; 39 import java.util.LinkedHashMap; 40 import java.util.List; 41 import java.util.Map; 42 import java.util.Map.Entry; 43 44 /** Collect test results for an entire suite invocation and output the final results. */ 45 public class SuiteResultReporter extends CollectingTestListener { 46 47 public static final String SUITE_REPORTER_SOURCE = SuiteResultReporter.class.getName(); 48 49 private long mStartTime = 0l; 50 private long mElapsedTime = 0l; 51 52 private int mTotalModules = 0; 53 private int mCompleteModules = 0; 54 55 private long mTotalTests = 0l; 56 private long mPassedTests = 0l; 57 private long mFailedTests = 0l; 58 private long mSkippedTests = 0l; 59 private long mAssumeFailureTests = 0l; 60 61 private Map<String, Integer> mModuleExpectedTests = new HashMap<>(); 62 private Map<String, String> mFailedModule = new HashMap<>(); 63 // Map holding the preparation time for each Module. 64 private Map<String, ModulePrepTimes> mPreparationMap = new HashMap<>(); 65 66 private Map<String, IAbi> mModuleAbi = new LinkedHashMap<>(); 67 68 private StringBuilder mSummary; 69 70 public SuiteResultReporter() { 71 super(); 72 // force aggregate true to get full metrics. 73 setIsAggregrateMetrics(true); 74 mSummary = new StringBuilder(); 75 } 76 77 @Override 78 public void invocationStarted(IInvocationContext context) { 79 super.invocationStarted(context); 80 mStartTime = System.currentTimeMillis(); 81 } 82 83 @Override 84 public void testModuleStarted(IInvocationContext moduleContext) { 85 super.testModuleStarted(moduleContext); 86 // Keep track of the module abi if it has one. 87 List<String> abiName = moduleContext.getAttributes().get(ModuleDefinition.MODULE_ABI); 88 if (abiName != null) { 89 IAbi abi = new Abi(abiName.get(0), AbiUtils.getBitness(abiName.get(0))); 90 mModuleAbi.put( 91 moduleContext.getAttributes().get(ModuleDefinition.MODULE_ID).get(0), abi); 92 } 93 } 94 95 @Override 96 public void testRunStarted(String name, int numTests) { 97 super.testRunStarted(name, numTests); 98 if (mModuleExpectedTests.get(name) == null) { 99 mModuleExpectedTests.put(name, numTests); 100 } else { 101 mModuleExpectedTests.put(name, mModuleExpectedTests.get(name) + numTests); 102 } 103 } 104 105 /** Helper to remove the module checker results from the final list of real module results. */ 106 private List<TestRunResult> extractModuleCheckers(Collection<TestRunResult> results) { 107 List<TestRunResult> moduleCheckers = new ArrayList<TestRunResult>(); 108 for (TestRunResult t : results) { 109 if (t.getName().startsWith(ITestSuite.MODULE_CHECKER_POST) 110 || t.getName().startsWith(ITestSuite.MODULE_CHECKER_PRE)) { 111 moduleCheckers.add(t); 112 } 113 } 114 results.removeAll(moduleCheckers); 115 return moduleCheckers; 116 } 117 118 @Override 119 public void invocationEnded(long elapsedTime) { 120 super.invocationEnded(elapsedTime); 121 mElapsedTime = elapsedTime; 122 123 // finalize and print results - general 124 Collection<TestRunResult> results = getRunResults(); 125 List<TestRunResult> moduleCheckers = extractModuleCheckers(results); 126 127 mTotalModules = results.size(); 128 129 for (TestRunResult moduleResult : results) { 130 if (!moduleResult.isRunFailure()) { 131 mCompleteModules++; 132 } else { 133 mFailedModule.put(moduleResult.getName(), moduleResult.getRunFailureMessage()); 134 } 135 mTotalTests += mModuleExpectedTests.get(moduleResult.getName()); 136 mPassedTests += moduleResult.getNumTestsInState(TestStatus.PASSED); 137 mFailedTests += moduleResult.getNumAllFailedTests(); 138 mSkippedTests += moduleResult.getNumTestsInState(TestStatus.IGNORED); 139 mAssumeFailureTests += moduleResult.getNumTestsInState(TestStatus.ASSUMPTION_FAILURE); 140 141 // Get the module metrics for target preparation 142 String prepTime = moduleResult.getRunMetrics().get(ModuleDefinition.PREPARATION_TIME); 143 String tearTime = moduleResult.getRunMetrics().get(ModuleDefinition.TEAR_DOWN_TIME); 144 if (prepTime != null && tearTime != null) { 145 mPreparationMap.put( 146 moduleResult.getName(), 147 new ModulePrepTimes(Long.parseLong(prepTime), Long.parseLong(tearTime))); 148 } 149 } 150 // print a short report summary 151 mSummary.append("\n============================================\n"); 152 mSummary.append("================= Results ==================\n"); 153 printModuleTestTime(results); 154 printTopSlowModules(results); 155 printPreparationMetrics(mPreparationMap); 156 printModuleCheckersMetric(moduleCheckers); 157 mSummary.append("=============== Summary ===============\n"); 158 mSummary.append( 159 String.format("Total Run time: %s\n", TimeUtil.formatElapsedTime(mElapsedTime))); 160 mSummary.append( 161 String.format("%s/%s modules completed\n", mCompleteModules, mTotalModules)); 162 if (!mFailedModule.isEmpty()) { 163 mSummary.append("Module(s) with run failure(s):\n"); 164 for (Entry<String, String> e : mFailedModule.entrySet()) { 165 mSummary.append(String.format(" %s: %s\n", e.getKey(), e.getValue())); 166 } 167 } 168 mSummary.append(String.format("Total Tests : %s\n", mTotalTests)); 169 mSummary.append(String.format("PASSED : %s\n", mPassedTests)); 170 mSummary.append(String.format("FAILED : %s\n", mFailedTests)); 171 172 if (mSkippedTests > 0l) { 173 mSummary.append(String.format("IGNORED : %s\n", mSkippedTests)); 174 } 175 if (mAssumeFailureTests > 0l) { 176 mSummary.append(String.format("ASSUMPTION_FAILURE: %s\n", mAssumeFailureTests)); 177 } 178 179 if (mCompleteModules != mTotalModules) { 180 mSummary.append( 181 "IMPORTANT: Some modules failed to run to completion, tests counts " 182 + "may be inaccurate.\n"); 183 } 184 185 for (Entry<Integer, List<String>> shard : 186 getInvocationContext().getShardsSerials().entrySet()) { 187 mSummary.append(String.format("Shard %s used: %s\n", shard.getKey(), shard.getValue())); 188 } 189 mSummary.append("============== End of Results ==============\n"); 190 mSummary.append("============================================\n"); 191 CLog.logAndDisplay(LogLevel.INFO, mSummary.toString()); 192 } 193 194 /** Displays the time consumed by each module to run. */ 195 private void printModuleTestTime(Collection<TestRunResult> results) { 196 List<TestRunResult> moduleTime = new ArrayList<>(); 197 moduleTime.addAll(results); 198 Collections.sort( 199 moduleTime, 200 new Comparator<TestRunResult>() { 201 @Override 202 public int compare(TestRunResult o1, TestRunResult o2) { 203 return (int) (o2.getElapsedTime() - o1.getElapsedTime()); 204 } 205 }); 206 long totalRunTime = 0l; 207 mSummary.append("=============== Consumed Time ==============\n"); 208 for (int i = 0; i < moduleTime.size(); i++) { 209 mSummary.append( 210 String.format( 211 " %s: %s\n", 212 moduleTime.get(i).getName(), 213 TimeUtil.formatElapsedTime(moduleTime.get(i).getElapsedTime()))); 214 totalRunTime += moduleTime.get(i).getElapsedTime(); 215 } 216 mSummary.append( 217 String.format( 218 "Total aggregated tests run time: %s\n", 219 TimeUtil.formatElapsedTime(totalRunTime))); 220 } 221 222 /** 223 * Display the average tests / second of modules because elapsed is not always relevant. (Some 224 * modules have way more test cases than others so only looking at elapsed time is not a good 225 * metric for slow modules). 226 */ 227 private void printTopSlowModules(Collection<TestRunResult> results) { 228 List<TestRunResult> moduleTime = new ArrayList<>(); 229 moduleTime.addAll(results); 230 // We don't consider module which runs in less than 5 sec. 231 for (TestRunResult t : results) { 232 if (t.getElapsedTime() < 5000) { 233 moduleTime.remove(t); 234 } 235 } 236 Collections.sort( 237 moduleTime, 238 new Comparator<TestRunResult>() { 239 @Override 240 public int compare(TestRunResult o1, TestRunResult o2) { 241 Float rate1 = ((float) o1.getNumTests() / o1.getElapsedTime()); 242 Float rate2 = ((float) o2.getNumTests() / o2.getElapsedTime()); 243 return rate1.compareTo(rate2); 244 } 245 }); 246 int maxModuleDisplay = moduleTime.size(); 247 if (maxModuleDisplay == 0) { 248 return; 249 } 250 mSummary.append( 251 String.format( 252 "============== TOP %s Slow Modules ==============\n", maxModuleDisplay)); 253 for (int i = 0; i < maxModuleDisplay; i++) { 254 mSummary.append( 255 String.format( 256 " %s: %.02f tests/sec [%s tests / %s msec]\n", 257 moduleTime.get(i).getName(), 258 (moduleTime.get(i).getNumTests() 259 / (moduleTime.get(i).getElapsedTime() / 1000f)), 260 moduleTime.get(i).getNumTests(), 261 moduleTime.get(i).getElapsedTime())); 262 } 263 } 264 265 /** Print the collected times for Module preparation and tear Down. */ 266 private void printPreparationMetrics(Map<String, ModulePrepTimes> metrics) { 267 if (metrics.isEmpty()) { 268 return; 269 } 270 mSummary.append("============== Modules Preparation Times ==============\n"); 271 long totalPrep = 0l; 272 long totalTear = 0l; 273 274 for (String moduleName : metrics.keySet()) { 275 mSummary.append( 276 String.format( 277 " %s => %s\n", moduleName, metrics.get(moduleName).toString())); 278 totalPrep += metrics.get(moduleName).mPrepTime; 279 totalTear += metrics.get(moduleName).mTearDownTime; 280 } 281 mSummary.append( 282 String.format( 283 "Total preparation time: %s || Total tear down time: %s\n", 284 TimeUtil.formatElapsedTime(totalPrep), 285 TimeUtil.formatElapsedTime(totalTear))); 286 mSummary.append("=======================================================\n"); 287 } 288 289 private void printModuleCheckersMetric(List<TestRunResult> moduleCheckerResults) { 290 if (moduleCheckerResults.isEmpty()) { 291 return; 292 } 293 mSummary.append("============== Modules Checkers Times ==============\n"); 294 long totalTime = 0l; 295 for (TestRunResult t : moduleCheckerResults) { 296 mSummary.append( 297 String.format( 298 " %s: %s\n", 299 t.getName(), TimeUtil.formatElapsedTime(t.getElapsedTime()))); 300 totalTime += t.getElapsedTime(); 301 } 302 mSummary.append( 303 String.format( 304 "Total module checkers time: %s\n", TimeUtil.formatElapsedTime(totalTime))); 305 mSummary.append("====================================================\n"); 306 } 307 308 /** Returns a map of modules abi: <module id, abi>. */ 309 public Map<String, IAbi> getModulesAbi() { 310 return mModuleAbi; 311 } 312 313 public int getTotalModules() { 314 return mTotalModules; 315 } 316 317 public int getCompleteModules() { 318 return mCompleteModules; 319 } 320 321 public long getTotalTests() { 322 return mTotalTests; 323 } 324 325 public long getPassedTests() { 326 return mPassedTests; 327 } 328 329 public long getFailedTests() { 330 return mFailedTests; 331 } 332 333 /** Object holder for the preparation and tear down time of one module. */ 334 public static class ModulePrepTimes { 335 336 public final long mPrepTime; 337 public final long mTearDownTime; 338 339 public ModulePrepTimes(long prepTime, long tearTime) { 340 mPrepTime = prepTime; 341 mTearDownTime = tearTime; 342 } 343 344 @Override 345 public String toString() { 346 return String.format("prep = %s ms || clean = %s ms", mPrepTime, mTearDownTime); 347 } 348 } 349 350 @Override 351 public TestSummary getSummary() { 352 TestSummary summary = new TestSummary(new TypedString(mSummary.toString(), Type.TEXT)); 353 summary.setSource(SUITE_REPORTER_SOURCE); 354 return summary; 355 } 356 357 /** Returns the start time of the run. */ 358 protected long getStartTime() { 359 return mStartTime; 360 } 361 362 /** Returns the elapsed time of the full run. */ 363 protected long getElapsedTime() { 364 return mElapsedTime; 365 } 366 } 367
