SPDY - Deleted the code that sends trailing ping.

Updated channel activity time whenever either read
or write is completed.

Fixed the unit tests to work with the new code.

R=jar
BUG=125356
TEST=network unit tests

Review URL: https://chromiumcodereview.appspot.com/10332104

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

4 files changed, 26 insertions, 111 deletions

diff --git a/net/spdy/spdy_session.cc b/net/spdy/spdy_session.cc
index a2249cb..9f5704b 100644
--- a/net/spdy/spdy_session.cc
+++ b/net/spdy/spdy_session.cc
@@ -103,7 +103,6 @@ namespace {
 
 const int kReadBufferSize = 8 * 1024;
 const int kDefaultConnectionAtRiskOfLossSeconds = 10;
-const int kTrailingPingDelayTimeSeconds = 1;
 const int kHungIntervalSeconds = 10;
 
 class NetLogSpdySessionParameter : public NetLog::EventParameters {
@@ -366,10 +365,8 @@ SpdySession::SpdySession(const HostPortProxyPair& host_port_proxy_pair,
       stalled_streams_(0),
       pings_in_flight_(0),
       next_ping_id_(1),
-      received_data_time_(base::TimeTicks::Now()),
-      trailing_ping_pending_(false),
+      last_activity_time_(base::TimeTicks::Now()),
       check_ping_status_pending_(false),
-      need_to_send_ping_(false),
       flow_control_(false),
       initial_send_window_size_(kSpdyStreamInitialWindowSize),
       initial_recv_window_size_(kSpdyStreamInitialWindowSize),
@@ -378,8 +375,6 @@ SpdySession::SpdySession(const HostPortProxyPair& host_port_proxy_pair,
       credential_state_(SpdyCredentialState::kDefaultNumSlots),
       connection_at_risk_of_loss_time_(
           base::TimeDelta::FromSeconds(kDefaultConnectionAtRiskOfLossSeconds)),
-      trailing_ping_delay_time_(
-          base::TimeDelta::FromSeconds(kTrailingPingDelayTimeSeconds)),
       hung_interval_(
           base::TimeDelta::FromSeconds(kHungIntervalSeconds)),
       trusted_spdy_proxy_(trusted_spdy_proxy) {
@@ -680,13 +675,6 @@ int SpdySession::WriteSynStream(
             new NetLogSpdySynParameter(headers, flags, stream_id, 0)));
   }
 
-  // Some servers don't like too many pings, so we limit our current sending to
-  // no more than two pings for any syn frame or data frame sent.  To do this,
-  // we avoid ever setting this to true unless we send a syn (which we have just
-  // done) or data frame. This approach may change over time as servers change
-  // their responses to pings.
-  need_to_send_ping_ = true;
-
   return ERR_IO_PENDING;
 }
 
@@ -802,14 +790,6 @@ int SpdySession::WriteStreamData(SpdyStreamId stream_id,
           stream_id, data->data(), len, flags));
   QueueFrame(frame.get(), stream->priority(), stream);
 
-  // Some servers don't like too many pings, so we limit our current sending to
-  // no more than two pings for any syn frame or data frame sent.  To do this,
-  // we avoid ever setting this to true unless we send a syn (which we have just
-  // done) or data frame. This approach may change over time as servers change
-  // their responses to pings.
-  if (len > 0)
-    need_to_send_ping_ = true;
-
   return ERR_IO_PENDING;
 }
 
