Replace inconsistent log_segments() function in RTC event log parser
Bug: webrtc:11566
Change-Id: I739bbc29ae5423f3fedcc08e991e27fa0af840c5
Reviewed-on: https://webrtc-review.googlesource.com/c/src/+/176081
Commit-Queue: Björn Terelius <terelius@webrtc.org>
Reviewed-by: Mirko Bonadei <mbonadei@webrtc.org>
Cr-Commit-Position: refs/heads/master@{#31371}
diff --git a/logging/rtc_event_log/encoder/rtc_event_log_encoder_unittest.cc b/logging/rtc_event_log/encoder/rtc_event_log_encoder_unittest.cc
index 3059621..cf85775 100644
--- a/logging/rtc_event_log/encoder/rtc_event_log_encoder_unittest.cc
+++ b/logging/rtc_event_log/encoder/rtc_event_log_encoder_unittest.cc
@@ -675,13 +675,18 @@
}
TEST_P(RtcEventLogEncoderTest, RtcEventLoggingStopped) {
- const int64_t timestamp_us = rtc::TimeMicros();
- std::string encoded = encoder_->EncodeLogEnd(timestamp_us);
+ const int64_t start_timestamp_us = rtc::TimeMicros();
+ const int64_t start_utc_time_us = rtc::TimeUTCMicros();
+ std::string encoded =
+ encoder_->EncodeLogStart(start_timestamp_us, start_utc_time_us);
+
+ const int64_t stop_timestamp_us = rtc::TimeMicros();
+ encoded += encoder_->EncodeLogEnd(stop_timestamp_us);
ASSERT_TRUE(parsed_log_.ParseString(encoded).ok());
const auto& stop_log_events = parsed_log_.stop_log_events();
ASSERT_EQ(stop_log_events.size(), 1u);
- verifier_.VerifyLoggedStopEvent(timestamp_us, stop_log_events[0]);
+ verifier_.VerifyLoggedStopEvent(stop_timestamp_us, stop_log_events[0]);
}
// TODO(eladalon/terelius): Test with multiple events in the batch.
diff --git a/logging/rtc_event_log/rtc_event_log_parser.cc b/logging/rtc_event_log/rtc_event_log_parser.cc
index a3982ba..c882076 100644
--- a/logging/rtc_event_log/rtc_event_log_parser.cc
+++ b/logging/rtc_event_log/rtc_event_log_parser.cc
@@ -1076,6 +1076,7 @@
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();
outgoing_rtp_extensions_maps_.clear();
@@ -1214,31 +1215,37 @@
StoreFirstAndLastTimestamp(generic_packets_sent_);
StoreFirstAndLastTimestamp(generic_packets_received_);
StoreFirstAndLastTimestamp(generic_acks_received_);
+ StoreFirstAndLastTimestamp(remote_estimate_events_);
- // TODO(terelius): This should be cleaned up. We could also handle
- // a "missing" end event, by inserting the last previous regular
- // event rather than the next start event.
+ // Stop events could be missing due to file size limits. If so, use the
+ // last event, or the next start timestamp if available.
+ // TODO(terelius): This could be improved. Instead of using the next start
+ // 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();
- while (start_iter != start_log_events().end()) {
- int64_t start_us = start_iter->log_time_us();
+ 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()) {
+ start_us = std::min(start_us, start_iter->log_time_us());
++start_iter;
- absl::optional<int64_t> next_start_us;
if (start_iter != start_log_events().end())
- next_start_us.emplace(start_iter->log_time_us());
- if (stop_iter != stop_log_events().end() &&
- stop_iter->log_time_us() <=
- next_start_us.value_or(std::numeric_limits<int64_t>::max())) {
- int64_t stop_us = stop_iter->log_time_us();
- RTC_PARSE_CHECK_OR_RETURN_LE(start_us, stop_us);
- log_segments_.emplace_back(start_us, stop_us);
- ++stop_iter;
- } else {
- // We're missing an end event. Assume that it occurred just before the
- // next start.
- log_segments_.emplace_back(start_us,
- next_start_us.value_or(last_timestamp()));
- }
+ next_start_us = start_iter->log_time_us();
+ }
+ if (stop_iter != stop_log_events().end()) {
+ stop_us = stop_iter->log_time_us();
+ }
+ stop_us = std::min(stop_us, next_start_us);
+ if (stop_us == std::numeric_limits<int64_t>::max() &&
+ 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_ == std::numeric_limits<int64_t>::max() &&
+ last_timestamp_ == std::numeric_limits<int64_t>::min()) {
+ first_timestamp_ = last_timestamp_ = 0;
}
return status;
diff --git a/logging/rtc_event_log/rtc_event_log_parser.h b/logging/rtc_event_log/rtc_event_log_parser.h
index 2165631..8d3351e 100644
--- a/logging/rtc_event_log/rtc_event_log_parser.h
+++ b/logging/rtc_event_log/rtc_event_log_parser.h
@@ -11,6 +11,7 @@
#define LOGGING_RTC_EVENT_LOG_RTC_EVENT_LOG_PARSER_H_
#include <iterator>
+#include <limits>
#include <map>
#include <set>
#include <sstream> // no-presubmit-check TODO(webrtc:8982)
@@ -613,7 +614,7 @@
int64_t first_timestamp() const { return first_timestamp_; }
int64_t last_timestamp() const { return last_timestamp_; }
- const std::vector<LogSegment>& log_segments() const { return log_segments_; }
+ const LogSegment& first_log_segment() const { return first_log_segment_; }
std::vector<LoggedPacketInfo> GetPacketInfos(PacketDirection direction) const;
std::vector<LoggedPacketInfo> GetIncomingPacketInfos() const {
@@ -868,8 +869,8 @@
int64_t first_timestamp_;
int64_t last_timestamp_;
- // Stores the start and end timestamp for each log segments.
- std::vector<LogSegment> log_segments_;
+ LogSegment first_log_segment_ =
+ LogSegment(0, std::numeric_limits<int64_t>::max());
// The extension maps are mutable to allow us to insert the default
// configuration when parsing an RTP header for an unconfigured stream.
diff --git a/logging/rtc_event_log/rtc_event_log_unittest.cc b/logging/rtc_event_log/rtc_event_log_unittest.cc
index 5989006..e785d61 100644
--- a/logging/rtc_event_log/rtc_event_log_unittest.cc
+++ b/logging/rtc_event_log/rtc_event_log_unittest.cc
@@ -739,10 +739,10 @@
EXPECT_EQ(first_timestamp_ms_, parsed_log.first_timestamp() / 1000);
EXPECT_EQ(last_timestamp_ms_, parsed_log.last_timestamp() / 1000);
- ASSERT_EQ(parsed_log.log_segments().size(), 1u);
- EXPECT_EQ(parsed_log.log_segments()[0].start_time_ms(),
- start_time_us_ / 1000);
- EXPECT_EQ(parsed_log.log_segments()[0].stop_time_ms(), stop_time_us_ / 1000);
+ EXPECT_EQ(parsed_log.first_log_segment().start_time_ms(),
+ std::min(start_time_us_ / 1000, first_timestamp_ms_));
+ EXPECT_EQ(parsed_log.first_log_segment().stop_time_ms(),
+ stop_time_us_ / 1000);
// Clean up temporary file - can be pretty slow.
remove(temp_filename_.c_str());
diff --git a/rtc_tools/rtc_event_log_visualizer/alerts.cc b/rtc_tools/rtc_event_log_visualizer/alerts.cc
index f2d9564..86372de 100644
--- a/rtc_tools/rtc_event_log_visualizer/alerts.cc
+++ b/rtc_tools/rtc_event_log_visualizer/alerts.cc
@@ -62,10 +62,7 @@
direction == kIncomingPacket ? TriageAlertType::kIncomingCaptureTimeJump
: TriageAlertType::kOutgoingCaptureTimeJump;
- const int64_t segment_end_us =
- parsed_log.log_segments().empty()
- ? std::numeric_limits<int64_t>::max()
- : parsed_log.log_segments().front().stop_time_us();
+ const int64_t segment_end_us = parsed_log.first_log_segment().stop_time_us();
// Check for gaps in sequence numbers and capture timestamps.
for (const auto& stream : parsed_log.rtp_packets_by_ssrc(direction)) {
@@ -133,10 +130,7 @@
? TriageAlertType::kIncomingRtcpGap
: TriageAlertType::kOutgoingRtcpGap;
- const int64_t segment_end_us =
- parsed_log.log_segments().empty()
- ? std::numeric_limits<int64_t>::max()
- : parsed_log.log_segments().front().stop_time_us();
+ const int64_t segment_end_us = parsed_log.first_log_segment().stop_time_us();
// TODO(terelius): The parser could provide a list of all packets, ordered
// by time, for each direction.
@@ -202,10 +196,7 @@
AnalyzeTransmissionGaps(parsed_log, kIncomingPacket);
AnalyzeTransmissionGaps(parsed_log, kOutgoingPacket);
- const int64_t segment_end_us =
- parsed_log.log_segments().empty()
- ? std::numeric_limits<int64_t>::max()
- : parsed_log.log_segments().front().stop_time_us();
+ const int64_t segment_end_us = parsed_log.first_log_segment().stop_time_us();
int64_t first_occurrence = parsed_log.last_timestamp();
constexpr double kMaxLossFraction = 0.05;
diff --git a/rtc_tools/rtc_event_log_visualizer/analyzer.cc b/rtc_tools/rtc_event_log_visualizer/analyzer.cc
index 9a9a455..a0e441c 100644
--- a/rtc_tools/rtc_event_log_visualizer/analyzer.cc
+++ b/rtc_tools/rtc_event_log_visualizer/analyzer.cc
@@ -465,15 +465,21 @@
config_.begin_time_ = config_.end_time_ = 0;
}
- RTC_LOG(LS_INFO) << "Found " << parsed_log_.log_segments().size()
- << " (LOG_START, LOG_END) segments in log.";
+ RTC_LOG(LS_INFO) << "Log is "
+ << (parsed_log_.last_timestamp() -
+ parsed_log_.first_timestamp()) /
+ 1000000
+ << " seconds long.";
}
EventLogAnalyzer::EventLogAnalyzer(const ParsedRtcEventLog& log,
const AnalyzerConfig& config)
: parsed_log_(log), config_(config) {
- RTC_LOG(LS_INFO) << "Found " << parsed_log_.log_segments().size()
- << " (LOG_START, LOG_END) segments in log.";
+ RTC_LOG(LS_INFO) << "Log is "
+ << (parsed_log_.last_timestamp() -
+ parsed_log_.first_timestamp()) /
+ 1000000
+ << " seconds long.";
}
class BitrateObserver : public RemoteBitrateObserver {
@@ -852,10 +858,7 @@
<< packets.size() << " packets in the stream.";
continue;
}
- int64_t segment_end_us =
- parsed_log_.log_segments().empty()
- ? std::numeric_limits<int64_t>::max()
- : parsed_log_.log_segments().front().stop_time_us();
+ int64_t segment_end_us = parsed_log_.first_log_segment().stop_time_us();
absl::optional<uint32_t> estimated_frequency =
EstimateRtpClockFrequency(packets, segment_end_us);
if (!estimated_frequency)
@@ -1586,10 +1589,7 @@
"pacer delay with less than 2 packets in the stream";
continue;
}
- int64_t segment_end_us =
- parsed_log_.log_segments().empty()
- ? std::numeric_limits<int64_t>::max()
- : parsed_log_.log_segments().front().stop_time_us();
+ int64_t segment_end_us = parsed_log_.first_log_segment().stop_time_us();
absl::optional<uint32_t> estimated_frequency =
EstimateRtpClockFrequency(packets, segment_end_us);
if (!estimated_frequency)
@@ -2050,11 +2050,7 @@
output_events_it = parsed_log_.audio_playout_events().cbegin();
}
- absl::optional<int64_t> end_time_ms =
- parsed_log_.log_segments().empty()
- ? absl::nullopt
- : absl::optional<int64_t>(
- parsed_log_.log_segments().front().stop_time_ms());
+ int64_t end_time_ms = parsed_log_.first_log_segment().stop_time_ms();
neteq_stats[ssrc] = CreateNetEqTestAndRun(
audio_packets, &output_events_it->second, end_time_ms,