net_log_util.cc 18 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369370371372373374375376377378379380381382383384385386387388389390391392393394395396397398399400401402403404405406407408409410411412413414415416417418419420421422423424425426427428429430431432433434435436437438439440441442443444445446447448449450451452453454455456457458459460461462463464465466467468469470471472473474475476477478479480481482483484485486487488489490491492493494495496497498499500501502503504505506507508509510511512513514515516517518519520521522523524525526527528529530531532533534535536537
  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. #include "net/log/net_log_util.h"
  5. #include <algorithm>
  6. #include <string>
  7. #include <utility>
  8. #include <vector>
  9. #include "base/check_op.h"
  10. #include "base/feature_list.h"
  11. #include "base/metrics/field_trial.h"
  12. #include "base/strings/strcat.h"
  13. #include "base/strings/string_number_conversions.h"
  14. #include "base/strings/string_split.h"
  15. #include "base/strings/string_util.h"
  16. #include "base/time/time.h"
  17. #include "base/values.h"
  18. #include "net/base/address_family.h"
  19. #include "net/base/load_states.h"
  20. #include "net/base/net_errors.h"
  21. #include "net/base/net_info_source_list.h"
  22. #include "net/cert/cert_verifier.h"
  23. #include "net/cert/pki/simple_path_builder_delegate.h"
  24. #include "net/cert/pki/trust_store.h"
  25. #include "net/disk_cache/disk_cache.h"
  26. #include "net/dns/host_cache.h"
  27. #include "net/dns/host_resolver.h"
  28. #include "net/dns/public/dns_query_type.h"
  29. #include "net/dns/public/doh_provider_entry.h"
  30. #include "net/dns/public/secure_dns_mode.h"
  31. #include "net/http/http_cache.h"
  32. #include "net/http/http_network_session.h"
  33. #include "net/http/http_server_properties.h"
  34. #include "net/http/http_transaction_factory.h"
  35. #include "net/log/net_log_capture_mode.h"
  36. #include "net/log/net_log_entry.h"
  37. #include "net/log/net_log_event_type.h"
  38. #include "net/log/net_log_values.h"
  39. #include "net/log/net_log_with_source.h"
  40. #include "net/proxy_resolution/proxy_config.h"
  41. #include "net/proxy_resolution/proxy_resolution_service.h"
  42. #include "net/proxy_resolution/proxy_retry_info.h"
  43. #include "net/socket/ssl_client_socket.h"
  44. #include "net/third_party/quiche/src/quiche/quic/core/quic_error_codes.h"
  45. #include "net/third_party/quiche/src/quiche/quic/core/quic_packets.h"
  46. #include "net/url_request/url_request.h"
  47. #include "net/url_request/url_request_context.h"
  48. #if BUILDFLAG(ENABLE_REPORTING)
  49. #include "net/network_error_logging/network_error_logging_service.h"
  50. #include "net/reporting/reporting_service.h"
  51. #endif // BUILDFLAG(ENABLE_REPORTING)
  52. namespace net {
  53. namespace {
  54. // This should be incremented when significant changes are made that will
  55. // invalidate the old loading code.
  56. const int kLogFormatVersion = 1;
  57. struct StringToConstant {
  58. const char* name;
  59. const int constant;
  60. };
  61. const StringToConstant kCertStatusFlags[] = {
  62. #define CERT_STATUS_FLAG(label, value) {#label, value},
  63. #include "net/cert/cert_status_flags_list.h"
  64. #undef CERT_STATUS_FLAG
  65. };
  66. const StringToConstant kLoadFlags[] = {
  67. #define LOAD_FLAG(label, value) {#label, value},
  68. #include "net/base/load_flags_list.h"
  69. #undef LOAD_FLAG
  70. };
  71. const StringToConstant kLoadStateTable[] = {
  72. #define LOAD_STATE(label, value) {#label, LOAD_STATE_##label},
  73. #include "net/base/load_states_list.h"
  74. #undef LOAD_STATE
  75. };
  76. const short kNetErrors[] = {
  77. #define NET_ERROR(label, value) value,
  78. #include "net/base/net_error_list.h"
  79. #undef NET_ERROR
  80. };
  81. // Returns the disk cache backend for |context| if there is one, or NULL.
  82. // Despite the name, can return an in memory "disk cache".
  83. disk_cache::Backend* GetDiskCacheBackend(URLRequestContext* context) {
  84. if (!context->http_transaction_factory())
  85. return nullptr;
  86. HttpCache* http_cache = context->http_transaction_factory()->GetCache();
  87. if (!http_cache)
  88. return nullptr;
  89. return http_cache->GetCurrentBackend();
  90. }
  91. // Returns true if |request1| was created before |request2|.
  92. bool RequestCreatedBefore(const URLRequest* request1,
  93. const URLRequest* request2) {
  94. // Only supported when both requests have the same non-null NetLog.
  95. DCHECK(request1->net_log().net_log());
  96. DCHECK_EQ(request1->net_log().net_log(), request2->net_log().net_log());
  97. if (request1->creation_time() < request2->creation_time())
  98. return true;
  99. if (request1->creation_time() > request2->creation_time())
  100. return false;
  101. // If requests were created at the same time, sort by NetLogSource ID. Some
  102. // NetLog tests assume the returned order exactly matches creation order, even
  103. // creation times of two events are potentially the same.
  104. return request1->net_log().source().id < request2->net_log().source().id;
  105. }
  106. base::Value GetActiveFieldTrialList() {
  107. base::FieldTrial::ActiveGroups active_groups;
  108. base::FieldTrialList::GetActiveFieldTrialGroups(&active_groups);
  109. base::Value::List field_trial_groups;
  110. for (const auto& group : active_groups) {
  111. field_trial_groups.Append(group.trial_name + ":" + group.group_name);
  112. }
  113. return base::Value(std::move(field_trial_groups));
  114. }
  115. } // namespace
  116. base::Value::Dict GetNetConstants() {
  117. base::Value::Dict constants_dict;
  118. // Version of the file format.
  119. constants_dict.Set("logFormatVersion", kLogFormatVersion);
  120. // Add a dictionary with information on the relationship between event type
  121. // enums and their symbolic names.
  122. constants_dict.Set("logEventTypes", NetLog::GetEventTypesAsValue());
  123. // Add a dictionary with information about the relationship between CertStatus
  124. // flags and their symbolic names.
  125. {
  126. base::Value::Dict dict;
  127. for (const auto& flag : kCertStatusFlags)
  128. dict.Set(flag.name, flag.constant);
  129. constants_dict.Set("certStatusFlag", std::move(dict));
  130. }
  131. // Add a dictionary with information about the relationship between
  132. // CertVerifier::VerifyFlags and their symbolic names.
  133. {
  134. base::Value::Dict dict;
  135. dict.Set("VERIFY_DISABLE_NETWORK_FETCHES",
  136. CertVerifier::VERIFY_DISABLE_NETWORK_FETCHES);
  137. static_assert(CertVerifier::VERIFY_FLAGS_LAST == (1 << 0),
  138. "Update with new flags");
  139. constants_dict.Set("certVerifierFlags", std::move(dict));
  140. }
  141. {
  142. base::Value::Dict dict;
  143. dict.Set("kStrong", static_cast<int>(
  144. SimplePathBuilderDelegate::DigestPolicy::kStrong));
  145. dict.Set("kWeakAllowSha1",
  146. static_cast<int>(
  147. SimplePathBuilderDelegate::DigestPolicy::kWeakAllowSha1));
  148. static_assert(SimplePathBuilderDelegate::DigestPolicy::kMaxValue ==
  149. SimplePathBuilderDelegate::DigestPolicy::kWeakAllowSha1,
  150. "Update with new flags");
  151. constants_dict.Set("certPathBuilderDigestPolicy", std::move(dict));
  152. }
  153. {
  154. base::Value::Dict dict;
  155. dict.Set("DISTRUSTED", static_cast<int>(CertificateTrustType::DISTRUSTED));
  156. dict.Set("UNSPECIFIED",
  157. static_cast<int>(CertificateTrustType::UNSPECIFIED));
  158. dict.Set("TRUSTED_ANCHOR",
  159. static_cast<int>(CertificateTrustType::TRUSTED_ANCHOR));
  160. dict.Set(
  161. "TRUSTED_ANCHOR_WITH_EXPIRATION",
  162. static_cast<int>(CertificateTrustType::TRUSTED_ANCHOR_WITH_EXPIRATION));
  163. dict.Set("TRUSTED_ANCHOR_WITH_CONSTRAINTS",
  164. static_cast<int>(
  165. CertificateTrustType::TRUSTED_ANCHOR_WITH_CONSTRAINTS));
  166. static_assert(CertificateTrustType::LAST ==
  167. CertificateTrustType::TRUSTED_ANCHOR_WITH_CONSTRAINTS,
  168. "Update with new flags");
  169. constants_dict.Set("certificateTrustType", std::move(dict));
  170. }
  171. // Add a dictionary with information about the relationship between load flag
  172. // enums and their symbolic names.
  173. {
  174. base::Value::Dict dict;
  175. for (const auto& flag : kLoadFlags)
  176. dict.Set(flag.name, flag.constant);
  177. constants_dict.Set("loadFlag", std::move(dict));
  178. }
  179. // Add a dictionary with information about the relationship between load state
  180. // enums and their symbolic names.
  181. {
  182. base::Value::Dict dict;
  183. for (const auto& state : kLoadStateTable)
  184. dict.Set(state.name, state.constant);
  185. constants_dict.Set("loadState", std::move(dict));
  186. }
  187. // Add information on the relationship between net error codes and their
  188. // symbolic names.
  189. {
  190. base::Value::Dict dict;
  191. for (const auto& error : kNetErrors)
  192. dict.Set(ErrorToShortString(error), error);
  193. constants_dict.Set("netError", std::move(dict));
  194. }
  195. // Add information on the relationship between QUIC error codes and their
  196. // symbolic names.
  197. {
  198. base::Value::Dict dict;
  199. for (quic::QuicErrorCode error = quic::QUIC_NO_ERROR;
  200. error < quic::QUIC_LAST_ERROR;
  201. error = static_cast<quic::QuicErrorCode>(error + 1)) {
  202. dict.Set(QuicErrorCodeToString(error), static_cast<int>(error));
  203. }
  204. constants_dict.Set("quicError", std::move(dict));
  205. }
  206. // Add information on the relationship between QUIC RST_STREAM error codes
  207. // and their symbolic names.
  208. {
  209. base::Value::Dict dict;
  210. for (quic::QuicRstStreamErrorCode error = quic::QUIC_STREAM_NO_ERROR;
  211. error < quic::QUIC_STREAM_LAST_ERROR;
  212. error = static_cast<quic::QuicRstStreamErrorCode>(error + 1)) {
  213. dict.Set(QuicRstStreamErrorCodeToString(error), static_cast<int>(error));
  214. }
  215. constants_dict.Set("quicRstStreamError", std::move(dict));
  216. }
  217. // Information about the relationship between event phase enums and their
  218. // symbolic names.
  219. {
  220. base::Value::Dict dict;
  221. dict.Set("PHASE_BEGIN", static_cast<int>(NetLogEventPhase::BEGIN));
  222. dict.Set("PHASE_END", static_cast<int>(NetLogEventPhase::END));
  223. dict.Set("PHASE_NONE", static_cast<int>(NetLogEventPhase::NONE));
  224. constants_dict.Set("logEventPhase", std::move(dict));
  225. }
  226. // Information about the relationship between source type enums and
  227. // their symbolic names.
  228. constants_dict.Set("logSourceType", NetLog::GetSourceTypesAsValue());
  229. // Information about the relationship between address family enums and
  230. // their symbolic names.
  231. {
  232. base::Value::Dict dict;
  233. dict.Set("ADDRESS_FAMILY_UNSPECIFIED", ADDRESS_FAMILY_UNSPECIFIED);
  234. dict.Set("ADDRESS_FAMILY_IPV4", ADDRESS_FAMILY_IPV4);
  235. dict.Set("ADDRESS_FAMILY_IPV6", ADDRESS_FAMILY_IPV6);
  236. constants_dict.Set("addressFamily", std::move(dict));
  237. }
  238. // Information about the relationship between DnsQueryType enums and their
  239. // symbolic names.
  240. {
  241. base::Value::Dict dict;
  242. for (const auto& type : kDnsQueryTypes) {
  243. dict.Set(type.second, static_cast<int>(type.first));
  244. }
  245. constants_dict.Set("dnsQueryType", std::move(dict));
  246. }
  247. // Information about the relationship between SecureDnsMode enums and their
  248. // symbolic names.
  249. {
  250. base::Value::Dict dict;
  251. for (const auto& mode : kSecureDnsModes) {
  252. dict.Set(mode.second, static_cast<int>(mode.first));
  253. }
  254. constants_dict.Set("secureDnsMode", std::move(dict));
  255. }
  256. // Information about how the "time ticks" values we have given it relate to
  257. // actual system times. Time ticks are used throughout since they are stable
  258. // across system clock changes. Note: |timeTickOffset| is only comparable to
  259. // TimeTicks values in milliseconds.
  260. // TODO(csharrison): This is an imprecise way to convert TimeTicks to unix
  261. // time. In fact, there isn't really a good way to do this unless we log Time
  262. // and TimeTicks values side by side for every event. crbug.com/593157 tracks
  263. // a change where the user will be notified if a timing anomaly occured that
  264. // would skew the conversion (i.e. the machine entered suspend mode while
  265. // logging).
  266. {
  267. base::TimeDelta time_since_epoch =
  268. base::Time::Now() - base::Time::UnixEpoch();
  269. base::TimeDelta reference_time_ticks =
  270. base::TimeTicks::Now() - base::TimeTicks();
  271. int64_t tick_to_unix_time_ms =
  272. (time_since_epoch - reference_time_ticks).InMilliseconds();
  273. constants_dict.Set("timeTickOffset",
  274. NetLogNumberValue(tick_to_unix_time_ms));
  275. }
  276. // TODO(eroman): Is this needed?
  277. // "clientInfo" key is required for some log readers. Provide a default empty
  278. // value for compatibility.
  279. constants_dict.Set("clientInfo", base::Value::Dict());
  280. // Add a list of field experiments active at the start of the capture.
  281. // Additional trials may be enabled later in the browser session.
  282. constants_dict.Set(kNetInfoFieldTrials, GetActiveFieldTrialList());
  283. return constants_dict;
  284. }
  285. NET_EXPORT base::Value::Dict GetNetInfo(URLRequestContext* context) {
  286. // May only be called on the context's thread.
  287. context->AssertCalledOnValidThread();
  288. base::Value::Dict net_info_dict =
  289. context->proxy_resolution_service()->GetProxyNetLogValues();
  290. // Log Host Resolver info.
  291. {
  292. HostResolver* host_resolver = context->host_resolver();
  293. DCHECK(host_resolver);
  294. HostCache* cache = host_resolver->GetHostCache();
  295. if (cache) {
  296. base::Value::Dict dict;
  297. base::Value dns_config = host_resolver->GetDnsConfigAsValue();
  298. dict.Set("dns_config", std::move(dns_config));
  299. base::Value::Dict cache_info_dict;
  300. base::Value::List cache_contents_list;
  301. cache_info_dict.Set("capacity", static_cast<int>(cache->max_entries()));
  302. cache_info_dict.Set("network_changes", cache->network_changes());
  303. cache->GetList(cache_contents_list, true /* include_staleness */,
  304. HostCache::SerializationType::kDebug);
  305. cache_info_dict.Set("entries", std::move(cache_contents_list));
  306. dict.Set("cache", std::move(cache_info_dict));
  307. net_info_dict.Set(kNetInfoHostResolver, std::move(dict));
  308. }
  309. // Construct a list containing the names of the disabled DoH providers.
  310. base::Value::List disabled_doh_providers_list;
  311. for (const DohProviderEntry* provider : DohProviderEntry::GetList()) {
  312. if (!base::FeatureList::IsEnabled(provider->feature)) {
  313. disabled_doh_providers_list.Append(
  314. NetLogStringValue(provider->provider));
  315. }
  316. }
  317. net_info_dict.Set(kNetInfoDohProvidersDisabledDueToFeature,
  318. base::Value(std::move(disabled_doh_providers_list)));
  319. }
  320. HttpNetworkSession* http_network_session =
  321. context->http_transaction_factory()->GetSession();
  322. // Log Socket Pool info.
  323. {
  324. net_info_dict.Set(kNetInfoSocketPool,
  325. http_network_session->SocketPoolInfoToValue());
  326. }
  327. // Log SPDY Sessions.
  328. {
  329. net_info_dict.Set(kNetInfoSpdySessions,
  330. base::Value::FromUniquePtrValue(
  331. http_network_session->SpdySessionPoolInfoToValue()));
  332. }
  333. // Log SPDY status.
  334. {
  335. base::Value::Dict status_dict;
  336. status_dict.Set("enable_http2",
  337. http_network_session->params().enable_http2);
  338. const NextProtoVector& alpn_protos = http_network_session->GetAlpnProtos();
  339. if (!alpn_protos.empty()) {
  340. std::string next_protos_string;
  341. for (NextProto proto : alpn_protos) {
  342. if (!next_protos_string.empty())
  343. next_protos_string.append(",");
  344. next_protos_string.append(NextProtoToString(proto));
  345. }
  346. status_dict.Set("alpn_protos", next_protos_string);
  347. }
  348. const SSLConfig::ApplicationSettings& application_settings =
  349. http_network_session->GetApplicationSettings();
  350. if (!application_settings.empty()) {
  351. base::Value::Dict application_settings_dict;
  352. for (const auto& setting : application_settings) {
  353. application_settings_dict.Set(
  354. NextProtoToString(setting.first),
  355. base::HexEncode(setting.second.data(), setting.second.size()));
  356. }
  357. status_dict.Set("application_settings",
  358. std::move(application_settings_dict));
  359. }
  360. net_info_dict.Set(kNetInfoSpdyStatus, std::move(status_dict));
  361. }
  362. // Log ALT_SVC mappings.
  363. {
  364. const HttpServerProperties& http_server_properties =
  365. *context->http_server_properties();
  366. net_info_dict.Set(
  367. kNetInfoAltSvcMappings,
  368. http_server_properties.GetAlternativeServiceInfoAsValue());
  369. }
  370. // Log QUIC info.
  371. { net_info_dict.Set(kNetInfoQuic, http_network_session->QuicInfoToValue()); }
  372. // Log HTTP Cache info.
  373. {
  374. base::Value::Dict info_dict;
  375. base::Value::Dict stats_dict;
  376. disk_cache::Backend* disk_cache = GetDiskCacheBackend(context);
  377. if (disk_cache) {
  378. // Extract the statistics key/value pairs from the backend.
  379. base::StringPairs stats;
  380. disk_cache->GetStats(&stats);
  381. for (auto& stat : stats) {
  382. stats_dict.Set(stat.first, std::move(stat.second));
  383. }
  384. }
  385. info_dict.Set("stats", std::move(stats_dict));
  386. net_info_dict.Set(kNetInfoHTTPCache, std::move(info_dict));
  387. }
  388. // Log Reporting API info.
  389. {
  390. #if BUILDFLAG(ENABLE_REPORTING)
  391. ReportingService* reporting_service = context->reporting_service();
  392. if (reporting_service) {
  393. base::Value reporting_value = reporting_service->StatusAsValue();
  394. NetworkErrorLoggingService* network_error_logging_service =
  395. context->network_error_logging_service();
  396. if (network_error_logging_service) {
  397. reporting_value.GetDict().Set(
  398. "networkErrorLogging",
  399. network_error_logging_service->StatusAsValue());
  400. }
  401. net_info_dict.Set(kNetInfoReporting, std::move(reporting_value));
  402. } else {
  403. base::Value::Dict reporting_dict;
  404. reporting_dict.Set("reportingEnabled", false);
  405. net_info_dict.Set(kNetInfoReporting, std::move(reporting_dict));
  406. }
  407. #else // BUILDFLAG(ENABLE_REPORTING)
  408. base::Value::Dict reporting_dict;
  409. reporting_dict.Set("reportingEnabled", false);
  410. net_info_dict.Set(kNetInfoReporting, std::move(reporting_dict));
  411. #endif // BUILDFLAG(ENABLE_REPORTING)
  412. }
  413. // Log currently-active field trials. New trials may have been enabled since
  414. // the start of this browser session (crbug.com/1133396).
  415. net_info_dict.Set(kNetInfoFieldTrials, GetActiveFieldTrialList());
  416. return net_info_dict;
  417. }
  418. NET_EXPORT void CreateNetLogEntriesForActiveObjects(
  419. const std::set<URLRequestContext*>& contexts,
  420. NetLog::ThreadSafeObserver* observer) {
  421. // Put together the list of all requests.
  422. std::vector<const URLRequest*> requests;
  423. for (auto* context : contexts) {
  424. // May only be called on the context's thread.
  425. context->AssertCalledOnValidThread();
  426. // Contexts should all be using the same NetLog.
  427. DCHECK_EQ((*contexts.begin())->net_log(), context->net_log());
  428. for (auto* request : *context->url_requests()) {
  429. requests.push_back(request);
  430. }
  431. }
  432. // Sort by creation time.
  433. std::sort(requests.begin(), requests.end(), RequestCreatedBefore);
  434. // Create fake events.
  435. for (auto* request : requests) {
  436. NetLogEntry entry(NetLogEventType::REQUEST_ALIVE,
  437. request->net_log().source(), NetLogEventPhase::BEGIN,
  438. request->creation_time(), request->GetStateAsValue());
  439. observer->OnAddEntry(entry);
  440. }
  441. }
  442. } // namespace net