summaryrefslogtreecommitdiffstats
diff options
context:
space:
mode:
-rw-r--r--chrome/browser/net/passive_log_collector.cc29
-rw-r--r--chrome/browser/net/passive_log_collector.h16
-rw-r--r--net/base/cert_verifier.cc55
-rw-r--r--net/base/cert_verifier.h7
-rw-r--r--net/base/cert_verifier_unittest.cc54
-rw-r--r--net/base/net_log_event_type_list.h18
-rw-r--r--net/base/net_log_source_type_list.h3
-rw-r--r--net/socket/ssl_client_socket_mac.cc3
-rw-r--r--net/socket/ssl_client_socket_nss.cc3
-rw-r--r--net/socket/ssl_client_socket_win.cc3
-rw-r--r--net/socket/ssl_host_info.cc4
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 {