Add transaction id to CandidatePairEvents.

The transaction id is a randomly generated number used to link stun
requests and responses (https://tools.ietf.org/html/rfc5389#section-6).
Logging this will help us debug ICE network issues.

Bug: webrtc:9972
Change-Id: I93167cb119aad99156e8727b6e4eeeff5198f924
Reviewed-on: https://webrtc-review.googlesource.com/c/109720
Commit-Queue: Zach Stein <zstein@webrtc.org>
Reviewed-by: Qingsi Wang <qingsi@webrtc.org>
Reviewed-by: Elad Alon <eladalon@webrtc.org>
Reviewed-by: Björn Terelius <terelius@webrtc.org>
Cr-Commit-Position: refs/heads/master@{#25848}

logging/rtc_event_log/events/rtc_event_ice_candidate_pair.cc

@@ -16,14 +16,18 @@ namespace webrtc {
 
 RtcEventIceCandidatePair::RtcEventIceCandidatePair(
     IceCandidatePairEventType type,
-    uint32_t candidate_pair_id)
-    : type_(type), candidate_pair_id_(candidate_pair_id) {}
+    uint32_t candidate_pair_id,
+    uint32_t transaction_id)
+    : type_(type),
+      candidate_pair_id_(candidate_pair_id),
+      transaction_id_(transaction_id) {}
 
 RtcEventIceCandidatePair::RtcEventIceCandidatePair(
     const RtcEventIceCandidatePair& other)
     : RtcEvent(other.timestamp_us_),
       type_(other.type_),
-      candidate_pair_id_(other.candidate_pair_id_) {}
+      candidate_pair_id_(other.candidate_pair_id_),
+      transaction_id_(other.transaction_id_) {}
 
 RtcEventIceCandidatePair::~RtcEventIceCandidatePair() = default;
 

logging/rtc_event_log/events/rtc_event_ice_candidate_pair.h

@@ -29,7 +29,8 @@ enum class IceCandidatePairEventType {
 class RtcEventIceCandidatePair final : public RtcEvent {
  public:
   RtcEventIceCandidatePair(IceCandidatePairEventType type,
-                           uint32_t candidate_pair_id);
+                           uint32_t candidate_pair_id,
+                           uint32_t transaction_id);
 
   ~RtcEventIceCandidatePair() override;
 
@@ -41,12 +42,14 @@ class RtcEventIceCandidatePair final : public RtcEvent {
 
   IceCandidatePairEventType type() const { return type_; }
   uint32_t candidate_pair_id() const { return candidate_pair_id_; }
+  uint32_t transaction_id() const { return transaction_id_; }
 
  private:
   RtcEventIceCandidatePair(const RtcEventIceCandidatePair& other);
 
   const IceCandidatePairEventType type_;
   const uint32_t candidate_pair_id_;
+  const uint32_t transaction_id_;
 };
 
 }  // namespace webrtc

logging/rtc_event_log/icelogger.cc

@@ -31,12 +31,13 @@ void IceEventLog::LogCandidatePairConfig(
 }
 
 void IceEventLog::LogCandidatePairEvent(IceCandidatePairEventType type,
-                                        uint32_t candidate_pair_id) {
+                                        uint32_t candidate_pair_id,
+                                        uint32_t transaction_id) {
   if (event_log_ == nullptr) {
     return;
   }
-  event_log_->Log(
-      absl::make_unique<RtcEventIceCandidatePair>(type, candidate_pair_id));
+  event_log_->Log(absl::make_unique<RtcEventIceCandidatePair>(
+      type, candidate_pair_id, transaction_id));
 }
 
 void IceEventLog::DumpCandidatePairDescriptionToMemoryAsConfigEvents() const {

logging/rtc_event_log/icelogger.h

@@ -36,7 +36,8 @@ class IceEventLog {
       const IceCandidatePairDescription& candidate_pair_desc);
 
   void LogCandidatePairEvent(IceCandidatePairEventType type,
-                             uint32_t candidate_pair_id);
+                             uint32_t candidate_pair_id,
+                             uint32_t transaction_id);
 
   // This method constructs a config event for each candidate pair with their
   // description and logs these config events. It is intended to be called when

logging/rtc_event_log/rtc_event_log_unittest_helper.cc

@@ -214,8 +214,10 @@ EventGenerator::NewIceCandidatePair() {
       static_cast<IceCandidatePairEventType>(prng_.Rand(
           static_cast<uint32_t>(IceCandidatePairEventType::kNumValues) - 1));
   uint32_t pair_id = prng_.Rand<uint32_t>();
+  uint32_t transaction_id = prng_.Rand<uint32_t>();
 
-  return absl::make_unique<RtcEventIceCandidatePair>(type, pair_id);
+  return absl::make_unique<RtcEventIceCandidatePair>(type, pair_id,
+                                                     transaction_id);
 }
 
 rtcp::ReportBlock EventGenerator::NewReportBlock() {

p2p/base/port.cc

@@ -860,7 +860,8 @@ void Port::SendBindingResponse(StunMessage* request,
 
     conn->stats_.sent_ping_responses++;
     conn->LogCandidatePairEvent(
-        webrtc::IceCandidatePairEventType::kCheckResponseSent);
+        webrtc::IceCandidatePairEventType::kCheckResponseSent,
+        request->reduced_transaction_id());
   }
 }
 
@@ -1340,7 +1341,8 @@ void Connection::HandleBindingRequest(IceMessage* msg) {
   }
 
   stats_.recv_ping_requests++;
-  LogCandidatePairEvent(webrtc::IceCandidatePairEventType::kCheckReceived);
+  LogCandidatePairEvent(webrtc::IceCandidatePairEventType::kCheckReceived,
+                        msg->reduced_transaction_id());
 
   // This is a validated stun request from remote peer.
   port_->SendBindingResponse(msg, remote_addr);
@@ -1677,11 +1679,12 @@ void Connection::LogCandidatePairConfig(
   ice_event_log_->LogCandidatePairConfig(type, id(), ToLogDescription());
 }
 
-void Connection::LogCandidatePairEvent(webrtc::IceCandidatePairEventType type) {
+void Connection::LogCandidatePairEvent(webrtc::IceCandidatePairEventType type,
+                                       uint32_t transaction_id) {
   if (ice_event_log_ == nullptr) {
     return;
   }
-  ice_event_log_->LogCandidatePairEvent(type, id());
+  ice_event_log_->LogCandidatePairEvent(type, id(), transaction_id);
 }
 
 void Connection::OnConnectionRequestResponse(ConnectionRequest* request,
@@ -1708,7 +1711,8 @@ void Connection::OnConnectionRequestResponse(ConnectionRequest* request,
 
   stats_.recv_ping_responses++;
   LogCandidatePairEvent(
-      webrtc::IceCandidatePairEventType::kCheckResponseReceived);
+      webrtc::IceCandidatePairEventType::kCheckResponseReceived,
+      response->reduced_transaction_id());
 
   MaybeUpdateLocalCandidate(request, response);
 }
@@ -1754,7 +1758,8 @@ void Connection::OnConnectionRequestSent(ConnectionRequest* request) {
                  << ", use_candidate=" << use_candidate_attr()
                  << ", nomination=" << nomination();
   stats_.sent_ping_requests_total++;
-  LogCandidatePairEvent(webrtc::IceCandidatePairEventType::kCheckSent);
+  LogCandidatePairEvent(webrtc::IceCandidatePairEventType::kCheckSent,
+                        request->reduced_transaction_id());
   if (stats_.recv_ping_responses == 0) {
     stats_.sent_ping_requests_before_first_response++;
   }

p2p/base/port.h

@@ -789,7 +789,8 @@ class Connection : public CandidatePairInterface,
                                  StunMessage* response);
 
   void LogCandidatePairConfig(webrtc::IceCandidatePairConfigType type);
-  void LogCandidatePairEvent(webrtc::IceCandidatePairEventType type);
+  void LogCandidatePairEvent(webrtc::IceCandidatePairEventType type,
+                             uint32_t transaction_id);
 
   WriteState write_state_;
   bool receiving_;

p2p/base/stun.cc

@@ -26,6 +26,25 @@
 using rtc::ByteBufferReader;
 using rtc::ByteBufferWriter;
 
+namespace {
+
+uint32_t ReduceTransactionId(const std::string& transaction_id) {
+  RTC_DCHECK(transaction_id.length() == cricket::kStunTransactionIdLength ||
+             transaction_id.length() ==
+                 cricket::kStunLegacyTransactionIdLength);
+  uint32_t transaction_id_as_ints[4];
+  memcpy(transaction_id_as_ints, transaction_id.c_str(),
+         transaction_id.length());
+
+  uint32_t result = 0;
+  for (size_t i = 0; i < transaction_id.length() / 4; ++i) {
+    result ^= transaction_id_as_ints[i];
+  }
+  return result;
+}
+
+}  // namespace
+
 namespace cricket {
 
 const char STUN_ERROR_REASON_TRY_ALTERNATE_SERVER[] = "Try Alternate Server";
@@ -68,6 +87,7 @@ bool StunMessage::SetTransactionID(const std::string& str) {
     return false;
   }
   transaction_id_ = str;
+  reduced_transaction_id_ = ReduceTransactionId(transaction_id_);
   return true;
 }
 
@@ -354,6 +374,7 @@ bool StunMessage::Read(ByteBufferReader* buf) {
   }
   RTC_DCHECK(IsValidTransactionId(transaction_id));
   transaction_id_ = transaction_id;
+  reduced_transaction_id_ = ReduceTransactionId(transaction_id_);
 
   if (length_ != buf->Length())
     return false;

p2p/base/stun.h

@@ -141,6 +141,7 @@ class StunMessage {
   int type() const { return type_; }
   size_t length() const { return length_; }
   const std::string& transaction_id() const { return transaction_id_; }
+  uint32_t reduced_transaction_id() const { return reduced_transaction_id_; }
 
   // Returns true if the message confirms to RFC3489 rather than
   // RFC5389. The main difference between two version of the STUN
@@ -214,6 +215,7 @@ class StunMessage {
   uint16_t type_;
   uint16_t length_;
   std::string transaction_id_;
+  uint32_t reduced_transaction_id_;
   std::vector<std::unique_ptr<StunAttribute>> attrs_;
   uint32_t stun_magic_cookie_;
 };

p2p/base/stunrequest.h

@@ -100,6 +100,11 @@ class StunRequest : public rtc::MessageHandler {
   // Returns the transaction ID of this request.
   const std::string& id() { return msg_->transaction_id(); }
 
+  // Returns the reduced transaction ID of this request.
+  uint32_t reduced_transaction_id() const {
+    return msg_->reduced_transaction_id();
+  }
+
   // the origin value
   const std::string& origin() const { return origin_; }
   void set_origin(const std::string& origin) { origin_ = origin; }