Merge commit 'upstream-main' into master

Bug: 261600888
Test: none, build files to be updated in follow up cl
Change-Id: Ib520938290c6bbdee4a9f73b6419b6c947a96ec4
This commit is contained in:
Jorge E. Moreira
2022-12-06 16:34:41 -08:00
5393 changed files with 541103 additions and 211666 deletions

View File

@ -19,22 +19,12 @@
#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 occurrence at %3.3lf\n", alert.second.count,
alert.second.explanation.c_str(), alert.second.first_occurrence);
}
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
@ -88,7 +78,7 @@ void TriageHelper::AnalyzeStreamGaps(const ParsedRtcEventLog& parsed_log,
int64_t seq_num = seq_num_unwrapper.Unwrap(packet.header.sequenceNumber);
if (std::abs(seq_num - last_seq_num) > kMaxSeqNumJump) {
Alert(seq_num_alert, config_.GetCallTimeSec(packet.log_time_us()),
Alert(seq_num_alert, config_.GetCallTimeSec(packet.log_time()),
seq_num_explanation);
}
last_seq_num = seq_num;
@ -98,7 +88,7 @@ void TriageHelper::AnalyzeStreamGaps(const ParsedRtcEventLog& parsed_log,
if (std::abs(capture_time - last_capture_time) >
kTicksPerMillisec *
(kCaptureTimeGraceMs + packet.log_time_ms() - last_log_time_ms)) {
Alert(capture_time_alert, config_.GetCallTimeSec(packet.log_time_us()),
Alert(capture_time_alert, config_.GetCallTimeSec(packet.log_time()),
capture_time_explanation);
}
last_capture_time = capture_time;
@ -149,7 +139,8 @@ void TriageHelper::AnalyzeTransmissionGaps(const ParsedRtcEventLog& parsed_log,
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);
Alert(rtp_alert, config_.GetCallTimeSec(Timestamp::Micros(timestamp)),
rtp_explanation);
}
last_rtp_time.emplace(timestamp);
}
@ -164,7 +155,7 @@ void TriageHelper::AnalyzeTransmissionGaps(const ParsedRtcEventLog& parsed_log,
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()),
Alert(rtcp_alert, config_.GetCallTimeSec(rtcp.log_time()),
rtcp_explanation);
}
last_rtcp_time.emplace(rtcp.log_time_us());
@ -178,7 +169,7 @@ void TriageHelper::AnalyzeTransmissionGaps(const ParsedRtcEventLog& parsed_log,
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()),
Alert(rtcp_alert, config_.GetCallTimeSec(rtcp.log_time()),
rtcp_explanation);
}
last_rtcp_time.emplace(rtcp.log_time_us());
@ -198,7 +189,7 @@ void TriageHelper::AnalyzeLog(const ParsedRtcEventLog& parsed_log) {
const int64_t segment_end_us = parsed_log.first_log_segment().stop_time_us();
int64_t first_occurrence = parsed_log.last_timestamp();
Timestamp first_occurrence = parsed_log.last_timestamp();
constexpr double kMaxLossFraction = 0.05;
// Loss feedback
int64_t total_lost_packets = 0;
@ -213,15 +204,33 @@ void TriageHelper::AnalyzeLog(const ParsedRtcEventLog& parsed_log) {
total_lost_packets += lost_packets;
total_expected_packets += bwe_update.expected_packets;
if (bwe_update.fraction_lost >= 255 * kMaxLossFraction) {
first_occurrence = std::min(first_occurrence, bwe_update.log_time_us());
first_occurrence = std::min(first_occurrence, bwe_update.log_time());
}
}
double avg_outgoing_loss =
static_cast<double>(total_lost_packets) / total_expected_packets;
if (avg_outgoing_loss > kMaxLossFraction) {
Alert(TriageAlertType::kOutgoingHighLoss, first_occurrence,
Alert(TriageAlertType::kOutgoingHighLoss,
config_.GetCallTimeSec(first_occurrence),
"More than 5% of outgoing packets lost.");
}
}
void TriageHelper::Print(FILE* file) {
fprintf(file, "========== TRIAGE NOTIFICATIONS ==========\n");
for (const auto& alert : triage_alerts_) {
fprintf(file, "%d %s. First occurrence at %3.3lf\n", alert.second.count,
alert.second.explanation.c_str(), alert.second.first_occurrence);
}
fprintf(file, "========== END TRIAGE NOTIFICATIONS ==========\n");
}
void TriageHelper::ProcessAlerts(
std::function<void(int, float, std::string)> f) {
for (const auto& alert : triage_alerts_) {
f(alert.second.count, alert.second.first_occurrence,
alert.second.explanation);
}
}
} // namespace webrtc

View File

@ -19,7 +19,6 @@
#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 {
@ -49,6 +48,9 @@ class TriageHelper {
public:
explicit TriageHelper(const AnalyzerConfig& config) : config_(config) {}
TriageHelper(const TriageHelper&) = delete;
TriageHelper& operator=(const TriageHelper&) = delete;
void AnalyzeLog(const ParsedRtcEventLog& parsed_log);
void AnalyzeStreamGaps(const ParsedRtcEventLog& parsed_log,
@ -57,6 +59,8 @@ class TriageHelper {
PacketDirection direction);
void Print(FILE* file);
void ProcessAlerts(std::function<void(int, float, std::string)> f);
private:
AnalyzerConfig config_;
std::map<TriageAlertType, TriageAlert> triage_alerts_;
@ -78,7 +82,6 @@ class TriageHelper {
it->second.count += 1;
}
}
RTC_DISALLOW_COPY_AND_ASSIGN(TriageHelper);
};
} // namespace webrtc

View File

