: event_media_type_(event_media_type),
clock_(clock),
offset_estimator_(offset_estimator),
+ capture_latency_datapoints_(0),
+ encode_time_datapoints_(0),
+ queueing_latency_datapoints_(0),
network_latency_datapoints_(0),
+ packet_latency_datapoints_(0),
+ frame_latency_datapoints_(0),
e2e_latency_datapoints_(0),
num_frames_dropped_by_encoder_(0),
num_frames_late_(0),
RecordE2ELatency(frame_event);
base::TimeDelta delay_delta = frame_event.delay_delta;
histograms_[PLAYOUT_DELAY_MS_HISTO]->Add(delay_delta.InMillisecondsF());
- if (delay_delta <= base::TimeDelta())
+
+ // Positive delay_delta means the frame is late.
+ if (delay_delta > base::TimeDelta())
num_frames_late_++;
}
if (type == PACKET_SENT_TO_NETWORK ||
type == PACKET_RECEIVED) {
- RecordNetworkLatency(packet_event);
+ RecordPacketRelatedLatencies(packet_event);
} else if (type == PACKET_RETRANSMITTED) {
// We only measure network latency using packets that doesn't have to be
// retransmitted as there is precisely one sent-receive timestamp pairs.
stats->SetDouble(CastStatToString(it->first),
round(it->second * 1000.0) / 1000.0);
}
+
+ // Populate all histograms.
for (HistogramMap::const_iterator it = histograms_.begin();
it != histograms_.end();
++it) {
frame_stats_.clear();
packet_stats_.clear();
+ total_capture_latency_ = base::TimeDelta();
+ capture_latency_datapoints_ = 0;
+ total_encode_time_ = base::TimeDelta();
+ encode_time_datapoints_ = 0;
+ total_queueing_latency_ = base::TimeDelta();
+ queueing_latency_datapoints_ = 0;
total_network_latency_ = base::TimeDelta();
network_latency_datapoints_ = 0;
+ total_packet_latency_ = base::TimeDelta();
+ packet_latency_datapoints_ = 0;
+ total_frame_latency_ = base::TimeDelta();
+ frame_latency_datapoints_ = 0;
total_e2e_latency_ = base::TimeDelta();
e2e_latency_datapoints_ = 0;
num_frames_dropped_by_encoder_ = 0;
STAT_ENUM_TO_STRING(CAPTURE_FPS);
STAT_ENUM_TO_STRING(ENCODE_FPS);
STAT_ENUM_TO_STRING(DECODE_FPS);
+ STAT_ENUM_TO_STRING(AVG_CAPTURE_LATENCY_MS);
STAT_ENUM_TO_STRING(AVG_ENCODE_TIME_MS);
- STAT_ENUM_TO_STRING(AVG_PLAYOUT_DELAY_MS);
+ STAT_ENUM_TO_STRING(AVG_QUEUEING_LATENCY_MS);
STAT_ENUM_TO_STRING(AVG_NETWORK_LATENCY_MS);
+ STAT_ENUM_TO_STRING(AVG_PACKET_LATENCY_MS);
+ STAT_ENUM_TO_STRING(AVG_FRAME_LATENCY_MS);
STAT_ENUM_TO_STRING(AVG_E2E_LATENCY_MS);
STAT_ENUM_TO_STRING(ENCODE_KBPS);
STAT_ENUM_TO_STRING(TRANSMISSION_KBPS);
STAT_ENUM_TO_STRING(RETRANSMISSION_KBPS);
- STAT_ENUM_TO_STRING(PACKET_LOSS_FRACTION);
STAT_ENUM_TO_STRING(MS_SINCE_LAST_RECEIVER_RESPONSE);
STAT_ENUM_TO_STRING(NUM_FRAMES_CAPTURED);
STAT_ENUM_TO_STRING(NUM_FRAMES_DROPPED_BY_ENCODER);
STAT_ENUM_TO_STRING(NUM_FRAMES_LATE);
STAT_ENUM_TO_STRING(NUM_PACKETS_SENT);
STAT_ENUM_TO_STRING(NUM_PACKETS_RETRANSMITTED);
+ STAT_ENUM_TO_STRING(NUM_PACKETS_RECEIVED);
STAT_ENUM_TO_STRING(NUM_PACKETS_RTX_REJECTED);
STAT_ENUM_TO_STRING(FIRST_EVENT_TIME_MS);
STAT_ENUM_TO_STRING(LAST_EVENT_TIME_MS);
STAT_ENUM_TO_STRING(CAPTURE_LATENCY_MS_HISTO);
- STAT_ENUM_TO_STRING(ENCODE_LATENCY_MS_HISTO);
+ STAT_ENUM_TO_STRING(ENCODE_TIME_MS_HISTO);
+ STAT_ENUM_TO_STRING(QUEUEING_LATENCY_MS_HISTO);
+ STAT_ENUM_TO_STRING(NETWORK_LATENCY_MS_HISTO);
STAT_ENUM_TO_STRING(PACKET_LATENCY_MS_HISTO);
STAT_ENUM_TO_STRING(FRAME_LATENCY_MS_HISTO);
+ STAT_ENUM_TO_STRING(E2E_LATENCY_MS_HISTO);
STAT_ENUM_TO_STRING(PLAYOUT_DELAY_MS_HISTO);
}
NOTREACHED();
return "";
}
-const int kMaxLatencyBucketMs = 800;
-const int kBucketWidthMs = 20;
+const int kDefaultMaxLatencyBucketMs = 800;
+const int kDefaultBucketWidthMs = 20;
+
+// For small latency values.
+const int kSmallMaxLatencyBucketMs = 100;
+const int kSmallBucketWidthMs = 5;
+
+// For large latency values.
+const int kLargeMaxLatencyBucketMs = 1200;
+const int kLargeBucketWidthMs = 50;
void StatsEventSubscriber::InitHistograms() {
- histograms_[CAPTURE_LATENCY_MS_HISTO].reset(
- new SimpleHistogram(0, kMaxLatencyBucketMs, kBucketWidthMs));
- histograms_[ENCODE_LATENCY_MS_HISTO].reset(
- new SimpleHistogram(0, kMaxLatencyBucketMs, kBucketWidthMs));
+ histograms_[E2E_LATENCY_MS_HISTO].reset(
+ new SimpleHistogram(0, kLargeMaxLatencyBucketMs,
+ kLargeBucketWidthMs));
+ histograms_[QUEUEING_LATENCY_MS_HISTO].reset(
+ new SimpleHistogram(0, kDefaultMaxLatencyBucketMs,
+ kDefaultBucketWidthMs));
+ histograms_[NETWORK_LATENCY_MS_HISTO].reset(
+ new SimpleHistogram(0, kDefaultMaxLatencyBucketMs,
+ kDefaultBucketWidthMs));
histograms_[PACKET_LATENCY_MS_HISTO].reset(
- new SimpleHistogram(0, kMaxLatencyBucketMs, kBucketWidthMs));
+ new SimpleHistogram(0, kDefaultMaxLatencyBucketMs,
+ kDefaultBucketWidthMs));
histograms_[FRAME_LATENCY_MS_HISTO].reset(
- new SimpleHistogram(0, kMaxLatencyBucketMs, kBucketWidthMs));
+ new SimpleHistogram(0, kDefaultMaxLatencyBucketMs,
+ kDefaultBucketWidthMs));
histograms_[PLAYOUT_DELAY_MS_HISTO].reset(
- new SimpleHistogram(0, kMaxLatencyBucketMs, kBucketWidthMs));
+ new SimpleHistogram(0, kSmallMaxLatencyBucketMs,
+ kSmallBucketWidthMs));
+ histograms_[CAPTURE_LATENCY_MS_HISTO].reset(
+ new SimpleHistogram(0, kSmallMaxLatencyBucketMs,
+ kSmallBucketWidthMs));
+ histograms_[ENCODE_TIME_MS_HISTO].reset(
+ new SimpleHistogram(0, kSmallMaxLatencyBucketMs,
+ kSmallBucketWidthMs));
}
void StatsEventSubscriber::GetStatsInternal(StatsMap* stats_map) const {
end_time, FRAME_ENCODED, ENCODE_FPS, stats_map);
PopulateFpsStat(
end_time, FRAME_DECODED, DECODE_FPS, stats_map);
- PopulatePlayoutDelayStat(stats_map);
PopulateFrameBitrateStat(end_time, stats_map);
PopulatePacketBitrateStat(end_time,
PACKET_SENT_TO_NETWORK,
PACKET_RETRANSMITTED,
RETRANSMISSION_KBPS,
stats_map);
- PopulatePacketLossPercentageStat(stats_map);
PopulateFrameCountStat(FRAME_CAPTURE_END, NUM_FRAMES_CAPTURED, stats_map);
PopulatePacketCountStat(PACKET_SENT_TO_NETWORK, NUM_PACKETS_SENT, stats_map);
PopulatePacketCountStat(
PACKET_RETRANSMITTED, NUM_PACKETS_RETRANSMITTED, stats_map);
+ PopulatePacketCountStat(PACKET_RECEIVED, NUM_PACKETS_RECEIVED, stats_map);
PopulatePacketCountStat(
PACKET_RTX_REJECTED, NUM_PACKETS_RTX_REJECTED, stats_map);
+ if (capture_latency_datapoints_ > 0) {
+ double avg_capture_latency_ms =
+ total_capture_latency_.InMillisecondsF() /
+ capture_latency_datapoints_;
+ stats_map->insert(
+ std::make_pair(AVG_CAPTURE_LATENCY_MS, avg_capture_latency_ms));
+ }
+
+ if (encode_time_datapoints_ > 0) {
+ double avg_encode_time_ms =
+ total_encode_time_.InMillisecondsF() /
+ encode_time_datapoints_;
+ stats_map->insert(
+ std::make_pair(AVG_ENCODE_TIME_MS, avg_encode_time_ms));
+ }
+
+ if (queueing_latency_datapoints_ > 0) {
+ double avg_queueing_latency_ms =
+ total_queueing_latency_.InMillisecondsF() /
+ queueing_latency_datapoints_;
+ stats_map->insert(
+ std::make_pair(AVG_QUEUEING_LATENCY_MS, avg_queueing_latency_ms));
+ }
+
if (network_latency_datapoints_ > 0) {
double avg_network_latency_ms =
total_network_latency_.InMillisecondsF() /
std::make_pair(AVG_NETWORK_LATENCY_MS, avg_network_latency_ms));
}
+ if (packet_latency_datapoints_ > 0) {
+ double avg_packet_latency_ms =
+ total_packet_latency_.InMillisecondsF() /
+ packet_latency_datapoints_;
+ stats_map->insert(
+ std::make_pair(AVG_PACKET_LATENCY_MS, avg_packet_latency_ms));
+ }
+
+ if (frame_latency_datapoints_ > 0) {
+ double avg_frame_latency_ms =
+ total_frame_latency_.InMillisecondsF() / frame_latency_datapoints_;
+ stats_map->insert(
+ std::make_pair(AVG_FRAME_LATENCY_MS, avg_frame_latency_ms));
+ }
+
if (e2e_latency_datapoints_ > 0) {
double avg_e2e_latency_ms =
total_e2e_latency_.InMillisecondsF() / e2e_latency_datapoints_;
}
}
+StatsEventSubscriber::SimpleHistogram*
+StatsEventSubscriber::GetHistogramForTesting(
+ CastStat stats) const {
+ DCHECK(histograms_.find(stats) != histograms_.end());
+ return histograms_.find(stats)->second.get();
+}
+
bool StatsEventSubscriber::GetReceiverOffset(base::TimeDelta* offset) {
base::TimeDelta receiver_offset_lower_bound;
base::TimeDelta receiver_offset_upper_bound;
if (recent_frame_infos_.size() >= kMaxFrameInfoMapSize) {
FrameInfoMap::iterator erase_it = recent_frame_infos_.begin();
- if (erase_it->second.encode_time.is_null())
+ if (erase_it->second.encode_end_time.is_null())
num_frames_dropped_by_encoder_++;
recent_frame_infos_.erase(erase_it);
}
void StatsEventSubscriber::RecordCaptureLatency(const FrameEvent& frame_event) {
FrameInfoMap::iterator it =
recent_frame_infos_.find(frame_event.rtp_timestamp);
- if (it == recent_frame_infos_.end())
+ if (it == recent_frame_infos_.end()) {
return;
+ }
if (!it->second.capture_time.is_null()) {
- double capture_latency_ms =
- (it->second.capture_time - frame_event.timestamp).InMillisecondsF();
- histograms_[CAPTURE_LATENCY_MS_HISTO]->Add(capture_latency_ms);
+ base::TimeDelta latency = frame_event.timestamp - it->second.capture_time;
+ total_capture_latency_ += latency;
+ capture_latency_datapoints_++;
+ histograms_[CAPTURE_LATENCY_MS_HISTO]->Add(latency.InMillisecondsF());
}
it->second.capture_end_time = frame_event.timestamp;
recent_frame_infos_.find(frame_event.rtp_timestamp);
if (it == recent_frame_infos_.end()) {
FrameInfo frame_info;
- frame_info.encode_time = frame_event.timestamp;
+ frame_info.encode_end_time = frame_event.timestamp;
MaybeInsertFrameInfo(frame_event.rtp_timestamp, frame_info);
return;
}
if (!it->second.capture_end_time.is_null()) {
- double encode_latency_ms =
- (frame_event.timestamp - it->second.capture_end_time).InMillisecondsF();
- histograms_[ENCODE_LATENCY_MS_HISTO]->Add(encode_latency_ms);
+ base::TimeDelta latency =
+ frame_event.timestamp - it->second.capture_end_time;
+ total_encode_time_ += latency;
+ encode_time_datapoints_++;
+ histograms_[ENCODE_TIME_MS_HISTO]->Add(latency.InMillisecondsF());
}
- it->second.encode_time = frame_event.timestamp;
+ it->second.encode_end_time = frame_event.timestamp;
}
void StatsEventSubscriber::RecordFrameTxLatency(const FrameEvent& frame_event) {
if (it == recent_frame_infos_.end())
return;
- if (it->second.encode_time.is_null())
+ if (it->second.encode_end_time.is_null())
return;
base::TimeDelta receiver_offset;
return;
base::TimeTicks sender_time = frame_event.timestamp - receiver_offset;
- double frame_tx_latency_ms =
- (sender_time - it->second.encode_time).InMillisecondsF();
- histograms_[FRAME_LATENCY_MS_HISTO]->Add(frame_tx_latency_ms);
+ base::TimeDelta latency = sender_time - it->second.encode_end_time;
+ total_frame_latency_ += latency;
+ frame_latency_datapoints_++;
+ histograms_[FRAME_LATENCY_MS_HISTO]->Add(latency.InMillisecondsF());
}
void StatsEventSubscriber::RecordE2ELatency(const FrameEvent& frame_event) {
// Playout time is event time + playout delay.
base::TimeTicks playout_time =
frame_event.timestamp + frame_event.delay_delta - receiver_offset;
- total_e2e_latency_ += playout_time - it->second.capture_time;
+ base::TimeDelta latency = playout_time - it->second.capture_time;
+ total_e2e_latency_ += latency;
e2e_latency_datapoints_++;
+ histograms_[E2E_LATENCY_MS_HISTO]->Add(latency.InMillisecondsF());
}
void StatsEventSubscriber::UpdateLastResponseTime(
packet_sent_times_.erase(key);
}
-void StatsEventSubscriber::RecordNetworkLatency(
+void StatsEventSubscriber::RecordPacketRelatedLatencies(
const PacketEvent& packet_event) {
+ // Log queueing latency.
+ if (packet_event.type == PACKET_SENT_TO_NETWORK) {
+ FrameInfoMap::iterator it =
+ recent_frame_infos_.find(packet_event.rtp_timestamp);
+ if (it != recent_frame_infos_.end()) {
+ base::TimeDelta latency =
+ packet_event.timestamp - it->second.encode_end_time;
+ total_queueing_latency_ += latency;
+ queueing_latency_datapoints_++;
+ histograms_[QUEUEING_LATENCY_MS_HISTO]->Add(
+ latency.InMillisecondsF());
+ }
+ }
+
+ // Log network latency and total packet latency;
base::TimeDelta receiver_offset;
if (!GetReceiverOffset(&receiver_offset))
return;
match = true;
}
if (match) {
+ packet_sent_times_.erase(it);
+
// Subtract by offset.
packet_received_time -= receiver_offset;
base::TimeDelta latency_delta = packet_received_time - packet_sent_time;
total_network_latency_ += latency_delta;
network_latency_datapoints_++;
-
- histograms_[PACKET_LATENCY_MS_HISTO]->Add(
+ histograms_[NETWORK_LATENCY_MS_HISTO]->Add(
latency_delta.InMillisecondsF());
- packet_sent_times_.erase(it);
+ // Log total network latency.
+ FrameInfoMap::iterator frame_it =
+ recent_frame_infos_.find(packet_event.rtp_timestamp);
+ if (frame_it != recent_frame_infos_.end()) {
+ base::TimeDelta latency =
+ packet_received_time - frame_it->second.encode_end_time;
+ total_packet_latency_ += latency;
+ packet_latency_datapoints_++;
+ histograms_[PACKET_LATENCY_MS_HISTO]->Add(
+ latency.InMillisecondsF());
+ }
}
}
}
}
}
-void StatsEventSubscriber::PopulatePlayoutDelayStat(StatsMap* stats_map) const {
- FrameStatsMap::const_iterator it = frame_stats_.find(FRAME_PLAYOUT);
- if (it != frame_stats_.end()) {
- double avg_delay_ms = 0.0;
- base::TimeDelta sum_delay = it->second.sum_delay;
- int count = it->second.event_counter;
- if (count != 0)
- avg_delay_ms = sum_delay.InMillisecondsF() / count;
- stats_map->insert(std::make_pair(AVG_PLAYOUT_DELAY_MS, avg_delay_ms));
- }
-}
-
void StatsEventSubscriber::PopulateFrameBitrateStat(base::TimeTicks end_time,
StatsMap* stats_map) const {
FrameStatsMap::const_iterator it = frame_stats_.find(FRAME_ENCODED);
}
}
-void StatsEventSubscriber::PopulatePacketLossPercentageStat(
- StatsMap* stats_map) const {
- // We assume that retransmission means that the packet's previous
- // (re)transmission was lost.
- // This means the percentage of packet loss is
- // (# of retransmit events) / (# of transmit + retransmit events).
- PacketStatsMap::const_iterator sent_it =
- packet_stats_.find(PACKET_SENT_TO_NETWORK);
- if (sent_it == packet_stats_.end())
- return;
- PacketStatsMap::const_iterator retransmitted_it =
- packet_stats_.find(PACKET_RETRANSMITTED);
- int sent_count = sent_it->second.event_counter;
- int retransmitted_count = 0;
- if (retransmitted_it != packet_stats_.end())
- retransmitted_count = retransmitted_it->second.event_counter;
- double packet_loss_fraction = static_cast<double>(retransmitted_count) /
- (sent_count + retransmitted_count);
- stats_map->insert(
- std::make_pair(PACKET_LOSS_FRACTION, packet_loss_fraction));
-}
-
StatsEventSubscriber::FrameLogStats::FrameLogStats()
: event_counter(0), sum_size(0) {}
StatsEventSubscriber::FrameLogStats::~FrameLogStats() {}