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)             \
  71   { #label, net::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(net::URLRequestContext* context) {
 107   if (!context->http_transaction_factory())
 108     return NULL;
 109
 110   net::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 net::URLRequest* request1,
 119                           const net::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 base::Value* GetRequestStateAsValue(const net::URLRequest* request,
 132                                     net::NetLog::LogLevel log_level) {
 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", net::NetLog::GetEventTypesAsValue());
 147
 148   // Add a dictionary with information about the relationship between CertStatus
 149   // flags and their symbolic names.
 150   {
 151     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);
 157   }
 158
 159   // Add a dictionary with information about the relationship between load flag
 160   // enums and their symbolic names.
 161   {
 162     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);
 168   }
 169
 170   // Add a dictionary with information about the relationship between load state
 171   // enums and their symbolic names.
 172   {
 173     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);
 179   }
 180
 181   {
 182     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);
 188   }
 189
 190   // Add information on the relationship between net error codes and their
 191   // symbolic names.
 192   {
 193     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);
 199   }
 200
 201   // Add information on the relationship between QUIC error codes and their
 202   // symbolic names.
 203   {
 204     base::DictionaryValue* dict = new base::DictionaryValue();
 205
 206     for (net::QuicErrorCode error = net::QUIC_NO_ERROR;
 207          error < net::QUIC_LAST_ERROR;
 208          error = static_cast<net::QuicErrorCode>(error + 1)) {
 209       dict->SetInteger(net::QuicUtils::ErrorToString(error),
 210                        static_cast<int>(error));
 211     }
 212
 213     constants_dict->Set("quicError", dict);
 214   }
 215
 216   // Add information on the relationship between QUIC RST_STREAM error codes
 217   // and their symbolic names.
 218   {
 219     base::DictionaryValue* dict = new base::DictionaryValue();
 220
 221     for (net::QuicRstStreamErrorCode error = net::QUIC_STREAM_NO_ERROR;
 222          error < net::QUIC_STREAM_LAST_ERROR;
 223          error = static_cast<net::QuicRstStreamErrorCode>(error + 1)) {
 224       dict->SetInteger(net::QuicUtils::StreamErrorToString(error),
 225                        static_cast<int>(error));
 226     }
 227
 228     constants_dict->Set("quicRstStreamError", dict);
 229   }
 230
 231   // Add information on the relationship between SDCH problem codes and their
 232   // symbolic names.
 233   {
 234     base::DictionaryValue* dict = new base::DictionaryValue();
 235
 236     for (size_t i = 0; i < arraysize(kSdchProblems); i++)
 237       dict->SetInteger(kSdchProblems[i].name, kSdchProblems[i].constant);
 238
 239     constants_dict->Set("sdchProblemCode", dict);
 240   }
 241
 242   // Information about the relationship between event phase enums and their
 243   // symbolic names.
 244   {
 245     base::DictionaryValue* dict = new base::DictionaryValue();
 246
 247     dict->SetInteger("PHASE_BEGIN", net::NetLog::PHASE_BEGIN);
 248     dict->SetInteger("PHASE_END", net::NetLog::PHASE_END);
 249     dict->SetInteger("PHASE_NONE", net::NetLog::PHASE_NONE);
 250
 251     constants_dict->Set("logEventPhase", dict);
 252   }
 253
 254   // Information about the relationship between source type enums and
 255   // their symbolic names.
 256   constants_dict->Set("logSourceType", net::NetLog::GetSourceTypesAsValue());
 257
 258   // Information about the relationship between LogLevel enums and their
 259   // symbolic names.
 260   {
 261     base::DictionaryValue* dict = new base::DictionaryValue();
 262
 263     dict->SetInteger("LOG_ALL", net::NetLog::LOG_ALL);
 264     dict->SetInteger("LOG_ALL_BUT_BYTES", net::NetLog::LOG_ALL_BUT_BYTES);
 265     dict->SetInteger("LOG_STRIP_PRIVATE_DATA",
 266                      net::NetLog::LOG_STRIP_PRIVATE_DATA);
 267
 268     constants_dict->Set("logLevelType", dict);
 269   }
 270
 271   // Information about the relationship between address family enums and
 272   // their symbolic names.
 273   {
 274     base::DictionaryValue* dict = new base::DictionaryValue();
 275
 276     dict->SetInteger("ADDRESS_FAMILY_UNSPECIFIED",
 277                      net::ADDRESS_FAMILY_UNSPECIFIED);
 278     dict->SetInteger("ADDRESS_FAMILY_IPV4", net::ADDRESS_FAMILY_IPV4);
 279     dict->SetInteger("ADDRESS_FAMILY_IPV6", net::ADDRESS_FAMILY_IPV6);
 280
 281     constants_dict->Set("addressFamily", dict);
 282   }
 283
 284   // Information about how the "time ticks" values we have given it relate to
 285   // actual system times. (We used time ticks throughout since they are stable
 286   // across system clock changes).
 287   {
 288     int64 cur_time_ms = (base::Time::Now() - base::Time()).InMilliseconds();
 289
 290     int64 cur_time_ticks_ms =
 291         (base::TimeTicks::Now() - base::TimeTicks()).InMilliseconds();
 292
 293     // If we add this number to a time tick value, it gives the timestamp.
 294     int64 tick_to_time_ms = cur_time_ms - cur_time_ticks_ms;
 295
 296     // Chrome on all platforms stores times using the Windows epoch
 297     // (Jan 1 1601), but the javascript wants a unix epoch.
 298     // TODO(eroman): Getting the timestamp relative to the unix epoch should
 299     //               be part of the time library.
 300     const int64 kUnixEpochMs = 11644473600000LL;
 301     int64 tick_to_unix_time_ms = tick_to_time_ms - kUnixEpochMs;
 302
 303     // Pass it as a string, since it may be too large to fit in an integer.
 304     constants_dict->SetString("timeTickOffset",
 305                               base::Int64ToString(tick_to_unix_time_ms));
 306   }
 307
 308   // "clientInfo" key is required for some NetLogLogger log readers.
 309   // Provide a default empty value for compatibility.
 310   constants_dict->Set("clientInfo", new base::DictionaryValue());
 311
 312   // Add a list of active field experiments.
 313   {
 314     base::FieldTrial::ActiveGroups active_groups;
 315     base::FieldTrialList::GetActiveFieldTrialGroups(&active_groups);
 316     base::ListValue* field_trial_groups = new base::ListValue();
 317     for (base::FieldTrial::ActiveGroups::const_iterator it =
 318              active_groups.begin();
 319          it != active_groups.end(); ++it) {
 320       field_trial_groups->AppendString(it->trial_name + ":" + it->group_name);
 321     }
 322     constants_dict->Set("activeFieldTrialGroups", field_trial_groups);
 323   }
 324
 325   return constants_dict.Pass();
 326 }
 327
 328 NET_EXPORT scoped_ptr<base::DictionaryValue> GetNetInfo(
 329     URLRequestContext* context,
 330     int info_sources) {
 331   // May only be called on the context's thread.
 332   DCHECK(context->CalledOnValidThread());
 333
 334   scoped_ptr<base::DictionaryValue> net_info_dict(new base::DictionaryValue());
 335
 336   // TODO(mmenke):  The code for most of these sources should probably be moved
 337   // into the sources themselves.
 338   if (info_sources & NET_INFO_PROXY_SETTINGS) {
 339     net::ProxyService* proxy_service = context->proxy_service();
 340
 341     base::DictionaryValue* dict = new base::DictionaryValue();
 342     if (proxy_service->fetched_config().is_valid())
 343       dict->Set("original", proxy_service->fetched_config().ToValue());
 344     if (proxy_service->config().is_valid())
 345       dict->Set("effective", proxy_service->config().ToValue());
 346
 347     net_info_dict->Set(NetInfoSourceToString(NET_INFO_PROXY_SETTINGS), dict);
 348   }
 349
 350   if (info_sources & NET_INFO_BAD_PROXIES) {
 351     const net::ProxyRetryInfoMap& bad_proxies_map =
 352         context->proxy_service()->proxy_retry_info();
 353
 354     base::ListValue* list = new base::ListValue();
 355
 356     for (net::ProxyRetryInfoMap::const_iterator it = bad_proxies_map.begin();
 357          it != bad_proxies_map.end(); ++it) {
 358       const std::string& proxy_uri = it->first;
 359       const net::ProxyRetryInfo& retry_info = it->second;
 360
 361       base::DictionaryValue* dict = new base::DictionaryValue();
 362       dict->SetString("proxy_uri", proxy_uri);
 363       dict->SetString("bad_until",
 364                       net::NetLog::TickCountToString(retry_info.bad_until));
 365
 366       list->Append(dict);
 367     }
 368
 369     net_info_dict->Set(NetInfoSourceToString(NET_INFO_BAD_PROXIES), list);
 370   }
 371
 372   if (info_sources & NET_INFO_HOST_RESOLVER) {
 373     net::HostResolver* host_resolver = context->host_resolver();
 374     DCHECK(host_resolver);
 375     net::HostCache* cache = host_resolver->GetHostCache();
 376     if (cache) {
 377       base::DictionaryValue* dict = new base::DictionaryValue();
 378       base::Value* dns_config = host_resolver->GetDnsConfigAsValue();
 379       if (dns_config)
 380         dict->Set("dns_config", dns_config);
 381
 382       dict->SetInteger(
 383           "default_address_family",
 384           static_cast<int>(host_resolver->GetDefaultAddressFamily()));
 385
 386       base::DictionaryValue* cache_info_dict = new base::DictionaryValue();
 387
 388       cache_info_dict->SetInteger("capacity",
 389                                   static_cast<int>(cache->max_entries()));
 390
 391       base::ListValue* entry_list = new base::ListValue();
 392
 393       net::HostCache::EntryMap::Iterator it(cache->entries());
 394       for (; it.HasNext(); it.Advance()) {
 395         const net::HostCache::Key& key = it.key();
 396         const net::HostCache::Entry& entry = it.value();
 397
 398         base::DictionaryValue* entry_dict = new base::DictionaryValue();
 399
 400         entry_dict->SetString("hostname", key.hostname);
 401         entry_dict->SetInteger("address_family",
 402                                static_cast<int>(key.address_family));
 403         entry_dict->SetString("expiration",
 404                               net::NetLog::TickCountToString(it.expiration()));
 405
 406         if (entry.error != net::OK) {
 407           entry_dict->SetInteger("error", entry.error);
 408         } else {
 409           // Append all of the resolved addresses.
 410           base::ListValue* address_list = new base::ListValue();
 411           for (size_t i = 0; i < entry.addrlist.size(); ++i) {
 412             address_list->AppendString(entry.addrlist[i].ToStringWithoutPort());
 413           }
 414           entry_dict->Set("addresses", address_list);
 415         }
 416
 417         entry_list->Append(entry_dict);
 418       }
 419
 420       cache_info_dict->Set("entries", entry_list);
 421       dict->Set("cache", cache_info_dict);
 422       net_info_dict->Set(NetInfoSourceToString(NET_INFO_HOST_RESOLVER), dict);
 423     }
 424   }
 425
 426   net::HttpNetworkSession* http_network_session =
 427       context->http_transaction_factory()->GetSession();
 428
 429   if (info_sources & NET_INFO_SOCKET_POOL) {
 430     net_info_dict->Set(NetInfoSourceToString(NET_INFO_SOCKET_POOL),
 431                        http_network_session->SocketPoolInfoToValue());
 432   }
 433
 434   if (info_sources & NET_INFO_SPDY_SESSIONS) {
 435     net_info_dict->Set(NetInfoSourceToString(NET_INFO_SPDY_SESSIONS),
 436                        http_network_session->SpdySessionPoolInfoToValue());
 437   }
 438
 439   if (info_sources & NET_INFO_SPDY_STATUS) {
 440     base::DictionaryValue* status_dict = new base::DictionaryValue();
 441
 442     status_dict->SetBoolean("spdy_enabled",
 443                             net::HttpStreamFactory::spdy_enabled());
 444     status_dict->SetBoolean(
 445         "use_alternate_protocols",
 446         http_network_session->params().use_alternate_protocols);
 447     status_dict->SetBoolean("force_spdy_over_ssl",
 448                             http_network_session->params().force_spdy_over_ssl);
 449     status_dict->SetBoolean("force_spdy_always",
 450                             http_network_session->params().force_spdy_always);
 451
 452     NextProtoVector next_protos;
 453     http_network_session->GetNextProtos(&next_protos);
 454     if (!next_protos.empty()) {
 455       std::string next_protos_string;
 456       for (const NextProto proto : next_protos) {
 457         if (!next_protos_string.empty())
 458           next_protos_string.append(",");
 459         next_protos_string.append(SSLClientSocket::NextProtoToString(proto));
 460       }
 461       status_dict->SetString("next_protos", next_protos_string);
 462     }
 463
 464     net_info_dict->Set(NetInfoSourceToString(NET_INFO_SPDY_STATUS),
 465                        status_dict);
 466   }
 467
 468   if (info_sources & NET_INFO_SPDY_ALT_PROTO_MAPPINGS) {
 469     base::ListValue* dict_list = new base::ListValue();
 470
 471     const net::HttpServerProperties& http_server_properties =
 472         *context->http_server_properties();
 473
 474     const net::AlternativeServiceMap& map =
 475         http_server_properties.alternative_service_map();
 476
 477     for (net::AlternativeServiceMap::const_iterator it = map.begin();
 478          it != map.end(); ++it) {
 479       base::DictionaryValue* dict = new base::DictionaryValue();
 480       dict->SetString("host_port_pair", it->first.ToString());
 481       dict->SetString("alternative_service", it->second.ToString());
 482       dict_list->Append(dict);
 483     }
 484
 485     net_info_dict->Set(NetInfoSourceToString(NET_INFO_SPDY_ALT_PROTO_MAPPINGS),
 486                        dict_list);
 487   }
 488
 489   if (info_sources & NET_INFO_QUIC) {
 490     net_info_dict->Set(NetInfoSourceToString(NET_INFO_QUIC),
 491                        http_network_session->QuicInfoToValue());
 492   }
 493
 494   if (info_sources & NET_INFO_HTTP_CACHE) {
 495     base::DictionaryValue* info_dict = new base::DictionaryValue();
 496     base::DictionaryValue* stats_dict = new base::DictionaryValue();
 497
 498     disk_cache::Backend* disk_cache = GetDiskCacheBackend(context);
 499
 500     if (disk_cache) {
 501       // Extract the statistics key/value pairs from the backend.
 502       base::StringPairs stats;
 503       disk_cache->GetStats(&stats);
 504       for (size_t i = 0; i < stats.size(); ++i) {
 505         stats_dict->SetStringWithoutPathExpansion(stats[i].first,
 506                                                   stats[i].second);
 507       }
 508     }
 509     info_dict->Set("stats", stats_dict);
 510
 511     net_info_dict->Set(NetInfoSourceToString(NET_INFO_HTTP_CACHE), info_dict);
 512   }
 513
 514   if (info_sources & NET_INFO_SDCH) {
 515     base::Value* info_dict;
 516     SdchManager* sdch_manager = context->sdch_manager();
 517     if (sdch_manager) {
 518       info_dict = sdch_manager->SdchInfoToValue();
 519     } else {
 520       info_dict = new base::DictionaryValue();
 521     }
 522     net_info_dict->Set(NetInfoSourceToString(NET_INFO_SDCH), info_dict);
 523   }
 524
 525   return net_info_dict.Pass();
 526 }
 527
 528 NET_EXPORT void CreateNetLogEntriesForActiveObjects(
 529     const std::set<URLRequestContext*>& contexts,
 530     NetLog::ThreadSafeObserver* observer) {
 531   // Not safe to call this when the observer is watching a NetLog.
 532   DCHECK(!observer->net_log());
 533
 534   // Put together the list of all requests.
 535   std::vector<const URLRequest*> requests;
 536   for (const auto& context : contexts) {
 537     // May only be called on the context's thread.
 538     DCHECK(context->CalledOnValidThread());
 539     // Contexts should all be using the same NetLog.
 540     DCHECK_EQ((*contexts.begin())->net_log(), context->net_log());
 541     for (const auto& request : *context->url_requests()) {
 542       requests.push_back(request);
 543     }
 544   }
 545
 546   // Sort by creation time.
 547   std::sort(requests.begin(), requests.end(), RequestCreatedBefore);
 548
 549   // Create fake events.
 550   ScopedVector<NetLog::Entry> entries;
 551   for (const auto& request : requests) {
 552     net::NetLog::ParametersCallback callback =
 553         base::Bind(&GetRequestStateAsValue, base::Unretained(request));
 554
 555     net::NetLog::EntryData entry_data(
 556         net::NetLog::TYPE_REQUEST_ALIVE, request->net_log().source(),
 557         net::NetLog::PHASE_BEGIN, request->creation_time(), &callback);
 558     NetLog::Entry entry(&entry_data, request->net_log().GetLogLevel());
 559     observer->OnAddEntry(entry);
 560   }
 561 }
 562
 563 }  // namespace net