root/net/proxy/proxy_resolver_v8_tracing.cc

/* [<][>][^][v][top][bottom][index][help] */

DEFINITIONS

This source file includes following definitions.
  1. NetLogErrorCallback
  2. IncrementWithoutOverflow
  3. metrics_num_errors_
  4. StartSetPacScript
  5. StartGetProxyForURL
  6. Cancel
  7. GetLoadState
  8. CheckIsOnWorkerThread
  9. CheckIsOnOriginThread
  10. SetCallback
  11. ReleaseCallback
  12. v8_resolver
  13. worker_loop
  14. host_resolver
  15. error_observer
  16. net_log
  17. NotifyCaller
  18. NotifyCallerOnOriginLoop
  19. RecordMetrics
  20. Start
  21. ExecuteBlocking
  22. ExecuteNonBlocking
  23. ExecuteProxyResolver
  24. ResolveDns
  25. Alert
  26. OnError
  27. ResolveDnsBlocking
  28. ResolveDnsNonBlocking
  29. PostDnsOperationAndWait
  30. DoDnsOperation
  31. OnDnsOperationComplete
  32. ScheduleRestartWithBlockingDns
  33. GetDnsFromLocalCache
  34. SaveDnsToLocalCache
  35. MakeDnsRequestInfo
  36. MakeDnsCacheKey
  37. HandleAlertOrError
  38. DispatchBufferedAlertsAndErrors
  39. DispatchAlertOrError
  40. LogEventToCurrentRequestAndGlobally
  41. num_outstanding_callbacks_
  42. GetProxyForURL
  43. CancelRequest
  44. GetLoadState
  45. CancelSetPacScript
  46. SetPacScript

// Copyright (c) 2013 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/proxy/proxy_resolver_v8_tracing.h"

#include "base/bind.h"
#include "base/message_loop/message_loop_proxy.h"
#include "base/metrics/histogram.h"
#include "base/strings/stringprintf.h"
#include "base/synchronization/cancellation_flag.h"
#include "base/synchronization/waitable_event.h"
#include "base/threading/thread.h"
#include "base/threading/thread_restrictions.h"
#include "base/values.h"
#include "net/base/address_list.h"
#include "net/base/net_errors.h"
#include "net/base/net_log.h"
#include "net/dns/host_resolver.h"
#include "net/proxy/proxy_info.h"
#include "net/proxy/proxy_resolver_error_observer.h"
#include "net/proxy/proxy_resolver_v8.h"

