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