Added net_log logging statments for CertVerifyResult

net/cert/multi_threaded_cert_verifier.cc

 // Copyright (c) 2012 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/cert/multi_threaded_cert_verifier.h"
 
 #include <algorithm>
+#include <cstdlib>
+#include <iostream>

[Ryan Sleevi, 2014/05/30 22:46:24]

Unnecessary includes, I suspect?

[mshelley, 2014/05/31 00:38:19]

Done.

 
 #include "base/bind.h"
 #include "base/bind_helpers.h"
 #include "base/compiler_specific.h"
 #include "base/message_loop/message_loop.h"
 #include "base/metrics/histogram.h"
 #include "base/stl_util.h"
 #include "base/synchronization/lock.h"
 #include "base/threading/worker_pool.h"
 #include "base/time/time.h"
+#include "net/base/hash_value.h"
 #include "net/base/net_errors.h"
-#include "net/base/net_log.h"
+#include "net/cert/cert_status_flags.h"
 #include "net/cert/cert_trust_anchor_provider.h"
 #include "net/cert/cert_verify_proc.h"
 #include "net/cert/crl_set.h"
 #include "net/cert/x509_certificate.h"
 #include "net/cert/x509_certificate_net_log_param.h"
 
 #if defined(USE_NSS) || defined(OS_IOS)
 #include <private/pprthred.h>  // PR_DetachThread
 #endif
 
+using namespace std;

[Ryan Sleevi, 2014/05/30 22:46:24]

STYLE: This is forbidden by the style guide.

See
http://google-styleguide.googlecode.com/svn/trunk/cppguide.xml?showone=Namesp...
and search for "Using-directive" within the Decision section of Named
Namespaces.

[mshelley, 2014/05/31 00:38:19]

Done.

