Add periodic logging of number of captured and dropped frames in VideoCaptureInput.

webrtc/video/vie_encoder.cc

 /*
  *  Copyright (c) 2012 The WebRTC project authors. All Rights Reserved.
  *
  *  Use of this source code is governed by a BSD-style license
  *  that can be found in the LICENSE file in the root of the source
  *  tree. An additional intellectual property rights grant can be found
  *  in the file PATENTS.  All contributing project authors may
  *  be found in the AUTHORS file in the root of the source tree.
  */
 
 #include "webrtc/video/vie_encoder.h"
 
 #include <algorithm>
 #include <limits>
 
 #include "webrtc/base/checks.h"
 #include "webrtc/base/logging.h"
 #include "webrtc/base/trace_event.h"
 #include "webrtc/base/timeutils.h"
 #include "webrtc/modules/pacing/paced_sender.h"
 #include "webrtc/modules/video_coding/include/video_coding.h"
 #include "webrtc/modules/video_coding/include/video_coding_defines.h"
-#include "webrtc/system_wrappers/include/metrics.h"
 #include "webrtc/video/overuse_frame_detector.h"
 #include "webrtc/video/send_statistics_proxy.h"
 #include "webrtc/video_frame.h"
 
 namespace webrtc {
 
 namespace {
+const int64_t kFrameLogIntervalMs = 60000;

[perkj_webrtc, 2016/09/08 07:34:40]

Can you please add a comment about what this does?

[åsapersson, 2016/09/08 08:17:53]

Done.

 
 VideoCodecType PayloadNameToCodecType(const std::string& payload_name) {
   if (payload_name == "VP8")
     return kVideoCodecVP8;
   if (payload_name == "VP9")
     return kVideoCodecVP9;
   if (payload_name == "H264")
     return kVideoCodecH264;
   return kVideoCodecGeneric;
 }
@@ skipping 151 matching lines @@
     options.low_encode_usage_threshold_percent = 150;
     options.high_encode_usage_threshold_percent = 200;
   }
   return options;
 }
 
 }  //  namespace
 
 class ViEEncoder::EncodeTask : public rtc::QueuedTask {
  public:
-  EncodeTask(const VideoFrame& frame, ViEEncoder* vie_encoder)
-      : vie_encoder_(vie_encoder) {
+  EncodeTask(const VideoFrame& frame, ViEEncoder* vie_encoder, bool log_stats)
+      : vie_encoder_(vie_encoder), log_stats_(log_stats) {
     frame_.ShallowCopy(frame);
     ++vie_encoder_->posted_frames_waiting_for_encode_;
   }
 
  private:
   bool Run() override {
+    RTC_DCHECK_RUN_ON(&vie_encoder_->encoder_queue_);
     RTC_DCHECK_GT(vie_encoder_->posted_frames_waiting_for_encode_.Value(), 0);
+    ++vie_encoder_->captured_frame_count_;
     if (--vie_encoder_->posted_frames_waiting_for_encode_ == 0) {
       vie_encoder_->EncodeVideoFrame(frame_);
     } else {
       // There is a newer frame in flight. Do not encode this frame.
       LOG(LS_VERBOSE)
           << "Incoming frame dropped due to that the encoder is blocked.";
+      ++vie_encoder_->dropped_frame_count_;
+    }
+    if (log_stats_) {
+      LOG(LS_INFO) << "Number of frames: captured "
+                   << vie_encoder_->captured_frame_count_ << ", dropped "

[perkj_webrtc, 2016/09/08 07:34:40]

add the reason why the frames are dropped? A frame can be dropped later in the
pipeline as well right? 

[åsapersson, 2016/09/08 08:17:53]

Done.

+                   << vie_encoder_->dropped_frame_count_ << ", interval_ms "
+                   << kFrameLogIntervalMs;
+      vie_encoder_->captured_frame_count_ = 0;
+      vie_encoder_->dropped_frame_count_ = 0;
     }
     return true;
   }
   VideoFrame frame_;
   ViEEncoder* vie_encoder_;
+  const bool log_stats_;
 };
 
 ViEEncoder::ViEEncoder(uint32_t number_of_cores,
                        SendStatisticsProxy* stats_proxy,
                        const VideoSendStream::Config::EncoderSettings& settings,
                        rtc::VideoSinkInterface<VideoFrame>* pre_encode_callback,
                        LoadObserver* overuse_callback,
                        EncodedFrameObserver* encoder_timing)
     : shutdown_event_(true /* manual_reset */, false),
       number_of_cores_(number_of_cores),
@@ skipping 14 matching lines @@
       last_observed_bitrate_bps_(0),
       encoder_paused_and_dropped_frame_(false),
       has_received_sli_(false),
       picture_id_sli_(0),
       has_received_rpsi_(false),
       picture_id_rpsi_(0),
       clock_(Clock::GetRealTimeClock()),
       last_captured_timestamp_(0),
       delta_ntp_internal_ms_(clock_->CurrentNtpInMilliseconds() -
                              clock_->TimeInMilliseconds()),
+      last_frame_log_ms_(clock_->TimeInMilliseconds()),
+      captured_frame_count_(0),
+      dropped_frame_count_(0),
       encoder_queue_("EncoderQueue") {
   vp_->EnableTemporalDecimation(false);
 
   encoder_queue_.PostTask([this] {
     RTC_DCHECK_RUN_ON(&encoder_queue_);
     video_sender_.RegisterExternalEncoder(
         settings_.encoder, settings_.payload_type, settings_.internal_source);
   });
 }
 
@@ skipping 123 matching lines @@
 
   if (incoming_frame.ntp_time_ms() <= last_captured_timestamp_) {
     // We don't allow the same capture time for two frames, drop this one.
     LOG(LS_WARNING) << "Same/old NTP timestamp ("
                     << incoming_frame.ntp_time_ms()
                     << " <= " << last_captured_timestamp_
                     << ") for incoming frame. Dropping.";
     return;
   }
 
+  bool log_stats = false;
+  if (current_time - last_frame_log_ms_ > kFrameLogIntervalMs) {
+    last_frame_log_ms_ = current_time;
+    log_stats = true;
+  }
+
   last_captured_timestamp_ = incoming_frame.ntp_time_ms();
   overuse_detector_.FrameCaptured(incoming_frame);
-  encoder_queue_.PostTask(
-      std::unique_ptr<rtc::QueuedTask>(new EncodeTask(incoming_frame, this)));
+  encoder_queue_.PostTask(std::unique_ptr<rtc::QueuedTask>(
+      new EncodeTask(incoming_frame, this, log_stats)));
 }
 
 bool ViEEncoder::EncoderPaused() const {
   RTC_DCHECK_RUN_ON(&encoder_queue_);
   // Pause video if paused by caller or as long as the network is down or the
   // pacer queue has grown too large in buffered mode.
   // If the pacer queue has grown too large or the network is down,
   // last_observed_bitrate_bps_ will be 0.
   return last_observed_bitrate_bps_ == 0;
 }
@@ skipping 170 matching lines @@
     load_observer_->OnLoadUpdate(LoadObserver::kOveruse);
 }
 
 void ViEEncoder::NormalUsage() {
   RTC_DCHECK_RUN_ON(&module_process_thread_checker_);
   if (load_observer_)
     load_observer_->OnLoadUpdate(LoadObserver::kUnderuse);
 }
 
 }  // namespace webrtc