sync/internal_api/http_bridge.cc

   1 // Copyright 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 "sync/internal_api/public/http_bridge.h"
   6
   7 #include "base/message_loop/message_loop.h"
   8 #include "base/metrics/histogram_macros.h"
   9 #include "base/strings/string_number_conversions.h"
  10 #include "net/base/load_flags.h"
  11 #include "net/base/net_errors.h"
  12 #include "net/cookies/cookie_monster.h"
  13 #include "net/http/http_cache.h"
  14 #include "net/http/http_network_layer.h"
  15 #include "net/http/http_response_headers.h"
  16 #include "net/url_request/static_http_user_agent_settings.h"
  17 #include "net/url_request/url_fetcher.h"
  18 #include "net/url_request/url_request_context.h"
  19 #include "net/url_request/url_request_job_factory_impl.h"
  20 #include "net/url_request/url_request_status.h"
  21 #include "sync/internal_api/public/base/cancelation_signal.h"
  22
  23 namespace syncer {
  24
  25 namespace {
  26
  27 // It's possible for an http request to be silently stalled. We set a time
  28 // limit for all http requests, beyond which the request is cancelled and
  29 // treated as a transient failure.
  30 const int kMaxHttpRequestTimeSeconds = 60 * 5;  // 5 minutes.
  31
  32 // Helper method for logging timeouts via UMA.
  33 void LogTimeout(bool timed_out) {
  34   UMA_HISTOGRAM_BOOLEAN("Sync.URLFetchTimedOut", timed_out);
  35 }
  36
  37 }  // namespace
  38
  39 HttpBridge::RequestContextGetter::RequestContextGetter(
  40     net::URLRequestContextGetter* baseline_context_getter,
  41     const std::string& user_agent)
  42     : baseline_context_getter_(baseline_context_getter),
  43       network_task_runner_(
  44           baseline_context_getter_->GetNetworkTaskRunner()),
  45       user_agent_(user_agent) {
  46   DCHECK(baseline_context_getter_.get());
  47   DCHECK(network_task_runner_.get());
  48   DCHECK(!user_agent_.empty());
  49 }
  50
  51 HttpBridge::RequestContextGetter::~RequestContextGetter() {}
  52
  53 net::URLRequestContext*
  54 HttpBridge::RequestContextGetter::GetURLRequestContext() {
  55   // Lazily create the context.
  56   if (!context_) {
  57     net::URLRequestContext* baseline_context =
  58         baseline_context_getter_->GetURLRequestContext();
  59     context_.reset(
  60         new RequestContext(baseline_context, GetNetworkTaskRunner(),
  61                            user_agent_));
  62     baseline_context_getter_ = NULL;
  63   }
  64
  65   return context_.get();
  66 }
  67
  68 scoped_refptr<base::SingleThreadTaskRunner>
  69 HttpBridge::RequestContextGetter::GetNetworkTaskRunner() const {
  70   return network_task_runner_;
  71 }
  72
  73 HttpBridgeFactory::HttpBridgeFactory(
  74     const scoped_refptr<net::URLRequestContextGetter>& baseline_context_getter,
  75     const NetworkTimeUpdateCallback& network_time_update_callback,
  76     CancelationSignal* cancelation_signal)
  77     : baseline_request_context_getter_(baseline_context_getter),
  78       network_time_update_callback_(network_time_update_callback),
  79       cancelation_signal_(cancelation_signal) {
  80   // Registration should never fail.  This should happen on the UI thread during
  81   // init.  It would be impossible for a shutdown to have been requested at this
  82   // point.
  83   bool result = cancelation_signal_->TryRegisterHandler(this);
  84   DCHECK(result);
  85 }
  86
  87 HttpBridgeFactory::~HttpBridgeFactory() {
  88   cancelation_signal_->UnregisterHandler(this);
  89 }
  90
  91 void HttpBridgeFactory::Init(const std::string& user_agent) {
  92   base::AutoLock lock(context_getter_lock_);
  93
  94   if (!baseline_request_context_getter_.get()) {
  95     // Uh oh.  We've been aborted before we finished initializing.  There's no
  96     // point in initializating further; let's just return right away.
  97     return;
  98   }
  99
 100   request_context_getter_ = new HttpBridge::RequestContextGetter(
 101       baseline_request_context_getter_.get(), user_agent);
 102 }
 103
 104 HttpPostProviderInterface* HttpBridgeFactory::Create() {
 105   base::AutoLock lock(context_getter_lock_);
 106
 107   // If we've been asked to shut down (something which may happen asynchronously
 108   // and at pretty much any time), then we won't have a request_context_getter_.
 109   // Some external mechanism must ensure that this function is not called after
 110   // we've been asked to shut down.
 111   CHECK(request_context_getter_.get());
 112
 113   HttpBridge* http = new HttpBridge(request_context_getter_.get(),
 114                                     network_time_update_callback_);
 115   http->AddRef();
 116   return http;
 117 }
 118
 119 void HttpBridgeFactory::Destroy(HttpPostProviderInterface* http) {
 120   static_cast<HttpBridge*>(http)->Release();
 121 }
 122
 123 void HttpBridgeFactory::OnSignalReceived() {
 124   base::AutoLock lock(context_getter_lock_);
 125   // Release |baseline_request_context_getter_| as soon as possible so that it
 126   // is destroyed in the right order on its network task runner.  The
 127   // |request_context_getter_| has a reference to the baseline, so we must
 128   // drop our reference to it, too.
 129   baseline_request_context_getter_ = NULL;
 130   request_context_getter_ = NULL;
 131 }
 132
 133 HttpBridge::RequestContext::RequestContext(
 134     net::URLRequestContext* baseline_context,
 135     const scoped_refptr<base::SingleThreadTaskRunner>&
 136         network_task_runner,
 137     const std::string& user_agent)
 138     : network_task_runner_(network_task_runner),
 139       job_factory_(new net::URLRequestJobFactoryImpl()) {
 140   DCHECK(!user_agent.empty());
 141
 142   // Create empty, in-memory cookie store.
 143   set_cookie_store(new net::CookieMonster(NULL, NULL));
 144
 145   // We don't use a cache for bridged loads, but we do want to share proxy info.
 146   set_host_resolver(baseline_context->host_resolver());
 147   set_proxy_service(baseline_context->proxy_service());
 148   set_ssl_config_service(baseline_context->ssl_config_service());
 149
 150   // Use its own job factory, which only supports http and https.
 151   set_job_factory(job_factory_.get());
 152
 153   // We want to share the HTTP session data with the network layer factory,
 154   // which includes auth_cache for proxies.
 155   // Session is not refcounted so we need to be careful to not lose the parent
 156   // context.
 157   net::HttpNetworkSession* session =
 158       baseline_context->http_transaction_factory()->GetSession();
 159   DCHECK(session);
 160   set_http_transaction_factory(new net::HttpNetworkLayer(session));
 161
 162   // TODO(timsteele): We don't currently listen for pref changes of these
 163   // fields or CookiePolicy; I'm not sure we want to strictly follow the
 164   // default settings, since for example if the user chooses to block all
 165   // cookies, sync will start failing. Also it seems like accept_lang/charset
 166   // should be tied to whatever the sync servers expect (if anything). These
 167   // fields should probably just be settable by sync backend; though we should
 168   // figure out if we need to give the user explicit control over policies etc.
 169   std::string accepted_language_list;
 170   if (baseline_context->http_user_agent_settings()) {
 171     accepted_language_list =
 172         baseline_context->http_user_agent_settings()->GetAcceptLanguage();
 173   }
 174   http_user_agent_settings_.reset(new net::StaticHttpUserAgentSettings(
 175       accepted_language_list,
 176       user_agent));
 177   set_http_user_agent_settings(http_user_agent_settings_.get());
 178
 179   set_net_log(baseline_context->net_log());
 180 }
 181
 182 HttpBridge::RequestContext::~RequestContext() {
 183   AssertNoURLRequests();
 184   DCHECK(network_task_runner_->BelongsToCurrentThread());
 185   delete http_transaction_factory();
 186 }
 187
 188 HttpBridge::URLFetchState::URLFetchState()
 189     : url_poster(NULL),
 190       aborted(false),
 191       request_completed(false),
 192       request_succeeded(false),
 193       http_response_code(-1),
 194       error_code(-1) {
 195 }
 196 HttpBridge::URLFetchState::~URLFetchState() {}
 197
 198 HttpBridge::HttpBridge(
 199     HttpBridge::RequestContextGetter* context_getter,
 200     const NetworkTimeUpdateCallback& network_time_update_callback)
 201     : created_on_loop_(base::MessageLoop::current()),
 202       http_post_completed_(false, false),
 203       context_getter_for_request_(context_getter),
 204       network_task_runner_(
 205           context_getter_for_request_->GetNetworkTaskRunner()),
 206       network_time_update_callback_(network_time_update_callback) {
 207 }
 208
 209 HttpBridge::~HttpBridge() {
 210 }
 211
 212 void HttpBridge::SetExtraRequestHeaders(const char * headers) {
 213   DCHECK(extra_headers_.empty())
 214       << "HttpBridge::SetExtraRequestHeaders called twice.";
 215   extra_headers_.assign(headers);
 216 }
 217
 218 void HttpBridge::SetURL(const char* url, int port) {
 219 #if DCHECK_IS_ON()
 220   DCHECK_EQ(base::MessageLoop::current(), created_on_loop_);
 221   {
 222     base::AutoLock lock(fetch_state_lock_);
 223     DCHECK(!fetch_state_.request_completed);
 224   }
 225   DCHECK(url_for_request_.is_empty())
 226       << "HttpBridge::SetURL called more than once?!";
 227 #endif
 228   GURL temp(url);
 229   GURL::Replacements replacements;
 230   std::string port_str = base::IntToString(port);
 231   replacements.SetPort(port_str.c_str(), url::Component(0, port_str.length()));
 232   url_for_request_ = temp.ReplaceComponents(replacements);
 233 }
 234
 235 void HttpBridge::SetPostPayload(const char* content_type,
 236                                 int content_length,
 237                                 const char* content) {
 238 #if DCHECK_IS_ON()
 239   DCHECK_EQ(base::MessageLoop::current(), created_on_loop_);
 240   {
 241     base::AutoLock lock(fetch_state_lock_);
 242     DCHECK(!fetch_state_.request_completed);
 243   }
 244   DCHECK(content_type_.empty()) << "Bridge payload already set.";
 245   DCHECK_GE(content_length, 0) << "Content length < 0";
 246 #endif
 247   content_type_ = content_type;
 248   if (!content || (content_length == 0)) {
 249     DCHECK_EQ(content_length, 0);
 250     request_content_ = " ";  // TODO(timsteele): URLFetcher requires non-empty
 251                              // content for POSTs whereas CURL does not, for now
 252                              // we hack this to support the sync backend.
 253   } else {
 254     request_content_.assign(content, content_length);
 255   }
 256 }
 257
 258 bool HttpBridge::MakeSynchronousPost(int* error_code, int* response_code) {
 259 #if DCHECK_IS_ON()
 260   DCHECK_EQ(base::MessageLoop::current(), created_on_loop_);
 261   {
 262     base::AutoLock lock(fetch_state_lock_);
 263     DCHECK(!fetch_state_.request_completed);
 264   }
 265   DCHECK(url_for_request_.is_valid()) << "Invalid URL for request";
 266   DCHECK(!content_type_.empty()) << "Payload not set";
 267 #endif
 268
 269   if (!network_task_runner_->PostTask(
 270           FROM_HERE,
 271           base::Bind(&HttpBridge::CallMakeAsynchronousPost, this))) {
 272     // This usually happens when we're in a unit test.
 273     LOG(WARNING) << "Could not post CallMakeAsynchronousPost task";
 274     return false;
 275   }
 276
 277   // Block until network request completes or is aborted. See
 278   // OnURLFetchComplete and Abort.
 279   http_post_completed_.Wait();
 280
 281   base::AutoLock lock(fetch_state_lock_);
 282   DCHECK(fetch_state_.request_completed || fetch_state_.aborted);
 283   *error_code = fetch_state_.error_code;
 284   *response_code = fetch_state_.http_response_code;
 285   return fetch_state_.request_succeeded;
 286 }
 287
 288 void HttpBridge::MakeAsynchronousPost() {
 289   DCHECK(network_task_runner_->BelongsToCurrentThread());
 290
 291   base::AutoLock lock(fetch_state_lock_);
 292   DCHECK(!fetch_state_.request_completed);
 293   if (fetch_state_.aborted)
 294     return;
 295
 296   // Start the timer on the network thread (the same thread progress is made
 297   // on, and on which the url fetcher lives).
 298   DCHECK(!fetch_state_.http_request_timeout_timer.get());
 299   fetch_state_.http_request_timeout_timer.reset(new base::Timer(false, false));
 300   fetch_state_.http_request_timeout_timer->Start(
 301       FROM_HERE, base::TimeDelta::FromSeconds(kMaxHttpRequestTimeSeconds),
 302       base::Bind(&HttpBridge::OnURLFetchTimedOut, this));
 303
 304   DCHECK(context_getter_for_request_.get());
 305   fetch_state_.url_poster =
 306       net::URLFetcher::Create(url_for_request_, net::URLFetcher::POST, this)
 307           .release();
 308   fetch_state_.url_poster->SetRequestContext(context_getter_for_request_.get());
 309   fetch_state_.url_poster->SetUploadData(content_type_, request_content_);
 310   fetch_state_.url_poster->SetExtraRequestHeaders(extra_headers_);
 311   fetch_state_.url_poster->SetLoadFlags(net::LOAD_DO_NOT_SEND_COOKIES);
 312   fetch_state_.start_time = base::Time::Now();
 313
 314   fetch_state_.url_poster->Start();
 315 }
 316
 317 int HttpBridge::GetResponseContentLength() const {
 318   DCHECK_EQ(base::MessageLoop::current(), created_on_loop_);
 319   base::AutoLock lock(fetch_state_lock_);
 320   DCHECK(fetch_state_.request_completed);
 321   return fetch_state_.response_content.size();
 322 }
 323
 324 const char* HttpBridge::GetResponseContent() const {
 325   DCHECK_EQ(base::MessageLoop::current(), created_on_loop_);
 326   base::AutoLock lock(fetch_state_lock_);
 327   DCHECK(fetch_state_.request_completed);
 328   return fetch_state_.response_content.data();
 329 }
 330
 331 const std::string HttpBridge::GetResponseHeaderValue(
 332     const std::string& name) const {
 333
 334   DCHECK_EQ(base::MessageLoop::current(), created_on_loop_);
 335   base::AutoLock lock(fetch_state_lock_);
 336   DCHECK(fetch_state_.request_completed);
 337
 338   std::string value;
 339   fetch_state_.response_headers->EnumerateHeader(NULL, name, &value);
 340   return value;
 341 }
 342
 343 void HttpBridge::Abort() {
 344   base::AutoLock lock(fetch_state_lock_);
 345
 346   // Release |request_context_getter_| as soon as possible so that it is
 347   // destroyed in the right order on its network task runner.
 348   context_getter_for_request_ = NULL;
 349
 350   DCHECK(!fetch_state_.aborted);
 351   if (fetch_state_.aborted || fetch_state_.request_completed)
 352     return;
 353
 354   fetch_state_.aborted = true;
 355   if (!network_task_runner_->PostTask(
 356           FROM_HERE,
 357           base::Bind(&HttpBridge::DestroyURLFetcherOnIOThread, this,
 358                      fetch_state_.url_poster,
 359                      fetch_state_.http_request_timeout_timer.release()))) {
 360     // Madness ensues.
 361     NOTREACHED() << "Could not post task to delete URLFetcher";
 362   }
 363
 364   fetch_state_.url_poster = NULL;
 365   fetch_state_.error_code = net::ERR_ABORTED;
 366   http_post_completed_.Signal();
 367 }
 368
 369 void HttpBridge::DestroyURLFetcherOnIOThread(
 370     net::URLFetcher* fetcher,
 371     base::Timer* fetch_timer) {
 372   DCHECK(network_task_runner_->BelongsToCurrentThread());
 373   if (fetch_timer)
 374     delete fetch_timer;
 375   delete fetcher;
 376 }
 377
 378 void HttpBridge::OnURLFetchComplete(const net::URLFetcher* source) {
 379   DCHECK(network_task_runner_->BelongsToCurrentThread());
 380
 381   base::AutoLock lock(fetch_state_lock_);
 382
 383   // Stop the request timer now that the request completed.
 384   if (fetch_state_.http_request_timeout_timer.get())
 385     fetch_state_.http_request_timeout_timer.reset();
 386
 387   if (fetch_state_.aborted)
 388     return;
 389
 390   fetch_state_.end_time = base::Time::Now();
 391   fetch_state_.request_completed = true;
 392   fetch_state_.request_succeeded =
 393       (net::URLRequestStatus::SUCCESS == source->GetStatus().status());
 394   fetch_state_.http_response_code = source->GetResponseCode();
 395   fetch_state_.error_code = source->GetStatus().error();
 396
 397   if (fetch_state_.request_succeeded)
 398     LogTimeout(false);
 399   UMA_HISTOGRAM_LONG_TIMES("Sync.URLFetchTime",
 400                            fetch_state_.end_time - fetch_state_.start_time);
 401
 402   // Use a real (non-debug) log to facilitate troubleshooting in the wild.
 403   VLOG(2) << "HttpBridge::OnURLFetchComplete for: "
 404           << fetch_state_.url_poster->GetURL().spec();
 405   VLOG(1) << "HttpBridge received response code: "
 406           << fetch_state_.http_response_code;
 407
 408   source->GetResponseAsString(&fetch_state_.response_content);
 409   fetch_state_.response_headers = source->GetResponseHeaders();
 410   UpdateNetworkTime();
 411
 412   // End of the line for url_poster_. It lives only on the IO loop.
 413   // We defer deletion because we're inside a callback from a component of the
 414   // URLFetcher, so it seems most natural / "polite" to let the stack unwind.
 415   base::MessageLoop::current()->DeleteSoon(FROM_HERE, fetch_state_.url_poster);
 416   fetch_state_.url_poster = NULL;
 417
 418   // Wake the blocked syncer thread in MakeSynchronousPost.
 419   // WARNING: DONT DO ANYTHING AFTER THIS CALL! |this| may be deleted!
 420   http_post_completed_.Signal();
 421 }
 422
 423 void HttpBridge::OnURLFetchDownloadProgress(const net::URLFetcher* source,
 424                                             int64 current, int64 total) {
 425   DCHECK(network_task_runner_->BelongsToCurrentThread());
 426   // Reset the delay when forward progress is made.
 427   base::AutoLock lock(fetch_state_lock_);
 428   if (fetch_state_.http_request_timeout_timer.get())
 429     fetch_state_.http_request_timeout_timer->Reset();
 430 }
 431
 432 void HttpBridge::OnURLFetchUploadProgress(const net::URLFetcher* source,
 433                                           int64 current, int64 total) {
 434   DCHECK(network_task_runner_->BelongsToCurrentThread());
 435   // Reset the delay when forward progress is made.
 436   base::AutoLock lock(fetch_state_lock_);
 437   if (fetch_state_.http_request_timeout_timer.get())
 438     fetch_state_.http_request_timeout_timer->Reset();
 439 }
 440
 441 void HttpBridge::OnURLFetchTimedOut() {
 442   DCHECK(network_task_runner_->BelongsToCurrentThread());
 443
 444   base::AutoLock lock(fetch_state_lock_);
 445   if (!fetch_state_.url_poster)
 446     return;
 447
 448   LogTimeout(true);
 449   DVLOG(1) << "Sync url fetch timed out. Canceling.";
 450
 451   fetch_state_.end_time = base::Time::Now();
 452   fetch_state_.request_completed = true;
 453   fetch_state_.request_succeeded = false;
 454   fetch_state_.http_response_code = -1;
 455   fetch_state_.error_code = net::URLRequestStatus::FAILED;
 456
 457   // This method is called by the timer, not the url fetcher implementation,
 458   // so it's safe to delete the fetcher here.
 459   delete fetch_state_.url_poster;
 460   fetch_state_.url_poster = NULL;
 461
 462   // Timer is smart enough to handle being deleted as part of the invoked task.
 463   fetch_state_.http_request_timeout_timer.reset();
 464
 465   // Wake the blocked syncer thread in MakeSynchronousPost.
 466   // WARNING: DONT DO ANYTHING AFTER THIS CALL! |this| may be deleted!
 467   http_post_completed_.Signal();
 468 }
 469
 470 net::URLRequestContextGetter* HttpBridge::GetRequestContextGetterForTest()
 471     const {
 472   base::AutoLock lock(fetch_state_lock_);
 473   return context_getter_for_request_.get();
 474 }
 475
 476 void HttpBridge::UpdateNetworkTime() {
 477   std::string sane_time_str;
 478   if (!fetch_state_.request_succeeded || fetch_state_.start_time.is_null() ||
 479       fetch_state_.end_time < fetch_state_.start_time ||
 480       !fetch_state_.response_headers ||
 481       !fetch_state_.response_headers->EnumerateHeader(NULL, "Sane-Time-Millis",
 482                                                       &sane_time_str)) {
 483     return;
 484   }
 485
 486   int64 sane_time_ms = 0;
 487   if (base::StringToInt64(sane_time_str, &sane_time_ms)) {
 488     network_time_update_callback_.Run(
 489         base::Time::FromJsTime(sane_time_ms),
 490         base::TimeDelta::FromMilliseconds(1),
 491         fetch_state_.end_time - fetch_state_.start_time);
 492   }
 493 }
 494
 495 }  // namespace syncer