Refactor/reimplement RTC event log triage alerts.
- Moves AnalyzerConfig and helper functions IsAudioSsrc, IsVideoSsrc, IsRtxSsrc, GetStreamNam and GetLayerName to analyzer_common.h
- Moves log_segments() code to rtc_event_log_parser.h
- Moves TriageAlert/Notification code to a new file with a couple of minor fixes to make it less spammy.
Bug: webrtc:11566
Change-Id: Ib33941d8185f7382fc72ed65768e46015e0320de
Reviewed-on: https://webrtc-review.googlesource.com/c/src/+/174824
Commit-Queue: Björn Terelius <terelius@webrtc.org>
Reviewed-by: Mirko Bonadei <mbonadei@webrtc.org>
Cr-Commit-Position: refs/heads/master@{#31318}
diff --git a/logging/rtc_event_log/rtc_event_log_parser.cc b/logging/rtc_event_log/rtc_event_log_parser.cc
index 4016f84..a3982ba 100644
--- a/logging/rtc_event_log/rtc_event_log_parser.cc
+++ b/logging/rtc_event_log/rtc_event_log_parser.cc
@@ -1215,6 +1215,32 @@
StoreFirstAndLastTimestamp(generic_packets_received_);
StoreFirstAndLastTimestamp(generic_acks_received_);
+ // TODO(terelius): This should be cleaned up. We could also handle
+ // a "missing" end event, by inserting the last previous regular
+ // event rather than the next start event.
+ auto start_iter = start_log_events().begin();
+ auto stop_iter = stop_log_events().begin();
+ while (start_iter != start_log_events().end()) {
+ int64_t start_us = start_iter->log_time_us();
+ ++start_iter;
+ absl::optional<int64_t> next_start_us;
+ if (start_iter != start_log_events().end())
+ next_start_us.emplace(start_iter->log_time_us());
+ if (stop_iter != stop_log_events().end() &&
+ stop_iter->log_time_us() <=
+ next_start_us.value_or(std::numeric_limits<int64_t>::max())) {
+ int64_t stop_us = stop_iter->log_time_us();
+ RTC_PARSE_CHECK_OR_RETURN_LE(start_us, stop_us);
+ log_segments_.emplace_back(start_us, stop_us);
+ ++stop_iter;
+ } else {
+ // We're missing an end event. Assume that it occurred just before the
+ // next start.
+ log_segments_.emplace_back(start_us,
+ next_start_us.value_or(last_timestamp()));
+ }
+ }
+
return status;
}
diff --git a/logging/rtc_event_log/rtc_event_log_parser.h b/logging/rtc_event_log/rtc_event_log_parser.h
index 7a162af..be6b99a 100644
--- a/logging/rtc_event_log/rtc_event_log_parser.h
+++ b/logging/rtc_event_log/rtc_event_log_parser.h
@@ -330,6 +330,20 @@
PacketView<const LoggedRtpPacket> packet_view;
};
+ class LogSegment {
+ public:
+ LogSegment(int64_t start_time_us, int64_t stop_time_us)
+ : start_time_us_(start_time_us), stop_time_us_(stop_time_us) {}
+ int64_t start_time_ms() const { return start_time_us_ / 1000; }
+ int64_t start_time_us() const { return start_time_us_; }
+ int64_t stop_time_ms() const { return stop_time_us_ / 1000; }
+ int64_t stop_time_us() const { return stop_time_us_; }
+
+ private:
+ int64_t start_time_us_;
+ int64_t stop_time_us_;
+ };
+
static webrtc::RtpHeaderExtensionMap GetDefaultHeaderExtensionMap();
explicit ParsedRtcEventLog(
@@ -597,6 +611,8 @@
int64_t first_timestamp() const { return first_timestamp_; }
int64_t last_timestamp() const { return last_timestamp_; }
+ const std::vector<LogSegment>& log_segments() const { return log_segments_; }
+
std::vector<LoggedPacketInfo> GetPacketInfos(PacketDirection direction) const;
std::vector<LoggedPacketInfo> GetIncomingPacketInfos() const {
return GetPacketInfos(kIncomingPacket);
@@ -850,6 +866,9 @@
int64_t first_timestamp_;
int64_t last_timestamp_;
+ // Stores the start and end timestamp for each log segments.
+ std::vector<LogSegment> log_segments_;
+
// The extension maps are mutable to allow us to insert the default
// configuration when parsing an RTP header for an unconfigured stream.
// TODO(terelius): This is only used for the legacy format. Remove once we've
diff --git a/logging/rtc_event_log/rtc_event_log_unittest.cc b/logging/rtc_event_log/rtc_event_log_unittest.cc
index 579c652..5989006 100644
--- a/logging/rtc_event_log/rtc_event_log_unittest.cc
+++ b/logging/rtc_event_log/rtc_event_log_unittest.cc
@@ -739,6 +739,11 @@
EXPECT_EQ(first_timestamp_ms_, parsed_log.first_timestamp() / 1000);
EXPECT_EQ(last_timestamp_ms_, parsed_log.last_timestamp() / 1000);
+ ASSERT_EQ(parsed_log.log_segments().size(), 1u);
+ EXPECT_EQ(parsed_log.log_segments()[0].start_time_ms(),
+ start_time_us_ / 1000);
+ EXPECT_EQ(parsed_log.log_segments()[0].stop_time_ms(), stop_time_us_ / 1000);
+
// Clean up temporary file - can be pretty slow.
remove(temp_filename_.c_str());
}
diff --git a/rtc_tools/BUILD.gn b/rtc_tools/BUILD.gn
index f293853..3d39845 100644
--- a/rtc_tools/BUILD.gn
+++ b/rtc_tools/BUILD.gn
@@ -319,8 +319,12 @@
rtc_library("event_log_visualizer_utils") {
visibility = [ "*" ]
sources = [
+ "rtc_event_log_visualizer/alerts.cc",
+ "rtc_event_log_visualizer/alerts.h",
"rtc_event_log_visualizer/analyzer.cc",
"rtc_event_log_visualizer/analyzer.h",
+ "rtc_event_log_visualizer/analyzer_common.cc",
+ "rtc_event_log_visualizer/analyzer_common.h",
"rtc_event_log_visualizer/log_simulation.cc",
"rtc_event_log_visualizer/log_simulation.h",
"rtc_event_log_visualizer/plot_base.cc",
@@ -329,7 +333,6 @@
"rtc_event_log_visualizer/plot_protobuf.h",
"rtc_event_log_visualizer/plot_python.cc",
"rtc_event_log_visualizer/plot_python.h",
- "rtc_event_log_visualizer/triage_notifications.h",
]
deps = [
":chart_proto",
diff --git a/rtc_tools/rtc_event_log_visualizer/alerts.cc b/rtc_tools/rtc_event_log_visualizer/alerts.cc
new file mode 100644
index 0000000..da059cb
--- /dev/null
+++ b/rtc_tools/rtc_event_log_visualizer/alerts.cc
@@ -0,0 +1,228 @@
+/*
+ * Copyright (c) 2020 The WebRTC project authors. All Rights Reserved.
+ *
+ * Use of this source code is governed by a BSD-style license
+ * that can be found in the LICENSE file in the root of the source
+ * tree. An additional intellectual property rights grant can be found
+ * in the file PATENTS. All contributing project authors may
+ * be found in the AUTHORS file in the root of the source tree.
+ */
+
+#include "rtc_tools/rtc_event_log_visualizer/alerts.h"
+
+#include <stdio.h>
+
+#include <algorithm>
+#include <limits>
+#include <map>
+#include <string>
+
+#include "logging/rtc_event_log/rtc_event_processor.h"
+#include "rtc_base/checks.h"
+#include "rtc_base/format_macros.h"
+#include "rtc_base/logging.h"
+#include "rtc_base/numerics/sequence_number_util.h"
+#include "rtc_base/strings/string_builder.h"
+
+namespace webrtc {
+
+void TriageHelper::Print(FILE* file) {
+ fprintf(file, "========== TRIAGE NOTIFICATIONS ==========\n");
+ for (const auto& alert : triage_alerts_) {
+ fprintf(file, "%d %s. First occurence at %3.3lf\n", alert.second.count,
+ alert.second.explanation.c_str(), alert.second.first_occurence);
+ }
+ fprintf(file, "========== END TRIAGE NOTIFICATIONS ==========\n");
+}
+
+void TriageHelper::AnalyzeStreamGaps(const ParsedRtcEventLog& parsed_log,
+ PacketDirection direction) {
+ // With 100 packets/s (~800kbps), false positives would require 10 s without
+ // data.
+ constexpr int64_t kMaxSeqNumJump = 1000;
+ // With a 90 kHz clock, false positives would require 10 s without data.
+ constexpr int64_t kMaxCaptureTimeJump = 900000;
+
+ std::string seq_num_explanation =
+ direction == kIncomingPacket
+ ? "Incoming RTP sequence number jumps more than 1000. Counter may "
+ "have been reset or rewritten incorrectly in a group call."
+ : "Outgoing RTP sequence number jumps more than 1000. Counter may "
+ "have been reset.";
+ std::string capture_time_explanation =
+ direction == kIncomingPacket ? "Incoming capture time jumps more than "
+ "10s. Clock might have been reset."
+ : "Outgoing capture time jumps more than "
+ "10s. Clock might have been reset.";
+ TriageAlertType seq_num_alert = direction == kIncomingPacket
+ ? TriageAlertType::kIncomingSeqNumJump
+ : TriageAlertType::kOutgoingSeqNumJump;
+ TriageAlertType capture_time_alert =
+ direction == kIncomingPacket ? TriageAlertType::kIncomingCaptureTimeJump
+ : TriageAlertType::kOutgoingCaptureTimeJump;
+
+ const int64_t segment_end_us =
+ parsed_log.log_segments().empty()
+ ? std::numeric_limits<int64_t>::max()
+ : parsed_log.log_segments().front().stop_time_us();
+
+ // Check for gaps in sequence numbers and capture timestamps.
+ for (const auto& stream : parsed_log.rtp_packets_by_ssrc(direction)) {
+ if (IsRtxSsrc(parsed_log, direction, stream.ssrc)) {
+ continue;
+ }
+ SeqNumUnwrapper<uint16_t> seq_num_unwrapper;
+ absl::optional<int64_t> last_seq_num;
+ SeqNumUnwrapper<uint32_t> capture_time_unwrapper;
+ absl::optional<int64_t> last_capture_time;
+ for (const auto& packet : stream.packet_view) {
+ if (packet.log_time_us() > segment_end_us) {
+ // Only process the first (LOG_START, LOG_END) segment.
+ break;
+ }
+
+ int64_t seq_num = seq_num_unwrapper.Unwrap(packet.header.sequenceNumber);
+ if (last_seq_num.has_value() &&
+ std::abs(seq_num - last_seq_num.value()) > kMaxSeqNumJump) {
+ Alert(seq_num_alert, config_.GetCallTimeSec(packet.log_time_us()),
+ seq_num_explanation);
+ }
+ last_seq_num.emplace(seq_num);
+
+ int64_t capture_time =
+ capture_time_unwrapper.Unwrap(packet.header.timestamp);
+ if (last_capture_time.has_value() &&
+ std::abs(capture_time - last_capture_time.value()) >
+ kMaxCaptureTimeJump) {
+ Alert(capture_time_alert, config_.GetCallTimeSec(packet.log_time_us()),
+ capture_time_explanation);
+ }
+ last_capture_time.emplace(capture_time);
+ }
+ }
+}
+
+void TriageHelper::AnalyzeTransmissionGaps(const ParsedRtcEventLog& parsed_log,
+ PacketDirection direction) {
+ constexpr int64_t kMaxRtpTransmissionGap = 500000;
+ constexpr int64_t kMaxRtcpTransmissionGap = 2000000;
+ std::string rtp_explanation =
+ direction == kIncomingPacket
+ ? "No RTP packets received for more than 500ms. This indicates a "
+ "network problem. Temporary video freezes and choppy or robotic "
+ "audio is unavoidable. Unnecessary BWE drops is a known issue."
+ : "No RTP packets sent for more than 500 ms. This might be an issue "
+ "with the pacer.";
+ std::string rtcp_explanation =
+ direction == kIncomingPacket
+ ? "No RTCP packets received for more than 2 s. Could be a longer "
+ "connection outage"
+ : "No RTCP sent for more than 2 s. This is most likely a bug.";
+ TriageAlertType rtp_alert = direction == kIncomingPacket
+ ? TriageAlertType::kIncomingRtpGap
+ : TriageAlertType::kOutgoingRtpGap;
+ TriageAlertType rtcp_alert = direction == kIncomingPacket
+ ? TriageAlertType::kIncomingRtcpGap
+ : TriageAlertType::kOutgoingRtcpGap;
+
+ const int64_t segment_end_us =
+ parsed_log.log_segments().empty()
+ ? std::numeric_limits<int64_t>::max()
+ : parsed_log.log_segments().front().stop_time_us();
+
+ // TODO(terelius): The parser could provide a list of all packets, ordered
+ // by time, for each direction.
+ std::multimap<int64_t, const LoggedRtpPacket*> rtp_in_direction;
+ for (const auto& stream : parsed_log.rtp_packets_by_ssrc(direction)) {
+ for (const LoggedRtpPacket& rtp_packet : stream.packet_view)
+ rtp_in_direction.emplace(rtp_packet.log_time_us(), &rtp_packet);
+ }
+ absl::optional<int64_t> last_rtp_time;
+ for (const auto& kv : rtp_in_direction) {
+ int64_t timestamp = kv.first;
+ if (timestamp > segment_end_us) {
+ // Only process the first (LOG_START, LOG_END) segment.
+ break;
+ }
+ int64_t duration = timestamp - last_rtp_time.value_or(0);
+ if (last_rtp_time.has_value() && duration > kMaxRtpTransmissionGap) {
+ // No packet sent/received for more than 500 ms.
+ Alert(rtp_alert, config_.GetCallTimeSec(timestamp), rtp_explanation);
+ }
+ last_rtp_time.emplace(timestamp);
+ }
+
+ absl::optional<int64_t> last_rtcp_time;
+ if (direction == kIncomingPacket) {
+ for (const auto& rtcp : parsed_log.incoming_rtcp_packets()) {
+ if (rtcp.log_time_us() > segment_end_us) {
+ // Only process the first (LOG_START, LOG_END) segment.
+ break;
+ }
+ int64_t duration = rtcp.log_time_us() - last_rtcp_time.value_or(0);
+ if (last_rtcp_time.has_value() && duration > kMaxRtcpTransmissionGap) {
+ // No feedback sent/received for more than 2000 ms.
+ Alert(rtcp_alert, config_.GetCallTimeSec(rtcp.log_time_us()),
+ rtcp_explanation);
+ }
+ last_rtcp_time.emplace(rtcp.log_time_us());
+ }
+ } else {
+ for (const auto& rtcp : parsed_log.outgoing_rtcp_packets()) {
+ if (rtcp.log_time_us() > segment_end_us) {
+ // Only process the first (LOG_START, LOG_END) segment.
+ break;
+ }
+ int64_t duration = rtcp.log_time_us() - last_rtcp_time.value_or(0);
+ if (last_rtcp_time.has_value() && duration > kMaxRtcpTransmissionGap) {
+ // No feedback sent/received for more than 2000 ms.
+ Alert(rtcp_alert, config_.GetCallTimeSec(rtcp.log_time_us()),
+ rtcp_explanation);
+ }
+ last_rtcp_time.emplace(rtcp.log_time_us());
+ }
+ }
+}
+
+// TODO(terelius): Notifications could possibly be generated by the same code
+// that produces the graphs. There is some code duplication that could be
+// avoided, but that might be solved anyway when we move functionality from the
+// analyzer to the parser.
+void TriageHelper::AnalyzeLog(const ParsedRtcEventLog& parsed_log) {
+ AnalyzeStreamGaps(parsed_log, kIncomingPacket);
+ AnalyzeStreamGaps(parsed_log, kOutgoingPacket);
+ AnalyzeTransmissionGaps(parsed_log, kIncomingPacket);
+ AnalyzeTransmissionGaps(parsed_log, kOutgoingPacket);
+
+ const int64_t segment_end_us =
+ parsed_log.log_segments().empty()
+ ? std::numeric_limits<int64_t>::max()
+ : parsed_log.log_segments().front().stop_time_us();
+
+ int64_t first_occurence = parsed_log.last_timestamp();
+ constexpr double kMaxLossFraction = 0.05;
+ // Loss feedback
+ int64_t total_lost_packets = 0;
+ int64_t total_expected_packets = 0;
+ for (auto& bwe_update : parsed_log.bwe_loss_updates()) {
+ if (bwe_update.log_time_us() > segment_end_us) {
+ // Only process the first (LOG_START, LOG_END) segment.
+ break;
+ }
+ int64_t lost_packets = static_cast<double>(bwe_update.fraction_lost) / 255 *
+ bwe_update.expected_packets;
+ total_lost_packets += lost_packets;
+ total_expected_packets += bwe_update.expected_packets;
+ if (bwe_update.fraction_lost >= 255 * kMaxLossFraction) {
+ first_occurence = std::min(first_occurence, bwe_update.log_time_us());
+ }
+ }
+ double avg_outgoing_loss =
+ static_cast<double>(total_lost_packets) / total_expected_packets;
+ if (avg_outgoing_loss > kMaxLossFraction) {
+ Alert(TriageAlertType::kOutgoingHighLoss, first_occurence,
+ "More than 5% of outgoing packets lost.");
+ }
+}
+
+} // namespace webrtc
diff --git a/rtc_tools/rtc_event_log_visualizer/alerts.h b/rtc_tools/rtc_event_log_visualizer/alerts.h
new file mode 100644
index 0000000..9e559e6
--- /dev/null
+++ b/rtc_tools/rtc_event_log_visualizer/alerts.h
@@ -0,0 +1,86 @@
+/*
+ * Copyright (c) 2020 The WebRTC project authors. All Rights Reserved.
+ *
+ * Use of this source code is governed by a BSD-style license
+ * that can be found in the LICENSE file in the root of the source
+ * tree. An additional intellectual property rights grant can be found
+ * in the file PATENTS. All contributing project authors may
+ * be found in the AUTHORS file in the root of the source tree.
+ */
+
+#ifndef RTC_TOOLS_RTC_EVENT_LOG_VISUALIZER_ALERTS_H_
+#define RTC_TOOLS_RTC_EVENT_LOG_VISUALIZER_ALERTS_H_
+
+#include <stdio.h>
+
+#include <map>
+#include <string>
+#include <utility>
+
+#include "absl/strings/string_view.h"
+#include "logging/rtc_event_log/rtc_event_log_parser.h"
+#include "rtc_base/constructor_magic.h"
+#include "rtc_tools/rtc_event_log_visualizer/analyzer_common.h"
+
+namespace webrtc {
+
+enum class TriageAlertType {
+ kUnknown = 0,
+ kIncomingRtpGap,
+ kOutgoingRtpGap,
+ kIncomingRtcpGap,
+ kOutgoingRtcpGap,
+ kIncomingSeqNumJump,
+ kOutgoingSeqNumJump,
+ kIncomingCaptureTimeJump,
+ kOutgoingCaptureTimeJump,
+ kOutgoingHighLoss,
+ kLast,
+};
+
+struct TriageAlert {
+ TriageAlertType type = TriageAlertType::kUnknown;
+ int count = 0;
+ float first_occurence = -1;
+ std::string explanation;
+};
+
+class TriageHelper {
+ public:
+ explicit TriageHelper(const AnalyzerConfig& config) : config_(config) {}
+
+ void AnalyzeLog(const ParsedRtcEventLog& parsed_log);
+
+ void AnalyzeStreamGaps(const ParsedRtcEventLog& parsed_log,
+ PacketDirection direction);
+ void AnalyzeTransmissionGaps(const ParsedRtcEventLog& parsed_log,
+ PacketDirection direction);
+ void Print(FILE* file);
+
+ private:
+ AnalyzerConfig config_;
+ std::map<TriageAlertType, TriageAlert> triage_alerts_;
+
+ void Alert(TriageAlertType type,
+ float time_seconds,
+ absl::string_view explanation) {
+ std::map<TriageAlertType, TriageAlert>::iterator it =
+ triage_alerts_.find(type);
+
+ if (it == triage_alerts_.end()) {
+ TriageAlert alert;
+ alert.type = type;
+ alert.first_occurence = time_seconds;
+ alert.count = 1;
+ alert.explanation = std::string(explanation);
+ triage_alerts_.insert(std::make_pair(type, alert));
+ } else {
+ it->second.count += 1;
+ }
+ }
+ RTC_DISALLOW_COPY_AND_ASSIGN(TriageHelper);
+};
+
+} // namespace webrtc
+
+#endif // RTC_TOOLS_RTC_EVENT_LOG_VISUALIZER_ALERTS_H_
diff --git a/rtc_tools/rtc_event_log_visualizer/analyzer.cc b/rtc_tools/rtc_event_log_visualizer/analyzer.cc
index 9fcb510..9a9a455 100644
--- a/rtc_tools/rtc_event_log_visualizer/analyzer.cc
+++ b/rtc_tools/rtc_event_log_visualizer/analyzer.cc
@@ -465,31 +465,14 @@
config_.begin_time_ = config_.end_time_ = 0;
}
- const auto& log_start_events = parsed_log_.start_log_events();
- const auto& log_end_events = parsed_log_.stop_log_events();
- auto start_iter = log_start_events.begin();
- auto end_iter = log_end_events.begin();
- while (start_iter != log_start_events.end()) {
- int64_t start = start_iter->log_time_us();
- ++start_iter;
- absl::optional<int64_t> next_start;
- if (start_iter != log_start_events.end())
- next_start.emplace(start_iter->log_time_us());
- if (end_iter != log_end_events.end() &&
- end_iter->log_time_us() <=
- next_start.value_or(std::numeric_limits<int64_t>::max())) {
- int64_t end = end_iter->log_time_us();
- RTC_DCHECK_LE(start, end);
- log_segments_.push_back(std::make_pair(start, end));
- ++end_iter;
- } else {
- // we're missing an end event. Assume that it occurred just before the
- // next start.
- log_segments_.push_back(
- std::make_pair(start, next_start.value_or(config_.end_time_)));
- }
- }
- RTC_LOG(LS_INFO) << "Found " << log_segments_.size()
+ RTC_LOG(LS_INFO) << "Found " << parsed_log_.log_segments().size()
+ << " (LOG_START, LOG_END) segments in log.";
+}
+
+EventLogAnalyzer::EventLogAnalyzer(const ParsedRtcEventLog& log,
+ const AnalyzerConfig& config)
+ : parsed_log_(log), config_(config) {
+ RTC_LOG(LS_INFO) << "Found " << parsed_log_.log_segments().size()
<< " (LOG_START, LOG_END) segments in log.";
}
@@ -527,7 +510,7 @@
continue;
}
- TimeSeries time_series(GetStreamName(direction, stream.ssrc),
+ TimeSeries time_series(GetStreamName(parsed_log_, direction, stream.ssrc),
LineStyle::kBar);
auto GetPacketSize = [](const LoggedRtpPacket& packet) {
return absl::optional<float>(packet.total_length);
@@ -597,8 +580,8 @@
for (const auto& stream : parsed_log_.rtp_packets_by_ssrc(direction)) {
if (!MatchingSsrc(stream.ssrc, desired_ssrc_))
continue;
- std::string label =
- std::string("RTP ") + GetStreamName(direction, stream.ssrc);
+ std::string label = std::string("RTP ") +
+ GetStreamName(parsed_log_, direction, stream.ssrc);
CreateAccumulatedPacketsTimeSeries(plot, stream.packet_view, label);
}
std::string label =
@@ -627,7 +610,8 @@
continue;
}
TimeSeries time_series(
- std::string("RTP ") + GetStreamName(direction, stream.ssrc),
+ std::string("RTP ") +
+ GetStreamName(parsed_log_, direction, stream.ssrc),
LineStyle::kLine);
MovingAverage<LoggedRtpPacket, double>(CountPackets, stream.packet_view,
config_, &time_series);
@@ -736,9 +720,9 @@
void EventLogAnalyzer::CreateAudioLevelGraph(PacketDirection direction,
Plot* plot) {
for (const auto& stream : parsed_log_.rtp_packets_by_ssrc(direction)) {
- if (!IsAudioSsrc(direction, stream.ssrc))
+ if (!IsAudioSsrc(parsed_log_, direction, stream.ssrc))
continue;
- TimeSeries time_series(GetStreamName(direction, stream.ssrc),
+ TimeSeries time_series(GetStreamName(parsed_log_, direction, stream.ssrc),
LineStyle::kLine);
for (auto& packet : stream.packet_view) {
if (packet.header.extension.hasAudioLevel) {
@@ -767,8 +751,9 @@
continue;
}
- TimeSeries time_series(GetStreamName(kIncomingPacket, stream.ssrc),
- LineStyle::kBar);
+ TimeSeries time_series(
+ GetStreamName(parsed_log_, kIncomingPacket, stream.ssrc),
+ LineStyle::kBar);
auto GetSequenceNumberDiff = [](const LoggedRtpPacketIncoming& old_packet,
const LoggedRtpPacketIncoming& new_packet) {
int64_t diff =
@@ -801,8 +786,9 @@
continue;
}
- TimeSeries time_series(GetStreamName(kIncomingPacket, stream.ssrc),
- LineStyle::kLine, PointStyle::kHighlight);
+ TimeSeries time_series(
+ GetStreamName(parsed_log_, kIncomingPacket, stream.ssrc),
+ LineStyle::kLine, PointStyle::kHighlight);
// TODO(terelius): Should the window and step size be read from the class
// instead?
const int64_t kWindowUs = 1000000;
@@ -855,7 +841,7 @@
for (const auto& stream : parsed_log_.incoming_rtp_packets_by_ssrc()) {
// Filter on SSRC.
if (!MatchingSsrc(stream.ssrc, desired_ssrc_) ||
- IsRtxSsrc(kIncomingPacket, stream.ssrc)) {
+ IsRtxSsrc(parsed_log_, kIncomingPacket, stream.ssrc)) {
continue;
}
@@ -866,15 +852,17 @@
<< packets.size() << " packets in the stream.";
continue;
}
- int64_t end_time_us = log_segments_.empty()
- ? std::numeric_limits<int64_t>::max()
- : log_segments_.front().second;
+ int64_t segment_end_us =
+ parsed_log_.log_segments().empty()
+ ? std::numeric_limits<int64_t>::max()
+ : parsed_log_.log_segments().front().stop_time_us();
absl::optional<uint32_t> estimated_frequency =
- EstimateRtpClockFrequency(packets, end_time_us);
+ EstimateRtpClockFrequency(packets, segment_end_us);
if (!estimated_frequency)
continue;
const double frequency_hz = *estimated_frequency;
- if (IsVideoSsrc(kIncomingPacket, stream.ssrc) && frequency_hz != 90000) {
+ if (IsVideoSsrc(parsed_log_, 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.";
@@ -891,14 +879,16 @@
};
TimeSeries capture_time_data(
- GetStreamName(kIncomingPacket, stream.ssrc) + " capture-time",
+ GetStreamName(parsed_log_, kIncomingPacket, stream.ssrc) +
+ " capture-time",
LineStyle::kLine);
AccumulatePairs<LoggedRtpPacketIncoming, double>(
ToCallTime, ToNetworkDelay, packets, &capture_time_data);
plot->AppendTimeSeries(std::move(capture_time_data));
TimeSeries send_time_data(
- GetStreamName(kIncomingPacket, stream.ssrc) + " abs-send-time",
+ GetStreamName(parsed_log_, kIncomingPacket, stream.ssrc) +
+ " abs-send-time",
LineStyle::kLine);
AccumulatePairs<LoggedRtpPacketIncoming, double>(
ToCallTime, NetworkDelayDiff_AbsSendTime, packets, &send_time_data);
@@ -1191,7 +1181,7 @@
continue;
}
- TimeSeries time_series(GetStreamName(direction, stream.ssrc),
+ TimeSeries time_series(GetStreamName(parsed_log_, direction, stream.ssrc),
LineStyle::kLine);
auto GetPacketSizeKilobits = [](const LoggedRtpPacket& packet) {
return packet.total_length * 8.0 / 1000.0;
@@ -1483,7 +1473,7 @@
std::multimap<int64_t, const RtpPacketType*> incoming_rtp;
for (const auto& stream : parsed_log_.incoming_rtp_packets_by_ssrc()) {
- if (IsVideoSsrc(kIncomingPacket, stream.ssrc)) {
+ if (IsVideoSsrc(parsed_log_, kIncomingPacket, stream.ssrc)) {
for (const auto& rtp_packet : stream.incoming_packets)
incoming_rtp.insert(
std::make_pair(rtp_packet.rtp.log_time_us(), &rtp_packet));
@@ -1586,7 +1576,7 @@
const std::vector<LoggedRtpPacketOutgoing>& packets =
stream.outgoing_packets;
- if (IsRtxSsrc(kOutgoingPacket, stream.ssrc)) {
+ if (IsRtxSsrc(parsed_log_, kOutgoingPacket, stream.ssrc)) {
continue;
}
@@ -1596,14 +1586,15 @@
"pacer delay with less than 2 packets in the stream";
continue;
}
- int64_t end_time_us = log_segments_.empty()
- ? std::numeric_limits<int64_t>::max()
- : log_segments_.front().second;
+ int64_t segment_end_us =
+ parsed_log_.log_segments().empty()
+ ? std::numeric_limits<int64_t>::max()
+ : parsed_log_.log_segments().front().stop_time_us();
absl::optional<uint32_t> estimated_frequency =
- EstimateRtpClockFrequency(packets, end_time_us);
+ EstimateRtpClockFrequency(packets, segment_end_us);
if (!estimated_frequency)
continue;
- if (IsVideoSsrc(kOutgoingPacket, stream.ssrc) &&
+ if (IsVideoSsrc(parsed_log_, kOutgoingPacket, stream.ssrc) &&
*estimated_frequency != 90000) {
RTC_LOG(LS_WARNING)
<< "Video stream should use a 90 kHz clock but appears to use "
@@ -1612,7 +1603,7 @@
}
TimeSeries pacer_delay_series(
- GetStreamName(kOutgoingPacket, stream.ssrc) + "(" +
+ GetStreamName(parsed_log_, kOutgoingPacket, stream.ssrc) + "(" +
std::to_string(*estimated_frequency / 1000) + " kHz)",
LineStyle::kLine, PointStyle::kHighlight);
SeqNumUnwrapper<uint32_t> timestamp_unwrapper;
@@ -1645,7 +1636,7 @@
Plot* plot) {
for (const auto& stream : parsed_log_.rtp_packets_by_ssrc(direction)) {
TimeSeries rtp_timestamps(
- GetStreamName(direction, stream.ssrc) + " capture-time",
+ GetStreamName(parsed_log_, direction, stream.ssrc) + " capture-time",
LineStyle::kLine, PointStyle::kHighlight);
for (const auto& packet : stream.packet_view) {
float x = config_.GetCallTimeSec(packet.log_time_us());
@@ -1655,7 +1646,8 @@
plot->AppendTimeSeries(std::move(rtp_timestamps));
TimeSeries rtcp_timestamps(
- GetStreamName(direction, stream.ssrc) + " rtcp capture-time",
+ GetStreamName(parsed_log_, direction, stream.ssrc) +
+ " rtcp capture-time",
LineStyle::kLine, PointStyle::kHighlight);
// TODO(terelius): Why only sender reports?
const auto& sender_reports = parsed_log_.sender_reports(direction);
@@ -1692,7 +1684,8 @@
bool inserted;
if (sr_report_it == sr_reports_by_ssrc.end()) {
std::tie(sr_report_it, inserted) = sr_reports_by_ssrc.emplace(
- ssrc, TimeSeries(GetStreamName(direction, ssrc) + " Sender Reports",
+ ssrc, TimeSeries(GetStreamName(parsed_log_, direction, ssrc) +
+ " Sender Reports",
LineStyle::kLine, PointStyle::kHighlight));
}
sr_report_it->second.points.emplace_back(x, y);
@@ -1713,9 +1706,9 @@
bool inserted;
if (rr_report_it == rr_reports_by_ssrc.end()) {
std::tie(rr_report_it, inserted) = rr_reports_by_ssrc.emplace(
- ssrc,
- TimeSeries(GetStreamName(direction, ssrc) + " Receiver Reports",
- LineStyle::kLine, PointStyle::kHighlight));
+ ssrc, TimeSeries(GetStreamName(parsed_log_, direction, ssrc) +
+ " Receiver Reports",
+ LineStyle::kLine, PointStyle::kHighlight));
}
rr_report_it->second.points.emplace_back(x, y);
}
@@ -2038,7 +2031,7 @@
for (const auto& stream : parsed_log_.incoming_rtp_packets_by_ssrc()) {
const uint32_t ssrc = stream.ssrc;
- if (!IsAudioSsrc(kIncomingPacket, ssrc))
+ if (!IsAudioSsrc(parsed_log_, kIncomingPacket, ssrc))
continue;
const std::vector<LoggedRtpPacketIncoming>* audio_packets =
&stream.incoming_packets;
@@ -2058,9 +2051,10 @@
}
absl::optional<int64_t> end_time_ms =
- log_segments_.empty()
+ parsed_log_.log_segments().empty()
? absl::nullopt
- : absl::optional<int64_t>(log_segments_.front().second / 1000);
+ : absl::optional<int64_t>(
+ parsed_log_.log_segments().front().stop_time_ms());
neteq_stats[ssrc] = CreateNetEqTestAndRun(
audio_packets, &output_events_it->second, end_time_ms,
@@ -2124,7 +2118,8 @@
"Time (s)", kLeftMargin, kRightMargin);
plot->SetSuggestedYAxis(0, 1, "Relative delay (ms)", kBottomMargin,
kTopMargin);
- plot->SetTitle("NetEq timing for " + GetStreamName(kIncomingPacket, ssrc));
+ plot->SetTitle("NetEq timing for " +
+ GetStreamName(parsed_log_, kIncomingPacket, ssrc));
}
template <typename NetEqStatsType>
@@ -2150,7 +2145,8 @@
}
for (auto& series : time_series) {
- series.second.label = GetStreamName(kIncomingPacket, series.first);
+ series.second.label =
+ GetStreamName(parsed_log_, kIncomingPacket, series.first);
series.second.line_style = LineStyle::kLine;
plot->AppendTimeSeries(std::move(series.second));
}
@@ -2326,181 +2322,4 @@
plot->SetTitle("DTLS Writable State");
}
-void EventLogAnalyzer::PrintNotifications(FILE* file) {
- fprintf(file, "========== TRIAGE NOTIFICATIONS ==========\n");
- for (const auto& alert : incoming_rtp_recv_time_gaps_) {
- fprintf(file, "%3.3lf s : %s\n", alert.Time(), alert.ToString().c_str());
- }
- for (const auto& alert : incoming_rtcp_recv_time_gaps_) {
- fprintf(file, "%3.3lf s : %s\n", alert.Time(), alert.ToString().c_str());
- }
- for (const auto& alert : outgoing_rtp_send_time_gaps_) {
- fprintf(file, "%3.3lf s : %s\n", alert.Time(), alert.ToString().c_str());
- }
- for (const auto& alert : outgoing_rtcp_send_time_gaps_) {
- fprintf(file, "%3.3lf s : %s\n", alert.Time(), alert.ToString().c_str());
- }
- for (const auto& alert : incoming_seq_num_jumps_) {
- fprintf(file, "%3.3lf s : %s\n", alert.Time(), alert.ToString().c_str());
- }
- for (const auto& alert : incoming_capture_time_jumps_) {
- fprintf(file, "%3.3lf s : %s\n", alert.Time(), alert.ToString().c_str());
- }
- for (const auto& alert : outgoing_seq_num_jumps_) {
- fprintf(file, "%3.3lf s : %s\n", alert.Time(), alert.ToString().c_str());
- }
- for (const auto& alert : outgoing_capture_time_jumps_) {
- fprintf(file, "%3.3lf s : %s\n", alert.Time(), alert.ToString().c_str());
- }
- for (const auto& alert : outgoing_high_loss_alerts_) {
- fprintf(file, " : %s\n", alert.ToString().c_str());
- }
- fprintf(file, "========== END TRIAGE NOTIFICATIONS ==========\n");
-}
-
-void EventLogAnalyzer::CreateStreamGapAlerts(PacketDirection direction) {
- // With 100 packets/s (~800kbps), false positives would require 10 s without
- // data.
- constexpr int64_t kMaxSeqNumJump = 1000;
- // With a 90 kHz clock, false positives would require 10 s without data.
- constexpr int64_t kMaxCaptureTimeJump = 900000;
-
- int64_t end_time_us = log_segments_.empty()
- ? std::numeric_limits<int64_t>::max()
- : log_segments_.front().second;
-
- SeqNumUnwrapper<uint16_t> seq_num_unwrapper;
- absl::optional<int64_t> last_seq_num;
- SeqNumUnwrapper<uint32_t> capture_time_unwrapper;
- absl::optional<int64_t> last_capture_time;
- // Check for gaps in sequence numbers and capture timestamps.
- for (const auto& stream : parsed_log_.rtp_packets_by_ssrc(direction)) {
- for (const auto& packet : stream.packet_view) {
- if (packet.log_time_us() > end_time_us) {
- // Only process the first (LOG_START, LOG_END) segment.
- break;
- }
-
- int64_t seq_num = seq_num_unwrapper.Unwrap(packet.header.sequenceNumber);
- if (last_seq_num.has_value() &&
- std::abs(seq_num - last_seq_num.value()) > kMaxSeqNumJump) {
- Alert_SeqNumJump(direction,
- config_.GetCallTimeSec(packet.log_time_us()),
- packet.header.ssrc);
- }
- last_seq_num.emplace(seq_num);
-
- int64_t capture_time =
- capture_time_unwrapper.Unwrap(packet.header.timestamp);
- if (last_capture_time.has_value() &&
- std::abs(capture_time - last_capture_time.value()) >
- kMaxCaptureTimeJump) {
- Alert_CaptureTimeJump(direction,
- config_.GetCallTimeSec(packet.log_time_us()),
- packet.header.ssrc);
- }
- last_capture_time.emplace(capture_time);
- }
- }
-}
-
-void EventLogAnalyzer::CreateTransmissionGapAlerts(PacketDirection direction) {
- constexpr int64_t kMaxRtpTransmissionGap = 500000;
- constexpr int64_t kMaxRtcpTransmissionGap = 2000000;
- int64_t end_time_us = log_segments_.empty()
- ? std::numeric_limits<int64_t>::max()
- : log_segments_.front().second;
-
- // TODO(terelius): The parser could provide a list of all packets, ordered
- // by time, for each direction.
- std::multimap<int64_t, const LoggedRtpPacket*> rtp_in_direction;
- for (const auto& stream : parsed_log_.rtp_packets_by_ssrc(direction)) {
- for (const LoggedRtpPacket& rtp_packet : stream.packet_view)
- rtp_in_direction.emplace(rtp_packet.log_time_us(), &rtp_packet);
- }
- absl::optional<int64_t> last_rtp_time;
- for (const auto& kv : rtp_in_direction) {
- int64_t timestamp = kv.first;
- if (timestamp > end_time_us) {
- // Only process the first (LOG_START, LOG_END) segment.
- break;
- }
- int64_t duration = timestamp - last_rtp_time.value_or(0);
- if (last_rtp_time.has_value() && duration > kMaxRtpTransmissionGap) {
- // No packet sent/received for more than 500 ms.
- Alert_RtpLogTimeGap(direction, config_.GetCallTimeSec(timestamp),
- duration / 1000);
- }
- last_rtp_time.emplace(timestamp);
- }
-
- absl::optional<int64_t> last_rtcp_time;
- if (direction == kIncomingPacket) {
- for (const auto& rtcp : parsed_log_.incoming_rtcp_packets()) {
- if (rtcp.log_time_us() > end_time_us) {
- // Only process the first (LOG_START, LOG_END) segment.
- break;
- }
- int64_t duration = rtcp.log_time_us() - last_rtcp_time.value_or(0);
- if (last_rtcp_time.has_value() && duration > kMaxRtcpTransmissionGap) {
- // No feedback sent/received for more than 2000 ms.
- Alert_RtcpLogTimeGap(direction,
- config_.GetCallTimeSec(rtcp.log_time_us()),
- duration / 1000);
- }
- last_rtcp_time.emplace(rtcp.log_time_us());
- }
- } else {
- for (const auto& rtcp : parsed_log_.outgoing_rtcp_packets()) {
- if (rtcp.log_time_us() > end_time_us) {
- // Only process the first (LOG_START, LOG_END) segment.
- break;
- }
- int64_t duration = rtcp.log_time_us() - last_rtcp_time.value_or(0);
- if (last_rtcp_time.has_value() && duration > kMaxRtcpTransmissionGap) {
- // No feedback sent/received for more than 2000 ms.
- Alert_RtcpLogTimeGap(direction,
- config_.GetCallTimeSec(rtcp.log_time_us()),
- duration / 1000);
- }
- last_rtcp_time.emplace(rtcp.log_time_us());
- }
- }
-}
-
-// TODO(terelius): Notifications could possibly be generated by the same code
-// that produces the graphs. There is some code duplication that could be
-// avoided, but that might be solved anyway when we move functionality from the
-// analyzer to the parser.
-void EventLogAnalyzer::CreateTriageNotifications() {
- CreateStreamGapAlerts(kIncomingPacket);
- CreateStreamGapAlerts(kOutgoingPacket);
- CreateTransmissionGapAlerts(kIncomingPacket);
- CreateTransmissionGapAlerts(kOutgoingPacket);
-
- int64_t end_time_us = log_segments_.empty()
- ? std::numeric_limits<int64_t>::max()
- : log_segments_.front().second;
-
- constexpr double kMaxLossFraction = 0.05;
- // Loss feedback
- int64_t total_lost_packets = 0;
- int64_t total_expected_packets = 0;
- for (auto& bwe_update : parsed_log_.bwe_loss_updates()) {
- if (bwe_update.log_time_us() > end_time_us) {
- // Only process the first (LOG_START, LOG_END) segment.
- break;
- }
- int64_t lost_packets = static_cast<double>(bwe_update.fraction_lost) / 255 *
- bwe_update.expected_packets;
- total_lost_packets += lost_packets;
- total_expected_packets += bwe_update.expected_packets;
- }
- double avg_outgoing_loss =
- static_cast<double>(total_lost_packets) / total_expected_packets;
- if (avg_outgoing_loss > kMaxLossFraction) {
- Alert_OutgoingHighLoss(avg_outgoing_loss);
- }
-}
-
} // namespace webrtc
diff --git a/rtc_tools/rtc_event_log_visualizer/analyzer.h b/rtc_tools/rtc_event_log_visualizer/analyzer.h
index 1e09109..ebdfdcc 100644
--- a/rtc_tools/rtc_event_log_visualizer/analyzer.h
+++ b/rtc_tools/rtc_event_log_visualizer/analyzer.h
@@ -21,41 +21,18 @@
#include "logging/rtc_event_log/rtc_event_log_parser.h"
#include "modules/audio_coding/neteq/tools/neteq_stats_getter.h"
#include "rtc_base/strings/string_builder.h"
+#include "rtc_tools/rtc_event_log_visualizer/analyzer_common.h"
#include "rtc_tools/rtc_event_log_visualizer/plot_base.h"
-#include "rtc_tools/rtc_event_log_visualizer/triage_notifications.h"
namespace webrtc {
-class AnalyzerConfig {
- public:
- float GetCallTimeSec(int64_t timestamp_us) const {
- int64_t offset = normalize_time_ ? begin_time_ : 0;
- return static_cast<float>(timestamp_us - offset) / 1000000;
- }
-
- float CallBeginTimeSec() const { return GetCallTimeSec(begin_time_); }
-
- float CallEndTimeSec() const { return GetCallTimeSec(end_time_); }
-
- // Window and step size used for calculating moving averages, e.g. bitrate.
- // The generated data points will be |step_| microseconds apart.
- // Only events occurring at most |window_duration_| microseconds before the
- // current data point will be part of the average.
- int64_t window_duration_;
- int64_t step_;
-
- // First and last events of the log.
- int64_t begin_time_;
- int64_t end_time_;
- bool normalize_time_;
-};
-
class EventLogAnalyzer {
public:
// The EventLogAnalyzer keeps a reference to the ParsedRtcEventLogNew for the
// duration of its lifetime. The ParsedRtcEventLogNew must not be destroyed or
// modified while the EventLogAnalyzer is being used.
EventLogAnalyzer(const ParsedRtcEventLog& log, bool normalize_time);
+ EventLogAnalyzer(const ParsedRtcEventLog& log, const AnalyzerConfig& config);
void CreatePacketGraph(PacketDirection direction, Plot* plot);
@@ -138,55 +115,6 @@
void PrintNotifications(FILE* file);
private:
- struct LayerDescription {
- LayerDescription(uint32_t ssrc,
- uint8_t spatial_layer,
- uint8_t temporal_layer)
- : ssrc(ssrc),
- spatial_layer(spatial_layer),
- temporal_layer(temporal_layer) {}
- bool operator<(const LayerDescription& other) const {
- if (ssrc != other.ssrc)
- return ssrc < other.ssrc;
- if (spatial_layer != other.spatial_layer)
- return spatial_layer < other.spatial_layer;
- return temporal_layer < other.temporal_layer;
- }
- uint32_t ssrc;
- uint8_t spatial_layer;
- uint8_t temporal_layer;
- };
-
- bool IsRtxSsrc(PacketDirection direction, uint32_t ssrc) const {
- if (direction == kIncomingPacket) {
- return parsed_log_.incoming_rtx_ssrcs().find(ssrc) !=
- parsed_log_.incoming_rtx_ssrcs().end();
- } else {
- return parsed_log_.outgoing_rtx_ssrcs().find(ssrc) !=
- parsed_log_.outgoing_rtx_ssrcs().end();
- }
- }
-
- bool IsVideoSsrc(PacketDirection direction, uint32_t ssrc) const {
- if (direction == kIncomingPacket) {
- return parsed_log_.incoming_video_ssrcs().find(ssrc) !=
- parsed_log_.incoming_video_ssrcs().end();
- } else {
- return parsed_log_.outgoing_video_ssrcs().find(ssrc) !=
- parsed_log_.outgoing_video_ssrcs().end();
- }
- }
-
- bool IsAudioSsrc(PacketDirection direction, uint32_t ssrc) const {
- if (direction == kIncomingPacket) {
- return parsed_log_.incoming_audio_ssrcs().find(ssrc) !=
- parsed_log_.incoming_audio_ssrcs().end();
- } else {
- return parsed_log_.outgoing_audio_ssrcs().find(ssrc) !=
- parsed_log_.outgoing_audio_ssrcs().end();
- }
- }
-
template <typename NetEqStatsType>
void CreateNetEqStatsGraphInternal(
const NetEqStatsGetterMap& neteq_stats,
@@ -201,82 +129,6 @@
const IterableType& packets,
const std::string& label);
- void CreateStreamGapAlerts(PacketDirection direction);
- void CreateTransmissionGapAlerts(PacketDirection direction);
-
- std::string GetStreamName(PacketDirection direction, uint32_t ssrc) const {
- char buffer[200];
- rtc::SimpleStringBuilder name(buffer);
- if (IsAudioSsrc(direction, ssrc)) {
- name << "Audio ";
- } else if (IsVideoSsrc(direction, ssrc)) {
- name << "Video ";
- } else {
- name << "Unknown ";
- }
- if (IsRtxSsrc(direction, ssrc)) {
- name << "RTX ";
- }
- if (direction == kIncomingPacket)
- name << "(In) ";
- else
- name << "(Out) ";
- name << "SSRC " << ssrc;
- return name.str();
- }
-
- std::string GetLayerName(LayerDescription layer) const {
- char buffer[100];
- rtc::SimpleStringBuilder name(buffer);
- name << "SSRC " << layer.ssrc << " sl " << layer.spatial_layer << ", tl "
- << layer.temporal_layer;
- return name.str();
- }
-
- void Alert_RtpLogTimeGap(PacketDirection direction,
- float time_seconds,
- int64_t duration) {
- if (direction == kIncomingPacket) {
- incoming_rtp_recv_time_gaps_.emplace_back(time_seconds, duration);
- } else {
- outgoing_rtp_send_time_gaps_.emplace_back(time_seconds, duration);
- }
- }
-
- void Alert_RtcpLogTimeGap(PacketDirection direction,
- float time_seconds,
- int64_t duration) {
- if (direction == kIncomingPacket) {
- incoming_rtcp_recv_time_gaps_.emplace_back(time_seconds, duration);
- } else {
- outgoing_rtcp_send_time_gaps_.emplace_back(time_seconds, duration);
- }
- }
-
- void Alert_SeqNumJump(PacketDirection direction,
- float time_seconds,
- uint32_t ssrc) {
- if (direction == kIncomingPacket) {
- incoming_seq_num_jumps_.emplace_back(time_seconds, ssrc);
- } else {
- outgoing_seq_num_jumps_.emplace_back(time_seconds, ssrc);
- }
- }
-
- void Alert_CaptureTimeJump(PacketDirection direction,
- float time_seconds,
- uint32_t ssrc) {
- if (direction == kIncomingPacket) {
- incoming_capture_time_jumps_.emplace_back(time_seconds, ssrc);
- } else {
- outgoing_capture_time_jumps_.emplace_back(time_seconds, ssrc);
- }
- }
-
- void Alert_OutgoingHighLoss(double avg_loss_fraction) {
- outgoing_high_loss_alerts_.emplace_back(avg_loss_fraction);
- }
-
std::string GetCandidatePairLogDescriptionFromId(uint32_t candidate_pair_id);
const ParsedRtcEventLog& parsed_log_;
@@ -285,20 +137,6 @@
// If left empty, all SSRCs will be considered relevant.
std::vector<uint32_t> desired_ssrc_;
- // Stores the timestamps for all log segments, in the form of associated start
- // and end events.
- std::vector<std::pair<int64_t, int64_t>> log_segments_;
-
- std::vector<IncomingRtpReceiveTimeGap> incoming_rtp_recv_time_gaps_;
- std::vector<IncomingRtcpReceiveTimeGap> incoming_rtcp_recv_time_gaps_;
- std::vector<OutgoingRtpSendTimeGap> outgoing_rtp_send_time_gaps_;
- std::vector<OutgoingRtcpSendTimeGap> outgoing_rtcp_send_time_gaps_;
- std::vector<IncomingSeqNumJump> incoming_seq_num_jumps_;
- std::vector<IncomingCaptureTimeJump> incoming_capture_time_jumps_;
- std::vector<OutgoingSeqNoJump> outgoing_seq_num_jumps_;
- std::vector<OutgoingCaptureTimeJump> outgoing_capture_time_jumps_;
- std::vector<OutgoingHighLoss> outgoing_high_loss_alerts_;
-
std::map<uint32_t, std::string> candidate_pair_desc_by_id_;
AnalyzerConfig config_;
diff --git a/rtc_tools/rtc_event_log_visualizer/analyzer_common.cc b/rtc_tools/rtc_event_log_visualizer/analyzer_common.cc
new file mode 100644
index 0000000..3d3ce5a
--- /dev/null
+++ b/rtc_tools/rtc_event_log_visualizer/analyzer_common.cc
@@ -0,0 +1,83 @@
+
+/*
+ * Copyright (c) 2020 The WebRTC project authors. All Rights Reserved.
+ *
+ * Use of this source code is governed by a BSD-style license
+ * that can be found in the LICENSE file in the root of the source
+ * tree. An additional intellectual property rights grant can be found
+ * in the file PATENTS. All contributing project authors may
+ * be found in the AUTHORS file in the root of the source tree.
+ */
+
+#include "rtc_tools/rtc_event_log_visualizer/analyzer_common.h"
+
+namespace webrtc {
+
+bool IsRtxSsrc(const ParsedRtcEventLog& parsed_log,
+ PacketDirection direction,
+ uint32_t ssrc) {
+ if (direction == kIncomingPacket) {
+ return parsed_log.incoming_rtx_ssrcs().find(ssrc) !=
+ parsed_log.incoming_rtx_ssrcs().end();
+ } else {
+ return parsed_log.outgoing_rtx_ssrcs().find(ssrc) !=
+ parsed_log.outgoing_rtx_ssrcs().end();
+ }
+}
+
+bool IsVideoSsrc(const ParsedRtcEventLog& parsed_log,
+ PacketDirection direction,
+ uint32_t ssrc) {
+ if (direction == kIncomingPacket) {
+ return parsed_log.incoming_video_ssrcs().find(ssrc) !=
+ parsed_log.incoming_video_ssrcs().end();
+ } else {
+ return parsed_log.outgoing_video_ssrcs().find(ssrc) !=
+ parsed_log.outgoing_video_ssrcs().end();
+ }
+}
+
+bool IsAudioSsrc(const ParsedRtcEventLog& parsed_log,
+ PacketDirection direction,
+ uint32_t ssrc) {
+ if (direction == kIncomingPacket) {
+ return parsed_log.incoming_audio_ssrcs().find(ssrc) !=
+ parsed_log.incoming_audio_ssrcs().end();
+ } else {
+ return parsed_log.outgoing_audio_ssrcs().find(ssrc) !=
+ parsed_log.outgoing_audio_ssrcs().end();
+ }
+}
+
+std::string GetStreamName(const ParsedRtcEventLog& parsed_log,
+ PacketDirection direction,
+ uint32_t ssrc) {
+ char buffer[200];
+ rtc::SimpleStringBuilder name(buffer);
+ if (IsAudioSsrc(parsed_log, direction, ssrc)) {
+ name << "Audio ";
+ } else if (IsVideoSsrc(parsed_log, direction, ssrc)) {
+ name << "Video ";
+ } else {
+ name << "Unknown ";
+ }
+ if (IsRtxSsrc(parsed_log, direction, ssrc)) {
+ name << "RTX ";
+ }
+ if (direction == kIncomingPacket)
+ name << "(In) ";
+ else
+ name << "(Out) ";
+ name << "SSRC " << ssrc;
+ return name.str();
+}
+
+std::string GetLayerName(LayerDescription layer) {
+ char buffer[100];
+ rtc::SimpleStringBuilder name(buffer);
+ name << "SSRC " << layer.ssrc << " sl " << layer.spatial_layer << ", tl "
+ << layer.temporal_layer;
+ return name.str();
+}
+
+} // namespace webrtc
diff --git a/rtc_tools/rtc_event_log_visualizer/analyzer_common.h b/rtc_tools/rtc_event_log_visualizer/analyzer_common.h
new file mode 100644
index 0000000..3ac651e
--- /dev/null
+++ b/rtc_tools/rtc_event_log_visualizer/analyzer_common.h
@@ -0,0 +1,79 @@
+/*
+ * Copyright (c) 2020 The WebRTC project authors. All Rights Reserved.
+ *
+ * Use of this source code is governed by a BSD-style license
+ * that can be found in the LICENSE file in the root of the source
+ * tree. An additional intellectual property rights grant can be found
+ * in the file PATENTS. All contributing project authors may
+ * be found in the AUTHORS file in the root of the source tree.
+ */
+
+#ifndef RTC_TOOLS_RTC_EVENT_LOG_VISUALIZER_ANALYZER_COMMON_H_
+#define RTC_TOOLS_RTC_EVENT_LOG_VISUALIZER_ANALYZER_COMMON_H_
+
+#include <cstdint>
+#include <string>
+
+#include "logging/rtc_event_log/rtc_event_log_parser.h"
+
+namespace webrtc {
+
+class AnalyzerConfig {
+ public:
+ float GetCallTimeSec(int64_t timestamp_us) const {
+ int64_t offset = normalize_time_ ? begin_time_ : 0;
+ return static_cast<float>(timestamp_us - offset) / 1000000;
+ }
+
+ float CallBeginTimeSec() const { return GetCallTimeSec(begin_time_); }
+
+ float CallEndTimeSec() const { return GetCallTimeSec(end_time_); }
+
+ // Window and step size used for calculating moving averages, e.g. bitrate.
+ // The generated data points will be |step_| microseconds apart.
+ // Only events occurring at most |window_duration_| microseconds before the
+ // current data point will be part of the average.
+ int64_t window_duration_;
+ int64_t step_;
+
+ // First and last events of the log.
+ int64_t begin_time_;
+ int64_t end_time_;
+ bool normalize_time_;
+};
+
+struct LayerDescription {
+ LayerDescription(uint32_t ssrc, uint8_t spatial_layer, uint8_t temporal_layer)
+ : ssrc(ssrc),
+ spatial_layer(spatial_layer),
+ temporal_layer(temporal_layer) {}
+ bool operator<(const LayerDescription& other) const {
+ if (ssrc != other.ssrc)
+ return ssrc < other.ssrc;
+ if (spatial_layer != other.spatial_layer)
+ return spatial_layer < other.spatial_layer;
+ return temporal_layer < other.temporal_layer;
+ }
+ uint32_t ssrc;
+ uint8_t spatial_layer;
+ uint8_t temporal_layer;
+};
+
+bool IsRtxSsrc(const ParsedRtcEventLog& parsed_log,
+ PacketDirection direction,
+ uint32_t ssrc);
+bool IsVideoSsrc(const ParsedRtcEventLog& parsed_log,
+ PacketDirection direction,
+ uint32_t ssrc);
+bool IsAudioSsrc(const ParsedRtcEventLog& parsed_log,
+ PacketDirection direction,
+ uint32_t ssrc);
+
+std::string GetStreamName(const ParsedRtcEventLog& parsed_log,
+ PacketDirection direction,
+ uint32_t ssrc);
+std::string GetLayerName(LayerDescription layer);
+
+} // namespace webrtc
+
+#endif // RTC_TOOLS_RTC_EVENT_LOG_VISUALIZER_ANALYZER_COMMON_H_
diff --git a/rtc_tools/rtc_event_log_visualizer/main.cc b/rtc_tools/rtc_event_log_visualizer/main.cc
index eb36b26..21768c9 100644
--- a/rtc_tools/rtc_event_log_visualizer/main.cc
+++ b/rtc_tools/rtc_event_log_visualizer/main.cc
@@ -30,6 +30,7 @@
#include "modules/rtp_rtcp/source/rtcp_packet/report_block.h"
#include "rtc_base/checks.h"
#include "rtc_base/logging.h"
+#include "rtc_tools/rtc_event_log_visualizer/alerts.h"
#include "rtc_tools/rtc_event_log_visualizer/analyzer.h"
#include "rtc_tools/rtc_event_log_visualizer/plot_base.h"
#include "rtc_tools/rtc_event_log_visualizer/plot_protobuf.h"
@@ -194,9 +195,9 @@
"A tool for visualizing WebRTC event logs.\n"
"Example usage:\n"
"./event_log_visualizer <logfile> | python\n");
- absl::FlagsUsageConfig config;
- config.contains_help_flags = &ContainsHelppackageFlags;
- absl::SetFlagsUsageConfig(config);
+ absl::FlagsUsageConfig flag_config;
+ flag_config.contains_help_flags = &ContainsHelppackageFlags;
+ absl::SetFlagsUsageConfig(flag_config);
std::vector<char*> args = absl::ParseCommandLine(argc, argv);
// Print RTC_LOG warnings and errors even in release builds.
@@ -261,8 +262,20 @@
}
}
- webrtc::EventLogAnalyzer analyzer(parsed_log,
- absl::GetFlag(FLAGS_normalize_time));
+ webrtc::AnalyzerConfig config;
+ config.window_duration_ = 250000;
+ config.step_ = 10000;
+ config.normalize_time_ = absl::GetFlag(FLAGS_normalize_time);
+ config.begin_time_ = parsed_log.first_timestamp();
+ config.end_time_ = parsed_log.last_timestamp();
+ if (config.end_time_ < config.begin_time_) {
+ RTC_LOG(LS_WARNING) << "Log end time " << config.end_time_
+ << " not after begin time " << config.begin_time_
+ << ". Nothing to analyze. Is the log broken?";
+ return -1;
+ }
+
+ webrtc::EventLogAnalyzer analyzer(parsed_log, config);
std::unique_ptr<webrtc::PlotCollection> collection;
if (absl::GetFlag(FLAGS_protobuf_output)) {
collection.reset(new webrtc::ProtobufPlotCollection());
@@ -614,8 +627,9 @@
collection->Draw();
if (absl::GetFlag(FLAGS_print_triage_alerts)) {
- analyzer.CreateTriageNotifications();
- analyzer.PrintNotifications(stderr);
+ webrtc::TriageHelper triage_alerts(config);
+ triage_alerts.AnalyzeLog(parsed_log);
+ triage_alerts.Print(stderr);
}
return 0;
diff --git a/rtc_tools/rtc_event_log_visualizer/triage_notifications.h b/rtc_tools/rtc_event_log_visualizer/triage_notifications.h
deleted file mode 100644
index 23b31ece..0000000
--- a/rtc_tools/rtc_event_log_visualizer/triage_notifications.h
+++ /dev/null
@@ -1,158 +0,0 @@
-/*
- * Copyright (c) 2017 The WebRTC project authors. All Rights Reserved.
- *
- * Use of this source code is governed by a BSD-style license
- * that can be found in the LICENSE file in the root of the source
- * tree. An additional intellectual property rights grant can be found
- * in the file PATENTS. All contributing project authors may
- * be found in the AUTHORS file in the root of the source tree.
- */
-
-#ifndef RTC_TOOLS_RTC_EVENT_LOG_VISUALIZER_TRIAGE_NOTIFICATIONS_H_
-#define RTC_TOOLS_RTC_EVENT_LOG_VISUALIZER_TRIAGE_NOTIFICATIONS_H_
-
-#include <string>
-
-namespace webrtc {
-
-class IncomingRtpReceiveTimeGap {
- public:
- IncomingRtpReceiveTimeGap(float time_seconds, int64_t duration)
- : time_seconds_(time_seconds), duration_(duration) {}
- float Time() const { return time_seconds_; }
- std::string ToString() const {
- return std::string("No RTP packets received for ") +
- std::to_string(duration_) + std::string(" ms");
- }
-
- private:
- float time_seconds_;
- int64_t duration_;
-};
-
-class IncomingRtcpReceiveTimeGap {
- public:
- IncomingRtcpReceiveTimeGap(float time_seconds, int64_t duration)
- : time_seconds_(time_seconds), duration_(duration) {}
- float Time() const { return time_seconds_; }
- std::string ToString() const {
- return std::string("No RTCP packets received for ") +
- std::to_string(duration_) + std::string(" ms");
- }
-
- private:
- float time_seconds_;
- int64_t duration_;
-};
-
-class OutgoingRtpSendTimeGap {
- public:
- OutgoingRtpSendTimeGap(float time_seconds, int64_t duration)
- : time_seconds_(time_seconds), duration_(duration) {}
- float Time() const { return time_seconds_; }
- std::string ToString() const {
- return std::string("No RTP packets sent for ") + std::to_string(duration_) +
- std::string(" ms");
- }
-
- private:
- float time_seconds_;
- int64_t duration_;
-};
-
-class OutgoingRtcpSendTimeGap {
- public:
- OutgoingRtcpSendTimeGap(float time_seconds, int64_t duration)
- : time_seconds_(time_seconds), duration_(duration) {}
- float Time() const { return time_seconds_; }
- std::string ToString() const {
- return std::string("No RTCP packets sent for ") +
- std::to_string(duration_) + std::string(" ms");
- }
-
- private:
- float time_seconds_;
- int64_t duration_;
-};
-
-class IncomingSeqNumJump {
- public:
- IncomingSeqNumJump(float time_seconds, uint32_t ssrc)
- : time_seconds_(time_seconds), ssrc_(ssrc) {}
- float Time() const { return time_seconds_; }
- std::string ToString() const {
- return std::string("Sequence number jumps on incoming SSRC ") +
- std::to_string(ssrc_);
- }
-
- private:
- float time_seconds_;
-
- uint32_t ssrc_;
-};
-
-class IncomingCaptureTimeJump {
- public:
- IncomingCaptureTimeJump(float time_seconds, uint32_t ssrc)
- : time_seconds_(time_seconds), ssrc_(ssrc) {}
- float Time() const { return time_seconds_; }
- std::string ToString() const {
- return std::string("Capture timestamp jumps on incoming SSRC ") +
- std::to_string(ssrc_);
- }
-
- private:
- float time_seconds_;
-
- uint32_t ssrc_;
-};
-
-class OutgoingSeqNoJump {
- public:
- OutgoingSeqNoJump(float time_seconds, uint32_t ssrc)
- : time_seconds_(time_seconds), ssrc_(ssrc) {}
- float Time() const { return time_seconds_; }
- std::string ToString() const {
- return std::string("Sequence number jumps on outgoing SSRC ") +
- std::to_string(ssrc_);
- }
-
- private:
- float time_seconds_;
-
- uint32_t ssrc_;
-};
-
-class OutgoingCaptureTimeJump {
- public:
- OutgoingCaptureTimeJump(float time_seconds, uint32_t ssrc)
- : time_seconds_(time_seconds), ssrc_(ssrc) {}
- float Time() const { return time_seconds_; }
- std::string ToString() const {
- return std::string("Capture timestamp jumps on outgoing SSRC ") +
- std::to_string(ssrc_);
- }
-
- private:
- float time_seconds_;
-
- uint32_t ssrc_;
-};
-
-class OutgoingHighLoss {
- public:
- explicit OutgoingHighLoss(double avg_loss_fraction)
- : avg_loss_fraction_(avg_loss_fraction) {}
- std::string ToString() const {
- return std::string("High average loss (") +
- std::to_string(avg_loss_fraction_ * 100) +
- std::string("%) across the call.");
- }
-
- private:
- double avg_loss_fraction_;
-};
-
-} // namespace webrtc
-
-#endif // RTC_TOOLS_RTC_EVENT_LOG_VISUALIZER_TRIAGE_NOTIFICATIONS_H_
