Only mark a proxy as bad if we have confirmation that another proxy succeeded for the same request.

BUG=87336
TEST=net_unittests --gtest_filter=ProxyServiceTest.ProxyFallback:HttpStreamFactoryTest.JobNotifiesProxy


Review URL: http://codereview.chromium.org/7532011

git-svn-id: svn://svn.chromium.org/chrome/trunk/src@98643 0039d316-1c4b-4281-b951-d872f2087c98

jingle/notifier/base/proxy_resolving_client_socket.cc

@@ -190,6 +190,8 @@ void ProxyResolvingClientSocket::ProcessConnectDone(int status) {
       // Proxy reconsideration pending. Return.
       return;
     CloseTransportSocket();
+  } else {
+    ReportSuccessfulProxyConnection();
   }
   RunUserConnectCallback(status);
 }
@@ -274,6 +276,10 @@ int ProxyResolvingClientSocket::ReconsiderProxyAfterError(int error) {
   return rv;
 }
 
+void ProxyResolvingClientSocket::ReportSuccessfulProxyConnection() {
+  network_session_->proxy_service()->ReportSuccess(proxy_info_);
+}
+
 void ProxyResolvingClientSocket::Disconnect() {
   CloseTransportSocket();
   if (pac_request_)

jingle/notifier/base/proxy_resolving_client_socket.h

@@ -67,6 +67,7 @@ class ProxyResolvingClientSocket : public net::StreamSocket {
   void CloseTransportSocket();
   void RunUserConnectCallback(int status);
   int ReconsiderProxyAfterError(int error);
+  void ReportSuccessfulProxyConnection();
 
   // Callbacks passed to net APIs.
   net::CompletionCallbackImpl<ProxyResolvingClientSocket>

net/base/net_log_event_type_list.h

@@ -220,6 +220,28 @@ EVENT_TYPE(PROXY_SERVICE_RESOLVED_PROXY_LIST)
 // proxy settings (since there wasn't a previous value).
 EVENT_TYPE(PROXY_CONFIG_CHANGED)
 
+// Emitted when a list of bad proxies is reported to the proxy service.
+//
+// Parameters:
+//   {
+//     "bad_proxy_list": <List of bad proxies>,
+//   }
+EVENT_TYPE(BAD_PROXY_LIST_REPORTED)
+
+// ------------------------------------------------------------------------
+// ProxyList
+// ------------------------------------------------------------------------
+
+// Emitted when the first proxy server in a list is being marked as
+// bad and proxy resolution is going to failover to the next one in
+// the list.  The fallback is local to the request.
+//
+// Parameters:
+//   {
+//     "bad_proxy": <URI representation of the failed proxy server>,
+//   }
+EVENT_TYPE(PROXY_LIST_FALLBACK)
+
 // ------------------------------------------------------------------------
 // Proxy Resolver
 // ------------------------------------------------------------------------

net/http/http_stream_factory_impl_job.cc

@@ -836,6 +836,7 @@ int HttpStreamFactoryImpl::Job::DoCreateStreamComplete(int result) {
   if (result < 0)
     return result;
 
+  session_->proxy_service()->ReportSuccess(proxy_info_);
   next_state_ = STATE_NONE;
   return OK;
 }

net/http/http_stream_factory_impl_unittest.cc

@@ -16,6 +16,7 @@
 #include "net/http/http_network_session.h"
 #include "net/http/http_network_session_peer.h"
 #include "net/http/http_request_info.h"
+#include "net/http/http_stream.h"
 #include "net/proxy/proxy_info.h"
 #include "net/proxy/proxy_service.h"
 #include "net/socket/socket_test_util.h"
@@ -55,6 +56,62 @@ class MockHttpStreamFactoryImpl : public HttpStreamFactoryImpl {
   bool waiting_for_preconnect_;
 };
 
+class StreamRequestWaiter : public HttpStreamRequest::Delegate {
+ public:
+  StreamRequestWaiter()
+      : waiting_for_stream_(false),
+        stream_done_(false) {}
+
+  // HttpStreamRequest::Delegate
+
+  virtual void OnStreamReady(
+      const SSLConfig& used_ssl_config,
+      const ProxyInfo& used_proxy_info,
+      HttpStream* stream) OVERRIDE {
+    stream_done_ = true;
+    if (waiting_for_stream_)
+      MessageLoop::current()->Quit();
+    stream_.reset(stream);
+  }
+
+  virtual void OnStreamFailed(
+      int status,
+      const SSLConfig& used_ssl_config) OVERRIDE {}
+
+  virtual void OnCertificateError(
+      int status,
+      const SSLConfig& used_ssl_config,
+      const SSLInfo& ssl_info) OVERRIDE {}
+
+  virtual void OnNeedsProxyAuth(const HttpResponseInfo& proxy_response,
+                                const SSLConfig& used_ssl_config,
+                                const ProxyInfo& used_proxy_info,
+                                HttpAuthController* auth_controller) OVERRIDE {}
+
+  virtual void OnNeedsClientAuth(const SSLConfig& used_ssl_config,
+                                 SSLCertRequestInfo* cert_info) OVERRIDE {}
+
+  virtual void OnHttpsProxyTunnelResponse(const HttpResponseInfo& response_info,
+                                          const SSLConfig& used_ssl_config,
+                                          const ProxyInfo& used_proxy_info,
+                                          HttpStream* stream) OVERRIDE {}
+
+  void WaitForStream() {
+    while (!stream_done_) {
+      waiting_for_stream_ = true;
+      MessageLoop::current()->Run();
+      waiting_for_stream_ = false;
+    }
+  }
+
+ private:
+  bool waiting_for_stream_;
+  bool stream_done_;
+  scoped_ptr<HttpStream> stream_;
+
+  DISALLOW_COPY_AND_ASSIGN(StreamRequestWaiter);
+};
+
 struct SessionDependencies {
   // Custom proxy service dependency.
   explicit SessionDependencies(ProxyService* proxy_service)
@@ -315,6 +372,48 @@ TEST(HttpStreamFactoryTest, PreconnectDirectWithExistingSpdySession) {
   }
 }
 
+TEST(HttpStreamFactoryTest, JobNotifiesProxy) {
+  const char* kProxyString = "PROXY bad:99; PROXY maybe:80; DIRECT";
+  SessionDependencies session_deps(
+      ProxyService::CreateFixedFromPacResult(kProxyString));
+
+  // First connection attempt fails
+  StaticSocketDataProvider socket_data1;
+  socket_data1.set_connect_data(MockConnect(true, ERR_ADDRESS_UNREACHABLE));
+  session_deps.socket_factory.AddSocketDataProvider(&socket_data1);
+
+  // Second connection attempt succeeds
+  StaticSocketDataProvider socket_data2;
+  socket_data2.set_connect_data(MockConnect(true, OK));
+  session_deps.socket_factory.AddSocketDataProvider(&socket_data2);
+
+  CapturingBoundNetLog log(CapturingNetLog::kUnbounded);
+  EXPECT_TRUE(log.bound().IsLoggingAllEvents());
+
+  scoped_refptr<HttpNetworkSession> session(CreateSession(&session_deps));
+
+  // Now request a stream.  It should succeed using the second proxy in the
+  // list.
+  HttpRequestInfo request_info;
+  request_info.method = "GET";
+  request_info.url = GURL("http://www.google.com");
+  request_info.load_flags = 0;
+
+  SSLConfig ssl_config;
+  StreamRequestWaiter waiter;
+  scoped_ptr<HttpStreamRequest> request(
+      session->http_stream_factory()->RequestStream(request_info, ssl_config,
+                                                    &waiter, log.bound()));
+  waiter.WaitForStream();
+
+  // The proxy that failed should now be known to the proxy_service as bad.
+  const ProxyRetryInfoMap& retry_info =
+      session->proxy_service()->proxy_retry_info();
+  EXPECT_EQ(1u, retry_info.size());
+  ProxyRetryInfoMap::const_iterator iter = retry_info.find("bad:99");
+  EXPECT_TRUE(iter != retry_info.end());
+}
+
 }  // namespace
 
 }  // namespace net

