Adds HostResolveImpl Requests and Jobs to log.

net/base/host_resolver_impl.cc

 // Copyright (c) 2010 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>
 #endif
 
 #include <cmath>
 #include <deque>
 #include <vector>
 
 #include "base/basictypes.h"
 #include "base/compiler_specific.h"
 #include "base/debug_util.h"
 #include "base/histogram.h"
 #include "base/lock.h"
 #include "base/message_loop.h"
 #include "base/stl_util-inl.h"
 #include "base/string_util.h"
 #include "base/time.h"
 #include "base/utf_string_conversions.h"
 #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)
 #include "net/base/winsock_init.h"
 #endif
 
 namespace net {
 
 namespace {
 
 HostCache* CreateDefaultCache() {
   static const size_t kMaxHostCacheEntries = 100;
 
   HostCache* cache = new HostCache(
       kMaxHostCacheEntries,
       base::TimeDelta::FromMinutes(1),
       base::TimeDelta::FromSeconds(0));  // Disable caching of failed DNS.
 
   return cache;
 }
 
 }  // 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;
 
   if (max_concurrent_resolves == HostResolver::kDefaultParallelism)
     max_concurrent_resolves = kDefaultMaxJobs;
 
   HostResolverImpl* resolver =
       new HostResolverImpl(NULL, CreateDefaultCache(),
-                           max_concurrent_resolves);
+                           max_concurrent_resolves, net_log);
 
   return resolver;
 }
 
 static int ResolveAddrInfo(HostResolverProc* resolver_proc,
                            const std::string& host,
                            AddressFamily address_family,
                            HostResolverFlags host_resolver_flags,
                            AddressList* out,
                            int* os_error) {
   if (resolver_proc) {
     // Use the custom procedure.
     return resolver_proc->Resolve(host, address_family,
                                   host_resolver_flags, out, os_error);
   } else {
     // Use the system procedure (getaddrinfo).
     return SystemHostResolverProc(host, address_family,
                                   host_resolver_flags, out, os_error);
   }
 }
 
 // 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_);
 #if defined(OS_POSIX)
       dict->SetString("os_error_string", gai_strerror(os_error_));
 #elif defined(OS_WIN)
       // Map the error code to a human-readable string.
       LPWSTR error_string = NULL;
       int size = FormatMessage(FORMAT_MESSAGE_ALLOCATE_BUFFER |
                                FORMAT_MESSAGE_FROM_SYSTEM,
                                0,  // Use the internal message table.
                                os_error_,
                                0,  // Use default language.
                                (LPWSTR)&error_string,
                                0,  // Buffer size.
                                0);  // Arguments (unused).
       dict->SetString("os_error_string", WideToUTF8(error_string));
       LocalFree(error_string);
 #endif
     }
 
     return dict;
   }
 
  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.
 std::vector<int> GetAllGetAddrinfoOSErrors() {
   int os_errors[] = {
 #if defined(OS_POSIX)
     EAI_ADDRFAMILY,
     EAI_AGAIN,
@@ skipping 30 matching lines @@
     // won't fall into the same buckets as the expected ones.
     errors.push_back(std::abs(os_errors[i]) + 1);
   }
   return errors;
 }
 
 //-----------------------------------------------------------------------------
 
 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),
         callback_(callback),
         addresses_(addresses) {
   }
 
   // Mark the request as cancelled.
   void MarkAsCancelled() {
     job_ = NULL;
@@ skipping 18 matching lines @@
   }
 
   int port() const {
     return info_.port();
   }
 
   Job* job() const {
     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_;
   }
 
   const RequestInfo& info() const {
     return info_;
   }
 
  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_;
 
   // The request info that started the request.
   RequestInfo info_;
 
   // The resolve job (running in worker pool) that this request is dependent on.
   Job* job_;
 
   // The user's callback to invoke when the request completes.
   CompletionCallback* callback_;
 
   // The address list to save result into.
   AddressList* addresses_;
 
   DISALLOW_COPY_AND_ASSIGN(Request);
 };
 
 //-----------------------------------------------------------------------------
 
 // This class represents a request to the worker pool for a "getaddrinfo()"
 // call.
 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);
 
     if (!req->info().is_speculative())
       had_non_speculative_request_ = true;
   }
 
   // Called from origin loop.
   void Start() {
     start_time_ = base::TimeTicks::Now();
 
     // Dispatch the job to a worker thread.
     if (!WorkerPool::PostTask(FROM_HERE,
             NewRunnableMethod(this, &Job::DoLookup), true)) {
       NOTREACHED();
 
       // Since we could be running within Resolve() right now, we can't just
       // call OnLookupComplete().  Instead we must wait until Resolve() has
       // returned (IO_PENDING).
       error_ = ERR_UNEXPECTED;
       MessageLoop::current()->PostTask(
           FROM_HERE, NewRunnableMethod(this, &Job::OnLookupComplete));
     }
   }
 
   // Cancels the current job. Callable from origin thread.
   void Cancel() {
+    net_log_.AddEvent(NetLog::TYPE_CANCELLED, NULL);
+
     HostResolver* resolver = resolver_;
     resolver_ = NULL;
 
     // Mark the job as cancelled, so when worker thread completes it will
     // not try to post completion to origin loop.
     {
       AutoLock locked(origin_loop_lock_);
       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();
          it != requests_.end(); ++it) {
       HostResolverImpl::Request* req = *it;
       if (!req->was_cancelled())
         resolver->CancelRequest(req);
     }
   }
 
