net/log/net_log.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 "net/log/net_log.h"
   6
   7 #include "base/bind.h"
   8 #include "base/debug/alias.h"
   9 #include "base/logging.h"
  10 #include "base/strings/string_number_conversions.h"
  11 #include "base/strings/utf_string_conversions.h"
  12 #include "base/time/time.h"
  13 #include "base/values.h"
  14 #include "net/base/net_errors.h"
  15
  16 namespace net {
  17
  18 namespace {
  19
  20 // Returns parameters for logging data transferred events. Includes number of
  21 // bytes transferred and, if the log level indicates bytes should be logged and
  22 // |byte_count| > 0, the bytes themselves.  The bytes are hex-encoded, since
  23 // base::StringValue only supports UTF-8.
  24 base::Value* BytesTransferredCallback(int byte_count,
  25                                       const char* bytes,
  26                                       NetLog::LogLevel log_level) {
  27   base::DictionaryValue* dict = new base::DictionaryValue();
  28   dict->SetInteger("byte_count", byte_count);
  29   if (NetLog::IsLoggingBytes(log_level) && byte_count > 0)
  30     dict->SetString("hex_encoded_bytes", base::HexEncode(bytes, byte_count));
  31   return dict;
  32 }
  33
  34 base::Value* SourceEventParametersCallback(const NetLog::Source source,
  35                                            NetLog::LogLevel /* log_level */) {
  36   if (!source.IsValid())
  37     return NULL;
  38   base::DictionaryValue* event_params = new base::DictionaryValue();
  39   source.AddToEventParameters(event_params);
  40   return event_params;
  41 }
  42
  43 base::Value* NetLogIntegerCallback(const char* name,
  44                                    int value,
  45                                    NetLog::LogLevel /* log_level */) {
  46   base::DictionaryValue* event_params = new base::DictionaryValue();
  47   event_params->SetInteger(name, value);
  48   return event_params;
  49 }
  50
  51 base::Value* NetLogInt64Callback(const char* name,
  52                                  int64 value,
  53                                  NetLog::LogLevel /* log_level */) {
  54   base::DictionaryValue* event_params = new base::DictionaryValue();
  55   event_params->SetString(name, base::Int64ToString(value));
  56   return event_params;
  57 }
  58
  59 base::Value* NetLogStringCallback(const char* name,
  60                                   const std::string* value,
  61                                   NetLog::LogLevel /* log_level */) {
  62   base::DictionaryValue* event_params = new base::DictionaryValue();
  63   event_params->SetString(name, *value);
  64   return event_params;
  65 }
  66
  67 base::Value* NetLogString16Callback(const char* name,
  68                                     const base::string16* value,
  69                                     NetLog::LogLevel /* log_level */) {
  70   base::DictionaryValue* event_params = new base::DictionaryValue();
  71   event_params->SetString(name, *value);
  72   return event_params;
  73 }
  74
  75 }  // namespace
  76
  77 // LoadTimingInfo requires this be 0.
  78 const uint32 NetLog::Source::kInvalidId = 0;
  79
  80 NetLog::Source::Source() : type(SOURCE_NONE), id(kInvalidId) {
  81 }
  82
  83 NetLog::Source::Source(SourceType type, uint32 id) : type(type), id(id) {
  84 }
  85
  86 bool NetLog::Source::IsValid() const {
  87   return id != kInvalidId;
  88 }
  89
  90 void NetLog::Source::AddToEventParameters(
  91     base::DictionaryValue* event_params) const {
  92   base::DictionaryValue* dict = new base::DictionaryValue();
  93   dict->SetInteger("type", static_cast<int>(type));
  94   dict->SetInteger("id", static_cast<int>(id));
  95   event_params->Set("source_dependency", dict);
  96 }
  97
  98 NetLog::ParametersCallback NetLog::Source::ToEventParametersCallback() const {
  99   return base::Bind(&SourceEventParametersCallback, *this);
 100 }
 101
 102 // static
 103 bool NetLog::Source::FromEventParameters(base::Value* event_params,
 104                                          Source* source) {
 105   base::DictionaryValue* dict = NULL;
 106   base::DictionaryValue* source_dict = NULL;
 107   int source_id = -1;
 108   int source_type = NetLog::SOURCE_COUNT;
 109   if (!event_params || !event_params->GetAsDictionary(&dict) ||
 110       !dict->GetDictionary("source_dependency", &source_dict) ||
 111       !source_dict->GetInteger("id", &source_id) ||
 112       !source_dict->GetInteger("type", &source_type)) {
 113     *source = Source();
 114     return false;
 115   }
 116
 117   DCHECK_GE(source_id, 0);
 118   DCHECK_LT(source_type, NetLog::SOURCE_COUNT);
 119   *source = Source(static_cast<SourceType>(source_type), source_id);
 120   return true;
 121 }
 122
 123 base::Value* NetLog::Entry::ToValue() const {
 124   base::DictionaryValue* entry_dict(new base::DictionaryValue());
 125
 126   entry_dict->SetString("time", TickCountToString(data_->time));
 127
 128   // Set the entry source.
 129   base::DictionaryValue* source_dict = new base::DictionaryValue();
 130   source_dict->SetInteger("id", data_->source.id);
 131   source_dict->SetInteger("type", static_cast<int>(data_->source.type));
 132   entry_dict->Set("source", source_dict);
 133
 134   // Set the event info.
 135   entry_dict->SetInteger("type", static_cast<int>(data_->type));
 136   entry_dict->SetInteger("phase", static_cast<int>(data_->phase));
 137
 138   // Set the event-specific parameters.
 139   if (data_->parameters_callback) {
 140     base::Value* value = data_->parameters_callback->Run(log_level_);
 141     if (value)
 142       entry_dict->Set("params", value);
 143   }
 144
 145   return entry_dict;
 146 }
 147
 148 base::Value* NetLog::Entry::ParametersToValue() const {
 149   if (data_->parameters_callback)
 150     return data_->parameters_callback->Run(log_level_);
 151   return NULL;
 152 }
 153
 154 NetLog::EntryData::EntryData(EventType type,
 155                              Source source,
 156                              EventPhase phase,
 157                              base::TimeTicks time,
 158                              const ParametersCallback* parameters_callback)
 159     : type(type),
 160       source(source),
 161       phase(phase),
 162       time(time),
 163       parameters_callback(parameters_callback) {
 164 }
 165
 166 NetLog::EntryData::~EntryData() {
 167 }
 168
 169 NetLog::Entry::Entry(const EntryData* data, LogLevel log_level)
 170     : data_(data), log_level_(log_level) {
 171 }
 172
 173 NetLog::Entry::~Entry() {
 174 }
 175
 176 NetLog::ThreadSafeObserver::ThreadSafeObserver()
 177     : log_level_(LOG_NONE), net_log_(NULL) {
 178 }
 179
 180 NetLog::ThreadSafeObserver::~ThreadSafeObserver() {
 181   // Make sure we aren't watching a NetLog on destruction.  Because the NetLog
 182   // may pass events to each observer on multiple threads, we cannot safely
 183   // stop watching a NetLog automatically from a parent class.
 184   DCHECK(!net_log_);
 185 }
 186
 187 NetLog::LogLevel NetLog::ThreadSafeObserver::log_level() const {
 188   DCHECK(net_log_);
 189   return log_level_;
 190 }
 191
 192 NetLog* NetLog::ThreadSafeObserver::net_log() const {
 193   return net_log_;
 194 }
 195
 196 void NetLog::ThreadSafeObserver::OnAddEntryData(const EntryData& entry_data) {
 197   OnAddEntry(Entry(&entry_data, log_level()));
 198 }
 199
 200 NetLog::NetLog() : last_id_(0), effective_log_level_(LOG_NONE) {
 201 }
 202
 203 NetLog::~NetLog() {
 204 }
 205
 206 void NetLog::AddGlobalEntry(EventType type) {
 207   AddEntry(type, Source(net::NetLog::SOURCE_NONE, NextID()),
 208            net::NetLog::PHASE_NONE, NULL);
 209 }
 210
 211 void NetLog::AddGlobalEntry(
 212     EventType type,
 213     const NetLog::ParametersCallback& parameters_callback) {
 214   AddEntry(type, Source(net::NetLog::SOURCE_NONE, NextID()),
 215            net::NetLog::PHASE_NONE, &parameters_callback);
 216 }
 217
 218 uint32 NetLog::NextID() {
 219   return base::subtle::NoBarrier_AtomicIncrement(&last_id_, 1);
 220 }
 221
 222 NetLog::LogLevel NetLog::GetLogLevel() const {
 223   base::subtle::Atomic32 log_level =
 224       base::subtle::NoBarrier_Load(&effective_log_level_);
 225   return static_cast<net::NetLog::LogLevel>(log_level);
 226 }
 227
 228 void NetLog::DeprecatedAddObserver(net::NetLog::ThreadSafeObserver* observer,
 229                                    LogLevel log_level) {
 230   DCHECK_NE(LOG_NONE, log_level);
 231   base::AutoLock lock(lock_);
 232
 233   DCHECK(!observer->net_log_);
 234   DCHECK_EQ(LOG_NONE, observer->log_level_);
 235   observers_.AddObserver(observer);
 236   observer->net_log_ = this;
 237   observer->log_level_ = log_level;
 238   UpdateLogLevel();
 239 }
 240
 241 void NetLog::SetObserverLogLevel(net::NetLog::ThreadSafeObserver* observer,
 242                                  LogLevel log_level) {
 243   DCHECK_NE(LOG_NONE, log_level);
 244   base::AutoLock lock(lock_);
 245
 246   DCHECK(observers_.HasObserver(observer));
 247   DCHECK_EQ(this, observer->net_log_);
 248   DCHECK_NE(LOG_NONE, observer->log_level_);
 249   observer->log_level_ = log_level;
 250   UpdateLogLevel();
 251 }
 252
 253 void NetLog::DeprecatedRemoveObserver(
 254     net::NetLog::ThreadSafeObserver* observer) {
 255   base::AutoLock lock(lock_);
 256
 257   DCHECK(observers_.HasObserver(observer));
 258   DCHECK_EQ(this, observer->net_log_);
 259   DCHECK_NE(LOG_NONE, observer->log_level_);
 260   observers_.RemoveObserver(observer);
 261   observer->net_log_ = NULL;
 262   observer->log_level_ = LOG_NONE;
 263   UpdateLogLevel();
 264 }
 265
 266 void NetLog::UpdateLogLevel() {
 267   lock_.AssertAcquired();
 268
 269   // Look through all the observers and find the finest granularity
 270   // log level (higher values of the enum imply *lower* log levels).
 271   LogLevel new_effective_log_level = LOG_NONE;
 272   ObserverListBase<ThreadSafeObserver>::Iterator it(&observers_);
 273   ThreadSafeObserver* observer;
 274   while ((observer = it.GetNext()) != NULL) {
 275     new_effective_log_level =
 276         std::min(new_effective_log_level, observer->log_level());
 277   }
 278   base::subtle::NoBarrier_Store(&effective_log_level_, new_effective_log_level);
 279 }
 280
 281 // static
 282 std::string NetLog::TickCountToString(const base::TimeTicks& time) {
 283   int64 delta_time = (time - base::TimeTicks()).InMilliseconds();
 284   return base::Int64ToString(delta_time);
 285 }
 286
 287 // static
 288 const char* NetLog::EventTypeToString(EventType event) {
 289   switch (event) {
 290 #define EVENT_TYPE(label) \
 291   case TYPE_##label:      \
 292     return #label;
 293 #include "net/log/net_log_event_type_list.h"
 294 #undef EVENT_TYPE
 295     default:
 296       NOTREACHED();
 297       return NULL;
 298   }
 299 }
 300
 301 // static
 302 base::Value* NetLog::GetEventTypesAsValue() {
 303   base::DictionaryValue* dict = new base::DictionaryValue();
 304   for (int i = 0; i < EVENT_COUNT; ++i) {
 305     dict->SetInteger(EventTypeToString(static_cast<EventType>(i)), i);
 306   }
 307   return dict;
 308 }
 309
 310 // static
 311 const char* NetLog::SourceTypeToString(SourceType source) {
 312   switch (source) {
 313 #define SOURCE_TYPE(label) \
 314   case SOURCE_##label:     \
 315     return #label;
 316 #include "net/log/net_log_source_type_list.h"
 317 #undef SOURCE_TYPE
 318     default:
 319       NOTREACHED();
 320       return NULL;
 321   }
 322 }
 323
 324 // static
 325 base::Value* NetLog::GetSourceTypesAsValue() {
 326   base::DictionaryValue* dict = new base::DictionaryValue();
 327   for (int i = 0; i < SOURCE_COUNT; ++i) {
 328     dict->SetInteger(SourceTypeToString(static_cast<SourceType>(i)), i);
 329   }
 330   return dict;
 331 }
 332
 333 // static
 334 const char* NetLog::EventPhaseToString(EventPhase phase) {
 335   switch (phase) {
 336     case PHASE_BEGIN:
 337       return "PHASE_BEGIN";
 338     case PHASE_END:
 339       return "PHASE_END";
 340     case PHASE_NONE:
 341       return "PHASE_NONE";
 342   }
 343   NOTREACHED();
 344   return NULL;
 345 }
 346
 347 // static
 348 bool NetLog::IsLoggingBytes(LogLevel log_level) {
 349   return log_level == NetLog::LOG_ALL;
 350 }
 351
 352 // static
 353 bool NetLog::IsLogging(LogLevel log_level) {
 354   return log_level < NetLog::LOG_NONE;
 355 }
 356
 357 // static
 358 NetLog::ParametersCallback NetLog::IntegerCallback(const char* name,
 359                                                    int value) {
 360   return base::Bind(&NetLogIntegerCallback, name, value);
 361 }
 362
 363 // static
 364 NetLog::ParametersCallback NetLog::Int64Callback(const char* name,
 365                                                  int64 value) {
 366   return base::Bind(&NetLogInt64Callback, name, value);
 367 }
 368
 369 // static
 370 NetLog::ParametersCallback NetLog::StringCallback(const char* name,
 371                                                   const std::string* value) {
 372   DCHECK(value);
 373   return base::Bind(&NetLogStringCallback, name, value);
 374 }
 375
 376 // static
 377 NetLog::ParametersCallback NetLog::StringCallback(const char* name,
 378                                                   const base::string16* value) {
 379   DCHECK(value);
 380   return base::Bind(&NetLogString16Callback, name, value);
 381 }
 382
 383 void NetLog::AddEntry(EventType type,
 384                       const Source& source,
 385                       EventPhase phase,
 386                       const NetLog::ParametersCallback* parameters_callback) {
 387   if (GetLogLevel() == LOG_NONE)
 388     return;
 389   EntryData entry_data(type, source, phase, base::TimeTicks::Now(),
 390                        parameters_callback);
 391
 392   // Notify all of the log observers.
 393   base::AutoLock lock(lock_);
 394   FOR_EACH_OBSERVER(ThreadSafeObserver, observers_, OnAddEntryData(entry_data));
 395 }
 396
 397 BoundNetLog::~BoundNetLog() {
 398   liveness_ = DEAD;
 399 }
 400
 401 void BoundNetLog::AddEntry(NetLog::EventType type,
 402                            NetLog::EventPhase phase) const {
 403   CrashIfInvalid();
 404
 405   if (!net_log_)
 406     return;
 407   net_log_->AddEntry(type, source_, phase, NULL);
 408 }
 409
 410 void BoundNetLog::AddEntry(
 411     NetLog::EventType type,
 412     NetLog::EventPhase phase,
 413     const NetLog::ParametersCallback& get_parameters) const {
 414   CrashIfInvalid();
 415
 416   if (!net_log_)
 417     return;
 418   net_log_->AddEntry(type, source_, phase, &get_parameters);
 419 }
 420
 421 void BoundNetLog::AddEvent(NetLog::EventType type) const {
 422   AddEntry(type, NetLog::PHASE_NONE);
 423 }
 424
 425 void BoundNetLog::AddEvent(
 426     NetLog::EventType type,
 427     const NetLog::ParametersCallback& get_parameters) const {
 428   AddEntry(type, NetLog::PHASE_NONE, get_parameters);
 429 }
 430
 431 void BoundNetLog::BeginEvent(NetLog::EventType type) const {
 432   AddEntry(type, NetLog::PHASE_BEGIN);
 433 }
 434
 435 void BoundNetLog::BeginEvent(
 436     NetLog::EventType type,
 437     const NetLog::ParametersCallback& get_parameters) const {
 438   AddEntry(type, NetLog::PHASE_BEGIN, get_parameters);
 439 }
 440
 441 void BoundNetLog::EndEvent(NetLog::EventType type) const {
 442   AddEntry(type, NetLog::PHASE_END);
 443 }
 444
 445 void BoundNetLog::EndEvent(
 446     NetLog::EventType type,
 447     const NetLog::ParametersCallback& get_parameters) const {
 448   AddEntry(type, NetLog::PHASE_END, get_parameters);
 449 }
 450
 451 void BoundNetLog::AddEventWithNetErrorCode(NetLog::EventType event_type,
 452                                            int net_error) const {
 453   DCHECK_NE(ERR_IO_PENDING, net_error);
 454   if (net_error >= 0) {
 455     AddEvent(event_type);
 456   } else {
 457     AddEvent(event_type, NetLog::IntegerCallback("net_error", net_error));
 458   }
 459 }
 460
 461 void BoundNetLog::EndEventWithNetErrorCode(NetLog::EventType event_type,
 462                                            int net_error) const {
 463   DCHECK_NE(ERR_IO_PENDING, net_error);
 464   if (net_error >= 0) {
 465     EndEvent(event_type);
 466   } else {
 467     EndEvent(event_type, NetLog::IntegerCallback("net_error", net_error));
 468   }
 469 }
 470
 471 void BoundNetLog::AddByteTransferEvent(NetLog::EventType event_type,
 472                                        int byte_count,
 473                                        const char* bytes) const {
 474   AddEvent(event_type, base::Bind(BytesTransferredCallback, byte_count, bytes));
 475 }
 476
 477 NetLog::LogLevel BoundNetLog::GetLogLevel() const {
 478   CrashIfInvalid();
 479
 480   if (net_log_)
 481     return net_log_->GetLogLevel();
 482   return NetLog::LOG_NONE;
 483 }
 484
 485 bool BoundNetLog::IsLoggingBytes() const {
 486   return NetLog::IsLoggingBytes(GetLogLevel());
 487 }
 488
 489 bool BoundNetLog::IsLogging() const {
 490   return NetLog::IsLogging(GetLogLevel());
 491 }
 492
 493 // static
 494 BoundNetLog BoundNetLog::Make(NetLog* net_log, NetLog::SourceType source_type) {
 495   if (!net_log)
 496     return BoundNetLog();
 497
 498   NetLog::Source source(source_type, net_log->NextID());
 499   return BoundNetLog(source, net_log);
 500 }
 501
 502 void BoundNetLog::CrashIfInvalid() const {
 503   Liveness liveness = liveness_;
 504
 505   if (liveness == ALIVE)
 506     return;
 507
 508   base::debug::Alias(&liveness);
 509   CHECK_EQ(ALIVE, liveness);
 510 }
 511
 512 }  // namespace net