From 297653965e4ac1cc799018470e6a3e66192c51dd Mon Sep 17 00:00:00 2001 From: jianli Date: Thu, 18 Jun 2015 13:43:21 -0700 Subject: [PATCH] Stop retring GCM unregistration requests after reaching maximum number of retries Also, we should retry for HTTP_NOT_OK and NO_RESPONSE_BODY. BUG=501081 TEST=new tests Review URL: https://codereview.chromium.org/1194453002 Cr-Commit-Position: refs/heads/master@{#335116} --- components/gcm_driver/gcm_client_impl.cc | 2 + components/gcm_driver/gcm_stats_recorder_impl.cc | 15 +++--- components/gcm_driver/gcm_stats_recorder_impl.h | 3 +- .../gcm_driver/gcm_stats_recorder_impl_unittest.cc | 6 +-- google_apis/gcm/engine/unregistration_request.cc | 28 ++++++++-- google_apis/gcm/engine/unregistration_request.h | 3 ++ .../gcm/engine/unregistration_request_unittest.cc | 62 ++++++++++++++++++++-- .../gcm/monitoring/fake_gcm_stats_recorder.cc | 3 +- .../gcm/monitoring/fake_gcm_stats_recorder.h | 3 +- google_apis/gcm/monitoring/gcm_stats_recorder.h | 3 +- tools/metrics/histograms/histograms.xml | 1 + 11 files changed, 107 insertions(+), 22 deletions(-) diff --git a/components/gcm_driver/gcm_client_impl.cc b/components/gcm_driver/gcm_client_impl.cc index 8ffc69542322..cf745a8d1d3b 100644 --- a/components/gcm_driver/gcm_client_impl.cc +++ b/components/gcm_driver/gcm_client_impl.cc @@ -75,6 +75,7 @@ enum ResetStoreError { const char kGCMScope[] = "GCM"; const int kMaxRegistrationRetries = 5; +const int kMaxUnregistrationRetries = 5; const char kMessageTypeDataMessage[] = "gcm"; const char kMessageTypeDeletedMessagesKey[] = "deleted_messages"; const char kMessageTypeKey[] = "message_type"; @@ -1050,6 +1051,7 @@ void GCMClientImpl::Unregister( base::Bind(&GCMClientImpl::OnUnregisterCompleted, weak_ptr_factory_.GetWeakPtr(), registration_info), + kMaxUnregistrationRetries, url_request_context_getter_, &recorder_); pending_unregistration_requests_[registration_info] = unregistration_request; diff --git a/components/gcm_driver/gcm_stats_recorder_impl.cc b/components/gcm_driver/gcm_stats_recorder_impl.cc index 792202b21a67..010aa8e5c11c 100644 --- a/components/gcm_driver/gcm_stats_recorder_impl.cc +++ b/components/gcm_driver/gcm_stats_recorder_impl.cc @@ -339,14 +339,17 @@ void GCMStatsRecorderImpl::RecordUnregistrationResponse( void GCMStatsRecorderImpl::RecordUnregistrationRetryDelayed( const std::string& app_id, - int64 delay_msec) { + int64 delay_msec, + int retries_left) { if (!is_recording_) return; - RecordRegistration(app_id, - std::string(), - "Unregistration retry delayed", - base::StringPrintf("Delayed for %" PRId64 " msec", - delay_msec)); + RecordRegistration( + app_id, + std::string(), + "Unregistration retry delayed", + base::StringPrintf("Delayed for %" PRId64 " msec, retries left: %d", + delay_msec, + retries_left)); } void GCMStatsRecorderImpl::RecordReceiving( diff --git a/components/gcm_driver/gcm_stats_recorder_impl.h b/components/gcm_driver/gcm_stats_recorder_impl.h index a8d3e3bc9dae..d09ddf041c6e 100644 --- a/components/gcm_driver/gcm_stats_recorder_impl.h +++ b/components/gcm_driver/gcm_stats_recorder_impl.h @@ -68,7 +68,8 @@ class GCMStatsRecorderImpl : public GCMStatsRecorder { const std::string& app_id, UnregistrationRequest::Status status) override; void RecordUnregistrationRetryDelayed(const std::string& app_id, - int64 delay_msec) override; + int64 delay_msec, + int retries_left) override; void RecordDataMessageReceived(const std::string& app_id, const std::string& from, int message_byte_size, diff --git a/components/gcm_driver/gcm_stats_recorder_impl_unittest.cc b/components/gcm_driver/gcm_stats_recorder_impl_unittest.cc index e45ab59f2e4f..871378d79a21 100644 --- a/components/gcm_driver/gcm_stats_recorder_impl_unittest.cc +++ b/components/gcm_driver/gcm_stats_recorder_impl_unittest.cc @@ -77,7 +77,7 @@ static const char kUnregistrationResponseDetails[] = "SUCCESS"; static const char kUnregistrationRetryDelayedEvent[] = "Unregistration retry delayed"; static const char kUnregistrationRetryDelayedDetails[] = - "Delayed for 15000 msec"; + "Delayed for 15000 msec, retries left: 3"; static const char kDataReceivedEvent[] = "Data msg received"; static const char kDataReceivedDetails[] = ""; @@ -383,7 +383,7 @@ TEST_F(GCMStatsRecorderImplTest, StartStopRecordingTest) { recorder_.RecordRegistrationRetryRequested(kAppId, sender_ids_, kRetries); recorder_.RecordUnregistrationSent(kAppId); recorder_.RecordUnregistrationResponse(kAppId, kUnregistrationStatus); - recorder_.RecordUnregistrationRetryDelayed(kAppId, kDelay); + recorder_.RecordUnregistrationRetryDelayed(kAppId, kDelay, kRetries); VerifyAllActivityQueueEmpty("no unregistration"); recorder_.RecordDataMessageReceived(kAppId, kFrom, kByteSize, true, @@ -478,7 +478,7 @@ TEST_F(GCMStatsRecorderImplTest, RegistrationTest) { VerifyRecordedRegistrationCount(5); VerifyUnregistrationResponse("5th call"); - recorder_.RecordUnregistrationRetryDelayed(kAppId, kDelay); + recorder_.RecordUnregistrationRetryDelayed(kAppId, kDelay, kRetries); VerifyRecordedRegistrationCount(6); VerifyUnregistrationRetryDelayed("6th call"); } diff --git a/google_apis/gcm/engine/unregistration_request.cc b/google_apis/gcm/engine/unregistration_request.cc index bb68c72c09c4..90bda2f392d2 100644 --- a/google_apis/gcm/engine/unregistration_request.cc +++ b/google_apis/gcm/engine/unregistration_request.cc @@ -56,6 +56,7 @@ UnregistrationRequest::UnregistrationRequest( scoped_ptr custom_request_handler, const net::BackoffEntry::Policy& backoff_policy, const UnregistrationCallback& callback, + int max_retry_count, scoped_refptr request_context_getter, GCMStatsRecorder* recorder) : callback_(callback), @@ -64,8 +65,10 @@ UnregistrationRequest::UnregistrationRequest( registration_url_(registration_url), backoff_entry_(&backoff_policy), request_context_getter_(request_context_getter), + retries_left_(max_retry_count), recorder_(recorder), weak_ptr_factory_(this) { + DCHECK_GE(max_retry_count, 0); } UnregistrationRequest::~UnregistrationRequest() {} @@ -140,6 +143,8 @@ UnregistrationRequest::Status UnregistrationRequest::ParseResponse( void UnregistrationRequest::RetryWithBackoff(bool update_backoff) { if (update_backoff) { + DCHECK_GT(retries_left_, 0); + --retries_left_; url_fetcher_.reset(); backoff_entry_.InformOfRequest(false); } @@ -151,7 +156,8 @@ void UnregistrationRequest::RetryWithBackoff(bool update_backoff) { << " milliseconds."; recorder_->RecordUnregistrationRetryDelayed( request_info_.app_id, - backoff_entry_.GetTimeUntilRelease().InMilliseconds()); + backoff_entry_.GetTimeUntilRelease().InMilliseconds(), + retries_left_ + 1); base::MessageLoop::current()->PostDelayedTask( FROM_HERE, base::Bind(&UnregistrationRequest::RetryWithBackoff, @@ -178,16 +184,28 @@ void UnregistrationRequest::OnURLFetchComplete(const net::URLFetcher* source) { recorder_->RecordUnregistrationResponse(request_info_.app_id, status); if (status == URL_FETCHING_FAILED || + status == HTTP_NOT_OK || + status == NO_RESPONSE_BODY || status == SERVICE_UNAVAILABLE || status == INTERNAL_SERVER_ERROR || status == INCORRECT_APP_ID || status == RESPONSE_PARSING_FAILED) { - RetryWithBackoff(true); - return; + if (retries_left_ > 0) { + RetryWithBackoff(true); + return; + } + + status = REACHED_MAX_RETRIES; + recorder_->RecordUnregistrationResponse(request_info_.app_id, status); + + // Only REACHED_MAX_RETRIES is reported because the function will skip + // reporting count and time when status is not SUCCESS. + DCHECK(custom_request_handler_.get()); + custom_request_handler_->ReportUMAs(status, 0, base::TimeDelta()); } - // status == SUCCESS || HTTP_NOT_OK || NO_RESPONSE_BODY || - // INVALID_PARAMETERS || UNKNOWN_ERROR + // status == SUCCESS || INVALID_PARAMETERS || UNKNOWN_ERROR || + // REACHED_MAX_RETRIES callback_.Run(status); } diff --git a/google_apis/gcm/engine/unregistration_request.h b/google_apis/gcm/engine/unregistration_request.h index 0f54538f77b6..501a943bc803 100644 --- a/google_apis/gcm/engine/unregistration_request.h +++ b/google_apis/gcm/engine/unregistration_request.h @@ -46,6 +46,7 @@ class GCM_EXPORT UnregistrationRequest : public net::URLFetcherDelegate { INTERNAL_SERVER_ERROR, // Internal server error happened during request. HTTP_NOT_OK, // HTTP response code was not OK. UNKNOWN_ERROR, // Unknown error. + REACHED_MAX_RETRIES, // Reached maximum number of retries. // NOTE: Always keep this entry at the end. Add new status types only // immediately above this line. Make sure to update the corresponding // histogram enum accordingly. @@ -102,6 +103,7 @@ class GCM_EXPORT UnregistrationRequest : public net::URLFetcherDelegate { scoped_ptr custom_request_handler, const net::BackoffEntry::Policy& backoff_policy, const UnregistrationCallback& callback, + int max_retry_count, scoped_refptr request_context_getter, GCMStatsRecorder* recorder); ~UnregistrationRequest() override; @@ -130,6 +132,7 @@ class GCM_EXPORT UnregistrationRequest : public net::URLFetcherDelegate { scoped_refptr request_context_getter_; scoped_ptr url_fetcher_; base::TimeTicks request_start_time_; + int retries_left_; // Recorder that records GCM activities for debugging purpose. Not owned. GCMStatsRecorder* recorder_; diff --git a/google_apis/gcm/engine/unregistration_request_unittest.cc b/google_apis/gcm/engine/unregistration_request_unittest.cc index 2cdde2a5742a..3f587888420d 100644 --- a/google_apis/gcm/engine/unregistration_request_unittest.cc +++ b/google_apis/gcm/engine/unregistration_request_unittest.cc @@ -18,6 +18,7 @@ namespace gcm { namespace { +const int kMaxRetries = 2; const uint64 kAndroidId = 42UL; const char kLoginHeader[] = "AidLogin"; const char kAppId[] = "TestAppId"; @@ -36,7 +37,7 @@ const net::BackoffEntry::Policy kDefaultBackoffPolicy = { // exponential back-off rules. // Explicitly set to 2 to skip the delay on the first retry, as we are not // trying to test the backoff itself, but rather the fact that retry happens. - 1, + 2, // Initial delay for exponential back-off in ms. 15000, // 15 seconds. @@ -71,7 +72,13 @@ class UnregistrationRequestTest : public testing::Test { const std::string& response_body); void CompleteFetch(); + int max_retry_count() const { return max_retry_count_; } + void set_max_retry_count(int max_retry_count) { + max_retry_count_ = max_retry_count; + } + protected: + int max_retry_count_; bool callback_called_; UnregistrationRequest::Status status_; scoped_ptr request_; @@ -82,7 +89,8 @@ class UnregistrationRequestTest : public testing::Test { }; UnregistrationRequestTest::UnregistrationRequestTest() - : callback_called_(false), + : max_retry_count_(kMaxRetries), + callback_called_(false), status_(UnregistrationRequest::UNREGISTRATION_STATUS_COUNT), url_request_context_getter_(new net::TestURLRequestContextGetter( message_loop_.task_runner())) {} @@ -138,6 +146,7 @@ void GCMUnregistrationRequestTest::CreateRequest() { kDefaultBackoffPolicy, base::Bind(&UnregistrationRequestTest::UnregistrationCallback, base::Unretained(this)), + max_retry_count_, url_request_context_getter_.get(), &recorder_)); } @@ -191,6 +200,7 @@ TEST_F(GCMUnregistrationRequestTest, RequestDataPassedToFetcher) { } TEST_F(GCMUnregistrationRequestTest, SuccessfulUnregistration) { + set_max_retry_count(0); CreateRequest(); request_->Start(); @@ -208,8 +218,13 @@ TEST_F(GCMUnregistrationRequestTest, ResponseHttpStatusNotOK) { SetResponseStatusAndString(net::HTTP_UNAUTHORIZED, ""); CompleteFetch(); + EXPECT_FALSE(callback_called_); + + SetResponseStatusAndString(net::HTTP_OK, kDeletedAppId); + CompleteFetch(); + EXPECT_TRUE(callback_called_); - EXPECT_EQ(UnregistrationRequest::HTTP_NOT_OK, status_); + EXPECT_EQ(UnregistrationRequest::SUCCESS, status_); } TEST_F(GCMUnregistrationRequestTest, ResponseEmpty) { @@ -314,6 +329,39 @@ TEST_F(GCMUnregistrationRequestTest, ResponseParsingFailed) { EXPECT_EQ(UnregistrationRequest::SUCCESS, status_); } +TEST_F(GCMUnregistrationRequestTest, MaximumAttemptsReachedWithZeroRetries) { + set_max_retry_count(0); + CreateRequest(); + request_->Start(); + + SetResponseStatusAndString(net::HTTP_GATEWAY_TIMEOUT, "bad response"); + CompleteFetch(); + + EXPECT_TRUE(callback_called_); + EXPECT_EQ(UnregistrationRequest::REACHED_MAX_RETRIES, status_); +} + +TEST_F(GCMUnregistrationRequestTest, MaximumAttemptsReached) { + CreateRequest(); + request_->Start(); + + SetResponseStatusAndString(net::HTTP_GATEWAY_TIMEOUT, "bad response"); + CompleteFetch(); + + EXPECT_FALSE(callback_called_); + + SetResponseStatusAndString(net::HTTP_GATEWAY_TIMEOUT, "bad response"); + CompleteFetch(); + + EXPECT_FALSE(callback_called_); + + SetResponseStatusAndString(net::HTTP_GATEWAY_TIMEOUT, "bad response"); + CompleteFetch(); + + EXPECT_TRUE(callback_called_); + EXPECT_EQ(UnregistrationRequest::REACHED_MAX_RETRIES, status_); +} + class InstaceIDDeleteTokenRequestTest : public UnregistrationRequestTest { public: InstaceIDDeleteTokenRequestTest(); @@ -346,6 +394,7 @@ void InstaceIDDeleteTokenRequestTest::CreateRequest( kDefaultBackoffPolicy, base::Bind(&UnregistrationRequestTest::UnregistrationCallback, base::Unretained(this)), + max_retry_count(), url_request_context_getter_.get(), &recorder_)); } @@ -420,8 +469,13 @@ TEST_F(InstaceIDDeleteTokenRequestTest, ResponseHttpStatusNotOK) { SetResponseStatusAndString(net::HTTP_UNAUTHORIZED, ""); CompleteFetch(); + EXPECT_FALSE(callback_called_); + + SetResponseStatusAndString(net::HTTP_OK, kDeletedToken); + CompleteFetch(); + EXPECT_TRUE(callback_called_); - EXPECT_EQ(UnregistrationRequest::HTTP_NOT_OK, status_); + EXPECT_EQ(UnregistrationRequest::SUCCESS, status_); } } // namespace gcm diff --git a/google_apis/gcm/monitoring/fake_gcm_stats_recorder.cc b/google_apis/gcm/monitoring/fake_gcm_stats_recorder.cc index 0388d24a5033..d4c781e8317b 100644 --- a/google_apis/gcm/monitoring/fake_gcm_stats_recorder.cc +++ b/google_apis/gcm/monitoring/fake_gcm_stats_recorder.cc @@ -70,7 +70,8 @@ void FakeGCMStatsRecorder::RecordUnregistrationResponse( void FakeGCMStatsRecorder::RecordUnregistrationRetryDelayed( const std::string& app_id, - int64 delay_msec) { + int64 delay_msec, + int retries_left) { } void FakeGCMStatsRecorder::RecordDataMessageReceived( diff --git a/google_apis/gcm/monitoring/fake_gcm_stats_recorder.h b/google_apis/gcm/monitoring/fake_gcm_stats_recorder.h index 5dcd44838f03..a48146c071aa 100644 --- a/google_apis/gcm/monitoring/fake_gcm_stats_recorder.h +++ b/google_apis/gcm/monitoring/fake_gcm_stats_recorder.h @@ -39,7 +39,8 @@ class FakeGCMStatsRecorder : public GCMStatsRecorder { const std::string& app_id, UnregistrationRequest::Status status) override; void RecordUnregistrationRetryDelayed(const std::string& app_id, - int64 delay_msec) override; + int64 delay_msec, + int retries_left) override; void RecordDataMessageReceived(const std::string& app_id, const std::string& from, int message_byte_size, diff --git a/google_apis/gcm/monitoring/gcm_stats_recorder.h b/google_apis/gcm/monitoring/gcm_stats_recorder.h index 83367d8ee146..5b493f840bc4 100644 --- a/google_apis/gcm/monitoring/gcm_stats_recorder.h +++ b/google_apis/gcm/monitoring/gcm_stats_recorder.h @@ -100,7 +100,8 @@ class GCM_EXPORT GCMStatsRecorder { // Records that an unregistration retry has been requested and delayed due to // backoff logic. virtual void RecordUnregistrationRetryDelayed(const std::string& app_id, - int64 delay_msec) = 0; + int64 delay_msec, + int retries_left) = 0; // Records that a data message has been received. If this message is not // sent to a registered app, to_registered_app shoudl be false. If it diff --git a/tools/metrics/histograms/histograms.xml b/tools/metrics/histograms/histograms.xml index 25cabd0f1136..2d80b30e31c5 100644 --- a/tools/metrics/histograms/histograms.xml +++ b/tools/metrics/histograms/histograms.xml @@ -56644,6 +56644,7 @@ http://cs/file:chrome/histograms.xml - but prefer this file for new entries. + -- 2.11.4.GIT