[GCM] Make heartbeat manager partially resistant to missed heartbeats

Chrome does not account for time the machine spends in suspend mode when
handling most timers and delayed tasks. As such, a heartbeat with a 15 minute
timer might actually run after X + 15 minutes, where X is the time spent in
suspend mode (for example when the laptop is in low power mode).

This patch attempts to mitigate that by polling every 5 minutes to see if the
heartbeat has been missed. 5 minutes is chosen as a conservative number. We
have UMA histograms to track how much the heartbeat was missed by, and if 5
minutes is too conservative the delta's will be high, and we can adjust the
time.

BUG=421725

Review URL: https://codereview.chromium.org/653283010

Cr-Commit-Position: refs/heads/master@{#301724}

3 files changed, 73 insertions, 0 deletions

diff --git a/google_apis/gcm/engine/heartbeat_manager.cc b/google_apis/gcm/engine/heartbeat_manager.cc
index 022b059..b6b0e88 100644
--- a/google_apis/gcm/engine/heartbeat_manager.cc
+++ b/google_apis/gcm/engine/heartbeat_manager.cc
@@ -4,6 +4,7 @@
 
 #include "google_apis/gcm/engine/heartbeat_manager.h"
 
+#include "base/metrics/histogram.h"
 #include "base/timer/timer.h"
 #include "google_apis/gcm/protocol/mcs.pb.h"
 #include "net/base/network_change_notifier.h"
@@ -17,6 +18,10 @@ const int64 kCellHeartbeatDefaultMs = 1000 * 60 * 28;  // 28 minutes.
 const int64 kWifiHeartbeatDefaultMs = 1000 * 60 * 15;  // 15 minutes.
 // The default heartbeat ack interval.
 const int64 kHeartbeatAckDefaultMs = 1000 * 60 * 1;  // 1 minute.
+// The period at which to check if the heartbeat time has passed. Used to
+// protect against platforms where the timer is delayed by the system being
+// suspended.
+const int kHeartbeatMissedCheckMs = 1000 * 60 * 5;  // 5 minutes.
 }  // namespace
 
 HeartbeatManager::HeartbeatManager(scoped_ptr<base::Timer> heartbeat_timer)
@@ -42,6 +47,7 @@ void HeartbeatManager::Start(
 }
 
 void HeartbeatManager::Stop() {
+  heartbeat_expected_time_ = base::Time();
   heartbeat_timer_->Stop();
   waiting_for_ack_ = false;
 }
@@ -75,6 +81,9 @@ base::TimeTicks HeartbeatManager::GetNextHeartbeatTime() const {
 }
 
 void HeartbeatManager::OnHeartbeatTriggered() {
+  // Reset the weak pointers used for heartbeat checks.
+  weak_ptr_factory_.InvalidateWeakPtrs();
+
   if (waiting_for_ack_) {
     LOG(WARNING) << "Lost connection to MCS, reconnecting.";
     Stop();
@@ -109,11 +118,45 @@ void HeartbeatManager::RestartTimer() {
     DVLOG(1) << "Resetting timer for ack with "
              << heartbeat_interval_ms_ << " ms interval.";
   }
+
+  heartbeat_expected_time_ =
+      base::Time::Now() +
+      base::TimeDelta::FromMilliseconds(heartbeat_interval_ms_);
   heartbeat_timer_->Start(FROM_HERE,
                          base::TimeDelta::FromMilliseconds(
                              heartbeat_interval_ms_),
                          base::Bind(&HeartbeatManager::OnHeartbeatTriggered,
                                     weak_ptr_factory_.GetWeakPtr()));
+
+  // TODO(zea): Polling is not a particularly good way to detect the missed
+  // heartbeat. Ideally we should be listening to wake-from-suspend events,
+  // although that would require platform-specific implementations.
+  base::MessageLoop::current()->PostDelayedTask(
+      FROM_HERE,
+      base::Bind(&HeartbeatManager::CheckForMissedHeartbeat,
+                 weak_ptr_factory_.GetWeakPtr()),
+      base::TimeDelta::FromMilliseconds(kHeartbeatMissedCheckMs));
+}
+
+void HeartbeatManager::CheckForMissedHeartbeat() {
+  // If there's no heartbeat pending, return without doing anything.
+  if (heartbeat_expected_time_.is_null())
+    return;
+
+  // If the heartbeat has been missed, manually trigger it.
+  if (base::Time::Now() > heartbeat_expected_time_) {
+    UMA_HISTOGRAM_LONG_TIMES("GCM.HeartbeatMissedDelta",
+                             base::Time::Now() - heartbeat_expected_time_);
+    OnHeartbeatTriggered();
+    return;
+  }
+
+  // Otherwise check again later.
+  base::MessageLoop::current()->PostDelayedTask(
+      FROM_HERE,
+      base::Bind(&HeartbeatManager::CheckForMissedHeartbeat,
+                 weak_ptr_factory_.GetWeakPtr()),
+      base::TimeDelta::FromMilliseconds(kHeartbeatMissedCheckMs));
 }
 
 }  // namespace gcm
