chrome/test/logging/win/test_log_collector.cc

   1 // Copyright (c) 2012 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 "chrome/test/logging/win/test_log_collector.h"
   6
   7 #include <windows.h>
   8
   9 #include <algorithm>
  10 #include <ios>
  11
  12 #include "base/command_line.h"
  13 #include "base/compiler_specific.h"
  14 #include "base/file_util.h"
  15 #include "base/files/file_path.h"
  16 #include "base/files/scoped_temp_dir.h"
  17 #include "base/lazy_instance.h"
  18 #include "base/logging.h"
  19 #include "base/memory/scoped_ptr.h"
  20 #include "base/strings/stringprintf.h"
  21 #include "chrome/test/base/test_switches.h"
  22 #include "chrome/test/logging/win/file_logger.h"
  23 #include "chrome/test/logging/win/log_file_printer.h"
  24 #include "testing/gtest/include/gtest/gtest.h"
  25
  26 namespace logging_win {
  27
  28 namespace {
  29
  30 const char kTraceLogExtension[] = ".etl";
  31
  32 class TestLogCollector {
  33  public:
  34   TestLogCollector();
  35   ~TestLogCollector();
  36
  37   void Initialize(testing::UnitTest* unit_test);
  38
  39   void SetUp();
  40   void StartSessionForTest(const testing::TestInfo& test_info);
  41   bool LogTestPartResult(const testing::TestPartResult& test_part_result);
  42   void ProcessSessionForTest(const testing::TestInfo& test_info);
  43   void TearDown();
  44
  45  private:
  46   // An EventListener that generally delegates to a given default result
  47   // printer with a few exceptions; see individual method comments for details.
  48   class EventListener : public testing::TestEventListener {
  49    public:
  50     // Ownership of |default_result_printer| is taken by the new instance.
  51     EventListener(TestLogCollector* test_log_collector,
  52                   testing::TestEventListener* default_result_printer);
  53     virtual ~EventListener();
  54
  55     // Sets up the log collector.
  56     virtual void OnTestProgramStart(
  57         const testing::UnitTest& unit_test) OVERRIDE {
  58       test_log_collector_->SetUp();
  59       default_result_printer_->OnTestProgramStart(unit_test);
  60     }
  61
  62     virtual void OnTestIterationStart(const testing::UnitTest& unit_test,
  63                                       int iteration) OVERRIDE {
  64       default_result_printer_->OnTestIterationStart(unit_test, iteration);
  65     }
  66
  67     virtual void OnEnvironmentsSetUpStart(
  68         const testing::UnitTest& unit_test) OVERRIDE {
  69       default_result_printer_->OnEnvironmentsSetUpStart(unit_test);
  70     }
  71
  72     virtual void OnEnvironmentsSetUpEnd(
  73         const testing::UnitTest& unit_test) OVERRIDE {
  74       default_result_printer_->OnEnvironmentsSetUpEnd(unit_test);
  75     }
  76
  77     virtual void OnTestCaseStart(const testing::TestCase& test_case) OVERRIDE {
  78       default_result_printer_->OnTestCaseStart(test_case);
  79     }
  80
  81     // Calls back to the collector to start collecting logs for this test.
  82     virtual void OnTestStart(const testing::TestInfo& test_info) OVERRIDE {
  83       default_result_printer_->OnTestStart(test_info);
  84       test_log_collector_->StartSessionForTest(test_info);
  85     }
  86
  87     // Calls back to the collector with the partial result.  If the collector
  88     // does not handle it, it is given to the default result printer.
  89     virtual void OnTestPartResult(
  90         const testing::TestPartResult& test_part_result) OVERRIDE {
  91       if (!test_log_collector_->LogTestPartResult(test_part_result))
  92         default_result_printer_->OnTestPartResult(test_part_result);
  93     }
  94
  95     // Calls back to the collector to handle the collected log for the test that
  96     // has just ended.
  97     virtual void OnTestEnd(const testing::TestInfo& test_info) OVERRIDE {
  98       test_log_collector_->ProcessSessionForTest(test_info);
  99       default_result_printer_->OnTestEnd(test_info);
 100     }
 101
 102     virtual void OnTestCaseEnd(const testing::TestCase& test_case) OVERRIDE {
 103       default_result_printer_->OnTestCaseEnd(test_case);
 104     }
 105
 106     virtual void OnEnvironmentsTearDownStart(
 107         const testing::UnitTest& unit_test) OVERRIDE {
 108       default_result_printer_->OnEnvironmentsTearDownStart(unit_test);
 109     }
 110
 111     virtual void OnEnvironmentsTearDownEnd(
 112         const testing::UnitTest& unit_test) OVERRIDE {
 113       default_result_printer_->OnEnvironmentsTearDownEnd(unit_test);
 114     }
 115
 116     virtual void OnTestIterationEnd(const testing::UnitTest& unit_test,
 117                                     int iteration) OVERRIDE {
 118       default_result_printer_->OnTestIterationEnd(unit_test, iteration);
 119     }
 120
 121     // Tears down the log collector.
 122     virtual void OnTestProgramEnd(const testing::UnitTest& unit_test) OVERRIDE {
 123       default_result_printer_->OnTestProgramEnd(unit_test);
 124       test_log_collector_->TearDown();
 125     }
 126
 127    private:
 128     TestLogCollector* test_log_collector_;
 129     scoped_ptr<testing::TestEventListener> default_result_printer_;
 130
 131     DISALLOW_COPY_AND_ASSIGN(EventListener);
 132   };
 133
 134   // The Google Test unit test into which the collector has been installed.
 135   testing::UnitTest* unit_test_;
 136
 137   // A temporary directory into which a log file is placed for the duration of
 138   // each test.  Created/destroyed at collector SetUp and TearDown.
 139   base::ScopedTempDir log_temp_dir_;
 140
 141   // The test logger.  Initialized/Unintitialized at collector SetUp and
 142   // TearDown.
 143   scoped_ptr<FileLogger> file_logger_;
 144
 145   // The current log file.  Valid only during a test.
 146   base::FilePath log_file_;
 147
 148   // True if --also-emit-success-logs was specified on the command line.
 149   bool also_emit_success_logs_;
 150
 151   DISALLOW_COPY_AND_ASSIGN(TestLogCollector);
 152 };
 153
 154 base::LazyInstance<TestLogCollector> g_test_log_collector =
 155     LAZY_INSTANCE_INITIALIZER;
 156
 157 // TestLogCollector::EventListener implementation
 158
 159 TestLogCollector::EventListener::EventListener(
 160     TestLogCollector* test_log_collector,
 161     testing::TestEventListener* default_result_printer)
 162     : test_log_collector_(test_log_collector),
 163       default_result_printer_(default_result_printer) {
 164 }
 165
 166 TestLogCollector::EventListener::~EventListener() {
 167 }
 168
 169 // TestLogCollector implementation
 170
 171 TestLogCollector::TestLogCollector()
 172     : unit_test_(NULL), also_emit_success_logs_(false) {
 173 }
 174
 175 TestLogCollector::~TestLogCollector() {
 176 }
 177
 178 void TestLogCollector::Initialize(testing::UnitTest* unit_test) {
 179   if (unit_test_ != NULL) {
 180     CHECK_EQ(unit_test, unit_test_)
 181         << "Cannot install the test log collector in multiple unit tests.";
 182     return;  // Already initialized.
 183   }
 184
 185   // Remove the default result printer and install the collector's listener
 186   // which delegates to the printer.  If the default result printer has already
 187   // been released, log an error and move on.
 188   testing::TestEventListeners& listeners = unit_test->listeners();
 189   testing::TestEventListener* default_result_printer =
 190       listeners.default_result_printer();
 191   if (default_result_printer == NULL) {
 192     LOG(ERROR) << "Failed to initialize the test log collector on account of "
 193                   "another component having released the default result "
 194                   "printer.";
 195   } else {
 196     // Ownership of |default_release_printer| is passed to the new listener, and
 197     // ownership of the new listener is passed to the unit test.
 198     listeners.Append(
 199         new EventListener(this, listeners.Release(default_result_printer)));
 200
 201     also_emit_success_logs_ = CommandLine::ForCurrentProcess()->HasSwitch(
 202         switches::kAlsoEmitSuccessLogs);
 203
 204     unit_test_ = unit_test;
 205   }
 206 }
 207
 208 // Invoked by the listener at test program start to create the temporary log
 209 // directory and initialize the logger.
 210 void TestLogCollector::SetUp() {
 211   if (!log_temp_dir_.CreateUniqueTempDir()) {
 212     LOG(ERROR) << "Failed to create temporary directory to hold log files.";
 213   } else {
 214     file_logger_.reset(new FileLogger());
 215     file_logger_->Initialize();
 216   }
 217 }
 218
 219 // Invoked by the listener at test start to begin collecting logs in a file.
 220 void TestLogCollector::StartSessionForTest(const testing::TestInfo& test_info) {
 221   if (log_temp_dir_.IsValid()) {
 222     std::string log_file_name(test_info.name());
 223     std::replace(log_file_name.begin(), log_file_name.end(), '/', '_');
 224     log_file_name.append(kTraceLogExtension);
 225     log_file_ = log_temp_dir_.path().AppendASCII(log_file_name);
 226
 227     file_logger_->StartLogging(log_file_);
 228   }
 229 }
 230
 231 // Invoked by the listener when a test result is produced to log an event for
 232 // the result.
 233 bool TestLogCollector::LogTestPartResult(
 234     const testing::TestPartResult& test_part_result) {
 235   // Can't handle the event if no trace session.
 236   if (!file_logger_.get() || !file_logger_->is_logging())
 237     return false;
 238
 239   if (test_part_result.type() != testing::TestPartResult::kSuccess) {
 240     // Approximate Google Test's message formatting.
 241     LOG(ERROR)
 242         << base::StringPrintf("%s(%d): error: %s", test_part_result.file_name(),
 243                               test_part_result.line_number(),
 244                               test_part_result.message());
 245   }
 246   return true;
 247 }
 248
 249 // Invoked by the listener at test end to dump the collected log in case of
 250 // error.
 251 void TestLogCollector::ProcessSessionForTest(
 252     const testing::TestInfo& test_info) {
 253   if (file_logger_.get() != NULL && file_logger_->is_logging()) {
 254     file_logger_->StopLogging();
 255
 256     if (also_emit_success_logs_ || test_info.result()->Failed()) {
 257       std::cerr << "----- log messages for "
 258                 << test_info.test_case_name() << "." << test_info.name()
 259                 << " above this line are repeated below -----" << std::endl;
 260       // Dump the log to stderr.
 261       logging_win::PrintLogFile(log_file_, &std::cerr);
 262       std::cerr.flush();
 263     }
 264
 265     if (!base::DeleteFile(log_file_, false))
 266       LOG(ERROR) << "Failed to delete log file " << log_file_.value();
 267   }
 268
 269   log_file_.clear();
 270 }
 271
 272 // Invoked by the listener at test program end to shut down the logger and
 273 // delete the temporary log directory.
 274 void TestLogCollector::TearDown() {
 275   file_logger_.reset();
 276
 277   ignore_result(log_temp_dir_.Delete());
 278 }
 279
 280 }  // namespace
 281
 282 void InstallTestLogCollector(testing::UnitTest* unit_test) {
 283   // Must be called before running any tests.
 284   DCHECK(unit_test);
 285   DCHECK(!unit_test->current_test_case());
 286
 287   g_test_log_collector.Get().Initialize(unit_test);
 288 }
 289
 290 }  // namespace logging_win