@ -21,7 +21,6 @@
#include "modules/audio_coding/neteq/tools/neteq_replacement_input.h"
#include "modules/audio_coding/neteq/tools/neteq_test.h"
#include "modules/audio_coding/neteq/tools/resample_input_audio_file.h"
#include "rtc_base/ref_counted_object.h"
namespace webrtc {
@ -38,7 +37,7 @@ void CreateAudioEncoderTargetBitrateGraph(const ParsedRtcEventLog& parsed_log,
return absl::nullopt;
};
auto ToCallTime = [config](const LoggedAudioNetworkAdaptationEvent& packet) {
return config.GetCallTimeSec(packet.log_time_us());
return config.GetCallTimeSec(packet.log_time());
};
ProcessPoints<LoggedAudioNetworkAdaptationEvent>(
ToCallTime, GetAnaBitrateBps,
@ -63,7 +62,7 @@ void CreateAudioEncoderFrameLengthGraph(const ParsedRtcEventLog& parsed_log,
return absl::optional<float>();
};
auto ToCallTime = [config](const LoggedAudioNetworkAdaptationEvent& packet) {
return config.GetCallTimeSec(packet.log_time_us());
return config.GetCallTimeSec(packet.log_time());
};
ProcessPoints<LoggedAudioNetworkAdaptationEvent>(
ToCallTime, GetAnaFrameLengthMs,
@ -88,7 +87,7 @@ void CreateAudioEncoderPacketLossGraph(const ParsedRtcEventLog& parsed_log,
return absl::optional<float>();
};
auto ToCallTime = [config](const LoggedAudioNetworkAdaptationEvent& packet) {
return config.GetCallTimeSec(packet.log_time_us());
return config.GetCallTimeSec(packet.log_time());
};
ProcessPoints<LoggedAudioNetworkAdaptationEvent>(
ToCallTime, GetAnaPacketLoss,
@ -114,7 +113,7 @@ void CreateAudioEncoderEnableFecGraph(const ParsedRtcEventLog& parsed_log,
return absl::optional<float>();
};
auto ToCallTime = [config](const LoggedAudioNetworkAdaptationEvent& packet) {
return config.GetCallTimeSec(packet.log_time_us());
return config.GetCallTimeSec(packet.log_time());
};
ProcessPoints<LoggedAudioNetworkAdaptationEvent>(
ToCallTime, GetAnaFecEnabled,
@ -139,7 +138,7 @@ void CreateAudioEncoderEnableDtxGraph(const ParsedRtcEventLog& parsed_log,
return absl::optional<float>();
};
auto ToCallTime = [config](const LoggedAudioNetworkAdaptationEvent& packet) {
return config.GetCallTimeSec(packet.log_time_us());
return config.GetCallTimeSec(packet.log_time());
};
ProcessPoints<LoggedAudioNetworkAdaptationEvent>(
ToCallTime, GetAnaDtxEnabled,
@ -164,7 +163,7 @@ void CreateAudioEncoderNumChannelsGraph(const ParsedRtcEventLog& parsed_log,
return absl::optional<float>();
};
auto ToCallTime = [config](const LoggedAudioNetworkAdaptationEvent& packet) {
return config.GetCallTimeSec(packet.log_time_us());
return config.GetCallTimeSec(packet.log_time());
};
ProcessPoints<LoggedAudioNetworkAdaptationEvent>(
ToCallTime, GetAnaNumChannels,
@ -266,7 +265,7 @@ class ReplacementAudioDecoderFactory : public AudioDecoderFactory {
file_sample_rate_hz_(file_sample_rate_hz) {}
std::vector<AudioCodecSpec> GetSupportedDecoders() override {
RTC_NOTREACHED();
RTC_DCHECK_NOTREACHED();
return {};
}
@ -307,14 +306,10 @@ std::unique_ptr<test::NetEqStatsGetter> CreateNetEqTestAndRun(
input.reset(new test::NetEqReplacementInput(std::move(input), kReplacementPt,
cn_types, forbidden_types));
NetEq::Config config;
config.max_packets_in_buffer = 200;
config.enable_fast_accelerate = true;
std::unique_ptr<test::VoidAudioSink> output(new test::VoidAudioSink());
rtc::scoped_refptr<AudioDecoderFactory> decoder_factory =
new rtc::RefCountedObject<ReplacementAudioDecoderFactory>(
rtc::make_ref_counted<ReplacementAudioDecoderFactory>(
replacement_file_name, file_sample_rate_hz);
test::NetEqTest::DecoderMap codecs = {
@ -330,6 +325,7 @@ std::unique_ptr<test::NetEqStatsGetter> CreateNetEqTestAndRun(
callbacks.post_insert_packet = neteq_stats_getter->delay_analyzer();
callbacks.get_audio_callback = neteq_stats_getter.get();
NetEq::Config config;
test::NetEqTest test(config, decoder_factory, codecs, /*text_log=*/nullptr,
/*factory=*/nullptr, std::move(input), std::move(output),
callbacks);
@ -400,23 +396,23 @@ void CreateAudioJitterBufferGraph(const ParsedRtcEventLog& parsed_log,
PointStyle::kHighlight);
for (const auto& data : arrival_delay_ms) {
const float x = config.GetCallTimeSec(data.first * 1000); // ms to us.
const float x = config.GetCallTimeSec(Timestamp::Millis(data.first));
const float y = data.second;
time_series_packet_arrival.points.emplace_back(TimeSeriesPoint(x, y));
}
for (const auto& data : corrected_arrival_delay_ms) {
const float x = config.GetCallTimeSec(data.first * 1000); // ms to us.
const float x = config.GetCallTimeSec(Timestamp::Millis(data.first));
const float y = data.second;
time_series_relative_packet_arrival.points.emplace_back(
TimeSeriesPoint(x, y));
}
for (const auto& data : playout_delay_ms) {
const float x = config.GetCallTimeSec(data.first * 1000); // ms to us.
const float x = config.GetCallTimeSec(Timestamp::Millis(data.first));
const float y = data.second;
time_series_play_time.points.emplace_back(TimeSeriesPoint(x, y));
}
for (const auto& data : target_delay_ms) {
const float x = config.GetCallTimeSec(data.first * 1000); // ms to us.
const float x = config.GetCallTimeSec(Timestamp::Millis(data.first));
const float y = data.second;
time_series_target_time.points.emplace_back(TimeSeriesPoint(x, y));
}
@ -451,7 +447,7 @@ void CreateNetEqStatsGraphInternal(
const std::vector<std::pair<int64_t, NetEqStatsType>>* data_vector =
data_extractor(st.second.get());
for (const auto& data : *data_vector) {
const float time = config.GetCallTimeSec(data.first * 1000); // ms to us.
const float time = config.GetCallTimeSec(Timestamp::Millis(data.first));
const float value = stats_extractor(data.second);
time_series[ssrc].points.emplace_back(TimeSeriesPoint(time, value));
}

View File

@ -19,8 +19,10 @@
#include <utility>
#include "absl/algorithm/container.h"
#include "absl/functional/bind_front.h"
#include "absl/strings/string_view.h"
#include "api/function_view.h"
#include "api/network_state_predictor.h"
#include "api/transport/field_trial_based_config.h"
#include "api/transport/goog_cc_factory.h"
#include "call/audio_receive_stream.h"
@ -36,9 +38,6 @@
#include "modules/congestion_controller/goog_cc/delay_based_bwe.h"
#include "modules/congestion_controller/include/receive_side_congestion_controller.h"
#include "modules/congestion_controller/rtp/transport_feedback_adapter.h"
#include "modules/pacing/paced_sender.h"
#include "modules/pacing/packet_router.h"
#include "modules/remote_bitrate_estimator/include/bwe_defines.h"
#include "modules/rtp_rtcp/include/rtp_rtcp_defines.h"
#include "modules/rtp_rtcp/source/rtcp_packet.h"
#include "modules/rtp_rtcp/source/rtcp_packet/common_header.h"
@ -48,9 +47,7 @@
#include "modules/rtp_rtcp/source/rtcp_packet/transport_feedback.h"
#include "modules/rtp_rtcp/source/rtp_header_extensions.h"
#include "modules/rtp_rtcp/source/rtp_rtcp_interface.h"
#include "modules/rtp_rtcp/source/rtp_utility.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/rate_statistics.h"
@ -87,10 +84,10 @@ double AbsSendTimeToMicroseconds(int64_t abs_send_time) {
return abs_send_time * kTimestampToMicroSec;
}
// Computes the difference |later| - |earlier| where |later| and |earlier|
// are counters that wrap at |modulus|. The difference is chosen to have the
// least absolute value. For example if |modulus| is 8, then the difference will
// be chosen in the range [-3, 4]. If |modulus| is 9, then the difference will
// Computes the difference `later` - `earlier` where `later` and `earlier`
// are counters that wrap at `modulus`. The difference is chosen to have the
// least absolute value. For example if `modulus` is 8, then the difference will
// be chosen in the range [-3, 4]. If `modulus` is 9, then the difference will
// be in [-4, 4].
int64_t WrappingDifference(uint32_t later, uint32_t earlier, int64_t modulus) {
RTC_DCHECK_LE(1, modulus);
@ -153,7 +150,9 @@ absl::optional<uint32_t> EstimateRtpClockFrequency(
}
RTC_LOG(LS_WARNING) << "Failed to estimate RTP clock frequency: Estimate "
<< estimated_frequency
<< " not close to any stardard RTP frequency.";
<< " not close to any standard RTP frequency."
<< " Last timestamp " << last_rtp_timestamp
<< " first timestamp " << first_rtp_timestamp;
return absl::nullopt;
}
@ -214,7 +213,7 @@ TimeSeries CreateRtcpTypeTimeSeries(const std::vector<T>& rtcp_list,
int category_id) {
TimeSeries time_series(rtcp_name, LineStyle::kNone, PointStyle::kHighlight);
for (const auto& rtcp : rtcp_list) {
float x = config.GetCallTimeSec(rtcp.log_time_us());
float x = config.GetCallTimeSec(rtcp.timestamp);
float y = category_id;
time_series.points.emplace_back(x, y);
}
@ -346,20 +345,24 @@ std::string GetDirectionAsShortString(PacketDirection direction) {
EventLogAnalyzer::EventLogAnalyzer(const ParsedRtcEventLog& log,
bool normalize_time)
: parsed_log_(log) {
config_.window_duration_ = 250000;
config_.step_ = 10000;
config_.window_duration_ = TimeDelta::Millis(250);
config_.step_ = TimeDelta::Millis(10);
if (!log.start_log_events().empty()) {
config_.rtc_to_utc_offset_ = log.start_log_events()[0].utc_time() -
log.start_log_events()[0].log_time();
}
config_.normalize_time_ = 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) << "No useful events in the log.";
config_.begin_time_ = config_.end_time_ = 0;
config_.begin_time_ = config_.end_time_ = Timestamp::Zero();
}
RTC_LOG(LS_INFO) << "Log is "
<< (parsed_log_.last_timestamp() -
parsed_log_.first_timestamp()) /
1000000
<< (parsed_log_.last_timestamp().ms() -
parsed_log_.first_timestamp().ms()) /
1000
<< " seconds long.";
}
@ -367,9 +370,9 @@ EventLogAnalyzer::EventLogAnalyzer(const ParsedRtcEventLog& log,
const AnalyzerConfig& config)
: parsed_log_(log), config_(config) {
RTC_LOG(LS_INFO) << "Log is "
<< (parsed_log_.last_timestamp() -
parsed_log_.first_timestamp()) /
1000000
<< (parsed_log_.last_timestamp().ms() -
parsed_log_.first_timestamp().ms()) /
1000
<< " seconds long.";
}
@ -413,7 +416,7 @@ void EventLogAnalyzer::CreatePacketGraph(PacketDirection direction,
return absl::optional<float>(packet.total_length);
};
auto ToCallTime = [this](const LoggedRtpPacket& packet) {
return this->config_.GetCallTimeSec(packet.log_time_us());
return this->config_.GetCallTimeSec(packet.timestamp);
};
ProcessPoints<LoggedRtpPacket>(ToCallTime, GetPacketSize,
stream.packet_view, &time_series);
@ -445,6 +448,8 @@ void EventLogAnalyzer::CreateRtcpTypeGraph(PacketDirection direction,
CreateRtcpTypeTimeSeries(parsed_log_.firs(direction), config_, "FIR", 7));
plot->AppendTimeSeries(
CreateRtcpTypeTimeSeries(parsed_log_.plis(direction), config_, "PLI", 8));
plot->AppendTimeSeries(
CreateRtcpTypeTimeSeries(parsed_log_.byes(direction), config_, "BYE", 9));
plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
"Time (s)", kLeftMargin, kRightMargin);
plot->SetSuggestedYAxis(0, 1, "RTCP type", kBottomMargin, kTopMargin);
@ -456,7 +461,8 @@ void EventLogAnalyzer::CreateRtcpTypeGraph(PacketDirection direction,
{5, "NACK"},
{6, "REMB"},
{7, "FIR"},
{8, "PLI"}});
{8, "PLI"},
{9, "BYE"}});
}
template <typename IterableType>
@ -466,7 +472,7 @@ void EventLogAnalyzer::CreateAccumulatedPacketsTimeSeries(
const std::string& label) {
TimeSeries time_series(label, LineStyle::kStep);
for (size_t i = 0; i < packets.size(); i++) {
float x = config_.GetCallTimeSec(packets[i].log_time_us());
float x = config_.GetCallTimeSec(packets[i].log_time());
time_series.points.emplace_back(x, i + 1);
}
plot->AppendTimeSeries(std::move(time_series));
@ -542,17 +548,15 @@ void EventLogAnalyzer::CreateTotalPacketRateGraph(PacketDirection direction,
// types using MovingAverage().
class LogTime {
public:
explicit LogTime(int64_t log_time_us) : log_time_us_(log_time_us) {}
int64_t log_time_us() const { return log_time_us_; }
explicit LogTime(Timestamp log_time) : log_time_(log_time) {}
Timestamp log_time() const { return log_time_; }
private:
int64_t log_time_us_;
Timestamp log_time_;
};
std::vector<LogTime> packet_times;
auto handle_rtp = [&](const LoggedRtpPacket& packet) {
packet_times.emplace_back(packet.log_time_us());
packet_times.emplace_back(packet.log_time());
};
RtcEventProcessor process;
for (const auto& stream : parsed_log_.rtp_packets_by_ssrc(direction)) {
@ -560,13 +564,13 @@ void EventLogAnalyzer::CreateTotalPacketRateGraph(PacketDirection direction,
}
if (direction == kIncomingPacket) {
auto handle_incoming_rtcp = [&](const LoggedRtcpPacketIncoming& packet) {
packet_times.emplace_back(packet.log_time_us());
packet_times.emplace_back(packet.log_time());
};
process.AddEvents(parsed_log_.incoming_rtcp_packets(),
handle_incoming_rtcp);
} else {
auto handle_outgoing_rtcp = [&](const LoggedRtcpPacketOutgoing& packet) {
packet_times.emplace_back(packet.log_time_us());
packet_times.emplace_back(packet.log_time());
};
process.AddEvents(parsed_log_.outgoing_rtcp_packets(),
handle_outgoing_rtcp);
@ -596,7 +600,7 @@ void EventLogAnalyzer::CreatePlayoutGraph(Plot* plot) {
absl::optional<int64_t> last_playout_ms;
TimeSeries time_series(SsrcToString(ssrc), LineStyle::kBar);
for (const auto& playout_event : playout_stream.second) {
float x = config_.GetCallTimeSec(playout_event.log_time_us());
float x = config_.GetCallTimeSec(playout_event.log_time());
int64_t playout_time_ms = playout_event.log_time_ms();
// If there were no previous playouts, place the point on the x-axis.
float y = playout_time_ms - last_playout_ms.value_or(playout_time_ms);
@ -623,7 +627,7 @@ void EventLogAnalyzer::CreateAudioLevelGraph(PacketDirection direction,
LineStyle::kLine);
for (auto& packet : stream.packet_view) {
if (packet.header.extension.hasAudioLevel) {
float x = config_.GetCallTimeSec(packet.log_time_us());
float x = config_.GetCallTimeSec(packet.log_time());
// The audio level is stored in -dBov (so e.g. -10 dBov is stored as 10)
// Here we convert it to dBov.
float y = static_cast<float>(-packet.header.extension.audioLevel);
@ -659,7 +663,7 @@ void EventLogAnalyzer::CreateSequenceNumberGraph(Plot* plot) {
return diff;
};
auto ToCallTime = [this](const LoggedRtpPacketIncoming& packet) {
return this->config_.GetCallTimeSec(packet.log_time_us());
return this->config_.GetCallTimeSec(packet.log_time());
};
ProcessPairs<LoggedRtpPacketIncoming, float>(
ToCallTime, GetSequenceNumberDiff, stream.incoming_packets,
@ -688,8 +692,8 @@ void EventLogAnalyzer::CreateIncomingPacketLossGraph(Plot* plot) {
LineStyle::kLine, PointStyle::kHighlight);
// TODO(terelius): Should the window and step size be read from the class
// instead?
const int64_t kWindowUs = 1000000;
const int64_t kStep = 1000000;
const TimeDelta kWindow = TimeDelta::Millis(1000);
const TimeDelta kStep = TimeDelta::Millis(1000);
SeqNumUnwrapper<uint16_t> unwrapper_;
SeqNumUnwrapper<uint16_t> prior_unwrapper_;
size_t window_index_begin = 0;
@ -699,17 +703,17 @@ void EventLogAnalyzer::CreateIncomingPacketLossGraph(Plot* plot) {
uint64_t highest_prior_seq_number =
prior_unwrapper_.Unwrap(packets[0].rtp.header.sequenceNumber) - 1;
for (int64_t t = config_.begin_time_; t < config_.end_time_ + kStep;
for (Timestamp t = config_.begin_time_; t < config_.end_time_ + kStep;
t += kStep) {
while (window_index_end < packets.size() &&
packets[window_index_end].rtp.log_time_us() < t) {
packets[window_index_end].rtp.log_time() < t) {
uint64_t sequence_number = unwrapper_.Unwrap(
packets[window_index_end].rtp.header.sequenceNumber);
highest_seq_number = std::max(highest_seq_number, sequence_number);
++window_index_end;
}
while (window_index_begin < packets.size() &&
packets[window_index_begin].rtp.log_time_us() < t - kWindowUs) {
packets[window_index_begin].rtp.log_time() < t - kWindow) {
uint64_t sequence_number = prior_unwrapper_.Unwrap(
packets[window_index_begin].rtp.header.sequenceNumber);
highest_prior_seq_number =
@ -764,7 +768,7 @@ void EventLogAnalyzer::CreateIncomingDelayGraph(Plot* plot) {
}
auto ToCallTime = [this](const LoggedRtpPacketIncoming& packet) {
return this->config_.GetCallTimeSec(packet.log_time_us());
return this->config_.GetCallTimeSec(packet.log_time());
};
auto ToNetworkDelay = [frequency_hz](
const LoggedRtpPacketIncoming& old_packet,
@ -800,7 +804,7 @@ void EventLogAnalyzer::CreateFractionLossGraph(Plot* plot) {
TimeSeries time_series("Fraction lost", LineStyle::kLine,
PointStyle::kHighlight);
for (auto& bwe_update : parsed_log_.bwe_loss_updates()) {
float x = config_.GetCallTimeSec(bwe_update.log_time_us());
float x = config_.GetCallTimeSec(bwe_update.log_time());
float y = static_cast<float>(bwe_update.fraction_lost) / 255 * 100;
time_series.points.emplace_back(x, y);
}
@ -815,11 +819,11 @@ void EventLogAnalyzer::CreateFractionLossGraph(Plot* plot) {
// Plot the total bandwidth used by all RTP streams.
void EventLogAnalyzer::CreateTotalIncomingBitrateGraph(Plot* plot) {
// TODO(terelius): This could be provided by the parser.
std::multimap<int64_t, size_t> packets_in_order;
std::multimap<Timestamp, size_t> packets_in_order;
for (const auto& stream : parsed_log_.incoming_rtp_packets_by_ssrc()) {
for (const LoggedRtpPacketIncoming& packet : stream.incoming_packets)
packets_in_order.insert(
std::make_pair(packet.rtp.log_time_us(), packet.rtp.total_length));
std::make_pair(packet.rtp.log_time(), packet.rtp.total_length));
}
auto window_begin = packets_in_order.begin();
@ -829,7 +833,7 @@ void EventLogAnalyzer::CreateTotalIncomingBitrateGraph(Plot* plot) {
if (!packets_in_order.empty()) {
// Calculate a moving average of the bitrate and store in a TimeSeries.
TimeSeries bitrate_series("Bitrate", LineStyle::kLine);
for (int64_t time = config_.begin_time_;
for (Timestamp time = config_.begin_time_;
time < config_.end_time_ + config_.step_; time += config_.step_) {
while (window_end != packets_in_order.end() && window_end->first < time) {
bytes_in_window += window_end->second;
@ -842,7 +846,8 @@ void EventLogAnalyzer::CreateTotalIncomingBitrateGraph(Plot* plot) {
++window_begin;
}
float window_duration_in_seconds =
static_cast<float>(config_.window_duration_) / kNumMicrosecsPerSec;
static_cast<float>(config_.window_duration_.us()) /
kNumMicrosecsPerSec;
float x = config_.GetCallTimeSec(time);
float y = bytes_in_window * 8 / window_duration_in_seconds / 1000;
bitrate_series.points.emplace_back(x, y);
@ -853,7 +858,7 @@ void EventLogAnalyzer::CreateTotalIncomingBitrateGraph(Plot* plot) {
// Overlay the outgoing REMB over incoming bitrate.
TimeSeries remb_series("Remb", LineStyle::kStep);
for (const auto& rtcp : parsed_log_.rembs(kOutgoingPacket)) {
float x = config_.GetCallTimeSec(rtcp.log_time_us());
float x = config_.GetCallTimeSec(rtcp.log_time());
float y = static_cast<float>(rtcp.remb.bitrate_bps()) / 1000;
remb_series.points.emplace_back(x, y);
}
@ -877,15 +882,17 @@ void EventLogAnalyzer::CreateTotalIncomingBitrateGraph(Plot* plot) {
}
// Plot the total bandwidth used by all RTP streams.
void EventLogAnalyzer::CreateTotalOutgoingBitrateGraph(Plot* plot,
bool show_detector_state,
bool show_alr_state) {
void EventLogAnalyzer::CreateTotalOutgoingBitrateGraph(
Plot* plot,
bool show_detector_state,
bool show_alr_state,
bool show_link_capacity) {
// TODO(terelius): This could be provided by the parser.
std::multimap<int64_t, size_t> packets_in_order;
std::multimap<Timestamp, size_t> packets_in_order;
for (const auto& stream : parsed_log_.outgoing_rtp_packets_by_ssrc()) {
for (const LoggedRtpPacketOutgoing& packet : stream.outgoing_packets)
packets_in_order.insert(
std::make_pair(packet.rtp.log_time_us(), packet.rtp.total_length));
std::make_pair(packet.rtp.log_time(), packet.rtp.total_length));
}
auto window_begin = packets_in_order.begin();
@ -895,7 +902,7 @@ void EventLogAnalyzer::CreateTotalOutgoingBitrateGraph(Plot* plot,
if (!packets_in_order.empty()) {
// Calculate a moving average of the bitrate and store in a TimeSeries.
TimeSeries bitrate_series("Bitrate", LineStyle::kLine);
for (int64_t time = config_.begin_time_;
for (Timestamp time = config_.begin_time_;
time < config_.end_time_ + config_.step_; time += config_.step_) {
while (window_end != packets_in_order.end() && window_end->first < time) {
bytes_in_window += window_end->second;
@ -908,7 +915,8 @@ void EventLogAnalyzer::CreateTotalOutgoingBitrateGraph(Plot* plot,
++window_begin;
}
float window_duration_in_seconds =
static_cast<float>(config_.window_duration_) / kNumMicrosecsPerSec;
static_cast<float>(config_.window_duration_.us()) /
kNumMicrosecsPerSec;
float x = config_.GetCallTimeSec(time);
float y = bytes_in_window * 8 / window_duration_in_seconds / 1000;
bitrate_series.points.emplace_back(x, y);
@ -919,11 +927,29 @@ void EventLogAnalyzer::CreateTotalOutgoingBitrateGraph(Plot* plot,
// Overlay the send-side bandwidth estimate over the outgoing bitrate.
TimeSeries loss_series("Loss-based estimate", LineStyle::kStep);
for (auto& loss_update : parsed_log_.bwe_loss_updates()) {
float x = config_.GetCallTimeSec(loss_update.log_time_us());
float x = config_.GetCallTimeSec(loss_update.log_time());
float y = static_cast<float>(loss_update.bitrate_bps) / 1000;
loss_series.points.emplace_back(x, y);
}
TimeSeries link_capacity_lower_series("Link-capacity-lower",
LineStyle::kStep);
TimeSeries link_capacity_upper_series("Link-capacity-upper",
LineStyle::kStep);
for (auto& remote_estimate_event : parsed_log_.remote_estimate_events()) {
float x = config_.GetCallTimeSec(remote_estimate_event.log_time());
if (remote_estimate_event.link_capacity_lower.has_value()) {
float link_capacity_lower = static_cast<float>(
remote_estimate_event.link_capacity_lower.value().kbps());
link_capacity_lower_series.points.emplace_back(x, link_capacity_lower);
}
if (remote_estimate_event.link_capacity_upper.has_value()) {
float link_capacity_upper = static_cast<float>(
remote_estimate_event.link_capacity_upper.value().kbps());
link_capacity_upper_series.points.emplace_back(x, link_capacity_upper);
}
}
TimeSeries delay_series("Delay-based estimate", LineStyle::kStep);
IntervalSeries overusing_series("Overusing", "#ff8e82",
IntervalSeries::kHorizontal);
@ -932,12 +958,12 @@ void EventLogAnalyzer::CreateTotalOutgoingBitrateGraph(Plot* plot,
IntervalSeries normal_series("Normal", "#c4ffc4",
IntervalSeries::kHorizontal);
IntervalSeries* last_series = &normal_series;
double last_detector_switch = 0.0;
float last_detector_switch = 0.0;
BandwidthUsage last_detector_state = BandwidthUsage::kBwNormal;
for (auto& delay_update : parsed_log_.bwe_delay_updates()) {
float x = config_.GetCallTimeSec(delay_update.log_time_us());
float x = config_.GetCallTimeSec(delay_update.log_time());
float y = static_cast<float>(delay_update.bitrate_bps) / 1000;
if (last_detector_state != delay_update.detector_state) {
@ -956,7 +982,7 @@ void EventLogAnalyzer::CreateTotalOutgoingBitrateGraph(Plot* plot,
last_series = &overusing_series;
break;
case BandwidthUsage::kLast:
RTC_NOTREACHED();
RTC_DCHECK_NOTREACHED();
}
}
@ -964,12 +990,13 @@ void EventLogAnalyzer::CreateTotalOutgoingBitrateGraph(Plot* plot,
}
RTC_CHECK(last_series);
last_series->intervals.emplace_back(last_detector_switch, config_.end_time_);
last_series->intervals.emplace_back(last_detector_switch,
config_.CallEndTimeSec());
TimeSeries created_series("Probe cluster created.", LineStyle::kNone,
PointStyle::kHighlight);
for (auto& cluster : parsed_log_.bwe_probe_cluster_created_events()) {
float x = config_.GetCallTimeSec(cluster.log_time_us());
float x = config_.GetCallTimeSec(cluster.log_time());
float y = static_cast<float>(cluster.bitrate_bps) / 1000;
created_series.points.emplace_back(x, y);
}
@ -977,7 +1004,7 @@ void EventLogAnalyzer::CreateTotalOutgoingBitrateGraph(Plot* plot,
TimeSeries result_series("Probing results.", LineStyle::kNone,
PointStyle::kHighlight);
for (auto& result : parsed_log_.bwe_probe_success_events()) {
float x = config_.GetCallTimeSec(result.log_time_us());
float x = config_.GetCallTimeSec(result.log_time());
float y = static_cast<float>(result.bitrate_bps) / 1000;
result_series.points.emplace_back(x, y);
}
@ -985,17 +1012,17 @@ void EventLogAnalyzer::CreateTotalOutgoingBitrateGraph(Plot* plot,
TimeSeries probe_failures_series("Probe failed", LineStyle::kNone,
PointStyle::kHighlight);
for (auto& failure : parsed_log_.bwe_probe_failure_events()) {
float x = config_.GetCallTimeSec(failure.log_time_us());
float x = config_.GetCallTimeSec(failure.log_time());
probe_failures_series.points.emplace_back(x, 0);
}
IntervalSeries alr_state("ALR", "#555555", IntervalSeries::kHorizontal);
bool previously_in_alr = false;
int64_t alr_start = 0;
Timestamp alr_start = Timestamp::Zero();
for (auto& alr : parsed_log_.alr_state_events()) {
float y = config_.GetCallTimeSec(alr.log_time_us());
float y = config_.GetCallTimeSec(alr.log_time());
if (!previously_in_alr && alr.in_alr) {
alr_start = alr.log_time_us();
alr_start = alr.log_time();
previously_in_alr = true;
} else if (previously_in_alr && !alr.in_alr) {
float x = config_.GetCallTimeSec(alr_start);
@ -1019,6 +1046,12 @@ void EventLogAnalyzer::CreateTotalOutgoingBitrateGraph(Plot* plot,
if (show_alr_state) {
plot->AppendIntervalSeries(std::move(alr_state));
}
if (show_link_capacity) {
plot->AppendTimeSeriesIfNotEmpty(std::move(link_capacity_lower_series));
plot->AppendTimeSeriesIfNotEmpty(std::move(link_capacity_upper_series));
}
plot->AppendTimeSeries(std::move(loss_series));
plot->AppendTimeSeriesIfNotEmpty(std::move(probe_failures_series));
plot->AppendTimeSeries(std::move(delay_series));
@ -1028,7 +1061,7 @@ void EventLogAnalyzer::CreateTotalOutgoingBitrateGraph(Plot* plot,
// Overlay the incoming REMB over the outgoing bitrate.
TimeSeries remb_series("Remb", LineStyle::kStep);
for (const auto& rtcp : parsed_log_.rembs(kIncomingPacket)) {
float x = config_.GetCallTimeSec(rtcp.log_time_us());
float x = config_.GetCallTimeSec(rtcp.log_time());
float y = static_cast<float>(rtcp.remb.bitrate_bps()) / 1000;
remb_series.points.emplace_back(x, y);
}
@ -1114,7 +1147,7 @@ void EventLogAnalyzer::CreateBitrateAllocationGraph(PacketDirection direction,
std::make_pair(layer, TimeSeries(layer_name, LineStyle::kStep)));
RTC_DCHECK(inserted);
}
float x = config_.GetCallTimeSec(rtcp.log_time_us());
float x = config_.GetCallTimeSec(rtcp.log_time());
float y = bitrate_item.target_bitrate_kbps;
time_series_it->second.points.emplace_back(x, y);
}
@ -1146,22 +1179,20 @@ void EventLogAnalyzer::CreateGoogCcSimulationGraph(Plot* plot) {
[&](const NetworkControlUpdate& update, Timestamp at_time) {
if (update.target_rate) {
target_rates.points.emplace_back(
config_.GetCallTimeSec(at_time.us()),
config_.GetCallTimeSec(at_time),
update.target_rate->target_rate.kbps<float>());
}
});
simulation.ProcessEventsInLog(parsed_log_);
for (const auto& logged : parsed_log_.bwe_delay_updates())
delay_based.points.emplace_back(
config_.GetCallTimeSec(logged.log_time_us()),
logged.bitrate_bps / 1000);
delay_based.points.emplace_back(config_.GetCallTimeSec(logged.log_time()),
logged.bitrate_bps / 1000);
for (const auto& logged : parsed_log_.bwe_probe_success_events())
probe_results.points.emplace_back(
config_.GetCallTimeSec(logged.log_time_us()),
logged.bitrate_bps / 1000);
probe_results.points.emplace_back(config_.GetCallTimeSec(logged.log_time()),
logged.bitrate_bps / 1000);
for (const auto& logged : parsed_log_.bwe_loss_updates())
loss_based.points.emplace_back(config_.GetCallTimeSec(logged.log_time_us()),
loss_based.points.emplace_back(config_.GetCallTimeSec(logged.log_time()),
logged.bitrate_bps / 1000);
plot->AppendTimeSeries(std::move(delay_based));
@ -1193,8 +1224,6 @@ void EventLogAnalyzer::CreateSendSideBweSimulationGraph(Plot* plot) {
SimulatedClock clock(0);
BitrateObserver observer;
RtcEventLogNull null_event_log;
PacketRouter packet_router;
PacedSender pacer(&clock, &packet_router, &null_event_log);
TransportFeedbackAdapter transport_feedback;
auto factory = GoogCcNetworkControllerFactory();
TimeDelta process_interval = factory.GetProcessInterval();
@ -1241,11 +1270,11 @@ void EventLogAnalyzer::CreateSendSideBweSimulationGraph(Plot* plot) {
return std::numeric_limits<int64_t>::max();
};
RateStatistics acked_bitrate(750, 8000);
RateStatistics raw_acked_bitrate(750, 8000);
test::ExplicitKeyValueConfig throughput_config(
"WebRTC-Bwe-RobustThroughputEstimatorSettings/"
"enabled:true,reduce_bias:true,assume_shared_link:false,initial_packets:"
"10,min_packets:25,window_duration:750ms,unacked_weight:0.5/");
"enabled:true,required_packets:10,"
"window_packets:25,window_duration:1000ms,unacked_weight:1.0/");
std::unique_ptr<AcknowledgedBitrateEstimatorInterface>
robust_throughput_estimator(
AcknowledgedBitrateEstimatorInterface::Create(&throughput_config));
@ -1263,7 +1292,7 @@ void EventLogAnalyzer::CreateSendSideBweSimulationGraph(Plot* plot) {
const RtpPacketType& rtp_packet = *rtp_iterator->second;
if (rtp_packet.rtp.header.extension.hasTransportSequenceNumber) {
RtpPacketSendInfo packet_info;
packet_info.ssrc = rtp_packet.rtp.header.ssrc;
packet_info.media_ssrc = rtp_packet.rtp.header.ssrc;
packet_info.transport_sequence_number =
rtp_packet.rtp.header.extension.transportSequenceNumber;
packet_info.rtp_sequence_number = rtp_packet.rtp.header.sequenceNumber;
@ -1304,7 +1333,6 @@ void EventLogAnalyzer::CreateSendSideBweSimulationGraph(Plot* plot) {
auto feedback_msg = transport_feedback.ProcessTransportFeedback(
rtcp_iterator->transport_feedback,
Timestamp::Millis(clock.TimeInMilliseconds()));
absl::optional<uint32_t> bitrate_bps;
if (feedback_msg) {
observer.Update(goog_cc->OnTransportPacketsFeedback(*feedback_msg));
std::vector<PacketResult> feedback =
@ -1314,24 +1342,30 @@ void EventLogAnalyzer::CreateSendSideBweSimulationGraph(Plot* plot) {
feedback);
robust_throughput_estimator->IncomingPacketFeedbackVector(feedback);
for (const PacketResult& packet : feedback) {
acked_bitrate.Update(packet.sent_packet.size.bytes(),
packet.receive_time.ms());
raw_acked_bitrate.Update(packet.sent_packet.size.bytes(),
packet.receive_time.ms());
}
absl::optional<uint32_t> raw_bitrate_bps =
raw_acked_bitrate.Rate(feedback.back().receive_time.ms());
float x = config_.GetCallTimeSec(clock.CurrentTime());
if (raw_bitrate_bps) {
float y = raw_bitrate_bps.value() / 1000;
acked_time_series.points.emplace_back(x, y);
}
absl::optional<DataRate> robust_estimate =
robust_throughput_estimator->bitrate();
if (robust_estimate) {
float y = robust_estimate.value().kbps();
robust_time_series.points.emplace_back(x, y);
}
absl::optional<DataRate> acked_estimate =
acknowledged_bitrate_estimator->bitrate();
if (acked_estimate) {
float y = acked_estimate.value().kbps();
acked_estimate_time_series.points.emplace_back(x, y);
}
bitrate_bps = acked_bitrate.Rate(feedback.back().receive_time.ms());
}
}
float x = config_.GetCallTimeSec(clock.TimeInMicroseconds());
float y = bitrate_bps.value_or(0) / 1000;
acked_time_series.points.emplace_back(x, y);
y = robust_throughput_estimator->bitrate()
.value_or(DataRate::Zero())
.kbps();
robust_time_series.points.emplace_back(x, y);
y = acknowledged_bitrate_estimator->bitrate()
.value_or(DataRate::Zero())
.kbps();
acked_estimate_time_series.points.emplace_back(x, y);
++rtcp_iterator;
}
if (clock.TimeInMicroseconds() >= NextProcessTime()) {
@ -1344,7 +1378,7 @@ void EventLogAnalyzer::CreateSendSideBweSimulationGraph(Plot* plot) {
if (observer.GetAndResetBitrateUpdated() ||
time_us - last_update_us >= 1e6) {
uint32_t y = observer.last_bitrate_bps() / 1000;
float x = config_.GetCallTimeSec(clock.TimeInMicroseconds());
float x = config_.GetCallTimeSec(clock.CurrentTime());
time_series.points.emplace_back(x, y);
last_update_us = time_us;
}
@ -1364,13 +1398,11 @@ void EventLogAnalyzer::CreateSendSideBweSimulationGraph(Plot* plot) {
void EventLogAnalyzer::CreateReceiveSideBweSimulationGraph(Plot* plot) {
using RtpPacketType = LoggedRtpPacketIncoming;
class RembInterceptingPacketRouter : public PacketRouter {
class RembInterceptor {
public:
void OnReceiveBitrateChanged(const std::vector<uint32_t>& ssrcs,
uint32_t bitrate_bps) override {
void SendRemb(uint32_t bitrate_bps, std::vector<uint32_t> ssrcs) {
last_bitrate_bps_ = bitrate_bps;
bitrate_updated_ = true;
PacketRouter::OnReceiveBitrateChanged(ssrcs, bitrate_bps);
}
uint32_t last_bitrate_bps() const { return last_bitrate_bps_; }
bool GetAndResetBitrateUpdated() {
@ -1397,10 +1429,10 @@ void EventLogAnalyzer::CreateReceiveSideBweSimulationGraph(Plot* plot) {
}
SimulatedClock clock(0);
RembInterceptingPacketRouter packet_router;
// TODO(terelius): The PacketRouter is used as the RemoteBitrateObserver.
// Is this intentional?
ReceiveSideCongestionController rscc(&clock, &packet_router);
RembInterceptor remb_interceptor;
ReceiveSideCongestionController rscc(
&clock, [](auto...) {},
absl::bind_front(&RembInterceptor::SendRemb, &remb_interceptor), nullptr);
// TODO(holmer): Log the call config and use that here instead.
// static const uint32_t kDefaultStartBitrateBps = 300000;
// rscc.SetBweBitrates(0, kDefaultStartBitrateBps, -1);
@ -1422,13 +1454,13 @@ void EventLogAnalyzer::CreateReceiveSideBweSimulationGraph(Plot* plot) {
absl::optional<uint32_t> bitrate_bps = acked_bitrate.Rate(arrival_time_ms);
if (bitrate_bps) {
uint32_t y = *bitrate_bps / 1000;
float x = config_.GetCallTimeSec(clock.TimeInMicroseconds());
float x = config_.GetCallTimeSec(clock.CurrentTime());
acked_time_series.points.emplace_back(x, y);
}
if (packet_router.GetAndResetBitrateUpdated() ||
if (remb_interceptor.GetAndResetBitrateUpdated() ||
clock.TimeInMicroseconds() - last_update_us >= 1e6) {
uint32_t y = packet_router.last_bitrate_bps() / 1000;
float x = config_.GetCallTimeSec(clock.TimeInMicroseconds());
uint32_t y = remb_interceptor.last_bitrate_bps() / 1000;
float x = config_.GetCallTimeSec(clock.CurrentTime());
time_series.points.emplace_back(x, y);
last_update_us = clock.TimeInMicroseconds();
}
@ -1449,7 +1481,6 @@ void EventLogAnalyzer::CreateNetworkDelayFeedbackGraph(Plot* plot) {
int64_t min_send_receive_diff_ms = std::numeric_limits<int64_t>::max();
int64_t min_rtt_ms = std::numeric_limits<int64_t>::max();
int64_t prev_y = 0;
std::vector<MatchedSendArrivalTimes> matched_rtp_rtcp =
GetNetworkTrace(parsed_log_);
absl::c_stable_sort(matched_rtp_rtcp, [](const MatchedSendArrivalTimes& a,
@ -1461,9 +1492,8 @@ void EventLogAnalyzer::CreateNetworkDelayFeedbackGraph(Plot* plot) {
for (const auto& packet : matched_rtp_rtcp) {
if (packet.arrival_time_ms == MatchedSendArrivalTimes::kNotReceived)
continue;
float x = config_.GetCallTimeSec(1000 * packet.feedback_arrival_time_ms);
float x = config_.GetCallTimeSecFromMs(packet.feedback_arrival_time_ms);
int64_t y = packet.arrival_time_ms - packet.send_time_ms;
prev_y = y;
int64_t rtt_ms = packet.feedback_arrival_time_ms - packet.send_time_ms;
min_rtt_ms = std::min(rtt_ms, min_rtt_ms);
min_send_receive_diff_ms = std::min(y, min_send_receive_diff_ms);
@ -1531,7 +1561,7 @@ void EventLogAnalyzer::CreatePacerDelayGraph(Plot* plot) {
double send_time_ms =
static_cast<double>(packet.rtp.log_time_us() - first_send_timestamp) /
1000;
float x = config_.GetCallTimeSec(packet.rtp.log_time_us());
float x = config_.GetCallTimeSec(packet.rtp.log_time());
float y = send_time_ms - capture_time_ms;
pacer_delay_series.points.emplace_back(x, y);
}
@ -1552,7 +1582,7 @@ void EventLogAnalyzer::CreateTimestampGraph(PacketDirection direction,
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());
float x = config_.GetCallTimeSec(packet.log_time());
float y = packet.header.timestamp;
rtp_timestamps.points.emplace_back(x, y);
}
@ -1567,7 +1597,7 @@ void EventLogAnalyzer::CreateTimestampGraph(PacketDirection direction,
for (const auto& rtcp : sender_reports) {
if (rtcp.sr.sender_ssrc() != stream.ssrc)
continue;
float x = config_.GetCallTimeSec(rtcp.log_time_us());
float x = config_.GetCallTimeSec(rtcp.log_time());
float y = rtcp.sr.rtp_timestamp();
rtcp_timestamps.points.emplace_back(x, y);
}
@ -1589,7 +1619,7 @@ void EventLogAnalyzer::CreateSenderAndReceiverReportPlot(
std::map<uint32_t, TimeSeries> sr_reports_by_ssrc;
const auto& sender_reports = parsed_log_.sender_reports(direction);
for (const auto& rtcp : sender_reports) {
float x = config_.GetCallTimeSec(rtcp.log_time_us());
float x = config_.GetCallTimeSec(rtcp.log_time());
uint32_t ssrc = rtcp.sr.sender_ssrc();
for (const auto& block : rtcp.sr.report_blocks()) {
float y = fy(block);
@ -1611,7 +1641,7 @@ void EventLogAnalyzer::CreateSenderAndReceiverReportPlot(
std::map<uint32_t, TimeSeries> rr_reports_by_ssrc;
const auto& receiver_reports = parsed_log_.receiver_reports(direction);
for (const auto& rtcp : receiver_reports) {
float x = config_.GetCallTimeSec(rtcp.log_time_us());
float x = config_.GetCallTimeSec(rtcp.log_time());
uint32_t ssrc = rtcp.rr.sender_ssrc();
for (const auto& block : rtcp.rr.report_blocks()) {
float y = fy(block);
@ -1650,7 +1680,7 @@ void EventLogAnalyzer::CreateIceCandidatePairConfigGraph(Plot* plot) {
candidate_pair_desc_by_id_[config.candidate_pair_id] =
candidate_pair_desc;
}
float x = config_.GetCallTimeSec(config.log_time_us());
float x = config_.GetCallTimeSec(config.log_time());
float y = static_cast<float>(config.type);
configs_by_cp_id[config.candidate_pair_id].points.emplace_back(x, y);
}
@ -1707,7 +1737,7 @@ void EventLogAnalyzer::CreateIceConnectivityCheckGraph(Plot* plot) {
GetCandidatePairLogDescriptionFromId(event.candidate_pair_id),
LineStyle::kNone, PointStyle::kHighlight);
}
float x = config_.GetCallTimeSec(event.log_time_us());
float x = config_.GetCallTimeSec(event.log_time());
float y = static_cast<float>(event.type) + kEventTypeOffset;
checks_by_cp_id[event.candidate_pair_id].points.emplace_back(x, y);
}
@ -1742,7 +1772,7 @@ void EventLogAnalyzer::CreateDtlsTransportStateGraph(Plot* plot) {
TimeSeries states("DTLS Transport State", LineStyle::kNone,
PointStyle::kHighlight);
for (const auto& event : parsed_log_.dtls_transport_states()) {
float x = config_.GetCallTimeSec(event.log_time_us());
float x = config_.GetCallTimeSec(event.log_time());
float y = static_cast<float>(event.dtls_transport_state);
states.points.emplace_back(x, y);
}
@ -1764,7 +1794,7 @@ void EventLogAnalyzer::CreateDtlsWritableStateGraph(Plot* plot) {
TimeSeries writable("DTLS Writable", LineStyle::kNone,
PointStyle::kHighlight);
for (const auto& event : parsed_log_.dtls_writable_states()) {
float x = config_.GetCallTimeSec(event.log_time_us());
float x = config_.GetCallTimeSec(event.log_time());
float y = static_cast<float>(event.writable);
writable.points.emplace_back(x, y);
}

View File

@ -59,7 +59,8 @@ class EventLogAnalyzer {
void CreateTotalIncomingBitrateGraph(Plot* plot);
void CreateTotalOutgoingBitrateGraph(Plot* plot,
bool show_detector_state = false,
bool show_alr_state = false);
bool show_alr_state = false,
bool show_link_capacity = false);
void CreateStreamBitrateGraph(PacketDirection direction, Plot* plot);
void CreateBitrateAllocationGraph(PacketDirection direction, Plot* plot);

View File

@ -22,6 +22,7 @@
namespace webrtc {
constexpr int kNumMicrosecsPerSec = 1000000;
constexpr int kNumMillisecsPerSec = 1000;
constexpr float kLeftMargin = 0.01f;
constexpr float kRightMargin = 0.02f;
constexpr float kBottomMargin = 0.02f;
@ -29,25 +30,38 @@ constexpr float kTopMargin = 0.05f;
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 GetCallTimeSec(Timestamp timestamp) const {
Timestamp offset = normalize_time_ ? begin_time_ : Timestamp::Zero();
return static_cast<float>((timestamp - offset).us()) / 1000000;
}
float GetCallTimeSecFromMs(int64_t timestamp_ms) const {
return GetCallTimeSec(Timestamp::Millis(timestamp_ms));
}
float CallBeginTimeSec() const { return GetCallTimeSec(begin_time_); }
float CallEndTimeSec() const { return GetCallTimeSec(end_time_); }
int64_t CallTimeToUtcOffsetMs() {
if (normalize_time_) {
Timestamp utc_begin_time_ = begin_time_ + rtc_to_utc_offset_;
return utc_begin_time_.ms();
}
return rtc_to_utc_offset_.ms();
}
// 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_;
// The generated data points will be `step_.ms()` milliseconds apart.
// Only events occurring at most `window_duration_.ms()` milliseconds before
// the current data point will be part of the average.
TimeDelta window_duration_ = TimeDelta::Millis(250);
TimeDelta step_ = TimeDelta::Millis(10);
// First and last events of the log.
int64_t begin_time_;
int64_t end_time_;
Timestamp begin_time_ = Timestamp::MinusInfinity();
Timestamp end_time_ = Timestamp::MinusInfinity();
TimeDelta rtc_to_utc_offset_ = TimeDelta::Zero();
bool normalize_time_;
};
@ -83,7 +97,7 @@ std::string GetStreamName(const ParsedRtcEventLog& parsed_log,
uint32_t ssrc);
std::string GetLayerName(LayerDescription layer);
// For each element in data_view, use |f()| to extract a y-coordinate and
// For each element in data_view, use `f()` to extract a y-coordinate and
// store the result in a TimeSeries.
template <typename DataType, typename IterableType>
void ProcessPoints(rtc::FunctionView<float(const DataType&)> fx,
@ -99,7 +113,7 @@ void ProcessPoints(rtc::FunctionView<float(const DataType&)> fx,
}
}
// For each pair of adjacent elements in |data|, use |f()| to extract a
// For each pair of adjacent elements in `data`, use `f()` to extract a
// y-coordinate and store the result in a TimeSeries. Note that the x-coordinate
// will be the time of the second element in the pair.
template <typename DataType, typename ResultType, typename IterableType>
@ -117,7 +131,7 @@ void ProcessPairs(
}
}
// For each pair of adjacent elements in |data|, use |f()| to extract a
// For each pair of adjacent elements in `data`, use `f()` to extract a
// y-coordinate and store the result in a TimeSeries. Note that the x-coordinate
// will be the time of the second element in the pair.
template <typename DataType, typename ResultType, typename IterableType>
@ -138,10 +152,10 @@ void AccumulatePairs(
}
}
// Calculates a moving average of |data| and stores the result in a TimeSeries.
// A data point is generated every |step| microseconds from |begin_time|
// to |end_time|. The value of each data point is the average of the data
// during the preceding |window_duration_us| microseconds.
// Calculates a moving average of `data` and stores the result in a TimeSeries.
// A data point is generated every `step` microseconds from `begin_time`
// to `end_time`. The value of each data point is the average of the data
// during the preceding `window_duration_us` microseconds.
template <typename DataType, typename ResultType, typename IterableType>
void MovingAverage(
rtc::FunctionView<absl::optional<ResultType>(const DataType&)> fy,
@ -152,17 +166,17 @@ void MovingAverage(
size_t window_index_end = 0;
ResultType sum_in_window = 0;
for (int64_t t = config.begin_time_; t < config.end_time_ + config.step_;
for (Timestamp t = config.begin_time_; t < config.end_time_ + config.step_;
t += config.step_) {
while (window_index_end < data_view.size() &&
data_view[window_index_end].log_time_us() < t) {
data_view[window_index_end].log_time() < t) {
absl::optional<ResultType> value = fy(data_view[window_index_end]);
if (value)
sum_in_window += *value;
++window_index_end;
}
while (window_index_begin < data_view.size() &&
data_view[window_index_begin].log_time_us() <
data_view[window_index_begin].log_time() <
t - config.window_duration_) {
absl::optional<ResultType> value = fy(data_view[window_index_begin]);
if (value)
@ -170,7 +184,7 @@ void MovingAverage(
++window_index_begin;
}
float window_duration_s =
static_cast<float>(config.window_duration_) / kNumMicrosecsPerSec;
static_cast<float>(config.window_duration_.us()) / kNumMicrosecsPerSec;
float x = config.GetCallTimeSec(t);
float y = sum_in_window / window_duration_s;
result->points.emplace_back(x, y);

File diff suppressed because it is too large Load Diff

View File

@ -14,6 +14,7 @@
#include "logging/rtc_event_log/rtc_event_processor.h"
#include "modules/rtp_rtcp/source/time_util.h"
#include "system_wrappers/include/clock.h"
namespace webrtc {
@ -83,7 +84,7 @@ void LogBasedNetworkControllerSimulation::OnPacketSent(
}
RtpPacketSendInfo packet_info;
packet_info.ssrc = packet.ssrc;
packet_info.media_ssrc = packet.ssrc;
packet_info.transport_sequence_number = packet.transport_seq_no;
packet_info.rtp_sequence_number = packet.stream_seq_no;
packet_info.length = packet.size;
@ -142,14 +143,16 @@ void LogBasedNetworkControllerSimulation::OnReceiverReport(
HandleStateUpdate(controller_->OnTransportLossReport(msg));
}
Clock* clock = Clock::GetRealTimeClock();
TimeDelta rtt = TimeDelta::PlusInfinity();
for (auto& rb : report.rr.report_blocks()) {
if (rb.last_sr()) {
Timestamp report_log_time = Timestamp::Micros(report.log_time_us());
uint32_t receive_time_ntp =
CompactNtp(TimeMicrosToNtp(report.log_time_us()));
CompactNtp(clock->ConvertTimestampToNtpTime(report_log_time));
uint32_t rtt_ntp =
receive_time_ntp - rb.delay_since_last_sr() - rb.last_sr();
rtt = std::min(rtt, TimeDelta::Millis(CompactNtpRttToMs(rtt_ntp)));
rtt = std::min(rtt, CompactNtpRttToTimeDelta(rtt_ntp));
}
}
if (rtt.IsFinite()) {

View File

@ -11,6 +11,8 @@
#include <stdio.h>
#include <string.h>
#include <cstdio>
#include <fstream>
#include <iostream>
#include <map>
#include <memory>
@ -33,10 +35,9 @@
#include "rtc_tools/rtc_event_log_visualizer/alerts.h"
#include "rtc_tools/rtc_event_log_visualizer/analyze_audio.h"
#include "rtc_tools/rtc_event_log_visualizer/analyzer.h"
#include "rtc_tools/rtc_event_log_visualizer/conversational_speech_en.h"
#include "rtc_tools/rtc_event_log_visualizer/plot_base.h"
#include "system_wrappers/include/field_trial.h"
#include "test/field_trial.h"
#include "test/testsupport/file_utils.h"
ABSL_FLAG(std::string,
plot,
@ -68,6 +69,12 @@ ABSL_FLAG(bool,
false,
"Show the state ALR state on the total bitrate graph");
ABSL_FLAG(bool,
show_link_capacity,
true,
"Show the lower and upper link capacity on the outgoing bitrate "
"graph");
ABSL_FLAG(bool,
parse_unconfigured_header_extensions,
true,
@ -229,8 +236,7 @@ int main(int argc, char* argv[]) {
{"simulated_neteq_stats",
{"simulated_neteq_jitter_buffer_delay",
"simulated_neteq_preferred_buffer_size",
"simulated_neteq_concealment_events",
"simulated_neteq_packet_loss_rate", "simulated_neteq_preemptive_rate",
"simulated_neteq_concealment_events", "simulated_neteq_preemptive_rate",
"simulated_neteq_accelerate_rate", "simulated_neteq_speech_expand_rate",
"simulated_neteq_expand_rate"}}};
@ -262,8 +268,12 @@ int main(int argc, char* argv[]) {
}
webrtc::AnalyzerConfig config;
config.window_duration_ = 250000;
config.step_ = 10000;
config.window_duration_ = webrtc::TimeDelta::Millis(250);
config.step_ = webrtc::TimeDelta::Millis(10);
if (!parsed_log.start_log_events().empty()) {
config.rtc_to_utc_offset_ = parsed_log.start_log_events()[0].utc_time() -
parsed_log.start_log_events()[0].log_time();
}
config.normalize_time_ = absl::GetFlag(FLAGS_normalize_time);
config.begin_time_ = parsed_log.first_timestamp();
config.end_time_ = parsed_log.last_timestamp();
@ -276,6 +286,7 @@ int main(int argc, char* argv[]) {
webrtc::EventLogAnalyzer analyzer(parsed_log, config);
webrtc::PlotCollection collection;
collection.SetCallTimeToUtcOffsetMs(config.CallTimeToUtcOffsetMs());
PlotMap plots;
plots.RegisterPlot("incoming_packet_sizes", [&](Plot* plot) {
@ -332,7 +343,8 @@ int main(int argc, char* argv[]) {
plots.RegisterPlot("outgoing_bitrate", [&](Plot* plot) {
analyzer.CreateTotalOutgoingBitrateGraph(
plot, absl::GetFlag(FLAGS_show_detector_state),
absl::GetFlag(FLAGS_show_alr_state));
absl::GetFlag(FLAGS_show_alr_state),
absl::GetFlag(FLAGS_show_link_capacity));
});
plots.RegisterPlot("incoming_stream_bitrate", [&](Plot* plot) {
analyzer.CreateStreamBitrateGraph(webrtc::kIncomingPacket, plot);
@ -461,11 +473,18 @@ int main(int argc, char* argv[]) {
});
std::string wav_path;
bool has_generated_wav_file = false;
if (!absl::GetFlag(FLAGS_wav_filename).empty()) {
wav_path = absl::GetFlag(FLAGS_wav_filename);
} else {
wav_path = webrtc::test::ResourcePath(
"audio_processing/conversational_speech/EN_script2_F_sp2_B1", "wav");
// TODO(bugs.webrtc.org/14248): Remove the need to generate a file
// and read the file directly from memory.
wav_path = std::tmpnam(nullptr);
std::ofstream out_wav_file(wav_path);
out_wav_file.write(
reinterpret_cast<char*>(&webrtc::conversational_speech_en_wav[0]),
webrtc::conversational_speech_en_wav_len);
has_generated_wav_file = true;
}
absl::optional<webrtc::NetEqStatsGetterMap> neteq_stats;
@ -517,18 +536,6 @@ int main(int argc, char* argv[]) {
"Preemptive rate", plot);
});
plots.RegisterPlot("simulated_neteq_packet_loss_rate", [&](Plot* plot) {
if (!neteq_stats) {
neteq_stats = webrtc::SimulateNetEq(parsed_log, config, wav_path, 48000);
}
webrtc::CreateNetEqNetworkStatsGraph(
parsed_log, config, *neteq_stats,
[](const webrtc::NetEqNetworkStatistics& stats) {
return stats.packet_loss_rate / 16384.f;
},
"Packet loss rate", plot);
});
plots.RegisterPlot("simulated_neteq_concealment_events", [&](Plot* plot) {
if (!neteq_stats) {
neteq_stats = webrtc::SimulateNetEq(parsed_log, config, wav_path, 48000);
@ -631,5 +638,11 @@ int main(int argc, char* argv[]) {
triage_alerts.Print(stderr);
}
// TODO(bugs.webrtc.org/14248): Remove the need to generate a file
// and read the file directly from memory.
if (has_generated_wav_file) {
RTC_CHECK_EQ(std::remove(wav_path.c_str()), 0)
<< "Failed to remove " << wav_path;
}
return 0;
}

View File

@ -127,9 +127,8 @@ void Plot::PrintPythonCode() const {
// There is a plt.bar function that draws bar plots,
// but it is *way* too slow to be useful.
printf(
"plt.vlines(x%zu, map(lambda t: min(t,0), y%zu), map(lambda t: "
"max(t,0), y%zu), color=colors[%zu], "
"label=\'%s\')\n",
"plt.vlines(x%zu, [min(t,0) for t in y%zu], [max(t,0) for t in "
"y%zu], color=colors[%zu], label=\'%s\')\n",
i, i, i, i, series_list_[i].label.c_str());
if (series_list_[i].point_style == PointStyle::kHighlight) {
printf(
@ -221,7 +220,7 @@ void Plot::PrintPythonCode() const {
printf("plt.ylabel(\'%s\')\n", yaxis_label_.c_str());
printf("plt.title(\'%s\')\n", title_.c_str());
printf("fig = plt.gcf()\n");
printf("fig.canvas.set_window_title(\'%s\')\n", id_.c_str());
printf("fig.canvas.manager.set_window_title(\'%s\')\n", id_.c_str());
if (!yaxis_tick_labels_.empty()) {
printf("yaxis_tick_labels = [");
for (const auto& kv : yaxis_tick_labels_) {
@ -308,13 +307,13 @@ void PlotCollection::PrintPythonCode(bool shared_xaxis) const {
void PlotCollection::ExportProtobuf(
webrtc::analytics::ChartCollection* collection) const {
for (const auto& plot : plots_) {
// TODO(terelius): Ensure that there is no way to insert plots other than
// ProtobufPlots in a ProtobufPlotCollection. Needed to safely static_cast
// here.
webrtc::analytics::Chart* protobuf_representation =
collection->add_charts();
plot->ExportProtobuf(protobuf_representation);
}
if (calltime_to_utc_ms_) {
collection->set_calltime_to_utc_ms(*calltime_to_utc_ms_);
}
}
Plot* PlotCollection::AppendNewPlot() {

View File

@ -15,7 +15,8 @@
#include <utility>
#include <vector>
#include "rtc_base/deprecation.h"
#include "absl/base/attributes.h"
#include "absl/types/optional.h"
#include "rtc_base/ignore_wundef.h"
RTC_PUSH_IGNORING_WUNDEF()
@ -101,8 +102,8 @@ class Plot {
public:
virtual ~Plot() {}
// Deprecated. Use PrintPythonCode() or ExportProtobuf() instead.
RTC_DEPRECATED virtual void Draw() {}
ABSL_DEPRECATED("Use PrintPythonCode() or ExportProtobuf() instead.")
virtual void Draw() {}
// Sets the lower x-axis limit to min_value (if left_margin == 0).
// Sets the upper x-axis limit to max_value (if right_margin == 0).
@ -189,11 +190,15 @@ class PlotCollection {
public:
virtual ~PlotCollection() {}
// Deprecated. Use PrintPythonCode() or ExportProtobuf() instead.
RTC_DEPRECATED virtual void Draw() {}
ABSL_DEPRECATED("Use PrintPythonCode() or ExportProtobuf() instead.")
virtual void Draw() {}
virtual Plot* AppendNewPlot();
void SetCallTimeToUtcOffsetMs(int64_t calltime_to_utc_ms) {
calltime_to_utc_ms_ = calltime_to_utc_ms;
}
// Replaces PythonPlotCollection::Draw()
void PrintPythonCode(bool shared_xaxis) const;
@ -202,6 +207,7 @@ class PlotCollection {
protected:
std::vector<std::unique_ptr<Plot>> plots_;
absl::optional<int64_t> calltime_to_utc_ms_;
};
} // namespace webrtc

View File

@ -10,6 +10,7 @@
#ifndef RTC_TOOLS_RTC_EVENT_LOG_VISUALIZER_PLOT_PROTOBUF_H_
#define RTC_TOOLS_RTC_EVENT_LOG_VISUALIZER_PLOT_PROTOBUF_H_
#include "absl/base/attributes.h"
#include "rtc_base/ignore_wundef.h"
RTC_PUSH_IGNORING_WUNDEF()
#include "rtc_tools/rtc_event_log_visualizer/proto/chart.pb.h"
@ -25,10 +26,10 @@ class ProtobufPlot final : public Plot {
void Draw() override;
};
class ProtobufPlotCollection final : public PlotCollection {
class ABSL_DEPRECATED("Use PlotCollection and ExportProtobuf() instead")
ProtobufPlotCollection final : public PlotCollection {
public:
// This class is deprecated. Use PlotCollection and ExportProtobuf() instead.
RTC_DEPRECATED ProtobufPlotCollection();
ProtobufPlotCollection();
~ProtobufPlotCollection() override;
void Draw() override;
Plot* AppendNewPlot() override;

View File

@ -10,6 +10,7 @@
#ifndef RTC_TOOLS_RTC_EVENT_LOG_VISUALIZER_PLOT_PYTHON_H_
#define RTC_TOOLS_RTC_EVENT_LOG_VISUALIZER_PLOT_PYTHON_H_
#include "absl/base/attributes.h"
#include "rtc_tools/rtc_event_log_visualizer/plot_base.h"
namespace webrtc {
@ -21,10 +22,10 @@ class PythonPlot final : public Plot {
void Draw() override;
};
class PythonPlotCollection final : public PlotCollection {
class ABSL_DEPRECATED("Use PlotCollection and PrintPythonCode() instead.")
PythonPlotCollection final : public PlotCollection {
public:
// This class is deprecated. Use PlotCollection and PrintPythonCode() instead.
RTC_DEPRECATED explicit PythonPlotCollection(bool shared_xaxis = false);
explicit PythonPlotCollection(bool shared_xaxis = false);
~PythonPlotCollection() override;
void Draw() override;
Plot* AppendNewPlot() override;

View File

@ -33,4 +33,8 @@ message Chart {
message ChartCollection {
repeated Chart charts = 1;
// `calltime_to_utc_ms` is the UTC time (in ms) for the x-axis in the charts.
// In other words, time t ms in the charts corresponds to
// t+calltime_to_utc_ms ms in UTC time.
int64 calltime_to_utc_ms = 2;
}