diff --git a/google_apis/gcm/engine/heartbeat_manager.h b/google_apis/gcm/engine/heartbeat_manager.h
index 086e411..a0a186e 100644
--- a/google_apis/gcm/engine/heartbeat_manager.h
+++ b/google_apis/gcm/engine/heartbeat_manager.h
@@ -56,10 +56,19 @@ class GCM_EXPORT HeartbeatManager {
   // Helper method to send heartbeat on timer trigger.
   void OnHeartbeatTriggered();
 
+  // Periodic check to see if the heartbeat has been missed due to some system
+  // issue (e.g. the machine was suspended and the timer did not account for
+  // that).
+  void CheckForMissedHeartbeat();
+
  private:
   // Restarts the heartbeat timer.
   void RestartTimer();
 
+  // The base::Time at which the heartbeat timer is expected to fire. Used to
+  // check if a heartbeat was somehow lost/delayed.
+  base::Time heartbeat_expected_time_;
+
   // Whether the last heartbeat ping sent has been acknowledged or not.
   bool waiting_for_ack_;
 
diff --git a/google_apis/gcm/engine/heartbeat_manager_unittest.cc b/google_apis/gcm/engine/heartbeat_manager_unittest.cc
index a2755df..e09707b 100644
--- a/google_apis/gcm/engine/heartbeat_manager_unittest.cc
+++ b/google_apis/gcm/engine/heartbeat_manager_unittest.cc
@@ -32,12 +32,19 @@ class TestHeartbeatManager : public HeartbeatManager {
 
   // Bypass the heartbeat timer, and send the heartbeat now.
   void TriggerHearbeat();
+
+  // Check for a missed heartbeat now.
+  void TriggerMissedHeartbeatCheck();
 };
 
 void TestHeartbeatManager::TriggerHearbeat() {
   OnHeartbeatTriggered();
 }
 
+void TestHeartbeatManager::TriggerMissedHeartbeatCheck() {
+  CheckForMissedHeartbeat();
+}
+
 class HeartbeatManagerTest : public testing::Test {
  public:
   HeartbeatManagerTest();
@@ -177,6 +184,20 @@ TEST_F(HeartbeatManagerTest, Stop) {
   EXPECT_TRUE(manager()->GetNextHeartbeatTime().is_null());
 }
 
+// Simulate missing a heartbeat by manually invoking the check method. The
+// heartbeat should only be triggered once, and only if the heartbeat timer
+// is running. Because the period is several minutes, none should fire.
+TEST_F(HeartbeatManagerTest, MissedHeartbeat) {
+  // Do nothing while stopped.
+  manager()->TriggerMissedHeartbeatCheck();
+  StartManager();
+  EXPECT_EQ(0, heartbeats_sent());
+
+  // Do nothing before the period is reached.
+  manager()->TriggerMissedHeartbeatCheck();
+  EXPECT_EQ(0, heartbeats_sent());
+}
+
 }  // namespace
 
 }  // namespace gcm