[net] Add AsyncDNS.TTL histogram.

net/base/host_resolver_impl.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/base/host_resolver_impl.h"
 
 #if defined(OS_WIN)
 #include <Winsock2.h>
 #elif defined(OS_POSIX)
 #include <netdb.h>
@@ skipping 187 matching lines @@
     }
   } else {
     if (speculative) {
       DNS_HISTOGRAM("DNS.TotalTime_speculative", duration);
     } else {
       DNS_HISTOGRAM("DNS.TotalTime", duration);
     }
   }
 }
 
+void RecordTTL(base::TimeDelta ttl) {
+  UMA_HISTOGRAM_CUSTOM_COUNTS("AsyncDNS.TTL", ttl.InSeconds(), 1, 86400, 100);

[cbentzel, 2012/10/13 10:50:45]

Should be UMA_HISTOGRAM_CUSTOM_TIMES?

[szym, 2012/10/15 19:45:36]

I initially used _TIMES, but then I looked at the histogram results and didn't
like the non-round number of milliseconds on the bucket boundaries. I don't
think it makes any difference so I'll make it _TIMES of TimeDelta.

+}
+
 //-----------------------------------------------------------------------------
 
 // Wraps call to SystemHostResolverProc as an instance of HostResolverProc.
 // TODO(szym): This should probably be declared in host_resolver_proc.h.
 class CallSystemHostResolverProc : public HostResolverProc {
  public:
   CallSystemHostResolverProc() : HostResolverProc(NULL) {}
   virtual int Resolve(const std::string& hostname,
                       AddressFamily address_family,
                       HostResolverFlags host_resolver_flags,
@@ skipping 1106 matching lines @@
         base::Bind(&NetLogJobAttachCallback,
                    req->request_net_log().source(),
                    priority()));
 
     if (num_active_requests() > 0) {
       UpdatePriority();
     } else {
       // If we were called from a Request's callback within CompleteRequests,
       // that Request could not have been cancelled, so num_active_requests()
       // could not be 0. Therefore, we are not in CompleteRequests().
-      CompleteRequests(OK, AddressList(), base::TimeDelta());
+      CompleteRequestsWithError(OK /* cancelled */);
     }
   }
 
   // Called from AbortAllInProgressJobs. Completes all requests as aborted
   // and destroys the job.
   void Abort() {
     DCHECK(is_running());
-    CompleteRequests(ERR_ABORTED, AddressList(), base::TimeDelta());
+    CompleteRequestsWithError(ERR_ABORTED);
   }
 
   // Called by HostResolverImpl when this job is evicted due to queue overflow.
   // Completes all requests and destroys the job.
   void OnEvicted() {
     DCHECK(!is_running());
     DCHECK(is_queued());
     handle_.Reset();
 
     net_log_.AddEvent(NetLog::TYPE_HOST_RESOLVER_IMPL_JOB_EVICTED);
 
     // This signals to CompleteRequests that this job never ran.
-    CompleteRequests(ERR_HOST_RESOLVER_QUEUE_TOO_LARGE,
-                     AddressList(),
-                     base::TimeDelta());
+    CompleteRequestsWithError(ERR_HOST_RESOLVER_QUEUE_TOO_LARGE);
   }
 
   // Attempts to serve the job from HOSTS. Returns true if succeeded and
   // this Job was destroyed.
   bool ServeFromHosts() {
     DCHECK_GT(num_active_requests(), 0u);
     AddressList addr_list;
     if (resolver_->ServeFromHosts(key(),
                                   requests_.front()->info(),
                                   &addr_list)) {
       // This will destroy the Job.
-      CompleteRequests(OK, addr_list, base::TimeDelta());
+      CompleteRequests(OK, addr_list, base::TimeDelta(), false /* true_ttl */);

[cbentzel, 2012/10/13 10:50:45]

Would it make sense to change to CompleteRequests(addr_list, base::TimeDelta())
and have a CompleteRequestsHelper which both that and CompleteRequestsWithError
call?

[szym, 2012/10/15 19:45:36]

I don't see the benefit. Wouldn't this be the only place where it is used? The
other places need to pass a custom net_error or custom true_ttl.

       return true;
     }
     return false;
   }
 
   const Key key() const {
     return key_;
   }
 
   bool is_queued() const {
@@ skipping 77 matching lines @@
           UmaAsyncDnsResolveStatus(RESOLVE_STATUS_PROC_SUCCESS);
         }
         UMA_HISTOGRAM_CUSTOM_ENUMERATION("AsyncDNS.ResolveError",
                                          std::abs(dns_task_error_),
                                          GetAllErrorCodesForUma());
       } else {
         UmaAsyncDnsResolveStatus(RESOLVE_STATUS_FAIL);
       }
     }
 
-    base::TimeDelta ttl = base::TimeDelta::FromSeconds(
-        kNegativeCacheEntryTTLSeconds);
+    base::TimeDelta ttl =
+        base::TimeDelta::FromSeconds(kNegativeCacheEntryTTLSeconds);
     if (net_error == OK)
       ttl = base::TimeDelta::FromSeconds(kCacheEntryTTLSeconds);
 
-    CompleteRequests(net_error, addr_list, ttl);
+    CompleteRequests(net_error, addr_list, ttl, false /* true_ttl */);
   }
 
   void StartDnsTask() {
     DCHECK(resolver_->HaveDnsConfig());
     dns_task_.reset(new DnsTask(
         resolver_->dns_client_.get(),
         key_,
         base::Bind(&Job::OnDnsTaskComplete, base::Unretained(this)),
         net_log_));
 
@@ skipping 19 matching lines @@
       // TODO(szym): Run ServeFromHosts now if nsswitch.conf says so.
       // http://crbug.com/117655
 
       // TODO(szym): Some net errors indicate lack of connectivity. Starting
       // ProcTask in that case is a waste of time.
       StartProcTask();
       return;
     }
 
     UmaAsyncDnsResolveStatus(RESOLVE_STATUS_DNS_SUCCESS);
