Add a histogram (Net.PacResultForStrippedUrl) that estimates how often PAC scripts depend on the UR…

net/proxy/proxy_resolver_v8_tracing.cc

 // 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 <map>
 #include <string>
 #include <utility>
 #include <vector>
 
+#include "base/auto_reset.h"
 #include "base/bind.h"
 #include "base/macros.h"
+#include "base/metrics/histogram_macros.h"
 #include "base/single_thread_task_runner.h"
 #include "base/strings/stringprintf.h"
 #include "base/synchronization/cancellation_flag.h"
 #include "base/synchronization/waitable_event.h"
 #include "base/thread_task_runner_handle.h"
 #include "base/threading/thread.h"
 #include "base/threading/thread_restrictions.h"
 #include "net/base/address_list.h"
 #include "net/base/net_errors.h"
 #include "net/base/network_interfaces.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"
+#include "url/url_canon.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.
@@ skipping 14 matching lines @@
 // 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;
 
+// Strips path information from the URL and replaces it with a
+// recognizable placeholder.
+// TODO(eroman): Remove when done gathering data for crbug.com/593759
+GURL StripUrlForBug593759(const GURL& url) {
+  GURL::Replacements replacements;
+  replacements.SetPathStr("PathIsHiddenForCrbug593759");
+  replacements.ClearQuery();
+  replacements.ClearRef();
+  return url.ReplaceComponents(replacements);
+}
+
+// TODO(eroman): Remove when done gathering data for crbug.com/593759
+void LogHistogramForBug593759(PacResultForStrippedUrl value) {
+  UMA_HISTOGRAM_ENUMERATION(
+      kHistogramPacResultForStrippedUrl, static_cast<int>(value),
+      static_cast<int>(PacResultForStrippedUrl::MAX_VALUE));
+}
+
 // The Job class is responsible for executing GetProxyForURL() and
 // creating ProxyResolverV8 instances, 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
@@ skipping 70 matching lines @@
   void NotifyCaller(int result);
   void NotifyCallerOnOriginLoop(int result);
 
   void Start(Operation op, bool blocking_dns,
              const CompletionCallback& callback);
 
   void ExecuteBlocking();
   void ExecuteNonBlocking();
   int ExecuteProxyResolver();
 
+  // TODO(eroman): Remove when done gathering data for crbug.com/593759
+  void LogMetricsForBug593759(int original_error);
+
   // Implementation of ProxyResolverv8::JSBindings
   bool ResolveDns(const std::string& host,
                   ResolveDnsOperation op,
                   std::string* output,
                   bool* terminate) override;
   void Alert(const base::string16& message) override;
   void OnError(int line_number, const base::string16& error) override;
 
   bool ResolveDnsBlocking(const std::string& host,
                           ResolveDnsOperation op,
@@ skipping 106 matching lines @@
   // 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_;
 
+  // TODO(eroman): Remove when done gathering data for crbug.com/593759
+  bool dont_start_dns_ = false;
+
   // ---------------------------------------------------------------------------
   // 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
@@ skipping 238 matching lines @@
 
   // 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();
 
+  // TODO(eroman): Remove when done gathering data for crbug.com/593759
+  LogMetricsForBug593759(result);
+
   if (should_restart_with_blocking_dns_) {
     DCHECK(!blocking_dns_);
     DCHECK(abandoned_);
     blocking_dns_ = true;
     ExecuteBlocking();
     return;
   }
 
   if (abandoned_)
     return;
@@ skipping 19 matching lines @@
           // request were to be cancelled from the origin thread, must guarantee
           // that |user_results_| is not accessed anymore.
           &results_, this);
       break;
     }
   }
 
   return result;
 }
 
