diff options
-rw-r--r-- | chrome/browser/net/passive_log_collector.cc | 29 | ||||
-rw-r--r-- | chrome/browser/net/passive_log_collector.h | 16 | ||||
-rw-r--r-- | net/base/cert_verifier.cc | 55 | ||||
-rw-r--r-- | net/base/cert_verifier.h | 7 | ||||
-rw-r--r-- | net/base/cert_verifier_unittest.cc | 54 | ||||
-rw-r--r-- | net/base/net_log_event_type_list.h | 18 | ||||
-rw-r--r-- | net/base/net_log_source_type_list.h | 3 | ||||
-rw-r--r-- | net/socket/ssl_client_socket_mac.cc | 3 | ||||
-rw-r--r-- | net/socket/ssl_client_socket_nss.cc | 3 | ||||
-rw-r--r-- | net/socket/ssl_client_socket_win.cc | 3 | ||||
-rw-r--r-- | net/socket/ssl_host_info.cc | 4 |
11 files changed, 158 insertions, 37 deletions
diff --git a/chrome/browser/net/passive_log_collector.cc b/chrome/browser/net/passive_log_collector.cc index db1736a..1791d99 100644 --- a/chrome/browser/net/passive_log_collector.cc +++ b/chrome/browser/net/passive_log_collector.cc @@ -81,6 +81,8 @@ PassiveLogCollector::PassiveLogCollector() trackers_[net::NetLog::SOURCE_ASYNC_HOST_RESOLVER_REQUEST] = &async_host_resolver_request_tracker_; trackers_[net::NetLog::SOURCE_UDP_SOCKET] = &udp_socket_tracker_; + trackers_[net::NetLog::SOURCE_CERT_VERIFIER_JOB] = + &cert_verifier_job_tracker_; // Make sure our mapping is up-to-date. for (size_t i = 0; i < arraysize(trackers_); ++i) DCHECK(trackers_[i]) << "Unhandled SourceType: " << i; @@ -755,3 +757,30 @@ PassiveLogCollector::UDPSocketTracker::DoAddEntry( return ACTION_NONE; } + +//---------------------------------------------------------------------------- +// CertVerifierJobTracker +//---------------------------------------------------------------------------- + +const size_t +PassiveLogCollector::CertVerifierJobTracker::kMaxNumSources = 100; + +const size_t +PassiveLogCollector::CertVerifierJobTracker::kMaxGraveyardSize = 15; + +PassiveLogCollector:: + CertVerifierJobTracker::CertVerifierJobTracker() + : SourceTracker(kMaxNumSources, kMaxGraveyardSize, NULL) { +} + +PassiveLogCollector::SourceTracker::Action +PassiveLogCollector::CertVerifierJobTracker::DoAddEntry( + const ChromeNetLog::Entry& entry, + SourceInfo* out_info) { + AddEntryToSourceInfo(entry, out_info); + if (entry.type == net::NetLog::TYPE_CERT_VERIFIER_JOB && + entry.phase == net::NetLog::PHASE_END) { + return ACTION_MOVE_TO_GRAVEYARD; + } + return ACTION_NONE; +} diff --git a/chrome/browser/net/passive_log_collector.h b/chrome/browser/net/passive_log_collector.h index 6da9734..63e2b18 100644 --- a/chrome/browser/net/passive_log_collector.h +++ b/chrome/browser/net/passive_log_collector.h @@ -400,6 +400,21 @@ class PassiveLogCollector : public ChromeNetLog::ThreadSafeObserverImpl { DISALLOW_COPY_AND_ASSIGN(UDPSocketTracker); }; + // Tracks the log entries for the last seen SOURCE_CERT_VERIFIER_JOB + class CertVerifierJobTracker : public SourceTracker { + public: + static const size_t kMaxNumSources; + static const size_t kMaxGraveyardSize; + + CertVerifierJobTracker(); + + private: + virtual Action DoAddEntry(const ChromeNetLog::Entry& entry, + SourceInfo* out_info); + + DISALLOW_COPY_AND_ASSIGN(CertVerifierJobTracker); + }; + PassiveLogCollector(); virtual ~PassiveLogCollector(); @@ -443,6 +458,7 @@ class PassiveLogCollector : public ChromeNetLog::ThreadSafeObserverImpl { DnsTransactionTracker dns_transaction_tracker_; AsyncHostResolverRequestTracker async_host_resolver_request_tracker_; UDPSocketTracker udp_socket_tracker_; + CertVerifierJobTracker cert_verifier_job_tracker_; // This array maps each NetLog::SourceType to one of the tracker instances // defined above. Use of this array avoid duplicating the list of trackers diff --git a/net/base/cert_verifier.cc b/net/base/cert_verifier.cc index ae474c5..efdee52 100644 --- a/net/base/cert_verifier.cc +++ b/net/base/cert_verifier.cc @@ -7,10 +7,13 @@ #include "base/bind.h" #include "base/compiler_specific.h" #include "base/message_loop.h" +#include "base/metrics/histogram.h" #include "base/stl_util.h" #include "base/synchronization/lock.h" +#include "base/time.h" #include "base/threading/worker_pool.h" #include "net/base/net_errors.h" +#include "net/base/net_log.h" #include "net/base/x509_certificate.h" #if defined(USE_NSS) @@ -89,21 +92,30 @@ bool CachedCertVerifyResult::HasExpired(const base::Time current_time) const { class CertVerifierRequest { public: CertVerifierRequest(const CompletionCallback& callback, - CertVerifyResult* verify_result) + CertVerifyResult* verify_result, + const BoundNetLog& net_log) : callback_(callback), - verify_result_(verify_result) { + verify_result_(verify_result), + net_log_(net_log) { + net_log_.BeginEvent(NetLog::TYPE_CERT_VERIFIER_REQUEST, NULL); + } + + ~CertVerifierRequest() { } // Ensures that the result callback will never be made. void Cancel() { callback_.Reset(); verify_result_ = NULL; + net_log_.AddEvent(NetLog::TYPE_CANCELLED, NULL); + net_log_.EndEvent(NetLog::TYPE_CERT_VERIFIER_REQUEST, NULL); } // Copies the contents of |verify_result| to the caller's // CertVerifyResult and calls the callback. void Post(const CachedCertVerifyResult& verify_result) { if (!callback_.is_null()) { + net_log_.EndEvent(NetLog::TYPE_CERT_VERIFIER_REQUEST, NULL); *verify_result_ = verify_result.result; callback_.Run(verify_result.error); } @@ -112,9 +124,12 @@ class CertVerifierRequest { bool canceled() const { return callback_.is_null(); } + const BoundNetLog& net_log() const { return net_log_; } + private: CompletionCallback callback_; CertVerifyResult* verify_result_; + const BoundNetLog net_log_; }; @@ -235,22 +250,40 @@ class CertVerifierWorker { // lives only on the CertVerifier's origin message loop. class CertVerifierJob { public: - explicit CertVerifierJob(CertVerifierWorker* worker) : worker_(worker) { + CertVerifierJob(CertVerifierWorker* worker, + const BoundNetLog& net_log) + : start_time_(base::TimeTicks::Now()), + worker_(worker), + net_log_(net_log) { + net_log_.BeginEvent(NetLog::TYPE_CERT_VERIFIER_JOB, NULL); } ~CertVerifierJob() { if (worker_) { + net_log_.AddEvent(NetLog::TYPE_CANCELLED, NULL); + net_log_.EndEvent(NetLog::TYPE_CERT_VERIFIER_JOB, NULL); worker_->Cancel(); DeleteAllCanceled(); } } void AddRequest(CertVerifierRequest* request) { + request->net_log().AddEvent( + NetLog::TYPE_CERT_VERIFIER_REQUEST_BOUND_TO_JOB, + make_scoped_refptr(new NetLogSourceParameter( + "source_dependency", net_log_.source()))); + requests_.push_back(request); } void HandleResult(const CachedCertVerifyResult& verify_result) { worker_ = NULL; + net_log_.EndEvent(NetLog::TYPE_CERT_VERIFIER_JOB, NULL); + UMA_HISTOGRAM_CUSTOM_TIMES("Net.CertVerifier_Job_Latency", + base::TimeTicks::Now() - start_time_, + base::TimeDelta::FromMilliseconds(1), + base::TimeDelta::FromMinutes(10), + 100); PostAll(verify_result); } @@ -277,8 +310,10 @@ class CertVerifierJob { } } + const base::TimeTicks start_time_; std::vector<CertVerifierRequest*> requests_; CertVerifierWorker* worker_; + const BoundNetLog net_log_; }; @@ -311,7 +346,8 @@ int CertVerifier::Verify(X509Certificate* cert, int flags, CertVerifyResult* verify_result, const CompletionCallback& callback, - RequestHandle* out_req) { + RequestHandle* out_req, + const BoundNetLog& net_log) { DCHECK(CalledOnValidThread()); if (callback.is_null() || !verify_result || hostname.empty()) { @@ -349,7 +385,9 @@ int CertVerifier::Verify(X509Certificate* cert, // Need to make a new request. CertVerifierWorker* worker = new CertVerifierWorker(cert, hostname, flags, this); - job = new CertVerifierJob(worker); + job = new CertVerifierJob( + worker, + BoundNetLog::Make(net_log.net_log(), NetLog::SOURCE_CERT_VERIFIER_JOB)); if (!worker->Start()) { delete job; delete worker; @@ -362,7 +400,7 @@ int CertVerifier::Verify(X509Certificate* cert, } CertVerifierRequest* request = - new CertVerifierRequest(callback, verify_result); + new CertVerifierRequest(callback, verify_result, net_log); job->AddRequest(request); *out_req = request; return ERR_IO_PENDING; @@ -464,7 +502,8 @@ int SingleRequestCertVerifier::Verify(X509Certificate* cert, const std::string& hostname, int flags, CertVerifyResult* verify_result, - const CompletionCallback& callback) { + const CompletionCallback& callback, + const BoundNetLog& net_log) { // Should not be already in use. DCHECK(!cur_request_ && cur_request_callback_.is_null()); @@ -480,7 +519,7 @@ int SingleRequestCertVerifier::Verify(X509Certificate* cert, cert, hostname, flags, verify_result, base::Bind(&SingleRequestCertVerifier::OnVerifyCompletion, base::Unretained(this)), - &request); + &request, net_log); if (rv == ERR_IO_PENDING) { // Cleared in OnVerifyCompletion(). diff --git a/net/base/cert_verifier.h b/net/base/cert_verifier.h index f701f77..5ad64b0 100644 --- a/net/base/cert_verifier.h +++ b/net/base/cert_verifier.h @@ -21,6 +21,7 @@ namespace net { +class BoundNetLog; class CertVerifierJob; class CertVerifierWorker; class X509Certificate; @@ -103,7 +104,8 @@ class NET_EXPORT CertVerifier : NON_EXPORTED_BASE(public base::NonThreadSafe), int flags, CertVerifyResult* verify_result, const CompletionCallback& callback, - RequestHandle* out_req); + RequestHandle* out_req, + const BoundNetLog& net_log); // Cancels the specified request. |req| is the handle returned by Verify(). // After a request is canceled, its completion callback will not be called. @@ -201,7 +203,8 @@ class SingleRequestCertVerifier { const std::string& hostname, int flags, CertVerifyResult* verify_result, - const CompletionCallback& callback); + const CompletionCallback& callback, + const BoundNetLog& net_log); private: // Callback for when the request to |cert_verifier_| completes, so we diff --git a/net/base/cert_verifier_unittest.cc b/net/base/cert_verifier_unittest.cc index 15eafa7..19dcc5c 100644 --- a/net/base/cert_verifier_unittest.cc +++ b/net/base/cert_verifier_unittest.cc @@ -9,6 +9,7 @@ #include "base/stringprintf.h" #include "net/base/cert_test_util.h" #include "net/base/net_errors.h" +#include "net/base/net_log.h" #include "net/base/test_completion_callback.h" #include "net/base/x509_certificate.h" #include "testing/gtest/include/gtest/gtest.h" @@ -50,7 +51,7 @@ TEST(CertVerifierTest, CacheHit) { CertVerifier::RequestHandle request_handle; error = verifier.Verify(test_cert, "www.example.com", 0, &verify_result, - callback.callback(), &request_handle); + callback.callback(), &request_handle, BoundNetLog()); ASSERT_EQ(ERR_IO_PENDING, error); ASSERT_TRUE(request_handle != NULL); error = callback.WaitForResult(); @@ -60,7 +61,7 @@ TEST(CertVerifierTest, CacheHit) { ASSERT_EQ(0u, verifier.inflight_joins()); error = verifier.Verify(test_cert, "www.example.com", 0, &verify_result, - callback.callback(), &request_handle); + callback.callback(), &request_handle, BoundNetLog()); // Synchronous completion. ASSERT_NE(ERR_IO_PENDING, error); ASSERT_TRUE(IsCertificateError(error)); @@ -91,11 +92,12 @@ TEST(CertVerifierTest, InflightJoin) { CertVerifier::RequestHandle request_handle2; error = verifier.Verify(test_cert, "www.example.com", 0, &verify_result, - callback.callback(), &request_handle); + callback.callback(), &request_handle, BoundNetLog()); ASSERT_EQ(ERR_IO_PENDING, error); ASSERT_TRUE(request_handle != NULL); - error = verifier.Verify(test_cert, "www.example.com", 0, &verify_result2, - callback2.callback(), &request_handle2); + error = verifier.Verify( + test_cert, "www.example.com", 0, &verify_result2, + callback2.callback(), &request_handle2, BoundNetLog()); ASSERT_EQ(ERR_IO_PENDING, error); ASSERT_TRUE(request_handle2 != NULL); error = callback.WaitForResult(); @@ -124,8 +126,9 @@ TEST(CertVerifierTest, ExpiredCacheEntry) { TestCompletionCallback callback; CertVerifier::RequestHandle request_handle; - error = verifier.Verify(test_cert, "www.example.com", 0, &verify_result, - callback.callback(), &request_handle); + error = verifier.Verify( + test_cert, "www.example.com", 0, &verify_result, + callback.callback(), &request_handle, BoundNetLog()); ASSERT_EQ(ERR_IO_PENDING, error); ASSERT_TRUE(request_handle != NULL); error = callback.WaitForResult(); @@ -135,8 +138,9 @@ TEST(CertVerifierTest, ExpiredCacheEntry) { ASSERT_EQ(0u, verifier.inflight_joins()); // Before expiration, should have a cache hit. - error = verifier.Verify(test_cert, "www.example.com", 0, &verify_result, - callback.callback(), &request_handle); + error = verifier.Verify( + test_cert, "www.example.com", 0, &verify_result, + callback.callback(), &request_handle, BoundNetLog()); // Synchronous completion. ASSERT_NE(ERR_IO_PENDING, error); ASSERT_TRUE(IsCertificateError(error)); @@ -149,8 +153,9 @@ TEST(CertVerifierTest, ExpiredCacheEntry) { ASSERT_EQ(1u, verifier.GetCacheSize()); current_time += base::TimeDelta::FromMinutes(60); time_service->set_current_time(current_time); - error = verifier.Verify(test_cert, "www.example.com", 0, &verify_result, - callback.callback(), &request_handle); + error = verifier.Verify( + test_cert, "www.example.com", 0, &verify_result, + callback.callback(), &request_handle, BoundNetLog()); ASSERT_EQ(ERR_IO_PENDING, error); ASSERT_TRUE(request_handle != NULL); ASSERT_EQ(0u, verifier.GetCacheSize()); @@ -183,8 +188,9 @@ TEST(CertVerifierTest, FullCache) { TestCompletionCallback callback; CertVerifier::RequestHandle request_handle; - error = verifier.Verify(test_cert, "www.example.com", 0, &verify_result, - callback.callback(), &request_handle); + error = verifier.Verify( + test_cert, "www.example.com", 0, &verify_result, + callback.callback(), &request_handle, BoundNetLog()); ASSERT_EQ(ERR_IO_PENDING, error); ASSERT_TRUE(request_handle != NULL); error = callback.WaitForResult(); @@ -195,8 +201,9 @@ TEST(CertVerifierTest, FullCache) { for (unsigned i = 0; i < kCacheSize; i++) { std::string hostname = base::StringPrintf("www%d.example.com", i + 1); - error = verifier.Verify(test_cert, hostname, 0, &verify_result, - callback.callback(), &request_handle); + error = verifier.Verify( + test_cert, hostname, 0, &verify_result, + callback.callback(), &request_handle, BoundNetLog()); ASSERT_EQ(ERR_IO_PENDING, error); ASSERT_TRUE(request_handle != NULL); error = callback.WaitForResult(); @@ -209,8 +216,9 @@ TEST(CertVerifierTest, FullCache) { ASSERT_EQ(kCacheSize, verifier.GetCacheSize()); current_time += base::TimeDelta::FromMinutes(60); time_service->set_current_time(current_time); - error = verifier.Verify(test_cert, "www999.example.com", 0, &verify_result, - callback.callback(), &request_handle); + error = verifier.Verify( + test_cert, "www999.example.com", 0, &verify_result, + callback.callback(), &request_handle, BoundNetLog()); ASSERT_EQ(ERR_IO_PENDING, error); ASSERT_TRUE(request_handle != NULL); ASSERT_EQ(kCacheSize, verifier.GetCacheSize()); @@ -235,8 +243,9 @@ TEST(CertVerifierTest, CancelRequest) { CertVerifyResult verify_result; CertVerifier::RequestHandle request_handle; - error = verifier.Verify(test_cert, "www.example.com", 0, &verify_result, - base::Bind(&FailTest), &request_handle); + error = verifier.Verify( + test_cert, "www.example.com", 0, &verify_result, + base::Bind(&FailTest), &request_handle, BoundNetLog()); ASSERT_EQ(ERR_IO_PENDING, error); ASSERT_TRUE(request_handle != NULL); verifier.CancelRequest(request_handle); @@ -246,8 +255,9 @@ TEST(CertVerifierTest, CancelRequest) { // worker thread) is likely to complete by the end of this test. TestCompletionCallback callback; for (int i = 0; i < 5; ++i) { - error = verifier.Verify(test_cert, "www2.example.com", 0, &verify_result, - callback.callback(), &request_handle); + error = verifier.Verify( + test_cert, "www2.example.com", 0, &verify_result, + callback.callback(), &request_handle, BoundNetLog()); ASSERT_EQ(ERR_IO_PENDING, error); ASSERT_TRUE(request_handle != NULL); error = callback.WaitForResult(); @@ -270,7 +280,7 @@ TEST(CertVerifierTest, CancelRequestThenQuit) { CertVerifier::RequestHandle request_handle; error = verifier.Verify(test_cert, "www.example.com", 0, &verify_result, - callback.callback(), &request_handle); + callback.callback(), &request_handle, BoundNetLog()); ASSERT_EQ(ERR_IO_PENDING, error); ASSERT_TRUE(request_handle != NULL); verifier.CancelRequest(request_handle); diff --git a/net/base/net_log_event_type_list.h b/net/base/net_log_event_type_list.h index 08c554b..1547bc8 100644 --- a/net/base/net_log_event_type_list.h +++ b/net/base/net_log_event_type_list.h @@ -1304,3 +1304,21 @@ EVENT_TYPE(CHROME_EXTENSION_PROVIDE_AUTH_CREDENTIALS) // This event is created when a request is blocked by a policy. EVENT_TYPE(CHROME_POLICY_ABORTED_REQUEST) + +// ------------------------------------------------------------------------ +// CertVerifier +// ------------------------------------------------------------------------ + +// This event is created when we start a CertVerifier request. +EVENT_TYPE(CERT_VERIFIER_REQUEST) + +// This event is created when we start a CertVerifier job. +EVENT_TYPE(CERT_VERIFIER_JOB) + +// This event is created when a CertVerifier request attaches to a job. +// +// The event parameters are: +// { +// "source_dependency": <Source identifer for the job we are bound to>, +// } +EVENT_TYPE(CERT_VERIFIER_REQUEST_BOUND_TO_JOB) diff --git a/net/base/net_log_source_type_list.h b/net/base/net_log_source_type_list.h index f54078d..7b1674b 100644 --- a/net/base/net_log_source_type_list.h +++ b/net/base/net_log_source_type_list.h @@ -23,5 +23,6 @@ SOURCE_TYPE(EXPONENTIAL_BACKOFF_THROTTLING, 12) SOURCE_TYPE(DNS_TRANSACTION, 13) SOURCE_TYPE(ASYNC_HOST_RESOLVER_REQUEST, 14) SOURCE_TYPE(UDP_SOCKET, 15) +SOURCE_TYPE(CERT_VERIFIER_JOB, 16) -SOURCE_TYPE(COUNT, 16) // Always keep this as the last entry. +SOURCE_TYPE(COUNT, 17) // Always keep this as the last entry. diff --git a/net/socket/ssl_client_socket_mac.cc b/net/socket/ssl_client_socket_mac.cc index a3c7854..b823265 100644 --- a/net/socket/ssl_client_socket_mac.cc +++ b/net/socket/ssl_client_socket_mac.cc @@ -1160,7 +1160,8 @@ int SSLClientSocketMac::DoVerifyCert() { server_cert_, host_and_port_.host(), flags, &server_cert_verify_result_, base::Bind(&SSLClientSocketMac::OnHandshakeIOComplete, - base::Unretained(this))); + base::Unretained(this)), + net_log_); } int SSLClientSocketMac::DoVerifyCertComplete(int result) { diff --git a/net/socket/ssl_client_socket_nss.cc b/net/socket/ssl_client_socket_nss.cc index e0ed410..bd7117d 100644 --- a/net/socket/ssl_client_socket_nss.cc +++ b/net/socket/ssl_client_socket_nss.cc @@ -1666,7 +1666,8 @@ int SSLClientSocketNSS::DoVerifyCert(int result) { server_cert_, host_and_port_.host(), flags, &local_server_cert_verify_result_, base::Bind(&SSLClientSocketNSS::OnHandshakeIOComplete, - base::Unretained(this))); + base::Unretained(this)), + net_log_); } // Derived from AuthCertificateCallback() in diff --git a/net/socket/ssl_client_socket_win.cc b/net/socket/ssl_client_socket_win.cc index 10ba66a..7235668 100644 --- a/net/socket/ssl_client_socket_win.cc +++ b/net/socket/ssl_client_socket_win.cc @@ -1177,7 +1177,8 @@ int SSLClientSocketWin::DoVerifyCert() { server_cert_, host_and_port_.host(), flags, &server_cert_verify_result_, base::Bind(&SSLClientSocketWin::OnHandshakeIOComplete, - base::Unretained(this))); + base::Unretained(this)), + net_log_); } int SSLClientSocketWin::DoVerifyCertComplete(int result) { diff --git a/net/socket/ssl_host_info.cc b/net/socket/ssl_host_info.cc index ae897b0..5b4b42dd 100644 --- a/net/socket/ssl_host_info.cc +++ b/net/socket/ssl_host_info.cc @@ -129,7 +129,9 @@ bool SSLHostInfo::ParseInner(const std::string& data) { verification_end_time_ = base::TimeTicks(); int rv = verifier_.Verify( cert_.get(), hostname_, flags, &cert_verify_result_, - base::Bind(&SSLHostInfo::VerifyCallback, weak_factory_.GetWeakPtr())); + base::Bind(&SSLHostInfo::VerifyCallback, weak_factory_.GetWeakPtr()), + // TODO(willchan): Figure out how to use NetLog here. + BoundNetLog()); if (rv != ERR_IO_PENDING) VerifyCallback(rv); } else { |