Always on statistics for AndroidMediaEncoder.

webrtc/api/java/jni/androidmediaencoder_jni.cc

Index: webrtc/api/java/jni/androidmediaencoder_jni.cc
diff --git a/webrtc/api/java/jni/androidmediaencoder_jni.cc b/webrtc/api/java/jni/androidmediaencoder_jni.cc
index 0e36aa1b7463dba4b60b3b7a488d452d85c3982a..d4e53b3db6ced027f7984b7a05624437a684ed07 100644
--- a/webrtc/api/java/jni/androidmediaencoder_jni.cc
+++ b/webrtc/api/java/jni/androidmediaencoder_jni.cc
@@ -226,7 +226,9 @@ class MediaCodecVideoEncoder : public webrtc::VideoEncoder,
   int current_encoding_time_ms_;  // Overall encoding time in the current second
   int64_t last_input_timestamp_ms_;  // Timestamp of last received yuv frame.
   int64_t last_output_timestamp_ms_;  // Timestamp of last encoded frame.
-  bool output_delivery_loop_running_; // Is the onMessage loop running
+  // Is the onMessage loop running at regular polling rate. If false, it is
+  // running at lower poll rate of kMediaCodecStatisticsIntervalMs.
+  bool output_delivery_loop_running_;
 
   struct InputFrameInfo {
     InputFrameInfo(int64_t encode_start_time,
@@ -307,7 +309,6 @@ MediaCodecVideoEncoder::MediaCodecVideoEncoder(
     inited_(false),
     use_surface_(false),
     picture_id_(0),
-    output_delivery_loop_running_(false),
     egl_context_(egl_context) {
   ScopedLocalRefFrame local_ref_frame(jni);
   // It would be nice to avoid spinning up a new thread per MediaCodec, and
@@ -479,9 +480,15 @@ void MediaCodecVideoEncoder::OnMessage(rtc::Message* msg) {
   // If there aren't more frames to deliver, we can stop the loop
   if (!input_frame_infos_.empty()) {
     codec_thread_->PostDelayed(kMediaCodecPollMs, this);
+    output_delivery_loop_running_ = true;
   } else {
+    codec_thread_->PostDelayed(kMediaCodecStatisticsIntervalMs, this);

[AlexG, 2016/06/10 20:16:25]

I think this stopping or increasing polling interval may be dangerous for the
case when encoder generates 2 frames for a single output - suppose for H.264
encoder it generates first frame with SPS and PPS NAL and then actual encoded
frame. Or something happens in HW that it by error generates 2 outputs. I
suggest instead of complete polling stop or increasing polling interval to 3
second increase it to 50 or 100 ms - it should not affect the performance, but
will make code more robust against encoder mis behaviour.

[sakal, 2016/06/13 07:13:21]

Done.

     output_delivery_loop_running_ = false;
   }
+
+  // Call log statistics here so it's called even if no frames are being
+  // delivered.
+  LogStatistics(false);
 }
 
 bool MediaCodecVideoEncoder::ResetCodecOnCodecThread() {
@@ -532,6 +539,7 @@ int32_t MediaCodecVideoEncoder::InitEncodeOnCodecThread(
   current_encoding_time_ms_ = 0;
   last_input_timestamp_ms_ = -1;
   last_output_timestamp_ms_ = -1;
+  output_delivery_loop_running_ = false;
   output_timestamp_ = 0;
   output_render_time_ms_ = 0;
   input_frame_infos_.clear();
@@ -595,6 +603,7 @@ int32_t MediaCodecVideoEncoder::InitEncodeOnCodecThread(
   }
 
   inited_ = true;
+  codec_thread_->PostDelayed(kMediaCodecStatisticsIntervalMs, this);

[AlexG, 2016/06/10 20:16:25]

This is not needed - first 10 frames are logged, so we can detect jam for them.

[sakal, 2016/06/13 07:13:21]

Done.

   return WEBRTC_VIDEO_CODEC_OK;
 }
 
@@ -741,8 +750,9 @@ int32_t MediaCodecVideoEncoder::EncodeOnCodecThread(
   current_timestamp_us_ += rtc::kNumMicrosecsPerSec / last_set_fps_;
 
   if (!output_delivery_loop_running_) {

[AlexG, 2016/06/10 20:16:25]

It is safer and less code to just remove this if condition - always schedule
DeliverPendingOutptu when input frame arrives

[sakal, 2016/06/13 07:13:21]

Done.

-    output_delivery_loop_running_ = true;
+    codec_thread_->Clear(this);
     codec_thread_->PostDelayed(kMediaCodecPollMs, this);
+    output_delivery_loop_running_ = true;
   }
 
   if (!DeliverPendingOutputs(jni)) {
@@ -926,6 +936,7 @@ jlong MediaCodecVideoEncoder::GetOutputBufferInfoPresentationTimestampUs(
 
 bool MediaCodecVideoEncoder::DeliverPendingOutputs(JNIEnv* jni) {
   RTC_DCHECK(codec_thread_checker_.CalledOnValidThread());
+
   while (true) {
     jobject j_output_buffer_info = jni->CallObjectMethod(
         *j_media_codec_video_encoder_, j_dequeue_output_buffer_method_);
@@ -1121,8 +1132,11 @@ bool MediaCodecVideoEncoder::DeliverPendingOutputs(JNIEnv* jni) {
 
 void MediaCodecVideoEncoder::LogStatistics(bool force_log) {
   int statistic_time_ms = rtc::TimeMillis() - stat_start_time_ms_;
-  if ((statistic_time_ms >= kMediaCodecStatisticsIntervalMs || force_log) &&
-      current_frames_ > 0 && statistic_time_ms > 0) {
+  if ((statistic_time_ms >= kMediaCodecStatisticsIntervalMs || force_log)
+      && statistic_time_ms > 0) {
+    // Prevent division by zero
+    int current_frames_divider = current_frames_ != 0 ? current_frames_ : 1;
+
     int current_bitrate = current_bytes_ * 8 / statistic_time_ms;
     int current_fps =
         (current_frames_ * 1000 + statistic_time_ms / 2) / statistic_time_ms;
@@ -1130,8 +1144,8 @@ void MediaCodecVideoEncoder::LogStatistics(bool force_log) {
         ". Bitrate: " << current_bitrate <<
         ", target: " << last_set_bitrate_kbps_ << " kbps" <<
         ", fps: " << current_fps <<
-        ", encTime: " << (current_encoding_time_ms_ / current_frames_) <<
-        ". QP: " << (current_acc_qp_ / current_frames_) <<
+        ", encTime: " << (current_encoding_time_ms_ / current_frames_divider) <<
+        ". QP: " << (current_acc_qp_ / current_frames_divider) <<
         " for last " << statistic_time_ms << " ms.";
     stat_start_time_ms_ = rtc::TimeMillis();
     current_frames_ = 0;