From c60a77731d68c8648135372dbe54c92dfba731bd Mon Sep 17 00:00:00 2001
From: Bjorn Terelius <terelius@webrtc.org>
Date: Wed, 5 Dec 2018 21:15:30 +0100
Subject: [PATCH] Process RTP before RTCP in RTC event log analyzer.
MIME-Version: 1.0
Content-Type: text/plain; charset=UTF-8
Content-Transfer-Encoding: 8bit

This handles an unlikely corner case where you receive a RTCP feedback for a packet the same millisecond that you send it.

Bug: None
Change-Id: I77f460bef4073d4d9c5633c88f4d2dd8470f8577
Reviewed-on: https://webrtc-review.googlesource.com/c/113305
Commit-Queue: Björn Terelius <terelius@webrtc.org>
Reviewed-by: Elad Alon <eladalon@webrtc.org>
Cr-Commit-Position: refs/heads/master@{#25911}
---
 .../rtc_event_log/rtc_event_log_parser_new.cc | 28 +++++++--------
 rtc_tools/event_log_visualizer/analyzer.cc    | 36 +++++++++----------
 2 files changed, 32 insertions(+), 32 deletions(-)

diff --git a/logging/rtc_event_log/rtc_event_log_parser_new.cc b/logging/rtc_event_log/rtc_event_log_parser_new.cc
index 14eb6cb2e1..7ae7fefe58 100644
--- a/logging/rtc_event_log/rtc_event_log_parser_new.cc
+++ b/logging/rtc_event_log/rtc_event_log_parser_new.cc
@@ -1819,20 +1819,6 @@ const std::vector<MatchedSendArrivalTimes> GetNetworkTrace(
   std::vector<MatchedSendArrivalTimes> rtp_rtcp_matched;
   while (time_us != std::numeric_limits<int64_t>::max()) {
     clock.AdvanceTimeMicroseconds(time_us - clock.TimeInMicroseconds());
-    if (clock.TimeInMicroseconds() >= NextRtcpTime()) {
-      RTC_DCHECK_EQ(clock.TimeInMicroseconds(), NextRtcpTime());
-      feedback_adapter.ProcessTransportFeedback(
-          rtcp_iterator->transport_feedback);
-      std::vector<PacketFeedback> feedback =
-          feedback_adapter.GetTransportFeedbackVector();
-      SortPacketFeedbackVectorWithLoss(&feedback);
-      for (const PacketFeedback& packet : feedback) {
-        rtp_rtcp_matched.emplace_back(
-            clock.TimeInMilliseconds(), packet.send_time_ms,
-            packet.arrival_time_ms, packet.payload_size);
-      }
-      ++rtcp_iterator;
-    }
     if (clock.TimeInMicroseconds() >= NextRtpTime()) {
       RTC_DCHECK_EQ(clock.TimeInMicroseconds(), NextRtpTime());
       const RtpPacketType& rtp_packet = *rtp_iterator->second;
@@ -1858,6 +1844,20 @@ const std::vector<MatchedSendArrivalTimes> GetNetworkTrace(
       }
       ++rtp_iterator;
     }
+    if (clock.TimeInMicroseconds() >= NextRtcpTime()) {
+      RTC_DCHECK_EQ(clock.TimeInMicroseconds(), NextRtcpTime());
+      feedback_adapter.ProcessTransportFeedback(
+          rtcp_iterator->transport_feedback);
+      std::vector<PacketFeedback> feedback =
+          feedback_adapter.GetTransportFeedbackVector();
+      SortPacketFeedbackVectorWithLoss(&feedback);
+      for (const PacketFeedback& packet : feedback) {
+        rtp_rtcp_matched.emplace_back(
+            clock.TimeInMilliseconds(), packet.send_time_ms,
+            packet.arrival_time_ms, packet.payload_size);
+      }
+      ++rtcp_iterator;
+    }
     time_us = std::min(NextRtpTime(), NextRtcpTime());
   }
   return rtp_rtcp_matched;
diff --git a/rtc_tools/event_log_visualizer/analyzer.cc b/rtc_tools/event_log_visualizer/analyzer.cc
index 9c0a1d6f75..8d346f03e0 100644
--- a/rtc_tools/event_log_visualizer/analyzer.cc
+++ b/rtc_tools/event_log_visualizer/analyzer.cc
@@ -1124,6 +1124,24 @@ void EventLogAnalyzer::CreateSendSideBweSimulationGraph(Plot* plot) {
   int64_t last_update_us = 0;
   while (time_us != std::numeric_limits<int64_t>::max()) {
     clock.AdvanceTimeMicroseconds(time_us - clock.TimeInMicroseconds());
+    if (clock.TimeInMicroseconds() >= NextRtpTime()) {
+      RTC_DCHECK_EQ(clock.TimeInMicroseconds(), NextRtpTime());
+      const RtpPacketType& rtp_packet = *rtp_iterator->second;
+      if (rtp_packet.rtp.header.extension.hasTransportSequenceNumber) {
+        RTC_DCHECK(rtp_packet.rtp.header.extension.hasTransportSequenceNumber);
+        transport_feedback.AddPacket(
+            rtp_packet.rtp.header.ssrc,
+            rtp_packet.rtp.header.extension.transportSequenceNumber,
+            rtp_packet.rtp.total_length, PacedPacketInfo());
+        rtc::SentPacket sent_packet(
+            rtp_packet.rtp.header.extension.transportSequenceNumber,
+            rtp_packet.rtp.log_time_us() / 1000);
+        auto sent_msg = transport_feedback.ProcessSentPacket(sent_packet);
+        if (sent_msg)
+          observer.Update(goog_cc->OnSentPacket(*sent_msg));
+      }
+      ++rtp_iterator;
+    }
     if (clock.TimeInMicroseconds() >= NextRtcpTime()) {
       RTC_DCHECK_EQ(clock.TimeInMicroseconds(), NextRtcpTime());
 
@@ -1154,24 +1172,6 @@ void EventLogAnalyzer::CreateSendSideBweSimulationGraph(Plot* plot) {
 #endif  // !(BWE_TEST_LOGGING_COMPILE_TIME_ENABLE)
       ++rtcp_iterator;
     }
-    if (clock.TimeInMicroseconds() >= NextRtpTime()) {
-      RTC_DCHECK_EQ(clock.TimeInMicroseconds(), NextRtpTime());
-      const RtpPacketType& rtp_packet = *rtp_iterator->second;
-      if (rtp_packet.rtp.header.extension.hasTransportSequenceNumber) {
-        RTC_DCHECK(rtp_packet.rtp.header.extension.hasTransportSequenceNumber);
-        transport_feedback.AddPacket(
-            rtp_packet.rtp.header.ssrc,
-            rtp_packet.rtp.header.extension.transportSequenceNumber,
-            rtp_packet.rtp.total_length, PacedPacketInfo());
-        rtc::SentPacket sent_packet(
-            rtp_packet.rtp.header.extension.transportSequenceNumber,
-            rtp_packet.rtp.log_time_us() / 1000);
-        auto sent_msg = transport_feedback.ProcessSentPacket(sent_packet);
-        if (sent_msg)
-          observer.Update(goog_cc->OnSentPacket(*sent_msg));
-      }
-      ++rtp_iterator;
-    }
     if (clock.TimeInMicroseconds() >= NextProcessTime()) {
       RTC_DCHECK_EQ(clock.TimeInMicroseconds(), NextProcessTime());
       ProcessInterval msg;