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