mollyim/webrtc
1
0
Fork 0
mirror of https://github.com/mollyim/webrtc.git synced 2025-05-13 05:40:42 +01:00
Code Issues Projects Releases Packages Wiki Activity Actions

Revert "Refactor AnalyzerConfig to use Timestamps instead of microseconds."

Browse source 
This reverts commit 43fb16921b.

Reason for revert: New type breaks downstream projects.

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}

TBR=terelius@webrtc.org,kerl@google.com,webrtc-scoped@luci-project-accounts.iam.gserviceaccount.com

Change-Id: If4f2330b9731f26a0e55c9ce9a500322a111b783
No-Presubmit: true
No-Tree-Checks: true
No-Try: true
Bug: b/215140373
Reviewed-on: https://webrtc-review.googlesource.com/c/src/+/251691
Bot-Commit: rubber-stamper@appspot.gserviceaccount.com <rubber-stamper@appspot.gserviceaccount.com>
Reviewed-by: Evan Shrubsole <eshr@webrtc.org>
Reviewed-by: Harald Alvestrand <hta@webrtc.org>
Commit-Queue: Christoffer Jansson <jansson@google.com>
Cr-Commit-Position: refs/heads/main@{#35994}
This commit is contained in:
Christoffer Jansson 2022-02-14 14:56:38 +00:00 committed by WebRTC LUCI CQ
parent e7b4c137cc
commit 66bfd6f57d
36 changed files with 129 additions and 203 deletions
Show stats Download patch file Download diff file Expand all files Collapse all files

16
logging/rtc_event_log/events/logged_rtp_rtcp.h
View file

@ -41,7 +41,6 @@ struct LoggedRtpPacket {
int64_t log_time_us() const { return timestamp.us(); }
int64_t log_time_ms() const { return timestamp.ms(); }
Timestamp log_time() const { return timestamp; }
Timestamp timestamp;
// TODO(terelius): This allocates space for 15 CSRCs even if none are used.
@ -58,7 +57,6 @@ struct LoggedRtpPacketIncoming {
: rtp(timestamp, header, header_length, total_length) {}
int64_t log_time_us() const { return rtp.timestamp.us(); }
int64_t log_time_ms() const { return rtp.timestamp.ms(); }
Timestamp log_time() const { return rtp.timestamp; }
LoggedRtpPacket rtp;
};
@ -71,7 +69,6 @@ struct LoggedRtpPacketOutgoing {
: rtp(timestamp, header, header_length, total_length) {}
int64_t log_time_us() const { return rtp.timestamp.us(); }
int64_t log_time_ms() const { return rtp.timestamp.ms(); }
Timestamp log_time() const { return rtp.timestamp; }
LoggedRtpPacket rtp;
};
@ -90,7 +87,6 @@ struct LoggedRtcpPacket {
int64_t log_time_us() const { return timestamp.us(); }
int64_t log_time_ms() const { return timestamp.ms(); }
Timestamp log_time() const { return timestamp; }
Timestamp timestamp;
std::vector<uint8_t> raw_data;
@ -105,7 +101,6 @@ struct LoggedRtcpPacketIncoming {
int64_t log_time_us() const { return rtcp.timestamp.us(); }
int64_t log_time_ms() const { return rtcp.timestamp.ms(); }
Timestamp log_time() const { return rtcp.timestamp; }
LoggedRtcpPacket rtcp;
};
@ -119,7 +114,6 @@ struct LoggedRtcpPacketOutgoing {
int64_t log_time_us() const { return rtcp.timestamp.us(); }
int64_t log_time_ms() const { return rtcp.timestamp.ms(); }
Timestamp log_time() const { return rtcp.timestamp; }
LoggedRtcpPacket rtcp;
};
@ -132,7 +126,6 @@ struct LoggedRtcpPacketReceiverReport {
int64_t log_time_us() const { return timestamp.us(); }
int64_t log_time_ms() const { return timestamp.ms(); }
Timestamp log_time() const { return timestamp; }
Timestamp timestamp = Timestamp::MinusInfinity();
rtcp::ReceiverReport rr;
@ -146,7 +139,6 @@ struct LoggedRtcpPacketSenderReport {
int64_t log_time_us() const { return timestamp.us(); }
int64_t log_time_ms() const { return timestamp.ms(); }
Timestamp log_time() const { return timestamp; }
Timestamp timestamp = Timestamp::MinusInfinity();
rtcp::SenderReport sr;
@ -157,7 +149,6 @@ struct LoggedRtcpPacketExtendedReports {
int64_t log_time_us() const { return timestamp.us(); }
int64_t log_time_ms() const { return timestamp.ms(); }
Timestamp log_time() const { return timestamp; }
Timestamp timestamp = Timestamp::MinusInfinity();
rtcp::ExtendedReports xr;
@ -170,7 +161,6 @@ struct LoggedRtcpPacketRemb {
int64_t log_time_us() const { return timestamp.us(); }
int64_t log_time_ms() const { return timestamp.ms(); }
Timestamp log_time() const { return timestamp; }
Timestamp timestamp = Timestamp::MinusInfinity();
rtcp::Remb remb;
@ -183,7 +173,6 @@ struct LoggedRtcpPacketNack {
int64_t log_time_us() const { return timestamp.us(); }
int64_t log_time_ms() const { return timestamp.ms(); }
Timestamp log_time() const { return timestamp; }
Timestamp timestamp = Timestamp::MinusInfinity();
rtcp::Nack nack;
@ -194,7 +183,6 @@ struct LoggedRtcpPacketFir {
int64_t log_time_us() const { return timestamp.us(); }
int64_t log_time_ms() const { return timestamp.ms(); }
Timestamp log_time() const { return timestamp; }
Timestamp timestamp = Timestamp::MinusInfinity();
rtcp::Fir fir;
@ -205,7 +193,6 @@ struct LoggedRtcpPacketPli {
int64_t log_time_us() const { return timestamp.us(); }
int64_t log_time_ms() const { return timestamp.ms(); }
Timestamp log_time() const { return timestamp; }
Timestamp timestamp = Timestamp::MinusInfinity();
rtcp::Pli pli;
@ -222,7 +209,6 @@ struct LoggedRtcpPacketTransportFeedback {
int64_t log_time_us() const { return timestamp.us(); }
int64_t log_time_ms() const { return timestamp.ms(); }
Timestamp log_time() const { return timestamp; }
Timestamp timestamp = Timestamp::MinusInfinity();
rtcp::TransportFeedback transport_feedback;
@ -237,7 +223,6 @@ struct LoggedRtcpPacketLossNotification {
int64_t log_time_us() const { return timestamp.us(); }
int64_t log_time_ms() const { return timestamp.ms(); }
Timestamp log_time() const { return timestamp; }
Timestamp timestamp = Timestamp::MinusInfinity();
rtcp::LossNotification loss_notification;
@ -248,7 +233,6 @@ struct LoggedRtcpPacketBye {
int64_t log_time_us() const { return timestamp.us(); }
int64_t log_time_ms() const { return timestamp.ms(); }
Timestamp log_time() const { return timestamp; }
Timestamp timestamp = Timestamp::MinusInfinity();
rtcp::Bye bye;

1
logging/rtc_event_log/events/rtc_event_alr_state.h
View file

@ -32,7 +32,6 @@ struct LoggedAlrStateEvent {
int64_t log_time_us() const { return timestamp.us(); }
int64_t log_time_ms() const { return timestamp.ms(); }
Timestamp log_time() const { return timestamp; }
Timestamp timestamp = Timestamp::MinusInfinity();
bool in_alr;

1
logging/rtc_event_log/events/rtc_event_audio_network_adaptation.h
View file

@ -31,7 +31,6 @@ struct LoggedAudioNetworkAdaptationEvent {
int64_t log_time_us() const { return timestamp.us(); }
int64_t log_time_ms() const { return timestamp.ms(); }
Timestamp log_time() const { return timestamp; }
Timestamp timestamp = Timestamp::MinusInfinity();
AudioEncoderRuntimeConfig config;

1
logging/rtc_event_log/events/rtc_event_audio_playout.h
View file

@ -32,7 +32,6 @@ struct LoggedAudioPlayoutEvent {
int64_t log_time_us() const { return timestamp.us(); }
int64_t log_time_ms() const { return timestamp.ms(); }
Timestamp log_time() const { return timestamp; }
Timestamp timestamp = Timestamp::MinusInfinity();
uint32_t ssrc;

1
logging/rtc_event_log/events/rtc_event_audio_receive_stream_config.h
View file

@ -30,7 +30,6 @@ struct LoggedAudioRecvConfig {
int64_t log_time_us() const { return timestamp.us(); }
int64_t log_time_ms() const { return timestamp.ms(); }
Timestamp log_time() const { return timestamp; }
Timestamp timestamp = Timestamp::MinusInfinity();
rtclog::StreamConfig config;

1
logging/rtc_event_log/events/rtc_event_audio_send_stream_config.h
View file

@ -29,7 +29,6 @@ struct LoggedAudioSendConfig {
int64_t log_time_us() const { return timestamp.us(); }
int64_t log_time_ms() const { return timestamp.ms(); }
Timestamp log_time() const { return timestamp; }
Timestamp timestamp = Timestamp::MinusInfinity();
rtclog::StreamConfig config;

1
logging/rtc_event_log/events/rtc_event_begin_log.h
View file

@ -35,7 +35,6 @@ struct LoggedStartEvent {
int64_t log_time_us() const { return timestamp.us(); }
int64_t log_time_ms() const { return timestamp.ms(); }
Timestamp log_time() const { return timestamp; }
Timestamp utc_time() const { return utc_start_time; }

1
logging/rtc_event_log/events/rtc_event_bwe_update_delay_based.h
View file

@ -76,7 +76,6 @@ struct LoggedBweDelayBasedUpdate {
int64_t log_time_us() const { return timestamp.us(); }
int64_t log_time_ms() const { return timestamp.ms(); }
Timestamp log_time() const { return timestamp; }
Timestamp timestamp = Timestamp::MinusInfinity();
int32_t bitrate_bps;

1
logging/rtc_event_log/events/rtc_event_bwe_update_loss_based.h
View file

@ -37,7 +37,6 @@ struct LoggedBweLossBasedUpdate {
int64_t log_time_us() const { return timestamp.us(); }
int64_t log_time_ms() const { return timestamp.ms(); }
Timestamp log_time() const { return timestamp; }
Timestamp timestamp = Timestamp::MinusInfinity();
int32_t bitrate_bps;

1
logging/rtc_event_log/events/rtc_event_dtls_transport_state.h
View file

@ -26,7 +26,6 @@ namespace webrtc {
struct LoggedDtlsTransportState {
int64_t log_time_us() const { return timestamp.us(); }
int64_t log_time_ms() const { return timestamp.ms(); }
Timestamp log_time() const { return timestamp; }
Timestamp timestamp = Timestamp::MinusInfinity();
DtlsTransportState dtls_transport_state;

1
logging/rtc_event_log/events/rtc_event_dtls_writable_state.h
View file

@ -28,7 +28,6 @@ struct LoggedDtlsWritableState {
int64_t log_time_us() const { return timestamp.us(); }
int64_t log_time_ms() const { return timestamp.ms(); }
Timestamp log_time() const { return timestamp; }
Timestamp timestamp = Timestamp::MinusInfinity();
bool writable;

1
logging/rtc_event_log/events/rtc_event_end_log.h
View file

@ -32,7 +32,6 @@ struct LoggedStopEvent {
int64_t log_time_us() const { return timestamp.us(); }
int64_t log_time_ms() const { return timestamp.ms(); }
Timestamp log_time() const { return timestamp; }
Timestamp timestamp = Timestamp::PlusInfinity();
};

1
logging/rtc_event_log/events/rtc_event_frame_decoded.h
View file

@ -29,7 +29,6 @@ namespace webrtc {
struct LoggedFrameDecoded {
int64_t log_time_us() const { return timestamp.us(); }
int64_t log_time_ms() const { return timestamp.ms(); }
Timestamp log_time() const { return timestamp; }
Timestamp timestamp = Timestamp::MinusInfinity();
int64_t render_time_ms;

1
logging/rtc_event_log/events/rtc_event_generic_ack_received.h
View file

@ -36,7 +36,6 @@ struct LoggedGenericAckReceived {
int64_t log_time_us() const { return timestamp.us(); }
int64_t log_time_ms() const { return timestamp.ms(); }
Timestamp log_time() const { return timestamp; }
Timestamp timestamp = Timestamp::MinusInfinity();
int64_t packet_number;

1
logging/rtc_event_log/events/rtc_event_generic_packet_received.h
View file

@ -33,7 +33,6 @@ struct LoggedGenericPacketReceived {
int64_t log_time_us() const { return timestamp.us(); }
int64_t log_time_ms() const { return timestamp.ms(); }
Timestamp log_time() const { return timestamp; }
Timestamp timestamp = Timestamp::MinusInfinity();
int64_t packet_number;

1
logging/rtc_event_log/events/rtc_event_generic_packet_sent.h
View file

@ -37,7 +37,6 @@ struct LoggedGenericPacketSent {
int64_t log_time_us() const { return timestamp.us(); }
int64_t log_time_ms() const { return timestamp.ms(); }
Timestamp log_time() const { return timestamp; }
size_t packet_length() const {
return payload_length + padding_length + overhead_length;

1
logging/rtc_event_log/events/rtc_event_ice_candidate_pair.h
View file

@ -45,7 +45,6 @@ struct LoggedIceCandidatePairEvent {
int64_t log_time_us() const { return timestamp.us(); }
int64_t log_time_ms() const { return timestamp.ms(); }
Timestamp log_time() const { return timestamp; }
Timestamp timestamp = Timestamp::MinusInfinity();
IceCandidatePairEventType type;

1
logging/rtc_event_log/events/rtc_event_ice_candidate_pair_config.h
View file

@ -72,7 +72,6 @@ enum class IceCandidateNetworkType {
struct LoggedIceCandidatePairConfig {
int64_t log_time_us() const { return timestamp.us(); }
int64_t log_time_ms() const { return timestamp.ms(); }
Timestamp log_time() const { return timestamp; }
Timestamp timestamp = Timestamp::MinusInfinity();
IceCandidatePairConfigType type;

1
logging/rtc_event_log/events/rtc_event_probe_cluster_created.h
View file

@ -39,7 +39,6 @@ struct LoggedBweProbeClusterCreatedEvent {
int64_t log_time_us() const { return timestamp.us(); }
int64_t log_time_ms() const { return timestamp.ms(); }
Timestamp log_time() const { return timestamp; }
Timestamp timestamp = Timestamp::MinusInfinity();
int32_t id;

1
logging/rtc_event_log/events/rtc_event_probe_result_failure.h
View file

@ -40,7 +40,6 @@ struct LoggedBweProbeFailureEvent {
int64_t log_time_us() const { return timestamp.us(); }
int64_t log_time_ms() const { return timestamp.ms(); }
Timestamp log_time() const { return timestamp; }
Timestamp timestamp = Timestamp::MinusInfinity();
int32_t id;

1
logging/rtc_event_log/events/rtc_event_probe_result_success.h
View file

@ -33,7 +33,6 @@ struct LoggedBweProbeSuccessEvent {
int64_t log_time_us() const { return timestamp.us(); }
int64_t log_time_ms() const { return timestamp.ms(); }
Timestamp log_time() const { return timestamp; }
Timestamp timestamp = Timestamp::MinusInfinity();
int32_t id;

1
logging/rtc_event_log/events/rtc_event_remote_estimate.h
View file

@ -28,7 +28,6 @@ struct LoggedRemoteEstimateEvent {
int64_t log_time_us() const { return timestamp.us(); }
int64_t log_time_ms() const { return timestamp.ms(); }
Timestamp log_time() const { return timestamp; }
Timestamp timestamp = Timestamp::MinusInfinity();
absl::optional<DataRate> link_capacity_lower;

1
logging/rtc_event_log/events/rtc_event_route_change.h
View file

@ -29,7 +29,6 @@ struct LoggedRouteChangeEvent {
int64_t log_time_us() const { return timestamp.us(); }
int64_t log_time_ms() const { return timestamp.ms(); }
Timestamp log_time() const { return timestamp; }
Timestamp timestamp = Timestamp::MinusInfinity();
bool connected;

1
logging/rtc_event_log/events/rtc_event_video_receive_stream_config.h
View file

@ -30,7 +30,6 @@ struct LoggedVideoRecvConfig {
int64_t log_time_us() const { return timestamp.us(); }
int64_t log_time_ms() const { return timestamp.ms(); }
Timestamp log_time() const { return timestamp; }
Timestamp timestamp = Timestamp::MinusInfinity();
rtclog::StreamConfig config;

1
logging/rtc_event_log/events/rtc_event_video_send_stream_config.h
View file

@ -30,7 +30,6 @@ struct LoggedVideoSendConfig {
int64_t log_time_us() const { return timestamp.us(); }
int64_t log_time_ms() const { return timestamp.ms(); }
Timestamp log_time() const { return timestamp; }
Timestamp timestamp = Timestamp::MinusInfinity();
rtclog::StreamConfig config;

24
logging/rtc_event_log/rtc_event_log_parser.cc
View file

@ -1110,8 +1110,8 @@ void ParsedRtcEventLog::Clear() {
last_incoming_rtcp_packet_.clear();
first_timestamp_ = Timestamp::PlusInfinity();
last_timestamp_ = Timestamp::MinusInfinity();
first_timestamp_ = std::numeric_limits<int64_t>::max();
last_timestamp_ = std::numeric_limits<int64_t>::min();
first_log_segment_ = LogSegment(0, std::numeric_limits<int64_t>::max());
incoming_rtp_extensions_maps_.clear();
@ -1232,8 +1232,8 @@ ParsedRtcEventLog::ParseStatus ParsedRtcEventLog::ParseStream(
// stream configurations and starting/stopping the log.
// TODO(terelius): Figure out if we actually need to find the first and last
// timestamp in the parser. It seems like this could be done by the caller.
first_timestamp_ = Timestamp::PlusInfinity();
last_timestamp_ = Timestamp::MinusInfinity();
first_timestamp_ = std::numeric_limits<int64_t>::max();
last_timestamp_ = std::numeric_limits<int64_t>::min();
StoreFirstAndLastTimestamp(alr_state_events());
StoreFirstAndLastTimestamp(route_change_events());
for (const auto& audio_stream : audio_playout_events()) {
@ -1272,8 +1272,7 @@ ParsedRtcEventLog::ParseStatus ParsedRtcEventLog::ParseStream(
// event, we could use the timestamp of the the last previous regular event.
auto start_iter = start_log_events().begin();
auto stop_iter = stop_log_events().begin();
int64_t start_us =
first_timestamp().us_or(std::numeric_limits<int64_t>::max());
int64_t start_us = first_timestamp();
int64_t next_start_us = std::numeric_limits<int64_t>::max();
int64_t stop_us = std::numeric_limits<int64_t>::max();
if (start_iter != start_log_events().end()) {
@ -1287,14 +1286,15 @@ ParsedRtcEventLog::ParseStatus ParsedRtcEventLog::ParseStream(
}
stop_us = std::min(stop_us, next_start_us);
if (stop_us == std::numeric_limits<int64_t>::max() &&
!last_timestamp().IsMinusInfinity()) {
stop_us = last_timestamp().us();
last_timestamp() != std::numeric_limits<int64_t>::min()) {
stop_us = last_timestamp();
}
RTC_PARSE_CHECK_OR_RETURN_LE(start_us, stop_us);
first_log_segment_ = LogSegment(start_us, stop_us);
if (first_timestamp_ > last_timestamp_) {
first_timestamp_ = last_timestamp_ = Timestamp::Zero();
if (first_timestamp_ == std::numeric_limits<int64_t>::max() &&
last_timestamp_ == std::numeric_limits<int64_t>::min()) {
first_timestamp_ = last_timestamp_ = 0;
}
return status;
@ -1563,8 +1563,8 @@ template <typename T>
void ParsedRtcEventLog::StoreFirstAndLastTimestamp(const std::vector<T>& v) {
if (v.empty())
return;
first_timestamp_ = std::min(first_timestamp_, v.front().log_time());
last_timestamp_ = std::max(last_timestamp_, v.back().log_time());
first_timestamp_ = std::min(first_timestamp_, v.front().log_time_us());
last_timestamp_ = std::max(last_timestamp_, v.back().log_time_us());
}
ParsedRtcEventLog::ParseStatus ParsedRtcEventLog::StoreParsedLegacyEvent(

8
logging/rtc_event_log/rtc_event_log_parser.h
View file

@ -643,8 +643,8 @@ class ParsedRtcEventLog {
return decoded_frames_;
}
Timestamp first_timestamp() const { return first_timestamp_; }
Timestamp last_timestamp() const { return last_timestamp_; }
int64_t first_timestamp() const { return first_timestamp_; }
int64_t last_timestamp() const { return last_timestamp_; }
const LogSegment& first_log_segment() const { return first_log_segment_; }
@ -889,8 +889,8 @@ class ParsedRtcEventLog {
std::vector<uint8_t> last_incoming_rtcp_packet_;
Timestamp first_timestamp_ = Timestamp::PlusInfinity();
Timestamp last_timestamp_ = Timestamp::MinusInfinity();
int64_t first_timestamp_;
int64_t last_timestamp_;
LogSegment first_log_segment_ =
LogSegment(0, std::numeric_limits<int64_t>::max());

4
logging/rtc_event_log/rtc_event_log_unittest.cc
View file

@ -785,8 +785,8 @@ void RtcEventLogSession::ReadAndVerifyLog() {
parsed_generic_acks_received[i]);
}
EXPECT_EQ(first_timestamp_ms_, parsed_log.first_timestamp().ms());
EXPECT_EQ(last_timestamp_ms_, parsed_log.last_timestamp().ms());
EXPECT_EQ(first_timestamp_ms_, parsed_log.first_timestamp() / 1000);
EXPECT_EQ(last_timestamp_ms_, parsed_log.last_timestamp() / 1000);
EXPECT_EQ(parsed_log.first_log_segment().start_time_ms(),
std::min(start_time_us_ / 1000, first_timestamp_ms_));

18
rtc_tools/rtc_event_log_visualizer/alerts.cc
View file

@ -79,7 +79,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()),
Alert(seq_num_alert, config_.GetCallTimeSec(packet.log_time_us()),
seq_num_explanation);
}
last_seq_num = seq_num;
@ -89,7 +89,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()),
Alert(capture_time_alert, config_.GetCallTimeSec(packet.log_time_us()),
capture_time_explanation);
}
last_capture_time = capture_time;
@ -140,8 +140,7 @@ 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::Micros(timestamp)),
rtp_explanation);
Alert(rtp_alert, config_.GetCallTimeSec(timestamp), rtp_explanation);
}
last_rtp_time.emplace(timestamp);
}
@ -156,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()),
Alert(rtcp_alert, config_.GetCallTimeSec(rtcp.log_time_us()),
rtcp_explanation);
}
last_rtcp_time.emplace(rtcp.log_time_us());
@ -170,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()),
Alert(rtcp_alert, config_.GetCallTimeSec(rtcp.log_time_us()),
rtcp_explanation);
}
last_rtcp_time.emplace(rtcp.log_time_us());
@ -190,7 +189,7 @@ void TriageHelper::AnalyzeLog(const ParsedRtcEventLog& parsed_log) {
const int64_t segment_end_us = parsed_log.first_log_segment().stop_time_us();
Timestamp first_occurrence = parsed_log.last_timestamp();
int64_t first_occurrence = parsed_log.last_timestamp();
constexpr double kMaxLossFraction = 0.05;
// Loss feedback
int64_t total_lost_packets = 0;
@ -205,14 +204,13 @@ 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());
first_occurrence = std::min(first_occurrence, bwe_update.log_time_us());
}
}
double avg_outgoing_loss =
static_cast<double>(total_lost_packets) / total_expected_packets;
if (avg_outgoing_loss > kMaxLossFraction) {
Alert(TriageAlertType::kOutgoingHighLoss,
config_.GetCallTimeSec(first_occurrence),
Alert(TriageAlertType::kOutgoingHighLoss, first_occurrence,
"More than 5% of outgoing packets lost.");
}
}

22
rtc_tools/rtc_event_log_visualizer/analyze_audio.cc
View file

@ -38,7 +38,7 @@ void CreateAudioEncoderTargetBitrateGraph(const ParsedRtcEventLog& parsed_log,
return absl::nullopt;
};
auto ToCallTime = [config](const LoggedAudioNetworkAdaptationEvent& packet) {
return config.GetCallTimeSec(packet.log_time());
return config.GetCallTimeSec(packet.log_time_us());
};
ProcessPoints<LoggedAudioNetworkAdaptationEvent>(
ToCallTime, GetAnaBitrateBps,
@ -63,7 +63,7 @@ void CreateAudioEncoderFrameLengthGraph(const ParsedRtcEventLog& parsed_log,
return absl::optional<float>();
};
auto ToCallTime = [config](const LoggedAudioNetworkAdaptationEvent& packet) {
return config.GetCallTimeSec(packet.log_time());
return config.GetCallTimeSec(packet.log_time_us());
};
ProcessPoints<LoggedAudioNetworkAdaptationEvent>(
ToCallTime, GetAnaFrameLengthMs,
@ -88,7 +88,7 @@ void CreateAudioEncoderPacketLossGraph(const ParsedRtcEventLog& parsed_log,
return absl::optional<float>();
};
auto ToCallTime = [config](const LoggedAudioNetworkAdaptationEvent& packet) {
return config.GetCallTimeSec(packet.log_time());
return config.GetCallTimeSec(packet.log_time_us());
};
ProcessPoints<LoggedAudioNetworkAdaptationEvent>(
ToCallTime, GetAnaPacketLoss,
@ -114,7 +114,7 @@ void CreateAudioEncoderEnableFecGraph(const ParsedRtcEventLog& parsed_log,
return absl::optional<float>();
};
auto ToCallTime = [config](const LoggedAudioNetworkAdaptationEvent& packet) {
return config.GetCallTimeSec(packet.log_time());
return config.GetCallTimeSec(packet.log_time_us());
};
ProcessPoints<LoggedAudioNetworkAdaptationEvent>(
ToCallTime, GetAnaFecEnabled,
@ -139,7 +139,7 @@ void CreateAudioEncoderEnableDtxGraph(const ParsedRtcEventLog& parsed_log,
return absl::optional<float>();
};
auto ToCallTime = [config](const LoggedAudioNetworkAdaptationEvent& packet) {
return config.GetCallTimeSec(packet.log_time());
return config.GetCallTimeSec(packet.log_time_us());
};
ProcessPoints<LoggedAudioNetworkAdaptationEvent>(
ToCallTime, GetAnaDtxEnabled,
@ -164,7 +164,7 @@ void CreateAudioEncoderNumChannelsGraph(const ParsedRtcEventLog& parsed_log,
return absl::optional<float>();
};
auto ToCallTime = [config](const LoggedAudioNetworkAdaptationEvent& packet) {
return config.GetCallTimeSec(packet.log_time());
return config.GetCallTimeSec(packet.log_time_us());
};
ProcessPoints<LoggedAudioNetworkAdaptationEvent>(
ToCallTime, GetAnaNumChannels,
@ -397,23 +397,23 @@ void CreateAudioJitterBufferGraph(const ParsedRtcEventLog& parsed_log,
PointStyle::kHighlight);
for (const auto& data : arrival_delay_ms) {
const float x = config.GetCallTimeSec(Timestamp::Millis(data.first));
const float x = config.GetCallTimeSec(data.first * 1000); // ms to us.
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(Timestamp::Millis(data.first));
const float x = config.GetCallTimeSec(data.first * 1000); // ms to us.
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(Timestamp::Millis(data.first));
const float x = config.GetCallTimeSec(data.first * 1000); // ms to us.
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(Timestamp::Millis(data.first));
const float x = config.GetCallTimeSec(data.first * 1000); // ms to us.
const float y = data.second;
time_series_target_time.points.emplace_back(TimeSeriesPoint(x, y));
}
@ -448,7 +448,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(Timestamp::Millis(data.first));
const float time = config.GetCallTimeSec(data.first * 1000); // ms to us.
const float value = stats_extractor(data.second);
time_series[ssrc].points.emplace_back(TimeSeriesPoint(time, value));
}

145
rtc_tools/rtc_event_log_visualizer/analyzer.cc
View file

@ -214,7 +214,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.timestamp);
float x = config.GetCallTimeSec(rtcp.log_time_us());
float y = category_id;
time_series.points.emplace_back(x, y);
}
@ -346,24 +346,20 @@ std::string GetDirectionAsShortString(PacketDirection direction) {
EventLogAnalyzer::EventLogAnalyzer(const ParsedRtcEventLog& log,
bool normalize_time)
: parsed_log_(log) {
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_.window_duration_ = 250000;
config_.step_ = 10000;
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_ = Timestamp::Zero();
config_.begin_time_ = config_.end_time_ = 0;
}
RTC_LOG(LS_INFO) << "Log is "
<< (parsed_log_.last_timestamp().ms() -
parsed_log_.first_timestamp().ms()) /
1000
<< (parsed_log_.last_timestamp() -
parsed_log_.first_timestamp()) /
1000000
<< " seconds long.";
}
@ -371,9 +367,9 @@ EventLogAnalyzer::EventLogAnalyzer(const ParsedRtcEventLog& log,
const AnalyzerConfig& config)
: parsed_log_(log), config_(config) {
RTC_LOG(LS_INFO) << "Log is "
<< (parsed_log_.last_timestamp().ms() -
parsed_log_.first_timestamp().ms()) /
1000
<< (parsed_log_.last_timestamp() -
parsed_log_.first_timestamp()) /
1000000
<< " seconds long.";
}
@ -417,7 +413,7 @@ void EventLogAnalyzer::CreatePacketGraph(PacketDirection direction,
return absl::optional<float>(packet.total_length);
};
auto ToCallTime = [this](const LoggedRtpPacket& packet) {
return this->config_.GetCallTimeSec(packet.timestamp);
return this->config_.GetCallTimeSec(packet.log_time_us());
};
ProcessPoints<LoggedRtpPacket>(ToCallTime, GetPacketSize,
stream.packet_view, &time_series);
@ -473,7 +469,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());
float x = config_.GetCallTimeSec(packets[i].log_time_us());
time_series.points.emplace_back(x, i + 1);
}
plot->AppendTimeSeries(std::move(time_series));
@ -549,15 +545,17 @@ void EventLogAnalyzer::CreateTotalPacketRateGraph(PacketDirection direction,
// types using MovingAverage().
class LogTime {
public:
explicit LogTime(Timestamp log_time) : log_time_(log_time) {}
Timestamp log_time() const { return log_time_; }
explicit LogTime(int64_t log_time_us) : log_time_us_(log_time_us) {}
int64_t log_time_us() const { return log_time_us_; }
private:
Timestamp log_time_;
int64_t log_time_us_;
};
std::vector<LogTime> packet_times;
auto handle_rtp = [&](const LoggedRtpPacket& packet) {
packet_times.emplace_back(packet.log_time());
packet_times.emplace_back(packet.log_time_us());
};
RtcEventProcessor process;
for (const auto& stream : parsed_log_.rtp_packets_by_ssrc(direction)) {
@ -565,13 +563,13 @@ void EventLogAnalyzer::CreateTotalPacketRateGraph(PacketDirection direction,
}
if (direction == kIncomingPacket) {
auto handle_incoming_rtcp = [&](const LoggedRtcpPacketIncoming& packet) {
packet_times.emplace_back(packet.log_time());
packet_times.emplace_back(packet.log_time_us());
};
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());
packet_times.emplace_back(packet.log_time_us());
};
process.AddEvents(parsed_log_.outgoing_rtcp_packets(),
handle_outgoing_rtcp);
@ -601,7 +599,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());
float x = config_.GetCallTimeSec(playout_event.log_time_us());
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);
@ -628,7 +626,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());
float x = config_.GetCallTimeSec(packet.log_time_us());
// 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);
@ -664,7 +662,7 @@ void EventLogAnalyzer::CreateSequenceNumberGraph(Plot* plot) {
return diff;
};
auto ToCallTime = [this](const LoggedRtpPacketIncoming& packet) {
return this->config_.GetCallTimeSec(packet.log_time());
return this->config_.GetCallTimeSec(packet.log_time_us());
};
ProcessPairs<LoggedRtpPacketIncoming, float>(
ToCallTime, GetSequenceNumberDiff, stream.incoming_packets,
@ -693,8 +691,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 TimeDelta kWindow = TimeDelta::Millis(1000);
const TimeDelta kStep = TimeDelta::Millis(1000);
const int64_t kWindowUs = 1000000;
const int64_t kStep = 1000000;
SeqNumUnwrapper<uint16_t> unwrapper_;
SeqNumUnwrapper<uint16_t> prior_unwrapper_;
size_t window_index_begin = 0;
@ -704,17 +702,17 @@ void EventLogAnalyzer::CreateIncomingPacketLossGraph(Plot* plot) {
uint64_t highest_prior_seq_number =
prior_unwrapper_.Unwrap(packets[0].rtp.header.sequenceNumber) - 1;
for (Timestamp t = config_.begin_time_; t < config_.end_time_ + kStep;
for (int64_t t = config_.begin_time_; t < config_.end_time_ + kStep;
t += kStep) {
while (window_index_end < packets.size() &&
packets[window_index_end].rtp.log_time() < t) {
packets[window_index_end].rtp.log_time_us() < 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() < t - kWindow) {
packets[window_index_begin].rtp.log_time_us() < t - kWindowUs) {
uint64_t sequence_number = prior_unwrapper_.Unwrap(
packets[window_index_begin].rtp.header.sequenceNumber);
highest_prior_seq_number =
@ -769,7 +767,7 @@ void EventLogAnalyzer::CreateIncomingDelayGraph(Plot* plot) {
}
auto ToCallTime = [this](const LoggedRtpPacketIncoming& packet) {
return this->config_.GetCallTimeSec(packet.log_time());
return this->config_.GetCallTimeSec(packet.log_time_us());
};
auto ToNetworkDelay = [frequency_hz](
const LoggedRtpPacketIncoming& old_packet,
@ -805,7 +803,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());
float x = config_.GetCallTimeSec(bwe_update.log_time_us());
float y = static_cast<float>(bwe_update.fraction_lost) / 255 * 100;
time_series.points.emplace_back(x, y);
}
@ -820,11 +818,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<Timestamp, size_t> packets_in_order;
std::multimap<int64_t, 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(), packet.rtp.total_length));
std::make_pair(packet.rtp.log_time_us(), packet.rtp.total_length));
}
auto window_begin = packets_in_order.begin();
@ -834,7 +832,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 (Timestamp time = config_.begin_time_;
for (int64_t 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;
@ -847,8 +845,7 @@ void EventLogAnalyzer::CreateTotalIncomingBitrateGraph(Plot* plot) {
++window_begin;
}
float window_duration_in_seconds =
static_cast<float>(config_.window_duration_.us()) /
kNumMicrosecsPerSec;
static_cast<float>(config_.window_duration_) / kNumMicrosecsPerSec;
float x = config_.GetCallTimeSec(time);
float y = bytes_in_window * 8 / window_duration_in_seconds / 1000;
bitrate_series.points.emplace_back(x, y);
@ -859,7 +856,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());
float x = config_.GetCallTimeSec(rtcp.log_time_us());
float y = static_cast<float>(rtcp.remb.bitrate_bps()) / 1000;
remb_series.points.emplace_back(x, y);
}
@ -887,11 +884,11 @@ void EventLogAnalyzer::CreateTotalOutgoingBitrateGraph(Plot* plot,
bool show_detector_state,
bool show_alr_state) {
// TODO(terelius): This could be provided by the parser.
std::multimap<Timestamp, size_t> packets_in_order;
std::multimap<int64_t, 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(), packet.rtp.total_length));
std::make_pair(packet.rtp.log_time_us(), packet.rtp.total_length));
}
auto window_begin = packets_in_order.begin();
@ -901,7 +898,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 (Timestamp time = config_.begin_time_;
for (int64_t 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;
@ -914,8 +911,7 @@ void EventLogAnalyzer::CreateTotalOutgoingBitrateGraph(Plot* plot,
++window_begin;
}
float window_duration_in_seconds =
static_cast<float>(config_.window_duration_.us()) /
kNumMicrosecsPerSec;
static_cast<float>(config_.window_duration_) / kNumMicrosecsPerSec;
float x = config_.GetCallTimeSec(time);
float y = bytes_in_window * 8 / window_duration_in_seconds / 1000;
bitrate_series.points.emplace_back(x, y);
@ -926,7 +922,7 @@ 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());
float x = config_.GetCallTimeSec(loss_update.log_time_us());
float y = static_cast<float>(loss_update.bitrate_bps) / 1000;
loss_series.points.emplace_back(x, y);
}
@ -939,12 +935,12 @@ void EventLogAnalyzer::CreateTotalOutgoingBitrateGraph(Plot* plot,
IntervalSeries normal_series("Normal", "#c4ffc4",
IntervalSeries::kHorizontal);
IntervalSeries* last_series = &normal_series;
float last_detector_switch = 0.0;
double 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());
float x = config_.GetCallTimeSec(delay_update.log_time_us());
float y = static_cast<float>(delay_update.bitrate_bps) / 1000;
if (last_detector_state != delay_update.detector_state) {
@ -971,13 +967,12 @@ void EventLogAnalyzer::CreateTotalOutgoingBitrateGraph(Plot* plot,
}
RTC_CHECK(last_series);
last_series->intervals.emplace_back(last_detector_switch,
config_.CallEndTimeSec());
last_series->intervals.emplace_back(last_detector_switch, config_.end_time_);
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());
float x = config_.GetCallTimeSec(cluster.log_time_us());
float y = static_cast<float>(cluster.bitrate_bps) / 1000;
created_series.points.emplace_back(x, y);
}
@ -985,7 +980,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());
float x = config_.GetCallTimeSec(result.log_time_us());
float y = static_cast<float>(result.bitrate_bps) / 1000;
result_series.points.emplace_back(x, y);
}
@ -993,17 +988,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());
float x = config_.GetCallTimeSec(failure.log_time_us());
probe_failures_series.points.emplace_back(x, 0);
}
IntervalSeries alr_state("ALR", "#555555", IntervalSeries::kHorizontal);
bool previously_in_alr = false;
Timestamp alr_start = Timestamp::Zero();
int64_t alr_start = 0;
for (auto& alr : parsed_log_.alr_state_events()) {
float y = config_.GetCallTimeSec(alr.log_time());
float y = config_.GetCallTimeSec(alr.log_time_us());
if (!previously_in_alr && alr.in_alr) {
alr_start = alr.log_time();
alr_start = alr.log_time_us();
previously_in_alr = true;
} else if (previously_in_alr && !alr.in_alr) {
float x = config_.GetCallTimeSec(alr_start);
@ -1036,7 +1031,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());
float x = config_.GetCallTimeSec(rtcp.log_time_us());
float y = static_cast<float>(rtcp.remb.bitrate_bps()) / 1000;
remb_series.points.emplace_back(x, y);
}
@ -1122,7 +1117,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());
float x = config_.GetCallTimeSec(rtcp.log_time_us());
float y = bitrate_item.target_bitrate_kbps;
time_series_it->second.points.emplace_back(x, y);
}
@ -1154,20 +1149,22 @@ void EventLogAnalyzer::CreateGoogCcSimulationGraph(Plot* plot) {
[&](const NetworkControlUpdate& update, Timestamp at_time) {
if (update.target_rate) {
target_rates.points.emplace_back(
config_.GetCallTimeSec(at_time),
config_.GetCallTimeSec(at_time.us()),
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()),
delay_based.points.emplace_back(
config_.GetCallTimeSec(logged.log_time_us()),
logged.bitrate_bps / 1000);
for (const auto& logged : parsed_log_.bwe_probe_success_events())
probe_results.points.emplace_back(config_.GetCallTimeSec(logged.log_time()),
probe_results.points.emplace_back(
config_.GetCallTimeSec(logged.log_time_us()),
logged.bitrate_bps / 1000);
for (const auto& logged : parsed_log_.bwe_loss_updates())
loss_based.points.emplace_back(config_.GetCallTimeSec(logged.log_time()),
loss_based.points.emplace_back(config_.GetCallTimeSec(logged.log_time_us()),
logged.bitrate_bps / 1000);
plot->AppendTimeSeries(std::move(delay_based));
@ -1327,7 +1324,7 @@ void EventLogAnalyzer::CreateSendSideBweSimulationGraph(Plot* plot) {
}
}
float x = config_.GetCallTimeSec(clock.CurrentTime());
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()
@ -1350,7 +1347,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.CurrentTime());
float x = config_.GetCallTimeSec(clock.TimeInMicroseconds());
time_series.points.emplace_back(x, y);
last_update_us = time_us;
}
@ -1426,13 +1423,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.CurrentTime());
float x = config_.GetCallTimeSec(clock.TimeInMicroseconds());
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.CurrentTime());
float x = config_.GetCallTimeSec(clock.TimeInMicroseconds());
time_series.points.emplace_back(x, y);
last_update_us = clock.TimeInMicroseconds();
}
@ -1464,7 +1461,7 @@ void EventLogAnalyzer::CreateNetworkDelayFeedbackGraph(Plot* plot) {
for (const auto& packet : matched_rtp_rtcp) {
if (packet.arrival_time_ms == MatchedSendArrivalTimes::kNotReceived)
continue;
float x = config_.GetCallTimeSecFromMs(packet.feedback_arrival_time_ms);
float x = config_.GetCallTimeSec(1000 * 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);
@ -1533,7 +1530,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());
float x = config_.GetCallTimeSec(packet.rtp.log_time_us());
float y = send_time_ms - capture_time_ms;
pacer_delay_series.points.emplace_back(x, y);
}
@ -1554,7 +1551,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());
float x = config_.GetCallTimeSec(packet.log_time_us());
float y = packet.header.timestamp;
rtp_timestamps.points.emplace_back(x, y);
}
@ -1569,7 +1566,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());
float x = config_.GetCallTimeSec(rtcp.log_time_us());
float y = rtcp.sr.rtp_timestamp();
rtcp_timestamps.points.emplace_back(x, y);
}
@ -1591,7 +1588,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());
float x = config_.GetCallTimeSec(rtcp.log_time_us());
uint32_t ssrc = rtcp.sr.sender_ssrc();
for (const auto& block : rtcp.sr.report_blocks()) {
float y = fy(block);
@ -1613,7 +1610,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());
float x = config_.GetCallTimeSec(rtcp.log_time_us());
uint32_t ssrc = rtcp.rr.sender_ssrc();
for (const auto& block : rtcp.rr.report_blocks()) {
float y = fy(block);
@ -1652,7 +1649,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());
float x = config_.GetCallTimeSec(config.log_time_us());
float y = static_cast<float>(config.type);
configs_by_cp_id[config.candidate_pair_id].points.emplace_back(x, y);
}
@ -1709,7 +1706,7 @@ void EventLogAnalyzer::CreateIceConnectivityCheckGraph(Plot* plot) {
GetCandidatePairLogDescriptionFromId(event.candidate_pair_id),
LineStyle::kNone, PointStyle::kHighlight);
}
float x = config_.GetCallTimeSec(event.log_time());
float x = config_.GetCallTimeSec(event.log_time_us());
float y = static_cast<float>(event.type) + kEventTypeOffset;
checks_by_cp_id[event.candidate_pair_id].points.emplace_back(x, y);
}
@ -1744,7 +1741,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());
float x = config_.GetCallTimeSec(event.log_time_us());
float y = static_cast<float>(event.dtls_transport_state);
states.points.emplace_back(x, y);
}
@ -1766,7 +1763,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());
float x = config_.GetCallTimeSec(event.log_time_us());
float y = static_cast<float>(event.writable);
writable.points.emplace_back(x, y);
}

42
rtc_tools/rtc_event_log_visualizer/analyzer_common.h
View file

@ -22,7 +22,6 @@
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;
@ -30,38 +29,25 @@ constexpr float kTopMargin = 0.05f;
class AnalyzerConfig {
public:
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 GetCallTimeSec(int64_t timestamp_us) const {
int64_t offset = normalize_time_ ? begin_time_ : 0;
return static_cast<float>(timestamp_us - offset) / 1000000;
}
float CallBeginTimeSec() const { return GetCallTimeSec(begin_time_); }
float CallEndTimeSec() const { return GetCallTimeSec(end_time_); }
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_.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);
// The generated data points will be `step_` microseconds apart.
// Only events occurring at most `window_duration_` microseconds before the
// current data point will be part of the average.
int64_t window_duration_;
int64_t step_;
// First and last events of the log.
Timestamp begin_time_ = Timestamp::MinusInfinity();
Timestamp end_time_ = Timestamp::MinusInfinity();
TimeDelta rtc_to_utc_offset_ = TimeDelta::Zero();
int64_t begin_time_;
int64_t end_time_;
bool normalize_time_;
};
@ -166,17 +152,17 @@ void MovingAverage(
size_t window_index_end = 0;
ResultType sum_in_window = 0;
for (Timestamp t = config.begin_time_; t < config.end_time_ + config.step_;
for (int64_t 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() < t) {
data_view[window_index_end].log_time_us() < 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() <
data_view[window_index_begin].log_time_us() <
t - config.window_duration_) {
absl::optional<ResultType> value = fy(data_view[window_index_begin]);
if (value)
@ -184,7 +170,7 @@ void MovingAverage(
++window_index_begin;
}
float window_duration_s =
static_cast<float>(config.window_duration_.us()) / kNumMicrosecsPerSec;
static_cast<float>(config.window_duration_) / kNumMicrosecsPerSec;
float x = config.GetCallTimeSec(t);
float y = sum_in_window / window_duration_s;
result->points.emplace_back(x, y);

9
rtc_tools/rtc_event_log_visualizer/main.cc
View file

@ -261,12 +261,8 @@ int main(int argc, char* argv[]) {
}
webrtc::AnalyzerConfig config;
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.window_duration_ = 250000;
config.step_ = 10000;
config.normalize_time_ = absl::GetFlag(FLAGS_normalize_time);
config.begin_time_ = parsed_log.first_timestamp();
config.end_time_ = parsed_log.last_timestamp();
@ -279,7 +275,6 @@ 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) {

6
rtc_tools/rtc_event_log_visualizer/plot_base.cc
View file

@ -307,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() {

6
rtc_tools/rtc_event_log_visualizer/plot_base.h
View file

@ -16,7 +16,6 @@
#include <vector>
#include "absl/base/attributes.h"
#include "absl/types/optional.h"
#include "rtc_base/ignore_wundef.h"
RTC_PUSH_IGNORING_WUNDEF()
@ -195,10 +194,6 @@ class PlotCollection {
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;
@ -207,7 +202,6 @@ class PlotCollection {
protected:
std::vector<std::unique_ptr<Plot>> plots_;
absl::optional<int64_t> calltime_to_utc_ms_;
};
} // namespace webrtc

4
rtc_tools/rtc_event_log_visualizer/proto/chart.proto
View file

@ -33,8 +33,4 @@ 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;
}