UMA metrics for LogDnsClient

components/certificate_transparency/log_dns_client.cc

Index: components/certificate_transparency/log_dns_client.cc
diff --git a/components/certificate_transparency/log_dns_client.cc b/components/certificate_transparency/log_dns_client.cc
index fabbbac4698c36a0e36c9d5690f38ab9aa85587a..c4fe5554a3d8bf48bff66063b6bae3d83a4f0cc1 100644
--- a/components/certificate_transparency/log_dns_client.cc
+++ b/components/certificate_transparency/log_dns_client.cc
@@ -8,10 +8,11 @@
 #include "base/callback_helpers.h"
 #include "base/format_macros.h"
 #include "base/location.h"
 #include "base/logging.h"
 #include "base/memory/ptr_util.h"
+#include "base/metrics/histogram_macros.h"
 #include "base/strings/string_number_conversions.h"
 #include "base/strings/string_util.h"
 #include "base/strings/stringprintf.h"
 #include "base/threading/thread_task_runner_handle.h"
 #include "base/time/time.h"
@@ -28,10 +29,32 @@
 
 namespace certificate_transparency {
 
 namespace {
 
+// Used by UMA_HISTOGRAM_ENUMERATION to record query success/failures.
+// These values are written to logs.  New enum values can be added, but existing
+// enums must never be renumbered or deleted and reused.
+enum QueryStatus {
+  QUERY_STATUS_SUCCESS = 0,
+  QUERY_STATUS_FAILED_MISC = 1,

[Eran Messeri, 2016/12/20 11:41:54]

Nit: Rename FAILED_MISC to FAILED_UNKNOWN / FAILED_OTHER_DNS_ERROR ?
MISC is a bit too general a name, but I don't have a better suggestion.

[Rob Percival, 2016/12/21 15:30:51]

Done.

+  QUERY_STATUS_FAILED_NAME_RESOLUTION = 2,
+  QUERY_STATUS_FAILED_LEAF_INDEX_MALFORMED = 3,
+  QUERY_STATUS_FAILED_INCLUSION_PROOF_MALFORMED = 4,
+  QUERY_STATUS_MAX  // Upper bound
+};
+
+void LogQueryStatus(QueryStatus result) {
+  UMA_HISTOGRAM_ENUMERATION("Net.CertificateTransparency.DnsQueryStatus",
+                            result, QUERY_STATUS_MAX);
+}
+
+void LogQueryDuration(const base::TimeDelta& duration) {
+  UMA_HISTOGRAM_MEDIUM_TIMES("Net.CertificateTransparency.DnsQueryDuration",
+                             duration);
+}
+
 // Parses the DNS response and extracts a single string from the TXT RDATA.
 // If the response is malformed, not a TXT record, or contains any number of
 // strings other than 1, this returns false and extracts nothing.
 // Otherwise, it returns true and the extracted string is assigned to |*txt|.
 bool ParseTxtResponse(const net::DnsResponse& response, std::string* txt) {
@@ -189,10 +212,12 @@ class LogDnsClient::AuditProofQuery {
   // The most recent DNS response. Only valid so long as the corresponding DNS
   // request is stored in |current_dns_transaction_|.
   const net::DnsResponse* last_dns_response_;
   // The NetLog that DNS transactions will log to.
   net::NetLogWithSource net_log_;
+  // The time that Start() was last called. Used to measure query duration.
+  base::TimeTicks start_time_;
   // Produces WeakPtrs to |this| for binding callbacks.
   base::WeakPtrFactory<AuditProofQuery> weak_ptr_factory_;
 };
 
 LogDnsClient::AuditProofQuery::AuditProofQuery(
@@ -215,10 +240,11 @@ net::Error LogDnsClient::AuditProofQuery::Start(
     uint64_t tree_size,
     const net::CompletionCallback& callback,
     net::ct::MerkleAuditProof* proof) {
   // It should not already be in progress.
   DCHECK_EQ(State::NONE, next_state_);
+  start_time_ = base::TimeTicks::Now();
   proof_ = proof;
   proof_->tree_size = tree_size;
   leaf_hash_ = std::move(leaf_hash);
   callback_ = callback;
   // The first step in the query is to request the leaf index corresponding to
@@ -228,12 +254,13 @@ net::Error LogDnsClient::AuditProofQuery::Start(
   return DoLoop(net::OK);
 }
 
 net::Error LogDnsClient::AuditProofQuery::DoLoop(net::Error result) {
   CHECK_NE(State::NONE, next_state_);
+  State state;
   do {
-    State state = next_state_;
+    state = next_state_;
     next_state_ = State::NONE;
     switch (state) {
       case State::REQUEST_LEAF_INDEX:
         result = RequestLeafIndex();
         break;
@@ -250,10 +277,42 @@ net::Error LogDnsClient::AuditProofQuery::DoLoop(net::Error result) {
         NOTREACHED();
         break;
     }
   } while (result != net::ERR_IO_PENDING && next_state_ != State::NONE);
 
+  if (result != net::ERR_IO_PENDING) {
+    // If the query is complete, log some metrics.
+    LogQueryDuration(base::TimeTicks::Now() - start_time_);
+
+    switch (result) {
+      case net::OK:
+        LogQueryStatus(QUERY_STATUS_SUCCESS);
+        break;
+      case net::ERR_NAME_RESOLUTION_FAILED:
+        LogQueryStatus(QUERY_STATUS_FAILED_NAME_RESOLUTION);
+        break;
+      case net::ERR_DNS_MALFORMED_RESPONSE:
+        switch (state) {
+          case State::REQUEST_LEAF_INDEX_COMPLETE:
+            LogQueryStatus(QUERY_STATUS_FAILED_LEAF_INDEX_MALFORMED);
+            break;
+          case State::REQUEST_AUDIT_PROOF_NODES_COMPLETE:
+            LogQueryStatus(QUERY_STATUS_FAILED_INCLUSION_PROOF_MALFORMED);
+            break;
+          default:
+            NOTREACHED();
+            LogQueryStatus(QUERY_STATUS_FAILED_MISC);

[Eran Messeri, 2016/12/20 11:41:54]

Nit: Don't log here, since it's unreachable code (and may be conflated with the
other case FAILED_MISC is logged anyway).

[Rob Percival, 2016/12/21 15:30:51]

Done.

+            break;
+        }
+        break;
+      default:
+        // Some other error occurred.
+        LogQueryStatus(QUERY_STATUS_FAILED_MISC);
+        break;
+    }
+  }
+
   return result;
 }
 
 void LogDnsClient::AuditProofQuery::OnDnsTransactionComplete(
     net::DnsTransaction* transaction,