base/test/launcher/test_launcher.cc

   1 // Copyright 2013 The Chromium Authors. All rights reserved.
   2 // Use of this source code is governed by a BSD-style license that can be
   3 // found in the LICENSE file.
   4
   5 #include "base/test/launcher/test_launcher.h"
   6
   7 #if defined(OS_POSIX)
   8 #include <fcntl.h>
   9 #endif
  10
  11 #include "base/at_exit.h"
  12 #include "base/bind.h"
  13 #include "base/command_line.h"
  14 #include "base/environment.h"
  15 #include "base/file_util.h"
  16 #include "base/files/file_path.h"
  17 #include "base/files/scoped_file.h"
  18 #include "base/format_macros.h"
  19 #include "base/hash.h"
  20 #include "base/lazy_instance.h"
  21 #include "base/logging.h"
  22 #include "base/memory/scoped_ptr.h"
  23 #include "base/message_loop/message_loop.h"
  24 #include "base/process/kill.h"
  25 #include "base/process/launch.h"
  26 #include "base/strings/string_number_conversions.h"
  27 #include "base/strings/string_split.h"
  28 #include "base/strings/string_util.h"
  29 #include "base/strings/stringize_macros.h"
  30 #include "base/strings/stringprintf.h"
  31 #include "base/strings/utf_string_conversions.h"
  32 #include "base/test/launcher/test_results_tracker.h"
  33 #include "base/test/sequenced_worker_pool_owner.h"
  34 #include "base/test/test_switches.h"
  35 #include "base/test/test_timeouts.h"
  36 #include "base/threading/thread_checker.h"
  37 #include "base/time/time.h"
  38 #include "testing/gtest/include/gtest/gtest.h"
  39
  40 #if defined(OS_MACOSX)
  41 #include "base/mac/scoped_nsautorelease_pool.h"
  42 #endif
  43
  44 namespace base {
  45
  46 // Launches a child process using |command_line|. If the child process is still
  47 // running after |timeout|, it is terminated and |*was_timeout| is set to true.
  48 // Returns exit code of the process.
  49 int LaunchChildTestProcessWithOptions(const CommandLine& command_line,
  50                                       const LaunchOptions& options,
  51                                       bool use_job_objects,
  52                                       base::TimeDelta timeout,
  53                                       bool* was_timeout);
  54
  55 // See https://groups.google.com/a/chromium.org/d/msg/chromium-dev/nkdTP7sstSc/uT3FaE_sgkAJ .
  56 using ::operator<<;
  57
  58 // The environment variable name for the total number of test shards.
  59 const char kTestTotalShards[] = "GTEST_TOTAL_SHARDS";
  60 // The environment variable name for the test shard index.
  61 const char kTestShardIndex[] = "GTEST_SHARD_INDEX";
  62
  63 namespace {
  64
  65 // Global tag for test runs where the results are incomplete or unreliable
  66 // for any reason, e.g. early exit because of too many broken tests.
  67 const char kUnreliableResultsTag[] = "UNRELIABLE_RESULTS";
  68
  69 // Maximum time of no output after which we print list of processes still
  70 // running. This deliberately doesn't use TestTimeouts (which is otherwise
  71 // a recommended solution), because they can be increased. This would defeat
  72 // the purpose of this timeout, which is 1) to avoid buildbot "no output for
  73 // X seconds" timeout killing the process 2) help communicate status of
  74 // the test launcher to people looking at the output (no output for a long
  75 // time is mysterious and gives no info about what is happening) 3) help
  76 // debugging in case the process hangs anyway.
  77 const int kOutputTimeoutSeconds = 15;
  78
  79 // Limit of output snippet lines when printing to stdout.
  80 // Avoids flooding the logs with amount of output that gums up
  81 // the infrastructure.
  82 const size_t kOutputSnippetLinesLimit = 5000;
  83
  84 // Set of live launch test processes with corresponding lock (it is allowed
  85 // for callers to launch processes on different threads).
  86 LazyInstance<std::map<ProcessHandle, CommandLine> > g_live_processes
  87     = LAZY_INSTANCE_INITIALIZER;
  88 LazyInstance<Lock> g_live_processes_lock = LAZY_INSTANCE_INITIALIZER;
  89
  90 #if defined(OS_POSIX)
  91 // Self-pipe that makes it possible to do complex shutdown handling
  92 // outside of the signal handler.
  93 int g_shutdown_pipe[2] = { -1, -1 };
  94
  95 void ShutdownPipeSignalHandler(int signal) {
  96   HANDLE_EINTR(write(g_shutdown_pipe[1], "q", 1));
  97 }
  98
  99 void KillSpawnedTestProcesses() {
 100   // Keep the lock until exiting the process to prevent further processes
 101   // from being spawned.
 102   AutoLock lock(g_live_processes_lock.Get());
 103
 104   fprintf(stdout,
 105           "Sending SIGTERM to %" PRIuS " child processes... ",
 106           g_live_processes.Get().size());
 107   fflush(stdout);
 108
 109   for (std::map<ProcessHandle, CommandLine>::iterator i =
 110            g_live_processes.Get().begin();
 111        i != g_live_processes.Get().end();
 112        ++i) {
 113     // Send the signal to entire process group.
 114     kill((-1) * (i->first), SIGTERM);
 115   }
 116
 117   fprintf(stdout,
 118           "done.\nGiving processes a chance to terminate cleanly... ");
 119   fflush(stdout);
 120
 121   PlatformThread::Sleep(TimeDelta::FromMilliseconds(500));
 122
 123   fprintf(stdout, "done.\n");
 124   fflush(stdout);
 125
 126   fprintf(stdout,
 127           "Sending SIGKILL to %" PRIuS " child processes... ",
 128           g_live_processes.Get().size());
 129   fflush(stdout);
 130
 131   for (std::map<ProcessHandle, CommandLine>::iterator i =
 132            g_live_processes.Get().begin();
 133        i != g_live_processes.Get().end();
 134        ++i) {
 135     // Send the signal to entire process group.
 136     kill((-1) * (i->first), SIGKILL);
 137   }
 138
 139   fprintf(stdout, "done.\n");
 140   fflush(stdout);
 141 }
 142
 143 // I/O watcher for the reading end of the self-pipe above.
 144 // Terminates any launched child processes and exits the process.
 145 class SignalFDWatcher : public MessageLoopForIO::Watcher {
 146  public:
 147   SignalFDWatcher() {
 148   }
 149
 150   virtual void OnFileCanReadWithoutBlocking(int fd) OVERRIDE {
 151     fprintf(stdout, "\nCaught signal. Killing spawned test processes...\n");
 152     fflush(stdout);
 153
 154     KillSpawnedTestProcesses();
 155
 156     // The signal would normally kill the process, so exit now.
 157     exit(1);
 158   }
 159
 160   virtual void OnFileCanWriteWithoutBlocking(int fd) OVERRIDE {
 161     NOTREACHED();
 162   }
 163
 164  private:
 165   DISALLOW_COPY_AND_ASSIGN(SignalFDWatcher);
 166 };
 167 #endif  // defined(OS_POSIX)
 168
 169 // Parses the environment variable var as an Int32.  If it is unset, returns
 170 // true.  If it is set, unsets it then converts it to Int32 before
 171 // returning it in |result|.  Returns true on success.
 172 bool TakeInt32FromEnvironment(const char* const var, int32* result) {
 173   scoped_ptr<Environment> env(Environment::Create());
 174   std::string str_val;
 175
 176   if (!env->GetVar(var, &str_val))
 177     return true;
 178
 179   if (!env->UnSetVar(var)) {
 180     LOG(ERROR) << "Invalid environment: we could not unset " << var << ".\n";
 181     return false;
 182   }
 183
 184   if (!StringToInt(str_val, result)) {
 185     LOG(ERROR) << "Invalid environment: " << var << " is not an integer.\n";
 186     return false;
 187   }
 188
 189   return true;
 190 }
 191
 192 // Unsets the environment variable |name| and returns true on success.
 193 // Also returns true if the variable just doesn't exist.
 194 bool UnsetEnvironmentVariableIfExists(const std::string& name) {
 195   scoped_ptr<Environment> env(Environment::Create());
 196   std::string str_val;
 197
 198   if (!env->GetVar(name.c_str(), &str_val))
 199     return true;
 200
 201   return env->UnSetVar(name.c_str());
 202 }
 203
 204 // Returns true if bot mode has been requested, i.e. defaults optimized
 205 // for continuous integration bots. This way developers don't have to remember
 206 // special command-line flags.
 207 bool BotModeEnabled() {
 208   scoped_ptr<Environment> env(Environment::Create());
 209   return CommandLine::ForCurrentProcess()->HasSwitch(
 210       switches::kTestLauncherBotMode) ||
 211       env->HasVar("CHROMIUM_TEST_LAUNCHER_BOT_MODE");
 212 }
 213
 214 void RunCallback(
 215     const TestLauncher::LaunchChildGTestProcessCallback& callback,
 216     int exit_code,
 217     const TimeDelta& elapsed_time,
 218     bool was_timeout,
 219     const std::string& output) {
 220   callback.Run(exit_code, elapsed_time, was_timeout, output);
 221 }
 222
 223 void DoLaunchChildTestProcess(
 224     const CommandLine& command_line,
 225     base::TimeDelta timeout,
 226     bool use_job_objects,
 227     bool redirect_stdio,
 228     scoped_refptr<MessageLoopProxy> message_loop_proxy,
 229     const TestLauncher::LaunchChildGTestProcessCallback& callback) {
 230   TimeTicks start_time = TimeTicks::Now();
 231
 232   // Redirect child process output to a file.
 233   base::FilePath output_file;
 234   CHECK(base::CreateTemporaryFile(&output_file));
 235
 236   LaunchOptions options;
 237 #if defined(OS_WIN)
 238   win::ScopedHandle handle;
 239
 240   if (redirect_stdio) {
 241     // Make the file handle inheritable by the child.
 242     SECURITY_ATTRIBUTES sa_attr;
 243     sa_attr.nLength = sizeof(SECURITY_ATTRIBUTES);
 244     sa_attr.lpSecurityDescriptor = NULL;
 245     sa_attr.bInheritHandle = TRUE;
 246
 247     handle.Set(CreateFile(output_file.value().c_str(),
 248                           GENERIC_WRITE,
 249                           FILE_SHARE_READ | FILE_SHARE_DELETE,
 250                           &sa_attr,
 251                           OPEN_EXISTING,
 252                           FILE_ATTRIBUTE_TEMPORARY,
 253                           NULL));
 254     CHECK(handle.IsValid());
 255     options.inherit_handles = true;
 256     options.stdin_handle = INVALID_HANDLE_VALUE;
 257     options.stdout_handle = handle.Get();
 258     options.stderr_handle = handle.Get();
 259   }
 260 #elif defined(OS_POSIX)
 261   options.new_process_group = true;
 262
 263   base::FileHandleMappingVector fds_mapping;
 264   base::ScopedFD output_file_fd;
 265
 266   if (redirect_stdio) {
 267     output_file_fd.reset(open(output_file.value().c_str(), O_RDWR));
 268     CHECK(output_file_fd.is_valid());
 269
 270     fds_mapping.push_back(std::make_pair(output_file_fd.get(), STDOUT_FILENO));
 271     fds_mapping.push_back(std::make_pair(output_file_fd.get(), STDERR_FILENO));
 272     options.fds_to_remap = &fds_mapping;
 273   }
 274 #endif
 275
 276   bool was_timeout = false;
 277   int exit_code = LaunchChildTestProcessWithOptions(
 278       command_line, options, use_job_objects, timeout, &was_timeout);
 279
 280   if (redirect_stdio) {
 281 #if defined(OS_WIN)
 282     FlushFileBuffers(handle.Get());
 283     handle.Close();
 284 #elif defined(OS_POSIX)
 285     output_file_fd.reset();
 286 #endif
 287   }
 288
 289   std::string output_file_contents;
 290   CHECK(base::ReadFileToString(output_file, &output_file_contents));
 291
 292   if (!base::DeleteFile(output_file, false)) {
 293     // This needs to be non-fatal at least for Windows.
 294     LOG(WARNING) << "Failed to delete " << output_file.AsUTF8Unsafe();
 295   }
 296
 297   // Run target callback on the thread it was originating from, not on
 298   // a worker pool thread.
 299   message_loop_proxy->PostTask(
 300       FROM_HERE,
 301       Bind(&RunCallback,
 302            callback,
 303            exit_code,
 304            TimeTicks::Now() - start_time,
 305            was_timeout,
 306            output_file_contents));
 307 }
 308
 309 }  // namespace
 310
 311 const char kGTestFilterFlag[] = "gtest_filter";
 312 const char kGTestHelpFlag[]   = "gtest_help";
 313 const char kGTestListTestsFlag[] = "gtest_list_tests";
 314 const char kGTestRepeatFlag[] = "gtest_repeat";
 315 const char kGTestRunDisabledTestsFlag[] = "gtest_also_run_disabled_tests";
 316 const char kGTestOutputFlag[] = "gtest_output";
 317
 318 TestLauncherDelegate::~TestLauncherDelegate() {
 319 }
 320
 321 TestLauncher::TestLauncher(TestLauncherDelegate* launcher_delegate,
 322                            size_t parallel_jobs)
 323     : launcher_delegate_(launcher_delegate),
 324       total_shards_(1),
 325       shard_index_(0),
 326       cycles_(1),
 327       test_started_count_(0),
 328       test_finished_count_(0),
 329       test_success_count_(0),
 330       test_broken_count_(0),
 331       retry_count_(0),
 332       retry_limit_(0),
 333       run_result_(true),
 334       watchdog_timer_(FROM_HERE,
 335                       TimeDelta::FromSeconds(kOutputTimeoutSeconds),
 336                       this,
 337                       &TestLauncher::OnOutputTimeout),
 338       parallel_jobs_(parallel_jobs) {
 339   if (BotModeEnabled()) {
 340     fprintf(stdout,
 341             "Enabling defaults optimized for continuous integration bots.\n");
 342     fflush(stdout);
 343
 344     // Enable test retries by default for bots. This can be still overridden
 345     // from command line using --test-launcher-retry-limit flag.
 346     retry_limit_ = 3;
 347   } else {
 348     // Default to serial test execution if not running on a bot. This makes it
 349     // possible to disable stdio redirection and can still be overridden with
 350     // --test-launcher-jobs flag.
 351     parallel_jobs_ = 1;
 352   }
 353 }
 354
 355 TestLauncher::~TestLauncher() {
 356   if (worker_pool_owner_)
 357     worker_pool_owner_->pool()->Shutdown();
 358 }
 359
 360 bool TestLauncher::Run() {
 361   if (!Init())
 362     return false;
 363
 364   // Value of |cycles_| changes after each iteration. Keep track of the
 365   // original value.
 366   int requested_cycles = cycles_;
 367
 368 #if defined(OS_POSIX)
 369   CHECK_EQ(0, pipe(g_shutdown_pipe));
 370
 371   struct sigaction action;
 372   memset(&action, 0, sizeof(action));
 373   sigemptyset(&action.sa_mask);
 374   action.sa_handler = &ShutdownPipeSignalHandler;
 375
 376   CHECK_EQ(0, sigaction(SIGINT, &action, NULL));
 377   CHECK_EQ(0, sigaction(SIGQUIT, &action, NULL));
 378   CHECK_EQ(0, sigaction(SIGTERM, &action, NULL));
 379
 380   MessageLoopForIO::FileDescriptorWatcher controller;
 381   SignalFDWatcher watcher;
 382
 383   CHECK(MessageLoopForIO::current()->WatchFileDescriptor(
 384             g_shutdown_pipe[0],
 385             true,
 386             MessageLoopForIO::WATCH_READ,
 387             &controller,
 388             &watcher));
 389 #endif  // defined(OS_POSIX)
 390
 391   // Start the watchdog timer.
 392   watchdog_timer_.Reset();
 393
 394   MessageLoop::current()->PostTask(
 395       FROM_HERE,
 396       Bind(&TestLauncher::RunTestIteration, Unretained(this)));
 397
 398   MessageLoop::current()->Run();
 399
 400   if (requested_cycles != 1)
 401     results_tracker_.PrintSummaryOfAllIterations();
 402
 403   MaybeSaveSummaryAsJSON();
 404
 405   return run_result_;
 406 }
 407
 408 void TestLauncher::LaunchChildGTestProcess(
 409     const CommandLine& command_line,
 410     const std::string& wrapper,
 411     base::TimeDelta timeout,
 412     bool use_job_objects,
 413     const LaunchChildGTestProcessCallback& callback) {
 414   DCHECK(thread_checker_.CalledOnValidThread());
 415
 416   // Record the exact command line used to launch the child.
 417   CommandLine new_command_line(
 418       PrepareCommandLineForGTest(command_line, wrapper));
 419
 420   // When running in parallel mode we need to redirect stdio to avoid mixed-up
 421   // output. We also always redirect on the bots to get the test output into
 422   // JSON summary.
 423   bool redirect_stdio = (parallel_jobs_ > 1) || BotModeEnabled();
 424
 425   worker_pool_owner_->pool()->PostWorkerTask(
 426       FROM_HERE,
 427       Bind(&DoLaunchChildTestProcess,
 428            new_command_line,
 429            timeout,
 430            use_job_objects,
 431            redirect_stdio,
 432            MessageLoopProxy::current(),
 433            Bind(&TestLauncher::OnLaunchTestProcessFinished,
 434                 Unretained(this),
 435                 callback)));
 436 }
 437
 438 void TestLauncher::OnTestFinished(const TestResult& result) {
 439   ++test_finished_count_;
 440
 441   bool print_snippet = false;
 442   std::string print_test_stdio("auto");
 443   if (CommandLine::ForCurrentProcess()->HasSwitch(
 444           switches::kTestLauncherPrintTestStdio)) {
 445     print_test_stdio = CommandLine::ForCurrentProcess()->GetSwitchValueASCII(
 446         switches::kTestLauncherPrintTestStdio);
 447   }
 448   if (print_test_stdio == "auto") {
 449     print_snippet = (result.status != TestResult::TEST_SUCCESS);
 450   } else if (print_test_stdio == "always") {
 451     print_snippet = true;
 452   } else if (print_test_stdio == "never") {
 453     print_snippet = false;
 454   } else {
 455     LOG(WARNING) << "Invalid value of " << switches::kTestLauncherPrintTestStdio
 456                  << ": " << print_test_stdio;
 457   }
 458   if (print_snippet) {
 459     std::vector<std::string> snippet_lines;
 460     SplitString(result.output_snippet, '\n', &snippet_lines);
 461     if (snippet_lines.size() > kOutputSnippetLinesLimit) {
 462       size_t truncated_size = snippet_lines.size() - kOutputSnippetLinesLimit;
 463       snippet_lines.erase(
 464           snippet_lines.begin(),
 465           snippet_lines.begin() + truncated_size);
 466       snippet_lines.insert(snippet_lines.begin(), "<truncated>");
 467     }
 468     fprintf(stdout, "%s", JoinString(snippet_lines, "\n").c_str());
 469     fflush(stdout);
 470   }
 471
 472   if (result.status == TestResult::TEST_SUCCESS) {
 473     ++test_success_count_;
 474   } else {
 475     tests_to_retry_.insert(result.full_name);
 476   }
 477
 478   results_tracker_.AddTestResult(result);
 479
 480   // TODO(phajdan.jr): Align counter (padding).
 481   std::string status_line(
 482       StringPrintf("[%" PRIuS "/%" PRIuS "] %s ",
 483                    test_finished_count_,
 484                    test_started_count_,
 485                    result.full_name.c_str()));
 486   if (result.completed()) {
 487     status_line.append(StringPrintf("(%" PRId64 " ms)",
 488                                     result.elapsed_time.InMilliseconds()));
 489   } else if (result.status == TestResult::TEST_TIMEOUT) {
 490     status_line.append("(TIMED OUT)");
 491   } else if (result.status == TestResult::TEST_CRASH) {
 492     status_line.append("(CRASHED)");
 493   } else if (result.status == TestResult::TEST_SKIPPED) {
 494     status_line.append("(SKIPPED)");
 495   } else if (result.status == TestResult::TEST_UNKNOWN) {
 496     status_line.append("(UNKNOWN)");
 497   } else {
 498     // Fail very loudly so it's not ignored.
 499     CHECK(false) << "Unhandled test result status: " << result.status;
 500   }
 501   fprintf(stdout, "%s\n", status_line.c_str());
 502   fflush(stdout);
 503
 504   // We just printed a status line, reset the watchdog timer.
 505   watchdog_timer_.Reset();
 506
 507   // Do not waste time on timeouts. We include tests with unknown results here
 508   // because sometimes (e.g. hang in between unit tests) that's how a timeout
 509   // gets reported.
 510   if (result.status == TestResult::TEST_TIMEOUT ||
 511       result.status == TestResult::TEST_UNKNOWN) {
 512     test_broken_count_++;
 513   }
 514   size_t broken_threshold =
 515       std::max(static_cast<size_t>(20), test_started_count_ / 10);
 516   if (test_broken_count_ >= broken_threshold) {
 517     fprintf(stdout, "Too many badly broken tests (%" PRIuS "), exiting now.\n",
 518             test_broken_count_);
 519     fflush(stdout);
 520
 521 #if defined(OS_POSIX)
 522     KillSpawnedTestProcesses();
 523 #endif  // defined(OS_POSIX)
 524
 525     results_tracker_.AddGlobalTag("BROKEN_TEST_EARLY_EXIT");
 526     results_tracker_.AddGlobalTag(kUnreliableResultsTag);
 527     MaybeSaveSummaryAsJSON();
 528
 529     exit(1);
 530   }
 531
 532   if (test_finished_count_ != test_started_count_)
 533     return;
 534
 535   if (tests_to_retry_.empty() || retry_count_ >= retry_limit_) {
 536     OnTestIterationFinished();
 537     return;
 538   }
 539
 540   if (tests_to_retry_.size() >= broken_threshold) {
 541     fprintf(stdout,
 542             "Too many failing tests (%" PRIuS "), skipping retries.\n",
 543             tests_to_retry_.size());
 544     fflush(stdout);
 545
 546     results_tracker_.AddGlobalTag("BROKEN_TEST_SKIPPED_RETRIES");
 547     results_tracker_.AddGlobalTag(kUnreliableResultsTag);
 548
 549     OnTestIterationFinished();
 550     return;
 551   }
 552
 553   retry_count_++;
 554
 555   std::vector<std::string> test_names(tests_to_retry_.begin(),
 556                                       tests_to_retry_.end());
 557
 558   tests_to_retry_.clear();
 559
 560   size_t retry_started_count = launcher_delegate_->RetryTests(this, test_names);
 561   if (retry_started_count == 0) {
 562     // Signal failure, but continue to run all requested test iterations.
 563     // With the summary of all iterations at the end this is a good default.
 564     run_result_ = false;
 565
 566     OnTestIterationFinished();
 567     return;
 568   }
 569
 570   fprintf(stdout, "Retrying %" PRIuS " test%s (retry #%" PRIuS ")\n",
 571           retry_started_count,
 572           retry_started_count > 1 ? "s" : "",
 573           retry_count_);
 574   fflush(stdout);
 575
 576   test_started_count_ += retry_started_count;
 577 }
 578
 579 bool TestLauncher::Init() {
 580   const CommandLine* command_line = CommandLine::ForCurrentProcess();
 581
 582   // Initialize sharding. Command line takes precedence over legacy environment
 583   // variables.
 584   if (command_line->HasSwitch(switches::kTestLauncherTotalShards) &&
 585       command_line->HasSwitch(switches::kTestLauncherShardIndex)) {
 586     if (!StringToInt(
 587             command_line->GetSwitchValueASCII(
 588                 switches::kTestLauncherTotalShards),
 589             &total_shards_)) {
 590       LOG(ERROR) << "Invalid value for " << switches::kTestLauncherTotalShards;
 591       return false;
 592     }
 593     if (!StringToInt(
 594             command_line->GetSwitchValueASCII(
 595                 switches::kTestLauncherShardIndex),
 596             &shard_index_)) {
 597       LOG(ERROR) << "Invalid value for " << switches::kTestLauncherShardIndex;
 598       return false;
 599     }
 600     fprintf(stdout,
 601             "Using sharding settings from command line. This is shard %d/%d\n",
 602             shard_index_, total_shards_);
 603     fflush(stdout);
 604   } else {
 605     if (!TakeInt32FromEnvironment(kTestTotalShards, &total_shards_))
 606       return false;
 607     if (!TakeInt32FromEnvironment(kTestShardIndex, &shard_index_))
 608       return false;
 609     fprintf(stdout,
 610             "Using sharding settings from environment. This is shard %d/%d\n",
 611             shard_index_, total_shards_);
 612     fflush(stdout);
 613   }
 614   if (shard_index_ < 0 ||
 615       total_shards_ < 0 ||
 616       shard_index_ >= total_shards_) {
 617     LOG(ERROR) << "Invalid sharding settings: we require 0 <= "
 618                << kTestShardIndex << " < " << kTestTotalShards
 619                << ", but you have " << kTestShardIndex << "=" << shard_index_
 620                << ", " << kTestTotalShards << "=" << total_shards_ << ".\n";
 621     return false;
 622   }
 623
 624   // Make sure we don't pass any sharding-related environment to the child
 625   // processes. This test launcher implements the sharding completely.
 626   CHECK(UnsetEnvironmentVariableIfExists("GTEST_TOTAL_SHARDS"));
 627   CHECK(UnsetEnvironmentVariableIfExists("GTEST_SHARD_INDEX"));
 628
 629   if (command_line->HasSwitch(kGTestRepeatFlag) &&
 630       !StringToInt(command_line->GetSwitchValueASCII(kGTestRepeatFlag),
 631                    &cycles_)) {
 632     LOG(ERROR) << "Invalid value for " << kGTestRepeatFlag;
 633     return false;
 634   }
 635
 636   if (CommandLine::ForCurrentProcess()->HasSwitch(
 637           switches::kTestLauncherRetryLimit)) {
 638     int retry_limit = -1;
 639     if (!StringToInt(CommandLine::ForCurrentProcess()->GetSwitchValueASCII(
 640                          switches::kTestLauncherRetryLimit), &retry_limit) ||
 641         retry_limit < 0) {
 642       LOG(ERROR) << "Invalid value for " << switches::kTestLauncherRetryLimit;
 643       return false;
 644     }
 645
 646     retry_limit_ = retry_limit;
 647   }
 648
 649   if (CommandLine::ForCurrentProcess()->HasSwitch(
 650           switches::kTestLauncherJobs)) {
 651     int jobs = -1;
 652     if (!StringToInt(CommandLine::ForCurrentProcess()->GetSwitchValueASCII(
 653                          switches::kTestLauncherJobs), &jobs) ||
 654         jobs < 0) {
 655       LOG(ERROR) << "Invalid value for " << switches::kTestLauncherJobs;
 656       return false;
 657     }
 658
 659     parallel_jobs_ = jobs;
 660   }
 661   fprintf(stdout, "Using %" PRIuS " parallel jobs.\n", parallel_jobs_);
 662   fflush(stdout);
 663   worker_pool_owner_.reset(
 664       new SequencedWorkerPoolOwner(parallel_jobs_, "test_launcher"));
 665
 666   if (command_line->HasSwitch(switches::kTestLauncherFilterFile) &&
 667       command_line->HasSwitch(kGTestFilterFlag)) {
 668     LOG(ERROR) << "Only one of --test-launcher-filter-file and --gtest_filter "
 669                << "at a time is allowed.";
 670     return false;
 671   }
 672
 673   if (command_line->HasSwitch(switches::kTestLauncherFilterFile)) {
 674     std::string filter;
 675     if (!ReadFileToString(
 676             command_line->GetSwitchValuePath(switches::kTestLauncherFilterFile),
 677             &filter)) {
 678       LOG(ERROR) << "Failed to read the filter file.";
 679       return false;
 680     }
 681
 682     std::vector<std::string> filter_lines;
 683     SplitString(filter, '\n', &filter_lines);
 684     for (size_t i = 0; i < filter_lines.size(); i++) {
 685       if (filter_lines[i].empty())
 686         continue;
 687
 688       if (filter_lines[i][0] == '-')
 689         negative_test_filter_.push_back(filter_lines[i].substr(1));
 690       else
 691         positive_test_filter_.push_back(filter_lines[i]);
 692     }
 693   } else {
 694     // Split --gtest_filter at '-', if there is one, to separate into
 695     // positive filter and negative filter portions.
 696     std::string filter = command_line->GetSwitchValueASCII(kGTestFilterFlag);
 697     size_t dash_pos = filter.find('-');
 698     if (dash_pos == std::string::npos) {
 699       SplitString(filter, ':', &positive_test_filter_);
 700     } else {
 701       // Everything up to the dash.
 702       SplitString(filter.substr(0, dash_pos), ':', &positive_test_filter_);
 703
 704       // Everything after the dash.
 705       SplitString(filter.substr(dash_pos + 1), ':', &negative_test_filter_);
 706     }
 707   }
 708
 709   if (!results_tracker_.Init(*command_line)) {
 710     LOG(ERROR) << "Failed to initialize test results tracker.";
 711     return 1;
 712   }
 713
 714 #if defined(NDEBUG)
 715   results_tracker_.AddGlobalTag("MODE_RELEASE");
 716 #else
 717   results_tracker_.AddGlobalTag("MODE_DEBUG");
 718 #endif
 719
 720   // Operating systems (sorted alphabetically).
 721   // Note that they can deliberately overlap, e.g. OS_LINUX is a subset
 722   // of OS_POSIX.
 723 #if defined(OS_ANDROID)
 724   results_tracker_.AddGlobalTag("OS_ANDROID");
 725 #endif
 726
 727 #if defined(OS_BSD)
 728   results_tracker_.AddGlobalTag("OS_BSD");
 729 #endif
 730
 731 #if defined(OS_FREEBSD)
 732   results_tracker_.AddGlobalTag("OS_FREEBSD");
 733 #endif
 734
 735 #if defined(OS_IOS)
 736   results_tracker_.AddGlobalTag("OS_IOS");
 737 #endif
 738
 739 #if defined(OS_LINUX)
 740   results_tracker_.AddGlobalTag("OS_LINUX");
 741 #endif
 742
 743 #if defined(OS_MACOSX)
 744   results_tracker_.AddGlobalTag("OS_MACOSX");
 745 #endif
 746
 747 #if defined(OS_NACL)
 748   results_tracker_.AddGlobalTag("OS_NACL");
 749 #endif
 750
 751 #if defined(OS_OPENBSD)
 752   results_tracker_.AddGlobalTag("OS_OPENBSD");
 753 #endif
 754
 755 #if defined(OS_POSIX)
 756   results_tracker_.AddGlobalTag("OS_POSIX");
 757 #endif
 758
 759 #if defined(OS_SOLARIS)
 760   results_tracker_.AddGlobalTag("OS_SOLARIS");
 761 #endif
 762
 763 #if defined(OS_WIN)
 764   results_tracker_.AddGlobalTag("OS_WIN");
 765 #endif
 766
 767   // CPU-related tags.
 768 #if defined(ARCH_CPU_32_BITS)
 769   results_tracker_.AddGlobalTag("CPU_32_BITS");
 770 #endif
 771
 772 #if defined(ARCH_CPU_64_BITS)
 773   results_tracker_.AddGlobalTag("CPU_64_BITS");
 774 #endif
 775
 776   return true;
 777 }
 778
 779 void TestLauncher::RunTests() {
 780   testing::UnitTest* const unit_test = testing::UnitTest::GetInstance();
 781
 782   std::vector<std::string> test_names;
 783
 784   for (int i = 0; i < unit_test->total_test_case_count(); ++i) {
 785     const testing::TestCase* test_case = unit_test->GetTestCase(i);
 786     for (int j = 0; j < test_case->total_test_count(); ++j) {
 787       const testing::TestInfo* test_info = test_case->GetTestInfo(j);
 788       std::string test_name = test_info->test_case_name();
 789       test_name.append(".");
 790       test_name.append(test_info->name());
 791
 792       results_tracker_.AddTest(test_name);
 793
 794       const CommandLine* command_line = CommandLine::ForCurrentProcess();
 795       if (test_name.find("DISABLED") != std::string::npos) {
 796         results_tracker_.AddDisabledTest(test_name);
 797
 798         // Skip disabled tests unless explicitly requested.
 799         if (!command_line->HasSwitch(kGTestRunDisabledTestsFlag))
 800           continue;
 801       }
 802
 803       // Skip the test that doesn't match the filter (if given).
 804       if (!positive_test_filter_.empty()) {
 805         bool found = false;
 806         for (size_t k = 0; k < positive_test_filter_.size(); ++k) {
 807           if (MatchPattern(test_name, positive_test_filter_[k])) {
 808             found = true;
 809             break;
 810           }
 811         }
 812
 813         if (!found)
 814           continue;
 815       }
 816       bool excluded = false;
 817       for (size_t k = 0; k < negative_test_filter_.size(); ++k) {
 818         if (MatchPattern(test_name, negative_test_filter_[k])) {
 819           excluded = true;
 820           break;
 821         }
 822       }
 823       if (excluded)
 824         continue;
 825
 826       if (!launcher_delegate_->ShouldRunTest(test_case, test_info))
 827         continue;
 828
 829       if (base::Hash(test_name) % total_shards_ !=
 830           static_cast<uint32>(shard_index_)) {
 831         continue;
 832       }
 833
 834       test_names.push_back(test_name);
 835     }
 836   }
 837
 838   test_started_count_ = launcher_delegate_->RunTests(this, test_names);
 839
 840   if (test_started_count_ == 0) {
 841     fprintf(stdout, "0 tests run\n");
 842     fflush(stdout);
 843
 844     // No tests have actually been started, so kick off the next iteration.
 845     MessageLoop::current()->PostTask(
 846         FROM_HERE,
 847         Bind(&TestLauncher::RunTestIteration, Unretained(this)));
 848   }
 849 }
 850
 851 void TestLauncher::RunTestIteration() {
 852   if (cycles_ == 0) {
 853     MessageLoop::current()->Quit();
 854     return;
 855   }
 856
 857   // Special value "-1" means "repeat indefinitely".
 858   cycles_ = (cycles_ == -1) ? cycles_ : cycles_ - 1;
 859
 860   test_started_count_ = 0;
 861   test_finished_count_ = 0;
 862   test_success_count_ = 0;
 863   test_broken_count_ = 0;
 864   retry_count_ = 0;
 865   tests_to_retry_.clear();
 866   results_tracker_.OnTestIterationStarting();
 867
 868   MessageLoop::current()->PostTask(
 869       FROM_HERE, Bind(&TestLauncher::RunTests, Unretained(this)));
 870 }
 871
 872 void TestLauncher::MaybeSaveSummaryAsJSON() {
 873   const CommandLine* command_line = CommandLine::ForCurrentProcess();
 874   if (command_line->HasSwitch(switches::kTestLauncherSummaryOutput)) {
 875     FilePath summary_path(command_line->GetSwitchValuePath(
 876                               switches::kTestLauncherSummaryOutput));
 877     if (!results_tracker_.SaveSummaryAsJSON(summary_path)) {
 878       LOG(ERROR) << "Failed to save test launcher output summary.";
 879     }
 880   }
 881 }
 882
 883 void TestLauncher::OnLaunchTestProcessFinished(
 884     const LaunchChildGTestProcessCallback& callback,
 885     int exit_code,
 886     const TimeDelta& elapsed_time,
 887     bool was_timeout,
 888     const std::string& output) {
 889   DCHECK(thread_checker_.CalledOnValidThread());
 890
 891   callback.Run(exit_code, elapsed_time, was_timeout, output);
 892 }
 893
 894 void TestLauncher::OnTestIterationFinished() {
 895   TestResultsTracker::TestStatusMap tests_by_status(
 896       results_tracker_.GetTestStatusMapForCurrentIteration());
 897   if (!tests_by_status[TestResult::TEST_UNKNOWN].empty())
 898     results_tracker_.AddGlobalTag(kUnreliableResultsTag);
 899
 900   // When we retry tests, success is determined by having nothing more
 901   // to retry (everything eventually passed), as opposed to having
 902   // no failures at all.
 903   if (tests_to_retry_.empty()) {
 904     fprintf(stdout, "SUCCESS: all tests passed.\n");
 905     fflush(stdout);
 906   } else {
 907     // Signal failure, but continue to run all requested test iterations.
 908     // With the summary of all iterations at the end this is a good default.
 909     run_result_ = false;
 910   }
 911
 912   results_tracker_.PrintSummaryOfCurrentIteration();
 913
 914   // Kick off the next iteration.
 915   MessageLoop::current()->PostTask(
 916       FROM_HERE,
 917       Bind(&TestLauncher::RunTestIteration, Unretained(this)));
 918 }
 919
 920 void TestLauncher::OnOutputTimeout() {
 921   DCHECK(thread_checker_.CalledOnValidThread());
 922
 923   AutoLock lock(g_live_processes_lock.Get());
 924
 925   fprintf(stdout, "Still waiting for the following processes to finish:\n");
 926
 927   for (std::map<ProcessHandle, CommandLine>::iterator i =
 928            g_live_processes.Get().begin();
 929        i != g_live_processes.Get().end();
 930        ++i) {
 931 #if defined(OS_WIN)
 932     fwprintf(stdout, L"\t%s\n", i->second.GetCommandLineString().c_str());
 933 #else
 934     fprintf(stdout, "\t%s\n", i->second.GetCommandLineString().c_str());
 935 #endif
 936   }
 937
 938   fflush(stdout);
 939
 940   // Arm the timer again - otherwise it would fire only once.
 941   watchdog_timer_.Reset();
 942 }
 943
 944 std::string GetTestOutputSnippet(const TestResult& result,
 945                                  const std::string& full_output) {
 946   size_t run_pos = full_output.find(std::string("[ RUN      ] ") +
 947                                     result.full_name);
 948   if (run_pos == std::string::npos)
 949     return std::string();
 950
 951   size_t end_pos = full_output.find(std::string("[  FAILED  ] ") +
 952                                     result.full_name,
 953                                     run_pos);
 954   // Only clip the snippet to the "OK" message if the test really
 955   // succeeded. It still might have e.g. crashed after printing it.
 956   if (end_pos == std::string::npos &&
 957       result.status == TestResult::TEST_SUCCESS) {
 958     end_pos = full_output.find(std::string("[       OK ] ") +
 959                                result.full_name,
 960                                run_pos);
 961   }
 962   if (end_pos != std::string::npos) {
 963     size_t newline_pos = full_output.find("\n", end_pos);
 964     if (newline_pos != std::string::npos)
 965       end_pos = newline_pos + 1;
 966   }
 967
 968   std::string snippet(full_output.substr(run_pos));
 969   if (end_pos != std::string::npos)
 970     snippet = full_output.substr(run_pos, end_pos - run_pos);
 971
 972   return snippet;
 973 }
 974
 975 CommandLine PrepareCommandLineForGTest(const CommandLine& command_line,
 976                                        const std::string& wrapper) {
 977   CommandLine new_command_line(command_line.GetProgram());
 978   CommandLine::SwitchMap switches = command_line.GetSwitches();
 979
 980   // Strip out gtest_repeat flag - this is handled by the launcher process.
 981   switches.erase(kGTestRepeatFlag);
 982
 983   // Don't try to write the final XML report in child processes.
 984   switches.erase(kGTestOutputFlag);
 985
 986   for (CommandLine::SwitchMap::const_iterator iter = switches.begin();
 987        iter != switches.end(); ++iter) {
 988     new_command_line.AppendSwitchNative((*iter).first, (*iter).second);
 989   }
 990
 991   // Prepend wrapper after last CommandLine quasi-copy operation. CommandLine
 992   // does not really support removing switches well, and trying to do that
 993   // on a CommandLine with a wrapper is known to break.
 994   // TODO(phajdan.jr): Give it a try to support CommandLine removing switches.
 995 #if defined(OS_WIN)
 996   new_command_line.PrependWrapper(ASCIIToWide(wrapper));
 997 #elif defined(OS_POSIX)
 998   new_command_line.PrependWrapper(wrapper);
 999 #endif
1000
1001   return new_command_line;
1002 }
1003
1004 // TODO(phajdan.jr): Move to anonymous namespace.
1005 int LaunchChildTestProcessWithOptions(const CommandLine& command_line,
1006                                       const LaunchOptions& options,
1007                                       bool use_job_objects,
1008                                       base::TimeDelta timeout,
1009                                       bool* was_timeout) {
1010 #if defined(OS_POSIX)
1011   // Make sure an option we rely on is present - see LaunchChildGTestProcess.
1012   DCHECK(options.new_process_group);
1013 #endif
1014
1015   LaunchOptions new_options(options);
1016
1017 #if defined(OS_WIN)
1018   DCHECK(!new_options.job_handle);
1019
1020   win::ScopedHandle job_handle;
1021   if (use_job_objects) {
1022     job_handle.Set(CreateJobObject(NULL, NULL));
1023     if (!job_handle.IsValid()) {
1024       LOG(ERROR) << "Could not create JobObject.";
1025       return -1;
1026     }
1027
1028     // Allow break-away from job since sandbox and few other places rely on it
1029     // on Windows versions prior to Windows 8 (which supports nested jobs).
1030     // TODO(phajdan.jr): Do not allow break-away on Windows 8.
1031     if (!SetJobObjectLimitFlags(job_handle.Get(),
1032                                 JOB_OBJECT_LIMIT_KILL_ON_JOB_CLOSE |
1033                                 JOB_OBJECT_LIMIT_BREAKAWAY_OK)) {
1034       LOG(ERROR) << "Could not SetJobObjectLimitFlags.";
1035       return -1;
1036     }
1037
1038     new_options.job_handle = job_handle.Get();
1039   }
1040 #endif  // defined(OS_WIN)
1041
1042 #if defined(OS_LINUX)
1043   // To prevent accidental privilege sharing to an untrusted child, processes
1044   // are started with PR_SET_NO_NEW_PRIVS. Do not set that here, since this
1045   // new child will be privileged and trusted.
1046   new_options.allow_new_privs = true;
1047 #endif
1048
1049   base::ProcessHandle process_handle;
1050
1051   {
1052     // Note how we grab the lock before the process possibly gets created.
1053     // This ensures that when the lock is held, ALL the processes are registered
1054     // in the set.
1055     AutoLock lock(g_live_processes_lock.Get());
1056
1057     if (!base::LaunchProcess(command_line, new_options, &process_handle))
1058       return -1;
1059
1060     g_live_processes.Get().insert(std::make_pair(process_handle, command_line));
1061   }
1062
1063   int exit_code = 0;
1064   if (!base::WaitForExitCodeWithTimeout(process_handle,
1065                                         &exit_code,
1066                                         timeout)) {
1067     *was_timeout = true;
1068     exit_code = -1;  // Set a non-zero exit code to signal a failure.
1069
1070     // Ensure that the process terminates.
1071     base::KillProcess(process_handle, -1, true);
1072   }
1073
1074   {
1075     // Note how we grab the log before issuing a possibly broad process kill.
1076     // Other code parts that grab the log kill processes, so avoid trying
1077     // to do that twice and trigger all kinds of log messages.
1078     AutoLock lock(g_live_processes_lock.Get());
1079
1080 #if defined(OS_POSIX)
1081     if (exit_code != 0) {
1082       // On POSIX, in case the test does not exit cleanly, either due to a crash
1083       // or due to it timing out, we need to clean up any child processes that
1084       // it might have created. On Windows, child processes are automatically
1085       // cleaned up using JobObjects.
1086       base::KillProcessGroup(process_handle);
1087     }
1088 #endif
1089
1090     g_live_processes.Get().erase(process_handle);
1091   }
1092
1093   base::CloseProcessHandle(process_handle);
1094
1095   return exit_code;
1096 }
1097
1098 }  // namespace base