| OLD | NEW |
| (Empty) |
| 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 "components/sync/core/http_bridge.h" | |
| 6 | |
| 7 #include <stddef.h> | |
| 8 | |
| 9 #include <vector> | |
| 10 | |
| 11 #include "base/bit_cast.h" | |
| 12 #include "base/location.h" | |
| 13 #include "base/metrics/histogram_macros.h" | |
| 14 #include "base/metrics/sparse_histogram.h" | |
| 15 #include "base/single_thread_task_runner.h" | |
| 16 #include "base/strings/string_number_conversions.h" | |
| 17 #include "base/strings/stringprintf.h" | |
| 18 #include "base/threading/thread_task_runner_handle.h" | |
| 19 #include "components/sync/base/cancelation_signal.h" | |
| 20 #include "net/base/load_flags.h" | |
| 21 #include "net/base/net_errors.h" | |
| 22 #include "net/http/http_cache.h" | |
| 23 #include "net/http/http_network_layer.h" | |
| 24 #include "net/http/http_request_headers.h" | |
| 25 #include "net/http/http_response_headers.h" | |
| 26 #include "net/url_request/static_http_user_agent_settings.h" | |
| 27 #include "net/url_request/url_fetcher.h" | |
| 28 #include "net/url_request/url_request_job_factory_impl.h" | |
| 29 #include "net/url_request/url_request_status.h" | |
| 30 | |
| 31 namespace syncer { | |
| 32 | |
| 33 namespace { | |
| 34 | |
| 35 // It's possible for an http request to be silently stalled. We set a time | |
| 36 // limit for all http requests, beyond which the request is cancelled and | |
| 37 // treated as a transient failure. | |
| 38 const int kMaxHttpRequestTimeSeconds = 60 * 5; // 5 minutes. | |
| 39 | |
| 40 // Helper method for logging timeouts via UMA. | |
| 41 void LogTimeout(bool timed_out) { | |
| 42 UMA_HISTOGRAM_BOOLEAN("Sync.URLFetchTimedOut", timed_out); | |
| 43 } | |
| 44 | |
| 45 void RecordSyncRequestContentLengthHistograms(int64_t compressed_content_length, | |
| 46 int64_t original_content_length) { | |
| 47 UMA_HISTOGRAM_COUNTS("Sync.RequestContentLength.Compressed", | |
| 48 compressed_content_length); | |
| 49 UMA_HISTOGRAM_COUNTS("Sync.RequestContentLength.Original", | |
| 50 original_content_length); | |
| 51 } | |
| 52 | |
| 53 void RecordSyncResponseContentLengthHistograms( | |
| 54 int64_t compressed_content_length, | |
| 55 int64_t original_content_length) { | |
| 56 UMA_HISTOGRAM_COUNTS("Sync.ResponseContentLength.Compressed", | |
| 57 compressed_content_length); | |
| 58 UMA_HISTOGRAM_COUNTS("Sync.ResponseContentLength.Original", | |
| 59 original_content_length); | |
| 60 } | |
| 61 | |
| 62 } // namespace | |
| 63 | |
| 64 HttpBridgeFactory::HttpBridgeFactory( | |
| 65 const scoped_refptr<net::URLRequestContextGetter>& request_context_getter, | |
| 66 const NetworkTimeUpdateCallback& network_time_update_callback, | |
| 67 CancelationSignal* cancelation_signal) | |
| 68 : request_context_getter_(request_context_getter), | |
| 69 network_time_update_callback_(network_time_update_callback), | |
| 70 cancelation_signal_(cancelation_signal) { | |
| 71 // Registration should never fail. This should happen on the UI thread during | |
| 72 // init. It would be impossible for a shutdown to have been requested at this | |
| 73 // point. | |
| 74 bool result = cancelation_signal_->TryRegisterHandler(this); | |
| 75 DCHECK(result); | |
| 76 } | |
| 77 | |
| 78 HttpBridgeFactory::~HttpBridgeFactory() { | |
| 79 cancelation_signal_->UnregisterHandler(this); | |
| 80 } | |
| 81 | |
| 82 void HttpBridgeFactory::Init( | |
| 83 const std::string& user_agent, | |
| 84 const BindToTrackerCallback& bind_to_tracker_callback) { | |
| 85 user_agent_ = user_agent; | |
| 86 bind_to_tracker_callback_ = bind_to_tracker_callback; | |
| 87 } | |
| 88 | |
| 89 HttpPostProviderInterface* HttpBridgeFactory::Create() { | |
| 90 base::AutoLock lock(request_context_getter_lock_); | |
| 91 | |
| 92 // If we've been asked to shut down (something which may happen asynchronously | |
| 93 // and at pretty much any time), then we won't have a request_context_getter_. | |
| 94 // Some external mechanism must ensure that this function is not called after | |
| 95 // we've been asked to shut down. | |
| 96 CHECK(request_context_getter_.get()); | |
| 97 | |
| 98 scoped_refptr<HttpBridge> http = | |
| 99 new HttpBridge(user_agent_, request_context_getter_, | |
| 100 network_time_update_callback_, bind_to_tracker_callback_); | |
| 101 http->AddRef(); | |
| 102 return http.get(); | |
| 103 } | |
| 104 | |
| 105 void HttpBridgeFactory::Destroy(HttpPostProviderInterface* http) { | |
| 106 static_cast<HttpBridge*>(http)->Release(); | |
| 107 } | |
| 108 | |
| 109 void HttpBridgeFactory::OnSignalReceived() { | |
| 110 base::AutoLock lock(request_context_getter_lock_); | |
| 111 // Release |request_context_getter_| as soon as possible so that it | |
| 112 // is destroyed in the right order on its network task runner. | |
| 113 request_context_getter_ = NULL; | |
| 114 } | |
| 115 | |
| 116 HttpBridge::URLFetchState::URLFetchState() | |
| 117 : url_poster(NULL), | |
| 118 aborted(false), | |
| 119 request_completed(false), | |
| 120 request_succeeded(false), | |
| 121 http_response_code(-1), | |
| 122 error_code(-1) {} | |
| 123 HttpBridge::URLFetchState::~URLFetchState() {} | |
| 124 | |
| 125 HttpBridge::HttpBridge( | |
| 126 const std::string& user_agent, | |
| 127 const scoped_refptr<net::URLRequestContextGetter>& context_getter, | |
| 128 const NetworkTimeUpdateCallback& network_time_update_callback, | |
| 129 const BindToTrackerCallback& bind_to_tracker_callback) | |
| 130 : user_agent_(user_agent), | |
| 131 http_post_completed_(base::WaitableEvent::ResetPolicy::AUTOMATIC, | |
| 132 base::WaitableEvent::InitialState::NOT_SIGNALED), | |
| 133 request_context_getter_(context_getter), | |
| 134 network_task_runner_(request_context_getter_->GetNetworkTaskRunner()), | |
| 135 network_time_update_callback_(network_time_update_callback), | |
| 136 bind_to_tracker_callback_(bind_to_tracker_callback) {} | |
| 137 | |
| 138 HttpBridge::~HttpBridge() {} | |
| 139 | |
| 140 void HttpBridge::SetExtraRequestHeaders(const char* headers) { | |
| 141 DCHECK(extra_headers_.empty()) | |
| 142 << "HttpBridge::SetExtraRequestHeaders called twice."; | |
| 143 extra_headers_.assign(headers); | |
| 144 } | |
| 145 | |
| 146 void HttpBridge::SetURL(const char* url, int port) { | |
| 147 #if DCHECK_IS_ON() | |
| 148 DCHECK(thread_checker_.CalledOnValidThread()); | |
| 149 { | |
| 150 base::AutoLock lock(fetch_state_lock_); | |
| 151 DCHECK(!fetch_state_.request_completed); | |
| 152 } | |
| 153 DCHECK(url_for_request_.is_empty()) | |
| 154 << "HttpBridge::SetURL called more than once?!"; | |
| 155 #endif | |
| 156 GURL temp(url); | |
| 157 GURL::Replacements replacements; | |
| 158 std::string port_str = base::IntToString(port); | |
| 159 replacements.SetPort(port_str.c_str(), url::Component(0, port_str.length())); | |
| 160 url_for_request_ = temp.ReplaceComponents(replacements); | |
| 161 } | |
| 162 | |
| 163 void HttpBridge::SetPostPayload(const char* content_type, | |
| 164 int content_length, | |
| 165 const char* content) { | |
| 166 #if DCHECK_IS_ON() | |
| 167 DCHECK(thread_checker_.CalledOnValidThread()); | |
| 168 { | |
| 169 base::AutoLock lock(fetch_state_lock_); | |
| 170 DCHECK(!fetch_state_.request_completed); | |
| 171 } | |
| 172 DCHECK(content_type_.empty()) << "Bridge payload already set."; | |
| 173 DCHECK_GE(content_length, 0) << "Content length < 0"; | |
| 174 #endif | |
| 175 content_type_ = content_type; | |
| 176 if (!content || (content_length == 0)) { | |
| 177 DCHECK_EQ(content_length, 0); | |
| 178 request_content_ = " "; // TODO(timsteele): URLFetcher requires non-empty | |
| 179 // content for POSTs whereas CURL does not, for now | |
| 180 // we hack this to support the sync backend. | |
| 181 } else { | |
| 182 request_content_.assign(content, content_length); | |
| 183 } | |
| 184 } | |
| 185 | |
| 186 bool HttpBridge::MakeSynchronousPost(int* error_code, int* response_code) { | |
| 187 #if DCHECK_IS_ON() | |
| 188 DCHECK(thread_checker_.CalledOnValidThread()); | |
| 189 { | |
| 190 base::AutoLock lock(fetch_state_lock_); | |
| 191 DCHECK(!fetch_state_.request_completed); | |
| 192 } | |
| 193 DCHECK(url_for_request_.is_valid()) << "Invalid URL for request"; | |
| 194 DCHECK(!content_type_.empty()) << "Payload not set"; | |
| 195 #endif | |
| 196 | |
| 197 if (!network_task_runner_->PostTask( | |
| 198 FROM_HERE, base::Bind(&HttpBridge::CallMakeAsynchronousPost, this))) { | |
| 199 // This usually happens when we're in a unit test. | |
| 200 LOG(WARNING) << "Could not post CallMakeAsynchronousPost task"; | |
| 201 return false; | |
| 202 } | |
| 203 | |
| 204 // Block until network request completes or is aborted. See | |
| 205 // OnURLFetchComplete and Abort. | |
| 206 http_post_completed_.Wait(); | |
| 207 | |
| 208 base::AutoLock lock(fetch_state_lock_); | |
| 209 DCHECK(fetch_state_.request_completed || fetch_state_.aborted); | |
| 210 *error_code = fetch_state_.error_code; | |
| 211 *response_code = fetch_state_.http_response_code; | |
| 212 return fetch_state_.request_succeeded; | |
| 213 } | |
| 214 | |
| 215 void HttpBridge::MakeAsynchronousPost() { | |
| 216 DCHECK(network_task_runner_->BelongsToCurrentThread()); | |
| 217 | |
| 218 base::AutoLock lock(fetch_state_lock_); | |
| 219 DCHECK(!fetch_state_.request_completed); | |
| 220 if (fetch_state_.aborted) | |
| 221 return; | |
| 222 | |
| 223 // Start the timer on the network thread (the same thread progress is made | |
| 224 // on, and on which the url fetcher lives). | |
| 225 DCHECK(!fetch_state_.http_request_timeout_timer.get()); | |
| 226 fetch_state_.http_request_timeout_timer.reset(new base::Timer(false, false)); | |
| 227 fetch_state_.http_request_timeout_timer->Start( | |
| 228 FROM_HERE, base::TimeDelta::FromSeconds(kMaxHttpRequestTimeSeconds), | |
| 229 base::Bind(&HttpBridge::OnURLFetchTimedOut, this)); | |
| 230 | |
| 231 DCHECK(request_context_getter_.get()); | |
| 232 fetch_state_.start_time = base::Time::Now(); | |
| 233 fetch_state_.url_poster = | |
| 234 net::URLFetcher::Create(url_for_request_, net::URLFetcher::POST, this) | |
| 235 .release(); | |
| 236 if (!bind_to_tracker_callback_.is_null()) | |
| 237 bind_to_tracker_callback_.Run(fetch_state_.url_poster); | |
| 238 fetch_state_.url_poster->SetRequestContext(request_context_getter_.get()); | |
| 239 fetch_state_.url_poster->SetExtraRequestHeaders(extra_headers_); | |
| 240 | |
| 241 fetch_state_.url_poster->SetUploadData(content_type_, request_content_); | |
| 242 RecordSyncRequestContentLengthHistograms(request_content_.size(), | |
| 243 request_content_.size()); | |
| 244 | |
| 245 fetch_state_.url_poster->AddExtraRequestHeader(base::StringPrintf( | |
| 246 "%s: %s", net::HttpRequestHeaders::kUserAgent, user_agent_.c_str())); | |
| 247 fetch_state_.url_poster->SetLoadFlags( | |
| 248 net::LOAD_BYPASS_CACHE | net::LOAD_DISABLE_CACHE | | |
| 249 net::LOAD_DO_NOT_SAVE_COOKIES | net::LOAD_DO_NOT_SEND_COOKIES); | |
| 250 | |
| 251 fetch_state_.url_poster->Start(); | |
| 252 } | |
| 253 | |
| 254 int HttpBridge::GetResponseContentLength() const { | |
| 255 DCHECK(thread_checker_.CalledOnValidThread()); | |
| 256 base::AutoLock lock(fetch_state_lock_); | |
| 257 DCHECK(fetch_state_.request_completed); | |
| 258 return fetch_state_.response_content.size(); | |
| 259 } | |
| 260 | |
| 261 const char* HttpBridge::GetResponseContent() const { | |
| 262 DCHECK(thread_checker_.CalledOnValidThread()); | |
| 263 base::AutoLock lock(fetch_state_lock_); | |
| 264 DCHECK(fetch_state_.request_completed); | |
| 265 return fetch_state_.response_content.data(); | |
| 266 } | |
| 267 | |
| 268 const std::string HttpBridge::GetResponseHeaderValue( | |
| 269 const std::string& name) const { | |
| 270 DCHECK(thread_checker_.CalledOnValidThread()); | |
| 271 base::AutoLock lock(fetch_state_lock_); | |
| 272 DCHECK(fetch_state_.request_completed); | |
| 273 | |
| 274 std::string value; | |
| 275 fetch_state_.response_headers->EnumerateHeader(NULL, name, &value); | |
| 276 return value; | |
| 277 } | |
| 278 | |
| 279 void HttpBridge::Abort() { | |
| 280 base::AutoLock lock(fetch_state_lock_); | |
| 281 | |
| 282 // Release |request_context_getter_| as soon as possible so that it is | |
| 283 // destroyed in the right order on its network task runner. | |
| 284 request_context_getter_ = NULL; | |
| 285 | |
| 286 DCHECK(!fetch_state_.aborted); | |
| 287 if (fetch_state_.aborted || fetch_state_.request_completed) | |
| 288 return; | |
| 289 | |
| 290 fetch_state_.aborted = true; | |
| 291 if (!network_task_runner_->PostTask( | |
| 292 FROM_HERE, | |
| 293 base::Bind(&HttpBridge::DestroyURLFetcherOnIOThread, this, | |
| 294 fetch_state_.url_poster, | |
| 295 fetch_state_.http_request_timeout_timer.release()))) { | |
| 296 // Madness ensues. | |
| 297 NOTREACHED() << "Could not post task to delete URLFetcher"; | |
| 298 } | |
| 299 | |
| 300 fetch_state_.url_poster = NULL; | |
| 301 fetch_state_.error_code = net::ERR_ABORTED; | |
| 302 http_post_completed_.Signal(); | |
| 303 } | |
| 304 | |
| 305 void HttpBridge::DestroyURLFetcherOnIOThread(net::URLFetcher* fetcher, | |
| 306 base::Timer* fetch_timer) { | |
| 307 DCHECK(network_task_runner_->BelongsToCurrentThread()); | |
| 308 if (fetch_timer) | |
| 309 delete fetch_timer; | |
| 310 delete fetcher; | |
| 311 } | |
| 312 | |
| 313 void HttpBridge::OnURLFetchComplete(const net::URLFetcher* source) { | |
| 314 DCHECK(network_task_runner_->BelongsToCurrentThread()); | |
| 315 | |
| 316 base::AutoLock lock(fetch_state_lock_); | |
| 317 | |
| 318 // Stop the request timer now that the request completed. | |
| 319 if (fetch_state_.http_request_timeout_timer.get()) | |
| 320 fetch_state_.http_request_timeout_timer.reset(); | |
| 321 | |
| 322 if (fetch_state_.aborted) | |
| 323 return; | |
| 324 | |
| 325 fetch_state_.end_time = base::Time::Now(); | |
| 326 fetch_state_.request_completed = true; | |
| 327 fetch_state_.request_succeeded = | |
| 328 (net::URLRequestStatus::SUCCESS == source->GetStatus().status()); | |
| 329 fetch_state_.http_response_code = source->GetResponseCode(); | |
| 330 fetch_state_.error_code = source->GetStatus().error(); | |
| 331 | |
| 332 if (fetch_state_.request_succeeded) | |
| 333 LogTimeout(false); | |
| 334 UMA_HISTOGRAM_SPARSE_SLOWLY("Sync.URLFetchResponse", | |
| 335 source->GetStatus().is_success() | |
| 336 ? source->GetResponseCode() | |
| 337 : source->GetStatus().ToNetError()); | |
| 338 UMA_HISTOGRAM_LONG_TIMES("Sync.URLFetchTime", | |
| 339 fetch_state_.end_time - fetch_state_.start_time); | |
| 340 | |
| 341 // Use a real (non-debug) log to facilitate troubleshooting in the wild. | |
| 342 VLOG(2) << "HttpBridge::OnURLFetchComplete for: " | |
| 343 << fetch_state_.url_poster->GetURL().spec(); | |
| 344 VLOG(1) << "HttpBridge received response code: " | |
| 345 << fetch_state_.http_response_code; | |
| 346 | |
| 347 source->GetResponseAsString(&fetch_state_.response_content); | |
| 348 fetch_state_.response_headers = source->GetResponseHeaders(); | |
| 349 UpdateNetworkTime(); | |
| 350 | |
| 351 int64_t original_content_length = fetch_state_.response_content.size(); | |
| 352 int64_t compressed_content_length = | |
| 353 source->GetReceivedResponseContentLength(); | |
| 354 RecordSyncResponseContentLengthHistograms(compressed_content_length, | |
| 355 original_content_length); | |
| 356 | |
| 357 // End of the line for url_poster_. It lives only on the IO loop. | |
| 358 // We defer deletion because we're inside a callback from a component of the | |
| 359 // URLFetcher, so it seems most natural / "polite" to let the stack unwind. | |
| 360 base::ThreadTaskRunnerHandle::Get()->DeleteSoon(FROM_HERE, | |
| 361 fetch_state_.url_poster); | |
| 362 fetch_state_.url_poster = NULL; | |
| 363 | |
| 364 // Wake the blocked syncer thread in MakeSynchronousPost. | |
| 365 // WARNING: DONT DO ANYTHING AFTER THIS CALL! |this| may be deleted! | |
| 366 http_post_completed_.Signal(); | |
| 367 } | |
| 368 | |
| 369 void HttpBridge::OnURLFetchDownloadProgress(const net::URLFetcher* source, | |
| 370 int64_t current, | |
| 371 int64_t total, | |
| 372 int64_t current_network_bytes) { | |
| 373 DCHECK(network_task_runner_->BelongsToCurrentThread()); | |
| 374 // Reset the delay when forward progress is made. | |
| 375 base::AutoLock lock(fetch_state_lock_); | |
| 376 if (fetch_state_.http_request_timeout_timer.get()) | |
| 377 fetch_state_.http_request_timeout_timer->Reset(); | |
| 378 } | |
| 379 | |
| 380 void HttpBridge::OnURLFetchUploadProgress(const net::URLFetcher* source, | |
| 381 int64_t current, | |
| 382 int64_t total) { | |
| 383 DCHECK(network_task_runner_->BelongsToCurrentThread()); | |
| 384 // Reset the delay when forward progress is made. | |
| 385 base::AutoLock lock(fetch_state_lock_); | |
| 386 if (fetch_state_.http_request_timeout_timer.get()) | |
| 387 fetch_state_.http_request_timeout_timer->Reset(); | |
| 388 } | |
| 389 | |
| 390 void HttpBridge::OnURLFetchTimedOut() { | |
| 391 DCHECK(network_task_runner_->BelongsToCurrentThread()); | |
| 392 | |
| 393 base::AutoLock lock(fetch_state_lock_); | |
| 394 if (!fetch_state_.url_poster) | |
| 395 return; | |
| 396 | |
| 397 LogTimeout(true); | |
| 398 DVLOG(1) << "Sync url fetch timed out. Canceling."; | |
| 399 | |
| 400 fetch_state_.end_time = base::Time::Now(); | |
| 401 fetch_state_.request_completed = true; | |
| 402 fetch_state_.request_succeeded = false; | |
| 403 fetch_state_.http_response_code = -1; | |
| 404 fetch_state_.error_code = net::ERR_TIMED_OUT; | |
| 405 | |
| 406 // This method is called by the timer, not the url fetcher implementation, | |
| 407 // so it's safe to delete the fetcher here. | |
| 408 delete fetch_state_.url_poster; | |
| 409 fetch_state_.url_poster = NULL; | |
| 410 | |
| 411 // Timer is smart enough to handle being deleted as part of the invoked task. | |
| 412 fetch_state_.http_request_timeout_timer.reset(); | |
| 413 | |
| 414 // Wake the blocked syncer thread in MakeSynchronousPost. | |
| 415 // WARNING: DONT DO ANYTHING AFTER THIS CALL! |this| may be deleted! | |
| 416 http_post_completed_.Signal(); | |
| 417 } | |
| 418 | |
| 419 net::URLRequestContextGetter* HttpBridge::GetRequestContextGetterForTest() | |
| 420 const { | |
| 421 base::AutoLock lock(fetch_state_lock_); | |
| 422 return request_context_getter_.get(); | |
| 423 } | |
| 424 | |
| 425 void HttpBridge::UpdateNetworkTime() { | |
| 426 std::string sane_time_str; | |
| 427 if (!fetch_state_.request_succeeded || fetch_state_.start_time.is_null() || | |
| 428 fetch_state_.end_time < fetch_state_.start_time || | |
| 429 !fetch_state_.response_headers || | |
| 430 !fetch_state_.response_headers->EnumerateHeader(NULL, "Sane-Time-Millis", | |
| 431 &sane_time_str)) { | |
| 432 return; | |
| 433 } | |
| 434 | |
| 435 int64_t sane_time_ms = 0; | |
| 436 if (base::StringToInt64(sane_time_str, &sane_time_ms)) { | |
| 437 network_time_update_callback_.Run( | |
| 438 base::Time::FromJsTime(sane_time_ms), | |
| 439 base::TimeDelta::FromMilliseconds(1), | |
| 440 fetch_state_.end_time - fetch_state_.start_time); | |
| 441 } | |
| 442 } | |
| 443 | |
| 444 } // namespace syncer | |
| OLD | NEW |