[Chromecast] Tweak Android's CMA backend playback logs

This tweaks/removes/reduces/throttles logging during audio playback
in CMA backend for Android. In addition, it added a couple of missing
initializers in AudioSinkAudioTrackImpl.

Bug: None
Test: run on IMX7, observe fewer/better logs...
Change-Id: I3ca294abe50a3e2a62c95c6b0feaff5bde485cdb
Reviewed-on: https://chromium-review.googlesource.com/545261Reviewed-by: Luke Halliwell <halliwell@chromium.org>
Commit-Queue: Chris Kuiper <ckuiper@chromium.org>
Cr-Commit-Position: refs/heads/master@{#481913}

chromecast/media/cma/backend/android/audio_sink_android_audiotrack_impl.cc

@@ -81,6 +81,10 @@ AudioSinkAndroidAudioTrackImpl::AudioSinkAndroidAudioTrackImpl(
   Java_AudioSinkAudioTrackImpl_init(
       base::android::AttachCurrentThread(), j_audio_sink_audiotrack_impl_,
       input_samples_per_second_, kDirectBufferSize);
+  // Should be set now.
+  DCHECK(direct_pcm_buffer_address_);
+  DCHECK(direct_rendering_delay_address_);
+
   base::Thread::Options options;
   options.priority = base::ThreadPriority::REALTIME_AUDIO;
   feeder_thread_.StartWithOptions(options);
@@ -118,7 +122,6 @@ const char* AudioSinkAndroidAudioTrackImpl::GetContentTypeName() const {
 
 void AudioSinkAndroidAudioTrackImpl::FinalizeOnFeederThread() {
   RUN_ON_FEEDER_THREAD(FinalizeOnFeederThread);
-  LOG(INFO) << __func__ << "(" << this << "):";
   if (j_audio_sink_audiotrack_impl_.is_null()) {
     LOG(WARNING) << "j_audio_sink_audiotrack_impl_ is NULL";
     return;
@@ -143,7 +146,6 @@ void AudioSinkAndroidAudioTrackImpl::CacheDirectBufferAddress(
     const JavaParamRef<jobject>& obj,
     const JavaParamRef<jobject>& pcm_byte_buffer,
     const JavaParamRef<jobject>& timestamp_byte_buffer) {
-  LOG(INFO) << __func__ << "(" << this << "):";
   direct_pcm_buffer_address_ =
       static_cast<uint8_t*>(env->GetDirectBufferAddress(pcm_byte_buffer));
   direct_rendering_delay_address_ = static_cast<uint64_t*>(
@@ -170,9 +172,9 @@ void AudioSinkAndroidAudioTrackImpl::FeedData() {
     return;
   }
 
-  VLOG(3) << __func__ << "(" << this << "):"
-          << " [" << pending_data_->data_size() << "]"
-          << " @ts=" << pending_data_->timestamp();
+  DVLOG(3) << __func__ << "(" << this << "):"
+           << " [" << pending_data_->data_size() << "]"
+           << " @ts=" << pending_data_->timestamp();
 
   if (pending_data_->data_size() == 0) {
     LOG(INFO) << __func__ << "(" << this << "): empty data buffer!";
@@ -322,9 +324,6 @@ void AudioSinkAndroidAudioTrackImpl::SetPaused(bool paused) {
 
 void AudioSinkAndroidAudioTrackImpl::UpdateVolume() {
   DCHECK(feeder_task_runner_->BelongsToCurrentThread());
-
-  LOG(INFO) << __func__ << "(" << this << "): vol=" << EffectiveVolume();
-
   Java_AudioSinkAudioTrackImpl_setVolume(base::android::AttachCurrentThread(),
                                          j_audio_sink_audiotrack_impl_,
                                          EffectiveVolume());

chromecast/media/cma/backend/android/java/src/org/chromium/chromecast/cma/backend/android/AudioSinkAudioTrackImpl.java

@@ -44,7 +44,7 @@ import java.nio.ByteOrder;
 @TargetApi(Build.VERSION_CODES.N)
 class AudioSinkAudioTrackImpl {
     private static final String TAG = "AudiotrackImpl";
-    private static final int DEBUG_LEVEL = 1;
+    private static final int DEBUG_LEVEL = 0;
 
     // hardcoded AudioTrack config parameters
     private static final int STREAM_TYPE = AudioManager.STREAM_MUSIC;
@@ -57,6 +57,7 @@ class AudioSinkAudioTrackImpl {
 
     private static final long SEC_IN_NSEC = 1000000000L;
     private static final long TIMESTAMP_UPDATE_PERIOD = 3 * SEC_IN_NSEC;
+    private static final long UNDERRUN_LOG_THROTTLE_PERIOD = SEC_IN_NSEC;
 
     private final long mNativeAudioSinkAudioTrackImpl;
 
@@ -73,6 +74,7 @@ class AudioSinkAudioTrackImpl {
     private boolean mTriggerTimestampUpdateNow; // Set to true to trigger an early update.
 
     private int mLastUnderrunCount;
+    private long mLastUnderrunLogNsec;
 
     // Statistics
     private long mTotalFramesWritten;
@@ -94,16 +96,16 @@ class AudioSinkAudioTrackImpl {
     @CalledByNative
     private static AudioSinkAudioTrackImpl createAudioSinkAudioTrackImpl(
             long nativeAudioSinkAudioTrackImpl) {
-        Log.i(TAG, "Creating new AudioSinkAudioTrackImpl instance");
         return new AudioSinkAudioTrackImpl(nativeAudioSinkAudioTrackImpl);
     }
 
     private AudioSinkAudioTrackImpl(long nativeAudioSinkAudioTrackImpl) {
-        Log.i(TAG, "Ctor called...");
         mNativeAudioSinkAudioTrackImpl = nativeAudioSinkAudioTrackImpl;
+        mIsInitialized = false;
         mLastTimestampUpdateNsec = NO_TIMESTAMP;
         mTriggerTimestampUpdateNow = false;
         mLastUnderrunCount = 0;
+        mLastUnderrunLogNsec = NO_TIMESTAMP;
         mTotalFramesWritten = 0;
     }
 
@@ -116,7 +118,7 @@ class AudioSinkAudioTrackImpl {
         Log.i(TAG,
                 "Init:"
                         + " sampleRateInHz=" + sampleRateInHz
-                        + " API-version=" + android.os.Build.VERSION.SDK_INT);
+                        + " bytesPerBuffer=" + bytesPerBuffer);
 
         if (mIsInitialized) {
             Log.w(TAG, "Init: already initialized.");
@@ -326,9 +328,7 @@ class AudioSinkAudioTrackImpl {
     private void updateTimestamp() {
         int underruns = getUnderrunCount();
         if (underruns != mLastUnderrunCount) {
-            Log.i(TAG,
-                    "Underrun detected (" + mLastUnderrunCount + "->" + underruns
-                            + ")! Resetting rendering delay logic.");
+            logUnderruns(underruns);
             mLastTimestampUpdateNsec = NO_TIMESTAMP;
             mLastUnderrunCount = underruns;
         }
@@ -351,6 +351,18 @@ class AudioSinkAudioTrackImpl {
         }
     }
 
+    /** Logs underruns in a throttled manner. */
+    private void logUnderruns(int newUnderruns) {
+        if (DEBUG_LEVEL >= 1
+                || (mLastUnderrunLogNsec == NO_TIMESTAMP
+                           || elapsedNsec(mLastUnderrunLogNsec) > UNDERRUN_LOG_THROTTLE_PERIOD)) {
+            Log.i(TAG,
+                    "Underrun detected (" + mLastUnderrunCount + "->" + newUnderruns
+                            + ")! Resetting rendering delay logic.");
+            mLastUnderrunLogNsec = System.nanoTime();
+        }
+    }
+
     //
     // JNI functions in native land.
     //