+    RecordTTL(ttl);
 
-    CompleteRequests(net_error, addr_list, ttl);
+    CompleteRequests(net_error, addr_list, ttl, true /* true_ttl */);
   }
 
   // Performs Job's last rites. Completes all Requests. Deletes this.
   void CompleteRequests(int net_error,
                         const AddressList& addr_list,
-                        base::TimeDelta ttl) {
+                        base::TimeDelta ttl,
+                        bool true_ttl) {
     CHECK(resolver_);
 
     // This job must be removed from resolver's |jobs_| now to make room for a
     // new job with the same key in case one of the OnComplete callbacks decides
     // to spawn one. Consequently, the job deletes itself when CompleteRequests
     // is done.
     scoped_ptr<Job> self_deleter(this);
 
     resolver_->RemoveJob(this);
 
-    // |addr_list| will be destroyed once we destroy |proc_task_| and
-    // |dns_task_|.
+    // |addr_list| will be destroyed with |proc_task_| and |dns_task_|.
     AddressList list = addr_list;
 
     if (is_running()) {
       DCHECK(!is_queued());
       if (is_proc_running()) {
         proc_task_->Cancel();
         proc_task_ = NULL;
       }
       dns_task_.reset();
 
@@ skipping 19 matching lines @@
     if (net_error == OK) {
       SetPortOnAddressList(requests_.front()->info().port(), &list);
       // Record this histogram here, when we know the system has a valid DNS
       // configuration.
       UMA_HISTOGRAM_BOOLEAN("AsyncDNS.HaveDnsConfig",
                             resolver_->received_dns_config_);
     }
 
     bool did_complete = (net_error != ERR_ABORTED) &&
                         (net_error != ERR_HOST_RESOLVER_QUEUE_TOO_LARGE);
-    if (did_complete)
-      resolver_->CacheResult(key_, net_error, list, ttl);
+    if (did_complete) {
+      HostCache::Entry entry = true_ttl ?
+          HostCache::Entry(net_error, list, ttl) :
+          HostCache::Entry(net_error, list);
+      resolver_->CacheResult(key_, entry, ttl);
+    }
 
     // Complete all of the requests that were attached to the job.
     for (RequestsList::const_iterator it = requests_.begin();
          it != requests_.end(); ++it) {
       Request* req = *it;
 
       if (req->was_canceled())
         continue;
 
       DCHECK_EQ(this, req->job());
       // Update the net log and notify registered observers.
       LogFinishRequest(req->source_net_log(), req->request_net_log(),
                        req->info(), net_error);
       if (did_complete) {
         // Record effective total time from creation to completion.
         RecordTotalTime(had_dns_config_, req->info().is_speculative(),
                         base::TimeTicks::Now() - req->request_time());
       }
       req->OnComplete(net_error, list);
 
       // Check if the resolver was destroyed as a result of running the
       // callback. If it was, we could continue, but we choose to bail.
       if (!resolver_)
         return;
     }
   }
 
+  // Convenience wrapper for CompleteRequests in case of failure.
+  void CompleteRequestsWithError(int net_error) {
+    CompleteRequests(net_error, AddressList(), base::TimeDelta(), false);
+  }
+
   RequestPriority priority() const {
     return priority_tracker_.highest_priority();
   }
 
   // Number of non-canceled requests in |requests_|.
   size_t num_active_requests() const {
     return priority_tracker_.total_count();
   }
 
   bool is_dns_running() const {
@@ skipping 341 matching lines @@
   if (!info.allow_cached_response() || !cache_.get())
     return false;
 
   const HostCache::Entry* cache_entry = cache_->Lookup(
       key, base::TimeTicks::Now());
   if (!cache_entry)
     return false;
 
   *net_error = cache_entry->error;
   if (*net_error == OK) {
+    if (cache_entry->has_ttl())
+      RecordTTL(cache_entry->ttl);
     *addresses = cache_entry->addrlist;
     EnsurePortOnAddressList(info.port(), addresses);
   }
   return true;
 }
 
 bool HostResolverImpl::ServeFromHosts(const Key& key,
                                       const RequestInfo& info,
                                       AddressList* addresses) {
   DCHECK(addresses);
@@ skipping 20 matching lines @@
     it = hosts.find(DnsHostsKey(hostname, ADDRESS_FAMILY_IPV6));
     if (it == hosts.end())
       return false;
   }
 
   *addresses = AddressList::CreateFromIPAddress(it->second, info.port());
   return true;
 }
 
 void HostResolverImpl::CacheResult(const Key& key,
-                                   int net_error,
-                                   const AddressList& addr_list,
+                                   const HostCache::Entry& entry,
                                    base::TimeDelta ttl) {
   if (cache_.get())
-    cache_->Set(key, net_error, addr_list, base::TimeTicks::Now(), ttl);
+    cache_->Set(key, entry, base::TimeTicks::Now(), ttl);
 }
 
 void HostResolverImpl::RemoveJob(Job* job) {
   DCHECK(job);
   JobMap::iterator it = jobs_.find(job->key());
   if (it != jobs_.end() && it->second == job)
     jobs_.erase(it);
 }
 
 void HostResolverImpl::DiscardIPv6ProbeJob() {
@@ skipping 130 matching lines @@
   // |this| may be deleted inside AbortAllInProgressJobs().
   if (self)
     TryServingAllJobsFromHosts();
 }
 
 bool HostResolverImpl::HaveDnsConfig() const {
   return (dns_client_.get() != NULL) && (dns_client_->GetConfig() != NULL);
 }
 
 }  // namespace net