transport_client_socket_pool.cc revision 116680a4aac90f2aa7413d9095a592090648e557 
1// Copyright (c) 2012 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 "net/socket/transport_client_socket_pool.h"
6
7#include <algorithm>
8
9#include "base/compiler_specific.h"
10#include "base/lazy_instance.h"
11#include "base/logging.h"
12#include "base/message_loop/message_loop.h"
13#include "base/metrics/histogram.h"
14#include "base/strings/string_util.h"
15#include "base/synchronization/lock.h"
16#include "base/time/time.h"
17#include "base/values.h"
18#include "net/base/ip_endpoint.h"
19#include "net/base/net_errors.h"
20#include "net/base/net_log.h"
21#include "net/socket/client_socket_factory.h"
22#include "net/socket/client_socket_handle.h"
23#include "net/socket/client_socket_pool_base.h"
24#include "net/socket/socket_net_log_params.h"
25#include "net/socket/tcp_client_socket.h"
26
27using base::TimeDelta;
28
29namespace net {
30
31// TODO(willchan): Base this off RTT instead of statically setting it. Note we
32// choose a timeout that is different from the backup connect job timer so they
33// don't synchronize.
34const int TransportConnectJobHelper::kIPv6FallbackTimerInMs = 300;
35
36namespace {
37
38// Returns true iff all addresses in |list| are in the IPv6 family.
39bool AddressListOnlyContainsIPv6(const AddressList& list) {
40  DCHECK(!list.empty());
41  for (AddressList::const_iterator iter = list.begin(); iter != list.end();
42       ++iter) {
43    if (iter->GetFamily() != ADDRESS_FAMILY_IPV6)
44      return false;
45  }
46  return true;
47}
48
49}  // namespace
50
51// This lock protects |g_last_connect_time|.
52static base::LazyInstance<base::Lock>::Leaky
53    g_last_connect_time_lock = LAZY_INSTANCE_INITIALIZER;
54
55// |g_last_connect_time| has the last time a connect() call is made.
56static base::LazyInstance<base::TimeTicks>::Leaky
57    g_last_connect_time = LAZY_INSTANCE_INITIALIZER;
58
59TransportSocketParams::TransportSocketParams(
60    const HostPortPair& host_port_pair,
61    bool disable_resolver_cache,
62    bool ignore_limits,
63    const OnHostResolutionCallback& host_resolution_callback)
64    : destination_(host_port_pair),
65      ignore_limits_(ignore_limits),
66      host_resolution_callback_(host_resolution_callback) {
67  if (disable_resolver_cache)
68    destination_.set_allow_cached_response(false);
69}
70
71TransportSocketParams::~TransportSocketParams() {}
72
73// TransportConnectJobs will time out after this many seconds.  Note this is
74// the total time, including both host resolution and TCP connect() times.
75//
76// TODO(eroman): The use of this constant needs to be re-evaluated. The time
77// needed for TCPClientSocketXXX::Connect() can be arbitrarily long, since
78// the address list may contain many alternatives, and most of those may
79// timeout. Even worse, the per-connect timeout threshold varies greatly
80// between systems (anywhere from 20 seconds to 190 seconds).
81// See comment #12 at http://crbug.com/23364 for specifics.
82static const int kTransportConnectJobTimeoutInSeconds = 240;  // 4 minutes.
83
84TransportConnectJobHelper::TransportConnectJobHelper(
85    const scoped_refptr<TransportSocketParams>& params,
86    ClientSocketFactory* client_socket_factory,
87    HostResolver* host_resolver,
88    LoadTimingInfo::ConnectTiming* connect_timing)
89    : params_(params),
90      client_socket_factory_(client_socket_factory),
91      resolver_(host_resolver),
92      next_state_(STATE_NONE),
93      connect_timing_(connect_timing) {}
94
95TransportConnectJobHelper::~TransportConnectJobHelper() {}
96
97int TransportConnectJobHelper::DoResolveHost(RequestPriority priority,
98                                             const BoundNetLog& net_log) {
99  next_state_ = STATE_RESOLVE_HOST_COMPLETE;
100  connect_timing_->dns_start = base::TimeTicks::Now();
101
102  return resolver_.Resolve(
103      params_->destination(), priority, &addresses_, on_io_complete_, net_log);
104}
105
106int TransportConnectJobHelper::DoResolveHostComplete(
107    int result,
108    const BoundNetLog& net_log) {
109  connect_timing_->dns_end = base::TimeTicks::Now();
110  // Overwrite connection start time, since for connections that do not go
111  // through proxies, |connect_start| should not include dns lookup time.
112  connect_timing_->connect_start = connect_timing_->dns_end;
113
114  if (result == OK) {
115    // Invoke callback, and abort if it fails.
116    if (!params_->host_resolution_callback().is_null())
117      result = params_->host_resolution_callback().Run(addresses_, net_log);
118
119    if (result == OK)
120      next_state_ = STATE_TRANSPORT_CONNECT;
121  }
122  return result;
123}
124
125base::TimeDelta TransportConnectJobHelper::HistogramDuration(
126    ConnectionLatencyHistogram race_result) {
127  DCHECK(!connect_timing_->connect_start.is_null());
128  DCHECK(!connect_timing_->dns_start.is_null());
129  base::TimeTicks now = base::TimeTicks::Now();
130  base::TimeDelta total_duration = now - connect_timing_->dns_start;
131  UMA_HISTOGRAM_CUSTOM_TIMES("Net.DNS_Resolution_And_TCP_Connection_Latency2",
132                             total_duration,
133                             base::TimeDelta::FromMilliseconds(1),
134                             base::TimeDelta::FromMinutes(10),
135                             100);
136
137  base::TimeDelta connect_duration = now - connect_timing_->connect_start;
138  UMA_HISTOGRAM_CUSTOM_TIMES("Net.TCP_Connection_Latency",
139                             connect_duration,
140                             base::TimeDelta::FromMilliseconds(1),
141                             base::TimeDelta::FromMinutes(10),
142                             100);
143
144  switch (race_result) {
145    case CONNECTION_LATENCY_IPV4_WINS_RACE:
146      UMA_HISTOGRAM_CUSTOM_TIMES("Net.TCP_Connection_Latency_IPv4_Wins_Race",
147                                 connect_duration,
148                                 base::TimeDelta::FromMilliseconds(1),
149                                 base::TimeDelta::FromMinutes(10),
150                                 100);
151      break;
152
153    case CONNECTION_LATENCY_IPV4_NO_RACE:
154      UMA_HISTOGRAM_CUSTOM_TIMES("Net.TCP_Connection_Latency_IPv4_No_Race",
155                                 connect_duration,
156                                 base::TimeDelta::FromMilliseconds(1),
157                                 base::TimeDelta::FromMinutes(10),
158                                 100);
159      break;
160
161    case CONNECTION_LATENCY_IPV6_RACEABLE:
162      UMA_HISTOGRAM_CUSTOM_TIMES("Net.TCP_Connection_Latency_IPv6_Raceable",
163                                 connect_duration,
164                                 base::TimeDelta::FromMilliseconds(1),
165                                 base::TimeDelta::FromMinutes(10),
166                                 100);
167      break;
168
169    case CONNECTION_LATENCY_IPV6_SOLO:
170      UMA_HISTOGRAM_CUSTOM_TIMES("Net.TCP_Connection_Latency_IPv6_Solo",
171                                 connect_duration,
172                                 base::TimeDelta::FromMilliseconds(1),
173                                 base::TimeDelta::FromMinutes(10),
174                                 100);
175      break;
176
177    default:
178      NOTREACHED();
179      break;
180  }
181
182  return connect_duration;
183}
184
185TransportConnectJob::TransportConnectJob(
186    const std::string& group_name,
187    RequestPriority priority,
188    const scoped_refptr<TransportSocketParams>& params,
189    base::TimeDelta timeout_duration,
190    ClientSocketFactory* client_socket_factory,
191    HostResolver* host_resolver,
192    Delegate* delegate,
193    NetLog* net_log)
194    : ConnectJob(group_name, timeout_duration, priority, delegate,
195                 BoundNetLog::Make(net_log, NetLog::SOURCE_CONNECT_JOB)),
196      helper_(params, client_socket_factory, host_resolver, &connect_timing_),
197      interval_between_connects_(CONNECT_INTERVAL_GT_20MS) {
198  helper_.SetOnIOComplete(this);
199}
200
201TransportConnectJob::~TransportConnectJob() {
202  // We don't worry about cancelling the host resolution and TCP connect, since
203  // ~SingleRequestHostResolver and ~StreamSocket will take care of it.
204}
205
206LoadState TransportConnectJob::GetLoadState() const {
207  switch (helper_.next_state()) {
208    case TransportConnectJobHelper::STATE_RESOLVE_HOST:
209    case TransportConnectJobHelper::STATE_RESOLVE_HOST_COMPLETE:
210      return LOAD_STATE_RESOLVING_HOST;
211    case TransportConnectJobHelper::STATE_TRANSPORT_CONNECT:
212    case TransportConnectJobHelper::STATE_TRANSPORT_CONNECT_COMPLETE:
213      return LOAD_STATE_CONNECTING;
214    case TransportConnectJobHelper::STATE_NONE:
215      return LOAD_STATE_IDLE;
216  }
217  NOTREACHED();
218  return LOAD_STATE_IDLE;
219}
220
221// static
222void TransportConnectJob::MakeAddressListStartWithIPv4(AddressList* list) {
223  for (AddressList::iterator i = list->begin(); i != list->end(); ++i) {
224    if (i->GetFamily() == ADDRESS_FAMILY_IPV4) {
225      std::rotate(list->begin(), i, list->end());
226      break;
227    }
228  }
229}
230
231int TransportConnectJob::DoResolveHost() {
232  return helper_.DoResolveHost(priority(), net_log());
233}
234
235int TransportConnectJob::DoResolveHostComplete(int result) {
236  return helper_.DoResolveHostComplete(result, net_log());
237}
238
239int TransportConnectJob::DoTransportConnect() {
240  base::TimeTicks now = base::TimeTicks::Now();
241  base::TimeTicks last_connect_time;
242  {
243    base::AutoLock lock(g_last_connect_time_lock.Get());
244    last_connect_time = g_last_connect_time.Get();
245    *g_last_connect_time.Pointer() = now;
246  }
247  if (last_connect_time.is_null()) {
248    interval_between_connects_ = CONNECT_INTERVAL_GT_20MS;
249  } else {
250    int64 interval = (now - last_connect_time).InMilliseconds();
251    if (interval <= 10)
252      interval_between_connects_ = CONNECT_INTERVAL_LE_10MS;
253    else if (interval <= 20)
254      interval_between_connects_ = CONNECT_INTERVAL_LE_20MS;
255    else
256      interval_between_connects_ = CONNECT_INTERVAL_GT_20MS;
257  }
258
259  helper_.set_next_state(
260      TransportConnectJobHelper::STATE_TRANSPORT_CONNECT_COMPLETE);
261  transport_socket_ =
262      helper_.client_socket_factory()->CreateTransportClientSocket(
263          helper_.addresses(), net_log().net_log(), net_log().source());
264  int rv = transport_socket_->Connect(helper_.on_io_complete());
265  if (rv == ERR_IO_PENDING &&
266      helper_.addresses().front().GetFamily() == ADDRESS_FAMILY_IPV6 &&
267      !AddressListOnlyContainsIPv6(helper_.addresses())) {
268    fallback_timer_.Start(
269        FROM_HERE,
270        base::TimeDelta::FromMilliseconds(
271            TransportConnectJobHelper::kIPv6FallbackTimerInMs),
272        this,
273        &TransportConnectJob::DoIPv6FallbackTransportConnect);
274  }
275  return rv;
276}
277
278int TransportConnectJob::DoTransportConnectComplete(int result) {
279  if (result == OK) {
280    bool is_ipv4 =
281        helper_.addresses().front().GetFamily() == ADDRESS_FAMILY_IPV4;
282    TransportConnectJobHelper::ConnectionLatencyHistogram race_result =
283        TransportConnectJobHelper::CONNECTION_LATENCY_UNKNOWN;
284    if (is_ipv4) {
285      race_result = TransportConnectJobHelper::CONNECTION_LATENCY_IPV4_NO_RACE;
286    } else {
287      if (AddressListOnlyContainsIPv6(helper_.addresses())) {
288        race_result = TransportConnectJobHelper::CONNECTION_LATENCY_IPV6_SOLO;
289      } else {
290        race_result =
291            TransportConnectJobHelper::CONNECTION_LATENCY_IPV6_RACEABLE;
292      }
293    }
294    base::TimeDelta connect_duration = helper_.HistogramDuration(race_result);
295    switch (interval_between_connects_) {
296      case CONNECT_INTERVAL_LE_10MS:
297        UMA_HISTOGRAM_CUSTOM_TIMES(
298            "Net.TCP_Connection_Latency_Interval_LessThanOrEqual_10ms",
299            connect_duration,
300            base::TimeDelta::FromMilliseconds(1),
301            base::TimeDelta::FromMinutes(10),
302            100);
303        break;
304      case CONNECT_INTERVAL_LE_20MS:
305        UMA_HISTOGRAM_CUSTOM_TIMES(
306            "Net.TCP_Connection_Latency_Interval_LessThanOrEqual_20ms",
307            connect_duration,
308            base::TimeDelta::FromMilliseconds(1),
309            base::TimeDelta::FromMinutes(10),
310            100);
311        break;
312      case CONNECT_INTERVAL_GT_20MS:
313        UMA_HISTOGRAM_CUSTOM_TIMES(
314            "Net.TCP_Connection_Latency_Interval_GreaterThan_20ms",
315            connect_duration,
316            base::TimeDelta::FromMilliseconds(1),
317            base::TimeDelta::FromMinutes(10),
318            100);
319        break;
320      default:
321        NOTREACHED();
322        break;
323    }
324
325    SetSocket(transport_socket_.Pass());
326    fallback_timer_.Stop();
327  } else {
328    // Be a bit paranoid and kill off the fallback members to prevent reuse.
329    fallback_transport_socket_.reset();
330    fallback_addresses_.reset();
331  }
332
333  return result;
334}
335
336void TransportConnectJob::DoIPv6FallbackTransportConnect() {
337  // The timer should only fire while we're waiting for the main connect to
338  // succeed.
339  if (helper_.next_state() !=
340      TransportConnectJobHelper::STATE_TRANSPORT_CONNECT_COMPLETE) {
341    NOTREACHED();
342    return;
343  }
344
345  DCHECK(!fallback_transport_socket_.get());
346  DCHECK(!fallback_addresses_.get());
347
348  fallback_addresses_.reset(new AddressList(helper_.addresses()));
349  MakeAddressListStartWithIPv4(fallback_addresses_.get());
350  fallback_transport_socket_ =
351      helper_.client_socket_factory()->CreateTransportClientSocket(
352          *fallback_addresses_, net_log().net_log(), net_log().source());
353  fallback_connect_start_time_ = base::TimeTicks::Now();
354  int rv = fallback_transport_socket_->Connect(
355      base::Bind(
356          &TransportConnectJob::DoIPv6FallbackTransportConnectComplete,
357          base::Unretained(this)));
358  if (rv != ERR_IO_PENDING)
359    DoIPv6FallbackTransportConnectComplete(rv);
360}
361
362void TransportConnectJob::DoIPv6FallbackTransportConnectComplete(int result) {
363  // This should only happen when we're waiting for the main connect to succeed.
364  if (helper_.next_state() !=
365      TransportConnectJobHelper::STATE_TRANSPORT_CONNECT_COMPLETE) {
366    NOTREACHED();
367    return;
368  }
369
370  DCHECK_NE(ERR_IO_PENDING, result);
371  DCHECK(fallback_transport_socket_.get());
372  DCHECK(fallback_addresses_.get());
373
374  if (result == OK) {
375    DCHECK(!fallback_connect_start_time_.is_null());
376    connect_timing_.connect_start = fallback_connect_start_time_;
377    helper_.HistogramDuration(
378        TransportConnectJobHelper::CONNECTION_LATENCY_IPV4_WINS_RACE);
379    SetSocket(fallback_transport_socket_.Pass());
380    helper_.set_next_state(TransportConnectJobHelper::STATE_NONE);
381    transport_socket_.reset();
382  } else {
383    // Be a bit paranoid and kill off the fallback members to prevent reuse.
384    fallback_transport_socket_.reset();
385    fallback_addresses_.reset();
386  }
387  NotifyDelegateOfCompletion(result);  // Deletes |this|
388}
389
390int TransportConnectJob::ConnectInternal() {
391  return helper_.DoConnectInternal(this);
392}
393
394scoped_ptr<ConnectJob>
395    TransportClientSocketPool::TransportConnectJobFactory::NewConnectJob(
396    const std::string& group_name,
397    const PoolBase::Request& request,
398    ConnectJob::Delegate* delegate) const {
399  return scoped_ptr<ConnectJob>(
400      new TransportConnectJob(group_name,
401                              request.priority(),
402                              request.params(),
403                              ConnectionTimeout(),
404                              client_socket_factory_,
405                              host_resolver_,
406                              delegate,
407                              net_log_));
408}
409
410base::TimeDelta
411    TransportClientSocketPool::TransportConnectJobFactory::ConnectionTimeout()
412    const {
413  return base::TimeDelta::FromSeconds(kTransportConnectJobTimeoutInSeconds);
414}
415
416TransportClientSocketPool::TransportClientSocketPool(
417    int max_sockets,
418    int max_sockets_per_group,
419    ClientSocketPoolHistograms* histograms,
420    HostResolver* host_resolver,
421    ClientSocketFactory* client_socket_factory,
422    NetLog* net_log)
423    : base_(NULL, max_sockets, max_sockets_per_group, histograms,
424            ClientSocketPool::unused_idle_socket_timeout(),
425            ClientSocketPool::used_idle_socket_timeout(),
426            new TransportConnectJobFactory(client_socket_factory,
427                                           host_resolver, net_log)) {
428  base_.EnableConnectBackupJobs();
429}
430
431TransportClientSocketPool::~TransportClientSocketPool() {}
432
433int TransportClientSocketPool::RequestSocket(
434    const std::string& group_name,
435    const void* params,
436    RequestPriority priority,
437    ClientSocketHandle* handle,
438    const CompletionCallback& callback,
439    const BoundNetLog& net_log) {
440  const scoped_refptr<TransportSocketParams>* casted_params =
441      static_cast<const scoped_refptr<TransportSocketParams>*>(params);
442
443  NetLogTcpClientSocketPoolRequestedSocket(net_log, casted_params);
444
445  return base_.RequestSocket(group_name, *casted_params, priority, handle,
446                             callback, net_log);
447}
448
449void TransportClientSocketPool::NetLogTcpClientSocketPoolRequestedSocket(
450    const BoundNetLog& net_log,
451    const scoped_refptr<TransportSocketParams>* casted_params) {
452  if (net_log.IsLogging()) {
453    // TODO(eroman): Split out the host and port parameters.
454    net_log.AddEvent(
455        NetLog::TYPE_TCP_CLIENT_SOCKET_POOL_REQUESTED_SOCKET,
456        CreateNetLogHostPortPairCallback(
457            &casted_params->get()->destination().host_port_pair()));
458  }
459}
460
461void TransportClientSocketPool::RequestSockets(
462    const std::string& group_name,
463    const void* params,
464    int num_sockets,
465    const BoundNetLog& net_log) {
466  const scoped_refptr<TransportSocketParams>* casted_params =
467      static_cast<const scoped_refptr<TransportSocketParams>*>(params);
468
469  if (net_log.IsLogging()) {
470    // TODO(eroman): Split out the host and port parameters.
471    net_log.AddEvent(
472        NetLog::TYPE_TCP_CLIENT_SOCKET_POOL_REQUESTED_SOCKETS,
473        CreateNetLogHostPortPairCallback(
474            &casted_params->get()->destination().host_port_pair()));
475  }
476
477  base_.RequestSockets(group_name, *casted_params, num_sockets, net_log);
478}
479
480void TransportClientSocketPool::CancelRequest(
481    const std::string& group_name,
482    ClientSocketHandle* handle) {
483  base_.CancelRequest(group_name, handle);
484}
485
486void TransportClientSocketPool::ReleaseSocket(
487    const std::string& group_name,
488    scoped_ptr<StreamSocket> socket,
489    int id) {
490  base_.ReleaseSocket(group_name, socket.Pass(), id);
491}
492
493void TransportClientSocketPool::FlushWithError(int error) {
494  base_.FlushWithError(error);
495}
496
497void TransportClientSocketPool::CloseIdleSockets() {
498  base_.CloseIdleSockets();
499}
500
501int TransportClientSocketPool::IdleSocketCount() const {
502  return base_.idle_socket_count();
503}
504
505int TransportClientSocketPool::IdleSocketCountInGroup(
506    const std::string& group_name) const {
507  return base_.IdleSocketCountInGroup(group_name);
508}
509
510LoadState TransportClientSocketPool::GetLoadState(
511    const std::string& group_name, const ClientSocketHandle* handle) const {
512  return base_.GetLoadState(group_name, handle);
513}
514
515base::DictionaryValue* TransportClientSocketPool::GetInfoAsValue(
516    const std::string& name,
517    const std::string& type,
518    bool include_nested_pools) const {
519  return base_.GetInfoAsValue(name, type);
520}
521
522base::TimeDelta TransportClientSocketPool::ConnectionTimeout() const {
523  return base_.ConnectionTimeout();
524}
525
526ClientSocketPoolHistograms* TransportClientSocketPool::histograms() const {
527  return base_.histograms();
528}
529
530bool TransportClientSocketPool::IsStalled() const {
531  return base_.IsStalled();
532}
533
534void TransportClientSocketPool::AddHigherLayeredPool(
535    HigherLayeredPool* higher_pool) {
536  base_.AddHigherLayeredPool(higher_pool);
537}
538
539void TransportClientSocketPool::RemoveHigherLayeredPool(
540    HigherLayeredPool* higher_pool) {
541  base_.RemoveHigherLayeredPool(higher_pool);
542}
543
544}  // namespace net
545