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