Add periodic logging of video stats.
Add ToString method to: Call::Stats, VideoSendStream::Stats, VideoReceiveStream::Stats and log stats periodically (every 10 seconds).
BUG=
Review-Url: https://codereview.webrtc.org/2133073002
Cr-Commit-Position: refs/heads/master@{#13727}
diff --git a/webrtc/call.h b/webrtc/call.h
index 779ffe9..ec43b18 100644
--- a/webrtc/call.h
+++ b/webrtc/call.h
@@ -92,6 +92,8 @@
};
struct Stats {
+ std::string ToString(int64_t time_ms) const;
+
int send_bandwidth_bps = 0; // Estimated available send bandwidth.
int max_padding_bitrate_bps = 0; // Cumulative configured max padding.
int recv_bandwidth_bps = 0; // Estimated available receive bandwidth.
diff --git a/webrtc/call/call.cc b/webrtc/call/call.cc
index f50a8d6..f6354ad 100644
--- a/webrtc/call/call.cc
+++ b/webrtc/call/call.cc
@@ -203,6 +203,18 @@
};
} // namespace internal
+std::string Call::Stats::ToString(int64_t time_ms) const {
+ std::stringstream ss;
+ ss << "Call stats: " << time_ms << ", {";
+ ss << "send_bw_bps: " << send_bandwidth_bps << ", ";
+ ss << "recv_bw_bps: " << recv_bandwidth_bps << ", ";
+ ss << "max_pad_bps: " << max_padding_bitrate_bps << ", ";
+ ss << "pacer_delay_ms: " << pacer_delay_ms << ", ";
+ ss << "rtt_ms: " << rtt_ms;
+ ss << '}';
+ return ss.str();
+}
+
Call* Call::Create(const Call::Config& config) {
return new internal::Call(config);
}
diff --git a/webrtc/media/engine/webrtcvideoengine2.cc b/webrtc/media/engine/webrtcvideoengine2.cc
index dc9cdf0..4a72ef6 100644
--- a/webrtc/media/engine/webrtcvideoengine2.cc
+++ b/webrtc/media/engine/webrtcvideoengine2.cc
@@ -342,6 +342,9 @@
// Down grade resolution at most 2 times for CPU reasons.
static const int kMaxCpuDowngrades = 2;
+// Minimum time interval for logging stats.
+static const int64_t kStatsLogIntervalMs = 10000;
+
// Adds |codec| to |list|, and also adds an RTX codec if |codec|'s name is
// recognized.
// TODO(deadbeef): Should we add RTX codecs for external codecs whose names we
@@ -676,7 +679,8 @@
external_encoder_factory_(external_encoder_factory),
external_decoder_factory_(external_decoder_factory),
default_send_options_(options),
- red_disabled_by_remote_side_(false) {
+ red_disabled_by_remote_side_(false),
+ last_stats_log_ms_(-1) {
RTC_DCHECK(thread_checker_.CalledOnValidThread());
rtcp_receiver_report_ssrc_ = kDefaultRtcpReceiverReportSsrc;
@@ -1344,9 +1348,19 @@
bool WebRtcVideoChannel2::GetStats(VideoMediaInfo* info) {
TRACE_EVENT0("webrtc", "WebRtcVideoChannel2::GetStats");
+
+ // Log stats periodically.
+ bool log_stats = false;
+ int64_t now_ms = rtc::TimeMillis();
+ if (last_stats_log_ms_ == -1 ||
+ now_ms - last_stats_log_ms_ > kStatsLogIntervalMs) {
+ last_stats_log_ms_ = now_ms;
+ log_stats = true;
+ }
+
info->Clear();
- FillSenderStats(info);
- FillReceiverStats(info);
+ FillSenderStats(info, log_stats);
+ FillReceiverStats(info, log_stats);
webrtc::Call::Stats stats = call_->GetStats();
FillBandwidthEstimationStats(stats, info);
if (stats.rtt_ms != -1) {
@@ -1354,24 +1368,32 @@
info->senders[i].rtt_ms = stats.rtt_ms;
}
}
+
+ if (log_stats)
+ LOG(LS_INFO) << stats.ToString(now_ms);
+
return true;
}
-void WebRtcVideoChannel2::FillSenderStats(VideoMediaInfo* video_media_info) {
+void WebRtcVideoChannel2::FillSenderStats(VideoMediaInfo* video_media_info,
+ bool log_stats) {
rtc::CritScope stream_lock(&stream_crit_);
for (std::map<uint32_t, WebRtcVideoSendStream*>::iterator it =
send_streams_.begin();
it != send_streams_.end(); ++it) {
- video_media_info->senders.push_back(it->second->GetVideoSenderInfo());
+ video_media_info->senders.push_back(
+ it->second->GetVideoSenderInfo(log_stats));
}
}
-void WebRtcVideoChannel2::FillReceiverStats(VideoMediaInfo* video_media_info) {
+void WebRtcVideoChannel2::FillReceiverStats(VideoMediaInfo* video_media_info,
+ bool log_stats) {
rtc::CritScope stream_lock(&stream_crit_);
for (std::map<uint32_t, WebRtcVideoReceiveStream*>::iterator it =
receive_streams_.begin();
it != receive_streams_.end(); ++it) {
- video_media_info->receivers.push_back(it->second->GetVideoReceiverInfo());
+ video_media_info->receivers.push_back(
+ it->second->GetVideoReceiverInfo(log_stats));
}
}
@@ -2096,8 +2118,8 @@
source_->AddOrUpdateSink(this, sink_wants_);
}
-VideoSenderInfo
-WebRtcVideoChannel2::WebRtcVideoSendStream::GetVideoSenderInfo() {
+VideoSenderInfo WebRtcVideoChannel2::WebRtcVideoSendStream::GetVideoSenderInfo(
+ bool log_stats) {
VideoSenderInfo info;
webrtc::VideoSendStream::Stats stats;
RTC_DCHECK(thread_checker_.CalledOnValidThread());
@@ -2123,6 +2145,10 @@
stats = stream_->GetStats();
}
+
+ if (log_stats)
+ LOG(LS_INFO) << stats.ToString(rtc::TimeMillis());
+
info.adapt_changes = number_of_cpu_adapt_changes_;
info.adapt_reason =
cpu_restricted_counter_ <= 0 ? ADAPTREASON_NONE : ADAPTREASON_CPU;
@@ -2512,7 +2538,8 @@
}
VideoReceiverInfo
-WebRtcVideoChannel2::WebRtcVideoReceiveStream::GetVideoReceiverInfo() {
+WebRtcVideoChannel2::WebRtcVideoReceiveStream::GetVideoReceiverInfo(
+ bool log_stats) {
VideoReceiverInfo info;
info.ssrc_groups = stream_params_.ssrc_groups;
info.add_ssrc(config_.rtp.remote_ssrc);
@@ -2551,6 +2578,9 @@
info.plis_sent = stats.rtcp_packet_type_counts.pli_packets;
info.nacks_sent = stats.rtcp_packet_type_counts.nack_packets;
+ if (log_stats)
+ LOG(LS_INFO) << stats.ToString(rtc::TimeMillis());
+
return info;
}
diff --git a/webrtc/media/engine/webrtcvideoengine2.h b/webrtc/media/engine/webrtcvideoengine2.h
index 14f271f..9413047 100644
--- a/webrtc/media/engine/webrtcvideoengine2.h
+++ b/webrtc/media/engine/webrtcvideoengine2.h
@@ -274,7 +274,7 @@
void OnLoadUpdate(Load load) override;
const std::vector<uint32_t>& GetSsrcs() const;
- VideoSenderInfo GetVideoSenderInfo();
+ VideoSenderInfo GetVideoSenderInfo(bool log_stats);
void FillBandwidthEstimationInfo(BandwidthEstimationInfo* bwe_info);
private:
@@ -442,7 +442,7 @@
void SetSink(rtc::VideoSinkInterface<cricket::VideoFrame>* sink);
- VideoReceiverInfo GetVideoReceiverInfo();
+ VideoReceiverInfo GetVideoReceiverInfo(bool log_stats);
// Used to disable RED/FEC when the remote description doesn't contain those
// codecs. This is needed to be able to work around an RTX bug which is only
@@ -514,8 +514,8 @@
static bool ReceiveCodecsHaveChanged(std::vector<VideoCodecSettings> before,
std::vector<VideoCodecSettings> after);
- void FillSenderStats(VideoMediaInfo* info);
- void FillReceiverStats(VideoMediaInfo* info);
+ void FillSenderStats(VideoMediaInfo* info, bool log_stats);
+ void FillReceiverStats(VideoMediaInfo* info, bool log_stats);
void FillBandwidthEstimationStats(const webrtc::Call::Stats& stats,
VideoMediaInfo* info);
@@ -553,6 +553,7 @@
VideoOptions default_send_options_;
VideoRecvParameters recv_params_;
bool red_disabled_by_remote_side_;
+ int64_t last_stats_log_ms_;
};
} // namespace cricket
diff --git a/webrtc/video/receive_statistics_proxy.cc b/webrtc/video/receive_statistics_proxy.cc
index 9057543..9e6c380 100644
--- a/webrtc/video/receive_statistics_proxy.cc
+++ b/webrtc/video/receive_statistics_proxy.cc
@@ -263,6 +263,8 @@
rtc::CritScope lock(&crit_);
renders_fps_estimator_.Update(1, now);
stats_.render_frame_rate = renders_fps_estimator_.Rate(now).value_or(0);
+ stats_.width = width;
+ stats_.height = height;
render_width_counter_.Add(width);
render_height_counter_.Add(height);
render_fps_tracker_.AddSamples(1);
diff --git a/webrtc/video/send_statistics_proxy.cc b/webrtc/video/send_statistics_proxy.cc
index dfa7185..9325b2f 100644
--- a/webrtc/video/send_statistics_proxy.cc
+++ b/webrtc/video/send_statistics_proxy.cc
@@ -402,15 +402,21 @@
if (it != stats_.substreams.end())
return &it->second;
+ bool is_rtx = false;
if (std::find(config_.rtp.ssrcs.begin(), config_.rtp.ssrcs.end(), ssrc) ==
- config_.rtp.ssrcs.end() &&
- std::find(config_.rtp.rtx.ssrcs.begin(),
- config_.rtp.rtx.ssrcs.end(),
- ssrc) == config_.rtp.rtx.ssrcs.end()) {
- return nullptr;
+ config_.rtp.ssrcs.end()) {
+ if (std::find(config_.rtp.rtx.ssrcs.begin(), config_.rtp.rtx.ssrcs.end(),
+ ssrc) == config_.rtp.rtx.ssrcs.end()) {
+ return nullptr;
+ }
+ is_rtx = true;
}
- return &stats_.substreams[ssrc]; // Insert new entry and return ptr.
+ // Insert new entry and return ptr.
+ VideoSendStream::StreamStats* entry = &stats_.substreams[ssrc];
+ entry->is_rtx = is_rtx;
+
+ return entry;
}
void SendStatisticsProxy::OnInactiveSsrc(uint32_t ssrc) {
diff --git a/webrtc/video/send_statistics_proxy_unittest.cc b/webrtc/video/send_statistics_proxy_unittest.cc
index b1bf161..1e92877 100644
--- a/webrtc/video/send_statistics_proxy_unittest.cc
+++ b/webrtc/video/send_statistics_proxy_unittest.cc
@@ -45,6 +45,10 @@
&fake_clock_, GetTestConfig(),
VideoEncoderConfig::ContentType::kRealtimeVideo));
expected_ = VideoSendStream::Stats();
+ for (const auto& ssrc : config_.rtp.ssrcs)
+ expected_.substreams[ssrc].is_rtx = false;
+ for (const auto& ssrc : config_.rtp.rtx.ssrcs)
+ expected_.substreams[ssrc].is_rtx = true;
}
VideoSendStream::Config GetTestConfig() {
@@ -73,6 +77,7 @@
const VideoSendStream::StreamStats& a = it->second;
const VideoSendStream::StreamStats& b = corresponding_it->second;
+ EXPECT_EQ(a.is_rtx, b.is_rtx);
EXPECT_EQ(a.frame_counts.key_frames, b.frame_counts.key_frames);
EXPECT_EQ(a.frame_counts.delta_frames, b.frame_counts.delta_frames);
EXPECT_EQ(a.total_bitrate_bps, b.total_bitrate_bps);
diff --git a/webrtc/video/video_receive_stream.cc b/webrtc/video/video_receive_stream.cc
index 4b5dd75..86bb76f 100644
--- a/webrtc/video/video_receive_stream.cc
+++ b/webrtc/video/video_receive_stream.cc
@@ -116,6 +116,34 @@
return ss.str();
}
+std::string VideoReceiveStream::Stats::ToString(int64_t time_ms) const {
+ std::stringstream ss;
+ ss << "VideoReceiveStream stats: " << time_ms << ", {ssrc: " << ssrc << ", ";
+ ss << "total_bps: " << total_bitrate_bps << ", ";
+ ss << "width: " << width << ", ";
+ ss << "height: " << height << ", ";
+ ss << "key: " << frame_counts.key_frames << ", ";
+ ss << "delta: " << frame_counts.delta_frames << ", ";
+ ss << "network_fps: " << network_frame_rate << ", ";
+ ss << "decode_fps: " << decode_frame_rate << ", ";
+ ss << "render_fps: " << render_frame_rate << ", ";
+ ss << "decode_ms: " << decode_ms << ", ";
+ ss << "max_decode_ms: " << max_decode_ms << ", ";
+ ss << "cur_delay_ms: " << current_delay_ms << ", ";
+ ss << "targ_delay_ms: " << target_delay_ms << ", ";
+ ss << "jb_delay_ms: " << jitter_buffer_ms << ", ";
+ ss << "min_playout_delay_ms: " << min_playout_delay_ms << ", ";
+ ss << "discarded: " << discarded_packets << ", ";
+ ss << "sync_offset_ms: " << sync_offset_ms << ", ";
+ ss << "cum_loss: " << rtcp_stats.cumulative_lost << ", ";
+ ss << "max_ext_seq: " << rtcp_stats.extended_max_sequence_number << ", ";
+ ss << "nack: " << rtcp_packet_type_counts.nack_packets << ", ";
+ ss << "fir: " << rtcp_packet_type_counts.fir_packets << ", ";
+ ss << "pli: " << rtcp_packet_type_counts.pli_packets;
+ ss << '}';
+ return ss.str();
+}
+
namespace {
VideoCodec CreateDecoderVideoCodec(const VideoReceiveStream::Decoder& decoder) {
VideoCodec codec;
diff --git a/webrtc/video/video_send_stream.cc b/webrtc/video/video_send_stream.cc
index cb9ff41..a46bc85 100644
--- a/webrtc/video/video_send_stream.cc
+++ b/webrtc/video/video_send_stream.cc
@@ -162,6 +162,46 @@
return ss.str();
}
+std::string VideoSendStream::Stats::ToString(int64_t time_ms) const {
+ std::stringstream ss;
+ ss << "VideoSendStream stats: " << time_ms << ", {";
+ ss << "input_fps: " << input_frame_rate << ", ";
+ ss << "encode_fps: " << encode_frame_rate << ", ";
+ ss << "encode_ms: " << avg_encode_time_ms << ", ";
+ ss << "encode_usage_perc: " << encode_usage_percent << ", ";
+ ss << "target_bps: " << target_media_bitrate_bps << ", ";
+ ss << "media_bps: " << media_bitrate_bps << ", ";
+ ss << "suspended: " << (suspended ? "true" : "false") << ", ";
+ ss << "bw_adapted: " << (bw_limited_resolution ? "true" : "false");
+ ss << '}';
+ for (const auto& substream : substreams) {
+ if (!substream.second.is_rtx) {
+ ss << " {ssrc: " << substream.first << ", ";
+ ss << substream.second.ToString();
+ ss << '}';
+ }
+ }
+ return ss.str();
+}
+
+std::string VideoSendStream::StreamStats::ToString() const {
+ std::stringstream ss;
+ ss << "width: " << width << ", ";
+ ss << "height: " << height << ", ";
+ ss << "key: " << frame_counts.key_frames << ", ";
+ ss << "delta: " << frame_counts.delta_frames << ", ";
+ ss << "total_bps: " << total_bitrate_bps << ", ";
+ ss << "retransmit_bps: " << retransmit_bitrate_bps << ", ";
+ ss << "avg_delay_ms: " << avg_delay_ms << ", ";
+ ss << "max_delay_ms: " << max_delay_ms << ", ";
+ ss << "cum_loss: " << rtcp_stats.cumulative_lost << ", ";
+ ss << "max_ext_seq: " << rtcp_stats.extended_max_sequence_number << ", ";
+ ss << "nack: " << rtcp_packet_type_counts.nack_packets << ", ";
+ ss << "fir: " << rtcp_packet_type_counts.fir_packets << ", ";
+ ss << "pli: " << rtcp_packet_type_counts.pli_packets;
+ return ss.str();
+}
+
namespace {
VideoCodecType PayloadNameToCodecType(const std::string& payload_name) {
diff --git a/webrtc/video_receive_stream.h b/webrtc/video_receive_stream.h
index 49466ff..0adcf3f 100644
--- a/webrtc/video_receive_stream.h
+++ b/webrtc/video_receive_stream.h
@@ -48,6 +48,8 @@
};
struct Stats {
+ std::string ToString(int64_t time_ms) const;
+
int network_frame_rate = 0;
int decode_frame_rate = 0;
int render_frame_rate = 0;
@@ -68,6 +70,9 @@
int total_bitrate_bps = 0;
int discarded_packets = 0;
+ int width = 0;
+ int height = 0;
+
int sync_offset_ms = std::numeric_limits<int>::max();
uint32_t ssrc = 0;
diff --git a/webrtc/video_send_stream.h b/webrtc/video_send_stream.h
index 886367f..b79f6dd 100644
--- a/webrtc/video_send_stream.h
+++ b/webrtc/video_send_stream.h
@@ -41,7 +41,10 @@
class VideoSendStream {
public:
struct StreamStats {
+ std::string ToString() const;
+
FrameCounts frame_counts;
+ bool is_rtx = false;
int width = 0;
int height = 0;
// TODO(holmer): Move bitrate_bps out to the webrtc::Call layer.
@@ -55,6 +58,7 @@
};
struct Stats {
+ std::string ToString(int64_t time_ms) const;
std::string encoder_implementation_name = "unknown";
int input_frame_rate = 0;
int encode_frame_rate = 0;