| OLD | NEW |
| (Empty) |
| 1 // Copyright 2014 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/trace_net_log_observer.h" | |
| 6 | |
| 7 #include <string> | |
| 8 #include <vector> | |
| 9 | |
| 10 #include "base/json/json_reader.h" | |
| 11 #include "base/logging.h" | |
| 12 #include "base/memory/ref_counted.h" | |
| 13 #include "base/memory/ref_counted_memory.h" | |
| 14 #include "base/memory/scoped_ptr.h" | |
| 15 #include "base/run_loop.h" | |
| 16 #include "base/strings/stringprintf.h" | |
| 17 #include "base/trace_event/trace_event.h" | |
| 18 #include "base/trace_event/trace_event_impl.h" | |
| 19 #include "base/values.h" | |
| 20 #include "net/base/capturing_net_log.h" | |
| 21 #include "net/base/net_log.h" | |
| 22 #include "testing/gtest/include/gtest/gtest.h" | |
| 23 | |
| 24 using base::trace_event::TraceLog; | |
| 25 | |
| 26 namespace net { | |
| 27 | |
| 28 namespace { | |
| 29 | |
| 30 // TraceLog category for NetLog events. | |
| 31 const char kNetLogTracingCategory[] = TRACE_DISABLED_BY_DEFAULT("netlog"); | |
| 32 | |
| 33 struct TraceEntryInfo { | |
| 34 std::string category; | |
| 35 std::string id; | |
| 36 std::string phase; | |
| 37 std::string name; | |
| 38 std::string source_type; | |
| 39 }; | |
| 40 | |
| 41 TraceEntryInfo GetTraceEntryInfoFromValue(const base::DictionaryValue& value) { | |
| 42 TraceEntryInfo info; | |
| 43 EXPECT_TRUE(value.GetString("cat", &info.category)); | |
| 44 EXPECT_TRUE(value.GetString("id", &info.id)); | |
| 45 EXPECT_TRUE(value.GetString("ph", &info.phase)); | |
| 46 EXPECT_TRUE(value.GetString("name", &info.name)); | |
| 47 EXPECT_TRUE(value.GetString("args.source_type", &info.source_type)); | |
| 48 | |
| 49 return info; | |
| 50 } | |
| 51 | |
| 52 class TraceNetLogObserverTest : public testing::Test { | |
| 53 public: | |
| 54 TraceNetLogObserverTest() { | |
| 55 TraceLog* tracelog = TraceLog::GetInstance(); | |
| 56 DCHECK(tracelog); | |
| 57 DCHECK(!tracelog->IsEnabled()); | |
| 58 trace_buffer_.SetOutputCallback(json_output_.GetCallback()); | |
| 59 trace_net_log_observer_.reset(new TraceNetLogObserver()); | |
| 60 trace_events_.reset(new base::ListValue()); | |
| 61 } | |
| 62 | |
| 63 ~TraceNetLogObserverTest() override { | |
| 64 DCHECK(!TraceLog::GetInstance()->IsEnabled()); | |
| 65 } | |
| 66 | |
| 67 void OnTraceDataCollected( | |
| 68 base::RunLoop* run_loop, | |
| 69 const scoped_refptr<base::RefCountedString>& events_str, | |
| 70 bool has_more_events) { | |
| 71 DCHECK(trace_events_->empty()); | |
| 72 trace_buffer_.Start(); | |
| 73 trace_buffer_.AddFragment(events_str->data()); | |
| 74 trace_buffer_.Finish(); | |
| 75 | |
| 76 scoped_ptr<base::Value> trace_value; | |
| 77 trace_value.reset(base::JSONReader::Read( | |
| 78 json_output_.json_output, | |
| 79 base::JSON_PARSE_RFC | base::JSON_DETACHABLE_CHILDREN)); | |
| 80 | |
| 81 ASSERT_TRUE(trace_value) << json_output_.json_output; | |
| 82 base::ListValue* trace_events = NULL; | |
| 83 ASSERT_TRUE(trace_value->GetAsList(&trace_events)); | |
| 84 | |
| 85 trace_events_ = FilterNetLogTraceEvents(*trace_events); | |
| 86 | |
| 87 if (!has_more_events) | |
| 88 run_loop->Quit(); | |
| 89 } | |
| 90 | |
| 91 static void EnableTraceLog() { | |
| 92 TraceLog::GetInstance()->SetEnabled( | |
| 93 base::trace_event::CategoryFilter(kNetLogTracingCategory), | |
| 94 TraceLog::RECORDING_MODE, | |
| 95 base::trace_event::TraceOptions()); | |
| 96 } | |
| 97 | |
| 98 void EndTraceAndFlush() { | |
| 99 base::RunLoop run_loop; | |
| 100 TraceLog::GetInstance()->SetDisabled(); | |
| 101 TraceLog::GetInstance()->Flush( | |
| 102 base::Bind(&TraceNetLogObserverTest::OnTraceDataCollected, | |
| 103 base::Unretained(this), | |
| 104 base::Unretained(&run_loop))); | |
| 105 run_loop.Run(); | |
| 106 } | |
| 107 | |
| 108 void set_trace_net_log_observer(TraceNetLogObserver* trace_net_log_observer) { | |
| 109 trace_net_log_observer_.reset(trace_net_log_observer); | |
| 110 } | |
| 111 | |
| 112 static scoped_ptr<base::ListValue> FilterNetLogTraceEvents( | |
| 113 const base::ListValue& trace_events) { | |
| 114 scoped_ptr<base::ListValue> filtered_trace_events(new base::ListValue()); | |
| 115 for (size_t i = 0; i < trace_events.GetSize(); i++) { | |
| 116 const base::DictionaryValue* dict = NULL; | |
| 117 if (!trace_events.GetDictionary(i, &dict)) { | |
| 118 ADD_FAILURE() << "Unexpected non-dictionary event in trace_events"; | |
| 119 continue; | |
| 120 } | |
| 121 std::string category; | |
| 122 if (!dict->GetString("cat", &category)) { | |
| 123 ADD_FAILURE() | |
| 124 << "Unexpected item without a category field in trace_events"; | |
| 125 continue; | |
| 126 } | |
| 127 if (category != kNetLogTracingCategory) | |
| 128 continue; | |
| 129 filtered_trace_events->Append(dict->DeepCopy()); | |
| 130 } | |
| 131 return filtered_trace_events.Pass(); | |
| 132 } | |
| 133 | |
| 134 base::ListValue* trace_events() const { | |
| 135 return trace_events_.get(); | |
| 136 } | |
| 137 | |
| 138 CapturingNetLog* net_log() { | |
| 139 return &net_log_; | |
| 140 } | |
| 141 | |
| 142 TraceNetLogObserver* trace_net_log_observer() const { | |
| 143 return trace_net_log_observer_.get(); | |
| 144 } | |
| 145 | |
| 146 private: | |
| 147 scoped_ptr<base::ListValue> trace_events_; | |
| 148 base::trace_event::TraceResultBuffer trace_buffer_; | |
| 149 base::trace_event::TraceResultBuffer::SimpleOutput json_output_; | |
| 150 CapturingNetLog net_log_; | |
| 151 scoped_ptr<TraceNetLogObserver> trace_net_log_observer_; | |
| 152 }; | |
| 153 | |
| 154 TEST_F(TraceNetLogObserverTest, TracingNotEnabled) { | |
| 155 trace_net_log_observer()->WatchForTraceStart(net_log()); | |
| 156 net_log()->AddGlobalEntry(NetLog::TYPE_REQUEST_ALIVE); | |
| 157 | |
| 158 EndTraceAndFlush(); | |
| 159 trace_net_log_observer()->StopWatchForTraceStart(); | |
| 160 | |
| 161 EXPECT_EQ(0u, trace_events()->GetSize()); | |
| 162 } | |
| 163 | |
| 164 TEST_F(TraceNetLogObserverTest, TraceEventCaptured) { | |
| 165 CapturingNetLog::CapturedEntryList entries; | |
| 166 net_log()->GetEntries(&entries); | |
| 167 EXPECT_TRUE(entries.empty()); | |
| 168 | |
| 169 trace_net_log_observer()->WatchForTraceStart(net_log()); | |
| 170 EnableTraceLog(); | |
| 171 BoundNetLog bound_net_log = | |
| 172 BoundNetLog::Make(net_log(), net::NetLog::SOURCE_NONE); | |
| 173 net_log()->AddGlobalEntry(NetLog::TYPE_CANCELLED); | |
| 174 bound_net_log.BeginEvent(NetLog::TYPE_URL_REQUEST_START_JOB); | |
| 175 bound_net_log.EndEvent(NetLog::TYPE_REQUEST_ALIVE); | |
| 176 | |
| 177 net_log()->GetEntries(&entries); | |
| 178 EXPECT_EQ(3u, entries.size()); | |
| 179 EndTraceAndFlush(); | |
| 180 trace_net_log_observer()->StopWatchForTraceStart(); | |
| 181 EXPECT_EQ(3u, trace_events()->GetSize()); | |
| 182 const base::DictionaryValue* item1 = NULL; | |
| 183 ASSERT_TRUE(trace_events()->GetDictionary(0, &item1)); | |
| 184 const base::DictionaryValue* item2 = NULL; | |
| 185 ASSERT_TRUE(trace_events()->GetDictionary(1, &item2)); | |
| 186 const base::DictionaryValue* item3 = NULL; | |
| 187 ASSERT_TRUE(trace_events()->GetDictionary(2, &item3)); | |
| 188 | |
| 189 TraceEntryInfo actual_item1 = GetTraceEntryInfoFromValue(*item1); | |
| 190 TraceEntryInfo actual_item2 = GetTraceEntryInfoFromValue(*item2); | |
| 191 TraceEntryInfo actual_item3 = GetTraceEntryInfoFromValue(*item3); | |
| 192 EXPECT_EQ(kNetLogTracingCategory, actual_item1.category); | |
| 193 EXPECT_EQ(base::StringPrintf("0x%d", entries[0].source.id), actual_item1.id); | |
| 194 EXPECT_EQ(std::string(1, TRACE_EVENT_PHASE_NESTABLE_ASYNC_INSTANT), | |
| 195 actual_item1.phase); | |
| 196 EXPECT_EQ(NetLog::EventTypeToString(NetLog::TYPE_CANCELLED), | |
| 197 actual_item1.name); | |
| 198 EXPECT_EQ(NetLog::SourceTypeToString(entries[0].source.type), | |
| 199 actual_item1.source_type); | |
| 200 | |
| 201 EXPECT_EQ(kNetLogTracingCategory, actual_item2.category); | |
| 202 EXPECT_EQ(base::StringPrintf("0x%d", entries[1].source.id), actual_item2.id); | |
| 203 EXPECT_EQ(std::string(1, TRACE_EVENT_PHASE_NESTABLE_ASYNC_BEGIN), | |
| 204 actual_item2.phase); | |
| 205 EXPECT_EQ(NetLog::EventTypeToString(NetLog::TYPE_URL_REQUEST_START_JOB), | |
| 206 actual_item2.name); | |
| 207 EXPECT_EQ(NetLog::SourceTypeToString(entries[1].source.type), | |
| 208 actual_item2.source_type); | |
| 209 | |
| 210 EXPECT_EQ(kNetLogTracingCategory, actual_item3.category); | |
| 211 EXPECT_EQ(base::StringPrintf("0x%d", entries[2].source.id), actual_item3.id); | |
| 212 EXPECT_EQ(std::string(1, TRACE_EVENT_PHASE_NESTABLE_ASYNC_END), | |
| 213 actual_item3.phase); | |
| 214 EXPECT_EQ(NetLog::EventTypeToString(NetLog::TYPE_REQUEST_ALIVE), | |
| 215 actual_item3.name); | |
| 216 EXPECT_EQ(NetLog::SourceTypeToString(entries[2].source.type), | |
| 217 actual_item3.source_type); | |
| 218 } | |
| 219 | |
| 220 TEST_F(TraceNetLogObserverTest, EnableAndDisableTracing) { | |
| 221 trace_net_log_observer()->WatchForTraceStart(net_log()); | |
| 222 EnableTraceLog(); | |
| 223 net_log()->AddGlobalEntry(NetLog::TYPE_CANCELLED); | |
| 224 TraceLog::GetInstance()->SetDisabled(); | |
| 225 net_log()->AddGlobalEntry(NetLog::TYPE_REQUEST_ALIVE); | |
| 226 EnableTraceLog(); | |
| 227 net_log()->AddGlobalEntry(NetLog::TYPE_URL_REQUEST_START_JOB); | |
| 228 | |
| 229 EndTraceAndFlush(); | |
| 230 trace_net_log_observer()->StopWatchForTraceStart(); | |
| 231 | |
| 232 CapturingNetLog::CapturedEntryList entries; | |
| 233 net_log()->GetEntries(&entries); | |
| 234 EXPECT_EQ(3u, entries.size()); | |
| 235 EXPECT_EQ(2u, trace_events()->GetSize()); | |
| 236 const base::DictionaryValue* item1 = NULL; | |
| 237 ASSERT_TRUE(trace_events()->GetDictionary(0, &item1)); | |
| 238 const base::DictionaryValue* item2 = NULL; | |
| 239 ASSERT_TRUE(trace_events()->GetDictionary(1, &item2)); | |
| 240 | |
| 241 TraceEntryInfo actual_item1 = GetTraceEntryInfoFromValue(*item1); | |
| 242 TraceEntryInfo actual_item2 = GetTraceEntryInfoFromValue(*item2); | |
| 243 EXPECT_EQ(kNetLogTracingCategory, actual_item1.category); | |
| 244 EXPECT_EQ(base::StringPrintf("0x%d", entries[0].source.id), actual_item1.id); | |
| 245 EXPECT_EQ(std::string(1, TRACE_EVENT_PHASE_NESTABLE_ASYNC_INSTANT), | |
| 246 actual_item1.phase); | |
| 247 EXPECT_EQ(NetLog::EventTypeToString(NetLog::TYPE_CANCELLED), | |
| 248 actual_item1.name); | |
| 249 EXPECT_EQ(NetLog::SourceTypeToString(entries[0].source.type), | |
| 250 actual_item1.source_type); | |
| 251 | |
| 252 EXPECT_EQ(kNetLogTracingCategory, actual_item2.category); | |
| 253 EXPECT_EQ(base::StringPrintf("0x%d", entries[2].source.id), actual_item2.id); | |
| 254 EXPECT_EQ(std::string(1, TRACE_EVENT_PHASE_NESTABLE_ASYNC_INSTANT), | |
| 255 actual_item2.phase); | |
| 256 EXPECT_EQ(NetLog::EventTypeToString(NetLog::TYPE_URL_REQUEST_START_JOB), | |
| 257 actual_item2.name); | |
| 258 EXPECT_EQ(NetLog::SourceTypeToString(entries[2].source.type), | |
| 259 actual_item2.source_type); | |
| 260 } | |
| 261 | |
| 262 TEST_F(TraceNetLogObserverTest, DestroyObserverWhileTracing) { | |
| 263 trace_net_log_observer()->WatchForTraceStart(net_log()); | |
| 264 EnableTraceLog(); | |
| 265 net_log()->AddGlobalEntry(NetLog::TYPE_CANCELLED); | |
| 266 trace_net_log_observer()->StopWatchForTraceStart(); | |
| 267 set_trace_net_log_observer(NULL); | |
| 268 net_log()->AddGlobalEntry(NetLog::TYPE_REQUEST_ALIVE); | |
| 269 | |
| 270 EndTraceAndFlush(); | |
| 271 | |
| 272 CapturingNetLog::CapturedEntryList entries; | |
| 273 net_log()->GetEntries(&entries); | |
| 274 EXPECT_EQ(2u, entries.size()); | |
| 275 EXPECT_EQ(1u, trace_events()->GetSize()); | |
| 276 | |
| 277 const base::DictionaryValue* item1 = NULL; | |
| 278 ASSERT_TRUE(trace_events()->GetDictionary(0, &item1)); | |
| 279 | |
| 280 TraceEntryInfo actual_item1 = GetTraceEntryInfoFromValue(*item1); | |
| 281 EXPECT_EQ(kNetLogTracingCategory, actual_item1.category); | |
| 282 EXPECT_EQ(base::StringPrintf("0x%d", entries[0].source.id), actual_item1.id); | |
| 283 EXPECT_EQ(std::string(1, TRACE_EVENT_PHASE_NESTABLE_ASYNC_INSTANT), | |
| 284 actual_item1.phase); | |
| 285 EXPECT_EQ(NetLog::EventTypeToString(NetLog::TYPE_CANCELLED), | |
| 286 actual_item1.name); | |
| 287 EXPECT_EQ(NetLog::SourceTypeToString(entries[0].source.type), | |
| 288 actual_item1.source_type); | |
| 289 } | |
| 290 | |
| 291 TEST_F(TraceNetLogObserverTest, DestroyObserverWhileNotTracing) { | |
| 292 trace_net_log_observer()->WatchForTraceStart(net_log()); | |
| 293 net_log()->AddGlobalEntry(NetLog::TYPE_CANCELLED); | |
| 294 trace_net_log_observer()->StopWatchForTraceStart(); | |
| 295 set_trace_net_log_observer(NULL); | |
| 296 net_log()->AddGlobalEntry(NetLog::TYPE_REQUEST_ALIVE); | |
| 297 net_log()->AddGlobalEntry(NetLog::TYPE_URL_REQUEST_START_JOB); | |
| 298 | |
| 299 EndTraceAndFlush(); | |
| 300 | |
| 301 CapturingNetLog::CapturedEntryList entries; | |
| 302 net_log()->GetEntries(&entries); | |
| 303 EXPECT_EQ(3u, entries.size()); | |
| 304 EXPECT_EQ(0u, trace_events()->GetSize()); | |
| 305 } | |
| 306 | |
| 307 TEST_F(TraceNetLogObserverTest, CreateObserverAfterTracingStarts) { | |
| 308 set_trace_net_log_observer(NULL); | |
| 309 EnableTraceLog(); | |
| 310 set_trace_net_log_observer(new TraceNetLogObserver()); | |
| 311 trace_net_log_observer()->WatchForTraceStart(net_log()); | |
| 312 net_log()->AddGlobalEntry(NetLog::TYPE_CANCELLED); | |
| 313 trace_net_log_observer()->StopWatchForTraceStart(); | |
| 314 net_log()->AddGlobalEntry(NetLog::TYPE_REQUEST_ALIVE); | |
| 315 net_log()->AddGlobalEntry(NetLog::TYPE_URL_REQUEST_START_JOB); | |
| 316 | |
| 317 EndTraceAndFlush(); | |
| 318 | |
| 319 CapturingNetLog::CapturedEntryList entries; | |
| 320 net_log()->GetEntries(&entries); | |
| 321 EXPECT_EQ(3u, entries.size()); | |
| 322 EXPECT_EQ(0u, trace_events()->GetSize()); | |
| 323 } | |
| 324 | |
| 325 TEST_F(TraceNetLogObserverTest, EventsWithAndWithoutParameters) { | |
| 326 trace_net_log_observer()->WatchForTraceStart(net_log()); | |
| 327 EnableTraceLog(); | |
| 328 NetLog::ParametersCallback net_log_callback; | |
| 329 std::string param = "bar"; | |
| 330 net_log_callback = NetLog::StringCallback("foo", ¶m); | |
| 331 | |
| 332 net_log()->AddGlobalEntry(NetLog::TYPE_CANCELLED, net_log_callback); | |
| 333 net_log()->AddGlobalEntry(NetLog::TYPE_REQUEST_ALIVE); | |
| 334 | |
| 335 EndTraceAndFlush(); | |
| 336 trace_net_log_observer()->StopWatchForTraceStart(); | |
| 337 | |
| 338 CapturingNetLog::CapturedEntryList entries; | |
| 339 net_log()->GetEntries(&entries); | |
| 340 EXPECT_EQ(2u, entries.size()); | |
| 341 EXPECT_EQ(2u, trace_events()->GetSize()); | |
| 342 const base::DictionaryValue* item1 = NULL; | |
| 343 ASSERT_TRUE(trace_events()->GetDictionary(0, &item1)); | |
| 344 const base::DictionaryValue* item2 = NULL; | |
| 345 ASSERT_TRUE(trace_events()->GetDictionary(1, &item2)); | |
| 346 | |
| 347 TraceEntryInfo actual_item1 = GetTraceEntryInfoFromValue(*item1); | |
| 348 TraceEntryInfo actual_item2 = GetTraceEntryInfoFromValue(*item2); | |
| 349 EXPECT_EQ(kNetLogTracingCategory, actual_item1.category); | |
| 350 EXPECT_EQ(base::StringPrintf("0x%d", entries[0].source.id), actual_item1.id); | |
| 351 EXPECT_EQ(std::string(1, TRACE_EVENT_PHASE_NESTABLE_ASYNC_INSTANT), | |
| 352 actual_item1.phase); | |
| 353 EXPECT_EQ(NetLog::EventTypeToString(NetLog::TYPE_CANCELLED), | |
| 354 actual_item1.name); | |
| 355 EXPECT_EQ(NetLog::SourceTypeToString(entries[0].source.type), | |
| 356 actual_item1.source_type); | |
| 357 | |
| 358 EXPECT_EQ(kNetLogTracingCategory, actual_item2.category); | |
| 359 EXPECT_EQ(base::StringPrintf("0x%d", entries[1].source.id), actual_item2.id); | |
| 360 EXPECT_EQ(std::string(1, TRACE_EVENT_PHASE_NESTABLE_ASYNC_INSTANT), | |
| 361 actual_item2.phase); | |
| 362 EXPECT_EQ(NetLog::EventTypeToString(NetLog::TYPE_REQUEST_ALIVE), | |
| 363 actual_item2.name); | |
| 364 EXPECT_EQ(NetLog::SourceTypeToString(entries[1].source.type), | |
| 365 actual_item2.source_type); | |
| 366 | |
| 367 std::string item1_params; | |
| 368 std::string item2_params; | |
| 369 EXPECT_TRUE(item1->GetString("args.params.foo", &item1_params)); | |
| 370 EXPECT_EQ("bar", item1_params); | |
| 371 | |
| 372 EXPECT_TRUE(item2->GetString("args.params", &item2_params)); | |
| 373 EXPECT_TRUE(item2_params.empty()); | |
| 374 } | |
| 375 | |
| 376 } // namespace | |
| 377 | |
| 378 } // namespace net | |
| OLD | NEW |