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_results_tracker.h"
6
7 #include <stddef.h>
8
9 #include <memory>
10 #include <utility>
11
12 #include "base/base64.h"
13 #include "base/command_line.h"
14 #include "base/files/file.h"
15 #include "base/files/file_path.h"
16 #include "base/files/file_util.h"
17 #include "base/format_macros.h"
18 #include "base/json/json_writer.h"
19 #include "base/json/string_escape.h"
20 #include "base/logging.h"
21 #include "base/strings/string_util.h"
22 #include "base/strings/stringprintf.h"
23 #include "base/test/gtest_util.h"
24 #include "base/test/launcher/test_launcher.h"
25 #include "base/time/time.h"
26 #include "base/values.h"
27
28 namespace base {
29
30 namespace {
31
32 // The default output file for XML output.
33 const FilePath::CharType kDefaultOutputFile[] = FILE_PATH_LITERAL(
34 "test_detail.xml");
35
36 // Converts the given epoch time in milliseconds to a date string in the ISO
37 // 8601 format, without the timezone information.
38 // TODO(xyzzyz): Find a good place in Chromium to put it and refactor all uses
39 // to point to it.
FormatTimeAsIso8601(Time time)40 std::string FormatTimeAsIso8601(Time time) {
41 Time::Exploded exploded;
42 time.UTCExplode(&exploded);
43 return StringPrintf("%04d-%02d-%02dT%02d:%02d:%02d",
44 exploded.year,
45 exploded.month,
46 exploded.day_of_month,
47 exploded.hour,
48 exploded.minute,
49 exploded.second);
50 }
51
52 struct TestSuiteResultsAggregator {
TestSuiteResultsAggregatorbase::__anonfcaa45060111::TestSuiteResultsAggregator53 TestSuiteResultsAggregator()
54 : tests(0), failures(0), disabled(0), errors(0) {}
55
Addbase::__anonfcaa45060111::TestSuiteResultsAggregator56 void Add(const TestResult& result) {
57 tests++;
58 elapsed_time += result.elapsed_time;
59
60 switch (result.status) {
61 case TestResult::TEST_SUCCESS:
62 break;
63 case TestResult::TEST_FAILURE:
64 failures++;
65 break;
66 case TestResult::TEST_EXCESSIVE_OUTPUT:
67 case TestResult::TEST_FAILURE_ON_EXIT:
68 case TestResult::TEST_TIMEOUT:
69 case TestResult::TEST_CRASH:
70 case TestResult::TEST_UNKNOWN:
71 errors++;
72 break;
73 case TestResult::TEST_SKIPPED:
74 disabled++;
75 break;
76 }
77 }
78
79 int tests;
80 int failures;
81 int disabled;
82 int errors;
83
84 TimeDelta elapsed_time;
85 };
86
87 } // namespace
88
TestResultsTracker()89 TestResultsTracker::TestResultsTracker() : iteration_(-1), out_(nullptr) {}
90
~TestResultsTracker()91 TestResultsTracker::~TestResultsTracker() {
92 DCHECK(thread_checker_.CalledOnValidThread());
93
94 if (!out_)
95 return;
96
97 // Maps test case names to test results.
98 typedef std::map<std::string, std::vector<TestResult> > TestCaseMap;
99 TestCaseMap test_case_map;
100
101 TestSuiteResultsAggregator all_tests_aggregator;
102 for (const PerIterationData::ResultsMap::value_type& i
103 : per_iteration_data_[iteration_].results) {
104 // Use the last test result as the final one.
105 TestResult result = i.second.test_results.back();
106 test_case_map[result.GetTestCaseName()].push_back(result);
107 all_tests_aggregator.Add(result);
108 }
109
110 fprintf(out_, "<?xml version=\"1.0\" encoding=\"UTF-8\"?>\n");
111 fprintf(out_,
112 "<testsuites name=\"AllTests\" tests=\"%d\" failures=\"%d\""
113 " disabled=\"%d\" errors=\"%d\" time=\"%.3f\" timestamp=\"%s\">\n",
114 all_tests_aggregator.tests, all_tests_aggregator.failures,
115 all_tests_aggregator.disabled, all_tests_aggregator.errors,
116 all_tests_aggregator.elapsed_time.InSecondsF(),
117 FormatTimeAsIso8601(Time::Now()).c_str());
118
119 for (const TestCaseMap::value_type& i : test_case_map) {
120 const std::string testsuite_name = i.first;
121 const std::vector<TestResult>& results = i.second;
122
123 TestSuiteResultsAggregator aggregator;
124 for (const TestResult& result : results) {
125 aggregator.Add(result);
126 }
127 fprintf(out_,
128 " <testsuite name=\"%s\" tests=\"%d\" "
129 "failures=\"%d\" disabled=\"%d\" errors=\"%d\" time=\"%.3f\" "
130 "timestamp=\"%s\">\n",
131 testsuite_name.c_str(), aggregator.tests, aggregator.failures,
132 aggregator.disabled, aggregator.errors,
133 aggregator.elapsed_time.InSecondsF(),
134 FormatTimeAsIso8601(Time::Now()).c_str());
135
136 for (const TestResult& result : results) {
137 fprintf(out_, " <testcase name=\"%s\" status=\"run\" time=\"%.3f\""
138 " classname=\"%s\">\n",
139 result.GetTestName().c_str(),
140 result.elapsed_time.InSecondsF(),
141 result.GetTestCaseName().c_str());
142 if (result.status != TestResult::TEST_SUCCESS) {
143 // The actual failure message is not propagated up to here, as it's too
144 // much work to escape it properly, and in case of failure, almost
145 // always one needs to look into full log anyway.
146 fprintf(out_, " <failure message=\"\" type=\"\"></failure>\n");
147 }
148 fprintf(out_, " </testcase>\n");
149 }
150 fprintf(out_, " </testsuite>\n");
151 }
152
153 fprintf(out_, "</testsuites>\n");
154 fclose(out_);
155 }
156
Init(const CommandLine & command_line)157 bool TestResultsTracker::Init(const CommandLine& command_line) {
158 DCHECK(thread_checker_.CalledOnValidThread());
159
160 // Prevent initializing twice.
161 if (out_) {
162 NOTREACHED();
163 return false;
164 }
165
166 if (!command_line.HasSwitch(kGTestOutputFlag))
167 return true;
168
169 std::string flag = command_line.GetSwitchValueASCII(kGTestOutputFlag);
170 size_t colon_pos = flag.find(':');
171 FilePath path;
172 if (colon_pos != std::string::npos) {
173 FilePath flag_path =
174 command_line.GetSwitchValuePath(kGTestOutputFlag);
175 FilePath::StringType path_string = flag_path.value();
176 path = FilePath(path_string.substr(colon_pos + 1));
177 // If the given path ends with '/', consider it is a directory.
178 // Note: This does NOT check that a directory (or file) actually exists
179 // (the behavior is same as what gtest does).
180 if (path.EndsWithSeparator()) {
181 FilePath executable = command_line.GetProgram().BaseName();
182 path = path.Append(executable.ReplaceExtension(
183 FilePath::StringType(FILE_PATH_LITERAL("xml"))));
184 }
185 }
186 if (path.value().empty())
187 path = FilePath(kDefaultOutputFile);
188 FilePath dir_name = path.DirName();
189 if (!DirectoryExists(dir_name)) {
190 LOG(WARNING) << "The output directory does not exist. "
191 << "Creating the directory: " << dir_name.value();
192 // Create the directory if necessary (because the gtest does the same).
193 if (!CreateDirectory(dir_name)) {
194 LOG(ERROR) << "Failed to created directory " << dir_name.value();
195 return false;
196 }
197 }
198 out_ = OpenFile(path, "w");
199 if (!out_) {
200 LOG(ERROR) << "Cannot open output file: "
201 << path.value() << ".";
202 return false;
203 }
204
205 return true;
206 }
207
OnTestIterationStarting()208 void TestResultsTracker::OnTestIterationStarting() {
209 DCHECK(thread_checker_.CalledOnValidThread());
210
211 // Start with a fresh state for new iteration.
212 iteration_++;
213 per_iteration_data_.push_back(PerIterationData());
214 }
215
AddTest(const std::string & test_name)216 void TestResultsTracker::AddTest(const std::string& test_name) {
217 // Record disabled test names without DISABLED_ prefix so that they are easy
218 // to compare with regular test names, e.g. before or after disabling.
219 all_tests_.insert(TestNameWithoutDisabledPrefix(test_name));
220 }
221
AddDisabledTest(const std::string & test_name)222 void TestResultsTracker::AddDisabledTest(const std::string& test_name) {
223 // Record disabled test names without DISABLED_ prefix so that they are easy
224 // to compare with regular test names, e.g. before or after disabling.
225 disabled_tests_.insert(TestNameWithoutDisabledPrefix(test_name));
226 }
227
AddTestLocation(const std::string & test_name,const std::string & file,int line)228 void TestResultsTracker::AddTestLocation(const std::string& test_name,
229 const std::string& file,
230 int line) {
231 test_locations_.insert(std::make_pair(test_name, CodeLocation(file, line)));
232 }
233
AddTestResult(const TestResult & result)234 void TestResultsTracker::AddTestResult(const TestResult& result) {
235 DCHECK(thread_checker_.CalledOnValidThread());
236
237 // Record disabled test names without DISABLED_ prefix so that they are easy
238 // to compare with regular test names, e.g. before or after disabling.
239 per_iteration_data_[iteration_].results[
240 TestNameWithoutDisabledPrefix(result.full_name)].test_results.push_back(
241 result);
242 }
243
PrintSummaryOfCurrentIteration() const244 void TestResultsTracker::PrintSummaryOfCurrentIteration() const {
245 TestStatusMap tests_by_status(GetTestStatusMapForCurrentIteration());
246
247 PrintTests(tests_by_status[TestResult::TEST_FAILURE].begin(),
248 tests_by_status[TestResult::TEST_FAILURE].end(),
249 "failed");
250 PrintTests(tests_by_status[TestResult::TEST_FAILURE_ON_EXIT].begin(),
251 tests_by_status[TestResult::TEST_FAILURE_ON_EXIT].end(),
252 "failed on exit");
253 PrintTests(tests_by_status[TestResult::TEST_EXCESSIVE_OUTPUT].begin(),
254 tests_by_status[TestResult::TEST_EXCESSIVE_OUTPUT].end(),
255 "produced excessive output");
256 PrintTests(tests_by_status[TestResult::TEST_TIMEOUT].begin(),
257 tests_by_status[TestResult::TEST_TIMEOUT].end(),
258 "timed out");
259 PrintTests(tests_by_status[TestResult::TEST_CRASH].begin(),
260 tests_by_status[TestResult::TEST_CRASH].end(),
261 "crashed");
262 PrintTests(tests_by_status[TestResult::TEST_SKIPPED].begin(),
263 tests_by_status[TestResult::TEST_SKIPPED].end(),
264 "skipped");
265 PrintTests(tests_by_status[TestResult::TEST_UNKNOWN].begin(),
266 tests_by_status[TestResult::TEST_UNKNOWN].end(),
267 "had unknown result");
268 }
269
PrintSummaryOfAllIterations() const270 void TestResultsTracker::PrintSummaryOfAllIterations() const {
271 DCHECK(thread_checker_.CalledOnValidThread());
272
273 TestStatusMap tests_by_status(GetTestStatusMapForAllIterations());
274
275 fprintf(stdout, "Summary of all test iterations:\n");
276 fflush(stdout);
277
278 PrintTests(tests_by_status[TestResult::TEST_FAILURE].begin(),
279 tests_by_status[TestResult::TEST_FAILURE].end(),
280 "failed");
281 PrintTests(tests_by_status[TestResult::TEST_FAILURE_ON_EXIT].begin(),
282 tests_by_status[TestResult::TEST_FAILURE_ON_EXIT].end(),
283 "failed on exit");
284 PrintTests(tests_by_status[TestResult::TEST_EXCESSIVE_OUTPUT].begin(),
285 tests_by_status[TestResult::TEST_EXCESSIVE_OUTPUT].end(),
286 "produced excessive output");
287 PrintTests(tests_by_status[TestResult::TEST_TIMEOUT].begin(),
288 tests_by_status[TestResult::TEST_TIMEOUT].end(),
289 "timed out");
290 PrintTests(tests_by_status[TestResult::TEST_CRASH].begin(),
291 tests_by_status[TestResult::TEST_CRASH].end(),
292 "crashed");
293 PrintTests(tests_by_status[TestResult::TEST_SKIPPED].begin(),
294 tests_by_status[TestResult::TEST_SKIPPED].end(),
295 "skipped");
296 PrintTests(tests_by_status[TestResult::TEST_UNKNOWN].begin(),
297 tests_by_status[TestResult::TEST_UNKNOWN].end(),
298 "had unknown result");
299
300 fprintf(stdout, "End of the summary.\n");
301 fflush(stdout);
302 }
303
AddGlobalTag(const std::string & tag)304 void TestResultsTracker::AddGlobalTag(const std::string& tag) {
305 global_tags_.insert(tag);
306 }
307
SaveSummaryAsJSON(const FilePath & path,const std::vector<std::string> & additional_tags) const308 bool TestResultsTracker::SaveSummaryAsJSON(
309 const FilePath& path,
310 const std::vector<std::string>& additional_tags) const {
311 std::unique_ptr<DictionaryValue> summary_root(new DictionaryValue);
312
313 std::unique_ptr<ListValue> global_tags(new ListValue);
314 for (const auto& global_tag : global_tags_) {
315 global_tags->AppendString(global_tag);
316 }
317 for (const auto& tag : additional_tags) {
318 global_tags->AppendString(tag);
319 }
320 summary_root->Set("global_tags", std::move(global_tags));
321
322 std::unique_ptr<ListValue> all_tests(new ListValue);
323 for (const auto& test : all_tests_) {
324 all_tests->AppendString(test);
325 }
326 summary_root->Set("all_tests", std::move(all_tests));
327
328 std::unique_ptr<ListValue> disabled_tests(new ListValue);
329 for (const auto& disabled_test : disabled_tests_) {
330 disabled_tests->AppendString(disabled_test);
331 }
332 summary_root->Set("disabled_tests", std::move(disabled_tests));
333
334 std::unique_ptr<ListValue> per_iteration_data(new ListValue);
335
336 for (int i = 0; i <= iteration_; i++) {
337 std::unique_ptr<DictionaryValue> current_iteration_data(
338 new DictionaryValue);
339
340 for (PerIterationData::ResultsMap::const_iterator j =
341 per_iteration_data_[i].results.begin();
342 j != per_iteration_data_[i].results.end();
343 ++j) {
344 std::unique_ptr<ListValue> test_results(new ListValue);
345
346 for (size_t k = 0; k < j->second.test_results.size(); k++) {
347 const TestResult& test_result = j->second.test_results[k];
348
349 std::unique_ptr<DictionaryValue> test_result_value(new DictionaryValue);
350
351 test_result_value->SetString("status", test_result.StatusAsString());
352 test_result_value->SetInteger(
353 "elapsed_time_ms",
354 static_cast<int>(test_result.elapsed_time.InMilliseconds()));
355
356 bool lossless_snippet = false;
357 if (IsStringUTF8(test_result.output_snippet)) {
358 test_result_value->SetString(
359 "output_snippet", test_result.output_snippet);
360 lossless_snippet = true;
361 } else {
362 test_result_value->SetString(
363 "output_snippet",
364 "<non-UTF-8 snippet, see output_snippet_base64>");
365 }
366
367 // TODO(phajdan.jr): Fix typo in JSON key (losless -> lossless)
368 // making sure not to break any consumers of this data.
369 test_result_value->SetBoolean("losless_snippet", lossless_snippet);
370
371 // Also include the raw version (base64-encoded so that it can be safely
372 // JSON-serialized - there are no guarantees about character encoding
373 // of the snippet). This can be very useful piece of information when
374 // debugging a test failure related to character encoding.
375 std::string base64_output_snippet;
376 Base64Encode(test_result.output_snippet, &base64_output_snippet);
377 test_result_value->SetString("output_snippet_base64",
378 base64_output_snippet);
379
380 std::unique_ptr<ListValue> test_result_parts(new ListValue);
381 for (const TestResultPart& result_part :
382 test_result.test_result_parts) {
383 std::unique_ptr<DictionaryValue> result_part_value(
384 new DictionaryValue);
385 result_part_value->SetString("type", result_part.TypeAsString());
386 result_part_value->SetString("file", result_part.file_name);
387 result_part_value->SetInteger("line", result_part.line_number);
388
389 bool lossless_summary = IsStringUTF8(result_part.summary);
390 if (lossless_summary) {
391 result_part_value->SetString("summary", result_part.summary);
392 } else {
393 result_part_value->SetString(
394 "summary", "<non-UTF-8 snippet, see summary_base64>");
395 }
396 result_part_value->SetBoolean("lossless_summary", lossless_summary);
397
398 std::string encoded_summary;
399 Base64Encode(result_part.summary, &encoded_summary);
400 result_part_value->SetString("summary_base64", encoded_summary);
401
402 bool lossless_message = IsStringUTF8(result_part.message);
403 if (lossless_message) {
404 result_part_value->SetString("message", result_part.message);
405 } else {
406 result_part_value->SetString(
407 "message", "<non-UTF-8 snippet, see message_base64>");
408 }
409 result_part_value->SetBoolean("lossless_message", lossless_message);
410
411 std::string encoded_message;
412 Base64Encode(result_part.message, &encoded_message);
413 result_part_value->SetString("message_base64", encoded_message);
414
415 test_result_parts->Append(std::move(result_part_value));
416 }
417 test_result_value->Set("result_parts", std::move(test_result_parts));
418
419 test_results->Append(std::move(test_result_value));
420 }
421
422 current_iteration_data->SetWithoutPathExpansion(j->first,
423 std::move(test_results));
424 }
425 per_iteration_data->Append(std::move(current_iteration_data));
426 }
427 summary_root->Set("per_iteration_data", std::move(per_iteration_data));
428
429 std::unique_ptr<DictionaryValue> test_locations(new DictionaryValue);
430 for (const auto& item : test_locations_) {
431 std::string test_name = item.first;
432 CodeLocation location = item.second;
433 std::unique_ptr<DictionaryValue> location_value(new DictionaryValue);
434 location_value->SetString("file", location.file);
435 location_value->SetInteger("line", location.line);
436 test_locations->SetWithoutPathExpansion(test_name,
437 std::move(location_value));
438 }
439 summary_root->Set("test_locations", std::move(test_locations));
440
441 std::string json;
442 if (!JSONWriter::Write(*summary_root, &json))
443 return false;
444
445 File output(path, File::FLAG_CREATE_ALWAYS | File::FLAG_WRITE);
446 if (!output.IsValid())
447 return false;
448
449 int json_size = static_cast<int>(json.size());
450 if (output.WriteAtCurrentPos(json.data(), json_size) != json_size) {
451 return false;
452 }
453
454 // File::Flush() will call fsync(). This is important on Fuchsia to ensure
455 // that the file is written to the disk - the system running under qemu will
456 // shutdown shortly after the test completes. On Fuchsia fsync() times out
457 // after 15 seconds. Apparently this may not be enough in some cases,
458 // particularly when running net_unittests on buildbots, see
459 // https://crbug.com/796318. Try calling fsync() more than once to workaround
460 // this issue.
461 //
462 // TODO(sergeyu): Figure out a better solution.
463 int flush_attempts_left = 4;
464 while (flush_attempts_left-- > 0) {
465 if (output.Flush())
466 return true;
467 LOG(ERROR) << "fsync() failed when saving test output summary. "
468 << ((flush_attempts_left > 0) ? "Retrying." : " Giving up.");
469 }
470
471 return false;
472 }
473
474 TestResultsTracker::TestStatusMap
GetTestStatusMapForCurrentIteration() const475 TestResultsTracker::GetTestStatusMapForCurrentIteration() const {
476 TestStatusMap tests_by_status;
477 GetTestStatusForIteration(iteration_, &tests_by_status);
478 return tests_by_status;
479 }
480
481 TestResultsTracker::TestStatusMap
GetTestStatusMapForAllIterations() const482 TestResultsTracker::GetTestStatusMapForAllIterations() const {
483 TestStatusMap tests_by_status;
484 for (int i = 0; i <= iteration_; i++)
485 GetTestStatusForIteration(i, &tests_by_status);
486 return tests_by_status;
487 }
488
GetTestStatusForIteration(int iteration,TestStatusMap * map) const489 void TestResultsTracker::GetTestStatusForIteration(
490 int iteration, TestStatusMap* map) const {
491 for (PerIterationData::ResultsMap::const_iterator j =
492 per_iteration_data_[iteration].results.begin();
493 j != per_iteration_data_[iteration].results.end();
494 ++j) {
495 // Use the last test result as the final one.
496 const TestResult& result = j->second.test_results.back();
497 (*map)[result.status].insert(result.full_name);
498 }
499 }
500
501 // Utility function to print a list of test names. Uses iterator to be
502 // compatible with different containers, like vector and set.
503 template<typename InputIterator>
PrintTests(InputIterator first,InputIterator last,const std::string & description) const504 void TestResultsTracker::PrintTests(InputIterator first,
505 InputIterator last,
506 const std::string& description) const {
507 size_t count = std::distance(first, last);
508 if (count == 0)
509 return;
510
511 fprintf(stdout,
512 "%" PRIuS " test%s %s:\n",
513 count,
514 count != 1 ? "s" : "",
515 description.c_str());
516 for (InputIterator it = first; it != last; ++it) {
517 const std::string& test_name = *it;
518 const auto location_it = test_locations_.find(test_name);
519 DCHECK(location_it != test_locations_.end()) << test_name;
520 const CodeLocation& location = location_it->second;
521 fprintf(stdout, " %s (%s:%d)\n", test_name.c_str(),
522 location.file.c_str(), location.line);
523 }
524 fflush(stdout);
525 }
526
527 TestResultsTracker::AggregateTestResult::AggregateTestResult() = default;
528
529 TestResultsTracker::AggregateTestResult::AggregateTestResult(
530 const AggregateTestResult& other) = default;
531
532 TestResultsTracker::AggregateTestResult::~AggregateTestResult() = default;
533
534 TestResultsTracker::PerIterationData::PerIterationData() = default;
535
536 TestResultsTracker::PerIterationData::PerIterationData(
537 const PerIterationData& other) = default;
538
539 TestResultsTracker::PerIterationData::~PerIterationData() = default;
540
541 } // namespace base
542