unit_test_launcher.cc revision f2477e01787aa58f445919b809d89e252beef54f
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/unit_test_launcher.h"
6
7#include "base/bind.h"
8#include "base/callback_helpers.h"
9#include "base/command_line.h"
10#include "base/compiler_specific.h"
11#include "base/file_util.h"
12#include "base/files/scoped_temp_dir.h"
13#include "base/format_macros.h"
14#include "base/message_loop/message_loop.h"
15#include "base/stl_util.h"
16#include "base/strings/string_number_conversions.h"
17#include "base/strings/string_util.h"
18#include "base/sys_info.h"
19#include "base/test/gtest_xml_util.h"
20#include "base/test/launcher/test_launcher.h"
21#include "base/test/test_switches.h"
22#include "base/test/test_timeouts.h"
23#include "base/threading/thread_checker.h"
24#include "testing/gtest/include/gtest/gtest.h"
25
26namespace base {
27
28namespace {
29
30// This constant controls how many tests are run in a single batch by default.
31const size_t kDefaultTestBatchLimit = 10;
32
33const char kHelpFlag[] = "help";
34
35// Flag to enable the new launcher logic.
36// TODO(phajdan.jr): Remove it, http://crbug.com/236893 .
37const char kBraveNewTestLauncherFlag[] = "brave-new-test-launcher";
38
39// Flag to run all tests in a single process.
40const char kSingleProcessTestsFlag[] = "single-process-tests";
41
42void PrintUsage() {
43  fprintf(stdout,
44          "Runs tests using the gtest framework, each batch of tests being\n"
45          "run in their own process. Supported command-line flags:\n"
46          "\n"
47          "  --single-process-tests\n"
48          "    Runs the tests and the launcher in the same process. Useful\n"
49          "    for debugging a specific test in a debugger.\n"
50          "  --test-launcher-jobs=N\n"
51          "    Sets the number of parallel test jobs to N.\n"
52          "  --test-launcher-batch-limit=N\n"
53          "    Sets the limit of test batch to run in a single process to N.\n"
54          "  --gtest_filter=...\n"
55          "    Runs a subset of tests (see --gtest_help for more info).\n"
56          "  --help\n"
57          "    Shows this message.\n"
58          "  --gtest_help\n"
59          "    Shows the gtest help message.\n");
60  fflush(stdout);
61}
62
63// Returns command line for child GTest process based on the command line
64// of current process. |test_names| is a vector of test full names
65// (e.g. "A.B"), |output_file| is path to the GTest XML output file.
66CommandLine GetCommandLineForChildGTestProcess(
67    const std::vector<std::string>& test_names,
68    const base::FilePath& output_file) {
69  CommandLine new_cmd_line(*CommandLine::ForCurrentProcess());
70
71  new_cmd_line.AppendSwitchPath(switches::kTestLauncherOutput, output_file);
72  new_cmd_line.AppendSwitchASCII(kGTestFilterFlag, JoinString(test_names, ":"));
73  new_cmd_line.AppendSwitch(kSingleProcessTestsFlag);
74  new_cmd_line.AppendSwitch(kBraveNewTestLauncherFlag);
75
76  return new_cmd_line;
77}
78
79class UnitTestLauncherDelegate : public TestLauncherDelegate {
80 public:
81  explicit UnitTestLauncherDelegate(size_t batch_limit)
82      : batch_limit_(batch_limit) {
83  }
84
85  virtual ~UnitTestLauncherDelegate() {
86    DCHECK(thread_checker_.CalledOnValidThread());
87  }
88
89 private:
90  struct GTestCallbackState {
91    TestLauncher* test_launcher;
92    std::vector<std::string> test_names;
93    FilePath output_file;
94  };
95
96  virtual void OnTestIterationStarting() OVERRIDE {
97    // Nothing to do.
98  }
99
100  virtual std::string GetTestNameForFiltering(
101      const testing::TestCase* test_case,
102      const testing::TestInfo* test_info) OVERRIDE {
103    DCHECK(thread_checker_.CalledOnValidThread());
104
105    return std::string(test_case->name()) + "." + test_info->name();
106  }
107
108  virtual bool ShouldRunTest(const testing::TestCase* test_case,
109                             const testing::TestInfo* test_info) OVERRIDE {
110    DCHECK(thread_checker_.CalledOnValidThread());
111
112    // There is no additional logic to disable specific tests.
113    return true;
114  }
115
116  virtual size_t RunTests(TestLauncher* test_launcher,
117                          const std::vector<std::string>& test_names) OVERRIDE {
118    DCHECK(thread_checker_.CalledOnValidThread());
119
120    std::vector<std::string> batch;
121    for (size_t i = 0; i < test_names.size(); i++) {
122      batch.push_back(test_names[i]);
123
124      if (batch.size() >= batch_limit_) {
125        RunBatch(test_launcher, batch);
126        batch.clear();
127      }
128    }
129
130    RunBatch(test_launcher, batch);
131
132    return test_names.size();
133  }
134
135  virtual size_t RetryTests(
136      TestLauncher* test_launcher,
137      const std::vector<std::string>& test_names) OVERRIDE {
138    MessageLoop::current()->PostTask(
139        FROM_HERE,
140        Bind(&UnitTestLauncherDelegate::RunSerially,
141             Unretained(this),
142             test_launcher,
143             test_names));
144    return test_names.size();
145  }
146
147  void RunSerially(TestLauncher* test_launcher,
148                   const std::vector<std::string>& test_names) {
149    if (test_names.empty())
150      return;
151
152    std::vector<std::string> new_test_names(test_names);
153    std::string test_name(new_test_names.back());
154    new_test_names.pop_back();
155
156    // Create a dedicated temporary directory to store the xml result data
157    // per run to ensure clean state and make it possible to launch multiple
158    // processes in parallel.
159    base::FilePath output_file;
160    CHECK(file_util::CreateNewTempDirectory(FilePath::StringType(),
161                                            &output_file));
162    output_file = output_file.AppendASCII("test_results.xml");
163
164    std::vector<std::string> current_test_names;
165    current_test_names.push_back(test_name);
166    CommandLine cmd_line(
167        GetCommandLineForChildGTestProcess(current_test_names, output_file));
168
169    GTestCallbackState callback_state;
170    callback_state.test_launcher = test_launcher;
171    callback_state.test_names = current_test_names;
172    callback_state.output_file = output_file;
173
174    test_launcher->LaunchChildGTestProcess(
175        cmd_line,
176        std::string(),
177        TestTimeouts::test_launcher_timeout(),
178        Bind(&UnitTestLauncherDelegate::SerialGTestCallback,
179             Unretained(this),
180             callback_state,
181             new_test_names));
182  }
183
184  void RunBatch(TestLauncher* test_launcher,
185                const std::vector<std::string>& test_names) {
186    DCHECK(thread_checker_.CalledOnValidThread());
187
188    if (test_names.empty())
189      return;
190
191    // Create a dedicated temporary directory to store the xml result data
192    // per run to ensure clean state and make it possible to launch multiple
193    // processes in parallel.
194    base::FilePath output_file;
195    CHECK(file_util::CreateNewTempDirectory(FilePath::StringType(),
196                                            &output_file));
197    output_file = output_file.AppendASCII("test_results.xml");
198
199    CommandLine cmd_line(
200        GetCommandLineForChildGTestProcess(test_names, output_file));
201
202    // Adjust the timeout depending on how many tests we're running
203    // (note that e.g. the last batch of tests will be smaller).
204    // TODO(phajdan.jr): Consider an adaptive timeout, which can change
205    // depending on how many tests ran and how many remain.
206    // Note: do NOT parse child's stdout to do that, it's known to be
207    // unreliable (e.g. buffering issues can mix up the output).
208    base::TimeDelta timeout =
209        test_names.size() * TestTimeouts::test_launcher_timeout();
210
211    GTestCallbackState callback_state;
212    callback_state.test_launcher = test_launcher;
213    callback_state.test_names = test_names;
214    callback_state.output_file = output_file;
215
216    test_launcher->LaunchChildGTestProcess(
217        cmd_line,
218        std::string(),
219        timeout,
220        Bind(&UnitTestLauncherDelegate::GTestCallback,
221             Unretained(this),
222             callback_state));
223  }
224
225  void GTestCallback(const GTestCallbackState& callback_state,
226                     int exit_code,
227                     const TimeDelta& elapsed_time,
228                     bool was_timeout,
229                     const std::string& output) {
230    DCHECK(thread_checker_.CalledOnValidThread());
231    std::vector<std::string> tests_to_relaunch;
232    ProcessTestResults(callback_state.test_launcher,
233                       callback_state.test_names,
234                       callback_state.output_file,
235                       output,
236                       exit_code,
237                       was_timeout,
238                       &tests_to_relaunch);
239
240    // Relaunch requested tests in parallel, but only use single
241    // test per batch for more precise results (crashes, test passes
242    // but non-zero exit codes etc).
243    for (size_t i = 0; i < tests_to_relaunch.size(); i++) {
244      std::vector<std::string> batch;
245      batch.push_back(tests_to_relaunch[i]);
246      RunBatch(callback_state.test_launcher, batch);
247    }
248
249    // The temporary file's directory is also temporary.
250    DeleteFile(callback_state.output_file.DirName(), true);
251  }
252
253  void SerialGTestCallback(const GTestCallbackState& callback_state,
254                           const std::vector<std::string>& test_names,
255                           int exit_code,
256                           const TimeDelta& elapsed_time,
257                           bool was_timeout,
258                           const std::string& output) {
259    DCHECK(thread_checker_.CalledOnValidThread());
260    std::vector<std::string> tests_to_relaunch;
261    bool called_any_callbacks =
262        ProcessTestResults(callback_state.test_launcher,
263                           callback_state.test_names,
264                           callback_state.output_file,
265                           output,
266                           exit_code,
267                           was_timeout,
268                           &tests_to_relaunch);
269
270    // There is only one test, there cannot be other tests to relaunch
271    // due to a crash.
272    DCHECK(tests_to_relaunch.empty());
273
274    // There is only one test, we should have called back with its result.
275    DCHECK(called_any_callbacks);
276
277    // The temporary file's directory is also temporary.
278    DeleteFile(callback_state.output_file.DirName(), true);
279
280    MessageLoop::current()->PostTask(
281        FROM_HERE,
282        Bind(&UnitTestLauncherDelegate::RunSerially,
283             Unretained(this),
284             callback_state.test_launcher,
285             test_names));
286  }
287
288  static bool ProcessTestResults(
289      TestLauncher* test_launcher,
290      const std::vector<std::string>& test_names,
291      const base::FilePath& output_file,
292      const std::string& output,
293      int exit_code,
294      bool was_timeout,
295      std::vector<std::string>* tests_to_relaunch) {
296    std::vector<TestResult> test_results;
297    bool crashed = false;
298    bool have_test_results =
299        ProcessGTestOutput(output_file, &test_results, &crashed);
300
301    bool called_any_callback = false;
302
303    if (have_test_results) {
304      // TODO(phajdan.jr): Check for duplicates and mismatches between
305      // the results we got from XML file and tests we intended to run.
306      std::map<std::string, TestResult> results_map;
307      for (size_t i = 0; i < test_results.size(); i++)
308        results_map[test_results[i].full_name] = test_results[i];
309
310      bool had_interrupted_test = false;
311
312      // Results to be reported back to the test launcher.
313      std::vector<TestResult> final_results;
314
315      for (size_t i = 0; i < test_names.size(); i++) {
316        if (ContainsKey(results_map, test_names[i])) {
317          TestResult test_result = results_map[test_names[i]];
318          if (test_result.status == TestResult::TEST_CRASH) {
319            had_interrupted_test = true;
320
321            if (was_timeout) {
322              // Fix up the test status: we forcibly kill the child process
323              // after the timeout, so from XML results it looks just like
324              // a crash.
325              test_result.status = TestResult::TEST_TIMEOUT;
326            }
327          } else if (test_result.status == TestResult::TEST_SUCCESS ||
328                     test_result.status == TestResult::TEST_FAILURE) {
329            // We run multiple tests in a batch with a timeout applied
330            // to the entire batch. It is possible that with other tests
331            // running quickly some tests take longer than the per-test timeout.
332            // For consistent handling of tests independent of order and other
333            // factors, mark them as timing out.
334            if (test_result.elapsed_time >
335                TestTimeouts::test_launcher_timeout()) {
336              test_result.status = TestResult::TEST_TIMEOUT;
337            }
338          }
339          test_result.output_snippet =
340              GetTestOutputSnippet(test_result, output);
341          final_results.push_back(test_result);
342        } else if (had_interrupted_test) {
343          tests_to_relaunch->push_back(test_names[i]);
344        } else {
345          // TODO(phajdan.jr): Explicitly pass the info that the test didn't
346          // run for a mysterious reason.
347          LOG(ERROR) << "no test result for " << test_names[i];
348          TestResult test_result;
349          test_result.full_name = test_names[i];
350          test_result.status = TestResult::TEST_UNKNOWN;
351          test_result.output_snippet =
352              GetTestOutputSnippet(test_result, output);
353          final_results.push_back(test_result);
354        }
355      }
356
357      // TODO(phajdan.jr): Handle the case where processing XML output
358      // indicates a crash but none of the test results is marked as crashing.
359
360      if (final_results.empty())
361        return false;
362
363      bool has_non_success_test = false;
364      for (size_t i = 0; i < final_results.size(); i++) {
365        if (final_results[i].status != TestResult::TEST_SUCCESS) {
366          has_non_success_test = true;
367          break;
368        }
369      }
370
371      if (!has_non_success_test && exit_code != 0) {
372        // This is a bit surprising case: all tests are marked as successful,
373        // but the exit code was not zero. This can happen e.g. under memory
374        // tools that report leaks this way.
375
376        if (final_results.size() == 1) {
377          // Easy case. One test only so we know the non-zero exit code
378          // was caused by that one test.
379          final_results[0].status = TestResult::TEST_FAILURE_ON_EXIT;
380        } else {
381          // Harder case. Discard the results and request relaunching all
382          // tests without batching. This will trigger above branch on
383          // relaunch leading to more precise results.
384          LOG(WARNING) << "Not sure which test caused non-zero exit code, "
385                       << "relaunching all of them without batching.";
386
387          for (size_t i = 0; i < final_results.size(); i++)
388            tests_to_relaunch->push_back(final_results[i].full_name);
389
390          return false;
391        }
392      }
393
394      for (size_t i = 0; i < final_results.size(); i++) {
395        // Fix the output snippet after possible changes to the test result.
396        final_results[i].output_snippet =
397            GetTestOutputSnippet(final_results[i], output);
398        test_launcher->OnTestFinished(final_results[i]);
399        called_any_callback = true;
400      }
401    } else {
402      fprintf(stdout,
403              "Failed to get out-of-band test success data, "
404              "dumping full stdio below:\n%s\n",
405              output.c_str());
406      fflush(stdout);
407
408      // We do not have reliable details about test results (parsing test
409      // stdout is known to be unreliable), apply the executable exit code
410      // to all tests.
411      // TODO(phajdan.jr): Be smarter about this, e.g. retry each test
412      // individually.
413      for (size_t i = 0; i < test_names.size(); i++) {
414        TestResult test_result;
415        test_result.full_name = test_names[i];
416        test_result.status = TestResult::TEST_UNKNOWN;
417        test_launcher->OnTestFinished(test_result);
418        called_any_callback = true;
419      }
420    }
421
422    return called_any_callback;
423  }
424
425  ThreadChecker thread_checker_;
426
427  // Maximum number of tests to run in a single batch.
428  size_t batch_limit_;
429};
430
431bool GetSwitchValueAsInt(const std::string& switch_name, int* result) {
432  if (!CommandLine::ForCurrentProcess()->HasSwitch(switch_name))
433    return true;
434
435  std::string switch_value =
436      CommandLine::ForCurrentProcess()->GetSwitchValueASCII(switch_name);
437  if (!StringToInt(switch_value, result) || *result < 1) {
438    LOG(ERROR) << "Invalid value for " << switch_name << ": " << switch_value;
439    return false;
440  }
441
442  return true;
443}
444
445}  // namespace
446
447int LaunchUnitTests(int argc,
448                    char** argv,
449                    const RunTestSuiteCallback& run_test_suite) {
450  CommandLine::Init(argc, argv);
451  if (CommandLine::ForCurrentProcess()->HasSwitch(kGTestHelpFlag) ||
452      CommandLine::ForCurrentProcess()->HasSwitch(kSingleProcessTestsFlag) ||
453      !CommandLine::ForCurrentProcess()->HasSwitch(kBraveNewTestLauncherFlag)) {
454    return run_test_suite.Run();
455  }
456
457  if (CommandLine::ForCurrentProcess()->HasSwitch(kHelpFlag)) {
458    PrintUsage();
459    return 0;
460  }
461
462  base::TimeTicks start_time(base::TimeTicks::Now());
463
464  testing::InitGoogleTest(&argc, argv);
465  TestTimeouts::Initialize();
466
467  int batch_limit = kDefaultTestBatchLimit;
468  if (!GetSwitchValueAsInt(switches::kTestLauncherBatchLimit, &batch_limit))
469    return 1;
470
471  fprintf(stdout,
472          "IMPORTANT DEBUGGING NOTE: batches of tests are run inside their\n"
473          "own process. For debugging a test inside a debugger, use the\n"
474          "--gtest_filter=<your_test_name> flag along with\n"
475          "--single-process-tests.\n");
476  fflush(stdout);
477
478  MessageLoopForIO message_loop;
479
480  base::UnitTestLauncherDelegate delegate(batch_limit);
481  base::TestLauncher launcher(&delegate, SysInfo::NumberOfProcessors());
482  bool success = launcher.Run(argc, argv);
483
484  fprintf(stdout,
485          "Tests took %" PRId64 " seconds.\n",
486          (base::TimeTicks::Now() - start_time).InSeconds());
487  fflush(stdout);
488
489  return (success ? 0 : 1);
490}
491
492}  // namespace base
493