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
48 namespace base {
49
50 // See https://groups.google.com/a/chromium.org/d/msg/chromium-dev/nkdTP7sstSc/uT3FaE_sgkAJ .
51 using ::operator<<;
52
53 // The environment variable name for the total number of test shards.
54 const char kTestTotalShards[] = "GTEST_TOTAL_SHARDS";
55 // The environment variable name for the test shard index.
56 const char kTestShardIndex[] = "GTEST_SHARD_INDEX";
57
58 namespace {
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.
62 const 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.
72 const 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.
77 const 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).
81 LazyInstance<std::map<ProcessHandle, CommandLine> > g_live_processes
82 = LAZY_INSTANCE_INITIALIZER;
83 LazyInstance<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.
88 int g_shutdown_pipe[2] = { -1, -1 };
89
ShutdownPipeSignalHandler(int signal)90 void ShutdownPipeSignalHandler(int signal) {
91 HANDLE_EINTR(write(g_shutdown_pipe[1], "q", 1));
92 }
93
KillSpawnedTestProcesses()94 void 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.
140 class SignalFDWatcher : public MessageLoopForIO::Watcher {
141 public:
SignalFDWatcher()142 SignalFDWatcher() {
143 }
144
OnFileCanReadWithoutBlocking(int fd)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
OnFileCanWriteWithoutBlocking(int fd)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.
TakeInt32FromEnvironment(const char * const var,int32 * result)167 bool 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.
UnsetEnvironmentVariableIfExists(const std::string & name)189 bool 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.
BotModeEnabled()202 bool 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|.
PrepareCommandLineForGTest(const CommandLine & command_line,const std::string & wrapper)211 CommandLine 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.
LaunchChildTestProcessWithOptions(const CommandLine & command_line,const LaunchOptions & options,int flags,base::TimeDelta timeout,bool * was_timeout)243 int 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
RunCallback(const TestLauncher::LaunchChildGTestProcessCallback & callback,int exit_code,const TimeDelta & elapsed_time,bool was_timeout,const std::string & output)340 void 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
DoLaunchChildTestProcess(const CommandLine & command_line,base::TimeDelta timeout,int flags,bool redirect_stdio,scoped_refptr<MessageLoopProxy> message_loop_proxy,const TestLauncher::LaunchChildGTestProcessCallback & callback)349 void 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
437 const char kGTestFilterFlag[] = "gtest_filter";
438 const char kGTestHelpFlag[] = "gtest_help";
439 const char kGTestListTestsFlag[] = "gtest_list_tests";
440 const char kGTestRepeatFlag[] = "gtest_repeat";
441 const char kGTestRunDisabledTestsFlag[] = "gtest_also_run_disabled_tests";
442 const char kGTestOutputFlag[] = "gtest_output";
443
~TestLauncherDelegate()444 TestLauncherDelegate::~TestLauncherDelegate() {
445 }
446
TestLauncher(TestLauncherDelegate * launcher_delegate,size_t parallel_jobs)447 TestLauncher::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
~TestLauncher()467 TestLauncher::~TestLauncher() {
468 if (worker_pool_owner_)
469 worker_pool_owner_->pool()->Shutdown();
470 }
471
Run()472 bool 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
LaunchChildGTestProcess(const CommandLine & command_line,const std::string & wrapper,base::TimeDelta timeout,int flags,const LaunchChildGTestProcessCallback & callback)520 void 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
OnTestFinished(const TestResult & result)550 void 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
FormatFullTestName(const std::string & test_case_name,const std::string & test_name)692 std::string TestLauncher::FormatFullTestName(const std::string& test_case_name,
693 const std::string& test_name) {
694 return test_case_name + "." + test_name;
695 }
696
Init()697 bool 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
RunTests()904 void 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
RunTestIteration()975 void 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
MaybeSaveSummaryAsJSON()996 void 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
OnLaunchTestProcessFinished(const LaunchChildGTestProcessCallback & callback,int exit_code,const TimeDelta & elapsed_time,bool was_timeout,const std::string & output)1007 void 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
OnTestIterationFinished()1018 void 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
OnOutputTimeout()1044 void 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
GetTestOutputSnippet(const TestResult & result,const std::string & full_output)1068 std::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