Certificate Transparency: Adding finch and NetLog logging for EV certs

net/cert/cert_policy_enforcer.cc

 // 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/cert/cert_policy_enforcer.h"
 
 #include <algorithm>
 
+#include "base/bind.h"
 #include "base/build_time.h"
+#include "base/callback_helpers.h"
 #include "base/metrics/field_trial.h"
 #include "base/metrics/histogram.h"
 #include "base/numerics/safe_conversions.h"
 #include "base/strings/string_number_conversions.h"
+#include "base/values.h"
+#include "net/base/net_log.h"
 #include "net/cert/ct_ev_whitelist.h"
 #include "net/cert/ct_verify_result.h"
 #include "net/cert/signed_certificate_timestamp.h"
 #include "net/cert/x509_certificate.h"
+#include "net/cert/x509_certificate_net_log_param.h"
 
 namespace net {
 
 namespace {
 
 bool IsEmbeddedSCT(const scoped_refptr<ct::SignedCertificateTimestamp>& sct) {
   return sct->origin == ct::SignedCertificateTimestamp::SCT_EMBEDDED;
 }
 
 // Returns true if the current build is recent enough to ensure that
@@ skipping 25 matching lines @@
   return month_diff;
 }
 
 enum CTComplianceStatus {
   CT_NOT_COMPLIANT = 0,
   CT_IN_WHITELIST = 1,
   CT_ENOUGH_SCTS = 2,
   CT_COMPLIANCE_MAX,
 };
 
+const char* ComplianceStatusToString(CTComplianceStatus status) {
+  switch (status) {
+    case CT_NOT_COMPLIANT:
+      return "NOT_COMPLIANT";
+      break;
+    case CT_IN_WHITELIST:
+      return "WHITELISTED";
+      break;
+    case CT_ENOUGH_SCTS:
+      return "ENOUGH_SCTS";
+      break;
+    case CT_COMPLIANCE_MAX:
+      break;
+  }
+
+  return "unknown";
+}
+
 void LogCTComplianceStatusToUMA(CTComplianceStatus status) {
   UMA_HISTOGRAM_ENUMERATION("Net.SSL_EVCertificateCTCompliance", status,
                             CT_COMPLIANCE_MAX);
 }
 
+struct PolicyComplianceResult {
+  PolicyComplianceResult() { Reset(); }
+
+  void Reset() {

[mmenke, 2014/12/10 20:36:39]

Not needed.  Can just do all this in the constructor.  As-is, you're calling
Reset() twice in a row, which doesn't get you anything.

[Eran Messeri, 2014/12/12 12:44:56]

Done.

+    ct_presence_required = false;
+    build_timely = false;
+    result = CT_NOT_COMPLIANT;
+  }
+
+  bool ct_presence_required;
+  bool build_timely;
+  CTComplianceStatus result;

[mmenke, 2014/12/10 20:36:39]

May want to document these (Disclaimer:  I know nothing about certs, so they may
be obvious to someone who does)

[mmenke, 2014/12/10 20:36:40]

result->result is a bit ugly.

[Eran Messeri, 2014/12/12 12:44:56]

Done.

[Eran Messeri, 2014/12/12 12:44:56]

Done, changed.

+};
+
+base::Value* NetLogComplianceCheckResultCallback(X509Certificate* cert,
+                                                 PolicyComplianceResult* result,
+                                                 NetLog::LogLevel log_level) {
+  base::DictionaryValue* dict = new base::DictionaryValue();
+  dict->Set("certificate", NetLogX509CertificateCallback(cert, log_level));
+  dict->SetBoolean("policy_enforcement_required", result->ct_presence_required);
+  dict->SetBoolean("build_timely", result->build_timely);
+  dict->SetString("ct_compliance_status",
+                  ComplianceStatusToString(result->result));

[mmenke, 2014/12/10 20:36:40]

Logging this when one of the others is false seems a bit weird, as does logging
build_timely when ct_presence_required is false.

I suggest getting rid of PolicyComplianceResult and adding two values of the
enums instead.  Can then just have CheckCTEVPolicyCompliance return a
CTComplianceStatus.  Think it results in much cleaner code.

[Eran Messeri, 2014/12/12 12:44:56]

Acknowledged - it indeed does not make sense to log all values when they may be
meaningless sometimes. I've changed the logging logic to not log in these cases.
I have not added values to the enum because:
(1) It is used for UMA and I would not like to include the cases where the build
timely or enforcement was not required there (it will clutter the histogram -
policy enforcement is completely under our control using finch and build
timeliness is completely out of our control).
(2) There's additional information to log - such as the EV whitelist version,
which Ryan pointed out. 

+  return dict;
+}
+
 }  // namespace
 
 CertPolicyEnforcer::CertPolicyEnforcer(size_t num_ct_logs,
                                        bool require_ct_for_ev)
     : num_ct_logs_(num_ct_logs), require_ct_for_ev_(require_ct_for_ev) {
 }
 
 CertPolicyEnforcer::~CertPolicyEnforcer() {
 }
 
 bool CertPolicyEnforcer::DoesConformToCTEVPolicy(
     X509Certificate* cert,
     const ct::EVCertsWhitelist* ev_whitelist,
-    const ct::CTVerifyResult& ct_result) {
-  if (!require_ct_for_ev_)
+    const ct::CTVerifyResult& ct_result,
+    const BoundNetLog& net_log) {
+  PolicyComplianceResult result;
+  CheckCTEVPolicyCompliance(cert, ev_whitelist, ct_result, &result);
+
+  NetLog::ParametersCallback net_log_callback =
+      base::Bind(&NetLogComplianceCheckResultCallback, base::Unretained(cert),
+                 base::Unretained(&result));

[Ryan Sleevi, 2014/12/10 20:09:26]

You don't log anything about the ev_whitelist, such as the version that was
fetched.

What about situations where the user is using an old version of the EV
whitelist? What about situations where the user is using a new version of the EV
whitelist? What are the implications to diagnostics? How would that materially
affect this design? For example, it seems somewhat weird to set
"ev_whitelist_version" in the PolicyComplianceResult, but maybe not too weird.

[Eran Messeri, 2014/12/10 20:37:03]

Good point, I'll add logging of the EV whitelist version.

+
+  net_log.AddEvent(NetLog::TYPE_EV_CERT_CT_COMPLIANCE_CHECKED,
+                   net_log_callback);
+
+  if (!result.ct_presence_required)
     return true;
 
-  if (!IsBuildTimely())
+  if (!result.build_timely)
     return false;
 
-  if (IsCertificateInWhitelist(cert, ev_whitelist)) {
-    LogCTComplianceStatusToUMA(CT_IN_WHITELIST);
+  LogCTComplianceStatusToUMA(result.result);
+
+  if (result.result == CT_IN_WHITELIST || result.result == CT_ENOUGH_SCTS)
     return true;
-  }
 
-  if (HasRequiredNumberOfSCTs(cert, ct_result)) {
-    LogCTComplianceStatusToUMA(CT_ENOUGH_SCTS);
-    return true;
-  }
-
-  LogCTComplianceStatusToUMA(CT_NOT_COMPLIANT);
   return false;
 }
 
 bool CertPolicyEnforcer::IsCertificateInWhitelist(
     X509Certificate* cert,
     const ct::EVCertsWhitelist* ev_whitelist) {
   bool cert_in_ev_whitelist = false;
   if (ev_whitelist && ev_whitelist->IsValid()) {
     const SHA256HashValue fingerprint(
         X509Certificate::CalculateFingerprint256(cert->os_cert_handle()));
@@ skipping 46 matching lines @@
     num_required_embedded_scts = 3;
   } else {
     num_required_embedded_scts = 2;
   }
 
   size_t min_acceptable_logs = std::max(num_ct_logs_, static_cast<size_t>(2u));
   return num_embedded_scts >=
          std::min(num_required_embedded_scts, min_acceptable_logs);
 }
 
