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