Adds HostResolveImpl Requests and Jobs to log.

net/base/host_resolver_impl.cc

Index: net/base/host_resolver_impl.cc
===================================================================
--- net/base/host_resolver_impl.cc	(revision 57182)
+++ net/base/host_resolver_impl.cc	(working copy)
@@ -27,9 +27,11 @@
 #include "base/values.h"
 #include "base/worker_pool.h"
 #include "net/base/address_list.h"
+#include "net/base/address_list_net_log_param.h"
+#include "net/base/host_port_pair.h"
 #include "net/base/host_resolver_proc.h"
+#include "net/base/net_errors.h"
 #include "net/base/net_log.h"
-#include "net/base/net_errors.h"
 #include "net/base/net_util.h"
 
 #if defined(OS_WIN)
@@ -53,7 +55,8 @@
 
 }  // anonymous namespace
 
-HostResolver* CreateSystemHostResolver(size_t max_concurrent_resolves) {
+HostResolver* CreateSystemHostResolver(size_t max_concurrent_resolves,
+                                       NetLog* net_log) {
   // Maximum of 50 concurrent threads.
   // TODO(eroman): Adjust this, do some A/B experiments.
   static const size_t kDefaultMaxJobs = 50u;
@@ -63,7 +66,7 @@
 
   HostResolverImpl* resolver =
       new HostResolverImpl(NULL, CreateDefaultCache(),
-                           max_concurrent_resolves);
+                           max_concurrent_resolves, net_log);
 
   return resolver;
 }
