Detect situation when there is no missing send completion signal in P2PSocket implementation.

content/renderer/p2p/ipc_socket_factory.cc

Index: content/renderer/p2p/ipc_socket_factory.cc
diff --git a/content/renderer/p2p/ipc_socket_factory.cc b/content/renderer/p2p/ipc_socket_factory.cc
index b56ebbab336bb8c7a288eafb97eaaae47c684b1e..9a01ae58af80851305b215cdc060ab4d969ae0b0 100644
--- a/content/renderer/p2p/ipc_socket_factory.cc
+++ b/content/renderer/p2p/ipc_socket_factory.cc
@@ -5,7 +5,7 @@
 #include "content/renderer/p2p/ipc_socket_factory.h"
 
 #include <algorithm>
-#include <deque>
+#include <list>
 
 #include "base/compiler_specific.h"
 #include "base/debug/trace_event.h"
@@ -76,6 +76,25 @@ class IpcPacketSocket : public rtc::AsyncPacketSocket,
   IpcPacketSocket();
   ~IpcPacketSocket() override;
 
+  // Struct to track information when a packet is received by this socket for
+  // send. The information tracked here will be used to match with the
+  // P2PSendPacketMetrics from the underneath system socket.
+  struct InFlightPacketRecord {
+    InFlightPacketRecord(uint64 packet_id,
+                         size_t packet_size,
+                         uint64 timeticks_received_by_socket)
+        : packet_id(packet_id),
+          packet_size(packet_size),
+          timeticks_received_by_socket(timeticks_received_by_socket) {}
+
+    uint64 packet_id;
+    size_t packet_size;
+    // The first time this packet shows up to this socket.
+    uint64 timeticks_received_by_socket;
+  };
+
+  typedef std::list<InFlightPacketRecord> InFlightPacketList;
+
   // Always takes ownership of client even if initialization fails.
   bool Init(P2PSocketType type, P2PSocketClientImpl* client,
             const rtc::SocketAddress& local_address,
@@ -103,7 +122,8 @@ class IpcPacketSocket : public rtc::AsyncPacketSocket,
               const net::IPEndPoint& remote_address) override;
   void OnIncomingTcpConnection(const net::IPEndPoint& address,
                                P2PSocketClient* client) override;