+void CertPolicyEnforcer::CheckCTEVPolicyCompliance(

[mmenke, 2014/12/10 20:36:40]

This doesn't seem to need to be a member of CertPolicyEnforcer.  Just move it up
into the anonymous namespace, and out of the header.

[Eran Messeri, 2014/12/12 12:44:56]

Done, although that led to a behaviour change as it was calling
HasRequiredNumberOfSCTs which does need a class member. Turns out that was a
desirable change :)

+    X509Certificate* cert,
+    const ct::EVCertsWhitelist* ev_whitelist,
+    const ct::CTVerifyResult& ct_result,
+    PolicyComplianceResult* check_result) {
+  check_result->Reset();
+  if (!require_ct_for_ev_)
+    return;
+  check_result->ct_presence_required = true;
+
+  if (!IsBuildTimely())
+    return;
+  check_result->build_timely = true;
+
+  if (IsCertificateInWhitelist(cert, ev_whitelist)) {
+    check_result->result = CT_IN_WHITELIST;
+    return;
+  }
+
+  if (HasRequiredNumberOfSCTs(cert, ct_result)) {
+    check_result->result = CT_ENOUGH_SCTS;
+    return;
+  }
+
+  check_result->result = CT_NOT_COMPLIANT;
+}
+
 }  // namespace net