diff --git a/rtc_tools/event_log_visualizer/analyzer.cc b/rtc_tools/event_log_visualizer/analyzer.cc index 880bec3195..3bdfbf32a0 100644 --- a/rtc_tools/event_log_visualizer/analyzer.cc +++ b/rtc_tools/event_log_visualizer/analyzer.cc @@ -177,13 +177,13 @@ constexpr float kBottomMargin = 0.02f; constexpr float kTopMargin = 0.05f; absl::optional NetworkDelayDiff_AbsSendTime( - const LoggedRtpPacket& old_packet, - const LoggedRtpPacket& new_packet) { - if (old_packet.header.extension.hasAbsoluteSendTime && - new_packet.header.extension.hasAbsoluteSendTime) { + const LoggedRtpPacketIncoming& old_packet, + const LoggedRtpPacketIncoming& new_packet) { + if (old_packet.rtp.header.extension.hasAbsoluteSendTime && + new_packet.rtp.header.extension.hasAbsoluteSendTime) { int64_t send_time_diff = WrappingDifference( - new_packet.header.extension.absoluteSendTime, - old_packet.header.extension.absoluteSendTime, 1ul << 24); + new_packet.rtp.header.extension.absoluteSendTime, + old_packet.rtp.header.extension.absoluteSendTime, 1ul << 24); int64_t recv_time_diff = new_packet.log_time_us() - old_packet.log_time_us(); double delay_change_us = @@ -195,34 +195,31 @@ absl::optional NetworkDelayDiff_AbsSendTime( } absl::optional NetworkDelayDiff_CaptureTime( - const LoggedRtpPacket& old_packet, - const LoggedRtpPacket& new_packet) { - int64_t send_time_diff = WrappingDifference( - new_packet.header.timestamp, old_packet.header.timestamp, 1ull << 32); + const LoggedRtpPacketIncoming& old_packet, + const LoggedRtpPacketIncoming& new_packet, + const double sample_rate) { + int64_t send_time_diff = + WrappingDifference(new_packet.rtp.header.timestamp, + old_packet.rtp.header.timestamp, 1ull << 32); int64_t recv_time_diff = new_packet.log_time_us() - old_packet.log_time_us(); - const double kVideoSampleRate = 90000; - // TODO(terelius): We treat all streams as video for now, even though - // audio might be sampled at e.g. 16kHz, because it is really difficult to - // figure out the true sampling rate of a stream. The effect is that the - // delay will be scaled incorrectly for non-video streams. - double delay_change = static_cast(recv_time_diff) / 1000 - - static_cast(send_time_diff) / kVideoSampleRate * 1000; + static_cast(send_time_diff) / sample_rate * 1000; if (delay_change < -10000 || 10000 < delay_change) { RTC_LOG(LS_WARNING) << "Very large delay change. Timestamps correct?"; - RTC_LOG(LS_WARNING) << "Old capture time " << old_packet.header.timestamp - << ", received time " << old_packet.log_time_us(); - RTC_LOG(LS_WARNING) << "New capture time " << new_packet.header.timestamp - << ", received time " << new_packet.log_time_us(); + RTC_LOG(LS_WARNING) << "Old capture time " + << old_packet.rtp.header.timestamp << ", received time " + << old_packet.log_time_us(); + RTC_LOG(LS_WARNING) << "New capture time " + << new_packet.rtp.header.timestamp << ", received time " + << new_packet.log_time_us(); RTC_LOG(LS_WARNING) << "Receive time difference " << recv_time_diff << " = " << static_cast(recv_time_diff) / kNumMicrosecsPerSec << "s"; RTC_LOG(LS_WARNING) << "Send time difference " << send_time_diff << " = " - << static_cast(send_time_diff) / - kVideoSampleRate + << static_cast(send_time_diff) / sample_rate << "s"; } return delay_change; @@ -276,9 +273,10 @@ void AccumulatePairs( for (size_t i = 1; i < data.size(); i++) { float x = fx(data[i]); absl::optional y = fy(data[i - 1], data[i]); - if (y) + if (y) { sum += *y; - result->points.emplace_back(x, static_cast(sum)); + result->points.emplace_back(x, static_cast(sum)); + } } } @@ -737,71 +735,58 @@ void EventLogAnalyzer::CreateIncomingPacketLossGraph(Plot* plot) { plot->SetTitle("Estimated incoming loss rate"); } -void EventLogAnalyzer::CreateIncomingDelayDeltaGraph(Plot* plot) { - for (const auto& stream : parsed_log_.rtp_packets_by_ssrc(kIncomingPacket)) { - // Filter on SSRC. - if (!MatchingSsrc(stream.ssrc, desired_ssrc_) || - IsAudioSsrc(kIncomingPacket, stream.ssrc) || - !IsVideoSsrc(kIncomingPacket, stream.ssrc) || - IsRtxSsrc(kIncomingPacket, stream.ssrc)) { - continue; - } - - TimeSeries capture_time_data( - GetStreamName(kIncomingPacket, stream.ssrc) + " capture-time", - LineStyle::kBar); - auto ToCallTime = [this](const LoggedRtpPacket& packet) { - return this->ToCallTimeSec(packet.log_time_us()); - }; - ProcessPairs( - ToCallTime, NetworkDelayDiff_CaptureTime, stream.packet_view, - &capture_time_data); - plot->AppendTimeSeries(std::move(capture_time_data)); - - TimeSeries send_time_data( - GetStreamName(kIncomingPacket, stream.ssrc) + " abs-send-time", - LineStyle::kBar); - ProcessPairs(ToCallTime, - NetworkDelayDiff_AbsSendTime, - stream.packet_view, &send_time_data); - plot->AppendTimeSeries(std::move(send_time_data)); - } - - plot->SetXAxis(ToCallTimeSec(begin_time_), call_duration_s_, "Time (s)", - kLeftMargin, kRightMargin); - plot->SetSuggestedYAxis(0, 1, "Latency change (ms)", kBottomMargin, - kTopMargin); - plot->SetTitle("Network latency difference between consecutive packets"); -} - void EventLogAnalyzer::CreateIncomingDelayGraph(Plot* plot) { - for (const auto& stream : parsed_log_.rtp_packets_by_ssrc(kIncomingPacket)) { + for (const auto& stream : parsed_log_.incoming_rtp_packets_by_ssrc()) { // Filter on SSRC. if (!MatchingSsrc(stream.ssrc, desired_ssrc_) || - IsAudioSsrc(kIncomingPacket, stream.ssrc) || - !IsVideoSsrc(kIncomingPacket, stream.ssrc) || IsRtxSsrc(kIncomingPacket, stream.ssrc)) { continue; } + const std::vector& packets = + stream.incoming_packets; + if (packets.size() < 100) { + RTC_LOG(LS_WARNING) << "Can't estimate the RTP clock frequency with " + << packets.size() << " packets in the stream."; + continue; + } + int64_t end_time_us = log_segments_.empty() + ? std::numeric_limits::max() + : log_segments_.front().second; + absl::optional estimated_frequency = + EstimateRtpClockFrequency(packets, end_time_us); + if (!estimated_frequency) + continue; + const double frequency_hz = *estimated_frequency; + if (IsVideoSsrc(kIncomingPacket, stream.ssrc) && frequency_hz != 90000) { + RTC_LOG(LS_WARNING) + << "Video stream should use a 90 kHz clock but appears to use " + << frequency_hz / 1000 << ". Discarding."; + continue; + } + + auto ToCallTime = [this](const LoggedRtpPacketIncoming& packet) { + return this->ToCallTimeSec(packet.log_time_us()); + }; + auto ToNetworkDelay = [frequency_hz]( + const LoggedRtpPacketIncoming& old_packet, + const LoggedRtpPacketIncoming& new_packet) { + return NetworkDelayDiff_CaptureTime(old_packet, new_packet, frequency_hz); + }; + TimeSeries capture_time_data( GetStreamName(kIncomingPacket, stream.ssrc) + " capture-time", LineStyle::kLine); - auto ToCallTime = [this](const LoggedRtpPacket& packet) { - return this->ToCallTimeSec(packet.log_time_us()); - }; - AccumulatePairs( - ToCallTime, NetworkDelayDiff_CaptureTime, stream.packet_view, - &capture_time_data); + AccumulatePairs( + ToCallTime, ToNetworkDelay, packets, &capture_time_data); plot->AppendTimeSeries(std::move(capture_time_data)); TimeSeries send_time_data( GetStreamName(kIncomingPacket, stream.ssrc) + " abs-send-time", LineStyle::kLine); - AccumulatePairs( - ToCallTime, NetworkDelayDiff_AbsSendTime, stream.packet_view, - &send_time_data); - plot->AppendTimeSeries(std::move(send_time_data)); + AccumulatePairs( + ToCallTime, NetworkDelayDiff_AbsSendTime, packets, &send_time_data); + plot->AppendTimeSeriesIfNotEmpty(std::move(send_time_data)); } plot->SetXAxis(ToCallTimeSec(begin_time_), call_duration_s_, "Time (s)", diff --git a/rtc_tools/event_log_visualizer/analyzer.h b/rtc_tools/event_log_visualizer/analyzer.h index 4b8c27c951..c6606c2b1f 100644 --- a/rtc_tools/event_log_visualizer/analyzer.h +++ b/rtc_tools/event_log_visualizer/analyzer.h @@ -45,7 +45,6 @@ class EventLogAnalyzer { void CreateIncomingPacketLossGraph(Plot* plot); - void CreateIncomingDelayDeltaGraph(Plot* plot); void CreateIncomingDelayGraph(Plot* plot); void CreateFractionLossGraph(Plot* plot); diff --git a/rtc_tools/event_log_visualizer/main.cc b/rtc_tools/event_log_visualizer/main.cc index ad90cfbacb..e4e183f8ff 100644 --- a/rtc_tools/event_log_visualizer/main.cc +++ b/rtc_tools/event_log_visualizer/main.cc @@ -54,10 +54,6 @@ WEBRTC_DEFINE_bool( false, "Plot the sequence number difference between consecutive incoming " "packets."); -WEBRTC_DEFINE_bool( - plot_incoming_delay_delta, - false, - "Plot the difference in 1-way path delay between consecutive packets."); WEBRTC_DEFINE_bool( plot_incoming_delay, true, @@ -216,7 +212,6 @@ int main(int argc, char* argv[]) { } else if (strcmp(FLAG_plot_profile, "receiveside_bwe") == 0) { SetAllPlotFlags(false); FLAG_plot_incoming_packet_sizes = true; - FLAG_plot_incoming_delay_delta = true; FLAG_plot_incoming_delay = true; FLAG_plot_incoming_loss_rate = true; FLAG_plot_incoming_bitrate = true; @@ -298,9 +293,6 @@ int main(int argc, char* argv[]) { if (FLAG_plot_incoming_sequence_number_delta) { analyzer.CreateSequenceNumberGraph(collection->AppendNewPlot()); } - if (FLAG_plot_incoming_delay_delta) { - analyzer.CreateIncomingDelayDeltaGraph(collection->AppendNewPlot()); - } if (FLAG_plot_incoming_delay) { analyzer.CreateIncomingDelayGraph(collection->AppendNewPlot()); } @@ -487,7 +479,6 @@ void SetAllPlotFlags(bool setting) { FLAG_plot_audio_playout = setting; FLAG_plot_audio_level = setting; FLAG_plot_incoming_sequence_number_delta = setting; - FLAG_plot_incoming_delay_delta = setting; FLAG_plot_incoming_delay = setting; FLAG_plot_incoming_loss_rate = setting; FLAG_plot_incoming_bitrate = setting;