-  void OnSendComplete() override;
+  void OnSendComplete(const P2PSendPacketMetrics& send_metrics) override;
+
   void OnError() override;
   void OnDataReceived(const net::IPEndPoint& address,
                       const std::vector<char>& data,
@@ -124,7 +144,7 @@ class IpcPacketSocket : public rtc::AsyncPacketSocket,
 
   // Update trace of send throttling internal state. This should be called
   // immediately after any changes to |send_bytes_available_| and/or
-  // |in_flight_packet_sizes_|.
+  // |in_flight_packet_records_|.
   void TraceSendThrottlingState() const;
 
   void InitAcceptedTcp(P2PSocketClient* client,
@@ -137,6 +157,13 @@ class IpcPacketSocket : public rtc::AsyncPacketSocket,
   // send_bytes_available_;
   void AdjustUdpSendBufferSize();
 
+  // Helper function to find the matching InFlightPacketRecord by packet_id.
+  // In normal case, it should always be the first one so the perf impact should
+  // be negligible. Return value is the iterator pointing to the matching
+  // InFlightPacketRecord. Can be InFlightPacketRecord::end() if no matching one
+  // is found.
+  InFlightPacketList::iterator FindInFlightRecord(uint64 packet_id);
+
   P2PSocketType type_;
 
   // Message loop on which this socket was created and being used.
@@ -163,7 +190,15 @@ class IpcPacketSocket : public rtc::AsyncPacketSocket,
   // allows short bursts of high-rate sending without dropping packets, but
   // quickly restricts the client to a sustainable steady-state rate.
   size_t send_bytes_available_;
-  std::deque<size_t> in_flight_packet_sizes_;
+
+  // This is a sorted linked list of all InFlightPacketRecord by its packet_id.
+  // In normal case without reordering, the first packet should always be the
+  // one that we're going to receive the next completion signal. However, since
+  // we can't rule out reordering happening (when system buffer is large enough
+  // on various platforms), if it happens, there could be some minor penalty
+  // looking for the right packet in the list. This list gives us a way to look
+  // for packets that we never receive its completion signal from OS.
+  InFlightPacketList in_flight_packet_records_;
 
   // Set to true once EWOULDBLOCK was returned from Send(). Indicates that the
   // caller expects SignalWritable notification.
@@ -245,7 +280,7 @@ void IpcPacketSocket::TraceSendThrottlingState() const {
   TRACE_COUNTER_ID1("p2p", "P2PSendBytesAvailable", local_address_.port(),
                     send_bytes_available_);
   TRACE_COUNTER_ID1("p2p", "P2PSendPacketsInFlight", local_address_.port(),
-                    in_flight_packet_sizes_.size());
+                    in_flight_packet_records_.size());
 }
 
 void IpcPacketSocket::IncrementDiscardCounters(size_t bytes_discarded) {
@@ -370,6 +405,8 @@ int IpcPacketSocket::SendTo(const void *data, size_t data_size,
       break;
   }
 
+  uint64 tick_received_in_socket = base::TimeTicks::Now().ToInternalValue();
+
   if (data_size == 0) {
     NOTREACHED();
     return 0;
@@ -385,7 +422,7 @@ int IpcPacketSocket::SendTo(const void *data, size_t data_size,
     if (!writable_signal_expected_) {
       WebRtcLogMessage(base::StringPrintf(
           "IpcPacketSocket: sending is blocked. %d packets_in_flight.",
-          static_cast<int>(in_flight_packet_sizes_.size())));
+          static_cast<int>(in_flight_packet_records_.size())));
 
       writable_signal_expected_ = true;
     }
@@ -408,12 +445,22 @@ int IpcPacketSocket::SendTo(const void *data, size_t data_size,
   }
 
   send_bytes_available_ -= data_size;
-  in_flight_packet_sizes_.push_back(data_size);
-  TraceSendThrottlingState();
 
   const char* data_char = reinterpret_cast<const char*>(data);
   std::vector<char> data_vector(data_char, data_char + data_size);
-  client_->SendWithDscp(address_chrome, data_vector, options);
+  uint64 packet_id =
+      client_->SendWithDscp(address_chrome, data_vector, options);
+
+  // Ensure packet_id is not 0. It can't be the case according to
+  // P2PSocketClientImpl::SendWithDscp().
+  DCHECK_NE(packet_id, 0uL);
+
+  // Since OnSendComplete happens on the same thread, there is no chance that
+  // for the same packet, OnSendComplete is called before SendWithDscp is
+  // finished with |packet_id| back.
+  in_flight_packet_records_.push_back(
+      InFlightPacketRecord(packet_id, data_size, tick_received_in_socket));
+  TraceSendThrottlingState();
 
   // Fake successful send. The caller ignores result anyway.
   return data_size;
@@ -559,21 +606,71 @@ void IpcPacketSocket::OnIncomingTcpConnection(
   SignalNewConnection(this, socket.release());
 }
 
-void IpcPacketSocket::OnSendComplete() {
+// For most of the case, the completion signal should be returned for the packet
+// at the beginning of |in_flight_packet_records_| so the perf impact should be
+// negligible.
+IpcPacketSocket::InFlightPacketList::iterator
+IpcPacketSocket::FindInFlightRecord(uint64 packet_id) {
+  CHECK(!in_flight_packet_records_.empty());
+  InFlightPacketList::iterator it = in_flight_packet_records_.begin();
+  for (; it != in_flight_packet_records_.end(); ++it) {
+    if (it->packet_id == packet_id) {
+      break;
+    }
+  }
+
+  // We should always be able to find matching packet_id in the
+  // in_flight_packet_records_.
+  DCHECK(it != in_flight_packet_records_.end());
+  return it;
+}
+
+void IpcPacketSocket::OnSendComplete(const P2PSendPacketMetrics& send_metrics) {
   DCHECK_EQ(base::MessageLoop::current(), message_loop_);
 
-  CHECK(!in_flight_packet_sizes_.empty());
-  send_bytes_available_ += in_flight_packet_sizes_.front();
+  CHECK(!in_flight_packet_records_.empty());
+
+  InFlightPacketList::iterator it;
+  if (send_metrics.packet_id == 0) {
+    // If send_metrics doesn't carry valid packet_id, it means that we should
+    // not try to detect mismatch packets.
+    it = in_flight_packet_records_.begin();
+  } else {
+    it = FindInFlightRecord(send_metrics.packet_id);
+
+    // If we can't find the record, something has gone very wrong at this point.
+    if (it == in_flight_packet_records_.end()) {
+      VLOG(1) << "Failed to find in-flight record with packet_id = "
+              << send_metrics.packet_id;
+      NOTREACHED();
+      return;
+    }
+  }
+
+  send_bytes_available_ += it->packet_size;
+
+  // Here is a heuristic to detect a completion signal is not returned. We can't
+  // rely on the destructor since if user closes the tab, destructor is not

[rkaplow, 2014/12/03 22:30:26]

if a user

[rkaplow, 2014/12/03 22:30:26]

the destructor

[guoweis_left_chromium, 2014/12/08 21:46:07]

Done.

[guoweis_left_chromium, 2014/12/08 21:46:08]

Done.

+  // invoked. Or if user just inputs another url, destructor will be called

[rkaplow, 2014/12/03 22:30:26]

a/the user

[guoweis_left_chromium, 2014/12/08 21:46:07]

Done.

+  // before all completion signals return.
+  if (send_metrics.packet_id != 0 &&
+      in_flight_packet_records_.front().packet_id + 100 <
+          send_metrics.packet_id) {
+    // Report an instance that a packet didn't have its completion
+    // signal returned.
+    UMA_HISTOGRAM_COUNTS("WebRTC.ApplicationSocketMismatchPacketsDetected_UDP",

[rkaplow, 2014/12/03 22:30:26]

instead of using a numeric histogram, it seems to me you want to see when
completion signal was not returned.
You can use  UMA_HISTOGRAM_BOOLEAN for something like this:

ie socket_mismatch = send_metrics.packet_id != 0 &&
      in_flight_packet_records_.front().packet_id + 100 <
          send_metrics.packet_id
and then
UMA_HISTOGRAM_BOOLEAN("WebRTC.ApplicationSocketMismatchPacketsDetected_UDP",
socket_mismatch)

or something like that. The advantage (other than allocated less space) is you
will actually mark down how many times it did not occur. 
If you're not interested in that case then you can just log true inside your if
clause.

[guoweis_left_chromium, 2014/12/08 21:46:08]

Done.

+                         1);
+  }
 
   DCHECK_LE(send_bytes_available_, kMaximumInFlightBytes);
 
-  in_flight_packet_sizes_.pop_front();
+  in_flight_packet_records_.erase(it);
   TraceSendThrottlingState();
 
   if (writable_signal_expected_ && send_bytes_available_ > 0) {
     WebRtcLogMessage(base::StringPrintf(
         "IpcPacketSocket: sending is unblocked. %d packets in flight.",
-        static_cast<int>(in_flight_packet_sizes_.size())));
+        static_cast<int>(in_flight_packet_records_.size())));
 
     SignalReadyToSend(this);
     writable_signal_expected_ = false;