@@ -881,7 +861,7 @@ void SpdySession::OnReadComplete(int bytes_read) {
 
   bytes_received_ += bytes_read;
 
-  received_data_time_ = base::TimeTicks::Now();
+  last_activity_time_ = base::TimeTicks::Now();
 
   // The SpdyFramer will use callbacks onto |this| as it parses frames.
   // When errors occur, those callbacks can lead to teardown of all references
@@ -910,6 +890,7 @@ void SpdySession::OnWriteComplete(int result) {
   DCHECK(write_pending_);
   DCHECK(in_flight_write_.size());
 
+  last_activity_time_ = base::TimeTicks::Now();
   write_pending_ = false;
 
   scoped_refptr<SpdyStream> stream = in_flight_write_.stream();
@@ -1626,6 +1607,7 @@ void SpdySession::OnPing(const SpdyPingControlFrame& frame) {
     RecordProtocolErrorHistogram(PROTOCOL_ERROR_UNEXPECTED_PING);
     CloseSessionOnError(
         net::ERR_SPDY_PROTOCOL_ERROR, true, "pings_in_flight_ is < 0.");
+    pings_in_flight_ = 0;
     return;
   }
 
@@ -1635,11 +1617,6 @@ void SpdySession::OnPing(const SpdyPingControlFrame& frame) {
   // We will record RTT in histogram when there are no more client sent
   // pings_in_flight_.
   RecordPingRTTHistogram(base::TimeTicks::Now() - last_ping_sent_time_);
-
-  if (!need_to_send_ping_)
-    return;
-
-  PlanToSendTrailingPing();
 }
 
 void SpdySession::OnWindowUpdate(
@@ -1788,39 +1765,19 @@ void SpdySession::UpdateStreamsSendWindowSize(int32 delta_window_size) {
 }
 
 void SpdySession::SendPrefacePingIfNoneInFlight() {
-  if (pings_in_flight_ || trailing_ping_pending_ ||
-      !g_enable_ping_based_connection_checking)
+  if (pings_in_flight_ || !g_enable_ping_based_connection_checking)
     return;
 
   base::TimeTicks now = base::TimeTicks::Now();
-  // If we haven't heard from server, then send a preface-PING.
-  if ((now - received_data_time_) > connection_at_risk_of_loss_time_)
+  // If there is no activity in the session, then send a preface-PING.
+  if ((now - last_activity_time_) > connection_at_risk_of_loss_time_)
     SendPrefacePing();
-
-  PlanToSendTrailingPing();
 }
 
 void SpdySession::SendPrefacePing() {
   WritePingFrame(next_ping_id_);
 }
 
-void SpdySession::PlanToSendTrailingPing() {
-  if (trailing_ping_pending_)
-    return;
-
-  trailing_ping_pending_ = true;
-  MessageLoop::current()->PostDelayedTask(
-      FROM_HERE,
-      base::Bind(&SpdySession::SendTrailingPing, weak_factory_.GetWeakPtr()),
-      trailing_ping_delay_time_);
-}
-
-void SpdySession::SendTrailingPing() {
-  DCHECK(trailing_ping_pending_);
-  trailing_ping_pending_ = false;
-  WritePingFrame(next_ping_id_);
-}
-
 void SpdySession::WritePingFrame(uint32 unique_id) {
   DCHECK(buffered_spdy_framer_.get());
   scoped_ptr<SpdyPingControlFrame> ping_frame(
@@ -1835,7 +1792,6 @@ void SpdySession::WritePingFrame(uint32 unique_id) {
   if (unique_id % 2 != 0) {
     next_ping_id_ += 2;
     ++pings_in_flight_;
-    need_to_send_ping_ = false;
     PlanToCheckPingStatus();
     last_ping_sent_time_ = base::TimeTicks::Now();
   }
@@ -1862,9 +1818,9 @@ void SpdySession::CheckPingStatus(base::TimeTicks last_check_time) {
   DCHECK(check_ping_status_pending_);
 
   base::TimeTicks now = base::TimeTicks::Now();
-  base::TimeDelta delay = hung_interval_ - (now - received_data_time_);
+  base::TimeDelta delay = hung_interval_ - (now - last_activity_time_);
 
-  if (delay.InMilliseconds() < 0 || received_data_time_ < last_check_time) {
+  if (delay.InMilliseconds() < 0 || last_activity_time_ < last_check_time) {
     CloseSessionOnError(net::ERR_SPDY_PING_FAILED, true, "Failed ping.");
     // Track all failed PING messages in a separate bucket.
     const base::TimeDelta kFailedPing =
diff --git a/net/spdy/spdy_session.h b/net/spdy/spdy_session.h
index a3cb485..439c0cc 100644
--- a/net/spdy/spdy_session.h
+++ b/net/spdy/spdy_session.h
@@ -398,20 +398,12 @@ class NET_EXPORT SpdySession : public base::RefCounted<SpdySession>,
   // Adjust the send window size of all ActiveStreams and PendingCreateStreams.
   void UpdateStreamsSendWindowSize(int32 delta_window_size);
 
-  // Send the PING (preface-PING and trailing-PING) frames.
+  // Send the PING (preface-PING) frame.
   void SendPrefacePingIfNoneInFlight();
 
   // Send PING if there are no PINGs in flight and we haven't heard from server.
   void SendPrefacePing();
 
-  // Send a PING after delay. Don't post a PING if there is already
-  // a trailing PING pending.
-  void PlanToSendTrailingPing();
-
-  // Send a PING if there is no |trailing_ping_pending_|. This PING verifies
-  // that the requests are being received by the server.
-  void SendTrailingPing();
-
   // Send the PING frame.
   void WritePingFrame(uint32 unique_id);
 
@@ -458,7 +450,6 @@ class NET_EXPORT SpdySession : public base::RefCounted<SpdySession>,
   bool Respond(const SpdyHeaderBlock& headers,
                const scoped_refptr<SpdyStream> stream);
 
-
   void RecordPingRTTHistogram(base::TimeDelta duration);
   void RecordHistograms();
   void RecordProtocolErrorHistogram(SpdyProtocolErrorDetails details);
@@ -502,10 +493,6 @@ class NET_EXPORT SpdySession : public base::RefCounted<SpdySession>,
     connection_at_risk_of_loss_time_ = duration;
   }
 
-  void set_trailing_ping_delay_time(base::TimeDelta duration) {
-    trailing_ping_delay_time_ = duration;
-  }
-
   void set_hung_interval(base::TimeDelta duration) {
     hung_interval_ = duration;
   }
@@ -514,9 +501,7 @@ class NET_EXPORT SpdySession : public base::RefCounted<SpdySession>,
 
   uint32 next_ping_id() const { return next_ping_id_; }
 
-  base::TimeTicks received_data_time() const { return received_data_time_; }
-
-  bool trailing_ping_pending() const { return trailing_ping_pending_; }
+  base::TimeTicks last_activity_time() const { return last_activity_time_; }
 
   bool check_ping_status_pending() const { return check_ping_status_pending_; }
 
@@ -621,22 +606,13 @@ class NET_EXPORT SpdySession : public base::RefCounted<SpdySession>,
   // This is the last time we have sent a PING.
   base::TimeTicks last_ping_sent_time_;
 
-  // This is the last time we have received data.
-  base::TimeTicks received_data_time_;
-
-  // Indicate if we have already scheduled a delayed task to send a trailing
-  // ping (and we never have more than one scheduled at a time).
-  bool trailing_ping_pending_;
+  // This is the last time we had activity in the session.
+  base::TimeTicks last_activity_time_;
 
   // Indicate if we have already scheduled a delayed task to check the ping
   // status.
   bool check_ping_status_pending_;
 
-  // Indicate if we need to send a ping (generally, a trailing ping). This helps
-  // us to decide if we need yet another trailing ping, or if it would be a
-  // waste of effort (and MUST not be done).
-  bool need_to_send_ping_;
-
   // Indicate if flow control is enabled or not.
   bool flow_control_;
 
@@ -673,16 +649,11 @@ class NET_EXPORT SpdySession : public base::RefCounted<SpdySession>,
   // we could adjust it to send fewer pings perhaps.
   base::TimeDelta connection_at_risk_of_loss_time_;
 
-  // This is the amount of time we wait before sending a trailing ping. We use
-  // a trailing ping (sent after all data) to get an effective acknowlegement
-  // from the server that it has indeed received all (prior) data frames. With
-  // that assurance, we are willing to enter into a wait state for responses
-  // to our last data frame(s) without further pings.
-  base::TimeDelta trailing_ping_delay_time_;
-
-  // The amount of time that we are willing to tolerate with no data received
-  // (of any form), while there is a ping in flight, before we declare the
-  // connection to be hung.
+  // The amount of time that we are willing to tolerate with no activity (of any
+  // form), while there is a ping in flight, before we declare the connection to
+  // be hung. TODO(rtenneti): When hung, instead of resetting connection, race
+  // to build a new connection, and see if that completes before we (finally)
+  // get a PING response (http://crbug.com/127812).
   base::TimeDelta hung_interval_;
 
   // This SPDY proxy is allowed to push resources from origins that are
diff --git a/net/spdy/spdy_session_spdy2_unittest.cc b/net/spdy/spdy_session_spdy2_unittest.cc
index 03bb6ae..121d157 100644
--- a/net/spdy/spdy_session_spdy2_unittest.cc
+++ b/net/spdy/spdy_session_spdy2_unittest.cc
@@ -172,13 +172,11 @@ TEST_F(SpdySessionSpdy2Test, Ping) {
   scoped_ptr<SpdyFrame> read_ping(ConstructSpdyPing());
   MockRead reads[] = {
     CreateMockRead(*read_ping),
-    CreateMockRead(*read_ping),
     MockRead(SYNCHRONOUS, 0, 0)  // EOF
   };
   scoped_ptr<SpdyFrame> write_ping(ConstructSpdyPing());
   MockRead writes[] = {
     CreateMockRead(*write_ping),
-    CreateMockRead(*write_ping),
   };
   StaticSocketDataProvider data(
       reads, arraysize(reads), writes, arraysize(writes));
@@ -205,7 +203,6 @@ TEST_F(SpdySessionSpdy2Test, Ping) {
       spdy_session_pool->Get(pair, BoundNetLog());
   EXPECT_TRUE(spdy_session_pool->HasSession(pair));
 
-
   scoped_refptr<TransportSocketParams> transport_params(
       new TransportSocketParams(test_host_port_pair,
                                 MEDIUM,
@@ -235,7 +232,6 @@ TEST_F(SpdySessionSpdy2Test, Ping) {
   // Enable sending of PING.
   SpdySession::set_enable_ping_based_connection_checking(true);
   session->set_connection_at_risk_of_loss_time(base::TimeDelta::FromSeconds(0));
-  session->set_trailing_ping_delay_time(base::TimeDelta::FromSeconds(0));
   session->set_hung_interval(base::TimeDelta::FromMilliseconds(50));
 
   session->SendPrefacePingIfNoneInFlight();
@@ -245,10 +241,9 @@ TEST_F(SpdySessionSpdy2Test, Ping) {
   session->CheckPingStatus(before_ping_time);
 
   EXPECT_EQ(0, session->pings_in_flight());
-  EXPECT_GT(session->next_ping_id(), static_cast<uint32>(1));
-  EXPECT_FALSE(session->trailing_ping_pending());
+  EXPECT_GE(session->next_ping_id(), static_cast<uint32>(1));
   EXPECT_FALSE(session->check_ping_status_pending());
-  EXPECT_GE(session->received_data_time(), before_ping_time);
+  EXPECT_GE(session->last_activity_time(), before_ping_time);
 
   EXPECT_FALSE(spdy_session_pool->HasSession(pair));
 
@@ -322,13 +317,12 @@ TEST_F(SpdySessionSpdy2Test, FailedPing) {
   // Enable sending of PING.
   SpdySession::set_enable_ping_based_connection_checking(true);
   session->set_connection_at_risk_of_loss_time(base::TimeDelta::FromSeconds(0));
-  session->set_trailing_ping_delay_time(base::TimeDelta::FromSeconds(0));
   session->set_hung_interval(base::TimeDelta::FromSeconds(0));
 
   // Send a PING frame.
   session->WritePingFrame(1);
   EXPECT_LT(0, session->pings_in_flight());
-  EXPECT_GT(session->next_ping_id(), static_cast<uint32>(1));
+  EXPECT_GE(session->next_ping_id(), static_cast<uint32>(1));
   EXPECT_TRUE(session->check_ping_status_pending());
 
   // Assert session is not closed.
@@ -339,7 +333,7 @@ TEST_F(SpdySessionSpdy2Test, FailedPing) {
   // We set last time we have received any data in 1 sec less than now.
   // CheckPingStatus will trigger timeout because hung interval is zero.
   base::TimeTicks now = base::TimeTicks::Now();
-  session->received_data_time_ = now - base::TimeDelta::FromSeconds(1);
+  session->last_activity_time_ = now - base::TimeDelta::FromSeconds(1);
   session->CheckPingStatus(now);
 
   EXPECT_TRUE(session->IsClosed());
diff --git a/net/spdy/spdy_session_spdy3_unittest.cc b/net/spdy/spdy_session_spdy3_unittest.cc
index 82b2342..c6c9fc5 100644
--- a/net/spdy/spdy_session_spdy3_unittest.cc
+++ b/net/spdy/spdy_session_spdy3_unittest.cc
@@ -172,13 +172,11 @@ TEST_F(SpdySessionSpdy3Test, Ping) {
   scoped_ptr<SpdyFrame> read_ping(ConstructSpdyPing());
   MockRead reads[] = {
     CreateMockRead(*read_ping),
-    CreateMockRead(*read_ping),
     MockRead(SYNCHRONOUS, 0, 0)  // EOF
   };
   scoped_ptr<SpdyFrame> write_ping(ConstructSpdyPing());
   MockRead writes[] = {
     CreateMockRead(*write_ping),
-    CreateMockRead(*write_ping),
   };
   StaticSocketDataProvider data(
       reads, arraysize(reads), writes, arraysize(writes));
@@ -205,7 +203,6 @@ TEST_F(SpdySessionSpdy3Test, Ping) {
       spdy_session_pool->Get(pair, BoundNetLog());
   EXPECT_TRUE(spdy_session_pool->HasSession(pair));
 
-
   scoped_refptr<TransportSocketParams> transport_params(
       new TransportSocketParams(test_host_port_pair,
                                 MEDIUM,
@@ -235,7 +232,6 @@ TEST_F(SpdySessionSpdy3Test, Ping) {
   // Enable sending of PING.
   SpdySession::set_enable_ping_based_connection_checking(true);
   session->set_connection_at_risk_of_loss_time(base::TimeDelta::FromSeconds(0));
-  session->set_trailing_ping_delay_time(base::TimeDelta::FromSeconds(0));
   session->set_hung_interval(base::TimeDelta::FromMilliseconds(50));
 
   session->SendPrefacePingIfNoneInFlight();
@@ -245,10 +241,9 @@ TEST_F(SpdySessionSpdy3Test, Ping) {
   session->CheckPingStatus(before_ping_time);
 
   EXPECT_EQ(0, session->pings_in_flight());
-  EXPECT_GT(session->next_ping_id(), static_cast<uint32>(1));
-  EXPECT_FALSE(session->trailing_ping_pending());
+  EXPECT_GE(session->next_ping_id(), static_cast<uint32>(1));
   EXPECT_FALSE(session->check_ping_status_pending());
-  EXPECT_GE(session->received_data_time(), before_ping_time);
+  EXPECT_GE(session->last_activity_time(), before_ping_time);
 
   EXPECT_FALSE(spdy_session_pool->HasSession(pair));
 
@@ -322,13 +317,12 @@ TEST_F(SpdySessionSpdy3Test, FailedPing) {
   // Enable sending of PING.
   SpdySession::set_enable_ping_based_connection_checking(true);
   session->set_connection_at_risk_of_loss_time(base::TimeDelta::FromSeconds(0));
-  session->set_trailing_ping_delay_time(base::TimeDelta::FromSeconds(0));
   session->set_hung_interval(base::TimeDelta::FromSeconds(0));
 
   // Send a PING frame.
   session->WritePingFrame(1);
   EXPECT_LT(0, session->pings_in_flight());
-  EXPECT_GT(session->next_ping_id(), static_cast<uint32>(1));
+  EXPECT_GE(session->next_ping_id(), static_cast<uint32>(1));
   EXPECT_TRUE(session->check_ping_status_pending());
 
   // Assert session is not closed.
@@ -339,7 +333,7 @@ TEST_F(SpdySessionSpdy3Test, FailedPing) {
   // We set last time we have received any data in 1 sec less than now.
   // CheckPingStatus will trigger timeout because hung interval is zero.
   base::TimeTicks now = base::TimeTicks::Now();
-  session->received_data_time_ = now - base::TimeDelta::FromSeconds(1);
+  session->last_activity_time_ = now - base::TimeDelta::FromSeconds(1);
   session->CheckPingStatus(now);
 
   EXPECT_TRUE(session->IsClosed());