[GCM] Make sure to send time spent in queue for TTL messages

Queue time is deducted from TTL time at server.

BUG=284553

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

git-svn-id: svn://svn.chromium.org/chrome/trunk/src@244639 0039d316-1c4b-4281-b951-d872f2087c98

2 files changed, 86 insertions, 19 deletions

diff --git a/google_apis/gcm/engine/mcs_client.cc b/google_apis/gcm/engine/mcs_client.cc
index 489bbf8..34e756c 100644
--- a/google_apis/gcm/engine/mcs_client.cc
+++ b/google_apis/gcm/engine/mcs_client.cc
@@ -189,6 +189,7 @@ void MCSClient::Initialize(
        iter != ordered_messages.end(); ++iter) {
     ReliablePacketInfo* packet_info = new ReliablePacketInfo();
     packet_info->protobuf.reset(iter->second);
+    packet_info->tag = GetMCSProtoTag(*iter->second);
     packet_info->persistent_id = base::Uint64ToString(iter->first);
     to_send_.push_back(make_linked_ptr(packet_info));
   }
@@ -229,6 +230,7 @@ void MCSClient::SendMessage(const MCSMessage& message) {
   }
 
   ReliablePacketInfo* packet_info = new ReliablePacketInfo();
+  packet_info->tag = message.tag();
   packet_info->protobuf = message.CloneProtobuf();
 
   if (ttl > 0) {
@@ -391,6 +393,19 @@ void MCSClient::SendPacketToWire(ReliablePacketInfo* packet_info) {
   packet_info->stream_id = ++stream_id_out_;
   DVLOG(1) << "Sending packet of type " << packet_info->protobuf->GetTypeName();
 
+  // Set the queued time as necessary.
+  if (packet_info->tag == kDataMessageStanzaTag) {
+    mcs_proto::DataMessageStanza* data_message =
+        reinterpret_cast<mcs_proto::DataMessageStanza*>(
+            packet_info->protobuf.get());
+    uint64 sent = data_message->sent();
+    DCHECK_GT(sent, 0U);
+    int queued = (clock_->Now().ToInternalValue() /
+        base::Time::kMicrosecondsPerSecond) - sent;
+    DVLOG(1) << "Message was queued for " << queued << " seconds.";
+    data_message->set_queued(queued);
+  }
+
   // Set the proper last received stream id to acknowledge received server
   // packets.
   DVLOG(1) << "Setting last stream id received to "
diff --git a/google_apis/gcm/engine/mcs_client_unittest.cc b/google_apis/gcm/engine/mcs_client_unittest.cc
index 13e376c..d5fdf23 100644
--- a/google_apis/gcm/engine/mcs_client_unittest.cc
+++ b/google_apis/gcm/engine/mcs_client_unittest.cc
@@ -41,7 +41,8 @@ MCSMessage BuildDataMessage(const std::string& from,
                             int last_stream_id_received,
                             const std::string persistent_id,
                             int ttl,
-                            uint64 sent) {
+                            uint64 sent,
+                            int queued) {
   mcs_proto::DataMessageStanza data_message;
   data_message.set_from(from);
   data_message.set_category(category);
@@ -50,6 +51,7 @@ MCSMessage BuildDataMessage(const std::string& from,
     data_message.set_persistent_id(persistent_id);
   data_message.set_ttl(ttl);
   data_message.set_sent(sent);
+  data_message.set_queued(queued);
   return MCSMessage(kDataMessageStanzaTag, data_message);
 }
 
@@ -131,6 +133,9 @@ MCSClientTest::MCSClientTest()
 #if defined(OS_MACOSX)
     Encryptor::UseMockKeychain(true);
 #endif
+
+  // Advance the clock to a non-zero time.
+  clock_.Advance(base::TimeDelta::FromSeconds(1));
 }
 
 MCSClientTest::~MCSClientTest() {}
@@ -258,7 +263,7 @@ TEST_F(MCSClientTest, SendMessageNoRMQ) {
   BuildMCSClient();
   InitializeClient();
   LoginClient(std::vector<std::string>());
-  MCSMessage message(BuildDataMessage("from", "category", 1, "", 0, 1));
+  MCSMessage message(BuildDataMessage("from", "category", 1, "", 0, 1, 0));
   GetFakeHandler()->ExpectOutgoingMessage(message);
   mcs_client()->SendMessage(message);
   EXPECT_TRUE(GetFakeHandler()->AllOutgoingMessagesReceived());
@@ -271,7 +276,7 @@ TEST_F(MCSClientTest, SendMessageNoRMQWhileDisconnected) {
   InitializeClient();
 
   EXPECT_TRUE(sent_message_id().empty());
-  MCSMessage message(BuildDataMessage("from", "category", 1, "", 0, 1));
+  MCSMessage message(BuildDataMessage("from", "category", 1, "", 0, 1, 0));
   mcs_client()->SendMessage(message);
 
   // Message sent callback should be invoked, but no message should actually
@@ -286,7 +291,7 @@ TEST_F(MCSClientTest, SendMessageRMQ) {
   InitializeClient();
   LoginClient(std::vector<std::string>());
   MCSMessage message(
-      BuildDataMessage("from", "category", 1, "1", kTTLValue, 1));
+      BuildDataMessage("from", "category", 1, "1", kTTLValue, 1, 0));
   GetFakeHandler()->ExpectOutgoingMessage(message);
   mcs_client()->SendMessage(message);
   EXPECT_TRUE(GetFakeHandler()->AllOutgoingMessagesReceived());
@@ -300,7 +305,7 @@ TEST_F(MCSClientTest, SendMessageRMQWhileDisconnected) {
   LoginClient(std::vector<std::string>());
   GetFakeHandler()->set_fail_send(true);
   MCSMessage message(
-      BuildDataMessage("from", "category", 1, "1", kTTLValue, 1));
+      BuildDataMessage("from", "category", 1, "1", kTTLValue, 1, 0));
 
   // The initial (failed) send.
   GetFakeHandler()->ExpectOutgoingMessage(message);
@@ -310,10 +315,18 @@ TEST_F(MCSClientTest, SendMessageRMQWhileDisconnected) {
                  BuildLoginRequest(kAndroidId, kSecurityToken).
                      PassAs<const google::protobuf::MessageLite>()));
   // The second (re)send.
-  GetFakeHandler()->ExpectOutgoingMessage(message);
+  MCSMessage message2(BuildDataMessage("from",
+                                       "category",
+                                       1,
+                                       "1",
+                                       kTTLValue,
+                                       1,
+                                       kTTLValue - 1));
+  GetFakeHandler()->ExpectOutgoingMessage(message2);
   mcs_client()->SendMessage(message);
   EXPECT_FALSE(GetFakeHandler()->AllOutgoingMessagesReceived());
   GetFakeHandler()->set_fail_send(false);
+  clock()->Advance(base::TimeDelta::FromSeconds(kTTLValue - 1));
   connection_factory()->Connect();
   WaitForMCSEvent();  // Wait for the login to finish.
   PumpLoop();         // Wait for the send to happen.
@@ -328,7 +341,7 @@ TEST_F(MCSClientTest, SendMessageRMQOnRestart) {
   LoginClient(std::vector<std::string>());
   GetFakeHandler()->set_fail_send(true);
   MCSMessage message(
-      BuildDataMessage("from", "category", 1, "1", kTTLValue, 1));
+      BuildDataMessage("from", "category", 1, "1", kTTLValue, 1, 0));
 
   // The initial (failed) send.
   GetFakeHandler()->ExpectOutgoingMessage(message);
@@ -339,8 +352,17 @@ TEST_F(MCSClientTest, SendMessageRMQOnRestart) {
   // Rebuild the client, which should resend the old message.
   BuildMCSClient();
   InitializeClient();
+
+  clock()->Advance(base::TimeDelta::FromSeconds(kTTLValue - 1));
+  MCSMessage message2(BuildDataMessage("from",
+                                       "category",
+                                       1,
+                                       "1",
+                                       kTTLValue,
+                                       1,
+                                       kTTLValue - 1));
   LoginClient(std::vector<std::string>());
-  GetFakeHandler()->ExpectOutgoingMessage(message);
+  GetFakeHandler()->ExpectOutgoingMessage(message2);
   PumpLoop();
   EXPECT_TRUE(GetFakeHandler()->AllOutgoingMessagesReceived());
 }
@@ -360,7 +382,7 @@ TEST_F(MCSClientTest, SendMessageRMQWithStreamAck) {
                          1,
                          base::IntToString(i),
                          kTTLValue,
-                         1));
+                         1, 0));
     GetFakeHandler()->ExpectOutgoingMessage(message);
     mcs_client()->SendMessage(message);
   }
