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