net/log/net_log_unittest.cc

   1 // Copyright (c) 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 "net/log/net_log.h"
   6
   7 #include "base/bind.h"
   8 #include "base/memory/scoped_vector.h"
   9 #include "base/synchronization/waitable_event.h"
  10 #include "base/threading/simple_thread.h"
  11 #include "base/values.h"
  12 #include "net/base/net_errors.h"
  13 #include "net/log/test_net_log.h"
  14 #include "net/log/test_net_log_entry.h"
  15 #include "net/log/test_net_log_util.h"
  16
  17 namespace net {
  18
  19 namespace {
  20
  21 const int kThreads = 10;
  22 const int kEvents = 100;
  23
  24 // Under the hood a NetLogCaptureMode is simply an int. But for layering reasons
  25 // this internal value is not exposed. These tests need to serialize a
  26 // NetLogCaptureMode to a base::Value, so create our own private mapping.
  27 int CaptureModeToInt(NetLogCaptureMode capture_mode) {
  28   if (capture_mode == NetLogCaptureMode::Default())
  29     return 0;
  30   if (capture_mode == NetLogCaptureMode::IncludeCookiesAndCredentials())
  31     return 1;
  32   if (capture_mode == NetLogCaptureMode::IncludeSocketBytes())
  33     return 2;
  34
  35   ADD_FAILURE() << "Unknown capture mode";
  36   return -1;
  37 }
  38
  39 scoped_ptr<base::Value> CaptureModeToValue(NetLogCaptureMode capture_mode) {
  40   return make_scoped_ptr(
  41       new base::FundamentalValue(CaptureModeToInt(capture_mode)));
  42 }
  43
  44 scoped_ptr<base::Value> NetCaptureModeCallback(NetLogCaptureMode capture_mode) {
  45   scoped_ptr<base::DictionaryValue> dict(new base::DictionaryValue());
  46   dict->Set("capture_mode", CaptureModeToValue(capture_mode));
  47   return dict.Pass();
  48 }
  49
  50 TEST(NetLogTest, Basic) {
  51   TestNetLog net_log;
  52   TestNetLogEntry::List entries;
  53   net_log.GetEntries(&entries);
  54   EXPECT_EQ(0u, entries.size());
  55
  56   net_log.AddGlobalEntry(NetLog::TYPE_CANCELLED);
  57
  58   net_log.GetEntries(&entries);
  59   ASSERT_EQ(1u, entries.size());
  60   EXPECT_EQ(NetLog::TYPE_CANCELLED, entries[0].type);
  61   EXPECT_EQ(NetLog::SOURCE_NONE, entries[0].source.type);
  62   EXPECT_NE(NetLog::Source::kInvalidId, entries[0].source.id);
  63   EXPECT_EQ(NetLog::PHASE_NONE, entries[0].phase);
  64   EXPECT_GE(base::TimeTicks::Now(), entries[0].time);
  65   EXPECT_FALSE(entries[0].params);
  66 }
  67
  68 // Check that the correct CaptureMode is sent to NetLog Value callbacks.
  69 TEST(NetLogTest, CaptureModes) {
  70   NetLogCaptureMode kModes[] = {
  71       NetLogCaptureMode::Default(),
  72       NetLogCaptureMode::IncludeCookiesAndCredentials(),
  73       NetLogCaptureMode::IncludeSocketBytes(),
  74   };
  75
  76   TestNetLog net_log;
  77
  78   for (NetLogCaptureMode mode : kModes) {
  79     net_log.SetCaptureMode(mode);
  80     EXPECT_EQ(mode, net_log.GetObserver()->capture_mode());
  81
  82     net_log.AddGlobalEntry(NetLog::TYPE_SOCKET_ALIVE,
  83                            base::Bind(NetCaptureModeCallback));
  84
  85     TestNetLogEntry::List entries;
  86     net_log.GetEntries(&entries);
  87
  88     ASSERT_EQ(1u, entries.size());
  89     EXPECT_EQ(NetLog::TYPE_SOCKET_ALIVE, entries[0].type);
  90     EXPECT_EQ(NetLog::SOURCE_NONE, entries[0].source.type);
  91     EXPECT_NE(NetLog::Source::kInvalidId, entries[0].source.id);
  92     EXPECT_EQ(NetLog::PHASE_NONE, entries[0].phase);
  93     EXPECT_GE(base::TimeTicks::Now(), entries[0].time);
  94
  95     int logged_capture_mode;
  96     ASSERT_TRUE(
  97         entries[0].GetIntegerValue("capture_mode", &logged_capture_mode));
  98     EXPECT_EQ(CaptureModeToInt(mode), logged_capture_mode);
  99
 100     net_log.Clear();
 101   }
 102 }
 103
 104 class CountingObserver : public NetLog::ThreadSafeObserver {
 105  public:
 106   CountingObserver() : count_(0) {}
 107
 108   ~CountingObserver() override {
 109     if (net_log())
 110       net_log()->DeprecatedRemoveObserver(this);
 111   }
 112
 113   void OnAddEntry(const NetLog::Entry& entry) override { ++count_; }
 114
 115   int count() const { return count_; }
 116
 117  private:
 118   int count_;
 119 };
 120
 121 class LoggingObserver : public NetLog::ThreadSafeObserver {
 122  public:
 123   LoggingObserver() {}
 124
 125   ~LoggingObserver() override {
 126     if (net_log())
 127       net_log()->DeprecatedRemoveObserver(this);
 128   }
 129
 130   void OnAddEntry(const NetLog::Entry& entry) override {
 131     base::Value* value = entry.ToValue();
 132     base::DictionaryValue* dict = NULL;
 133     ASSERT_TRUE(value->GetAsDictionary(&dict));
 134     values_.push_back(dict);
 135   }
 136
 137   size_t GetNumValues() const { return values_.size(); }
 138   base::DictionaryValue* GetValue(size_t index) const { return values_[index]; }
 139
 140  private:
 141   ScopedVector<base::DictionaryValue> values_;
 142 };
 143
 144 void AddEvent(NetLog* net_log) {
 145   net_log->AddGlobalEntry(NetLog::TYPE_CANCELLED,
 146                           base::Bind(CaptureModeToValue));
 147 }
 148
 149 // A thread that waits until an event has been signalled before calling
 150 // RunTestThread.
 151 class NetLogTestThread : public base::SimpleThread {
 152  public:
 153   NetLogTestThread()
 154       : base::SimpleThread("NetLogTest"), net_log_(NULL), start_event_(NULL) {}
 155
 156   // We'll wait for |start_event| to be triggered before calling a subclass's
 157   // subclass's RunTestThread() function.
 158   void Init(NetLog* net_log, base::WaitableEvent* start_event) {
 159     start_event_ = start_event;
 160     net_log_ = net_log;
 161   }
 162
 163   void Run() override {
 164     start_event_->Wait();
 165     RunTestThread();
 166   }
 167
 168   // Subclasses must override this with the code they want to run on their
 169   // thread.
 170   virtual void RunTestThread() = 0;
 171
 172  protected:
 173   NetLog* net_log_;
 174
 175  private:
 176   // Only triggered once all threads have been created, to make it less likely
 177   // each thread completes before the next one starts.
 178   base::WaitableEvent* start_event_;
 179
 180   DISALLOW_COPY_AND_ASSIGN(NetLogTestThread);
 181 };
 182
 183 // A thread that adds a bunch of events to the NetLog.
 184 class AddEventsTestThread : public NetLogTestThread {
 185  public:
 186   AddEventsTestThread() {}
 187   ~AddEventsTestThread() override {}
 188
 189  private:
 190   void RunTestThread() override {
 191     for (int i = 0; i < kEvents; ++i)
 192       AddEvent(net_log_);
 193   }
 194
 195   DISALLOW_COPY_AND_ASSIGN(AddEventsTestThread);
 196 };
 197
 198 // A thread that adds and removes an observer from the NetLog repeatedly.
 199 class AddRemoveObserverTestThread : public NetLogTestThread {
 200  public:
 201   AddRemoveObserverTestThread() {}
 202
 203   ~AddRemoveObserverTestThread() override { EXPECT_TRUE(!observer_.net_log()); }
 204
 205  private:
 206   void RunTestThread() override {
 207     for (int i = 0; i < kEvents; ++i) {
 208       ASSERT_FALSE(observer_.net_log());
 209
 210       net_log_->DeprecatedAddObserver(
 211           &observer_, NetLogCaptureMode::IncludeCookiesAndCredentials());
 212       ASSERT_EQ(net_log_, observer_.net_log());
 213       ASSERT_EQ(NetLogCaptureMode::IncludeCookiesAndCredentials(),
 214                 observer_.capture_mode());
 215
 216       net_log_->SetObserverCaptureMode(&observer_,
 217                                        NetLogCaptureMode::IncludeSocketBytes());
 218       ASSERT_EQ(net_log_, observer_.net_log());
 219       ASSERT_EQ(NetLogCaptureMode::IncludeSocketBytes(),
 220                 observer_.capture_mode());
 221
 222       net_log_->DeprecatedRemoveObserver(&observer_);
 223       ASSERT_TRUE(!observer_.net_log());
 224     }
 225   }
 226
 227   CountingObserver observer_;
 228
 229   DISALLOW_COPY_AND_ASSIGN(AddRemoveObserverTestThread);
 230 };
 231
 232 // Creates |kThreads| threads of type |ThreadType| and then runs them all
 233 // to completion.
 234 template <class ThreadType>
 235 void RunTestThreads(NetLog* net_log) {
 236   ThreadType threads[kThreads];
 237   base::WaitableEvent start_event(true, false);
 238
 239   for (size_t i = 0; i < arraysize(threads); ++i) {
 240     threads[i].Init(net_log, &start_event);
 241     threads[i].Start();
 242   }
 243
 244   start_event.Signal();
 245
 246   for (size_t i = 0; i < arraysize(threads); ++i)
 247     threads[i].Join();
 248 }
 249
 250 // Makes sure that events on multiple threads are dispatched to all observers.
 251 TEST(NetLogTest, NetLogEventThreads) {
 252   NetLog net_log;
 253
 254   // Attach some observers.  Since they're created after |net_log|, they'll
 255   // safely detach themselves on destruction.
 256   CountingObserver observers[3];
 257   for (size_t i = 0; i < arraysize(observers); ++i) {
 258     net_log.DeprecatedAddObserver(&observers[i],
 259                                   NetLogCaptureMode::IncludeSocketBytes());
 260   }
 261
 262   // Run a bunch of threads to completion, each of which will emit events to
 263   // |net_log|.
 264   RunTestThreads<AddEventsTestThread>(&net_log);
 265
 266   // Check that each observer saw the emitted events.
 267   const int kTotalEvents = kThreads * kEvents;
 268   for (size_t i = 0; i < arraysize(observers); ++i)
 269     EXPECT_EQ(kTotalEvents, observers[i].count());
 270 }
 271
 272 // Test adding and removing a single observer.
 273 TEST(NetLogTest, NetLogAddRemoveObserver) {
 274   NetLog net_log;
 275   CountingObserver observer;
 276
 277   AddEvent(&net_log);
 278   EXPECT_EQ(0, observer.count());
 279   EXPECT_EQ(NULL, observer.net_log());
 280   EXPECT_FALSE(net_log.IsCapturing());
 281
 282   // Add the observer and add an event.
 283   net_log.DeprecatedAddObserver(
 284       &observer, NetLogCaptureMode::IncludeCookiesAndCredentials());
 285   EXPECT_TRUE(net_log.IsCapturing());
 286   EXPECT_EQ(&net_log, observer.net_log());
 287   EXPECT_EQ(NetLogCaptureMode::IncludeCookiesAndCredentials(),
 288             observer.capture_mode());
 289   EXPECT_TRUE(net_log.IsCapturing());
 290
 291   AddEvent(&net_log);
 292   EXPECT_EQ(1, observer.count());
 293
 294   // Change the observer's logging level and add an event.
 295   net_log.SetObserverCaptureMode(&observer,
 296                                  NetLogCaptureMode::IncludeSocketBytes());
 297   EXPECT_EQ(&net_log, observer.net_log());
 298   EXPECT_EQ(NetLogCaptureMode::IncludeSocketBytes(), observer.capture_mode());
 299   EXPECT_TRUE(net_log.IsCapturing());
 300
 301   AddEvent(&net_log);
 302   EXPECT_EQ(2, observer.count());
 303
 304   // Remove observer and add an event.
 305   net_log.DeprecatedRemoveObserver(&observer);
 306   EXPECT_EQ(NULL, observer.net_log());
 307   EXPECT_FALSE(net_log.IsCapturing());
 308
 309   AddEvent(&net_log);
 310   EXPECT_EQ(2, observer.count());
 311
 312   // Add the observer a final time, and add an event.
 313   net_log.DeprecatedAddObserver(&observer,
 314                                 NetLogCaptureMode::IncludeSocketBytes());
 315   EXPECT_EQ(&net_log, observer.net_log());
 316   EXPECT_EQ(NetLogCaptureMode::IncludeSocketBytes(), observer.capture_mode());
 317   EXPECT_TRUE(net_log.IsCapturing());
 318
 319   AddEvent(&net_log);
 320   EXPECT_EQ(3, observer.count());
 321 }
 322
 323 // Test adding and removing two observers at different log levels.
 324 TEST(NetLogTest, NetLogTwoObservers) {
 325   NetLog net_log;
 326   LoggingObserver observer[2];
 327
 328   // Add first observer.
 329   net_log.DeprecatedAddObserver(
 330       &observer[0], NetLogCaptureMode::IncludeCookiesAndCredentials());
 331   EXPECT_EQ(&net_log, observer[0].net_log());
 332   EXPECT_EQ(NULL, observer[1].net_log());
 333   EXPECT_EQ(NetLogCaptureMode::IncludeCookiesAndCredentials(),
 334             observer[0].capture_mode());
 335   EXPECT_TRUE(net_log.IsCapturing());
 336
 337   // Add second observer observer.
 338   net_log.DeprecatedAddObserver(&observer[1],
 339                                 NetLogCaptureMode::IncludeSocketBytes());
 340   EXPECT_EQ(&net_log, observer[0].net_log());
 341   EXPECT_EQ(&net_log, observer[1].net_log());
 342   EXPECT_EQ(NetLogCaptureMode::IncludeCookiesAndCredentials(),
 343             observer[0].capture_mode());
 344   EXPECT_EQ(NetLogCaptureMode::IncludeSocketBytes(),
 345             observer[1].capture_mode());
 346   EXPECT_TRUE(net_log.IsCapturing());
 347
 348   // Add event and make sure both observers receive it at their respective log
 349   // levels.
 350   int param;
 351   AddEvent(&net_log);
 352   ASSERT_EQ(1U, observer[0].GetNumValues());
 353   ASSERT_TRUE(observer[0].GetValue(0)->GetInteger("params", &param));
 354   EXPECT_EQ(CaptureModeToInt(observer[0].capture_mode()), param);
 355   ASSERT_EQ(1U, observer[1].GetNumValues());
 356   ASSERT_TRUE(observer[1].GetValue(0)->GetInteger("params", &param));
 357   EXPECT_EQ(CaptureModeToInt(observer[1].capture_mode()), param);
 358
 359   // Remove second observer.
 360   net_log.DeprecatedRemoveObserver(&observer[1]);
 361   EXPECT_EQ(&net_log, observer[0].net_log());
 362   EXPECT_EQ(NULL, observer[1].net_log());
 363   EXPECT_EQ(NetLogCaptureMode::IncludeCookiesAndCredentials(),
 364             observer[0].capture_mode());
 365   EXPECT_TRUE(net_log.IsCapturing());
 366
 367   // Add event and make sure only second observer gets it.
 368   AddEvent(&net_log);
 369   EXPECT_EQ(2U, observer[0].GetNumValues());
 370   EXPECT_EQ(1U, observer[1].GetNumValues());
 371
 372   // Remove first observer.
 373   net_log.DeprecatedRemoveObserver(&observer[0]);
 374   EXPECT_EQ(NULL, observer[0].net_log());
 375   EXPECT_EQ(NULL, observer[1].net_log());
 376   EXPECT_FALSE(net_log.IsCapturing());
 377
 378   // Add event and make sure neither observer gets it.
 379   AddEvent(&net_log);
 380   EXPECT_EQ(2U, observer[0].GetNumValues());
 381   EXPECT_EQ(1U, observer[1].GetNumValues());
 382 }
 383
 384 // Makes sure that adding and removing observers simultaneously on different
 385 // threads works.
 386 TEST(NetLogTest, NetLogAddRemoveObserverThreads) {
 387   NetLog net_log;
 388
 389   // Run a bunch of threads to completion, each of which will repeatedly add
 390   // and remove an observer, and set its logging level.
 391   RunTestThreads<AddRemoveObserverTestThread>(&net_log);
 392 }
 393
 394 }  // namespace
 395
 396 }  // namespace net