Reland "Reland "Refactor AnalyzerConfig to use Timestamps instead of microseconds.""
This reverts commit 7306c75c12e6dd70e1f1a0904b6bda347423a556.
Reason for revert: Downstream updated
Original change's description:
> Revert "Reland "Refactor AnalyzerConfig to use Timestamps instead of microseconds.""
>
> This reverts commit 7a992e21b9c3ff03aa34488a9c91fa580ca4faa6.
>
> Reason for revert: Breaks downstream build due to type change.
>
> Original change's description:
> > Reland "Refactor AnalyzerConfig to use Timestamps instead of microseconds."
> >
> > This is a reland of 43fb16921b29ecd3a2d87876dda75c575e05f66a
> >
> > Original change's description:
> > > Refactor AnalyzerConfig to use Timestamps instead of microseconds.
> > >
> > > Add optional offset-to-UTC parameter to output. This allows aligning
> > > the x-axis in the generated charts to other UTC-based logs.
> > >
> > > Bug: b/215140373
> > > Change-Id: I65bcd295718acbb8c94e363907c1abc458067bfd
> > > Reviewed-on: https://webrtc-review.googlesource.com/c/src/+/250203
> > > Reviewed-by: Kristoffer Erlandsson <kerl@google.com>
> > > Commit-Queue: Björn Terelius <terelius@webrtc.org>
> > > Cr-Commit-Position: refs/heads/main@{#35992}
> >
> > Bug: b/215140373
> > Change-Id: Id2b88cc4b8078a97275d49a617581cbbd02d2c6f
> > Reviewed-on: https://webrtc-review.googlesource.com/c/src/+/252380
> > Reviewed-by: Kristoffer Erlandsson <kerl@google.com>
> > Commit-Queue: Björn Terelius <terelius@webrtc.org>
> > Cr-Commit-Position: refs/heads/main@{#36066}
>
> Bug: b/215140373
> Change-Id: I951ac26b8176e58da18e93835f13f6b9deb6d4fa
> No-Presubmit: true
> No-Tree-Checks: true
> No-Try: true
> Reviewed-on: https://webrtc-review.googlesource.com/c/src/+/252443
> Auto-Submit: Björn Terelius <terelius@webrtc.org>
> Bot-Commit: rubber-stamper@appspot.gserviceaccount.com <rubber-stamper@appspot.gserviceaccount.com>
> Commit-Queue: Björn Terelius <terelius@webrtc.org>
> Cr-Commit-Position: refs/heads/main@{#36068}
Bug: b/215140373
Change-Id: Ie2b9a961d1e09dbeabeb6bfb02b43c047df69515
Reviewed-on: https://webrtc-review.googlesource.com/c/src/+/252582
Bot-Commit: rubber-stamper@appspot.gserviceaccount.com <rubber-stamper@appspot.gserviceaccount.com>
Commit-Queue: Björn Terelius <terelius@webrtc.org>
Reviewed-by: Kristoffer Erlandsson <kerl@google.com>
Cr-Commit-Position: refs/heads/main@{#36079}
diff --git a/rtc_tools/rtc_event_log_visualizer/alerts.cc b/rtc_tools/rtc_event_log_visualizer/alerts.cc
index 2d1868f..c0d8784 100644
--- a/rtc_tools/rtc_event_log_visualizer/alerts.cc
+++ b/rtc_tools/rtc_event_log_visualizer/alerts.cc
@@ -79,7 +79,7 @@
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;
@@ -89,7 +89,7 @@
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;
@@ -140,7 +140,8 @@
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);
}
@@ -155,7 +156,7 @@
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());
@@ -169,7 +170,7 @@
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());
@@ -189,7 +190,7 @@
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;
@@ -204,13 +205,14 @@
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.");
}
}
diff --git a/rtc_tools/rtc_event_log_visualizer/analyze_audio.cc b/rtc_tools/rtc_event_log_visualizer/analyze_audio.cc
index 69a753b..854c6d0 100644
--- a/rtc_tools/rtc_event_log_visualizer/analyze_audio.cc
+++ b/rtc_tools/rtc_event_log_visualizer/analyze_audio.cc
@@ -38,7 +38,7 @@
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 +63,7 @@
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 +88,7 @@
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 +114,7 @@
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 +139,7 @@
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 +164,7 @@
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,
@@ -397,23 +397,23 @@
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));
}
@@ -448,7 +448,7 @@
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));
}
diff --git a/rtc_tools/rtc_event_log_visualizer/analyzer.cc b/rtc_tools/rtc_event_log_visualizer/analyzer.cc
index b438016..4c71818 100644
--- a/rtc_tools/rtc_event_log_visualizer/analyzer.cc
+++ b/rtc_tools/rtc_event_log_visualizer/analyzer.cc
@@ -214,7 +214,7 @@
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 +346,24 @@
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 +371,9 @@
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 +417,7 @@
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);
@@ -469,7 +473,7 @@
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));
@@ -545,17 +549,15 @@
// 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)) {
@@ -563,13 +565,13 @@
}
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);
@@ -599,7 +601,7 @@
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);
@@ -626,7 +628,7 @@
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);
@@ -662,7 +664,7 @@
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,
@@ -691,8 +693,8 @@
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;
@@ -702,17 +704,17 @@
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 =
@@ -767,7 +769,7 @@
}
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,
@@ -803,7 +805,7 @@
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);
}
@@ -818,11 +820,11 @@
// 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();
@@ -832,7 +834,7 @@
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;
@@ -845,7 +847,8 @@
++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);
@@ -856,7 +859,7 @@
// 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);
}
@@ -884,11 +887,11 @@
bool show_detector_state,
bool show_alr_state) {
// 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();
@@ -898,7 +901,7 @@
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;
@@ -911,7 +914,8 @@
++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);
@@ -922,7 +926,7 @@
// 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);
}
@@ -935,12 +939,12 @@
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) {
@@ -967,12 +971,13 @@
}
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);
}
@@ -980,7 +985,7 @@
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);
}
@@ -988,17 +993,17 @@
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);
@@ -1031,7 +1036,7 @@
// 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);
}
@@ -1117,7 +1122,7 @@
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);
}
@@ -1149,22 +1154,20 @@
[&](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));
@@ -1324,7 +1327,7 @@
}
}
- float x = config_.GetCallTimeSec(clock.TimeInMicroseconds());
+ float x = config_.GetCallTimeSec(clock.CurrentTime());
float y = bitrate_bps.value_or(0) / 1000;
acked_time_series.points.emplace_back(x, y);
y = robust_throughput_estimator->bitrate()
@@ -1347,7 +1350,7 @@
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;
}
@@ -1423,13 +1426,13 @@
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 (remb_interceptor.GetAndResetBitrateUpdated() ||
clock.TimeInMicroseconds() - last_update_us >= 1e6) {
uint32_t y = remb_interceptor.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 = clock.TimeInMicroseconds();
}
@@ -1461,7 +1464,7 @@
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;
int64_t rtt_ms = packet.feedback_arrival_time_ms - packet.send_time_ms;
min_rtt_ms = std::min(rtt_ms, min_rtt_ms);
@@ -1530,7 +1533,7 @@
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);
}
@@ -1551,7 +1554,7 @@
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);
}
@@ -1566,7 +1569,7 @@
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);
}
@@ -1588,7 +1591,7 @@
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);
@@ -1610,7 +1613,7 @@
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);
@@ -1649,7 +1652,7 @@
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);
}
@@ -1706,7 +1709,7 @@
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);
}
@@ -1741,7 +1744,7 @@
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);
}
@@ -1763,7 +1766,7 @@
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);
}
diff --git a/rtc_tools/rtc_event_log_visualizer/analyzer_common.h b/rtc_tools/rtc_event_log_visualizer/analyzer_common.h
index a4305a7..b0b556a 100644
--- a/rtc_tools/rtc_event_log_visualizer/analyzer_common.h
+++ b/rtc_tools/rtc_event_log_visualizer/analyzer_common.h
@@ -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 @@
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_;
};
@@ -152,17 +166,17 @@
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 @@
++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);
diff --git a/rtc_tools/rtc_event_log_visualizer/main.cc b/rtc_tools/rtc_event_log_visualizer/main.cc
index ab4b7eb..6182b70 100644
--- a/rtc_tools/rtc_event_log_visualizer/main.cc
+++ b/rtc_tools/rtc_event_log_visualizer/main.cc
@@ -261,8 +261,12 @@
}
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();
@@ -275,6 +279,7 @@
webrtc::EventLogAnalyzer analyzer(parsed_log, config);
webrtc::PlotCollection collection;
+ collection.SetCallTimeToUtcOffsetMs(config.CallTimeToUtcOffsetMs());
PlotMap plots;
plots.RegisterPlot("incoming_packet_sizes", [&](Plot* plot) {
diff --git a/rtc_tools/rtc_event_log_visualizer/plot_base.cc b/rtc_tools/rtc_event_log_visualizer/plot_base.cc
index 82533e6..bf76a67 100644
--- a/rtc_tools/rtc_event_log_visualizer/plot_base.cc
+++ b/rtc_tools/rtc_event_log_visualizer/plot_base.cc
@@ -307,13 +307,13 @@
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() {
diff --git a/rtc_tools/rtc_event_log_visualizer/plot_base.h b/rtc_tools/rtc_event_log_visualizer/plot_base.h
index a26146b..dbc9535 100644
--- a/rtc_tools/rtc_event_log_visualizer/plot_base.h
+++ b/rtc_tools/rtc_event_log_visualizer/plot_base.h
@@ -16,6 +16,7 @@
#include <vector>
#include "absl/base/attributes.h"
+#include "absl/types/optional.h"
#include "rtc_base/ignore_wundef.h"
RTC_PUSH_IGNORING_WUNDEF()
@@ -194,6 +195,10 @@
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 @@
protected:
std::vector<std::unique_ptr<Plot>> plots_;
+ absl::optional<int64_t> calltime_to_utc_ms_;
};
} // namespace webrtc
diff --git a/rtc_tools/rtc_event_log_visualizer/proto/chart.proto b/rtc_tools/rtc_event_log_visualizer/proto/chart.proto
index e5960b2..f82d9c1 100644
--- a/rtc_tools/rtc_event_log_visualizer/proto/chart.proto
+++ b/rtc_tools/rtc_event_log_visualizer/proto/chart.proto
@@ -33,4 +33,8 @@
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;
}