// Copyright 2014 The Chromium Authors. All rights reserved. // Use of this source code is governed by a BSD-style license that can be // found in the LICENSE file. #include "net/log/net_log_util.h" #include #include #include #include #include "base/bind.h" #include "base/logging.h" #include "base/metrics/field_trial.h" #include "base/strings/string_number_conversions.h" #include "base/strings/string_split.h" #include "base/strings/string_util.h" #include "base/time/time.h" #include "base/values.h" #include "net/base/address_family.h" #include "net/base/load_states.h" #include "net/base/net_errors.h" #include "net/base/sdch_manager.h" #include "net/disk_cache/disk_cache.h" #include "net/dns/host_cache.h" #include "net/dns/host_resolver.h" #include "net/http/http_cache.h" #include "net/http/http_network_session.h" #include "net/http/http_server_properties.h" #include "net/http/http_transaction_factory.h" #include "net/log/net_log.h" #include "net/proxy/proxy_config.h" #include "net/proxy/proxy_retry_info.h" #include "net/proxy/proxy_service.h" #include "net/quic/quic_protocol.h" #include "net/quic/quic_utils.h" #include "net/socket/ssl_client_socket.h" #include "net/url_request/url_request.h" #include "net/url_request/url_request_context.h" namespace net { namespace { // This should be incremented when significant changes are made that will // invalidate the old loading code. const int kLogFormatVersion = 1; struct StringToConstant { const char* name; const int constant; }; const StringToConstant kCertStatusFlags[] = { #define CERT_STATUS_FLAG(label, value) \ { #label, value } \ , #include "net/cert/cert_status_flags_list.h" #undef CERT_STATUS_FLAG }; const StringToConstant kLoadFlags[] = { #define LOAD_FLAG(label, value) \ { #label, value } \ , #include "net/base/load_flags_list.h" #undef LOAD_FLAG }; const StringToConstant kLoadStateTable[] = { #define LOAD_STATE(label, value) \ { #label, LOAD_STATE_##label } \ , #include "net/base/load_states_list.h" #undef LOAD_STATE }; const short kNetErrors[] = { #define NET_ERROR(label, value) value, #include "net/base/net_error_list.h" #undef NET_ERROR }; const StringToConstant kSdchProblems[] = { #define SDCH_PROBLEM_CODE(label, value) \ { #label, value } \ , #include "net/base/sdch_problem_code_list.h" #undef SDCH_PROBLEM_CODE }; const char* NetInfoSourceToString(NetInfoSource source) { switch (source) { #define NET_INFO_SOURCE(label, string, value) \ case NET_INFO_##label: \ return string; #include "net/base/net_info_source_list.h" #undef NET_INFO_SOURCE case NET_INFO_ALL_SOURCES: return "All"; } return "?"; } // Returns the disk cache backend for |context| if there is one, or NULL. // Despite the name, can return an in memory "disk cache". disk_cache::Backend* GetDiskCacheBackend(URLRequestContext* context) { if (!context->http_transaction_factory()) return NULL; HttpCache* http_cache = context->http_transaction_factory()->GetCache(); if (!http_cache) return NULL; return http_cache->GetCurrentBackend(); } // Returns true if |request1| was created before |request2|. bool RequestCreatedBefore(const URLRequest* request1, const URLRequest* request2) { if (request1->creation_time() < request2->creation_time()) return true; if (request1->creation_time() > request2->creation_time()) return false; // If requests were created at the same time, sort by ID. Mostly matters for // testing purposes. return request1->identifier() < request2->identifier(); } // Returns a Value representing the state of a pre-existing URLRequest when // net-internals was opened. scoped_ptr GetRequestStateAsValue(const net::URLRequest* request, NetLogCaptureMode capture_mode) { return request->GetStateAsValue(); } } // namespace scoped_ptr GetNetConstants() { scoped_ptr constants_dict(new base::DictionaryValue()); // Version of the file format. constants_dict->SetInteger("logFormatVersion", kLogFormatVersion); // Add a dictionary with information on the relationship between event type // enums and their symbolic names. constants_dict->Set("logEventTypes", NetLog::GetEventTypesAsValue()); // Add a dictionary with information about the relationship between CertStatus // flags and their symbolic names. { scoped_ptr dict(new base::DictionaryValue()); for (size_t i = 0; i < arraysize(kCertStatusFlags); i++) dict->SetInteger(kCertStatusFlags[i].name, kCertStatusFlags[i].constant); constants_dict->Set("certStatusFlag", std::move(dict)); } // Add a dictionary with information about the relationship between load flag // enums and their symbolic names. { scoped_ptr dict(new base::DictionaryValue()); for (size_t i = 0; i < arraysize(kLoadFlags); i++) dict->SetInteger(kLoadFlags[i].name, kLoadFlags[i].constant); constants_dict->Set("loadFlag", std::move(dict)); } // Add a dictionary with information about the relationship between load state // enums and their symbolic names. { scoped_ptr dict(new base::DictionaryValue()); for (size_t i = 0; i < arraysize(kLoadStateTable); i++) dict->SetInteger(kLoadStateTable[i].name, kLoadStateTable[i].constant); constants_dict->Set("loadState", std::move(dict)); } { scoped_ptr dict(new base::DictionaryValue()); #define NET_INFO_SOURCE(label, string, value) \ dict->SetInteger(string, NET_INFO_##label); #include "net/base/net_info_source_list.h" #undef NET_INFO_SOURCE constants_dict->Set("netInfoSources", std::move(dict)); } // Add information on the relationship between net error codes and their // symbolic names. { scoped_ptr dict(new base::DictionaryValue()); for (size_t i = 0; i < arraysize(kNetErrors); i++) dict->SetInteger(ErrorToShortString(kNetErrors[i]), kNetErrors[i]); constants_dict->Set("netError", std::move(dict)); } // Add information on the relationship between QUIC error codes and their // symbolic names. { scoped_ptr dict(new base::DictionaryValue()); for (QuicErrorCode error = QUIC_NO_ERROR; error < QUIC_LAST_ERROR; error = static_cast(error + 1)) { dict->SetInteger(QuicUtils::ErrorToString(error), static_cast(error)); } constants_dict->Set("quicError", std::move(dict)); } // Add information on the relationship between QUIC RST_STREAM error codes // and their symbolic names. { scoped_ptr dict(new base::DictionaryValue()); for (QuicRstStreamErrorCode error = QUIC_STREAM_NO_ERROR; error < QUIC_STREAM_LAST_ERROR; error = static_cast(error + 1)) { dict->SetInteger(QuicUtils::StreamErrorToString(error), static_cast(error)); } constants_dict->Set("quicRstStreamError", std::move(dict)); } // Add information on the relationship between SDCH problem codes and their // symbolic names. { scoped_ptr dict(new base::DictionaryValue()); for (size_t i = 0; i < arraysize(kSdchProblems); i++) dict->SetInteger(kSdchProblems[i].name, kSdchProblems[i].constant); constants_dict->Set("sdchProblemCode", std::move(dict)); } // Information about the relationship between event phase enums and their // symbolic names. { scoped_ptr dict(new base::DictionaryValue()); dict->SetInteger("PHASE_BEGIN", NetLog::PHASE_BEGIN); dict->SetInteger("PHASE_END", NetLog::PHASE_END); dict->SetInteger("PHASE_NONE", NetLog::PHASE_NONE); constants_dict->Set("logEventPhase", std::move(dict)); } // Information about the relationship between source type enums and // their symbolic names. constants_dict->Set("logSourceType", NetLog::GetSourceTypesAsValue()); // TODO(eroman): This is here for compatibility in loading new log files with // older builds of Chrome. Safe to remove this once M45 is on the stable // channel. constants_dict->Set("logLevelType", new base::DictionaryValue()); // Information about the relationship between address family enums and // their symbolic names. { scoped_ptr dict(new base::DictionaryValue()); dict->SetInteger("ADDRESS_FAMILY_UNSPECIFIED", ADDRESS_FAMILY_UNSPECIFIED); dict->SetInteger("ADDRESS_FAMILY_IPV4", ADDRESS_FAMILY_IPV4); dict->SetInteger("ADDRESS_FAMILY_IPV6", ADDRESS_FAMILY_IPV6); constants_dict->Set("addressFamily", std::move(dict)); } // Information about how the "time ticks" values we have given it relate to // actual system times. Time ticks are used throughout since they are stable // across system clock changes. Note: |timeTickOffset| is only comparable to // TimeTicks values in milliseconds. // TODO(csharrison): This is an imprecise way to convert TimeTicks to unix // time. In fact, there isn't really a good way to do this unless we log Time // and TimeTicks values side by side for every event. crbug.com/593157 tracks // a change where the user will be notified if a timing anomaly occured that // would skew the conversion (i.e. the machine entered suspend mode while // logging). { base::TimeDelta time_since_epoch = base::Time::Now() - base::Time::UnixEpoch(); base::TimeDelta reference_time_ticks = base::TimeTicks::Now() - base::TimeTicks(); int64_t tick_to_unix_time_ms = (time_since_epoch - reference_time_ticks).InMilliseconds(); // Pass it as a string, since it may be too large to fit in an integer. constants_dict->SetString("timeTickOffset", base::Int64ToString(tick_to_unix_time_ms)); } // "clientInfo" key is required for some WriteToFileNetLogObserver log // readers. Provide a default empty value for compatibility. constants_dict->Set("clientInfo", new base::DictionaryValue()); // Add a list of active field experiments. { base::FieldTrial::ActiveGroups active_groups; base::FieldTrialList::GetActiveFieldTrialGroups(&active_groups); base::ListValue* field_trial_groups = new base::ListValue(); for (base::FieldTrial::ActiveGroups::const_iterator it = active_groups.begin(); it != active_groups.end(); ++it) { field_trial_groups->AppendString(it->trial_name + ":" + it->group_name); } constants_dict->Set("activeFieldTrialGroups", field_trial_groups); } return constants_dict; } NET_EXPORT scoped_ptr GetNetInfo( URLRequestContext* context, int info_sources) { // May only be called on the context's thread. DCHECK(context->CalledOnValidThread()); scoped_ptr net_info_dict(new base::DictionaryValue()); // TODO(mmenke): The code for most of these sources should probably be moved // into the sources themselves. if (info_sources & NET_INFO_PROXY_SETTINGS) { ProxyService* proxy_service = context->proxy_service(); scoped_ptr dict(new base::DictionaryValue()); if (proxy_service->fetched_config().is_valid()) dict->Set("original", proxy_service->fetched_config().ToValue()); if (proxy_service->config().is_valid()) dict->Set("effective", proxy_service->config().ToValue()); net_info_dict->Set(NetInfoSourceToString(NET_INFO_PROXY_SETTINGS), std::move(dict)); } if (info_sources & NET_INFO_BAD_PROXIES) { const ProxyRetryInfoMap& bad_proxies_map = context->proxy_service()->proxy_retry_info(); base::ListValue* list = new base::ListValue(); for (ProxyRetryInfoMap::const_iterator it = bad_proxies_map.begin(); it != bad_proxies_map.end(); ++it) { const std::string& proxy_uri = it->first; const ProxyRetryInfo& retry_info = it->second; scoped_ptr dict(new base::DictionaryValue()); dict->SetString("proxy_uri", proxy_uri); dict->SetString("bad_until", NetLog::TickCountToString(retry_info.bad_until)); list->Append(std::move(dict)); } net_info_dict->Set(NetInfoSourceToString(NET_INFO_BAD_PROXIES), list); } if (info_sources & NET_INFO_HOST_RESOLVER) { HostResolver* host_resolver = context->host_resolver(); DCHECK(host_resolver); HostCache* cache = host_resolver->GetHostCache(); if (cache) { scoped_ptr dict(new base::DictionaryValue()); scoped_ptr dns_config = host_resolver->GetDnsConfigAsValue(); if (dns_config) dict->Set("dns_config", std::move(dns_config)); base::DictionaryValue* cache_info_dict = new base::DictionaryValue(); cache_info_dict->SetInteger("capacity", static_cast(cache->max_entries())); base::ListValue* entry_list = new base::ListValue(); HostCache::EntryMap::Iterator it(cache->entries()); for (; it.HasNext(); it.Advance()) { const HostCache::Key& key = it.key(); const HostCache::Entry& entry = it.value(); base::DictionaryValue* entry_dict = new base::DictionaryValue(); entry_dict->SetString("hostname", key.hostname); entry_dict->SetInteger("address_family", static_cast(key.address_family)); entry_dict->SetString("expiration", NetLog::TickCountToString(it.expiration())); if (entry.error != OK) { entry_dict->SetInteger("error", entry.error); } else { // Append all of the resolved addresses. base::ListValue* address_list = new base::ListValue(); for (size_t i = 0; i < entry.addrlist.size(); ++i) { address_list->AppendString(entry.addrlist[i].ToStringWithoutPort()); } entry_dict->Set("addresses", address_list); } entry_list->Append(entry_dict); } cache_info_dict->Set("entries", entry_list); dict->Set("cache", cache_info_dict); net_info_dict->Set(NetInfoSourceToString(NET_INFO_HOST_RESOLVER), std::move(dict)); } } HttpNetworkSession* http_network_session = context->http_transaction_factory()->GetSession(); if (info_sources & NET_INFO_SOCKET_POOL) { net_info_dict->Set(NetInfoSourceToString(NET_INFO_SOCKET_POOL), http_network_session->SocketPoolInfoToValue()); } if (info_sources & NET_INFO_SPDY_SESSIONS) { net_info_dict->Set(NetInfoSourceToString(NET_INFO_SPDY_SESSIONS), http_network_session->SpdySessionPoolInfoToValue()); } if (info_sources & NET_INFO_SPDY_STATUS) { base::DictionaryValue* status_dict = new base::DictionaryValue(); status_dict->SetBoolean("enable_spdy31", http_network_session->params().enable_spdy31 && HttpStreamFactory::spdy_enabled()); status_dict->SetBoolean("enable_http2", http_network_session->params().enable_http2 && HttpStreamFactory::spdy_enabled()); status_dict->SetBoolean( "use_alternative_services", http_network_session->params().parse_alternative_services); NextProtoVector alpn_protos; http_network_session->GetAlpnProtos(&alpn_protos); if (!alpn_protos.empty()) { std::string next_protos_string; for (NextProto proto : alpn_protos) { if (!next_protos_string.empty()) next_protos_string.append(","); next_protos_string.append(SSLClientSocket::NextProtoToString(proto)); } status_dict->SetString("alpn_protos", next_protos_string); } NextProtoVector npn_protos; http_network_session->GetNpnProtos(&npn_protos); if (!npn_protos.empty()) { std::string next_protos_string; for (NextProto proto : npn_protos) { if (!next_protos_string.empty()) next_protos_string.append(","); next_protos_string.append(SSLClientSocket::NextProtoToString(proto)); } status_dict->SetString("npn_protos", next_protos_string); } net_info_dict->Set(NetInfoSourceToString(NET_INFO_SPDY_STATUS), status_dict); } if (info_sources & NET_INFO_ALT_SVC_MAPPINGS) { const HttpServerProperties& http_server_properties = *context->http_server_properties(); net_info_dict->Set( NetInfoSourceToString(NET_INFO_ALT_SVC_MAPPINGS), http_server_properties.GetAlternativeServiceInfoAsValue()); } if (info_sources & NET_INFO_QUIC) { net_info_dict->Set(NetInfoSourceToString(NET_INFO_QUIC), http_network_session->QuicInfoToValue()); } if (info_sources & NET_INFO_HTTP_CACHE) { base::DictionaryValue* info_dict = new base::DictionaryValue(); base::DictionaryValue* stats_dict = new base::DictionaryValue(); disk_cache::Backend* disk_cache = GetDiskCacheBackend(context); if (disk_cache) { // Extract the statistics key/value pairs from the backend. base::StringPairs stats; disk_cache->GetStats(&stats); for (size_t i = 0; i < stats.size(); ++i) { stats_dict->SetStringWithoutPathExpansion(stats[i].first, stats[i].second); } } info_dict->Set("stats", stats_dict); net_info_dict->Set(NetInfoSourceToString(NET_INFO_HTTP_CACHE), info_dict); } if (info_sources & NET_INFO_SDCH) { scoped_ptr info_dict; SdchManager* sdch_manager = context->sdch_manager(); if (sdch_manager) { info_dict = sdch_manager->SdchInfoToValue(); } else { info_dict.reset(new base::DictionaryValue()); } net_info_dict->Set(NetInfoSourceToString(NET_INFO_SDCH), std::move(info_dict)); } return net_info_dict; } NET_EXPORT void CreateNetLogEntriesForActiveObjects( const std::set& contexts, NetLog::ThreadSafeObserver* observer) { // Put together the list of all requests. std::vector requests; for (const auto& context : contexts) { // May only be called on the context's thread. DCHECK(context->CalledOnValidThread()); // Contexts should all be using the same NetLog. DCHECK_EQ((*contexts.begin())->net_log(), context->net_log()); for (const auto& request : *context->url_requests()) { requests.push_back(request); } } // Sort by creation time. std::sort(requests.begin(), requests.end(), RequestCreatedBefore); // Create fake events. for (const auto& request : requests) { NetLog::ParametersCallback callback = base::Bind(&GetRequestStateAsValue, base::Unretained(request)); // Note that passing the hardcoded NetLogCaptureMode::Default() below is // fine, since GetRequestStateAsValue() ignores the capture mode. NetLog::EntryData entry_data( NetLog::TYPE_REQUEST_ALIVE, request->net_log().source(), NetLog::PHASE_BEGIN, request->creation_time(), &callback); NetLog::Entry entry(&entry_data, NetLogCaptureMode::Default()); observer->OnAddEntry(entry); } } } // namespace net