Adds HostResolveImpl Requests and Jobs to log.

Differences over the reverted version (http://codereview.chromium.org/3080034/show - reverted http://codereview.chromium.org/3137022/show ): * Jobs never log anything in their destructor, as the HostResolverImpl randomly outlives the NetLog, at least in some unit tests. * Removed the extra log entries for when a DNS lookup starts/completes. Instead, the job's event is ended in OnLookupComplete(). * Slight modification of the CanceledAsynchronousLookup unit test, as the Job is now closed before posting any events to the Request. For actual lookups, this behavior means the Job's duration more accurately reflects the time the DNS lookup takes itself. BUG=46844 TEST=Look at the net-internals screen. Review URL: http://codereview.chromium.org/3119027 git-svn-id: svn://svn.chromium.org/chrome/trunk/src@57189 0039d316-1c4b-4281-b951-d872f2087c98
author: mmenke@chromium.org <mmenke@chromium.org@0039d316-1c4b-4281-b951-d872f2087c98> 2010-08-24 15:55:51 +0000
committer: mmenke@chromium.org <mmenke@chromium.org@0039d316-1c4b-4281-b951-d872f2087c98> 2010-08-24 15:55:51 +0000
commit: ee094b89dd380eed93bc0e6ce380d03a0b1b5329 (patch)
tree: d49719e986de616af7b59b95046be1613568a8f7 /net/base
parent: bb872ba65a60c2ade48089f6f0bc538e0cc649ac (diff)
download: chromium_src-ee094b89dd380eed93bc0e6ce380d03a0b1b5329.zip
chromium_src-ee094b89dd380eed93bc0e6ce380d03a0b1b5329.tar.gz
chromium_src-ee094b89dd380eed93bc0e6ce380d03a0b1b5329.tar.bz2
10 files changed, 352 insertions, 89 deletions
diff --git a/net/base/host_resolver.h b/net/base/host_resolver.h
index a41b226..664dfb3 100644
--- a/net/base/host_resolver.h
+++ b/net/base/host_resolver.h
@@ -19,6 +19,7 @@ namespace net {
 class AddressList;
 class BoundNetLog;
 class HostResolverImpl;
+class NetLog;
 
 // This class represents the task of resolving hostnames (or IP address
 // literal) to an AddressList object.
@@ -244,7 +245,8 @@ class SingleRequestHostResolver {
 // |max_concurrent_resolves| is how many resolve requests will be allowed to
 // run in parallel. Pass HostResolver::kDefaultParallelism to choose a
 // default value.
-HostResolver* CreateSystemHostResolver(size_t max_concurrent_resolves);
+HostResolver* CreateSystemHostResolver(size_t max_concurrent_resolves,
+                                       NetLog* net_log);
 
 }  // namespace net
 
diff --git a/net/base/host_resolver_impl.cc b/net/base/host_resolver_impl.cc
index 11d9306..f4f7bbd 100644
--- a/net/base/host_resolver_impl.cc
+++ b/net/base/host_resolver_impl.cc
@@ -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_log.h"
 #include "net/base/net_errors.h"
+#include "net/base/net_log.h"
 #include "net/base/net_util.h"
 
 #if defined(OS_WIN)
@@ -53,7 +55,8 @@ HostCache* CreateDefaultCache() {
 
 }  // 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 @@ HostResolver* CreateSystemHostResolver(size_t max_concurrent_resolves) {
 
   HostResolverImpl* resolver =
       new HostResolverImpl(NULL, CreateDefaultCache(),
-                           max_concurrent_resolves);
+                           max_concurrent_resolves, net_log);
 
   return resolver;
 }