@@ -392,8 +414,14 @@ TEST_F(MCSClientTest, SendMessageRMQAckOnReconnect) {
   std::vector<std::string> id_list;
   for (int i = 1; i <= kMessageBatchSize; ++i) {
     id_list.push_back(base::IntToString(i));
-    MCSMessage message(
-        BuildDataMessage("from", "category", 1, id_list.back(), kTTLValue, 1));
+        MCSMessage message(
+            BuildDataMessage("from",
+                             "category",
+                             1,
+                             id_list.back(),
+                             kTTLValue,
+                             1,
+                             0));
     GetFakeHandler()->ExpectOutgoingMessage(message);
     mcs_client()->SendMessage(message);
   }
@@ -425,7 +453,13 @@ TEST_F(MCSClientTest, SendMessageRMQPartialAckOnReconnect) {
   for (int i = 1; i <= kMessageBatchSize; ++i) {
     id_list.push_back(base::IntToString(i));
     MCSMessage message(
-        BuildDataMessage("from", "category", 1, id_list.back(), kTTLValue, 1));
+        BuildDataMessage("from",
+                         "category",
+                         1,
+                         id_list.back(),
+                         kTTLValue,
+                         1,
+                         0));
     GetFakeHandler()->ExpectOutgoingMessage(message);
     mcs_client()->SendMessage(message);
   }
@@ -451,7 +485,7 @@ TEST_F(MCSClientTest, SendMessageRMQPartialAckOnReconnect) {
                          2,
                          remaining_ids[i - 1],
                          kTTLValue,
-                         1));
+                         1, 0));
     GetFakeHandler()->ExpectOutgoingMessage(message);
   }
   scoped_ptr<mcs_proto::IqStanza> ack(BuildSelectiveAck(acked_ids));