net/proxy/proxy_info.cc

-// Copyright (c) 2006-2008 The Chromium Authors. All rights reserved.
+// Copyright (c) 2011 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.
 
@@ -16,26 +16,30 @@ ProxyInfo::~ProxyInfo() {
 
 void ProxyInfo::Use(const ProxyInfo& other) {
   proxy_list_ = other.proxy_list_;
+  proxy_retry_info_ = other.proxy_retry_info_;
 }
 
 void ProxyInfo::UseDirect() {
   proxy_list_.SetSingleProxyServer(ProxyServer::Direct());
+  proxy_retry_info_.clear();
 }
 
 void ProxyInfo::UseNamedProxy(const std::string& proxy_uri_list) {
   proxy_list_.Set(proxy_uri_list);
+  proxy_retry_info_.clear();
 }
 
 void ProxyInfo::UseProxyServer(const ProxyServer& proxy_server) {
   proxy_list_.SetSingleProxyServer(proxy_server);
+  proxy_retry_info_.clear();
 }
 
 std::string ProxyInfo::ToPacString() const {
   return proxy_list_.ToPacString();
 }
 
-bool ProxyInfo::Fallback(ProxyRetryInfoMap* proxy_retry_info) {
-  return proxy_list_.Fallback(proxy_retry_info);
+bool ProxyInfo::Fallback(const BoundNetLog& net_log) {
+  return proxy_list_.Fallback(&proxy_retry_info_, net_log);
 }
 
 void ProxyInfo::DeprioritizeBadProxies(

net/proxy/proxy_info.h

@@ -9,6 +9,7 @@
 #include <string>
 
 #include "net/base/net_export.h"
+#include "net/base/net_log.h"
 #include "net/proxy/proxy_config.h"
 #include "net/proxy/proxy_list.h"
 #include "net/proxy/proxy_retry_info.h"
@@ -86,7 +87,7 @@ class NET_EXPORT ProxyInfo {
 
   // Marks the current proxy as bad. Returns true if there is another proxy
   // available to try in proxy list_.
-  bool Fallback(ProxyRetryInfoMap* proxy_retry_info);
+  bool Fallback(const BoundNetLog& net_log);
 
   // De-prioritizes the proxies that we have cached as not working, by moving
   // them to the end of the proxy list.
@@ -98,10 +99,17 @@ class NET_EXPORT ProxyInfo {
  private:
   friend class ProxyService;
 
+  const ProxyRetryInfoMap& proxy_retry_info() const {
+    return proxy_retry_info_;
+  }
+
   // The ordered list of proxy servers (including DIRECT attempts) remaining to
   // try. If proxy_list_ is empty, then there is nothing left to fall back to.
   ProxyList proxy_list_;
 
+  // List of proxies that have been tried already.
+  ProxyRetryInfoMap proxy_retry_info_;
+
   // This value identifies the proxy config used to initialize this object.
   ProxyConfig::ID config_id_;
 };

net/proxy/proxy_list.cc

-// Copyright (c) 2006-2008 The Chromium Authors. All rights reserved.
+// Copyright (c) 2011 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.
 
@@ -115,7 +115,8 @@ std::string ProxyList::ToPacString() const {
   return proxy_list.empty() ? std::string() : proxy_list;
 }
 
-bool ProxyList::Fallback(ProxyRetryInfoMap* proxy_retry_info) {
+bool ProxyList::Fallback(ProxyRetryInfoMap* proxy_retry_info,
+                         const BoundNetLog& net_log) {
   // Number of minutes to wait before retrying a bad proxy server.
   const TimeDelta kProxyRetryDelay = TimeDelta::FromMinutes(5);
 
@@ -152,6 +153,9 @@ bool ProxyList::Fallback(ProxyRetryInfoMap* proxy_retry_info) {
       retry_info.bad_until = TimeTicks().Now() + retry_info.current_delay;
       (*proxy_retry_info)[key] = retry_info;
     }
+    net_log.AddEvent(
+        NetLog::TYPE_PROXY_LIST_FALLBACK,
+        make_scoped_refptr(new NetLogStringParameter("bad_proxy", key)));
   }
 
   // Remove this proxy from our list.

net/proxy/proxy_list.h

@@ -10,6 +10,7 @@
 #include <vector>
 
 #include "net/base/net_export.h"
+#include "net/base/net_log.h"
 #include "net/proxy/proxy_retry_info.h"
 
 namespace net {
@@ -61,7 +62,8 @@ class NET_EXPORT_PRIVATE ProxyList {
   // Marks the current proxy server as bad and deletes it from the list.  The
   // list of known bad proxies is given by proxy_retry_info.  Returns true if
   // there is another server available in the list.
-  bool Fallback(ProxyRetryInfoMap* proxy_retry_info);
+  bool Fallback(ProxyRetryInfoMap* proxy_retry_info,
+                const BoundNetLog& net_log);
 
  private:
   // List of proxies.

net/proxy/proxy_service.cc

@@ -264,6 +264,31 @@ class ProxyConfigChangedNetLogParam : public NetLog::EventParameters {
   DISALLOW_COPY_AND_ASSIGN(ProxyConfigChangedNetLogParam);
 };
 
+class BadProxyListNetLogParam : public NetLog::EventParameters {
+ public:
+  BadProxyListNetLogParam(const ProxyRetryInfoMap& retry_info) {
+    proxy_list_.reserve(retry_info.size());
+    for (ProxyRetryInfoMap::const_iterator iter = retry_info.begin();
+         iter != retry_info.end(); ++iter) {
+      proxy_list_.push_back(iter->first);
+    }
+  }
+
+  virtual Value* ToValue() const OVERRIDE {
+    DictionaryValue* dict = new DictionaryValue();
+    ListValue* list = new ListValue();
+    for (std::vector<std::string>::const_iterator iter = proxy_list_.begin();
+         iter != proxy_list_.end(); ++iter)
+      list->Append(Value::CreateStringValue(*iter));
+    dict->Set("bad_proxy_list", list);
+    return dict;
+  }
+
+ private:
+  std::vector<std::string> proxy_list_;
+  DISALLOW_COPY_AND_ASSIGN(BadProxyListNetLogParam);
+};
+
 }  // namespace
 
 // ProxyService::PacRequest ---------------------------------------------------
@@ -715,13 +740,38 @@ int ProxyService::ReconsiderProxyAfterError(const GURL& url,
 
   // We don't have new proxy settings to try, try to fallback to the next proxy
   // in the list.
-  bool did_fallback = result->Fallback(&proxy_retry_info_);
+  bool did_fallback = result->Fallback(net_log);
 
   // Return synchronous failure if there is nothing left to fall-back to.
   // TODO(eroman): This is a yucky API, clean it up.
   return did_fallback ? OK : ERR_FAILED;
 }
 
+void ProxyService::ReportSuccess(const ProxyInfo& result) {
+  DCHECK(CalledOnValidThread());
+
+  const ProxyRetryInfoMap& new_retry_info = result.proxy_retry_info();
+  if (new_retry_info.empty())
+    return;
+
+  for (ProxyRetryInfoMap::const_iterator iter = new_retry_info.begin();
+       iter != new_retry_info.end(); ++iter) {
+    ProxyRetryInfoMap::iterator existing = proxy_retry_info_.find(iter->first);
+    if (existing == proxy_retry_info_.end())
+      proxy_retry_info_[iter->first] = iter->second;
+    else if (existing->second.bad_until < iter->second.bad_until)
+      existing->second.bad_until = iter->second.bad_until;
+  }
+  if (net_log_) {
+    net_log_->AddEntry(NetLog::TYPE_BAD_PROXY_LIST_REPORTED,
+                       base::TimeTicks::Now(),
+                       NetLog::Source(),
+                       NetLog::PHASE_NONE,
+                       make_scoped_refptr(
+                           new BadProxyListNetLogParam(new_retry_info)));
+  }
+}
+
 void ProxyService::CancelPacRequest(PacRequest* req) {
   DCHECK(CalledOnValidThread());
   DCHECK(req);

net/proxy/proxy_service.h

@@ -97,6 +97,11 @@ class NET_EXPORT ProxyService : public NetworkChangeNotifier::IPAddressObserver,
                                 PacRequest** pac_request,
                                 const BoundNetLog& net_log);
 
+  // Called to report that the last proxy connection succeeded.  If |proxy_info|
+  // has a non empty proxy_retry_info map, the proxies that have been tried (and
+  // failed) for this request will be marked as bad.
+  void ReportSuccess(const ProxyInfo& proxy_info);
+
   // Call this method with a non-null |pac_request| to cancel the PAC request.
   void CancelPacRequest(PacRequest* pac_request);
 

net/proxy/proxy_service_unittest.cc

@@ -541,6 +541,9 @@ TEST(ProxyServiceTest, ProxyFallback) {
 
   // The second proxy should be specified.
   EXPECT_EQ("foopy2:9090", info.proxy_server().ToURI());
+  // Report back that the second proxy worked.  This will globally mark the
+  // first proxy as bad.
+  service.ReportSuccess(info);
 
   TestCompletionCallback callback3;
   rv = service.ResolveProxy(url, &info, &callback3, NULL, BoundNetLog());
@@ -584,6 +587,25 @@ TEST(ProxyServiceTest, ProxyFallback) {
   EXPECT_FALSE(info.is_direct());
   EXPECT_TRUE(info.is_empty());
 
+  // Look up proxies again
+  TestCompletionCallback callback7;
+  rv = service.ResolveProxy(url, &info, &callback7, NULL, BoundNetLog());
+  EXPECT_EQ(ERR_IO_PENDING, rv);
+
+  ASSERT_EQ(1u, resolver->pending_requests().size());
+  EXPECT_EQ(url, resolver->pending_requests()[0]->url());
+
+  // This time, the first 3 results have been found to be bad, but only the
+  // first proxy has been confirmed ...
+  resolver->pending_requests()[0]->results()->UseNamedProxy(
+      "foopy1:8080;foopy3:7070;foopy2:9090;foopy4:9091");
+  resolver->pending_requests()[0]->CompleteNow(OK);
+
+  // ... therefore, we should see the second proxy first.
+  EXPECT_EQ(OK, callback7.WaitForResult());
+  EXPECT_FALSE(info.is_direct());
+  EXPECT_EQ("foopy3:7070", info.proxy_server().ToURI());
+
   // TODO(nsylvain): Test that the proxy can be retried after the delay.
 }