@@ -88,16 +91,14 @@ static int ResolveAddrInfo(HostResolverProc* resolver_proc,
 // 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,7 +126,53 @@ class HostResolveFailedParams : public NetLog::EventParameters {
  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
@@ -176,12 +223,14 @@ std::vector<int> GetAllGetAddrinfoOSErrors() {
 
 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,8 +269,12 @@ class HostResolverImpl::Request {
     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 {
@@ -233,7 +286,8 @@ class HostResolverImpl::Request {
   }
 
  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::Request {
 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 @@ class HostResolverImpl::Job
 
   // 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 @@ class HostResolverImpl::Job
       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 @@ class HostResolverImpl::Job
     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 @@ class HostResolverImpl::Job
   // The time when the job was started.
   base::TimeTicks start_time_;
 
+  BoundNetLog net_log_;
+
   DISALLOW_COPY_AND_ASSIGN(Job);
 };
 
@@ -608,6 +694,10 @@ class HostResolverImpl::JobPool {
   // 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 @@ class HostResolverImpl::JobPool {
         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 @@ class HostResolverImpl::JobPool {
     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 @@ class HostResolverImpl::JobPool {
       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 @@ class HostResolverImpl::JobPool {
 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 @@ HostResolverImpl::HostResolverImpl(
       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 @@ int HostResolverImpl::Resolve(const RequestInfo& info,
                               AddressList* addresses,
                               CompletionCallback* callback,
                               RequestHandle* out_req,
-                              const BoundNetLog& net_log) {
+                              const BoundNetLog& source_net_log) {
   DCHECK(CalledOnValidThread());
 
   if (shutdown_)
@@ -767,8 +867,12 @@ int HostResolverImpl::Resolve(const RequestInfo& info,
   // 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 @@ int HostResolverImpl::Resolve(const RequestInfo& info,
 
     *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 @@ int HostResolverImpl::Resolve(const RequestInfo& info,
     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 @@ int HostResolverImpl::Resolve(const RequestInfo& info,
       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 @@ void HostResolverImpl::CancelRequest(RequestHandle req_handle) {
     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 @@ void HostResolverImpl::OnJobComplete(Job* job,
     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,10 +1123,17 @@ void HostResolverImpl::OnJobComplete(Job* job,
   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()) {
@@ -1026,12 +1144,12 @@ void HostResolverImpl::OnStartRequest(const BoundNetLog& net_log,
   }
 }
 
-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 @@ void HostResolverImpl::OnFinishRequest(const BoundNetLog& net_log,
     }
   }
 
-  // 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 @@ void HostResolverImpl::OnCancelRequest(const BoundNetLog& net_log,
     }
   }
 
-  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::Key HostResolverImpl::GetEffectiveKeyForRequest(
 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 @@ int HostResolverImpl::EnqueueRequest(JobPool* pool, Request* req) {
     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;
diff --git a/net/base/host_resolver_impl.h b/net/base/host_resolver_impl.h
index 0bebe59..a06a478 100644
--- a/net/base/host_resolver_impl.h
+++ b/net/base/host_resolver_impl.h
@@ -75,16 +75,19 @@ class HostResolverImpl : public HostResolver,
   // used (which is SystemHostResolverProc except if overridden).
   // |max_jobs| specifies the maximum number of threads that the host resolver
   // will use. Use SetPoolConstraints() to specify finer-grain settings.
+  //
+  // |net_log| must remain valid for the life of the HostResolverImpl.
   HostResolverImpl(HostResolverProc* resolver_proc,
                    HostCache* cache,
-                   size_t max_jobs);
+                   size_t max_jobs,
+                   NetLog* net_log);
 
   // HostResolver methods:
   virtual int Resolve(const RequestInfo& info,
                       AddressList* addresses,
                       CompletionCallback* callback,
                       RequestHandle* out_req,
-                      const BoundNetLog& net_log);
+                      const BoundNetLog& source_net_log);
   virtual void CancelRequest(RequestHandle req);
   virtual void AddObserver(HostResolver::Observer* observer);
   virtual void RemoveObserver(HostResolver::Observer* observer);
@@ -154,20 +157,22 @@ class HostResolverImpl : public HostResolver,
                      const AddressList& addrlist);
 
   // Called when a request has just been started.
-  void OnStartRequest(const BoundNetLog& net_log,
+  void OnStartRequest(const BoundNetLog& source_net_log,
+                      const BoundNetLog& request_net_log,
                       int request_id,
                       const RequestInfo& info);
 
   // Called when a request has just completed (before its callback is run).
-  void OnFinishRequest(const BoundNetLog& net_log,
+  void 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);
 
   // Called when a request has been cancelled.
-  void OnCancelRequest(const BoundNetLog& net_log,
+  void OnCancelRequest(const BoundNetLog& source_net_log,
+                       const BoundNetLog& request_net_log,
                        int request_id,
                        const RequestInfo& info);
 
@@ -255,6 +260,8 @@ class HostResolverImpl : public HostResolver,
   // Any resolver flags that should be added to a request by default.
   HostResolverFlags additional_resolver_flags_;
 
+  NetLog* net_log_;
+
   DISALLOW_COPY_AND_ASSIGN(HostResolverImpl);
 };
 
diff --git a/net/base/host_resolver_impl_unittest.cc b/net/base/host_resolver_impl_unittest.cc
index a3b863d..a78d1c0 100644
--- a/net/base/host_resolver_impl_unittest.cc
+++ b/net/base/host_resolver_impl_unittest.cc
@@ -38,7 +38,8 @@ HostCache* CreateDefaultCache() {
 static const size_t kMaxJobs = 10u;
 
 HostResolverImpl* CreateHostResolverImpl(HostResolverProc* resolver_proc) {
-  return new HostResolverImpl(resolver_proc, CreateDefaultCache(), kMaxJobs);
+  return new HostResolverImpl(resolver_proc, CreateDefaultCache(), kMaxJobs,
+                              NULL);
 }
 
 // Helper to create a HostResolver::RequestInfo.
@@ -329,10 +330,14 @@ TEST_F(HostResolverImplTest, CanceledAsynchronousLookup) {
   scoped_refptr<WaitingHostResolverProc> resolver_proc =
       new WaitingHostResolverProc(NULL);
 
+  CapturingNetLog net_log(CapturingNetLog::kUnbounded);
   CapturingBoundNetLog log(CapturingNetLog::kUnbounded);
   {
     scoped_refptr<HostResolver> host_resolver(
-        CreateHostResolverImpl(resolver_proc));
+        new HostResolverImpl(resolver_proc,
+                             CreateDefaultCache(),
+                             kMaxJobs,
+                             &net_log));
     AddressList adrlist;
     const int kPortnum = 80;
 
@@ -350,13 +355,33 @@ TEST_F(HostResolverImplTest, CanceledAsynchronousLookup) {
 
   resolver_proc->Signal();
 
-  EXPECT_EQ(3u, log.entries().size());
+  EXPECT_EQ(2u, log.entries().size());
   EXPECT_TRUE(LogContainsBeginEvent(
       log.entries(), 0, NetLog::TYPE_HOST_RESOLVER_IMPL));
-  EXPECT_TRUE(LogContainsEvent(
-      log.entries(), 1, NetLog::TYPE_CANCELLED, NetLog::PHASE_NONE));
   EXPECT_TRUE(LogContainsEndEvent(
-      log.entries(), 2, NetLog::TYPE_HOST_RESOLVER_IMPL));
+      log.entries(), 1, NetLog::TYPE_HOST_RESOLVER_IMPL));
+
+  int pos = net::ExpectLogContainsSomewhereAfter(net_log.entries(), 0,
+      net::NetLog::TYPE_HOST_RESOLVER_IMPL_REQUEST,
+      net::NetLog::PHASE_BEGIN);
+  pos = net::ExpectLogContainsSomewhereAfter(net_log.entries(), pos + 1,
+      net::NetLog::TYPE_HOST_RESOLVER_IMPL_JOB,
+      net::NetLog::PHASE_BEGIN);
+  // Both Job and Request need to be cancelled.
+  pos = net::ExpectLogContainsSomewhereAfter(net_log.entries(), pos + 1,
+      net::NetLog::TYPE_CANCELLED,
+      net::NetLog::PHASE_NONE);
+  // Don't care about order in which they end, or when the other one is
+  // cancelled.
+  net::ExpectLogContainsSomewhereAfter(net_log.entries(), pos + 1,
+      net::NetLog::TYPE_CANCELLED,
+      net::NetLog::PHASE_NONE);
+  net::ExpectLogContainsSomewhereAfter(net_log.entries(), pos + 1,
+      net::NetLog::TYPE_HOST_RESOLVER_IMPL_REQUEST,
+      net::NetLog::PHASE_END);
+  net::ExpectLogContainsSomewhereAfter(net_log.entries(), pos + 1,
+      net::NetLog::TYPE_HOST_RESOLVER_IMPL_JOB,
+      net::NetLog::PHASE_END);
 
   EXPECT_FALSE(callback_called_);
 }
@@ -753,7 +778,7 @@ TEST_F(HostResolverImplTest, StartWithinCallback) {
 
   // Turn off caching for this host resolver.
   scoped_refptr<HostResolver> host_resolver(
-      new HostResolverImpl(resolver_proc, NULL, kMaxJobs));
+      new HostResolverImpl(resolver_proc, NULL, kMaxJobs, NULL));
 
   // The class will receive callbacks for when each resolve completes. It
   // checks that the right things happened.
@@ -1050,7 +1075,7 @@ TEST_F(HostResolverImplTest, CancellationObserver) {
 // Test that IP address changes flush the cache.
 TEST_F(HostResolverImplTest, FlushCacheOnIPAddressChange) {
   scoped_refptr<HostResolver> host_resolver(
-      new HostResolverImpl(NULL, CreateDefaultCache(), kMaxJobs));
+      new HostResolverImpl(NULL, CreateDefaultCache(), kMaxJobs, NULL));
 
   AddressList addrlist;
 
@@ -1087,7 +1112,8 @@ TEST_F(HostResolverImplTest, HigherPriorityRequestsStartedFirst) {
   // This HostResolverImpl will only allow 1 outstanding resolve at a time.
   size_t kMaxJobs = 1u;
   scoped_refptr<HostResolver> host_resolver(
-      new HostResolverImpl(resolver_proc, CreateDefaultCache(), kMaxJobs));
+      new HostResolverImpl(resolver_proc, CreateDefaultCache(), kMaxJobs,
+                           NULL));
 
   CapturingObserver observer;
   host_resolver->AddObserver(&observer);
@@ -1171,7 +1197,8 @@ TEST_F(HostResolverImplTest, CancelPendingRequest) {
   // This HostResolverImpl will only allow 1 outstanding resolve at a time.
   const size_t kMaxJobs = 1u;
   scoped_refptr<HostResolver> host_resolver(
-      new HostResolverImpl(resolver_proc, CreateDefaultCache(), kMaxJobs));
+      new HostResolverImpl(resolver_proc, CreateDefaultCache(), kMaxJobs,
+                           NULL));
 
   // Note that at this point the CapturingHostResolverProc is blocked, so any
   // requests we make will not complete.
@@ -1233,7 +1260,7 @@ TEST_F(HostResolverImplTest, QueueOverflow) {
   // This HostResolverImpl will only allow 1 outstanding resolve at a time.
   const size_t kMaxOutstandingJobs = 1u;
   scoped_refptr<HostResolverImpl> host_resolver(new HostResolverImpl(
-      resolver_proc, CreateDefaultCache(), kMaxOutstandingJobs));
+      resolver_proc, CreateDefaultCache(), kMaxOutstandingJobs, NULL));
 
   // Only allow up to 3 requests to be enqueued at a time.
   const size_t kMaxPendingRequests = 3u;
@@ -1311,7 +1338,7 @@ TEST_F(HostResolverImplTest, SetDefaultAddressFamily_IPv4) {
   // This HostResolverImpl will only allow 1 outstanding resolve at a time.
   const size_t kMaxOutstandingJobs = 1u;
   scoped_refptr<HostResolverImpl> host_resolver(new HostResolverImpl(
-      resolver_proc, CreateDefaultCache(), kMaxOutstandingJobs));
+      resolver_proc, CreateDefaultCache(), kMaxOutstandingJobs, NULL));
 
   host_resolver->SetDefaultAddressFamily(ADDRESS_FAMILY_IPV4);
 
@@ -1379,7 +1406,7 @@ TEST_F(HostResolverImplTest, SetDefaultAddressFamily_IPv6) {
   // This HostResolverImpl will only allow 1 outstanding resolve at a time.
   const size_t kMaxOutstandingJobs = 1u;
   scoped_refptr<HostResolverImpl> host_resolver(new HostResolverImpl(
-      resolver_proc, CreateDefaultCache(), kMaxOutstandingJobs));
+      resolver_proc, CreateDefaultCache(), kMaxOutstandingJobs, NULL));
 
   host_resolver->SetDefaultAddressFamily(ADDRESS_FAMILY_IPV6);
 
@@ -1445,7 +1472,7 @@ TEST_F(HostResolverImplTest, SetDefaultAddressFamily_Synchronous) {
 
   const size_t kMaxOutstandingJobs = 10u;
   scoped_refptr<HostResolverImpl> host_resolver(new HostResolverImpl(
-      resolver_proc, CreateDefaultCache(), kMaxOutstandingJobs));
+      resolver_proc, CreateDefaultCache(), kMaxOutstandingJobs, NULL));
 
   host_resolver->SetDefaultAddressFamily(ADDRESS_FAMILY_IPV4);
 
diff --git a/net/base/mock_host_resolver.cc b/net/base/mock_host_resolver.cc
index a9fc754..2baeb26 100644
--- a/net/base/mock_host_resolver.cc
+++ b/net/base/mock_host_resolver.cc
@@ -102,7 +102,7 @@ void MockHostResolverBase::Reset(HostResolverProc* interceptor) {
         base::TimeDelta::FromSeconds(0));
   }
 
-  impl_ = new HostResolverImpl(proc, cache, 50u);
+  impl_ = new HostResolverImpl(proc, cache, 50u, NULL);
 }
 
 //-----------------------------------------------------------------------------
diff --git a/net/base/net_log.cc b/net/base/net_log.cc
index adf8381..c91306c 100644
--- a/net/base/net_log.cc
+++ b/net/base/net_log.cc
@@ -11,6 +11,13 @@
 
 namespace net {
 
+Value* NetLog::Source::ToValue() const {
+  DictionaryValue* dict = new DictionaryValue();
+  dict->SetInteger("type", static_cast<int>(type));
+  dict->SetInteger("id", static_cast<int>(id));
+  return dict;
+}
+
 // static
 const char* NetLog::EventTypeToString(EventType event) {
   switch (event) {
@@ -169,11 +176,7 @@ Value* NetLogStringParameter::ToValue() const {
 Value* NetLogSourceParameter::ToValue() const {
   DictionaryValue* dict = new DictionaryValue();
 
-  DictionaryValue* source_dict = new DictionaryValue();
-  source_dict->SetInteger("type", static_cast<int>(value_.type));
-  source_dict->SetInteger("id", static_cast<int>(value_.id));
-
-  dict->Set(name_, source_dict);
+  dict->Set(name_, value_.ToValue());
   return dict;
 }
 
diff --git a/net/base/net_log.h b/net/base/net_log.h
index b6492cd..fc6d9b5 100644
--- a/net/base/net_log.h
+++ b/net/base/net_log.h
@@ -70,7 +70,10 @@ class NetLog {
 
     Source() : type(SOURCE_NONE), id(kInvalidId) {}
     Source(SourceType type, uint32 id) : type(type), id(id) {}
-    bool is_valid() { return id != kInvalidId; }
+    bool is_valid() const { return id != kInvalidId; }
+
+    // The caller takes ownership of the returned Value*.
+    Value* ToValue() const;
 
     SourceType type;
     uint32 id;
diff --git a/net/base/net_log_event_type_list.h b/net/base/net_log_event_type_list.h
index f729c2d..c09b46c 100644
--- a/net/base/net_log_event_type_list.h
+++ b/net/base/net_log_event_type_list.h
@@ -20,14 +20,86 @@ EVENT_TYPE(REQUEST_ALIVE)
 // HostResolverImpl
 // ------------------------------------------------------------------------
 
-// The start/end of a host resolve (DNS) request.
-// If an error occurred, the end phase will contain these parameters:
+// The start/end of waiting on a host resolve (DNS) request.
+// The BEGIN phase contains the following parameters:
+//
+//   {
+//     "source_dependency": <Source id of the request being waited on>
+//   }
+EVENT_TYPE(HOST_RESOLVER_IMPL)
+
+// The start/end of a host resolve (DNS) request.  Note that these events are
+// logged for all DNS requests, though not all requests result in the creation
+// of a HostResolvedImpl::Request object.
+//
+// The BEGIN phase contains the following parameters:
+//
+//   {
+//     "host": <Hostname associated with the request>
+//     "source_dependency": <Source id, if any, of what created the request>
+//   }
+//
+// If an error occurred, the END phase will contain these parameters:
 //   {
 //     "net_error": <The net error code integer for the failure>,
 //     "os_error": <The exact error code integer that getaddrinfo() returned>,
-//     "was_from_cache": <True if the response was gotten from the cache>
 //   }
-EVENT_TYPE(HOST_RESOLVER_IMPL)
+
+EVENT_TYPE(HOST_RESOLVER_IMPL_REQUEST)
+
+// This event is logged when a request is handled by a cache entry.
+EVENT_TYPE(HOST_RESOLVER_IMPL_CACHE_HIT)
+
+// This event means a request was queued/dequeued for subsequent job creation,
+// because there are already too many active HostResolverImpl::Jobs.
+//
+// The BEGIN phase contains the following parameters:
+//
+//   {
+//     "priority": <Priority of the queued request>
+//   }
+EVENT_TYPE(HOST_RESOLVER_IMPL_JOB_POOL_QUEUE)
+
+// This event is created when a new HostResolverImpl::Request is evicted from
+// JobPool without a Job being created, because the limit on number of queued
+// Requests was reached.
+EVENT_TYPE(HOST_RESOLVER_IMPL_JOB_POOL_QUEUE_EVICTED)
+
+// This event is created when a new HostResolverImpl::Job is about to be created
+// for a request.
+EVENT_TYPE(HOST_RESOLVER_IMPL_CREATE_JOB)
+
+// This is logged for a request when it's attached to a
+// HostResolverImpl::Job.  When this occurs without a preceding
+// HOST_RESOLVER_IMPL_CREATE_JOB entry, it means the request was attached to an
+// existing HostResolverImpl::Job.
+//
+// If the BoundNetLog used to create the event has a valid source id, the BEGIN
+// phase contains the following parameters:
+//
+//   {
+//     "source_dependency": <Source identifier for the attached Job>
+//   }
+EVENT_TYPE(HOST_RESOLVER_IMPL_JOB_ATTACH)
+
+// The creation/completion of a host resolve (DNS) job.
+// The BEGIN phase contains the following parameters:
+//
+//   {
+//     "host": <Hostname associated with the request>
+//     "source_dependency": <Source id, if any, of what created the request>
+//   }
+//
+// On success, the END phase has these parameters:
+//   {
+//     "address_list": <The host name being resolved>,
+//   }
+// If an error occurred, the END phase will contain these parameters:
+//   {
+//     "net_error": <The net error code integer for the failure>,
+//     "os_error": <The exact error code integer that getaddrinfo() returned>,
+//   }
+EVENT_TYPE(HOST_RESOLVER_IMPL_JOB)
 
 // ------------------------------------------------------------------------
 // InitProxyResolver
diff --git a/net/base/net_log_source_type_list.h b/net/base/net_log_source_type_list.h
index d416f3f..231ecd2 100644
--- a/net/base/net_log_source_type_list.h
+++ b/net/base/net_log_source_type_list.h
@@ -13,5 +13,7 @@ SOURCE_TYPE(INIT_PROXY_RESOLVER, 3)
 SOURCE_TYPE(CONNECT_JOB, 4)
 SOURCE_TYPE(SOCKET, 5)
 SOURCE_TYPE(SPDY_SESSION, 6)
+SOURCE_TYPE(HOST_RESOLVER_IMPL_REQUEST, 7)
+SOURCE_TYPE(HOST_RESOLVER_IMPL_JOB, 8)
 
-SOURCE_TYPE(COUNT, 7) // Always keep this as the last entry.
+SOURCE_TYPE(COUNT, 9) // Always keep this as the last entry.
diff --git a/net/base/net_log_unittest.h b/net/base/net_log_unittest.h
index 8db51e5..77a9cbd7 100644
--- a/net/base/net_log_unittest.h
+++ b/net/base/net_log_unittest.h
@@ -106,7 +106,7 @@ inline ::testing::AssertionResult LogContainsEntryWithType(
 
 
 // Expect that the log contains an event, but don't care about where
-// as long as the index where it is found is greater than min_index.
+// as long as the first index where it is found is at least |min_index|.
 // Returns the position where the event was found.
 inline size_t ExpectLogContainsSomewhere(
     const CapturingNetLog::EntryList& entries,
@@ -125,6 +125,25 @@ inline size_t ExpectLogContainsSomewhere(
   return i;
 }
 
+// Expect that the log contains an event, but don't care about where
+// as long as one index where it is found is at least |min_index|.
+// Returns the first such position where the event was found.
+inline size_t ExpectLogContainsSomewhereAfter(
+    const CapturingNetLog::EntryList& entries,
+    size_t min_index,
+    NetLog::EventType expected_event,
+    NetLog::EventPhase expected_phase) {
+  size_t i = min_index;
+  for (; i < entries.size(); ++i) {
+    const CapturingNetLog::Entry& entry = entries[i];
+    if (entry.type == expected_event &&
+        entry.phase == expected_phase)
+      break;
+  }
+  EXPECT_LT(i, entries.size());
+  return i;
+}
+
 }  // namespace net
 
 #endif  // NET_BASE_NET_LOG_UNITTEST_H_
author	mmenke@chromium.org <mmenke@chromium.org@0039d316-1c4b-4281-b951-d872f2087c98>	2010-08-24 15:55:51 +0000
committer	mmenke@chromium.org <mmenke@chromium.org@0039d316-1c4b-4281-b951-d872f2087c98>	2010-08-24 15:55:51 +0000
commit	ee094b89dd380eed93bc0e6ce380d03a0b1b5329 (patch)
tree	d49719e986de616af7b59b95046be1613568a8f7 /net/base
parent	bb872ba65a60c2ade48089f6f0bc538e0cc649ac (diff)
download	chromium_src-ee094b89dd380eed93bc0e6ce380d03a0b1b5329.zip chromium_src-ee094b89dd380eed93bc0e6ce380d03a0b1b5329.tar.gz chromium_src-ee094b89dd380eed93bc0e6ce380d03a0b1b5329.tar.bz2