diff --git a/logging/rtc_event_log/rtc_event_log_parser_new.cc b/logging/rtc_event_log/rtc_event_log_parser_new.cc index 672fcc1aab..14eb6cb2e1 100644 --- a/logging/rtc_event_log/rtc_event_log_parser_new.cc +++ b/logging/rtc_event_log/rtc_event_log_parser_new.cc @@ -1002,6 +1002,39 @@ bool ParsedRtcEventLogNew::ParseStream( &outgoing_remb_, &outgoing_nack_); } + // Store first and last timestamp events that might happen before the call is + // connected or after the call is disconnected. Typical examples are + // 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(); + + StoreFirstAndLastTimestamp(alr_state_events()); + for (const auto& audio_stream : audio_playout_events()) { + // Audio playout events are grouped by SSRC. + StoreFirstAndLastTimestamp(audio_stream.second); + } + StoreFirstAndLastTimestamp(audio_network_adaptation_events()); + StoreFirstAndLastTimestamp(bwe_probe_cluster_created_events()); + StoreFirstAndLastTimestamp(bwe_probe_failure_events()); + StoreFirstAndLastTimestamp(bwe_probe_success_events()); + StoreFirstAndLastTimestamp(bwe_delay_updates()); + StoreFirstAndLastTimestamp(bwe_loss_updates()); + StoreFirstAndLastTimestamp(dtls_transport_states()); + StoreFirstAndLastTimestamp(dtls_writable_states()); + StoreFirstAndLastTimestamp(ice_candidate_pair_configs()); + StoreFirstAndLastTimestamp(ice_candidate_pair_events()); + for (const auto& rtp_stream : incoming_rtp_packets_by_ssrc()) { + StoreFirstAndLastTimestamp(rtp_stream.incoming_packets); + } + for (const auto& rtp_stream : outgoing_rtp_packets_by_ssrc()) { + StoreFirstAndLastTimestamp(rtp_stream.outgoing_packets); + } + StoreFirstAndLastTimestamp(incoming_rtcp_packets()); + StoreFirstAndLastTimestamp(outgoing_rtcp_packets()); + return success; } @@ -1087,20 +1120,16 @@ bool ParsedRtcEventLogNew::ParseStreamInternal( return true; } +template +void ParsedRtcEventLogNew::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()); +} + void ParsedRtcEventLogNew::StoreParsedLegacyEvent(const rtclog::Event& event) { RTC_CHECK(event.has_type()); - if (event.type() != rtclog::Event::VIDEO_RECEIVER_CONFIG_EVENT && - event.type() != rtclog::Event::VIDEO_SENDER_CONFIG_EVENT && - event.type() != rtclog::Event::AUDIO_RECEIVER_CONFIG_EVENT && - event.type() != rtclog::Event::AUDIO_SENDER_CONFIG_EVENT && - event.type() != rtclog::Event::LOG_START && - event.type() != rtclog::Event::LOG_END) { - RTC_CHECK(event.has_timestamp_us()); - int64_t timestamp = event.timestamp_us(); - first_timestamp_ = std::min(first_timestamp_, timestamp); - last_timestamp_ = std::max(last_timestamp_, timestamp); - } - switch (event.type()) { case rtclog::Event::VIDEO_RECEIVER_CONFIG_EVENT: { rtclog::StreamConfig config = GetVideoReceiveConfig(event); @@ -2271,7 +2300,7 @@ void ParsedRtcEventLogNew::StoreAudioNetworkAdaptationEvent( // were shifted down by one, but in the base event, they were not. // We likewise shift the base event down by one, to get the same base as // encoding had, but then shift all of the values (except the base) back up - // to their original value. + // to their original value. absl::optional shifted_base_num_channels; if (proto.has_num_channels()) { shifted_base_num_channels = diff --git a/logging/rtc_event_log/rtc_event_log_parser_new.h b/logging/rtc_event_log/rtc_event_log_parser_new.h index 98d02ad699..ae97f95ed8 100644 --- a/logging/rtc_event_log/rtc_event_log_parser_new.h +++ b/logging/rtc_event_log/rtc_event_log_parser_new.h @@ -748,6 +748,10 @@ class ParsedRtcEventLogNew { return stop_log_events_; } + const std::vector& alr_state_events() const { + return alr_state_events_; + } + // Audio const std::map>& audio_playout_events() const { @@ -783,19 +787,15 @@ class ParsedRtcEventLogNew { return bwe_loss_updates_; } - const std::vector& dtls_writable_states() const { - return dtls_writable_states_; - } - - const std::vector& alr_state_events() const { - return alr_state_events_; - } - // DTLS const std::vector& dtls_transport_states() const { return dtls_transport_states_; } + const std::vector& dtls_writable_states() const { + return dtls_writable_states_; + } + // ICE events const std::vector& ice_candidate_pair_configs() const { @@ -889,6 +889,9 @@ class ParsedRtcEventLogNew { void StoreParsedLegacyEvent(const rtclog::Event& event); + template + void StoreFirstAndLastTimestamp(const std::vector& v); + // Reads the arrival timestamp (in microseconds) from a rtclog::Event. int64_t GetTimestamp(const rtclog::Event& event) const; @@ -954,19 +957,19 @@ class ParsedRtcEventLogNew { void StoreOutgoingRtpPackets(const rtclog2::OutgoingRtpPackets& proto); void StoreIncomingRtcpPackets(const rtclog2::IncomingRtcpPackets& proto); void StoreOutgoingRtcpPackets(const rtclog2::OutgoingRtcpPackets& proto); - void StoreAudioPlayoutEvent(const rtclog2::AudioPlayoutEvents& proto); void StoreStartEvent(const rtclog2::BeginLogEvent& proto); void StoreStopEvent(const rtclog2::EndLogEvent& proto); - void StoreBweLossBasedUpdate(const rtclog2::LossBasedBweUpdates& proto); - void StoreBweDelayBasedUpdate(const rtclog2::DelayBasedBweUpdates& proto); - void StoreDtlsWritableState(const rtclog2::DtlsWritableState& proto); + void StoreAlrStateEvent(const rtclog2::AlrState& proto); void StoreAudioNetworkAdaptationEvent( const rtclog2::AudioNetworkAdaptations& proto); + void StoreAudioPlayoutEvent(const rtclog2::AudioPlayoutEvents& proto); + void StoreBweLossBasedUpdate(const rtclog2::LossBasedBweUpdates& proto); + void StoreBweDelayBasedUpdate(const rtclog2::DelayBasedBweUpdates& proto); void StoreBweProbeClusterCreated(const rtclog2::BweProbeCluster& proto); void StoreBweProbeSuccessEvent(const rtclog2::BweProbeResultSuccess& proto); void StoreBweProbeFailureEvent(const rtclog2::BweProbeResultFailure& proto); - void StoreAlrStateEvent(const rtclog2::AlrState& proto); void StoreDtlsTransportState(const rtclog2::DtlsTransportStateEvent& proto); + void StoreDtlsWritableState(const rtclog2::DtlsWritableState& proto); void StoreIceCandidatePairConfig( const rtclog2::IceCandidatePairConfig& proto); void StoreIceCandidateEvent(const rtclog2::IceCandidatePairEvent& proto); @@ -1044,6 +1047,8 @@ class ParsedRtcEventLogNew { std::vector start_log_events_; std::vector stop_log_events_; + std::vector alr_state_events_; + std::map> audio_playout_events_; @@ -1057,17 +1062,12 @@ class ParsedRtcEventLogNew { std::vector bwe_probe_success_events_; std::vector bwe_delay_updates_; - - // A list of all updates from the send-side loss-based bandwidth estimator. std::vector bwe_loss_updates_; std::vector dtls_transport_states_; std::vector dtls_writable_states_; - std::vector alr_state_events_; - std::vector ice_candidate_pair_configs_; - std::vector ice_candidate_pair_events_; std::vector audio_recv_configs_; diff --git a/logging/rtc_event_log/rtc_event_log_unittest.cc b/logging/rtc_event_log/rtc_event_log_unittest.cc index 9177dd0365..a89de54dcf 100644 --- a/logging/rtc_event_log/rtc_event_log_unittest.cc +++ b/logging/rtc_event_log/rtc_event_log_unittest.cc @@ -9,6 +9,7 @@ */ #include +#include #include #include #include @@ -181,6 +182,9 @@ class RtcEventLogSession int64_t utc_start_time_us_; int64_t stop_time_us_; + int64_t first_timestamp_ms_ = std::numeric_limits::max(); + int64_t last_timestamp_ms_ = std::numeric_limits::min(); + const uint64_t seed_; Random prng_; const int64_t output_period_ms_; @@ -325,6 +329,8 @@ void RtcEventLogSession::WriteLog(EventCounts count, clock_.AdvanceTimeMicros(prng_.Rand(20) * 1000); size_t selection = prng_.Rand(remaining_events - 1); + first_timestamp_ms_ = std::min(first_timestamp_ms_, rtc::TimeMillis()); + last_timestamp_ms_ = std::max(last_timestamp_ms_, rtc::TimeMillis()); if (selection < count.alr_states) { auto event = gen_.NewAlrState(); @@ -656,6 +662,9 @@ void RtcEventLogSession::ReadAndVerifyLog() { parsed_video_send_configs[i]); } + EXPECT_EQ(first_timestamp_ms_, parsed_log.first_timestamp() / 1000); + EXPECT_EQ(last_timestamp_ms_, parsed_log.last_timestamp() / 1000); + // Clean up temporary file - can be pretty slow. remove(temp_filename_.c_str()); }