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