• Home
  • Line#
  • Scopes#
  • Navigate#
  • Raw
  • Download
1 // Copyright (c) 2013 The Chromium Authors. All rights reserved.
2 // Use of this source code is governed by a BSD-style license that can be
3 // found in the LICENSE file.
4 
5 #include "google_apis/gcm/engine/connection_factory_impl.h"
6 
7 #include "base/message_loop/message_loop.h"
8 #include "base/metrics/histogram.h"
9 #include "base/metrics/sparse_histogram.h"
10 #include "google_apis/gcm/engine/connection_handler_impl.h"
11 #include "google_apis/gcm/monitoring/gcm_stats_recorder.h"
12 #include "google_apis/gcm/protocol/mcs.pb.h"
13 #include "net/base/net_errors.h"
14 #include "net/http/http_network_session.h"
15 #include "net/http/http_request_headers.h"
16 #include "net/proxy/proxy_info.h"
17 #include "net/socket/client_socket_handle.h"
18 #include "net/socket/client_socket_pool_manager.h"
19 #include "net/ssl/ssl_config_service.h"
20 
21 namespace gcm {
22 
23 namespace {
24 
25 // The amount of time a Socket read should wait before timing out.
26 const int kReadTimeoutMs = 30000;  // 30 seconds.
27 
28 // If a connection is reset after succeeding within this window of time,
29 // the previous backoff entry is restored (and the connection success is treated
30 // as if it was transient).
31 const int kConnectionResetWindowSecs = 10;  // 10 seconds.
32 
33 // Decides whether the last login was within kConnectionResetWindowSecs of now
34 // or not.
ShouldRestorePreviousBackoff(const base::TimeTicks & login_time,const base::TimeTicks & now_ticks)35 bool ShouldRestorePreviousBackoff(const base::TimeTicks& login_time,
36                                   const base::TimeTicks& now_ticks) {
37   return !login_time.is_null() &&
38       now_ticks - login_time <=
39           base::TimeDelta::FromSeconds(kConnectionResetWindowSecs);
40 }
41 
42 }  // namespace
43 
ConnectionFactoryImpl(const std::vector<GURL> & mcs_endpoints,const net::BackoffEntry::Policy & backoff_policy,scoped_refptr<net::HttpNetworkSession> network_session,net::NetLog * net_log,GCMStatsRecorder * recorder)44 ConnectionFactoryImpl::ConnectionFactoryImpl(
45     const std::vector<GURL>& mcs_endpoints,
46     const net::BackoffEntry::Policy& backoff_policy,
47     scoped_refptr<net::HttpNetworkSession> network_session,
48     net::NetLog* net_log,
49     GCMStatsRecorder* recorder)
50   : mcs_endpoints_(mcs_endpoints),
51     next_endpoint_(0),
52     last_successful_endpoint_(0),
53     backoff_policy_(backoff_policy),
54     network_session_(network_session),
55     bound_net_log_(
56         net::BoundNetLog::Make(net_log, net::NetLog::SOURCE_SOCKET)),
57     pac_request_(NULL),
58     connecting_(false),
59     waiting_for_backoff_(false),
60     waiting_for_network_online_(false),
61     logging_in_(false),
62     recorder_(recorder),
63     listener_(NULL),
64     weak_ptr_factory_(this) {
65   DCHECK_GE(mcs_endpoints_.size(), 1U);
66 }
67 
~ConnectionFactoryImpl()68 ConnectionFactoryImpl::~ConnectionFactoryImpl() {
69   net::NetworkChangeNotifier::RemoveNetworkChangeObserver(this);
70   if (pac_request_) {
71     network_session_->proxy_service()->CancelPacRequest(pac_request_);
72     pac_request_ = NULL;
73   }
74 }
75 
Initialize(const BuildLoginRequestCallback & request_builder,const ConnectionHandler::ProtoReceivedCallback & read_callback,const ConnectionHandler::ProtoSentCallback & write_callback)76 void ConnectionFactoryImpl::Initialize(
77     const BuildLoginRequestCallback& request_builder,
78     const ConnectionHandler::ProtoReceivedCallback& read_callback,
79     const ConnectionHandler::ProtoSentCallback& write_callback) {
80   DCHECK(!connection_handler_);
81 
82   previous_backoff_ = CreateBackoffEntry(&backoff_policy_);
83   backoff_entry_ = CreateBackoffEntry(&backoff_policy_);
84   request_builder_ = request_builder;
85 
86   net::NetworkChangeNotifier::AddNetworkChangeObserver(this);
87   waiting_for_network_online_ = net::NetworkChangeNotifier::IsOffline();
88   connection_handler_ = CreateConnectionHandler(
89       base::TimeDelta::FromMilliseconds(kReadTimeoutMs),
90       read_callback,
91       write_callback,
92       base::Bind(&ConnectionFactoryImpl::ConnectionHandlerCallback,
93                  weak_ptr_factory_.GetWeakPtr())).Pass();
94 }
95 
GetConnectionHandler() const96 ConnectionHandler* ConnectionFactoryImpl::GetConnectionHandler() const {
97   return connection_handler_.get();
98 }
99 
Connect()100 void ConnectionFactoryImpl::Connect() {
101   DCHECK(connection_handler_);
102 
103   if (connecting_ || waiting_for_backoff_)
104     return;  // Connection attempt already in progress or pending.
105 
106   if (IsEndpointReachable())
107     return;  // Already connected.
108 
109   ConnectWithBackoff();
110 }
111 
ConnectWithBackoff()112 void ConnectionFactoryImpl::ConnectWithBackoff() {
113   // If a canary managed to connect while a backoff expiration was pending,
114   // just cleanup the internal state.
115   if (connecting_ || logging_in_ || IsEndpointReachable()) {
116     waiting_for_backoff_ = false;
117     return;
118   }
119 
120   if (backoff_entry_->ShouldRejectRequest()) {
121     DVLOG(1) << "Delaying MCS endpoint connection for "
122              << backoff_entry_->GetTimeUntilRelease().InMilliseconds()
123              << " milliseconds.";
124     waiting_for_backoff_ = true;
125     recorder_->RecordConnectionDelayedDueToBackoff(
126         backoff_entry_->GetTimeUntilRelease().InMilliseconds());
127     base::MessageLoop::current()->PostDelayedTask(
128         FROM_HERE,
129         base::Bind(&ConnectionFactoryImpl::ConnectWithBackoff,
130                    weak_ptr_factory_.GetWeakPtr()),
131         backoff_entry_->GetTimeUntilRelease());
132     return;
133   }
134 
135   DVLOG(1) << "Attempting connection to MCS endpoint.";
136   waiting_for_backoff_ = false;
137   ConnectImpl();
138 }
139 
IsEndpointReachable() const140 bool ConnectionFactoryImpl::IsEndpointReachable() const {
141   return connection_handler_ && connection_handler_->CanSendMessage();
142 }
143 
GetConnectionStateString() const144 std::string ConnectionFactoryImpl::GetConnectionStateString() const {
145   if (IsEndpointReachable())
146     return "CONNECTED";
147   if (logging_in_)
148     return "LOGGING IN";
149   if (connecting_)
150     return "CONNECTING";
151   if (waiting_for_backoff_)
152     return "WAITING FOR BACKOFF";
153   if (waiting_for_network_online_)
154     return "WAITING FOR NETWORK CHANGE";
155   return "NOT CONNECTED";
156 }
157 
SignalConnectionReset(ConnectionResetReason reason)158 void ConnectionFactoryImpl::SignalConnectionReset(
159     ConnectionResetReason reason) {
160   // A failure can trigger multiple resets, so no need to do anything if a
161   // connection is already in progress.
162   if (connecting_) {
163     DVLOG(1) << "Connection in progress, ignoring reset.";
164     return;
165   }
166 
167   if (listener_)
168     listener_->OnDisconnected();
169 
170   UMA_HISTOGRAM_ENUMERATION("GCM.ConnectionResetReason",
171                             reason,
172                             CONNECTION_RESET_COUNT);
173   recorder_->RecordConnectionResetSignaled(reason);
174   if (!last_login_time_.is_null()) {
175     UMA_HISTOGRAM_CUSTOM_TIMES("GCM.ConnectionUpTime",
176                                NowTicks() - last_login_time_,
177                                base::TimeDelta::FromSeconds(1),
178                                base::TimeDelta::FromHours(24),
179                                50);
180     // |last_login_time_| will be reset below, before attempting the new
181     // connection.
182   }
183 
184   CloseSocket();
185   DCHECK(!IsEndpointReachable());
186 
187   // TODO(zea): if the network is offline, don't attempt to connect.
188   // See crbug.com/396687
189 
190   // Network changes get special treatment as they can trigger a one-off canary
191   // request that bypasses backoff (but does nothing if a connection is in
192   // progress). Other connection reset events can be ignored as a connection
193   // is already awaiting backoff expiration.
194   if (waiting_for_backoff_ && reason != NETWORK_CHANGE) {
195     DVLOG(1) << "Backoff expiration pending, ignoring reset.";
196     return;
197   }
198 
199   if (logging_in_) {
200     // Failures prior to login completion just reuse the existing backoff entry.
201     logging_in_ = false;
202     backoff_entry_->InformOfRequest(false);
203   } else if (reason == LOGIN_FAILURE ||
204              ShouldRestorePreviousBackoff(last_login_time_, NowTicks())) {
205     // Failures due to login, or within the reset window of a login, restore
206     // the backoff entry that was saved off at login completion time.
207     backoff_entry_.swap(previous_backoff_);
208     backoff_entry_->InformOfRequest(false);
209   } else if (reason == NETWORK_CHANGE) {
210     ConnectImpl();  // Canary attempts bypass backoff without resetting it.
211     return;
212   } else {
213     // We shouldn't be in backoff in thise case.
214     DCHECK_EQ(0, backoff_entry_->failure_count());
215   }
216 
217   // At this point the last login time has been consumed or deemed irrelevant,
218   // reset it.
219   last_login_time_ = base::TimeTicks();
220 
221   Connect();
222 }
223 
SetConnectionListener(ConnectionListener * listener)224 void ConnectionFactoryImpl::SetConnectionListener(
225     ConnectionListener* listener) {
226   listener_ = listener;
227 }
228 
NextRetryAttempt() const229 base::TimeTicks ConnectionFactoryImpl::NextRetryAttempt() const {
230   if (!backoff_entry_)
231     return base::TimeTicks();
232   return backoff_entry_->GetReleaseTime();
233 }
234 
OnNetworkChanged(net::NetworkChangeNotifier::ConnectionType type)235 void ConnectionFactoryImpl::OnNetworkChanged(
236     net::NetworkChangeNotifier::ConnectionType type) {
237   if (type == net::NetworkChangeNotifier::CONNECTION_NONE) {
238     DVLOG(1) << "Network lost, resettion connection.";
239     waiting_for_network_online_ = true;
240 
241     // Will do nothing due to |waiting_for_network_online_ == true|.
242     // TODO(zea): make the above statement actually true. See crbug.com/396687
243     SignalConnectionReset(NETWORK_CHANGE);
244     return;
245   }
246 
247   DVLOG(1) << "Connection type changed to " << type << ", reconnecting.";
248   waiting_for_network_online_ = false;
249   SignalConnectionReset(NETWORK_CHANGE);
250 }
251 
GetCurrentEndpoint() const252 GURL ConnectionFactoryImpl::GetCurrentEndpoint() const {
253   // Note that IsEndpointReachable() returns false anytime connecting_ is true,
254   // so while connecting this always uses |next_endpoint_|.
255   if (IsEndpointReachable())
256     return mcs_endpoints_[last_successful_endpoint_];
257   return mcs_endpoints_[next_endpoint_];
258 }
259 
GetPeerIP()260 net::IPEndPoint ConnectionFactoryImpl::GetPeerIP() {
261   if (!socket_handle_.socket())
262     return net::IPEndPoint();
263 
264   net::IPEndPoint ip_endpoint;
265   int result = socket_handle_.socket()->GetPeerAddress(&ip_endpoint);
266   if (result != net::OK)
267     return net::IPEndPoint();
268 
269   return ip_endpoint;
270 }
271 
ConnectImpl()272 void ConnectionFactoryImpl::ConnectImpl() {
273   DCHECK(!IsEndpointReachable());
274   DCHECK(!socket_handle_.socket());
275 
276   // TODO(zea): if the network is offline, don't attempt to connect.
277   // See crbug.com/396687
278 
279   connecting_ = true;
280   GURL current_endpoint = GetCurrentEndpoint();
281   recorder_->RecordConnectionInitiated(current_endpoint.host());
282   int status = network_session_->proxy_service()->ResolveProxy(
283       current_endpoint,
284       &proxy_info_,
285       base::Bind(&ConnectionFactoryImpl::OnProxyResolveDone,
286                  weak_ptr_factory_.GetWeakPtr()),
287       &pac_request_,
288       bound_net_log_);
289   if (status != net::ERR_IO_PENDING)
290     OnProxyResolveDone(status);
291 }
292 
InitHandler()293 void ConnectionFactoryImpl::InitHandler() {
294   // May be null in tests.
295   mcs_proto::LoginRequest login_request;
296   if (!request_builder_.is_null()) {
297     request_builder_.Run(&login_request);
298     DCHECK(login_request.IsInitialized());
299   }
300 
301   connection_handler_->Init(login_request, socket_handle_.socket());
302 }
303 
CreateBackoffEntry(const net::BackoffEntry::Policy * const policy)304 scoped_ptr<net::BackoffEntry> ConnectionFactoryImpl::CreateBackoffEntry(
305     const net::BackoffEntry::Policy* const policy) {
306   return scoped_ptr<net::BackoffEntry>(new net::BackoffEntry(policy));
307 }
308 
CreateConnectionHandler(base::TimeDelta read_timeout,const ConnectionHandler::ProtoReceivedCallback & read_callback,const ConnectionHandler::ProtoSentCallback & write_callback,const ConnectionHandler::ConnectionChangedCallback & connection_callback)309 scoped_ptr<ConnectionHandler> ConnectionFactoryImpl::CreateConnectionHandler(
310     base::TimeDelta read_timeout,
311     const ConnectionHandler::ProtoReceivedCallback& read_callback,
312     const ConnectionHandler::ProtoSentCallback& write_callback,
313     const ConnectionHandler::ConnectionChangedCallback& connection_callback) {
314   return make_scoped_ptr<ConnectionHandler>(
315       new ConnectionHandlerImpl(read_timeout,
316                                 read_callback,
317                                 write_callback,
318                                 connection_callback));
319 }
320 
NowTicks()321 base::TimeTicks ConnectionFactoryImpl::NowTicks() {
322   return base::TimeTicks::Now();
323 }
324 
OnConnectDone(int result)325 void ConnectionFactoryImpl::OnConnectDone(int result) {
326   if (result != net::OK) {
327     // If the connection fails, try another proxy.
328     result = ReconsiderProxyAfterError(result);
329     // ReconsiderProxyAfterError either returns an error (in which case it is
330     // not reconsidering a proxy) or returns ERR_IO_PENDING if it is considering
331     // another proxy.
332     DCHECK_NE(result, net::OK);
333     if (result == net::ERR_IO_PENDING)
334       return;  // Proxy reconsideration pending. Return.
335     LOG(ERROR) << "Failed to connect to MCS endpoint with error " << result;
336     UMA_HISTOGRAM_BOOLEAN("GCM.ConnectionSuccessRate", false);
337     recorder_->RecordConnectionFailure(result);
338     CloseSocket();
339     backoff_entry_->InformOfRequest(false);
340     UMA_HISTOGRAM_SPARSE_SLOWLY("GCM.ConnectionFailureErrorCode", result);
341 
342     // If there are other endpoints available, use the next endpoint on the
343     // subsequent retry.
344     next_endpoint_++;
345     if (next_endpoint_ >= mcs_endpoints_.size())
346       next_endpoint_ = 0;
347     connecting_ = false;
348     Connect();
349     return;
350   }
351 
352   UMA_HISTOGRAM_BOOLEAN("GCM.ConnectionSuccessRate", true);
353   UMA_HISTOGRAM_COUNTS("GCM.ConnectionEndpoint", next_endpoint_);
354   UMA_HISTOGRAM_BOOLEAN("GCM.ConnectedViaProxy",
355                         !(proxy_info_.is_empty() || proxy_info_.is_direct()));
356   ReportSuccessfulProxyConnection();
357   recorder_->RecordConnectionSuccess();
358 
359   // Reset the endpoint back to the default.
360   // TODO(zea): consider prioritizing endpoints more intelligently based on
361   // which ones succeed most for this client? Although that will affect
362   // measuring the success rate of the default endpoint vs fallback.
363   last_successful_endpoint_ = next_endpoint_;
364   next_endpoint_ = 0;
365   connecting_ = false;
366   logging_in_ = true;
367   DVLOG(1) << "MCS endpoint socket connection success, starting login.";
368   InitHandler();
369 }
370 
ConnectionHandlerCallback(int result)371 void ConnectionFactoryImpl::ConnectionHandlerCallback(int result) {
372   DCHECK(!connecting_);
373   if (result != net::OK) {
374     // TODO(zea): Consider how to handle errors that may require some sort of
375     // user intervention (login page, etc.).
376     UMA_HISTOGRAM_SPARSE_SLOWLY("GCM.ConnectionDisconnectErrorCode", result);
377     SignalConnectionReset(SOCKET_FAILURE);
378     return;
379   }
380 
381   // Handshake complete, reset backoff. If the login failed with an error,
382   // the client should invoke SignalConnectionReset(LOGIN_FAILURE), which will
383   // restore the previous backoff.
384   DVLOG(1) << "Handshake complete.";
385   last_login_time_ = NowTicks();
386   previous_backoff_.swap(backoff_entry_);
387   backoff_entry_->Reset();
388   logging_in_ = false;
389 
390   if (listener_)
391     listener_->OnConnected(GetCurrentEndpoint(), GetPeerIP());
392 }
393 
394 // This has largely been copied from
395 // HttpStreamFactoryImpl::Job::DoResolveProxyComplete. This should be
396 // refactored into some common place.
OnProxyResolveDone(int status)397 void ConnectionFactoryImpl::OnProxyResolveDone(int status) {
398   pac_request_ = NULL;
399   DVLOG(1) << "Proxy resolution status: " << status;
400 
401   DCHECK_NE(status, net::ERR_IO_PENDING);
402   if (status == net::OK) {
403     // Remove unsupported proxies from the list.
404     proxy_info_.RemoveProxiesWithoutScheme(
405         net::ProxyServer::SCHEME_DIRECT |
406         net::ProxyServer::SCHEME_HTTP | net::ProxyServer::SCHEME_HTTPS |
407         net::ProxyServer::SCHEME_SOCKS4 | net::ProxyServer::SCHEME_SOCKS5);
408 
409     if (proxy_info_.is_empty()) {
410       // No proxies/direct to choose from. This happens when we don't support
411       // any of the proxies in the returned list.
412       status = net::ERR_NO_SUPPORTED_PROXIES;
413     }
414   }
415 
416   if (status != net::OK) {
417     // Failed to resolve proxy. Retry later.
418     OnConnectDone(status);
419     return;
420   }
421 
422   DVLOG(1) << "Resolved proxy with PAC:" << proxy_info_.ToPacString();
423 
424   net::SSLConfig ssl_config;
425   network_session_->ssl_config_service()->GetSSLConfig(&ssl_config);
426   status = net::InitSocketHandleForTlsConnect(
427       net::HostPortPair::FromURL(GetCurrentEndpoint()),
428       network_session_.get(),
429       proxy_info_,
430       ssl_config,
431       ssl_config,
432       net::PRIVACY_MODE_DISABLED,
433       bound_net_log_,
434       &socket_handle_,
435       base::Bind(&ConnectionFactoryImpl::OnConnectDone,
436                  weak_ptr_factory_.GetWeakPtr()));
437   if (status != net::ERR_IO_PENDING)
438     OnConnectDone(status);
439 }
440 
441 // This has largely been copied from
442 // HttpStreamFactoryImpl::Job::ReconsiderProxyAfterError. This should be
443 // refactored into some common place.
444 // This method reconsiders the proxy on certain errors. If it does reconsider
445 // a proxy it always returns ERR_IO_PENDING and posts a call to
446 // OnProxyResolveDone with the result of the reconsideration.
ReconsiderProxyAfterError(int error)447 int ConnectionFactoryImpl::ReconsiderProxyAfterError(int error) {
448   DCHECK(!pac_request_);
449   DCHECK_NE(error, net::OK);
450   DCHECK_NE(error, net::ERR_IO_PENDING);
451   // A failure to resolve the hostname or any error related to establishing a
452   // TCP connection could be grounds for trying a new proxy configuration.
453   //
454   // Why do this when a hostname cannot be resolved?  Some URLs only make sense
455   // to proxy servers.  The hostname in those URLs might fail to resolve if we
456   // are still using a non-proxy config.  We need to check if a proxy config
457   // now exists that corresponds to a proxy server that could load the URL.
458   //
459   switch (error) {
460     case net::ERR_PROXY_CONNECTION_FAILED:
461     case net::ERR_NAME_NOT_RESOLVED:
462     case net::ERR_INTERNET_DISCONNECTED:
463     case net::ERR_ADDRESS_UNREACHABLE:
464     case net::ERR_CONNECTION_CLOSED:
465     case net::ERR_CONNECTION_TIMED_OUT:
466     case net::ERR_CONNECTION_RESET:
467     case net::ERR_CONNECTION_REFUSED:
468     case net::ERR_CONNECTION_ABORTED:
469     case net::ERR_TIMED_OUT:
470     case net::ERR_TUNNEL_CONNECTION_FAILED:
471     case net::ERR_SOCKS_CONNECTION_FAILED:
472     // This can happen in the case of trying to talk to a proxy using SSL, and
473     // ending up talking to a captive portal that supports SSL instead.
474     case net::ERR_PROXY_CERTIFICATE_INVALID:
475     // This can happen when trying to talk SSL to a non-SSL server (Like a
476     // captive portal).
477     case net::ERR_SSL_PROTOCOL_ERROR:
478       break;
479     case net::ERR_SOCKS_CONNECTION_HOST_UNREACHABLE:
480       // Remap the SOCKS-specific "host unreachable" error to a more
481       // generic error code (this way consumers like the link doctor
482       // know to substitute their error page).
483       //
484       // Note that if the host resolving was done by the SOCKS5 proxy, we can't
485       // differentiate between a proxy-side "host not found" versus a proxy-side
486       // "address unreachable" error, and will report both of these failures as
487       // ERR_ADDRESS_UNREACHABLE.
488       return net::ERR_ADDRESS_UNREACHABLE;
489     default:
490       return error;
491   }
492 
493   net::SSLConfig ssl_config;
494   network_session_->ssl_config_service()->GetSSLConfig(&ssl_config);
495   if (proxy_info_.is_https() && ssl_config.send_client_cert) {
496     network_session_->ssl_client_auth_cache()->Remove(
497         proxy_info_.proxy_server().host_port_pair());
498   }
499 
500   int status = network_session_->proxy_service()->ReconsiderProxyAfterError(
501       GetCurrentEndpoint(), error, &proxy_info_,
502       base::Bind(&ConnectionFactoryImpl::OnProxyResolveDone,
503                  weak_ptr_factory_.GetWeakPtr()),
504       &pac_request_,
505       bound_net_log_);
506   if (status == net::OK || status == net::ERR_IO_PENDING) {
507     CloseSocket();
508   } else {
509     // If ReconsiderProxyAfterError() failed synchronously, it means
510     // there was nothing left to fall-back to, so fail the transaction
511     // with the last connection error we got.
512     status = error;
513   }
514 
515   // If there is new proxy info, post OnProxyResolveDone to retry it. Otherwise,
516   // if there was an error falling back, fail synchronously.
517   if (status == net::OK) {
518     base::MessageLoop::current()->PostTask(
519         FROM_HERE,
520         base::Bind(&ConnectionFactoryImpl::OnProxyResolveDone,
521                    weak_ptr_factory_.GetWeakPtr(), status));
522     status = net::ERR_IO_PENDING;
523   }
524   return status;
525 }
526 
ReportSuccessfulProxyConnection()527 void ConnectionFactoryImpl::ReportSuccessfulProxyConnection() {
528   if (network_session_ && network_session_->proxy_service())
529     network_session_->proxy_service()->ReportSuccess(proxy_info_);
530 }
531 
CloseSocket()532 void ConnectionFactoryImpl::CloseSocket() {
533   // The connection handler needs to be reset, else it'll attempt to keep using
534   // the destroyed socket.
535   if (connection_handler_)
536     connection_handler_->Reset();
537 
538   if (socket_handle_.socket() && socket_handle_.socket()->IsConnected())
539     socket_handle_.socket()->Disconnect();
540   socket_handle_.Reset();
541 }
542 
543 }  // namespace gcm
544