1 /* 2 * Copyright (C) 2022 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.bazel; 17 18 import com.android.annotations.VisibleForTesting; 19 import com.android.tradefed.config.ConfigurationDescriptor; 20 import com.android.tradefed.config.Option; 21 import com.android.tradefed.config.OptionClass; 22 import com.android.tradefed.device.DeviceNotAvailableException; 23 import com.android.tradefed.invoker.IInvocationContext; 24 import com.android.tradefed.invoker.InvocationContext; 25 import com.android.tradefed.invoker.TestInformation; 26 import com.android.tradefed.invoker.logger.InvocationMetricLogger; 27 import com.android.tradefed.invoker.logger.InvocationMetricLogger.InvocationMetricKey; 28 import com.android.tradefed.invoker.tracing.CloseableTraceScope; 29 import com.android.tradefed.invoker.tracing.TracePropagatingExecutorService; 30 import com.android.tradefed.log.ITestLogger; 31 import com.android.tradefed.log.LogUtil.CLog; 32 import com.android.tradefed.result.FailureDescription; 33 import com.android.tradefed.result.FileInputStreamSource; 34 import com.android.tradefed.result.ITestInvocationListener; 35 import com.android.tradefed.result.LogDataType; 36 import com.android.tradefed.result.error.ErrorIdentifier; 37 import com.android.tradefed.result.error.TestErrorIdentifier; 38 import com.android.tradefed.result.proto.ProtoResultParser; 39 import com.android.tradefed.result.proto.TestRecordProto.FailureStatus; 40 import com.android.tradefed.result.proto.TestRecordProto.TestRecord; 41 import com.android.tradefed.testtype.IRemoteTest; 42 import com.android.tradefed.util.AbiUtils; 43 import com.android.tradefed.util.ZipUtil; 44 import com.android.tradefed.util.proto.TestRecordProtoUtil; 45 46 import com.google.common.collect.BiMap; 47 import com.google.common.collect.HashBiMap; 48 import com.google.common.collect.HashMultimap; 49 import com.google.common.collect.ImmutableBiMap; 50 import com.google.common.collect.Maps; 51 import com.google.common.collect.SetMultimap; 52 import com.google.common.io.CharStreams; 53 import com.google.common.io.MoreFiles; 54 import com.google.common.io.Resources; 55 import com.google.devtools.build.lib.buildeventstream.BuildEventStreamProtos; 56 import com.google.protobuf.InvalidProtocolBufferException; 57 58 import java.io.File; 59 import java.io.FileWriter; 60 import java.io.IOException; 61 import java.io.FileOutputStream; 62 import java.lang.ProcessBuilder.Redirect; 63 import java.net.URI; 64 import java.net.URISyntaxException; 65 import java.nio.file.Files; 66 import java.nio.file.Path; 67 import java.nio.file.Paths; 68 import java.time.Duration; 69 import java.util.ArrayList; 70 import java.util.Collection; 71 import java.util.Collections; 72 import java.util.List; 73 import java.util.Map.Entry; 74 import java.util.Map; 75 import java.util.Properties; 76 import java.util.Set; 77 import java.util.concurrent.ExecutorService; 78 import java.util.concurrent.Executors; 79 import java.util.concurrent.TimeUnit; 80 import java.util.function.Consumer; 81 import java.util.stream.Collectors; 82 import java.util.stream.Stream; 83 import java.util.zip.ZipFile; 84 85 /** Test runner for executing Bazel tests. */ 86 @OptionClass(alias = "bazel-test") 87 public final class BazelTest implements IRemoteTest { 88 89 public static final String QUERY_ALL_TARGETS = "query_all_targets"; 90 public static final String QUERY_MAP_MODULES_TO_TARGETS = "query_map_modules_to_targets"; 91 public static final String RUN_TESTS = "run_tests"; 92 public static final String BUILD_TEST_ARG = "bazel-build"; 93 public static final String TEST_TAG_TEST_ARG = "bazel-test"; 94 public static final String BRANCH_TEST_ARG = "bazel-branch"; 95 public static final int BAZEL_TESTS_FAILED_RETURN_CODE = 3; 96 97 // Add method excludes to TF's global filters since Bazel doesn't support target-specific 98 // arguments. See https://github.com/bazelbuild/rules_go/issues/2784. 99 // TODO(b/274787592): Integrate with Bazel's test filtering to filter specific test cases. 100 public static final String GLOBAL_EXCLUDE_FILTER_TEMPLATE = 101 "--test_arg=--global-filters:exclude-filter=%s"; 102 103 private static final Duration BAZEL_QUERY_TIMEOUT = Duration.ofMinutes(5); 104 private static final String TEST_NAME = BazelTest.class.getName(); 105 // Bazel internally calls the test output archive file "test.outputs__outputs.zip", the double 106 // underscore is part of this name. 107 private static final String TEST_UNDECLARED_OUTPUTS_ARCHIVE_NAME = "test.outputs__outputs.zip"; 108 private static final String PROTO_RESULTS_FILE_NAME = "proto-results"; 109 110 private final List<Path> mTemporaryPaths = new ArrayList<>(); 111 private final List<LogFileWithType> mLogFiles = new ArrayList<>(); 112 private final Properties mProperties; 113 private final ProcessStarter mProcessStarter; 114 private final Path mTemporaryDirectory; 115 private final ExecutorService mExecutor; 116 117 private Path mRunTemporaryDirectory; 118 private Path mBazelOutputRoot; 119 private Path mJavaTempOutput; 120 121 private enum FilterType { 122 MODULE, 123 TEST_CASE 124 }; 125 126 @Option( 127 name = "bazel-test-command-timeout", 128 description = "Timeout for running the Bazel test.") 129 private Duration mBazelCommandTimeout = Duration.ofHours(1L); 130 131 @Option( 132 name = "bazel-test-suite-root-dir", 133 description = 134 "Name of the environment variable set by CtsTestLauncher indicating the" 135 + " location of the root bazel-test-suite dir.") 136 private String mSuiteRootDirEnvVar = "BAZEL_SUITE_ROOT"; 137 138 @Option( 139 name = "bazel-startup-options", 140 description = "List of startup options to be passed to Bazel.") 141 private final List<String> mBazelStartupOptions = new ArrayList<>(); 142 143 @Option( 144 name = "bazel-test-extra-args", 145 description = "List of extra arguments to be passed to Bazel") 146 private final List<String> mBazelTestExtraArgs = new ArrayList<>(); 147 148 @Option( 149 name = "bazel-max-idle-timout", 150 description = "Max idle timeout in seconds for bazel commands.") 151 private Duration mBazelMaxIdleTimeout = Duration.ofSeconds(30L); 152 153 @Option(name = "exclude-filter", description = "Test modules to exclude when running tests.") 154 private final List<String> mExcludeTargets = new ArrayList<>(); 155 156 @Option(name = "include-filter", description = "Test modules to include when running tests.") 157 private final List<String> mIncludeTargets = new ArrayList<>(); 158 159 @Option( 160 name = "bazel-query", 161 description = "Bazel query to return list of tests, defaults to all deviceless tests") 162 private String mBazelQuery = "kind(tradefed_deviceless_test, tests(//...))"; 163 164 @Option( 165 name = "report-cached-test-results", 166 description = "Whether or not to report cached test results.") 167 private boolean mReportCachedTestResults = true; 168 169 @Option( 170 name = "report-cached-modules-sparsely", 171 description = "Whether to only report module level events for cached test modules.") 172 private boolean mReportCachedModulesSparsely = false; 173 BazelTest()174 public BazelTest() { 175 this(new DefaultProcessStarter(), System.getProperties()); 176 } 177 178 @VisibleForTesting BazelTest(ProcessStarter processStarter, Properties properties)179 BazelTest(ProcessStarter processStarter, Properties properties) { 180 mProcessStarter = processStarter; 181 mExecutor = TracePropagatingExecutorService.create(Executors.newCachedThreadPool()); 182 mProperties = properties; 183 mTemporaryDirectory = Paths.get(properties.getProperty("java.io.tmpdir")); 184 } 185 186 @Override run(TestInformation testInfo, ITestInvocationListener listener)187 public void run(TestInformation testInfo, ITestInvocationListener listener) 188 throws DeviceNotAvailableException { 189 190 List<FailureDescription> runFailures = new ArrayList<>(); 191 long startTime = System.currentTimeMillis(); 192 RunStats stats = new RunStats(); 193 194 try { 195 initialize(); 196 logWorkspaceContents(); 197 runTestsAndParseResults(testInfo, listener, runFailures, stats); 198 } catch (AbortRunException e) { 199 runFailures.add(e.getFailureDescription()); 200 } catch (IOException | InterruptedException e) { 201 runFailures.add(throwableToTestFailureDescription(e)); 202 } 203 204 listener.testModuleStarted(testInfo.getContext()); 205 listener.testRunStarted(TEST_NAME, 0); 206 reportRunFailures(runFailures, listener); 207 listener.testRunEnded(System.currentTimeMillis() - startTime, Collections.emptyMap()); 208 listener.testModuleEnded(); 209 210 addTestLogs(listener); 211 stats.addInvocationAttributes(testInfo.getContext()); 212 cleanup(); 213 } 214 initialize()215 private void initialize() throws IOException { 216 mRunTemporaryDirectory = Files.createTempDirectory(mTemporaryDirectory, "bazel-test-"); 217 mBazelOutputRoot = createTemporaryDirectory("java-tmp-out"); 218 mJavaTempOutput = createTemporaryDirectory("bazel-tmp-out"); 219 } 220 logWorkspaceContents()221 private void logWorkspaceContents() throws IOException { 222 Path workspaceDirectory = resolveWorkspacePath(); 223 224 try (Stream<String> files = 225 Files.walk(workspaceDirectory) 226 .filter(Files::isRegularFile) 227 .map(x -> workspaceDirectory.relativize(x).toString())) { 228 229 Path outputFile = createLogFile("workspace-contents"); 230 try (FileWriter writer = new FileWriter(outputFile.toAbsolutePath().toString())) { 231 for (String file : (Iterable<String>) () -> files.iterator()) { 232 writer.write(file); 233 writer.write(System.lineSeparator()); 234 } 235 } 236 } 237 } 238 runTestsAndParseResults( TestInformation testInfo, ITestInvocationListener listener, List<FailureDescription> runFailures, RunStats stats)239 private void runTestsAndParseResults( 240 TestInformation testInfo, 241 ITestInvocationListener listener, 242 List<FailureDescription> runFailures, 243 RunStats stats) 244 throws IOException, InterruptedException { 245 246 Path workspaceDirectory = resolveWorkspacePath(); 247 248 BiMap<String, String> modulesToTargets = listTestModulesToTargets(workspaceDirectory); 249 if (modulesToTargets.isEmpty()) { 250 throw new AbortRunException( 251 "No targets found, aborting", 252 FailureStatus.DEPENDENCY_ISSUE, 253 TestErrorIdentifier.TEST_ABORTED); 254 } 255 256 Path bepFile = createTemporaryFile("BEP_output"); 257 258 Process bazelTestProcess = 259 startTests(testInfo, modulesToTargets.values(), workspaceDirectory, bepFile); 260 261 try (BepFileTailer tailer = BepFileTailer.create(bepFile)) { 262 bazelTestProcess.onExit().thenRun(() -> tailer.stop()); 263 reportTestResults(listener, testInfo, runFailures, tailer, stats, modulesToTargets); 264 } 265 266 // Note that if Bazel exits without writing the 'last' BEP message marker we won't get to 267 // here since the above reporting code throws. 268 int bazelTestExitCode = bazelTestProcess.waitFor(); 269 270 // TODO(b/296923373): If there is any parsing issue for a specific module consider reporting 271 // a generic module failure for that module. 272 if (bazelTestExitCode == BAZEL_TESTS_FAILED_RETURN_CODE) { 273 CLog.w("Bazel exited with exit code: %d, some tests failed.", bazelTestExitCode); 274 return; 275 } 276 277 if (bazelTestExitCode == 0) { 278 return; 279 } 280 281 throw new AbortRunException( 282 String.format("%s command failed. Exit code: %d", RUN_TESTS, bazelTestExitCode), 283 FailureStatus.DEPENDENCY_ISSUE, 284 TestErrorIdentifier.TEST_ABORTED); 285 } 286 reportTestResults( ITestInvocationListener listener, TestInformation testInfo, List<FailureDescription> runFailures, BepFileTailer tailer, RunStats stats, BiMap<String, String> modulesToTargets)287 void reportTestResults( 288 ITestInvocationListener listener, 289 TestInformation testInfo, 290 List<FailureDescription> runFailures, 291 BepFileTailer tailer, 292 RunStats stats, 293 BiMap<String, String> modulesToTargets) 294 throws InterruptedException, IOException { 295 296 try (CloseableTraceScope ignored = new CloseableTraceScope("reportTestResults")) { 297 reportTestResultsNoTrace( 298 listener, testInfo, runFailures, tailer, stats, modulesToTargets); 299 } 300 } 301 reportTestResultsNoTrace( ITestInvocationListener listener, TestInformation testInfo, List<FailureDescription> runFailures, BepFileTailer tailer, RunStats stats, BiMap<String, String> modulesToTargets)302 void reportTestResultsNoTrace( 303 ITestInvocationListener listener, 304 TestInformation testInfo, 305 List<FailureDescription> runFailures, 306 BepFileTailer tailer, 307 RunStats stats, 308 BiMap<String, String> modulesToTargets) 309 throws InterruptedException, IOException { 310 311 BuildEventStreamProtos.BuildEvent event; 312 while ((event = tailer.nextEvent()) != null) { 313 if (event.getLastMessage()) { 314 return; 315 } 316 317 if (!event.hasTestResult()) { 318 continue; 319 } 320 321 stats.addTestResult(event.getTestResult()); 322 323 if (!mReportCachedTestResults && isTestResultCached(event.getTestResult())) { 324 continue; 325 } 326 327 try { 328 reportEventsInTestOutputsArchive( 329 event, listener, testInfo.getContext(), modulesToTargets); 330 } catch (IOException 331 | InterruptedException 332 | URISyntaxException 333 | IllegalArgumentException e) { 334 runFailures.add( 335 throwableToInfraFailureDescription(e) 336 .setErrorIdentifier(TestErrorIdentifier.OUTPUT_PARSER_ERROR)); 337 } 338 } 339 340 throw new AbortRunException( 341 "Unexpectedly hit end of BEP file without receiving last message", 342 FailureStatus.INFRA_FAILURE, 343 TestErrorIdentifier.OUTPUT_PARSER_ERROR); 344 } 345 isTestResultCached(BuildEventStreamProtos.TestResult result)346 private static boolean isTestResultCached(BuildEventStreamProtos.TestResult result) { 347 return result.getCachedLocally() || result.getExecutionInfo().getCachedRemotely(); 348 } 349 createBazelCommand(Path workspaceDirectory, String tmpDirPrefix)350 private ProcessBuilder createBazelCommand(Path workspaceDirectory, String tmpDirPrefix) 351 throws IOException { 352 353 List<String> command = new ArrayList<>(); 354 355 command.add(workspaceDirectory.resolve("bazel.sh").toAbsolutePath().toString()); 356 command.add( 357 "--host_jvm_args=-Djava.io.tmpdir=%s" 358 .formatted(mJavaTempOutput.toAbsolutePath().toString())); 359 command.add( 360 "--output_user_root=%s".formatted(mBazelOutputRoot.toAbsolutePath().toString())); 361 command.add("--max_idle_secs=%d".formatted(mBazelMaxIdleTimeout.toSeconds())); 362 363 ProcessBuilder builder = new ProcessBuilder(command); 364 365 builder.directory(workspaceDirectory.toFile()); 366 367 return builder; 368 } 369 listTestModulesToTargets(Path workspaceDirectory)370 private BiMap<String, String> listTestModulesToTargets(Path workspaceDirectory) 371 throws IOException, InterruptedException { 372 373 try (CloseableTraceScope ignored = new CloseableTraceScope("listTestModulesToTargets")) { 374 return listTestModulesToTargetsNoTrace(workspaceDirectory); 375 } 376 } 377 listTestModulesToTargetsNoTrace(Path workspaceDirectory)378 private BiMap<String, String> listTestModulesToTargetsNoTrace(Path workspaceDirectory) 379 throws IOException, InterruptedException { 380 381 // We need to query all tests targets first in a separate Bazel query call since 'cquery 382 // tests(...)' doesn't work in the Atest Bazel workspace. 383 List<String> allTestTargets = queryAllTestTargets(workspaceDirectory); 384 CLog.i("Found %d test targets in workspace", allTestTargets.size()); 385 386 BiMap<String, String> moduleToTarget = 387 queryModulesToTestTargets(workspaceDirectory, allTestTargets); 388 389 Set<String> moduleExcludes = groupTargetsByType(mExcludeTargets).get(FilterType.MODULE); 390 Set<String> moduleIncludes = groupTargetsByType(mIncludeTargets).get(FilterType.MODULE); 391 392 if (!moduleIncludes.isEmpty() && !moduleExcludes.isEmpty()) { 393 throw new AbortRunException( 394 "Invalid options: cannot set both module-level include filters and module-level" 395 + " exclude filters.", 396 FailureStatus.DEPENDENCY_ISSUE, 397 TestErrorIdentifier.TEST_ABORTED); 398 } 399 400 if (!moduleIncludes.isEmpty()) { 401 return Maps.filterKeys(moduleToTarget, s -> moduleIncludes.contains(s)); 402 } 403 404 if (!moduleExcludes.isEmpty()) { 405 return Maps.filterKeys(moduleToTarget, s -> !moduleExcludes.contains(s)); 406 } 407 408 return moduleToTarget; 409 } 410 queryAllTestTargets(Path workspaceDirectory)411 private List<String> queryAllTestTargets(Path workspaceDirectory) 412 throws IOException, InterruptedException { 413 414 Path logFile = createLogFile("%s-log".formatted(QUERY_ALL_TARGETS)); 415 416 ProcessBuilder builder = createBazelCommand(workspaceDirectory, QUERY_ALL_TARGETS); 417 418 builder.command().add("query"); 419 builder.command().add(mBazelQuery); 420 421 builder.redirectError(Redirect.appendTo(logFile.toFile())); 422 423 Process queryProcess = startProcess(QUERY_ALL_TARGETS, builder, BAZEL_QUERY_TIMEOUT); 424 List<String> queryLines = readProcessLines(queryProcess); 425 426 waitForSuccessfulProcess(queryProcess, QUERY_ALL_TARGETS); 427 428 return queryLines; 429 } 430 queryModulesToTestTargets( Path workspaceDirectory, List<String> allTestTargets)431 private BiMap<String, String> queryModulesToTestTargets( 432 Path workspaceDirectory, List<String> allTestTargets) 433 throws IOException, InterruptedException { 434 435 Path cqueryTestTargetsFile = createTemporaryFile("test_targets"); 436 Files.write(cqueryTestTargetsFile, String.join("+", allTestTargets).getBytes()); 437 438 Path cqueryFormatFile = createTemporaryFile("format_module_name_to_test_target"); 439 try (FileOutputStream os = new FileOutputStream(cqueryFormatFile.toFile())) { 440 Resources.copy( 441 Resources.getResource("config/format_module_name_to_test_target.cquery"), os); 442 } 443 444 Path logFile = createLogFile("%s-log".formatted(QUERY_MAP_MODULES_TO_TARGETS)); 445 ProcessBuilder builder = 446 createBazelCommand(workspaceDirectory, QUERY_MAP_MODULES_TO_TARGETS); 447 448 builder.command().add("cquery"); 449 builder.command().add("--query_file=%s".formatted(cqueryTestTargetsFile.toAbsolutePath())); 450 builder.command().add("--output=starlark"); 451 builder.command().add("--starlark:file=%s".formatted(cqueryFormatFile.toAbsolutePath())); 452 builder.redirectError(Redirect.appendTo(logFile.toFile())); 453 454 Process process = startProcess(QUERY_MAP_MODULES_TO_TARGETS, builder, BAZEL_QUERY_TIMEOUT); 455 456 List<String> queryLines = readProcessLines(process); 457 458 waitForSuccessfulProcess(process, QUERY_MAP_MODULES_TO_TARGETS); 459 460 return parseModulesToTargets(queryLines); 461 } 462 readProcessLines(Process process)463 private List<String> readProcessLines(Process process) throws IOException { 464 return CharStreams.readLines(process.inputReader()); 465 } 466 parseModulesToTargets(Collection<String> lines)467 private BiMap<String, String> parseModulesToTargets(Collection<String> lines) { 468 BiMap<String, String> moduleToTarget = HashBiMap.create(lines.size()); 469 StringBuilder errorMessage = new StringBuilder(); 470 for (String line : lines) { 471 // Query output format is: "module_name //bazel/test:target" if a test target is a 472 // TF test, "" otherwise, so only count proper targets. 473 if (line.isEmpty()) { 474 continue; 475 } 476 477 String[] splitLine = line.split(" "); 478 479 if (splitLine.length != 2) { 480 throw new AbortRunException( 481 String.format( 482 "Unrecognized output from %s command: %s", 483 QUERY_MAP_MODULES_TO_TARGETS, line), 484 FailureStatus.DEPENDENCY_ISSUE, 485 TestErrorIdentifier.TEST_ABORTED); 486 } 487 488 String moduleName = splitLine[0]; 489 String targetName = splitLine[1]; 490 491 String duplicateEntry; 492 if ((duplicateEntry = moduleToTarget.get(moduleName)) != null) { 493 errorMessage.append( 494 "Multiple test targets found for module %s: %s, %s\n" 495 .formatted(moduleName, duplicateEntry, targetName)); 496 continue; 497 } 498 499 moduleToTarget.put(moduleName, targetName); 500 } 501 502 if (errorMessage.length() != 0) { 503 throw new AbortRunException( 504 errorMessage.toString(), 505 FailureStatus.DEPENDENCY_ISSUE, 506 TestErrorIdentifier.TEST_ABORTED); 507 } 508 return ImmutableBiMap.copyOf(moduleToTarget); 509 } 510 startTests( TestInformation testInfo, Collection<String> testTargets, Path workspaceDirectory, Path bepFile)511 private Process startTests( 512 TestInformation testInfo, 513 Collection<String> testTargets, 514 Path workspaceDirectory, 515 Path bepFile) 516 throws IOException { 517 518 Path logFile = createLogFile("%s-log".formatted(RUN_TESTS)); 519 Path bazelTraceFile = createLogFile("bazel-trace", ".perfetto-trace", LogDataType.PERFETTO); 520 521 ProcessBuilder builder = createBazelCommand(workspaceDirectory, RUN_TESTS); 522 523 builder.command().addAll(mBazelStartupOptions); 524 builder.command().add("test"); 525 builder.command().addAll(testTargets); 526 527 builder.command().add("--build_event_binary_file=%s".formatted(bepFile.toAbsolutePath())); 528 529 builder.command().add("--generate_json_trace_profile"); 530 builder.command().add("--profile=%s".formatted(bazelTraceFile.toAbsolutePath().toString())); 531 532 builder.command().add("--test_arg=--test-tag=%s".formatted(TEST_TAG_TEST_ARG)); 533 builder.command().add("--test_arg=--build-id=%s".formatted(BUILD_TEST_ARG)); 534 builder.command().add("--test_arg=--branch=%s".formatted(BRANCH_TEST_ARG)); 535 536 builder.command().addAll(mBazelTestExtraArgs); 537 538 Set<String> testFilters = groupTargetsByType(mExcludeTargets).get(FilterType.TEST_CASE); 539 for (String test : testFilters) { 540 builder.command().add(GLOBAL_EXCLUDE_FILTER_TEMPLATE.formatted(test)); 541 } 542 builder.redirectErrorStream(true); 543 builder.redirectOutput(Redirect.appendTo(logFile.toFile())); 544 545 return startProcess(RUN_TESTS, builder, mBazelCommandTimeout); 546 } 547 groupTargetsByType(List<String> targets)548 private static SetMultimap<FilterType, String> groupTargetsByType(List<String> targets) { 549 Map<FilterType, List<String>> groupedMap = 550 targets.stream() 551 .collect( 552 Collectors.groupingBy( 553 s -> 554 s.contains(" ") 555 ? FilterType.TEST_CASE 556 : FilterType.MODULE)); 557 558 SetMultimap<FilterType, String> groupedMultiMap = HashMultimap.create(); 559 for (Entry<FilterType, List<String>> entry : groupedMap.entrySet()) { 560 groupedMultiMap.putAll(entry.getKey(), entry.getValue()); 561 } 562 563 return groupedMultiMap; 564 } 565 startAndWaitForSuccessfulProcess( String processTag, ProcessBuilder builder, Duration processTimeout)566 private Process startAndWaitForSuccessfulProcess( 567 String processTag, ProcessBuilder builder, Duration processTimeout) 568 throws InterruptedException, IOException { 569 570 Process process = startProcess(processTag, builder, processTimeout); 571 waitForSuccessfulProcess(process, processTag); 572 return process; 573 } 574 startProcess(String processTag, ProcessBuilder builder, Duration timeout)575 private Process startProcess(String processTag, ProcessBuilder builder, Duration timeout) 576 throws IOException { 577 578 CLog.i("Running command for %s: %s", processTag, new ProcessDebugString(builder)); 579 String traceTag = "Process:" + processTag; 580 Process process = mProcessStarter.start(processTag, builder); 581 582 // We wait for the process in a separate thread so that we can trace its execution time. 583 // Another alternative could be to start/stop tracing with explicit calls but these would 584 // have to be done on the same thread as required by the tracing facility. 585 mExecutor.submit( 586 () -> { 587 try (CloseableTraceScope unused = new CloseableTraceScope(traceTag)) { 588 if (waitForProcessUninterruptibly(process, timeout)) { 589 return; 590 } 591 592 CLog.e("%s command timed out and is being destroyed", processTag); 593 process.destroy(); 594 595 // Give the process a grace period to properly shut down before forcibly 596 // terminating it. We _could_ deduct this time from the total timeout but 597 // it's overkill. 598 if (!waitForProcessUninterruptibly(process, Duration.ofSeconds(5))) { 599 CLog.w( 600 "%s command did not terminate normally after the grace period" 601 + " and is being forcibly destroyed", 602 processTag); 603 process.destroyForcibly(); 604 } 605 606 // We wait for the process as it may take it some time to terminate and 607 // otherwise skew the trace results. 608 waitForProcessUninterruptibly(process); 609 CLog.i("%s command timed out and was destroyed", processTag); 610 } 611 }); 612 613 return process; 614 } 615 waitForSuccessfulProcess(Process process, String processTag)616 private void waitForSuccessfulProcess(Process process, String processTag) 617 throws InterruptedException { 618 619 if (process.waitFor() == 0) { 620 return; 621 } 622 623 throw new AbortRunException( 624 String.format("%s command failed. Exit code: %d", processTag, process.exitValue()), 625 FailureStatus.DEPENDENCY_ISSUE, 626 TestErrorIdentifier.TEST_ABORTED); 627 } 628 reportEventsInTestOutputsArchive( BuildEventStreamProtos.BuildEvent event, ITestInvocationListener listener, IInvocationContext context, BiMap<String, String> modulesToTargets)629 private void reportEventsInTestOutputsArchive( 630 BuildEventStreamProtos.BuildEvent event, 631 ITestInvocationListener listener, 632 IInvocationContext context, 633 BiMap<String, String> modulesToTargets) 634 throws IOException, InvalidProtocolBufferException, InterruptedException, 635 URISyntaxException { 636 637 try (CloseableTraceScope ignored = 638 new CloseableTraceScope("reportEventsInTestOutputsArchive")) { 639 reportEventsInTestOutputsArchiveNoTrace(event, listener, context, modulesToTargets); 640 } 641 } 642 reportEventsInTestOutputsArchiveNoTrace( BuildEventStreamProtos.BuildEvent event, ITestInvocationListener listener, IInvocationContext context, BiMap<String, String> modulesToTargets)643 private void reportEventsInTestOutputsArchiveNoTrace( 644 BuildEventStreamProtos.BuildEvent event, 645 ITestInvocationListener listener, 646 IInvocationContext context, 647 BiMap<String, String> modulesToTargets) 648 throws IOException, InvalidProtocolBufferException, InterruptedException, 649 URISyntaxException { 650 651 BuildEventStreamProtos.TestResult result = event.getTestResult(); 652 BuildEventStreamProtos.File outputsFile = 653 result.getTestActionOutputList().stream() 654 .filter(file -> file.getName().equals(TEST_UNDECLARED_OUTPUTS_ARCHIVE_NAME)) 655 .findAny() 656 .orElseThrow(() -> new IOException("No test output archive found")); 657 658 URI uri = new URI(outputsFile.getUri()); 659 660 File zipFile = new File(uri.getPath()); 661 Path outputFilesDir = Files.createTempDirectory(mRunTemporaryDirectory, "output_zip-"); 662 Path delimiter = Paths.get(BRANCH_TEST_ARG, BUILD_TEST_ARG, TEST_TAG_TEST_ARG); 663 listener = new LogPathUpdatingListener(listener, delimiter, outputFilesDir); 664 665 try { 666 String filePrefix = "tf-test-process-"; 667 ZipUtil.extractZip(new ZipFile(zipFile), outputFilesDir.toFile()); 668 669 // Test timed out, report as failure and upload any test output found for debugging 670 if (result.getStatus() == BuildEventStreamProtos.TestStatus.TIMEOUT) { 671 reportTimedOutTestResults(event, outputFilesDir, modulesToTargets, listener); 672 return; 673 } 674 675 File protoResult = outputFilesDir.resolve(PROTO_RESULTS_FILE_NAME).toFile(); 676 TestRecord record = TestRecordProtoUtil.readFromFile(protoResult); 677 678 if (mReportCachedModulesSparsely && isTestResultCached(result)) { 679 listener = new SparseTestListener(listener); 680 } 681 682 // Tradefed does not report the invocation trace to the proto result file so we have to 683 // explicitly re-add it here. 684 List<Consumer<ITestInvocationListener>> extraLogCalls = new ArrayList<>(); 685 extraLogCalls.addAll(collectInvocationLogCalls(context, record, filePrefix)); 686 extraLogCalls.addAll(collectTraceFileLogCalls(outputFilesDir, filePrefix)); 687 688 BazelTestListener bazelListener = 689 new BazelTestListener(listener, extraLogCalls, isTestResultCached(result)); 690 parseResultsToListener(bazelListener, context, record, filePrefix); 691 } finally { 692 MoreFiles.deleteRecursively(outputFilesDir); 693 } 694 } 695 reportTimedOutTestResults( BuildEventStreamProtos.BuildEvent event, Path outputFilesDir, BiMap<String, String> modulesToTargets, ITestInvocationListener listener)696 private static void reportTimedOutTestResults( 697 BuildEventStreamProtos.BuildEvent event, 698 Path outputFilesDir, 699 BiMap<String, String> modulesToTargets, 700 ITestInvocationListener listener) 701 throws IOException { 702 String label = event.getId().getTestResult().getLabel(); 703 String module = modulesToTargets.inverse().get("@" + label); 704 705 IInvocationContext moduleContext = new InvocationContext(); 706 String abi = AbiUtils.getHostAbi().iterator().next(); 707 moduleContext.addInvocationAttribute("module-id", abi + " " + module); 708 moduleContext.addInvocationAttribute("module-abi", abi); 709 moduleContext.addInvocationAttribute("module-name", module); 710 ConfigurationDescriptor descriptor = new ConfigurationDescriptor(); 711 descriptor.addMetadata("module-name", module); 712 descriptor.setModuleName(module); 713 moduleContext.setConfigurationDescriptor(descriptor); 714 715 listener.testModuleStarted(moduleContext); 716 listener.testRunStarted(module, 0); 717 listener.testRunFailed( 718 FailureDescription.create( 719 "Test timed out, results cannot be processed, but any outputs" 720 + " generated will be uploaded.", 721 FailureStatus.TIMED_OUT) 722 .setErrorIdentifier(TestErrorIdentifier.TEST_BINARY_TIMED_OUT)); 723 listener.testRunEnded(0L, Collections.emptyMap()); 724 uploadTestModuleOutputs(listener, outputFilesDir, module); 725 listener.testModuleEnded(); 726 } 727 uploadTestModuleOutputs( ITestInvocationListener listener, Path outputFilesDir, String module)728 private static void uploadTestModuleOutputs( 729 ITestInvocationListener listener, Path outputFilesDir, String module) 730 throws IOException { 731 try (Stream<Path> testOutputs = 732 Files.walk(outputFilesDir).filter(x -> Files.isRegularFile(x))) { 733 testOutputs.forEach( 734 testOutput -> { 735 try (FileInputStreamSource source = 736 new FileInputStreamSource(testOutput.toFile())) { 737 listener.testLog( 738 module + "-" + testOutput.getFileName().toString(), 739 LogDataType.TEXT, 740 source); 741 } 742 }); 743 } 744 } 745 collectInvocationLogCalls( IInvocationContext context, TestRecord record, String filePrefix)746 private static List<Consumer<ITestInvocationListener>> collectInvocationLogCalls( 747 IInvocationContext context, TestRecord record, String filePrefix) { 748 749 InvocationLogCollector logCollector = new InvocationLogCollector(); 750 parseResultsToListener(logCollector, context, record, filePrefix); 751 return logCollector.getLogCalls(); 752 } 753 parseResultsToListener( ITestInvocationListener listener, IInvocationContext context, TestRecord record, String filePrefix)754 private static void parseResultsToListener( 755 ITestInvocationListener listener, 756 IInvocationContext context, 757 TestRecord record, 758 String filePrefix) { 759 760 ProtoResultParser parser = new ProtoResultParser(listener, context, false, filePrefix); 761 // Avoid merging serialized invocation attributes into the current invocation context. 762 // Not doing so adds misleading information on the top-level invocation 763 // such as bad timing data. See b/284294864. 764 parser.setMergeInvocationContext(false); 765 parser.processFinalizedProto(record); 766 } 767 collectTraceFileLogCalls( Path outputFilesDir, String filePrefix)768 private static List<Consumer<ITestInvocationListener>> collectTraceFileLogCalls( 769 Path outputFilesDir, String filePrefix) throws IOException { 770 771 List<Consumer<ITestInvocationListener>> logCalls = new ArrayList<>(); 772 773 try (Stream<Path> traceFiles = 774 Files.walk(outputFilesDir) 775 .filter(x -> MoreFiles.getFileExtension(x).equals("perfetto-trace"))) { 776 777 traceFiles.forEach( 778 traceFile -> { 779 logCalls.add( 780 (ITestInvocationListener l) -> { 781 l.testLog( 782 filePrefix + traceFile.getFileName().toString(), 783 // We don't mark this file as a PERFETTO log to 784 // avoid having its contents automatically merged in 785 // the top-level invocation's trace. The merge 786 // process is wonky and makes the resulting trace 787 // difficult to read. 788 // TODO(b/284328869): Switch to PERFETTO log type 789 // once traces are properly merged. 790 LogDataType.TEXT, 791 new FileInputStreamSource(traceFile.toFile())); 792 }); 793 }); 794 } 795 return logCalls; 796 } 797 reportRunFailures( List<FailureDescription> runFailures, ITestInvocationListener listener)798 private void reportRunFailures( 799 List<FailureDescription> runFailures, ITestInvocationListener listener) { 800 801 if (runFailures.isEmpty()) { 802 return; 803 } 804 805 for (FailureDescription runFailure : runFailures) { 806 CLog.e(runFailure.getErrorMessage()); 807 } 808 809 FailureDescription reportedFailure = runFailures.get(0); 810 listener.testRunFailed( 811 FailureDescription.create( 812 String.format( 813 "The run had %d failures, the first of which was: %s\n" 814 + "See the subprocess-host_log for more details.", 815 runFailures.size(), reportedFailure.getErrorMessage()), 816 reportedFailure.getFailureStatus()) 817 .setErrorIdentifier(reportedFailure.getErrorIdentifier())); 818 } 819 resolveWorkspacePath()820 private Path resolveWorkspacePath() { 821 String suiteRootPath = mProperties.getProperty(mSuiteRootDirEnvVar); 822 if (suiteRootPath == null || suiteRootPath.isEmpty()) { 823 throw new AbortRunException( 824 "Bazel Test Suite root directory not set, aborting", 825 FailureStatus.DEPENDENCY_ISSUE, 826 TestErrorIdentifier.TEST_ABORTED); 827 } 828 829 // TODO(b/233885171): Remove resolve once workspace archive is updated. 830 return Paths.get(suiteRootPath).resolve("android-bazel-suite/out/atest_bazel_workspace"); 831 } 832 addTestLogs(ITestLogger logger)833 private void addTestLogs(ITestLogger logger) { 834 for (LogFileWithType logFile : mLogFiles) { 835 try (FileInputStreamSource source = 836 new FileInputStreamSource(logFile.getPath().toFile(), true)) { 837 logger.testLog(logFile.getPath().toFile().getName(), logFile.getType(), source); 838 } 839 } 840 } 841 cleanup()842 private void cleanup() { 843 try { 844 MoreFiles.deleteRecursively(mRunTemporaryDirectory); 845 } catch (IOException e) { 846 CLog.e(e); 847 } 848 } 849 850 interface ProcessStarter { start(String processTag, ProcessBuilder builder)851 Process start(String processTag, ProcessBuilder builder) throws IOException; 852 } 853 854 private static final class DefaultProcessStarter implements ProcessStarter { 855 @Override start(String processTag, ProcessBuilder builder)856 public Process start(String processTag, ProcessBuilder builder) throws IOException { 857 return builder.start(); 858 } 859 } 860 createTemporaryDirectory(String prefix)861 private Path createTemporaryDirectory(String prefix) throws IOException { 862 return Files.createTempDirectory(mRunTemporaryDirectory, prefix); 863 } 864 createTemporaryFile(String prefix)865 private Path createTemporaryFile(String prefix) throws IOException { 866 return Files.createTempFile(mRunTemporaryDirectory, prefix, ""); 867 } 868 createLogFile(String name)869 private Path createLogFile(String name) throws IOException { 870 return createLogFile(name, ".txt", LogDataType.TEXT); 871 } 872 createLogFile(String name, String extension, LogDataType type)873 private Path createLogFile(String name, String extension, LogDataType type) throws IOException { 874 Path logPath = Files.createTempFile(mRunTemporaryDirectory, name, extension); 875 876 mLogFiles.add(new LogFileWithType(logPath, type)); 877 878 return logPath; 879 } 880 throwableToTestFailureDescription(Throwable t)881 private static FailureDescription throwableToTestFailureDescription(Throwable t) { 882 return FailureDescription.create(t.getMessage()) 883 .setCause(t) 884 .setFailureStatus(FailureStatus.TEST_FAILURE); 885 } 886 throwableToInfraFailureDescription(Exception e)887 private static FailureDescription throwableToInfraFailureDescription(Exception e) { 888 return FailureDescription.create(e.getMessage()) 889 .setCause(e) 890 .setFailureStatus(FailureStatus.INFRA_FAILURE); 891 } 892 waitForProcessUninterruptibly(Process process, Duration timeout)893 private static boolean waitForProcessUninterruptibly(Process process, Duration timeout) { 894 long remainingNanos = timeout.toNanos(); 895 long end = System.nanoTime() + remainingNanos; 896 boolean interrupted = false; 897 898 try { 899 while (true) { 900 try { 901 return process.waitFor(remainingNanos, TimeUnit.NANOSECONDS); 902 } catch (InterruptedException e) { 903 interrupted = true; 904 remainingNanos = end - System.nanoTime(); 905 } 906 } 907 } finally { 908 if (interrupted) { 909 Thread.currentThread().interrupt(); 910 } 911 } 912 } 913 waitForProcessUninterruptibly(Process process)914 private static int waitForProcessUninterruptibly(Process process) { 915 boolean interrupted = false; 916 917 try { 918 while (true) { 919 try { 920 return process.waitFor(); 921 } catch (InterruptedException e) { 922 interrupted = true; 923 } 924 } 925 } finally { 926 if (interrupted) { 927 Thread.currentThread().interrupt(); 928 } 929 } 930 } 931 932 private static final class AbortRunException extends RuntimeException { 933 private final FailureDescription mFailureDescription; 934 AbortRunException( String errorMessage, FailureStatus failureStatus, ErrorIdentifier errorIdentifier)935 public AbortRunException( 936 String errorMessage, FailureStatus failureStatus, ErrorIdentifier errorIdentifier) { 937 this( 938 FailureDescription.create(errorMessage, failureStatus) 939 .setErrorIdentifier(errorIdentifier)); 940 } 941 AbortRunException(FailureDescription failureDescription)942 public AbortRunException(FailureDescription failureDescription) { 943 super(failureDescription.getErrorMessage()); 944 mFailureDescription = failureDescription; 945 } 946 getFailureDescription()947 public FailureDescription getFailureDescription() { 948 return mFailureDescription; 949 } 950 } 951 952 private static final class ProcessDebugString { 953 954 private final ProcessBuilder mBuilder; 955 ProcessDebugString(ProcessBuilder builder)956 ProcessDebugString(ProcessBuilder builder) { 957 mBuilder = builder; 958 } 959 toString()960 public String toString() { 961 return String.join(" ", mBuilder.command()); 962 } 963 } 964 965 private static final class LogFileWithType { 966 private final Path mPath; 967 private final LogDataType mType; 968 LogFileWithType(Path path, LogDataType type)969 public LogFileWithType(Path path, LogDataType type) { 970 mPath = path; 971 mType = type; 972 } 973 getPath()974 public Path getPath() { 975 return mPath; 976 } 977 getType()978 public LogDataType getType() { 979 return mType; 980 } 981 } 982 983 private static final class RunStats { 984 985 private int mCachedTestResults; 986 addTestResult(BuildEventStreamProtos.TestResult e)987 void addTestResult(BuildEventStreamProtos.TestResult e) { 988 if (isTestResultCached(e)) { 989 mCachedTestResults++; 990 } 991 } 992 addInvocationAttributes(IInvocationContext context)993 void addInvocationAttributes(IInvocationContext context) { 994 InvocationMetricLogger.addInvocationMetrics( 995 InvocationMetricKey.CACHED_MODULE_RESULTS_COUNT, 996 Integer.toString(mCachedTestResults)); 997 } 998 } 999 } 1000