@@ skipping 81 matching lines @@
 
     if (error_ != OK) {
       UMA_HISTOGRAM_CUSTOM_ENUMERATION("Net.OSErrorsForGetAddrinfo",
                                        std::abs(os_error_),
                                        GetAllGetAddrinfoOSErrors());
     }
 
     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.
     if (error_ == OK)
       results_.SetPort(requests_[0]->port());
 
     resolver_->OnJobComplete(this, error_, os_error_, results_);
   }
 
   // Immutable. Can be read from either thread,
@@ skipping 24 matching lines @@
   // (regardless of whether or not it was later cancelled.
   // This boolean is used for histogramming the duration of jobs used to
   // service non-speculative requests.
   bool had_non_speculative_request_;
 
   AddressList results_;
 
   // The time when the job was started.
   base::TimeTicks start_time_;
 
+  BoundNetLog net_log_;
+
   DISALLOW_COPY_AND_ASSIGN(Job);
 };
 
 //-----------------------------------------------------------------------------
 
 // This class represents a request to the worker pool for a "probe for IPv6
 // support" call.
 class HostResolverImpl::IPv6ProbeJob
     : public base::RefCountedThreadSafe<HostResolverImpl::IPv6ProbeJob> {
  public:
@@ skipping 132 matching lines @@
 
   bool HasPendingRequests() const {
     return GetNumPendingRequests() > 0u;
   }
 
   // Enqueues a request to this pool. As a result of enqueing this request,
   // the queue may have reached its maximum size. In this case, a request is
   // 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);
 
     // If the queue is too big, kick out the lowest priority oldest request.
     if (GetNumPendingRequests() > max_pending_requests_) {
       // Iterate over the queues from lowest priority to highest priority.
       for (int i = static_cast<int>(arraysize(pending_requests_)) - 1;
            i >= 0; --i) {
         PendingRequestsQueue& q = pending_requests_[i];
         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;
         }
       }
     }
 
     return NULL;
   }
 
   // Erases |req| from this container. Caller is responsible for freeing
   // |req| afterwards.
   void RemovePendingRequest(Request* req) {
     PendingRequestsQueue& q = pending_requests_[req->info().priority()];
     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.
   Request* RemoveTopPendingRequest() {
     DCHECK(HasPendingRequests());
 
     for (size_t i = 0u; i < arraysize(pending_requests_); ++i) {
       PendingRequestsQueue& q = pending_requests_[i];
       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;
       }
     }
 
     NOTREACHED();
     return NULL;
   }
 
   // Keeps track of a job that was just added/removed, and belongs to this pool.
   void AdjustNumOutstandingJobs(int offset) {
@@ skipping 43 matching lines @@
 
   // The requests which are waiting to be started for this pool.
   PendingRequestsQueue pending_requests_[NUM_PRIORITIES];
 };
 
 //-----------------------------------------------------------------------------
 
 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),
       next_job_id_(0),
       resolver_proc_(resolver_proc),
       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,
   // so we choose some defaults, which users can override later.
   job_pools_[POOL_NORMAL] = new JobPool(max_jobs, 100u * max_jobs);
 
 #if defined(OS_WIN)
   EnsureWinsockInit();
 #endif
 #if defined(OS_LINUX)