+
 namespace net {
 
 ////////////////////////////////////////////////////////////////////////////
 
 // Life of a request:
 //
 // MultiThreadedCertVerifier  CertVerifierJob  CertVerifierWorker     Request
 //      |                                         (origin loop)    (worker loop)
 //      |
 //   Verify()
@@ skipping 30 matching lines @@
 // On a cache hit, MultiThreadedCertVerifier::Verify() returns synchronously
 // without posting a task to a worker thread.
 
 namespace {
 
 // The default value of max_cache_entries_.
 const unsigned kMaxCacheEntries = 256;
 
 // The number of seconds for which we'll cache a cache entry.
 const unsigned kTTLSecs = 1800;  // 30 minutes.
 

[Ryan Sleevi, 2014/05/30 22:46:24]

STYLE: You would move lines 590-660 here

Longer explanation:
http://google-styleguide.googlecode.com/svn/trunk/cppguide.xml?showone=Declar...
documents the recommended order for declarations. While this section is specific
to classes, it also generally applies to unnamed namespaces.

The only exception is with respect to the "inline in the class definition" - we
generally inline functions within an unnamed namespace if they're free
functions, but *recommend* (but not require) that functions be out of line when
within classes within unnamed namespaces.

[Ryan Sleevi, 2014/05/31 00:53:02]

Still need to do this one.

 }  // namespace
 
 MultiThreadedCertVerifier::CachedResult::CachedResult() : error(ERR_FAILED) {}
 
 MultiThreadedCertVerifier::CachedResult::~CachedResult() {}
 
 MultiThreadedCertVerifier::CacheValidityPeriod::CacheValidityPeriod(
     const base::Time& now)
     : verification_time(now),
       expiration_time(now) {
@@ skipping 252 matching lines @@
     request->net_log().AddEvent(
         NetLog::TYPE_CERT_VERIFIER_REQUEST_BOUND_TO_JOB,
         net_log_.source().ToEventParametersCallback());
 
     requests_.push_back(request);
   }
 
   void HandleResult(
       const MultiThreadedCertVerifier::CachedResult& verify_result,
       bool is_first_job) {
+    net_log_.AddEvent(NetLog::TYPE_CERT_VERIFIER_JOB,
+                      base::Bind(&NetLogX509CertificateCallback,
+                                 verify_result.result.verified_cert));

[Ryan Sleevi, 2014/05/30 22:46:24]

Instead of logging this as a distinct event, use base::DictionaryValue::Set to
store the result of NetLogX509CertificateCallback

Say, on line 612

results->Set("verified_cert",
NetLogX509CertificateCallback(verify_result.result.verified_cert));

[mshelley, 2014/05/31 00:38:19]

When I explicitly call NetLogX509CC, I have to pass it a LogLevel -- I know the
options for this are: LOG_ALL, LOG_ALL_BUT_BYTES, LOG_STRIP_PRIVATE_DATA, and
LOG_NONE, but I'm not sure which I'm supposed to use?  

+    net_log_.AddEvent(
+        NetLog::TYPE_CERT_VERIFIER_JOB,
+        base::Bind(&CertVerifyResultCallback, verify_result.result));

[Ryan Sleevi, 2014/05/30 22:46:24]

Instead of using AddEvent to do this, update the EndEvent (line 365) to use the
CertVerifyResultCallback.

Note: You will also need to update the documentation in
net_log_event_type_list.h, at
https://code.google.com/p/chromium/codesearch#chromium/src/net/base/net_log_e...

[mshelley, 2014/05/31 00:38:19]

Done.

     worker_ = NULL;
     net_log_.EndEvent(NetLog::TYPE_CERT_VERIFIER_JOB);
     base::TimeDelta latency = base::TimeTicks::Now() - start_time_;
     UMA_HISTOGRAM_CUSTOM_TIMES("Net.CertVerifier_Job_Latency",
                                latency,
                                base::TimeDelta::FromMilliseconds(1),
                                base::TimeDelta::FromMinutes(10),
                                100);
     if (is_first_job) {
       UMA_HISTOGRAM_CUSTOM_TIMES("Net.CertVerifier_First_Job_Latency",
@@ skipping 213 matching lines @@
 }
 
 void MultiThreadedCertVerifier::OnCACertChanged(
     const X509Certificate* cert) {
   DCHECK(CalledOnValidThread());
 
   ClearCache();
 }
 
 }  // namespace net
+
+namespace {

[Ryan Sleevi, 2014/05/30 22:46:24]

STYLE: Add a newline between 598 and 599.

Long Answer: The general namespace formatting, which is not *required* so much
as *suggested*, is at
http://google-styleguide.googlecode.com/svn/trunk/cppguide.xml?showone=Namesp...

Within this, we usually place a blank line between the "namespace {" and the
first symbol within that namespace.

[mshelley, 2014/05/31 00:38:19]

Done.

+base::Value* CertVerifyResultCallback(net::CertVerifyResult verify_result,
+                                      net::NetLog::LogLevel log_level) {
+  base::DictionaryValue* results = new base::DictionaryValue();
+  results->SetBoolean("has_md5", verify_result.has_md5);
+  results->SetBoolean("has_md2", verify_result.has_md2);
+  results->SetBoolean("has_md4", verify_result.has_md4);
+  results->SetBoolean("is_issued_by_known_root",
+                      verify_result.is_issued_by_known_root);
+  results->SetBoolean("is_issued_by_additional_trust_anchor",
+                      verify_result.is_issued_by_additional_trust_anchor);
+  results->SetBoolean("common_name_fallback_used",
+                      verify_result.common_name_fallback_used);
+  results->SetInteger("cert_status.value", verify_result.cert_status);

[Ryan Sleevi, 2014/05/30 22:46:24]

Just call this

results->SetInteger("cert_status", verify_result.cert_status)

I explain why below.

[mshelley, 2014/05/31 00:38:19]

Done.

+  base::ListValue* flags = new base::ListValue();
+
+  // Parse bitmasked value into individual flags
+  if (verify_result.cert_status & (0xFFFF == 15))
+    flags->AppendString("CERT_STATUS_ALL_ERRORS");

[Ryan Sleevi, 2014/05/30 22:46:24]

This is a mask value for processing in conditionals. You don't need to log this.

[mshelley, 2014/05/31 00:38:19]

Done.

+  else {
+    if (verify_result.cert_status & net::CERT_STATUS_COMMON_NAME_INVALID)
+      flags->AppendString("CERT_STATUS_COMMON_NAME_INVALID");

[Ryan Sleevi, 2014/05/30 22:46:24]

So, turns out I steered you wrong, and this particular logging is actually going
to be a bit more complex, but we can defer that to a follow-up commit.

For this commit, just log the numeric value of the cert_status

You'd need to match how LoadFlags are handled. You can see how this works in
https://code.google.com/p/chromium/codesearch#chromium/src/net/base/net_log_l...

This would involve changing how CertStatus is declared (in
net/cert/cert_status_flags.h) to behave like load_flags.h / load_flags_list.h (
see
https://code.google.com/p/chromium/codesearch#chromium/src/net/base/load_flag...
and
https://code.google.com/p/chromium/codesearch#chromium/src/net/base/net_log_l...
)

Once this is in place (and it's creating symbolic names for CERT_STATUS), you'd
then need to update the .js responsible for chrome://net-internals (see
https://code.google.com/p/chromium/codesearch#chromium/src/chrome/browser/res...
for the starting point)

Once updated, you'd then also update
https://code.google.com/p/chromium/codesearch#chromium/src/chrome/browser/res...

+    if (verify_result.cert_status & net::CERT_STATUS_DATE_INVALID)
+      flags->AppendString("CERT_STATUS_DATE_INVALID");
+    if (verify_result.cert_status & net::CERT_STATUS_AUTHORITY_INVALID)
+      flags->AppendString("CERT_STATUS_AUTHORITY_INVALID");
+    if (verify_result.cert_status & net::CERT_STATUS_NO_REVOCATION_MECHANISM)
+      flags->AppendString("CERT_STATUS_NO_REVOCATION_MECHANISM");
+    if (verify_result.cert_status & net::CERT_STATUS_UNABLE_TO_CHECK_REVOCATION)
+      flags->AppendString("CERT_STATUS_UNABLE_TO_CHECK_REVOCATION");
+    if (verify_result.cert_status & net::CERT_STATUS_REVOKED)
+      flags->AppendString("CERT_STATUS_REVOKED");
+    if (verify_result.cert_status & net::CERT_STATUS_INVALID)
+      flags->AppendString("CERT_STATUS_INVALID");
+    if (verify_result.cert_status & net::CERT_STATUS_WEAK_SIGNATURE_ALGORITHM)
+      flags->AppendString("CERT_STATUS_WEAK_SIGNATURE_ALGORITHM");
+    if (verify_result.cert_status & net::CERT_STATUS_NON_UNIQUE_NAME)
+      flags->AppendString("CERT_STATUS_NON_UNIQUE_NAME");
+    if (verify_result.cert_status & net::CERT_STATUS_WEAK_KEY)
+      flags->AppendString("CERT_STATUS_WEAK_KEY");
+    if (verify_result.cert_status & net::CERT_STATUS_PINNED_KEY_MISSING)
+      flags->AppendString("CERT_STATUS_PINNED_KEY_MISSING");
+    if (verify_result.cert_status & net::CERT_STATUS_NAME_CONSTRAINT_VIOLATION)
+      flags->AppendString("CERT_STATUS_NAME_CONSTRAINT_VIOLATION");
+  }
+  if (verify_result.cert_status & net::CERT_STATUS_IS_EV)
+    flags->AppendString("CERT_STATUS_IS_EV");
+  if (verify_result.cert_status & net::CERT_STATUS_REV_CHECKING_ENABLED)
+    flags->AppendString("CERT_STATUS_REV_CHECKING_ENABLED");
+  results->Set("cert_status.flags_set", flags);
+
+  base::ListValue* hashes = new base::ListValue();
+  for (vector<net::HashValue>::iterator it =

[Ryan Sleevi, 2014/05/30 22:46:24]

When iterating in loops, prefer a const_iterator to an iterator. Not only does
it allow the compiler to generate more efficient code (or at least spend less
time doing the same code), it also helps clarify that you're not modifying
anything.

[mshelley, 2014/05/31 00:38:19]

Done.

+           verify_result.public_key_hashes.begin();
+       it != verify_result.public_key_hashes.end();
+       it++) {
+    hashes->AppendString(it->ToString());
+  }
+
+  results->Set("public_key_hashes", hashes);
+
+  return results;
+}
+}