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