@@ -88,16 +91,14 @@
 // Extra parameters to attach to the NetLog when the resolve failed.
 class HostResolveFailedParams : public NetLog::EventParameters {
  public:
-  HostResolveFailedParams(int net_error, int os_error, bool was_from_cache)
+  HostResolveFailedParams(int net_error, int os_error)
       : net_error_(net_error),
-        os_error_(os_error),
-        was_from_cache_(was_from_cache) {
+        os_error_(os_error) {
   }
 
   virtual Value* ToValue() const {
     DictionaryValue* dict = new DictionaryValue();
     dict->SetInteger("net_error", net_error_);
-    dict->SetBoolean("was_from_cache", was_from_cache_);
 
     if (os_error_) {
       dict->SetInteger("os_error", os_error_);
@@ -125,9 +126,55 @@
  private:
   const int net_error_;
   const int os_error_;
-  const bool was_from_cache_;
 };
 
+// Parameters representing the information in a RequestInfo object, along with
+// the associated NetLog::Source.
+class RequestInfoParameters : public NetLog::EventParameters {
+ public:
+  RequestInfoParameters(const HostResolver::RequestInfo& info,
+                        const NetLog::Source& source)
+      : info_(info), source_(source) {}
+
+  virtual Value* ToValue() const {
+    DictionaryValue* dict = new DictionaryValue();
+    dict->SetString("host", HostPortPair(info_.hostname(),
+                                         info_.port()).ToString());
+    dict->SetInteger("address_family",
+                     static_cast<int>(info_.address_family()));
+    dict->SetBoolean("allow_cached_response", info_.allow_cached_response());
+    dict->SetBoolean("is_speculative", info_.is_speculative());
+    dict->SetInteger("priority", info_.priority());
+
+    if (source_.is_valid())
+      dict->Set("source_dependency", source_.ToValue());
+
+    return dict;
+  }
+
+ private:
+  const HostResolver::RequestInfo info_;
+  const NetLog::Source source_;
+};
+
+// Parameters associated with the creation of a HostResolveImpl::Job.
+class JobCreationParameters : public NetLog::EventParameters {
+ public:
+  JobCreationParameters(const std::string& host, const NetLog::Source& source)
+      : host_(host), source_(source) {}
+
+  virtual Value* ToValue() const {
+    DictionaryValue* dict = new DictionaryValue();
+    dict->SetString("host", host_);
+    dict->Set("source_dependency", source_.ToValue());
+    return dict;
+  }
+
+ private:
+  const std::string host_;
+  const NetLog::Source source_;
+};
+
 // Gets a list of the likely error codes that getaddrinfo() can return
 // (non-exhaustive). These are the error codes that we will track via
 // a histogram.
@@ -176,12 +223,14 @@
 
 class HostResolverImpl::Request {
  public:
-  Request(const BoundNetLog& net_log,
+  Request(const BoundNetLog& source_net_log,
+          const BoundNetLog& request_net_log,
           int id,
           const RequestInfo& info,
           CompletionCallback* callback,
           AddressList* addresses)
-      : net_log_(net_log),
+      : source_net_log_(source_net_log),
+        request_net_log_(request_net_log),
         id_(id),
         info_(info),
         job_(NULL),
@@ -220,10 +269,14 @@
     return job_;
   }
 
-  const BoundNetLog& net_log() {
-    return net_log_;
+  const BoundNetLog& source_net_log() {
+    return source_net_log_;
   }
 
+  const BoundNetLog& request_net_log() {
+    return request_net_log_;
+  }
+
   int id() const {
     return id_;
   }
@@ -233,7 +286,8 @@
   }
 
  private:
-  BoundNetLog net_log_;
+  BoundNetLog source_net_log_;
+  BoundNetLog request_net_log_;
 
   // Unique ID for this request. Used by observers to identify requests.
   int id_;
@@ -260,20 +314,33 @@
 class HostResolverImpl::Job
     : public base::RefCountedThreadSafe<HostResolverImpl::Job> {
  public:
-  Job(int id, HostResolverImpl* resolver, const Key& key)
-      : id_(id),
-        key_(key),
-        resolver_(resolver),
-        origin_loop_(MessageLoop::current()),
-        resolver_proc_(resolver->effective_resolver_proc()),
-        error_(OK),
-        os_error_(0),
-        had_non_speculative_request_(false) {
+  Job(int id,
+      HostResolverImpl* resolver,
+      const Key& key,
+      const BoundNetLog& source_net_log,
+      NetLog* net_log)
+     : id_(id),
+       key_(key),
+       resolver_(resolver),
+       origin_loop_(MessageLoop::current()),
+       resolver_proc_(resolver->effective_resolver_proc()),
+       error_(OK),
+       os_error_(0),
+       had_non_speculative_request_(false),
+       net_log_(BoundNetLog::Make(net_log,
+                                  NetLog::SOURCE_HOST_RESOLVER_IMPL_JOB)) {
+    net_log_.BeginEvent(NetLog::TYPE_HOST_RESOLVER_IMPL_JOB,
+            new JobCreationParameters(key.hostname,
+                                      source_net_log.source()));
   }
 
   // Attaches a request to this job. The job takes ownership of |req| and will
   // take care to delete it.
   void AddRequest(Request* req) {
+    req->request_net_log().BeginEvent(
+        NetLog::TYPE_HOST_RESOLVER_IMPL_JOB_ATTACH,
+        new NetLogSourceParameter("source_dependency", net_log_.source()));
+
     req->set_job(this);
     requests_.push_back(req);
 
@@ -301,6 +368,8 @@
 
   // Cancels the current job. Callable from origin thread.
   void Cancel() {
+    net_log_.AddEvent(NetLog::TYPE_CANCELLED, NULL);
+
     HostResolver* resolver = resolver_;
     resolver_ = NULL;
 
@@ -311,6 +380,10 @@
       origin_loop_ = NULL;
     }
 
+    // End here to prevent issues when a Job outlives the HostResolver that
+    // spawned it.
+    net_log_.EndEvent(NetLog::TYPE_HOST_RESOLVER_IMPL_JOB, NULL);
+
     // We will call HostResolverImpl::CancelRequest(Request*) on each one
     // in order to notify any observers.
     for (RequestsList::const_iterator it = requests_.begin();
@@ -412,6 +485,17 @@
     if (was_cancelled())
       return;
 
+    scoped_refptr<NetLog::EventParameters> params;
+    if (error_ != OK) {
+      params = new HostResolveFailedParams(error_, os_error_);
+    } else {
+      params = new AddressListNetLogParam(results_);
+    }
+
+    // End here to prevent issues when a Job outlives the HostResolver that
+    // spawned it.
+    net_log_.EndEvent(NetLog::TYPE_HOST_RESOLVER_IMPL_JOB, params);
+
     DCHECK(!requests_.empty());
 
      // Use the port number of the first request.
@@ -456,6 +540,8 @@
   // The time when the job was started.
   base::TimeTicks start_time_;
 
+  BoundNetLog net_log_;
+
   DISALLOW_COPY_AND_ASSIGN(Job);
 };
 
@@ -608,6 +694,10 @@
   // evicted from the queue, and returned. Otherwise returns NULL. The caller
   // is responsible for freeing the evicted request.
   Request* InsertPendingRequest(Request* req) {
+    req->request_net_log().BeginEvent(
+        NetLog::TYPE_HOST_RESOLVER_IMPL_JOB_POOL_QUEUE,
+        NULL);
+
     PendingRequestsQueue& q = pending_requests_[req->info().priority()];
     q.push_back(req);
 
@@ -620,6 +710,10 @@
         if (!q.empty()) {
           Request* req = q.front();
           q.pop_front();
+          req->request_net_log().AddEvent(
+              NetLog::TYPE_HOST_RESOLVER_IMPL_JOB_POOL_QUEUE_EVICTED, NULL);
+          req->request_net_log().EndEvent(
+              NetLog::TYPE_HOST_RESOLVER_IMPL_JOB_POOL_QUEUE, NULL);
           return req;
         }
       }
@@ -635,6 +729,8 @@
     PendingRequestsQueue::iterator it = std::find(q.begin(), q.end(), req);
     DCHECK(it != q.end());
     q.erase(it);
+    req->request_net_log().EndEvent(
+        NetLog::TYPE_HOST_RESOLVER_IMPL_JOB_POOL_QUEUE, NULL);
   }
 
   // Removes and returns the highest priority pending request.
@@ -646,6 +742,8 @@
       if (!q.empty()) {
         Request* req = q.front();
         q.pop_front();
+        req->request_net_log().EndEvent(
+            NetLog::TYPE_HOST_RESOLVER_IMPL_JOB_POOL_QUEUE, NULL);
         return req;
       }
     }
@@ -709,7 +807,8 @@
 HostResolverImpl::HostResolverImpl(
     HostResolverProc* resolver_proc,
     HostCache* cache,
-    size_t max_jobs)
+    size_t max_jobs,
+    NetLog* net_log)
     : cache_(cache),
       max_jobs_(max_jobs),
       next_request_id_(0),
@@ -718,7 +817,8 @@
       default_address_family_(ADDRESS_FAMILY_UNSPECIFIED),
       shutdown_(false),
       ipv6_probe_monitoring_(false),
-      additional_resolver_flags_(0) {
+      additional_resolver_flags_(0),
+      net_log_(net_log) {
   DCHECK_GT(max_jobs, 0u);
 
   // It is cumbersome to expose all of the constraints in the constructor,
@@ -758,7 +858,7 @@
                               AddressList* addresses,
                               CompletionCallback* callback,
                               RequestHandle* out_req,
-                              const BoundNetLog& net_log) {
+                              const BoundNetLog& source_net_log) {
   DCHECK(CalledOnValidThread());
 
   if (shutdown_)
@@ -767,8 +867,12 @@
   // Choose a unique ID number for observers to see.
   int request_id = next_request_id_++;
 
+  // Make a log item for the request.
+  BoundNetLog request_net_log = BoundNetLog::Make(net_log_,
+      NetLog::SOURCE_HOST_RESOLVER_IMPL_REQUEST);
+
   // Update the net log and notify registered observers.
-  OnStartRequest(net_log, request_id, info);
+  OnStartRequest(source_net_log, request_net_log, request_id, info);
 
   // Check for IP literal.
   IPAddressNumber ip_number;
@@ -781,9 +885,8 @@
 
     *addresses = result;
     // Update the net log and notify registered observers.
-    OnFinishRequest(net_log, request_id, info, OK,
-                    0,  /* os_error (unknown since from cache) */
-                    false  /* was_from_cache */);
+    OnFinishRequest(source_net_log, request_net_log, request_id, info, OK,
+                    0  /* os_error (unknown since from cache) */);
     return OK;
   }
 
@@ -796,14 +899,15 @@
     const HostCache::Entry* cache_entry = cache_->Lookup(
         key, base::TimeTicks::Now());
     if (cache_entry) {
+      request_net_log.AddEvent(NetLog::TYPE_HOST_RESOLVER_IMPL_CACHE_HIT, NULL);
       int net_error = cache_entry->error;
       if (net_error == OK)
         addresses->SetFrom(cache_entry->addrlist, info.port());
 
       // Update the net log and notify registered observers.
-      OnFinishRequest(net_log, request_id, info, net_error,
-                      0,  /* os_error (unknown since from cache) */
-                      true  /* was_from_cache */);
+      OnFinishRequest(source_net_log, request_net_log, request_id, info,
+                      net_error,
+                      0  /* os_error (unknown since from cache) */);
 
       return net_error;
     }
@@ -826,15 +930,16 @@
       cache_->Set(key, error, addrlist, base::TimeTicks::Now());
 
     // Update the net log and notify registered observers.
-    OnFinishRequest(net_log, request_id, info, error, os_error,
-                    false /* was_from_cache */);
+    OnFinishRequest(source_net_log, request_net_log, request_id, info, error,
+                    os_error);
 
     return error;
   }
 
   // Create a handle for this request, and pass it back to the user if they
   // asked for it (out_req != NULL).
-  Request* req = new Request(net_log, request_id, info, callback, addresses);
+  Request* req = new Request(source_net_log, request_net_log, request_id, info,
+                             callback, addresses);
   if (out_req)
     *out_req = reinterpret_cast<RequestHandle>(req);
 
@@ -885,11 +990,15 @@
     JobPool* pool = GetPoolForRequest(req);
     pool->RemovePendingRequest(req);
     request_deleter.reset(req);
+  } else {
+    req->request_net_log().EndEvent(
+        NetLog::TYPE_HOST_RESOLVER_IMPL_JOB_ATTACH, NULL);
   }
 
   // NULL out the fields of req, to mark it as cancelled.
   req->MarkAsCancelled();
-  OnCancelRequest(req->net_log(), req->id(), req->info());
+  OnCancelRequest(req->source_net_log(), req->request_net_log(), req->id(),
+                  req->info());
 }
 
 void HostResolverImpl::AddObserver(HostResolver::Observer* observer) {
@@ -995,10 +1104,12 @@
     Request* req = *it;
     if (!req->was_cancelled()) {
       DCHECK_EQ(job, req->job());
+      req->request_net_log().EndEvent(
+          NetLog::TYPE_HOST_RESOLVER_IMPL_JOB_ATTACH, NULL);
 
       // Update the net log and notify registered observers.
-      OnFinishRequest(req->net_log(), req->id(), req->info(), net_error,
-                      os_error, false  /* was_from_cache */);
+      OnFinishRequest(req->source_net_log(), req->request_net_log(), req->id(),
+                      req->info(), net_error, os_error);
 
       req->OnComplete(net_error, addrlist);
 
@@ -1012,11 +1123,18 @@
   cur_completing_job_ = NULL;
 }
 
-void HostResolverImpl::OnStartRequest(const BoundNetLog& net_log,
+void HostResolverImpl::OnStartRequest(const BoundNetLog& source_net_log,
+                                      const BoundNetLog& request_net_log,
                                       int request_id,
                                       const RequestInfo& info) {
-  net_log.BeginEvent(NetLog::TYPE_HOST_RESOLVER_IMPL, NULL);
+  source_net_log.BeginEvent(
+      NetLog::TYPE_HOST_RESOLVER_IMPL,
+      new NetLogSourceParameter("source_dependency", request_net_log.source()));
 
+  request_net_log.BeginEvent(
+      NetLog::TYPE_HOST_RESOLVER_IMPL_REQUEST,
+      new RequestInfoParameters(info, source_net_log.source()));
+
   // Notify the observers of the start.
   if (!observers_.empty()) {
     for (ObserversList::iterator it = observers_.begin();
@@ -1026,12 +1144,12 @@
   }
 }
 
-void HostResolverImpl::OnFinishRequest(const BoundNetLog& net_log,
+void HostResolverImpl::OnFinishRequest(const BoundNetLog& source_net_log,
+                                       const BoundNetLog& request_net_log,
                                        int request_id,
                                        const RequestInfo& info,
                                        int net_error,
-                                       int os_error,
-                                       bool was_from_cache) {
+                                       int os_error) {
   bool was_resolved = net_error == OK;
 
   // Notify the observers of the completion.
@@ -1042,18 +1160,21 @@
     }
   }
 
-  // Log some extra parameters on failure.
+  // Log some extra parameters on failure for synchronous requests.
   scoped_refptr<NetLog::EventParameters> params;
-  if (!was_resolved)
-    params = new HostResolveFailedParams(net_error, os_error, was_from_cache);
+  if (!was_resolved) {
+    params = new HostResolveFailedParams(net_error, os_error);
+  }
 
-  net_log.EndEvent(NetLog::TYPE_HOST_RESOLVER_IMPL, params);
+  request_net_log.EndEvent(NetLog::TYPE_HOST_RESOLVER_IMPL_REQUEST, params);
+  source_net_log.EndEvent(NetLog::TYPE_HOST_RESOLVER_IMPL, NULL);
 }
 
-void HostResolverImpl::OnCancelRequest(const BoundNetLog& net_log,
+void HostResolverImpl::OnCancelRequest(const BoundNetLog& source_net_log,
+                                       const BoundNetLog& request_net_log,
                                        int request_id,
                                        const RequestInfo& info) {
-  net_log.AddEvent(NetLog::TYPE_CANCELLED, NULL);
+  request_net_log.AddEvent(NetLog::TYPE_CANCELLED, NULL);
 
   // Notify the observers of the cancellation.
   if (!observers_.empty()) {
@@ -1063,7 +1184,8 @@
     }
   }
 
-  net_log.EndEvent(NetLog::TYPE_HOST_RESOLVER_IMPL, NULL);
+  request_net_log.EndEvent(NetLog::TYPE_HOST_RESOLVER_IMPL_REQUEST, NULL);
+  source_net_log.EndEvent(NetLog::TYPE_HOST_RESOLVER_IMPL, NULL);
 }
 
 void HostResolverImpl::OnIPAddressChanged() {
@@ -1160,10 +1282,16 @@
 HostResolverImpl::Job* HostResolverImpl::CreateAndStartJob(Request* req) {
   DCHECK(CanCreateJobForPool(*GetPoolForRequest(req)));
   Key key = GetEffectiveKeyForRequest(req->info());
-  scoped_refptr<Job> job = new Job(next_job_id_++, this, key);
+
+  req->request_net_log().AddEvent(NetLog::TYPE_HOST_RESOLVER_IMPL_CREATE_JOB,
+                                  NULL);
+
+  scoped_refptr<Job> job = new Job(next_job_id_++, this, key,
+                                   req->request_net_log(), net_log_);
   job->AddRequest(req);
   AddOutstandingJob(job);
   job->Start();
+
   return job.get();
 }
 
@@ -1176,9 +1304,9 @@
     Request* r = req_evicted_from_queue.get();
     int error = ERR_HOST_RESOLVER_QUEUE_TOO_LARGE;
 
-    OnFinishRequest(r->net_log(), r->id(), r->info(), error,
-                    0,  /* os_error (not applicable) */
-                    false  /* was_from_cache */);
+    OnFinishRequest(r->source_net_log(), r->request_net_log(), r->id(),
+                    r->info(), error,
+                    0  /* os_error (not applicable) */);
 
     if (r == req)
       return error;