@@ -474,7 +508,13 @@ TEST_F(MCSClientTest, AckOnLogin) {
   for (int i = 1; i <= kMessageBatchSize; ++i) {
     id_list.push_back(base::IntToString(i));
     MCSMessage message(
-        BuildDataMessage("from", "category", i, id_list.back(), kTTLValue, 1));
+        BuildDataMessage("from",
+                         "category",
+                         1,
+                         id_list.back(),
+                         kTTLValue,
+                         1,
+                         0));
     GetFakeHandler()->ReceiveMessage(message);
     WaitForMCSEvent();
     PumpLoop();
@@ -498,7 +538,13 @@ TEST_F(MCSClientTest, AckOnSend) {
   for (int i = 1; i <= kMessageBatchSize; ++i) {
     id_list.push_back(base::IntToString(i));
     MCSMessage message(
-        BuildDataMessage("from", "category", i, id_list.back(), kTTLValue, 1));
+        BuildDataMessage("from",
+                         "category",
+                         1,
+                         id_list.back(),
+                         kTTLValue,
+                         1,
+                         0));
     GetFakeHandler()->ReceiveMessage(message);
     WaitForMCSEvent();
     PumpLoop();
@@ -511,7 +557,7 @@ TEST_F(MCSClientTest, AckOnSend) {
                        kMessageBatchSize + 1,
                        "1",
                        kTTLValue,
-                       1));
+                       1, 0));
   GetFakeHandler()->ExpectOutgoingMessage(message);
   mcs_client()->SendMessage(message);
   EXPECT_TRUE(GetFakeHandler()->AllOutgoingMessagesReceived());
@@ -536,7 +582,13 @@ TEST_F(MCSClientTest, AckWhenLimitReachedWithHeartbeat) {
   for (int i = 1; i <= kAckLimitSize; ++i) {
     id_list.push_back(base::IntToString(i));
     MCSMessage message(
-        BuildDataMessage("from", "category", i, id_list.back(), kTTLValue, 1));
+        BuildDataMessage("from",
+                         "category",
+                         1,
+                         id_list.back(),
+                         kTTLValue,
+                         1,
+                         0));
     GetFakeHandler()->ReceiveMessage(message);
     WaitForMCSEvent();
     PumpLoop();
@@ -575,7 +627,7 @@ TEST_F(MCSClientTest, ExpiredTTLOnSend) {
   InitializeClient();
   LoginClient(std::vector<std::string>());
   MCSMessage message(
-      BuildDataMessage("from", "category", 1, "1", kTTLValue, 1));
+      BuildDataMessage("from", "category", 1, "1", kTTLValue, 1, 0));
 
   // Advance time to after the TTL.
   clock()->Advance(base::TimeDelta::FromSeconds(kTTLValue + 2));
@@ -593,7 +645,7 @@ TEST_F(MCSClientTest, ExpiredTTLOnRestart) {
   LoginClient(std::vector<std::string>());
   GetFakeHandler()->set_fail_send(true);
   MCSMessage message(
-      BuildDataMessage("from", "category", 1, "1", kTTLValue, 1));
+      BuildDataMessage("from", "category", 1, "1", kTTLValue, 1, 0));
 
   // The initial (failed) send.
   GetFakeHandler()->ExpectOutgoingMessage(message);