Logging basic bad call detection

webrtc/video/receive_statistics_proxy.cc

Index: webrtc/video/receive_statistics_proxy.cc
diff --git a/webrtc/video/receive_statistics_proxy.cc b/webrtc/video/receive_statistics_proxy.cc
index 15a2206589efd1b66eff41f3002429354bbbcd9f..61de680d38a3f01ed8f4402ad28ad0b565cf6616 100644
--- a/webrtc/video/receive_statistics_proxy.cc
+++ b/webrtc/video/receive_statistics_proxy.cc
@@ -13,6 +13,7 @@
 #include <cmath>
 
 #include "webrtc/base/checks.h"
+#include "webrtc/base/logging.h"
 #include "webrtc/modules/video_coding/include/video_codec_interface.h"
 #include "webrtc/system_wrappers/include/clock.h"
 #include "webrtc/system_wrappers/include/field_trial.h"
@@ -22,6 +23,21 @@ namespace webrtc {
 namespace {
 // Periodic time interval for processing samples for |freq_offset_counter_|.
 const int64_t kFreqOffsetProcessIntervalMs = 40000;
+
+// Configuration for bad call detection.
+const int kNumMeasurements = 10;
+const int kNumMeasurementsVariance = kNumMeasurements * 1.5;
+const float kBadFraction = 0.8f;
+// For fps and framerate variance:
+// Low means low enough to be bad, high means high enough to be good
+const int kLowFpsThreshold = 12;
+const int kHighFpsThreshold = 14;
+const int kLowVarianceThreshold = 1;

[åsapersson, 2016/12/07 15:34:51]

For variance, low enough to be good..?

+const int kHighVarianceThreshold = 2;
+// For qp:
+// Low means low enough to be good, high means high enough to be bad
+const int kLowQpThreshold = 60;
+const int kHighQpThreshold = 70;

[åsapersson, 2016/12/07 15:34:51]

Add Vp8 to variable name (since the qp range depends on the codec).

 }  // namespace
 
 ReceiveStatisticsProxy::ReceiveStatisticsProxy(
@@ -31,6 +47,19 @@ ReceiveStatisticsProxy::ReceiveStatisticsProxy(
       config_(*config),
       start_ms_(clock->TimeInMilliseconds()),
       // 1000ms window, scale 1000 for ms to s.

[åsapersson, 2016/12/07 15:34:50]

Move comment to decode_fps_estimator_

+      last_sample_time_(clock->TimeInMilliseconds()),
+      fps_threshold_(kLowFpsThreshold,
+                     kHighFpsThreshold,
+                     kBadFraction,
+                     kNumMeasurements),
+      qp_threshold_(kLowQpThreshold,
+                    kHighQpThreshold,
+                    kBadFraction,
+                    kNumMeasurements),
+      variance_threshold_(kLowVarianceThreshold,
+                          kHighVarianceThreshold,
+                          kBadFraction,
+                          kNumMeasurementsVariance),
       decode_fps_estimator_(1000, 1000),
       renders_fps_estimator_(1000, 1000),
       render_fps_tracker_(100, 10u),
@@ -173,6 +202,64 @@ void ReceiveStatisticsProxy::UpdateHistograms() {
   }
 }
 
+void ReceiveStatisticsProxy::QualitySample() {
+  uint64_t now = clock_->TimeInMilliseconds();
+

[åsapersson, 2016/12/07 15:34:50]

Perhaps check that some minimum time has passed since last_sample_time_.

+  double fps =
+      render_fps_tracker_.ComputeRateForInterval(now - last_sample_time_);
+  int qp = qp_sample_.Avg(1);

[åsapersson, 2016/12/07 15:34:51]

Handle -1 (i.e. no samples)?

[palmkvist, 2016/12/08 14:15:02]

My original thinking was that that was ok, since that either means lost frames
(i.e. fps will be bad, so we'll report bad anyway) or we're not getting qp data
at all (so qp cannot be a cause of a bad judgement), but I guess it's just as
well/better to just ignore it.

+
+  bool prev_fps_bad = !fps_threshold_.IsHigh().value_or(true);
+  bool prev_qp_bad = qp_threshold_.IsHigh().value_or(false);
+  bool prev_variance_bad = variance_threshold_.IsHigh().value_or(false);
+  bool prev_any_bad = prev_fps_bad || prev_qp_bad || prev_variance_bad;
+
+  fps_threshold_.AddMeasurement(static_cast<int>(fps));
+  qp_threshold_.AddMeasurement(qp);
+  rtc::Optional<double> fps_variance_opt = fps_threshold_.CalculateVariance();
+  double fps_variance = fps_variance_opt.value_or(0);
+  if (fps_variance_opt) {
+    variance_threshold_.AddMeasurement(static_cast<int>(fps_variance));
+  }
+
+  bool fps_bad = !fps_threshold_.IsHigh().value_or(true);
+  bool qp_bad = qp_threshold_.IsHigh().value_or(false);
+  bool variance_bad = variance_threshold_.IsHigh().value_or(false);
+  bool any_bad = fps_bad || qp_bad || variance_bad;
+
+  if (!prev_any_bad && any_bad) {
+    LOG(LS_WARNING) << "Bad call (any) start: " << now;
+  } else if (prev_any_bad && !any_bad) {
+    LOG(LS_WARNING) << "Bad call (any) end: " << now;
+  }
+
+  if (!prev_fps_bad && fps_bad) {
+    LOG(LS_WARNING) << "Bad call (fps) start: " << now;
+  } else if (prev_fps_bad && !fps_bad) {
+    LOG(LS_WARNING) << "Bad call (fps) end: " << now;
+  }
+
+  if (!prev_qp_bad && qp_bad) {
+    LOG(LS_WARNING) << "Bad call (qp) start: " << now;
+  } else if (prev_qp_bad && !qp_bad) {
+    LOG(LS_WARNING) << "Bad call (qp) end: " << now;
+  }
+
+  if (!prev_variance_bad && variance_bad) {
+    LOG(LS_WARNING) << "Bad call (variance) start: " << now;
+  } else if (prev_variance_bad && !variance_bad) {
+    LOG(LS_WARNING) << "Bad call (variance) end: " << now;
+  }
+
+  LOG(LS_INFO) << "SAMPLE: sample_length: " << (now - last_sample_time_)
+               << " fps: " << fps << " fps_bad: " << fps_bad << " qp: " << qp
+               << " qp_bad: " << qp_bad << " variance_bad: " << variance_bad
+               << " fps_variance: " << fps_variance;
+
+  last_sample_time_ = now;
+  qp_sample_.Reset();
+}
+
 VideoReceiveStream::Stats ReceiveStatisticsProxy::GetStats() const {
   rtc::CritScope lock(&crit_);
   return stats_;
@@ -191,6 +278,7 @@ void ReceiveStatisticsProxy::OnDecoderImplementationName(
 void ReceiveStatisticsProxy::OnIncomingRate(unsigned int framerate,
                                             unsigned int bitrate_bps) {
   rtc::CritScope lock(&crit_);
+  QualitySample();
   stats_.network_frame_rate = framerate;
   stats_.total_bitrate_bps = bitrate_bps;
 }
@@ -340,6 +428,8 @@ void ReceiveStatisticsProxy::OnPreDecode(
   }
   if (codec_specific_info->codecType == kVideoCodecVP8) {
     qp_counters_.vp8.Add(encoded_image.qp_);
+    rtc::CritScope lock(&crit_);
+    qp_sample_.Add(encoded_image.qp_);
   }
 }
 
@@ -354,4 +444,9 @@ int ReceiveStatisticsProxy::SampleCounter::Avg(int min_required_samples) const {
   return sum / num_samples;
 }
 
+void ReceiveStatisticsProxy::SampleCounter::Reset() {
+  num_samples = 0;
+  sum = 0;
+}
+
 }  // namespace webrtc