net/log/net_log_util.cc

   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/log/net_log_util.h"
   6
   7 #include <algorithm>
   8 #include <string>
   9 #include <vector>
  10
  11 #include "base/bind.h"
  12 #include "base/logging.h"
  13 #include "base/metrics/field_trial.h"
  14 #include "base/strings/string_number_conversions.h"
  15 #include "base/strings/string_split.h"
  16 #include "base/strings/string_util.h"
  17 #include "base/time/time.h"
  18 #include "base/values.h"
  19 #include "net/base/address_family.h"
  20 #include "net/base/load_states.h"
  21 #include "net/base/net_errors.h"
  22 #include "net/base/sdch_manager.h"
  23 #include "net/disk_cache/disk_cache.h"
  24 #include "net/dns/host_cache.h"
  25 #include "net/dns/host_resolver.h"
  26 #include "net/http/http_cache.h"
  27 #include "net/http/http_network_session.h"
  28 #include "net/http/http_server_properties.h"
  29 #include "net/http/http_transaction_factory.h"
  30 #include "net/log/net_log.h"
  31 #include "net/proxy/proxy_config.h"
  32 #include "net/proxy/proxy_retry_info.h"
  33 #include "net/proxy/proxy_service.h"
  34 #include "net/quic/quic_protocol.h"
  35 #include "net/quic/quic_utils.h"
  36 #include "net/socket/ssl_client_socket.h"
  37 #include "net/url_request/url_request.h"
  38 #include "net/url_request/url_request_context.h"
  39
  40 namespace net {
  41
  42 namespace {
  43
  44 // This should be incremented when significant changes are made that will
  45 // invalidate the old loading code.
  46 const int kLogFormatVersion = 1;
  47
  48 struct StringToConstant {
  49   const char* name;
  50   const int constant;
  51 };
  52
  53 const StringToConstant kCertStatusFlags[] = {
  54 #define CERT_STATUS_FLAG(label, value) \
  55   { #label, value }                    \
  56   ,
  57 #include "net/cert/cert_status_flags_list.h"
  58 #undef CERT_STATUS_FLAG
  59 };
  60
  61 const StringToConstant kLoadFlags[] = {
  62 #define LOAD_FLAG(label, value) \
  63   { #label, value }             \
  64   ,
  65 #include "net/base/load_flags_list.h"
  66 #undef LOAD_FLAG
  67 };
  68
  69 const StringToConstant kLoadStateTable[] = {
  70 #define LOAD_STATE(label, value) \
  71   { #label, LOAD_STATE_##label } \
  72   ,
  73 #include "net/base/load_states_list.h"
  74 #undef LOAD_STATE
  75 };
  76
  77 const short kNetErrors[] = {
  78 #define NET_ERROR(label, value) value,
  79 #include "net/base/net_error_list.h"
  80 #undef NET_ERROR
  81 };
  82
  83 const StringToConstant kSdchProblems[] = {
  84 #define SDCH_PROBLEM_CODE(label, value) \
  85   { #label, value }                     \
  86   ,
  87 #include "net/base/sdch_problem_code_list.h"
  88 #undef SDCH_PROBLEM_CODE
  89 };
  90
  91 const char* NetInfoSourceToString(NetInfoSource source) {
  92   switch (source) {
  93 #define NET_INFO_SOURCE(label, string, value) \
  94   case NET_INFO_##label:                      \
  95     return string;
  96 #include "net/base/net_info_source_list.h"
  97 #undef NET_INFO_SOURCE
  98     case NET_INFO_ALL_SOURCES:
  99       return "All";
 100   }
 101   return "?";
 102 }
 103
 104 // Returns the disk cache backend for |context| if there is one, or NULL.
 105 // Despite the name, can return an in memory "disk cache".
 106 disk_cache::Backend* GetDiskCacheBackend(URLRequestContext* context) {
 107   if (!context->http_transaction_factory())
 108     return NULL;
 109
 110   HttpCache* http_cache = context->http_transaction_factory()->GetCache();
 111   if (!http_cache)
 112     return NULL;
 113
 114   return http_cache->GetCurrentBackend();
 115 }
 116
 117 // Returns true if |request1| was created before |request2|.
 118 bool RequestCreatedBefore(const URLRequest* request1,
 119                           const URLRequest* request2) {
 120   if (request1->creation_time() < request2->creation_time())
 121     return true;
 122   if (request1->creation_time() > request2->creation_time())
 123     return false;
 124   // If requests were created at the same time, sort by ID.  Mostly matters for
 125   // testing purposes.
 126   return request1->identifier() < request2->identifier();
 127 }
 128
 129 // Returns a Value representing the state of a pre-existing URLRequest when
 130 // net-internals was opened.
 131 scoped_ptr<base::Value> GetRequestStateAsValue(const net::URLRequest* request,
 132                                                NetLogCaptureMode capture_mode) {
 133   return request->GetStateAsValue();
 134 }
 135
 136 }  // namespace
 137
 138 scoped_ptr<base::DictionaryValue> GetNetConstants() {
 139   scoped_ptr<base::DictionaryValue> constants_dict(new base::DictionaryValue());
 140
 141   // Version of the file format.
 142   constants_dict->SetInteger("logFormatVersion", kLogFormatVersion);
 143
 144   // Add a dictionary with information on the relationship between event type
 145   // enums and their symbolic names.
 146   constants_dict->Set("logEventTypes", NetLog::GetEventTypesAsValue());
 147
 148   // Add a dictionary with information about the relationship between CertStatus
 149   // flags and their symbolic names.
 150   {
 151     scoped_ptr<base::DictionaryValue> dict(new base::DictionaryValue());
 152
 153     for (size_t i = 0; i < arraysize(kCertStatusFlags); i++)
 154       dict->SetInteger(kCertStatusFlags[i].name, kCertStatusFlags[i].constant);
 155
 156     constants_dict->Set("certStatusFlag", dict.Pass());
 157   }
 158
 159   // Add a dictionary with information about the relationship between load flag
 160   // enums and their symbolic names.
 161   {
 162     scoped_ptr<base::DictionaryValue> dict(new base::DictionaryValue());
 163
 164     for (size_t i = 0; i < arraysize(kLoadFlags); i++)
 165       dict->SetInteger(kLoadFlags[i].name, kLoadFlags[i].constant);
 166
 167     constants_dict->Set("loadFlag", dict.Pass());
 168   }
 169
 170   // Add a dictionary with information about the relationship between load state
 171   // enums and their symbolic names.
 172   {
 173     scoped_ptr<base::DictionaryValue> dict(new base::DictionaryValue());
 174
 175     for (size_t i = 0; i < arraysize(kLoadStateTable); i++)
 176       dict->SetInteger(kLoadStateTable[i].name, kLoadStateTable[i].constant);
 177
 178     constants_dict->Set("loadState", dict.Pass());
 179   }
 180
 181   {
 182     scoped_ptr<base::DictionaryValue> dict(new base::DictionaryValue());
 183 #define NET_INFO_SOURCE(label, string, value) \
 184   dict->SetInteger(string, NET_INFO_##label);
 185 #include "net/base/net_info_source_list.h"
 186 #undef NET_INFO_SOURCE
 187     constants_dict->Set("netInfoSources", dict.Pass());
 188   }
 189
 190   // Add information on the relationship between net error codes and their
 191   // symbolic names.
 192   {
 193     scoped_ptr<base::DictionaryValue> dict(new base::DictionaryValue());
 194
 195     for (size_t i = 0; i < arraysize(kNetErrors); i++)
 196       dict->SetInteger(ErrorToShortString(kNetErrors[i]), kNetErrors[i]);
 197
 198     constants_dict->Set("netError", dict.Pass());
 199   }
 200
 201   // Add information on the relationship between QUIC error codes and their
 202   // symbolic names.
 203   {
 204     scoped_ptr<base::DictionaryValue> dict(new base::DictionaryValue());
 205
 206     for (QuicErrorCode error = QUIC_NO_ERROR; error < QUIC_LAST_ERROR;
 207          error = static_cast<QuicErrorCode>(error + 1)) {
 208       dict->SetInteger(QuicUtils::ErrorToString(error),
 209                        static_cast<int>(error));
 210     }
 211
 212     constants_dict->Set("quicError", dict.Pass());
 213   }
 214
 215   // Add information on the relationship between QUIC RST_STREAM error codes
 216   // and their symbolic names.
 217   {
 218     scoped_ptr<base::DictionaryValue> dict(new base::DictionaryValue());
 219
 220     for (QuicRstStreamErrorCode error = QUIC_STREAM_NO_ERROR;
 221          error < QUIC_STREAM_LAST_ERROR;
 222          error = static_cast<QuicRstStreamErrorCode>(error + 1)) {
 223       dict->SetInteger(QuicUtils::StreamErrorToString(error),
 224                        static_cast<int>(error));
 225     }
 226
 227     constants_dict->Set("quicRstStreamError", dict.Pass());
 228   }
 229
 230   // Add information on the relationship between SDCH problem codes and their
 231   // symbolic names.
 232   {
 233     scoped_ptr<base::DictionaryValue> dict(new base::DictionaryValue());
 234
 235     for (size_t i = 0; i < arraysize(kSdchProblems); i++)
 236       dict->SetInteger(kSdchProblems[i].name, kSdchProblems[i].constant);
 237
 238     constants_dict->Set("sdchProblemCode", dict.Pass());
 239   }
 240
 241   // Information about the relationship between event phase enums and their
 242   // symbolic names.
 243   {
 244     scoped_ptr<base::DictionaryValue> dict(new base::DictionaryValue());
 245
 246     dict->SetInteger("PHASE_BEGIN", NetLog::PHASE_BEGIN);
 247     dict->SetInteger("PHASE_END", NetLog::PHASE_END);
 248     dict->SetInteger("PHASE_NONE", NetLog::PHASE_NONE);
 249
 250     constants_dict->Set("logEventPhase", dict.Pass());
 251   }
 252
 253   // Information about the relationship between source type enums and
 254   // their symbolic names.
 255   constants_dict->Set("logSourceType", NetLog::GetSourceTypesAsValue());
 256
 257   // TODO(eroman): This is here for compatibility in loading new log files with
 258   // older builds of Chrome. Safe to remove this once M45 is on the stable
 259   // channel.
 260   constants_dict->Set("logLevelType", new base::DictionaryValue());
 261
 262   // Information about the relationship between address family enums and
 263   // their symbolic names.
 264   {
 265     scoped_ptr<base::DictionaryValue> dict(new base::DictionaryValue());
 266
 267     dict->SetInteger("ADDRESS_FAMILY_UNSPECIFIED", ADDRESS_FAMILY_UNSPECIFIED);
 268     dict->SetInteger("ADDRESS_FAMILY_IPV4", ADDRESS_FAMILY_IPV4);
 269     dict->SetInteger("ADDRESS_FAMILY_IPV6", ADDRESS_FAMILY_IPV6);
 270
 271     constants_dict->Set("addressFamily", dict.Pass());
 272   }
 273
 274   // Information about how the "time ticks" values we have given it relate to
 275   // actual system times.  Time ticks are used throughout since they are stable
 276   // across system clock changes.
 277   {
 278     int64 tick_to_unix_time_ms =
 279         (base::TimeTicks() - base::TimeTicks::UnixEpoch()).InMilliseconds();
 280
 281     // Pass it as a string, since it may be too large to fit in an integer.
 282     constants_dict->SetString("timeTickOffset",
 283                               base::Int64ToString(tick_to_unix_time_ms));
 284   }
 285
 286   // "clientInfo" key is required for some WriteToFileNetLogObserver log
 287   // readers. Provide a default empty value for compatibility.
 288   constants_dict->Set("clientInfo", new base::DictionaryValue());
 289
 290   // Add a list of active field experiments.
 291   {
 292     base::FieldTrial::ActiveGroups active_groups;
 293     base::FieldTrialList::GetActiveFieldTrialGroups(&active_groups);
 294     base::ListValue* field_trial_groups = new base::ListValue();
 295     for (base::FieldTrial::ActiveGroups::const_iterator it =
 296              active_groups.begin();
 297          it != active_groups.end(); ++it) {
 298       field_trial_groups->AppendString(it->trial_name + ":" + it->group_name);
 299     }
 300     constants_dict->Set("activeFieldTrialGroups", field_trial_groups);
 301   }
 302
 303   return constants_dict.Pass();
 304 }
 305
 306 NET_EXPORT scoped_ptr<base::DictionaryValue> GetNetInfo(
 307     URLRequestContext* context,
 308     int info_sources) {
 309   // May only be called on the context's thread.
 310   DCHECK(context->CalledOnValidThread());
 311
 312   scoped_ptr<base::DictionaryValue> net_info_dict(new base::DictionaryValue());
 313
 314   // TODO(mmenke):  The code for most of these sources should probably be moved
 315   // into the sources themselves.
 316   if (info_sources & NET_INFO_PROXY_SETTINGS) {
 317     ProxyService* proxy_service = context->proxy_service();
 318
 319     scoped_ptr<base::DictionaryValue> dict(new base::DictionaryValue());
 320     if (proxy_service->fetched_config().is_valid())
 321       dict->Set("original", proxy_service->fetched_config().ToValue());
 322     if (proxy_service->config().is_valid())
 323       dict->Set("effective", proxy_service->config().ToValue());
 324
 325     net_info_dict->Set(NetInfoSourceToString(NET_INFO_PROXY_SETTINGS),
 326                        dict.Pass());
 327   }
 328
 329   if (info_sources & NET_INFO_BAD_PROXIES) {
 330     const ProxyRetryInfoMap& bad_proxies_map =
 331         context->proxy_service()->proxy_retry_info();
 332
 333     base::ListValue* list = new base::ListValue();
 334
 335     for (ProxyRetryInfoMap::const_iterator it = bad_proxies_map.begin();
 336          it != bad_proxies_map.end(); ++it) {
 337       const std::string& proxy_uri = it->first;
 338       const ProxyRetryInfo& retry_info = it->second;
 339
 340       scoped_ptr<base::DictionaryValue> dict(new base::DictionaryValue());
 341       dict->SetString("proxy_uri", proxy_uri);
 342       dict->SetString("bad_until",
 343                       NetLog::TickCountToString(retry_info.bad_until));
 344
 345       list->Append(dict.Pass());
 346     }
 347
 348     net_info_dict->Set(NetInfoSourceToString(NET_INFO_BAD_PROXIES), list);
 349   }
 350
 351   if (info_sources & NET_INFO_HOST_RESOLVER) {
 352     HostResolver* host_resolver = context->host_resolver();
 353     DCHECK(host_resolver);
 354     HostCache* cache = host_resolver->GetHostCache();
 355     if (cache) {
 356       scoped_ptr<base::DictionaryValue> dict(new base::DictionaryValue());
 357       base::Value* dns_config = host_resolver->GetDnsConfigAsValue();
 358       if (dns_config)
 359         dict->Set("dns_config", dns_config);
 360
 361       base::DictionaryValue* cache_info_dict = new base::DictionaryValue();
 362
 363       cache_info_dict->SetInteger("capacity",
 364                                   static_cast<int>(cache->max_entries()));
 365
 366       base::ListValue* entry_list = new base::ListValue();
 367
 368       HostCache::EntryMap::Iterator it(cache->entries());
 369       for (; it.HasNext(); it.Advance()) {
 370         const HostCache::Key& key = it.key();
 371         const HostCache::Entry& entry = it.value();
 372
 373         base::DictionaryValue* entry_dict = new base::DictionaryValue();
 374
 375         entry_dict->SetString("hostname", key.hostname);
 376         entry_dict->SetInteger("address_family",
 377                                static_cast<int>(key.address_family));
 378         entry_dict->SetString("expiration",
 379                               NetLog::TickCountToString(it.expiration()));
 380
 381         if (entry.error != OK) {
 382           entry_dict->SetInteger("error", entry.error);
 383         } else {
 384           // Append all of the resolved addresses.
 385           base::ListValue* address_list = new base::ListValue();
 386           for (size_t i = 0; i < entry.addrlist.size(); ++i) {
 387             address_list->AppendString(entry.addrlist[i].ToStringWithoutPort());
 388           }
 389           entry_dict->Set("addresses", address_list);
 390         }
 391
 392         entry_list->Append(entry_dict);
 393       }
 394
 395       cache_info_dict->Set("entries", entry_list);
 396       dict->Set("cache", cache_info_dict);
 397       net_info_dict->Set(NetInfoSourceToString(NET_INFO_HOST_RESOLVER),
 398                          dict.Pass());
 399     }
 400   }
 401
 402   HttpNetworkSession* http_network_session =
 403       context->http_transaction_factory()->GetSession();
 404
 405   if (info_sources & NET_INFO_SOCKET_POOL) {
 406     net_info_dict->Set(NetInfoSourceToString(NET_INFO_SOCKET_POOL),
 407                        http_network_session->SocketPoolInfoToValue());
 408   }
 409
 410   if (info_sources & NET_INFO_SPDY_SESSIONS) {
 411     net_info_dict->Set(NetInfoSourceToString(NET_INFO_SPDY_SESSIONS),
 412                        http_network_session->SpdySessionPoolInfoToValue());
 413   }
 414
 415   if (info_sources & NET_INFO_SPDY_STATUS) {
 416     base::DictionaryValue* status_dict = new base::DictionaryValue();
 417
 418     status_dict->SetBoolean("spdy_enabled", HttpStreamFactory::spdy_enabled());
 419     status_dict->SetBoolean(
 420         "use_alternate_protocols",
 421         http_network_session->params().use_alternate_protocols);
 422
 423     NextProtoVector next_protos;
 424     http_network_session->GetNextProtos(&next_protos);
 425     if (!next_protos.empty()) {
 426       std::string next_protos_string;
 427       for (const NextProto proto : next_protos) {
 428         if (!next_protos_string.empty())
 429           next_protos_string.append(",");
 430         next_protos_string.append(SSLClientSocket::NextProtoToString(proto));
 431       }
 432       status_dict->SetString("next_protos", next_protos_string);
 433     }
 434
 435     net_info_dict->Set(NetInfoSourceToString(NET_INFO_SPDY_STATUS),
 436                        status_dict);
 437   }
 438
 439   if (info_sources & NET_INFO_SPDY_ALT_SVC_MAPPINGS) {
 440     const HttpServerProperties& http_server_properties =
 441         *context->http_server_properties();
 442     net_info_dict->Set(
 443         NetInfoSourceToString(NET_INFO_SPDY_ALT_SVC_MAPPINGS),
 444         http_server_properties.GetAlternativeServiceInfoAsValue());
 445   }
 446
 447   if (info_sources & NET_INFO_QUIC) {
 448     net_info_dict->Set(NetInfoSourceToString(NET_INFO_QUIC),
 449                        http_network_session->QuicInfoToValue());
 450   }
 451
 452   if (info_sources & NET_INFO_HTTP_CACHE) {
 453     base::DictionaryValue* info_dict = new base::DictionaryValue();
 454     base::DictionaryValue* stats_dict = new base::DictionaryValue();
 455
 456     disk_cache::Backend* disk_cache = GetDiskCacheBackend(context);
 457
 458     if (disk_cache) {
 459       // Extract the statistics key/value pairs from the backend.
 460       base::StringPairs stats;
 461       disk_cache->GetStats(&stats);
 462       for (size_t i = 0; i < stats.size(); ++i) {
 463         stats_dict->SetStringWithoutPathExpansion(stats[i].first,
 464                                                   stats[i].second);
 465       }
 466     }
 467     info_dict->Set("stats", stats_dict);
 468
 469     net_info_dict->Set(NetInfoSourceToString(NET_INFO_HTTP_CACHE), info_dict);
 470   }
 471
 472   if (info_sources & NET_INFO_SDCH) {
 473     scoped_ptr<base::Value> info_dict;
 474     SdchManager* sdch_manager = context->sdch_manager();
 475     if (sdch_manager) {
 476       info_dict = sdch_manager->SdchInfoToValue();
 477     } else {
 478       info_dict.reset(new base::DictionaryValue());
 479     }
 480     net_info_dict->Set(NetInfoSourceToString(NET_INFO_SDCH), info_dict.Pass());
 481   }
 482
 483   return net_info_dict.Pass();
 484 }
 485
 486 NET_EXPORT void CreateNetLogEntriesForActiveObjects(
 487     const std::set<URLRequestContext*>& contexts,
 488     NetLog::ThreadSafeObserver* observer) {
 489   // Put together the list of all requests.
 490   std::vector<const URLRequest*> requests;
 491   for (const auto& context : contexts) {
 492     // May only be called on the context's thread.
 493     DCHECK(context->CalledOnValidThread());
 494     // Contexts should all be using the same NetLog.
 495     DCHECK_EQ((*contexts.begin())->net_log(), context->net_log());
 496     for (const auto& request : *context->url_requests()) {
 497       requests.push_back(request);
 498     }
 499   }
 500
 501   // Sort by creation time.
 502   std::sort(requests.begin(), requests.end(), RequestCreatedBefore);
 503
 504   // Create fake events.
 505   ScopedVector<NetLog::Entry> entries;
 506   for (const auto& request : requests) {
 507     NetLog::ParametersCallback callback =
 508         base::Bind(&GetRequestStateAsValue, base::Unretained(request));
 509
 510     // Note that passing the hardcoded NetLogCaptureMode::Default() below is
 511     // fine, since GetRequestStateAsValue() ignores the capture mode.
 512     NetLog::EntryData entry_data(
 513         NetLog::TYPE_REQUEST_ALIVE, request->net_log().source(),
 514         NetLog::PHASE_BEGIN, request->creation_time(), &callback);
 515     NetLog::Entry entry(&entry_data, NetLogCaptureMode::Default());
 516     observer->OnAddEntry(entry);
 517   }
 518 }
 519
 520 }  // namespace net