@@ skipping 19 matching lines @@
 
   // Delete the job pools.
   for (size_t i = 0u; i < arraysize(job_pools_); ++i)
     delete job_pools_[i];
 }
 
 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_)
     return ERR_UNEXPECTED;
 
   // 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;
   if (ParseIPLiteralToNumber(info.hostname(), &ip_number)) {
     DCHECK_EQ((info.host_resolver_flags() &
                ~(HOST_RESOLVER_CANONNAME | HOST_RESOLVER_LOOPBACK_ONLY)), 0)
         << " Unhandled flag";
     AddressList result(ip_number, info.port(),
                        (info.host_resolver_flags() & HOST_RESOLVER_CANONNAME));
 
     *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;
   }
 
   // Build a key that identifies the request in the cache and in the
   // outstanding jobs map.
   Key key = GetEffectiveKeyForRequest(info);
 
   // If we have an unexpired cache entry, use it.
   if (info.allow_cached_response() && cache_.get()) {
     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;
     }
   }
 
   // If no callback was specified, do a synchronous resolution.
   if (!callback) {
     AddressList addrlist;
     int os_error = 0;
     int error = ResolveAddrInfo(
         effective_resolver_proc(), key.hostname, key.address_family,
         key.host_resolver_flags, &addrlist, &os_error);
     if (error == OK) {
       addrlist.SetPort(info.port());
       *addresses = addrlist;
     }
 
     // Write to cache.
     if (cache_.get())
       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);
 
   // Next we need to attach our request to a "job". This job is responsible for
   // calling "getaddrinfo(hostname)" on a worker thread.
   scoped_refptr<Job> job;
 
   // If there is already an outstanding job to resolve |key|, use
   // it. This prevents starting concurrent resolves for the same hostname.
   job = FindOutstandingJob(key);
@@ skipping 30 matching lines @@
   scoped_ptr<Request> request_deleter;  // Frees at end of function.
 
   if (!req->job()) {
     // If the request was not attached to a job yet, it must have been
     // enqueued into a pool. Remove it from that pool's queue.
     // Otherwise if it was attached to a job, the job is responsible for
     // deleting it.
     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) {
   DCHECK(CalledOnValidThread());
   observers_.push_back(observer);
 }
 
 void HostResolverImpl::RemoveObserver(HostResolver::Observer* observer) {
   DCHECK(CalledOnValidThread());
   ObserversList::iterator it =
@@ skipping 85 matching lines @@
 
   // Try to start any queued requests now that a job-slot has freed up.
   ProcessQueuedRequests();
 
   // Complete all of the requests that were attached to the job.
   for (RequestsList::const_iterator it = job->requests().begin();
        it != job->requests().end(); ++it) {
     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);
 
       // Check if the job was cancelled as a result of running the callback.
       // (Meaning that |this| was deleted).
       if (job->was_cancelled())
         return;
     }
   }
 
   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();
          it != observers_.end(); ++it) {
       (*it)->OnStartResolution(request_id, info);
     }
   }
 }
 
-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.
   if (!observers_.empty()) {
     for (ObserversList::iterator it = observers_.begin();
          it != observers_.end(); ++it) {
       (*it)->OnFinishResolutionWithStatus(request_id, was_resolved, info);
     }
   }
 
-  // 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()) {
     for (ObserversList::iterator it = observers_.begin();
          it != observers_.end(); ++it) {
       (*it)->OnCancelResolution(request_id, info);
     }
   }
 
-  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() {
   if (cache_.get())
     cache_->clear();
   if (ipv6_probe_monitoring_) {
     DCHECK(!shutdown_);
     if (shutdown_)
       return;
     DiscardIPv6ProbeJob();
@@ skipping 76 matching lines @@
   AddressFamily effective_address_family = info.address_family();
   if (effective_address_family == ADDRESS_FAMILY_UNSPECIFIED)
     effective_address_family = default_address_family_;
   return Key(info.hostname(), effective_address_family,
              info.host_resolver_flags() | additional_resolver_flags_);
 }
 
 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();
 }
 
 int HostResolverImpl::EnqueueRequest(JobPool* pool, Request* req) {
   scoped_ptr<Request> req_evicted_from_queue(
       pool->InsertPendingRequest(req));
 
   // If the queue has become too large, we need to kick something out.
   if (req_evicted_from_queue.get()) {
     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;
 
     r->OnComplete(error, AddressList());
   }
 
   return ERR_IO_PENDING;
 }
 
 }  // namespace net