// The intent of this class is explained in the design document:
// https://docs.google.com/a/chromium.org/document/d/16Ij5OcVnR3s0MH4Z5XkhI9VTPoMJdaBn9rKreAmGOdE/edit
//
// In a nutshell, PAC scripts are Javascript programs and may depend on
// network I/O, by calling functions like dnsResolve().
//
// This is problematic since functions such as dnsResolve() will block the
// Javascript execution until the DNS result is availble, thereby stalling the
// PAC thread, which hurts the ability to process parallel proxy resolves.
// An obvious solution is to simply start more PAC threads, however this scales
// poorly, which hurts the ability to process parallel proxy resolves.
//
// The solution in ProxyResolverV8Tracing is to model PAC scripts as being
// deterministic, and depending only on the inputted URL. When the script
// issues a dnsResolve() for a yet unresolved hostname, the Javascript
// execution is "aborted", and then re-started once the DNS result is
// known.
namespace net {

namespace {

// Upper bound on how many *unique* DNS resolves a PAC script is allowed
// to make. This is a failsafe both for scripts that do a ridiculous
// number of DNS resolves, as well as scripts which are misbehaving
// under the tracing optimization. It is not expected to hit this normally.
const size_t kMaxUniqueResolveDnsPerExec = 20;

// Approximate number of bytes to use for buffering alerts() and errors.
// This is a failsafe in case repeated executions of the script causes
// too much memory bloat. It is not expected for well behaved scripts to
// hit this. (In fact normal scripts should not even have alerts() or errors).
const size_t kMaxAlertsAndErrorsBytes = 2048;

// Returns event parameters for a PAC error message (line number + message).
base::Value* NetLogErrorCallback(int line_number,
                                 const base::string16* message,
                                 NetLog::LogLevel /* log_level */) {
  base::DictionaryValue* dict = new base::DictionaryValue();
  dict->SetInteger("line_number", line_number);
  dict->SetString("message", *message);
  return dict;
}

void IncrementWithoutOverflow(uint8* x) {
  if (*x != 0xFF)
    *x += 1;
}

}  // namespace

// The Job class is responsible for executing GetProxyForURL() and
// SetPacScript(), since both of these operations share similar code.
//
// The DNS for these operations can operate in either blocking or
// non-blocking mode. Blocking mode is used as a fallback when the PAC script
// seems to be misbehaving under the tracing optimization.
//
// Note that this class runs on both the origin thread and a worker
// thread. Most methods are expected to be used exclusively on one thread
// or the other.
//
// The lifetime of Jobs does not exceed that of the ProxyResolverV8Tracing that
// spawned it. Destruction might happen on either the origin thread or the
// worker thread.
class ProxyResolverV8Tracing::Job
    : public base::RefCountedThreadSafe<ProxyResolverV8Tracing::Job>,
      public ProxyResolverV8::JSBindings {
 public:
  // |parent| is non-owned. It is the ProxyResolverV8Tracing that spawned this
  // Job, and must oulive it.
  explicit Job(ProxyResolverV8Tracing* parent);

  // Called from origin thread.
  void StartSetPacScript(
      const scoped_refptr<ProxyResolverScriptData>& script_data,
      const CompletionCallback& callback);

  // Called from origin thread.
  void StartGetProxyForURL(const GURL& url,
                           ProxyInfo* results,
                           const BoundNetLog& net_log,
                           const CompletionCallback& callback);

  // Called from origin thread.
  void Cancel();

  // Called from origin thread.
  LoadState GetLoadState() const;

 private:
  typedef std::map<std::string, std::string> DnsCache;
  friend class base::RefCountedThreadSafe<ProxyResolverV8Tracing::Job>;

  enum Operation {
    SET_PAC_SCRIPT,
    GET_PROXY_FOR_URL,
  };

  struct AlertOrError {
    bool is_alert;
    int line_number;
    base::string16 message;
  };

  virtual ~Job();

  void CheckIsOnWorkerThread() const;
  void CheckIsOnOriginThread() const;

  void SetCallback(const CompletionCallback& callback);
  void ReleaseCallback();

  ProxyResolverV8* v8_resolver();
  base::MessageLoop* worker_loop();
  HostResolver* host_resolver();
  ProxyResolverErrorObserver* error_observer();
  NetLog* net_log();

  // Invokes the user's callback.
  void NotifyCaller(int result);
  void NotifyCallerOnOriginLoop(int result);

  void RecordMetrics() const;

  void Start(Operation op, bool blocking_dns,
             const CompletionCallback& callback);

  void ExecuteBlocking();
  void ExecuteNonBlocking();
  int ExecuteProxyResolver();

  // Implementation of ProxyResolverv8::JSBindings
  virtual bool ResolveDns(const std::string& host,
                          ResolveDnsOperation op,
                          std::string* output,
                          bool* terminate) OVERRIDE;
  virtual void Alert(const base::string16& message) OVERRIDE;
  virtual void OnError(int line_number, const base::string16& error) OVERRIDE;

  bool ResolveDnsBlocking(const std::string& host,
                          ResolveDnsOperation op,
                          std::string* output);

  bool ResolveDnsNonBlocking(const std::string& host,
                             ResolveDnsOperation op,
                             std::string* output,
                             bool* terminate);

  bool PostDnsOperationAndWait(const std::string& host,
                               ResolveDnsOperation op,
                               bool* completed_synchronously)
                               WARN_UNUSED_RESULT;

  void DoDnsOperation();
  void OnDnsOperationComplete(int result);

  void ScheduleRestartWithBlockingDns();

  bool GetDnsFromLocalCache(const std::string& host, ResolveDnsOperation op,
                            std::string* output, bool* return_value);

  void SaveDnsToLocalCache(const std::string& host, ResolveDnsOperation op,
                           int net_error, const net::AddressList& addresses);

  // Builds a RequestInfo to service the specified PAC DNS operation.
  static HostResolver::RequestInfo MakeDnsRequestInfo(const std::string& host,
                                                      ResolveDnsOperation op);

  // Makes a key for looking up |host, op| in |dns_cache_|. Strings are used for
  // convenience, to avoid defining custom comparators.
  static std::string MakeDnsCacheKey(const std::string& host,
                                     ResolveDnsOperation op);

  void HandleAlertOrError(bool is_alert, int line_number,
                          const base::string16& message);
  void DispatchBufferedAlertsAndErrors();
  void DispatchAlertOrError(bool is_alert, int line_number,
                            const base::string16& message);

  void LogEventToCurrentRequestAndGlobally(
      NetLog::EventType type,
      const NetLog::ParametersCallback& parameters_callback);

  // The thread which called into ProxyResolverV8Tracing, and on which the
  // completion callback is expected to run.
  scoped_refptr<base::MessageLoopProxy> origin_loop_;

  // The ProxyResolverV8Tracing which spawned this Job.
  // Initialized on origin thread and then accessed from both threads.
  ProxyResolverV8Tracing* parent_;

  // The callback to run (on the origin thread) when the Job finishes.
  // Should only be accessed from origin thread.
  CompletionCallback callback_;

  // Flag to indicate whether the request has been cancelled.
  base::CancellationFlag cancelled_;

  // The operation that this Job is running.
  // Initialized on origin thread and then accessed from both threads.
  Operation operation_;

  // The DNS mode for this Job.
  // Initialized on origin thread, mutated on worker thread, and accessed
  // by both the origin thread and worker thread.
  bool blocking_dns_;

  // Used to block the worker thread on a DNS operation taking place on the
  // origin thread.
  base::WaitableEvent event_;

  // Map of DNS operations completed so far. Written into on the origin thread
  // and read on the worker thread.
  DnsCache dns_cache_;

  // The job holds a reference to itself to ensure that it remains alive until
  // either completion or cancellation.
  scoped_refptr<Job> owned_self_reference_;

  // -------------------------------------------------------
  // State specific to SET_PAC_SCRIPT.
  // -------------------------------------------------------

  scoped_refptr<ProxyResolverScriptData> script_data_;

  // -------------------------------------------------------
  // State specific to GET_PROXY_FOR_URL.
  // -------------------------------------------------------

  ProxyInfo* user_results_;  // Owned by caller, lives on origin thread.
  GURL url_;
  ProxyInfo results_;
  BoundNetLog bound_net_log_;

  // ---------------------------------------------------------------------------
  // State for ExecuteNonBlocking()
  // ---------------------------------------------------------------------------
  // These variables are used exclusively on the worker thread and are only
  // meaningful when executing inside of ExecuteNonBlocking().

  // Whether this execution was abandoned due to a missing DNS dependency.
  bool abandoned_;

  // Number of calls made to ResolveDns() by this execution.
  int num_dns_;

  // Sequence of calls made to Alert() or OnError() by this execution.
  std::vector<AlertOrError> alerts_and_errors_;
  size_t alerts_and_errors_byte_cost_;  // Approximate byte cost of the above.

  // Number of calls made to ResolveDns() by the PREVIOUS execution.
  int last_num_dns_;

  // Whether the current execution needs to be restarted in blocking mode.
  bool should_restart_with_blocking_dns_;

  // ---------------------------------------------------------------------------
  // State for pending DNS request.
  // ---------------------------------------------------------------------------

  // Handle to the outstanding request in the HostResolver, or NULL.
  // This is mutated and used on the origin thread, however it may be read by
  // the worker thread for some DCHECKS().
  HostResolver::RequestHandle pending_dns_;

  // Indicates if the outstanding DNS request completed synchronously. Written
  // on the origin thread, and read by the worker thread.
  bool pending_dns_completed_synchronously_;

  // These are the inputs to DoDnsOperation(). Written on the worker thread,
  // read by the origin thread.
  std::string pending_dns_host_;
  ResolveDnsOperation pending_dns_op_;

  // This contains the resolved address list that DoDnsOperation() fills in.
  // Used exclusively on the origin thread.
  AddressList pending_dns_addresses_;

  // ---------------------------------------------------------------------------
  // Metrics for histograms
  // ---------------------------------------------------------------------------
  // These values are used solely for logging histograms. They do not affect
  // the execution flow of requests.

  // The time when the proxy resolve request started. Used exclusively on the
  // origin thread.
  base::TimeTicks metrics_start_time_;

  // The time when the proxy resolve request completes on the worker thread.
  // Written on the worker thread, read on the origin thread.
  base::TimeTicks metrics_end_time_;

  // The time when PostDnsOperationAndWait() was called. Written on the worker
  // thread, read by the origin thread.
  base::TimeTicks metrics_pending_dns_start_;

  // The total amount of time that has been spent by the script waiting for
  // DNS dependencies. This includes the time spent posting the task to
  // the origin thread, up until the DNS result is found on the origin
  // thread. It does not include any time spent waiting in the message loop
  // for the worker thread, nor any time restarting or executing the
  // script. Used exclusively on the origin thread.
  base::TimeDelta metrics_dns_total_time_;

  // The following variables are initialized on the origin thread,
  // incremented on the worker thread, and then read upon completion on the
  // origin thread. The values are not expected to exceed the range of a uint8.
  // If they do, then they will be clamped to 0xFF.
  uint8 metrics_num_executions_;
  uint8 metrics_num_unique_dns_;
  uint8 metrics_num_alerts_;
  uint8 metrics_num_errors_;

  // The time that the latest execution took (time spent inside of
  // ExecuteProxyResolver(), which includes time spent in bindings too).
  // Written on the worker thread, read on the origin thread.
  base::TimeDelta metrics_execution_time_;

  // The cumulative time spent in ExecuteProxyResolver() that was ultimately
  // discarded work.
  // Written on the worker thread, read on the origin thread.
  base::TimeDelta metrics_abandoned_execution_total_time_;

  // The duration that the worker thread was blocked waiting on DNS results from
  // the origin thread, when operating in nonblocking mode.
  // Written on the worker thread, read on the origin thread.
  base::TimeDelta metrics_nonblocking_dns_wait_total_time_;
};

ProxyResolverV8Tracing::Job::Job(ProxyResolverV8Tracing* parent)
    : origin_loop_(base::MessageLoopProxy::current()),
      parent_(parent),
      event_(true, false),
      last_num_dns_(0),
      pending_dns_(NULL),
      metrics_num_executions_(0),
      metrics_num_unique_dns_(0),
      metrics_num_alerts_(0),
      metrics_num_errors_(0) {
  CheckIsOnOriginThread();
}

void ProxyResolverV8Tracing::Job::StartSetPacScript(
    const scoped_refptr<ProxyResolverScriptData>& script_data,
    const CompletionCallback& callback) {
  CheckIsOnOriginThread();

  script_data_ = script_data;

  // Script initialization uses blocking DNS since there isn't any
  // advantage to using non-blocking mode here. That is because the
  // parent ProxyService can't submit any ProxyResolve requests until
  // initialization has completed successfully!
  Start(SET_PAC_SCRIPT, true /*blocking*/, callback);
}

void ProxyResolverV8Tracing::Job::StartGetProxyForURL(
    const GURL& url,
    ProxyInfo* results,
    const BoundNetLog& net_log,
    const CompletionCallback& callback) {
  CheckIsOnOriginThread();

  url_ = url;
  user_results_ = results;
  bound_net_log_ = net_log;

  Start(GET_PROXY_FOR_URL, false /*non-blocking*/, callback);
}

void ProxyResolverV8Tracing::Job::Cancel() {
  CheckIsOnOriginThread();

  // There are several possibilities to consider for cancellation:
  // (a) The job has been posted to the worker thread, however script execution
  //     has not yet started.
  // (b) The script is executing on the worker thread.
  // (c) The script is executing on the worker thread, however is blocked inside
  //     of dnsResolve() waiting for a response from the origin thread.
  // (d) Nothing is running on the worker thread, however the host resolver has
  //     a pending DNS request which upon completion will restart the script
  //     execution.
  // (e) The worker thread has a pending task to restart execution, which was
  //     posted after the DNS dependency was resolved and saved to local cache.
  // (f) The script execution completed entirely, and posted a task to the
  //     origin thread to notify the caller.
  //
  // |cancelled_| is read on both the origin thread and worker thread. The
  // code that runs on the worker thread is littered with checks on
  // |cancelled_| to break out early.
  cancelled_.Set();

  ReleaseCallback();

  if (pending_dns_) {
    host_resolver()->CancelRequest(pending_dns_);
    pending_dns_ = NULL;
  }

  // The worker thread might be blocked waiting for DNS.
  event_.Signal();

  owned_self_reference_ = NULL;
}

LoadState ProxyResolverV8Tracing::Job::GetLoadState() const {
  CheckIsOnOriginThread();

  if (pending_dns_)
    return LOAD_STATE_RESOLVING_HOST_IN_PROXY_SCRIPT;

  return LOAD_STATE_RESOLVING_PROXY_FOR_URL;
}

ProxyResolverV8Tracing::Job::~Job() {
  DCHECK(!pending_dns_);
  DCHECK(callback_.is_null());
}

void ProxyResolverV8Tracing::Job::CheckIsOnWorkerThread() const {
  DCHECK_EQ(base::MessageLoop::current(), parent_->thread_->message_loop());
}

void ProxyResolverV8Tracing::Job::CheckIsOnOriginThread() const {
  DCHECK(origin_loop_->BelongsToCurrentThread());
}

void ProxyResolverV8Tracing::Job::SetCallback(
    const CompletionCallback& callback) {
  CheckIsOnOriginThread();
  DCHECK(callback_.is_null());
  parent_->num_outstanding_callbacks_++;
  callback_ = callback;
}

void ProxyResolverV8Tracing::Job::ReleaseCallback() {
  CheckIsOnOriginThread();
  DCHECK(!callback_.is_null());
  CHECK_GT(parent_->num_outstanding_callbacks_, 0);
  parent_->num_outstanding_callbacks_--;
  callback_.Reset();

  // For good measure, clear this other user-owned pointer.
  user_results_ = NULL;
}

ProxyResolverV8* ProxyResolverV8Tracing::Job::v8_resolver() {
  return parent_->v8_resolver_.get();
}

base::MessageLoop* ProxyResolverV8Tracing::Job::worker_loop() {
  return parent_->thread_->message_loop();
}

HostResolver* ProxyResolverV8Tracing::Job::host_resolver() {
  return parent_->host_resolver_;
}

ProxyResolverErrorObserver* ProxyResolverV8Tracing::Job::error_observer() {
  return parent_->error_observer_.get();
}

NetLog* ProxyResolverV8Tracing::Job::net_log() {
  return parent_->net_log_;
}

void ProxyResolverV8Tracing::Job::NotifyCaller(int result) {
  CheckIsOnWorkerThread();

  metrics_end_time_ = base::TimeTicks::Now();

  origin_loop_->PostTask(
      FROM_HERE,
      base::Bind(&Job::NotifyCallerOnOriginLoop, this, result));
}

void ProxyResolverV8Tracing::Job::NotifyCallerOnOriginLoop(int result) {
  CheckIsOnOriginThread();

  if (cancelled_.IsSet())
    return;

  DCHECK(!callback_.is_null());
  DCHECK(!pending_dns_);

  if (operation_ == GET_PROXY_FOR_URL) {
    RecordMetrics();
    *user_results_ = results_;
  }

  // There is only ever 1 outstanding SET_PAC_SCRIPT job. It needs to be
  // tracked to support cancellation.
  if (operation_ == SET_PAC_SCRIPT) {
    DCHECK_EQ(parent_->set_pac_script_job_.get(), this);
    parent_->set_pac_script_job_ = NULL;
  }

  CompletionCallback callback = callback_;
  ReleaseCallback();
  callback.Run(result);

  owned_self_reference_ = NULL;
}

void ProxyResolverV8Tracing::Job::RecordMetrics() const {
  CheckIsOnOriginThread();
  DCHECK_EQ(GET_PROXY_FOR_URL, operation_);

  base::TimeTicks now = base::TimeTicks::Now();

  // Metrics are output for each completed request to GetProxyForURL()).
  //
  // Note that a different set of histograms is used to record the metrics for
  // requests that completed in non-blocking mode versus blocking mode. The
  // expectation is for requests to complete in non-blocking mode each time.
  // If they don't then something strange is happening, and the purpose of the
  // seprate statistics is to better understand that trend.
#define UPDATE_HISTOGRAMS(base_name) \
  do {\
  UMA_HISTOGRAM_MEDIUM_TIMES(base_name "TotalTime", now - metrics_start_time_);\
  UMA_HISTOGRAM_MEDIUM_TIMES(base_name "TotalTimeWorkerThread",\
                             metrics_end_time_ - metrics_start_time_);\
  UMA_HISTOGRAM_TIMES(base_name "OriginThreadLatency",\
                      now - metrics_end_time_);\
  UMA_HISTOGRAM_MEDIUM_TIMES(base_name "TotalTimeDNS",\
                             metrics_dns_total_time_);\
  UMA_HISTOGRAM_MEDIUM_TIMES(base_name "ExecutionTime",\
                             metrics_execution_time_);\
  UMA_HISTOGRAM_MEDIUM_TIMES(base_name "AbandonedExecutionTotalTime",\
                             metrics_abandoned_execution_total_time_);\
  UMA_HISTOGRAM_MEDIUM_TIMES(base_name "DnsWaitTotalTime",\
                             metrics_nonblocking_dns_wait_total_time_);\
  UMA_HISTOGRAM_CUSTOM_COUNTS(\
      base_name "NumRestarts", metrics_num_executions_ - 1,\
      1, kMaxUniqueResolveDnsPerExec, kMaxUniqueResolveDnsPerExec);\
  UMA_HISTOGRAM_CUSTOM_COUNTS(\
      base_name "UniqueDNS", metrics_num_unique_dns_,\
      1, kMaxUniqueResolveDnsPerExec, kMaxUniqueResolveDnsPerExec);\
  UMA_HISTOGRAM_COUNTS_100(base_name "NumAlerts", metrics_num_alerts_);\
  UMA_HISTOGRAM_CUSTOM_COUNTS(\
      base_name "NumErrors", metrics_num_errors_, 1, 10, 10);\
  } while (false)

  if (!blocking_dns_)
    UPDATE_HISTOGRAMS("Net.ProxyResolver.");
  else
    UPDATE_HISTOGRAMS("Net.ProxyResolver.BlockingDNSMode.");

#undef UPDATE_HISTOGRAMS

  // Histograms to better understand http://crbug.com/240536 -- long
  // URLs can cause a significant slowdown in PAC execution. Figure out how
  // severe this is in the wild.
  if (!blocking_dns_) {
    size_t url_size = url_.spec().size();

    UMA_HISTOGRAM_CUSTOM_COUNTS(
        "Net.ProxyResolver.URLSize", url_size, 1, 200000, 50);

    if (url_size > 2048) {
      UMA_HISTOGRAM_MEDIUM_TIMES("Net.ProxyResolver.ExecutionTime_UrlOver2K",
                                 metrics_execution_time_);
    }

    if (url_size > 4096) {
      UMA_HISTOGRAM_MEDIUM_TIMES("Net.ProxyResolver.ExecutionTime_UrlOver4K",
                                 metrics_execution_time_);
    }

    if (url_size > 8192) {
      UMA_HISTOGRAM_MEDIUM_TIMES("Net.ProxyResolver.ExecutionTime_UrlOver8K",
                                 metrics_execution_time_);
    }

    if (url_size > 131072) {
      UMA_HISTOGRAM_MEDIUM_TIMES("Net.ProxyResolver.ExecutionTime_UrlOver128K",
                                 metrics_execution_time_);
    }
  }
}


void ProxyResolverV8Tracing::Job::Start(Operation op, bool blocking_dns,
                                        const CompletionCallback& callback) {
  CheckIsOnOriginThread();

  metrics_start_time_ = base::TimeTicks::Now();
  operation_ = op;
  blocking_dns_ = blocking_dns;
  SetCallback(callback);

  owned_self_reference_ = this;

  worker_loop()->PostTask(FROM_HERE,
      blocking_dns_ ? base::Bind(&Job::ExecuteBlocking, this) :
                      base::Bind(&Job::ExecuteNonBlocking, this));
}

void ProxyResolverV8Tracing::Job::ExecuteBlocking() {
  CheckIsOnWorkerThread();
  DCHECK(blocking_dns_);

  if (cancelled_.IsSet())
    return;

  NotifyCaller(ExecuteProxyResolver());
}

void ProxyResolverV8Tracing::Job::ExecuteNonBlocking() {
  CheckIsOnWorkerThread();
  DCHECK(!blocking_dns_);

  if (cancelled_.IsSet())
    return;

  // Reset state for the current execution.
  abandoned_ = false;
  num_dns_ = 0;
  alerts_and_errors_.clear();
  alerts_and_errors_byte_cost_ = 0;
  should_restart_with_blocking_dns_ = false;

  int result = ExecuteProxyResolver();

  if (abandoned_)
    metrics_abandoned_execution_total_time_ += metrics_execution_time_;

  if (should_restart_with_blocking_dns_) {
    DCHECK(!blocking_dns_);
    DCHECK(abandoned_);
    blocking_dns_ = true;
    ExecuteBlocking();
    return;
  }

  if (abandoned_)
    return;

  DispatchBufferedAlertsAndErrors();
  NotifyCaller(result);
}

int ProxyResolverV8Tracing::Job::ExecuteProxyResolver() {
  IncrementWithoutOverflow(&metrics_num_executions_);

  base::TimeTicks start = base::TimeTicks::Now();

  JSBindings* prev_bindings = v8_resolver()->js_bindings();
  v8_resolver()->set_js_bindings(this);

  int result = ERR_UNEXPECTED;  // Initialized to silence warnings.

  switch (operation_) {
    case SET_PAC_SCRIPT:
      result = v8_resolver()->SetPacScript(
          script_data_, CompletionCallback());
      break;
    case GET_PROXY_FOR_URL:
      result = v8_resolver()->GetProxyForURL(
        url_,
        // Important: Do not write directly into |user_results_|, since if the
        // request were to be cancelled from the origin thread, must guarantee
        // that |user_results_| is not accessed anymore.
        &results_,
        CompletionCallback(),
        NULL,
        bound_net_log_);
      break;
  }

  v8_resolver()->set_js_bindings(prev_bindings);

  metrics_execution_time_ = base::TimeTicks::Now() - start;

  return result;
}

bool ProxyResolverV8Tracing::Job::ResolveDns(const std::string& host,
                                             ResolveDnsOperation op,
                                             std::string* output,
                                             bool* terminate) {
  if (cancelled_.IsSet()) {
    *terminate = true;
    return false;
  }

  if ((op == DNS_RESOLVE || op == DNS_RESOLVE_EX) && host.empty()) {
    // a DNS resolve with an empty hostname is considered an error.
    return false;
  }

  return blocking_dns_ ?
      ResolveDnsBlocking(host, op, output) :
      ResolveDnsNonBlocking(host, op, output, terminate);
}

void ProxyResolverV8Tracing::Job::Alert(const base::string16& message) {
  HandleAlertOrError(true, -1, message);
}

void ProxyResolverV8Tracing::Job::OnError(int line_number,
                                          const base::string16& error) {
  HandleAlertOrError(false, line_number, error);
}

bool ProxyResolverV8Tracing::Job::ResolveDnsBlocking(const std::string& host,
                                                     ResolveDnsOperation op,
                                                     std::string* output) {
  CheckIsOnWorkerThread();

  // Check if the DNS result for this host has already been cached.
  bool rv;
  if (GetDnsFromLocalCache(host, op, output, &rv)) {
    // Yay, cache hit!
    return rv;
  }

  // If the host was not in the local cache, this is a new hostname.
  IncrementWithoutOverflow(&metrics_num_unique_dns_);

  if (dns_cache_.size() >= kMaxUniqueResolveDnsPerExec) {
    // Safety net for scripts with unexpectedly many DNS calls.
    // We will continue running to completion, but will fail every
    // subsequent DNS request.
    return false;
  }

  if (!PostDnsOperationAndWait(host, op, NULL))
    return false;  // Was cancelled.

  CHECK(GetDnsFromLocalCache(host, op, output, &rv));
  return rv;
}

bool ProxyResolverV8Tracing::Job::ResolveDnsNonBlocking(const std::string& host,
                                                        ResolveDnsOperation op,
                                                        std::string* output,
                                                        bool* terminate) {
  CheckIsOnWorkerThread();

  if (abandoned_) {
    // If this execution was already abandoned can fail right away. Only 1 DNS
    // dependency will be traced at a time (for more predictable outcomes).
    return false;
  }

  num_dns_ += 1;

  // Check if the DNS result for this host has already been cached.
  bool rv;
  if (GetDnsFromLocalCache(host, op, output, &rv)) {
    // Yay, cache hit!
    return rv;
  }

  // If the host was not in the local cache, then this is a new hostname.
  IncrementWithoutOverflow(&metrics_num_unique_dns_);

  if (num_dns_ <= last_num_dns_) {
    // The sequence of DNS operations is different from last time!
    ScheduleRestartWithBlockingDns();
    *terminate = true;
    return false;
  }

  if (dns_cache_.size() >= kMaxUniqueResolveDnsPerExec) {
    // Safety net for scripts with unexpectedly many DNS calls.
    return false;
  }

  DCHECK(!should_restart_with_blocking_dns_);

  bool completed_synchronously;
  if (!PostDnsOperationAndWait(host, op, &completed_synchronously))
    return false;  // Was cancelled.

  if (completed_synchronously) {
    CHECK(GetDnsFromLocalCache(host, op, output, &rv));
    return rv;
  }

  // Otherwise if the result was not in the cache, then a DNS request has
  // been started. Abandon this invocation of FindProxyForURL(), it will be
  // restarted once the DNS request completes.
  abandoned_ = true;
  *terminate = true;
  last_num_dns_ = num_dns_;
  return false;
}

bool ProxyResolverV8Tracing::Job::PostDnsOperationAndWait(
    const std::string& host, ResolveDnsOperation op,
    bool* completed_synchronously) {

  base::TimeTicks start = base::TimeTicks::Now();

  // Post the DNS request to the origin thread.
  DCHECK(!pending_dns_);
  metrics_pending_dns_start_ = base::TimeTicks::Now();
  pending_dns_host_ = host;
  pending_dns_op_ = op;
  origin_loop_->PostTask(FROM_HERE, base::Bind(&Job::DoDnsOperation, this));

  event_.Wait();
  event_.Reset();

  if (cancelled_.IsSet())
    return false;

  if (completed_synchronously)
    *completed_synchronously = pending_dns_completed_synchronously_;

  if (!blocking_dns_)
    metrics_nonblocking_dns_wait_total_time_ += base::TimeTicks::Now() - start;

  return true;
}

void ProxyResolverV8Tracing::Job::DoDnsOperation() {
  CheckIsOnOriginThread();
  DCHECK(!pending_dns_);

  if (cancelled_.IsSet())
    return;

  HostResolver::RequestHandle dns_request = NULL;
  int result = host_resolver()->Resolve(
      MakeDnsRequestInfo(pending_dns_host_, pending_dns_op_),
      DEFAULT_PRIORITY,
      &pending_dns_addresses_,
      base::Bind(&Job::OnDnsOperationComplete, this),
      &dns_request,
      bound_net_log_);

  pending_dns_completed_synchronously_ = result != ERR_IO_PENDING;

  // Check if the request was cancelled as a side-effect of calling into the
  // HostResolver. This isn't the ordinary execution flow, however it is
  // exercised by unit-tests.
  if (cancelled_.IsSet()) {
    if (!pending_dns_completed_synchronously_)
      host_resolver()->CancelRequest(dns_request);
    return;
  }

  if (pending_dns_completed_synchronously_) {
    OnDnsOperationComplete(result);
  } else {
    DCHECK(dns_request);
    pending_dns_ = dns_request;
    // OnDnsOperationComplete() will be called by host resolver on completion.
  }

  if (!blocking_dns_) {
    // The worker thread always blocks waiting to see if the result can be
    // serviced from cache before restarting.
    event_.Signal();
  }
}

void ProxyResolverV8Tracing::Job::OnDnsOperationComplete(int result) {
  CheckIsOnOriginThread();

  DCHECK(!cancelled_.IsSet());
  DCHECK(pending_dns_completed_synchronously_ == (pending_dns_ == NULL));

  SaveDnsToLocalCache(pending_dns_host_, pending_dns_op_, result,
                      pending_dns_addresses_);
  pending_dns_ = NULL;

  metrics_dns_total_time_ +=
      base::TimeTicks::Now() - metrics_pending_dns_start_;

  if (blocking_dns_) {
    event_.Signal();
    return;
  }

  if (!blocking_dns_ && !pending_dns_completed_synchronously_) {
    // Restart. This time it should make more progress due to having
    // cached items.
    worker_loop()->PostTask(FROM_HERE,
                            base::Bind(&Job::ExecuteNonBlocking, this));
  }
}

void ProxyResolverV8Tracing::Job::ScheduleRestartWithBlockingDns() {
  CheckIsOnWorkerThread();

  DCHECK(!should_restart_with_blocking_dns_);
  DCHECK(!abandoned_);
  DCHECK(!blocking_dns_);

  abandoned_ = true;

  // The restart will happen after ExecuteNonBlocking() finishes.
  should_restart_with_blocking_dns_ = true;
}

bool ProxyResolverV8Tracing::Job::GetDnsFromLocalCache(
    const std::string& host,
    ResolveDnsOperation op,
    std::string* output,
    bool* return_value) {
  CheckIsOnWorkerThread();

  DnsCache::const_iterator it = dns_cache_.find(MakeDnsCacheKey(host, op));
  if (it == dns_cache_.end())
    return false;

  *output = it->second;
  *return_value = !it->second.empty();
  return true;
}

void ProxyResolverV8Tracing::Job::SaveDnsToLocalCache(
    const std::string& host,
    ResolveDnsOperation op,
    int net_error,
    const net::AddressList& addresses) {
  CheckIsOnOriginThread();

  // Serialize the result into a string to save to the cache.
  std::string cache_value;
  if (net_error != OK) {
    cache_value = std::string();
  } else if (op == DNS_RESOLVE || op == MY_IP_ADDRESS) {
    // dnsResolve() and myIpAddress() are expected to return a single IP
    // address.
    cache_value = addresses.front().ToStringWithoutPort();
  } else {
    // The *Ex versions are expected to return a semi-colon separated list.
    for (AddressList::const_iterator iter = addresses.begin();
         iter != addresses.end(); ++iter) {
      if (!cache_value.empty())
        cache_value += ";";
      cache_value += iter->ToStringWithoutPort();
    }
  }

  dns_cache_[MakeDnsCacheKey(host, op)] = cache_value;
}

// static
HostResolver::RequestInfo ProxyResolverV8Tracing::Job::MakeDnsRequestInfo(
    const std::string& host, ResolveDnsOperation op) {
  HostPortPair host_port = HostPortPair(host, 80);
  if (op == MY_IP_ADDRESS || op == MY_IP_ADDRESS_EX) {
    host_port.set_host(GetHostName());
  }

  HostResolver::RequestInfo info(host_port);

  // The non-ex flavors are limited to IPv4 results.
  if (op == MY_IP_ADDRESS || op == DNS_RESOLVE) {
    info.set_address_family(ADDRESS_FAMILY_IPV4);
  }

  return info;
}

std::string ProxyResolverV8Tracing::Job::MakeDnsCacheKey(
    const std::string& host, ResolveDnsOperation op) {
  return base::StringPrintf("%d:%s", op, host.c_str());
}

void ProxyResolverV8Tracing::Job::HandleAlertOrError(
    bool is_alert,
    int line_number,
    const base::string16& message) {
  CheckIsOnWorkerThread();

  if (cancelled_.IsSet())
    return;

  if (blocking_dns_) {
    // In blocking DNS mode the events can be dispatched immediately.
    DispatchAlertOrError(is_alert, line_number, message);
    return;
  }

  // Otherwise in nonblocking mode, buffer all the messages until
  // the end.

  if (abandoned_)
    return;

  alerts_and_errors_byte_cost_ += sizeof(AlertOrError) + message.size() * 2;

  // If there have been lots of messages, enqueing could be expensive on
  // memory. Consider a script which does megabytes worth of alerts().
  // Avoid this by falling back to blocking mode.
  if (alerts_and_errors_byte_cost_ > kMaxAlertsAndErrorsBytes) {
    ScheduleRestartWithBlockingDns();
    return;
  }

  AlertOrError entry = {is_alert, line_number, message};
  alerts_and_errors_.push_back(entry);
}

void ProxyResolverV8Tracing::Job::DispatchBufferedAlertsAndErrors() {
  CheckIsOnWorkerThread();
  DCHECK(!blocking_dns_);
  DCHECK(!abandoned_);

  for (size_t i = 0; i < alerts_and_errors_.size(); ++i) {
    const AlertOrError& x = alerts_and_errors_[i];
    DispatchAlertOrError(x.is_alert, x.line_number, x.message);
  }
}

void ProxyResolverV8Tracing::Job::DispatchAlertOrError(
    bool is_alert, int line_number, const base::string16& message) {
  CheckIsOnWorkerThread();

  // Note that the handling of cancellation is racy with regard to
  // alerts/errors. The request might get cancelled shortly after this
  // check! (There is no lock being held to guarantee otherwise).
  //
  // If this happens, then some information will get written to the NetLog
  // needlessly, however the NetLog will still be alive so it shouldn't cause
  // problems.
  if (cancelled_.IsSet())
    return;

  if (is_alert) {
    // -------------------
    // alert
    // -------------------
    IncrementWithoutOverflow(&metrics_num_alerts_);
    VLOG(1) << "PAC-alert: " << message;

    // Send to the NetLog.
    LogEventToCurrentRequestAndGlobally(
        NetLog::TYPE_PAC_JAVASCRIPT_ALERT,
        NetLog::StringCallback("message", &message));
  } else {
    // -------------------
    // error
    // -------------------
    IncrementWithoutOverflow(&metrics_num_errors_);
    if (line_number == -1)
      VLOG(1) << "PAC-error: " << message;
    else
      VLOG(1) << "PAC-error: " << "line: " << line_number << ": " << message;

    // Send the error to the NetLog.
    LogEventToCurrentRequestAndGlobally(
        NetLog::TYPE_PAC_JAVASCRIPT_ERROR,
        base::Bind(&NetLogErrorCallback, line_number, &message));

    if (error_observer())
      error_observer()->OnPACScriptError(line_number, message);
  }
}

void ProxyResolverV8Tracing::Job::LogEventToCurrentRequestAndGlobally(
    NetLog::EventType type,
    const NetLog::ParametersCallback& parameters_callback) {
  CheckIsOnWorkerThread();
  bound_net_log_.AddEvent(type, parameters_callback);

  // Emit to the global NetLog event stream.
  if (net_log())
    net_log()->AddGlobalEntry(type, parameters_callback);
}

ProxyResolverV8Tracing::ProxyResolverV8Tracing(
    HostResolver* host_resolver,
    ProxyResolverErrorObserver* error_observer,
    NetLog* net_log)
    : ProxyResolver(true /*expects_pac_bytes*/),
      host_resolver_(host_resolver),
      error_observer_(error_observer),
      net_log_(net_log),
      num_outstanding_callbacks_(0) {
  DCHECK(host_resolver);
  // Start up the thread.
  thread_.reset(new base::Thread("Proxy resolver"));
  CHECK(thread_->Start());

  v8_resolver_.reset(new ProxyResolverV8);
}

ProxyResolverV8Tracing::~ProxyResolverV8Tracing() {
  // Note, all requests should have been cancelled.
  CHECK(!set_pac_script_job_.get());
  CHECK_EQ(0, num_outstanding_callbacks_);

  // Join the worker thread. See http://crbug.com/69710. Note that we call
  // Stop() here instead of simply clearing thread_ since there may be pending
  // callbacks on the worker thread which want to dereference thread_.
  base::ThreadRestrictions::ScopedAllowIO allow_io;
  thread_->Stop();
}

int ProxyResolverV8Tracing::GetProxyForURL(const GURL& url,
                                           ProxyInfo* results,
                                           const CompletionCallback& callback,
                                           RequestHandle* request,
                                           const BoundNetLog& net_log) {
  DCHECK(CalledOnValidThread());
  DCHECK(!callback.is_null());
  DCHECK(!set_pac_script_job_.get());

  scoped_refptr<Job> job = new Job(this);

  if (request)
    *request = job.get();

  job->StartGetProxyForURL(url, results, net_log, callback);
  return ERR_IO_PENDING;
}

void ProxyResolverV8Tracing::CancelRequest(RequestHandle request) {
  Job* job = reinterpret_cast<Job*>(request);
  job->Cancel();
}

LoadState ProxyResolverV8Tracing::GetLoadState(RequestHandle request) const {
  Job* job = reinterpret_cast<Job*>(request);
  return job->GetLoadState();
}

void ProxyResolverV8Tracing::CancelSetPacScript() {
  DCHECK(set_pac_script_job_.get());
  set_pac_script_job_->Cancel();
  set_pac_script_job_ = NULL;
}

int ProxyResolverV8Tracing::SetPacScript(
    const scoped_refptr<ProxyResolverScriptData>& script_data,
    const CompletionCallback& callback) {
  DCHECK(CalledOnValidThread());
  DCHECK(!callback.is_null());

  // Note that there should not be any outstanding (non-cancelled) Jobs when
  // setting the PAC script (ProxyService should guarantee this). If there are,
  // then they might complete in strange ways after the new script is set.
  DCHECK(!set_pac_script_job_.get());
  CHECK_EQ(0, num_outstanding_callbacks_);

  set_pac_script_job_ = new Job(this);
  set_pac_script_job_->StartSetPacScript(script_data, callback);

  return ERR_IO_PENDING;
}

}  // namespace net

/* [<][>][^][v][top][bottom][index][help] */