+// Gathers data on how often PAC scripts execute differently depending
+// on the URL path and parameters.
+//
+// TODO(eroman): Remove when done gathering data for crbug.com/593759
+void Job::LogMetricsForBug593759(int original_error) {
+  CheckIsOnWorkerThread();
+
+  DCHECK(!blocking_dns_);
+
+  if (operation_ != GET_PROXY_FOR_URL || !url_.SchemeIsCryptographic()) {
+    // Only interested in FindProxyForURL() invocations for cryptographic URL
+    // schemes (https:// and wss://).
+    return;
+  }
+
+  if (should_restart_with_blocking_dns_) {
+    // The current instrumentation is limited to non-blocking DNS mode, for
+    // simplicity. Fallback to blocking mode is possible for unusual PAC
+    // scripts (non-deterministic, or relies on global state).
+    LogHistogramForBug593759(
+        PacResultForStrippedUrl::SKIPPED_FALLBACK_BLOCKING_DNS);
+    return;
+  }
+
+  if (abandoned_) {
+    // If the FindProxyForURL() attempt was abandoned, it was either cancelled
+    // or it encountered a missing DNS dependency. In the latter case the job
+    // will be re-started once the DNS has been resolved, so just wait until
+    // then.
+    return;
+  }
+
+  if (original_error != OK) {
+    // Only run the extra diagnostics for successful invocations of
+    // FindProxyForURL(). In other words, the instrumentation will
+    // not check whether the script succeeds when using a stripped
+    // path after having already failed on the original URL. A script error
+    // means the PAC script is already broken, so this would just skew the data.
+    return;
+  }
+
+  // Save some state variables to compare the original run against the new run
+  // using a stripped URL.
+  auto original_num_dns = num_dns_;
+  auto original_alerts_and_errors_byte_cost_ = alerts_and_errors_byte_cost_;
+  auto original_results = results_.ToPacString();
+
+  // Reset state variables used by ExecuteProxyResolver().
+  //
+  // This is a bit messy, but it keeps the diagnostics code local
+  // to LogMetricsForBug593759() without having to refactor the existing
+  // code.
+  //
+  // The intent is that after returning from this function all of the
+  // internal state is re-set to reflect the original completion of
+  // ExecuteProxyResolver(), not the second diagnostic one.
+  //
+  // Any global modifications made to the script state however are
+  // not undone, since creating a new script context just for this
+  // test would be expensive.
+  //
+  // Lastly, DNS resolution is disabled before calling
+  // ExecuteProxyResolver(), so only previously cached results can be
+  // used.
+  base::AutoReset<GURL> reset_url(&url_, StripUrlForBug593759(url_));
+  base::AutoReset<int> reset_num_dns(&num_dns_, 0);
+  base::AutoReset<std::vector<AlertOrError>> reset_alerts_and_errors(
+      &alerts_and_errors_, std::vector<AlertOrError>());
+  base::AutoReset<size_t> reset_alerts_and_errors_byte_cost(
+      &alerts_and_errors_byte_cost_, 0);
+  base::AutoReset<bool> reset_should_restart_with_blocking_dns(
+      &should_restart_with_blocking_dns_, false);
+  base::AutoReset<ProxyInfo> reset_results(&results_, ProxyInfo());
+  base::AutoReset<bool> reset_dont_start_dns(&dont_start_dns_, true);
+  base::AutoReset<bool> reset_abandoned(&abandoned_, false);
+
+  // Re-run FindProxyForURL().
+  auto result = ExecuteProxyResolver();
+
+  // Log the result of having run FindProxyForURL() with the modified
+  // URL to an UMA histogram.
+  if (should_restart_with_blocking_dns_) {
+    LogHistogramForBug593759(
+        PacResultForStrippedUrl::FAIL_FALLBACK_BLOCKING_DNS);
+  } else if (abandoned_) {
+    LogHistogramForBug593759(PacResultForStrippedUrl::FAIL_ABANDONED);
+  } else if (result != OK) {
+    LogHistogramForBug593759(PacResultForStrippedUrl::FAIL_ERROR);
+  } else if (original_results != results_.ToPacString()) {
+    LogHistogramForBug593759(
+        PacResultForStrippedUrl::FAIL_DIFFERENT_PROXY_LIST);
+  } else if (original_alerts_and_errors_byte_cost_ !=
+             alerts_and_errors_byte_cost_) {
+    // Here alerts_and_errors_byte_cost_ is being used as a cheap (albeit
+    // imprecise) fingerprint for the calls that were made to alert().
+    LogHistogramForBug593759(PacResultForStrippedUrl::SUCCESS_DIFFERENT_ALERTS);
+  } else if (original_num_dns != num_dns_) {
+    LogHistogramForBug593759(
+        PacResultForStrippedUrl::SUCCESS_DIFFERENT_NUM_DNS);
+  } else {
+    LogHistogramForBug593759(PacResultForStrippedUrl::SUCCESS);
+  }
+}
+
 bool 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()) {
@@ skipping 54 matching lines @@
 
   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;
   }
 
+  // TODO(eroman): Remove when done gathering data for crbug.com/593759
+  if (dont_start_dns_) {
+    abandoned_ = true;
+    return false;
+  }
+
   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;
@@ skipping 433 matching lines @@
 }
 
 }  // namespace
 
 // static
 scoped_ptr<ProxyResolverV8TracingFactory>
 ProxyResolverV8TracingFactory::Create() {
   return make_scoped_ptr(new ProxyResolverV8TracingFactoryImpl());
 }
 
+const char kHistogramPacResultForStrippedUrl[] = "Net.PacResultForStrippedUrl";
+
 }  // namespace net