diff --git a/logging/rtc_event_log/events/logged_rtp_rtcp.h b/logging/rtc_event_log/events/logged_rtp_rtcp.h index 179d70dd63..053a16371d 100644 --- a/logging/rtc_event_log/events/logged_rtp_rtcp.h +++ b/logging/rtc_event_log/events/logged_rtp_rtcp.h @@ -41,6 +41,7 @@ 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. @@ -57,6 +58,7 @@ 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; }; @@ -69,6 +71,7 @@ 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; }; @@ -87,6 +90,7 @@ 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 raw_data; @@ -101,6 +105,7 @@ 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; }; @@ -114,6 +119,7 @@ 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; }; @@ -126,6 +132,7 @@ 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; @@ -139,6 +146,7 @@ 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; @@ -149,6 +157,7 @@ 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; @@ -161,6 +170,7 @@ 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; @@ -173,6 +183,7 @@ 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; @@ -183,6 +194,7 @@ 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; @@ -193,6 +205,7 @@ 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; @@ -209,6 +222,7 @@ 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; @@ -223,6 +237,7 @@ 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; @@ -233,6 +248,7 @@ 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; diff --git a/logging/rtc_event_log/events/rtc_event_alr_state.h b/logging/rtc_event_log/events/rtc_event_alr_state.h index 44e68a680e..9f595ecd90 100644 --- a/logging/rtc_event_log/events/rtc_event_alr_state.h +++ b/logging/rtc_event_log/events/rtc_event_alr_state.h @@ -32,6 +32,7 @@ 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; diff --git a/logging/rtc_event_log/events/rtc_event_audio_network_adaptation.h b/logging/rtc_event_log/events/rtc_event_audio_network_adaptation.h index b9e919c2e8..d4cae3abfa 100644 --- a/logging/rtc_event_log/events/rtc_event_audio_network_adaptation.h +++ b/logging/rtc_event_log/events/rtc_event_audio_network_adaptation.h @@ -31,6 +31,7 @@ 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; diff --git a/logging/rtc_event_log/events/rtc_event_audio_playout.h b/logging/rtc_event_log/events/rtc_event_audio_playout.h index 3788324d15..196c3ca247 100644 --- a/logging/rtc_event_log/events/rtc_event_audio_playout.h +++ b/logging/rtc_event_log/events/rtc_event_audio_playout.h @@ -32,6 +32,7 @@ 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; diff --git a/logging/rtc_event_log/events/rtc_event_audio_receive_stream_config.h b/logging/rtc_event_log/events/rtc_event_audio_receive_stream_config.h index ac8813c937..9863e235af 100644 --- a/logging/rtc_event_log/events/rtc_event_audio_receive_stream_config.h +++ b/logging/rtc_event_log/events/rtc_event_audio_receive_stream_config.h @@ -30,6 +30,7 @@ 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; diff --git a/logging/rtc_event_log/events/rtc_event_audio_send_stream_config.h b/logging/rtc_event_log/events/rtc_event_audio_send_stream_config.h index 8b699e71cf..550723bcf0 100644 --- a/logging/rtc_event_log/events/rtc_event_audio_send_stream_config.h +++ b/logging/rtc_event_log/events/rtc_event_audio_send_stream_config.h @@ -29,6 +29,7 @@ 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; diff --git a/logging/rtc_event_log/events/rtc_event_begin_log.h b/logging/rtc_event_log/events/rtc_event_begin_log.h index 8dc47b5a02..f3b74c117e 100644 --- a/logging/rtc_event_log/events/rtc_event_begin_log.h +++ b/logging/rtc_event_log/events/rtc_event_begin_log.h @@ -35,6 +35,7 @@ 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; } diff --git a/logging/rtc_event_log/events/rtc_event_bwe_update_delay_based.h b/logging/rtc_event_log/events/rtc_event_bwe_update_delay_based.h index 4f145de412..796f119388 100644 --- a/logging/rtc_event_log/events/rtc_event_bwe_update_delay_based.h +++ b/logging/rtc_event_log/events/rtc_event_bwe_update_delay_based.h @@ -76,6 +76,7 @@ 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; diff --git a/logging/rtc_event_log/events/rtc_event_bwe_update_loss_based.h b/logging/rtc_event_log/events/rtc_event_bwe_update_loss_based.h index 1caf818a0c..fd41b316e0 100644 --- a/logging/rtc_event_log/events/rtc_event_bwe_update_loss_based.h +++ b/logging/rtc_event_log/events/rtc_event_bwe_update_loss_based.h @@ -37,6 +37,7 @@ 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; diff --git a/logging/rtc_event_log/events/rtc_event_dtls_transport_state.h b/logging/rtc_event_log/events/rtc_event_dtls_transport_state.h index c2496dd532..b9af213256 100644 --- a/logging/rtc_event_log/events/rtc_event_dtls_transport_state.h +++ b/logging/rtc_event_log/events/rtc_event_dtls_transport_state.h @@ -26,6 +26,7 @@ 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; diff --git a/logging/rtc_event_log/events/rtc_event_dtls_writable_state.h b/logging/rtc_event_log/events/rtc_event_dtls_writable_state.h index 20221df9da..c820f184d7 100644 --- a/logging/rtc_event_log/events/rtc_event_dtls_writable_state.h +++ b/logging/rtc_event_log/events/rtc_event_dtls_writable_state.h @@ -28,6 +28,7 @@ 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; diff --git a/logging/rtc_event_log/events/rtc_event_end_log.h b/logging/rtc_event_log/events/rtc_event_end_log.h index ed7770f339..79648bdb8d 100644 --- a/logging/rtc_event_log/events/rtc_event_end_log.h +++ b/logging/rtc_event_log/events/rtc_event_end_log.h @@ -32,6 +32,7 @@ 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(); }; diff --git a/logging/rtc_event_log/events/rtc_event_frame_decoded.h b/logging/rtc_event_log/events/rtc_event_frame_decoded.h index db5162cd0d..91190faea9 100644 --- a/logging/rtc_event_log/events/rtc_event_frame_decoded.h +++ b/logging/rtc_event_log/events/rtc_event_frame_decoded.h @@ -29,6 +29,7 @@ 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; diff --git a/logging/rtc_event_log/events/rtc_event_generic_ack_received.h b/logging/rtc_event_log/events/rtc_event_generic_ack_received.h index d1ad0f1fef..57fd7cd9a6 100644 --- a/logging/rtc_event_log/events/rtc_event_generic_ack_received.h +++ b/logging/rtc_event_log/events/rtc_event_generic_ack_received.h @@ -36,6 +36,7 @@ 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; diff --git a/logging/rtc_event_log/events/rtc_event_generic_packet_received.h b/logging/rtc_event_log/events/rtc_event_generic_packet_received.h index fddee67740..a6006ca4d4 100644 --- a/logging/rtc_event_log/events/rtc_event_generic_packet_received.h +++ b/logging/rtc_event_log/events/rtc_event_generic_packet_received.h @@ -33,6 +33,7 @@ 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; diff --git a/logging/rtc_event_log/events/rtc_event_generic_packet_sent.h b/logging/rtc_event_log/events/rtc_event_generic_packet_sent.h index 0f839ca949..903950a398 100644 --- a/logging/rtc_event_log/events/rtc_event_generic_packet_sent.h +++ b/logging/rtc_event_log/events/rtc_event_generic_packet_sent.h @@ -37,6 +37,7 @@ 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; diff --git a/logging/rtc_event_log/events/rtc_event_ice_candidate_pair.h b/logging/rtc_event_log/events/rtc_event_ice_candidate_pair.h index 85cf79735a..bdacf15a59 100644 --- a/logging/rtc_event_log/events/rtc_event_ice_candidate_pair.h +++ b/logging/rtc_event_log/events/rtc_event_ice_candidate_pair.h @@ -45,6 +45,7 @@ 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; diff --git a/logging/rtc_event_log/events/rtc_event_ice_candidate_pair_config.h b/logging/rtc_event_log/events/rtc_event_ice_candidate_pair_config.h index 0dfbfc838a..e72d999cff 100644 --- a/logging/rtc_event_log/events/rtc_event_ice_candidate_pair_config.h +++ b/logging/rtc_event_log/events/rtc_event_ice_candidate_pair_config.h @@ -72,6 +72,7 @@ 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; diff --git a/logging/rtc_event_log/events/rtc_event_probe_cluster_created.h b/logging/rtc_event_log/events/rtc_event_probe_cluster_created.h index b91d89c239..ae6810c39d 100644 --- a/logging/rtc_event_log/events/rtc_event_probe_cluster_created.h +++ b/logging/rtc_event_log/events/rtc_event_probe_cluster_created.h @@ -39,6 +39,7 @@ 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; diff --git a/logging/rtc_event_log/events/rtc_event_probe_result_failure.h b/logging/rtc_event_log/events/rtc_event_probe_result_failure.h index ba4db75c66..1aa6e75cb7 100644 --- a/logging/rtc_event_log/events/rtc_event_probe_result_failure.h +++ b/logging/rtc_event_log/events/rtc_event_probe_result_failure.h @@ -40,6 +40,7 @@ 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; diff --git a/logging/rtc_event_log/events/rtc_event_probe_result_success.h b/logging/rtc_event_log/events/rtc_event_probe_result_success.h index 172e9aa2eb..49d1abec5a 100644 --- a/logging/rtc_event_log/events/rtc_event_probe_result_success.h +++ b/logging/rtc_event_log/events/rtc_event_probe_result_success.h @@ -33,6 +33,7 @@ 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; diff --git a/logging/rtc_event_log/events/rtc_event_remote_estimate.h b/logging/rtc_event_log/events/rtc_event_remote_estimate.h index 17de63c475..4a39ecc597 100644 --- a/logging/rtc_event_log/events/rtc_event_remote_estimate.h +++ b/logging/rtc_event_log/events/rtc_event_remote_estimate.h @@ -28,6 +28,7 @@ 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 link_capacity_lower; diff --git a/logging/rtc_event_log/events/rtc_event_route_change.h b/logging/rtc_event_log/events/rtc_event_route_change.h index 542d15e3b3..bc1461d7bb 100644 --- a/logging/rtc_event_log/events/rtc_event_route_change.h +++ b/logging/rtc_event_log/events/rtc_event_route_change.h @@ -29,6 +29,7 @@ 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; diff --git a/logging/rtc_event_log/events/rtc_event_video_receive_stream_config.h b/logging/rtc_event_log/events/rtc_event_video_receive_stream_config.h index f3380d1bb6..0be56c2065 100644 --- a/logging/rtc_event_log/events/rtc_event_video_receive_stream_config.h +++ b/logging/rtc_event_log/events/rtc_event_video_receive_stream_config.h @@ -30,6 +30,7 @@ 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; diff --git a/logging/rtc_event_log/events/rtc_event_video_send_stream_config.h b/logging/rtc_event_log/events/rtc_event_video_send_stream_config.h index 15c28999dc..f1717b19ea 100644 --- a/logging/rtc_event_log/events/rtc_event_video_send_stream_config.h +++ b/logging/rtc_event_log/events/rtc_event_video_send_stream_config.h @@ -30,6 +30,7 @@ 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; diff --git a/logging/rtc_event_log/rtc_event_log_parser.cc b/logging/rtc_event_log/rtc_event_log_parser.cc index f0d165bdb2..b4392e8088 100644 --- a/logging/rtc_event_log/rtc_event_log_parser.cc +++ b/logging/rtc_event_log/rtc_event_log_parser.cc @@ -1110,8 +1110,8 @@ void ParsedRtcEventLog::Clear() { last_incoming_rtcp_packet_.clear(); - first_timestamp_ = std::numeric_limits::max(); - last_timestamp_ = std::numeric_limits::min(); + first_timestamp_ = Timestamp::PlusInfinity(); + last_timestamp_ = Timestamp::MinusInfinity(); first_log_segment_ = LogSegment(0, std::numeric_limits::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_ = std::numeric_limits::max(); - last_timestamp_ = std::numeric_limits::min(); + first_timestamp_ = Timestamp::PlusInfinity(); + last_timestamp_ = Timestamp::MinusInfinity(); StoreFirstAndLastTimestamp(alr_state_events()); StoreFirstAndLastTimestamp(route_change_events()); for (const auto& audio_stream : audio_playout_events()) { @@ -1272,7 +1272,8 @@ 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(); + int64_t start_us = + first_timestamp().us_or(std::numeric_limits::max()); int64_t next_start_us = std::numeric_limits::max(); int64_t stop_us = std::numeric_limits::max(); if (start_iter != start_log_events().end()) { @@ -1286,15 +1287,14 @@ ParsedRtcEventLog::ParseStatus ParsedRtcEventLog::ParseStream( } stop_us = std::min(stop_us, next_start_us); if (stop_us == std::numeric_limits::max() && - last_timestamp() != std::numeric_limits::min()) { - stop_us = last_timestamp(); + !last_timestamp().IsMinusInfinity()) { + stop_us = last_timestamp().us(); } RTC_PARSE_CHECK_OR_RETURN_LE(start_us, stop_us); first_log_segment_ = LogSegment(start_us, stop_us); - if (first_timestamp_ == std::numeric_limits::max() && - last_timestamp_ == std::numeric_limits::min()) { - first_timestamp_ = last_timestamp_ = 0; + if (first_timestamp_ > last_timestamp_) { + first_timestamp_ = last_timestamp_ = Timestamp::Zero(); } return status; @@ -1563,8 +1563,8 @@ template void ParsedRtcEventLog::StoreFirstAndLastTimestamp(const std::vector& v) { if (v.empty()) return; - first_timestamp_ = std::min(first_timestamp_, v.front().log_time_us()); - last_timestamp_ = std::max(last_timestamp_, v.back().log_time_us()); + first_timestamp_ = std::min(first_timestamp_, v.front().log_time()); + last_timestamp_ = std::max(last_timestamp_, v.back().log_time()); } ParsedRtcEventLog::ParseStatus ParsedRtcEventLog::StoreParsedLegacyEvent( diff --git a/logging/rtc_event_log/rtc_event_log_parser.h b/logging/rtc_event_log/rtc_event_log_parser.h index 4a9ff3495f..9ef4e347de 100644 --- a/logging/rtc_event_log/rtc_event_log_parser.h +++ b/logging/rtc_event_log/rtc_event_log_parser.h @@ -643,8 +643,8 @@ class ParsedRtcEventLog { return decoded_frames_; } - int64_t first_timestamp() const { return first_timestamp_; } - int64_t last_timestamp() const { return last_timestamp_; } + Timestamp first_timestamp() const { return first_timestamp_; } + Timestamp last_timestamp() const { return last_timestamp_; } const LogSegment& first_log_segment() const { return first_log_segment_; } @@ -889,8 +889,8 @@ class ParsedRtcEventLog { std::vector last_incoming_rtcp_packet_; - int64_t first_timestamp_; - int64_t last_timestamp_; + Timestamp first_timestamp_ = Timestamp::PlusInfinity(); + Timestamp last_timestamp_ = Timestamp::MinusInfinity(); LogSegment first_log_segment_ = LogSegment(0, std::numeric_limits::max()); diff --git a/logging/rtc_event_log/rtc_event_log_unittest.cc b/logging/rtc_event_log/rtc_event_log_unittest.cc index 8f32eecd8b..34904a5e02 100644 --- a/logging/rtc_event_log/rtc_event_log_unittest.cc +++ b/logging/rtc_event_log/rtc_event_log_unittest.cc @@ -785,8 +785,8 @@ void RtcEventLogSession::ReadAndVerifyLog() { parsed_generic_acks_received[i]); } - EXPECT_EQ(first_timestamp_ms_, parsed_log.first_timestamp() / 1000); - EXPECT_EQ(last_timestamp_ms_, parsed_log.last_timestamp() / 1000); + EXPECT_EQ(first_timestamp_ms_, parsed_log.first_timestamp().ms()); + EXPECT_EQ(last_timestamp_ms_, parsed_log.last_timestamp().ms()); EXPECT_EQ(parsed_log.first_log_segment().start_time_ms(), std::min(start_time_us_ / 1000, first_timestamp_ms_)); diff --git a/rtc_tools/rtc_event_log_visualizer/alerts.cc b/rtc_tools/rtc_event_log_visualizer/alerts.cc index 2d1868fa28..c0d8784fa8 100644 --- a/rtc_tools/rtc_event_log_visualizer/alerts.cc +++ b/rtc_tools/rtc_event_log_visualizer/alerts.cc @@ -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_us()), + Alert(seq_num_alert, config_.GetCallTimeSec(packet.log_time()), 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_us()), + Alert(capture_time_alert, config_.GetCallTimeSec(packet.log_time()), capture_time_explanation); } last_capture_time = capture_time; @@ -140,7 +140,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); } @@ -155,7 +156,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()); @@ -169,7 +170,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()); @@ -189,7 +190,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; @@ -204,13 +205,14 @@ 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(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 69a753bf22..854c6d05ae 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 @@ 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( ToCallTime, GetAnaBitrateBps, @@ -63,7 +63,7 @@ void CreateAudioEncoderFrameLengthGraph(const ParsedRtcEventLog& parsed_log, return absl::optional(); }; auto ToCallTime = [config](const LoggedAudioNetworkAdaptationEvent& packet) { - return config.GetCallTimeSec(packet.log_time_us()); + return config.GetCallTimeSec(packet.log_time()); }; ProcessPoints( ToCallTime, GetAnaFrameLengthMs, @@ -88,7 +88,7 @@ void CreateAudioEncoderPacketLossGraph(const ParsedRtcEventLog& parsed_log, return absl::optional(); }; auto ToCallTime = [config](const LoggedAudioNetworkAdaptationEvent& packet) { - return config.GetCallTimeSec(packet.log_time_us()); + return config.GetCallTimeSec(packet.log_time()); }; ProcessPoints( ToCallTime, GetAnaPacketLoss, @@ -114,7 +114,7 @@ void CreateAudioEncoderEnableFecGraph(const ParsedRtcEventLog& parsed_log, return absl::optional(); }; auto ToCallTime = [config](const LoggedAudioNetworkAdaptationEvent& packet) { - return config.GetCallTimeSec(packet.log_time_us()); + return config.GetCallTimeSec(packet.log_time()); }; ProcessPoints( ToCallTime, GetAnaFecEnabled, @@ -139,7 +139,7 @@ void CreateAudioEncoderEnableDtxGraph(const ParsedRtcEventLog& parsed_log, return absl::optional(); }; auto ToCallTime = [config](const LoggedAudioNetworkAdaptationEvent& packet) { - return config.GetCallTimeSec(packet.log_time_us()); + return config.GetCallTimeSec(packet.log_time()); }; ProcessPoints( ToCallTime, GetAnaDtxEnabled, @@ -164,7 +164,7 @@ void CreateAudioEncoderNumChannelsGraph(const ParsedRtcEventLog& parsed_log, return absl::optional(); }; auto ToCallTime = [config](const LoggedAudioNetworkAdaptationEvent& packet) { - return config.GetCallTimeSec(packet.log_time_us()); + return config.GetCallTimeSec(packet.log_time()); }; ProcessPoints( 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(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 @@ void CreateNetEqStatsGraphInternal( const std::vector>* 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 b43801623c..4c718185df 100644 --- a/rtc_tools/rtc_event_log_visualizer/analyzer.cc +++ b/rtc_tools/rtc_event_log_visualizer/analyzer.cc @@ -214,7 +214,7 @@ TimeSeries CreateRtcpTypeTimeSeries(const std::vector& 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 +346,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 +371,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 +417,7 @@ void EventLogAnalyzer::CreatePacketGraph(PacketDirection direction, return absl::optional(packet.total_length); }; auto ToCallTime = [this](const LoggedRtpPacket& packet) { - return this->config_.GetCallTimeSec(packet.log_time_us()); + return this->config_.GetCallTimeSec(packet.timestamp); }; ProcessPoints(ToCallTime, GetPacketSize, stream.packet_view, &time_series); @@ -469,7 +473,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)); @@ -545,17 +549,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 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 @@ 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); @@ -599,7 +601,7 @@ void EventLogAnalyzer::CreatePlayoutGraph(Plot* plot) { absl::optional 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 @@ 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(-packet.header.extension.audioLevel); @@ -662,7 +664,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( ToCallTime, GetSequenceNumberDiff, stream.incoming_packets, @@ -691,8 +693,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 unwrapper_; SeqNumUnwrapper prior_unwrapper_; size_t window_index_begin = 0; @@ -702,17 +704,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 = @@ -767,7 +769,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, @@ -803,7 +805,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(bwe_update.fraction_lost) / 255 * 100; time_series.points.emplace_back(x, y); } @@ -818,11 +820,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 packets_in_order; + std::multimap 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 @@ 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; @@ -845,7 +847,8 @@ void EventLogAnalyzer::CreateTotalIncomingBitrateGraph(Plot* plot) { ++window_begin; } float window_duration_in_seconds = - static_cast(config_.window_duration_) / kNumMicrosecsPerSec; + static_cast(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 @@ 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(rtcp.remb.bitrate_bps()) / 1000; remb_series.points.emplace_back(x, y); } @@ -884,11 +887,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 packets_in_order; + std::multimap 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 @@ 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; @@ -911,7 +914,8 @@ void EventLogAnalyzer::CreateTotalOutgoingBitrateGraph(Plot* plot, ++window_begin; } float window_duration_in_seconds = - static_cast(config_.window_duration_) / kNumMicrosecsPerSec; + static_cast(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 @@ 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(loss_update.bitrate_bps) / 1000; loss_series.points.emplace_back(x, y); } @@ -935,12 +939,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(delay_update.bitrate_bps) / 1000; if (last_detector_state != delay_update.detector_state) { @@ -967,12 +971,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(cluster.bitrate_bps) / 1000; created_series.points.emplace_back(x, y); } @@ -980,7 +985,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(result.bitrate_bps) / 1000; result_series.points.emplace_back(x, y); } @@ -988,17 +993,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); @@ -1031,7 +1036,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(rtcp.remb.bitrate_bps()) / 1000; remb_series.points.emplace_back(x, y); } @@ -1117,7 +1122,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); } @@ -1149,22 +1154,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()); } }); 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 @@ void EventLogAnalyzer::CreateSendSideBweSimulationGraph(Plot* plot) { } } - 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 @@ 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; } @@ -1423,13 +1426,13 @@ void EventLogAnalyzer::CreateReceiveSideBweSimulationGraph(Plot* plot) { absl::optional 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 @@ 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; 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 @@ void EventLogAnalyzer::CreatePacerDelayGraph(Plot* plot) { double send_time_ms = static_cast(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 @@ 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); } @@ -1566,7 +1569,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); } @@ -1588,7 +1591,7 @@ void EventLogAnalyzer::CreateSenderAndReceiverReportPlot( std::map 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 @@ void EventLogAnalyzer::CreateSenderAndReceiverReportPlot( std::map 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 @@ 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(config.type); configs_by_cp_id[config.candidate_pair_id].points.emplace_back(x, y); } @@ -1706,7 +1709,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(event.type) + kEventTypeOffset; checks_by_cp_id[event.candidate_pair_id].points.emplace_back(x, y); } @@ -1741,7 +1744,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(event.dtls_transport_state); states.points.emplace_back(x, y); } @@ -1763,7 +1766,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(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 a4305a708f..b0b556aa62 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 @@ 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(timestamp_us - offset) / 1000000; + float GetCallTimeSec(Timestamp timestamp) const { + Timestamp offset = normalize_time_ ? begin_time_ : Timestamp::Zero(); + return static_cast((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 @@ 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 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 value = fy(data_view[window_index_begin]); if (value) @@ -170,7 +184,7 @@ void MovingAverage( ++window_index_begin; } float window_duration_s = - static_cast(config.window_duration_) / kNumMicrosecsPerSec; + static_cast(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 ab4b7ebac1..6182b701df 100644 --- a/rtc_tools/rtc_event_log_visualizer/main.cc +++ b/rtc_tools/rtc_event_log_visualizer/main.cc @@ -261,8 +261,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(); @@ -275,6 +279,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) { diff --git a/rtc_tools/rtc_event_log_visualizer/plot_base.cc b/rtc_tools/rtc_event_log_visualizer/plot_base.cc index 82533e6eb0..bf76a67bb5 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::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() { diff --git a/rtc_tools/rtc_event_log_visualizer/plot_base.h b/rtc_tools/rtc_event_log_visualizer/plot_base.h index a26146b5e5..dbc9535fc1 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 #include "absl/base/attributes.h" +#include "absl/types/optional.h" #include "rtc_base/ignore_wundef.h" RTC_PUSH_IGNORING_WUNDEF() @@ -194,6 +195,10 @@ 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; @@ -202,6 +207,7 @@ class PlotCollection { protected: std::vector> plots_; + absl::optional 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 e5960b2677..f82d9c1ead 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 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; }